Erlang/OTP 18 の実行環境(ERTS バージョン 7.0)では、時刻に関連する新しい API と、Time Warp(タイムワープ)モードが導入されました。この記事では、ERTS ユーザーガイドの「Time and Time Correction in Erlang」中でポイントとなる概念について、実験を通して確認しようと思います。
OTP 17 までは erlang:now/0
を使いまわしてきた
OTP 18 より前のリリースでは、現在時刻のタイムスタンプを取得する API として、erlang:now/0
が使われてきました。また、類似のものに os:timestamp/0
もあります。前者は Erlang 実行環境(Erlang VM)の中で管理されているシステムクロックからタイムスタンプを取得し、後者は OS が管理するシステムクロックから取得します。
1> F = fun() -> {erlang:now(), os:timestamp()} end.
#Fun<erl_eval.20.54118792>
2> F().
{{1449,412303,848793},{1449,412303,848798}}
タイムスタンプは左から、メガ秒、秒、マイクロ秒となっており、これらを足し合わせることで、UNIX エポックからの経過時間を、マイクロ秒の分解能で得ることができます。なお、erlang:now()
は、単に now()
と書くこともできます。
3> {MegaSecs, Secs, MicroSecs} = now().
{1449,412312,352252}
4> CurrentTimeMicro = MegaSecs * 1000000000000 + Secs * 1000000 + MicroSecs.
1449412312352252
5> CurrentTimeMicro div 1000000.
1449412312
$ date --date='@1449412312'
Sun Dec 6 22:31:52 CST 2015
(ちなみに CST は China Standard Time です。いま上海に住んでます)
最初の例で、erlang:now/0
と os:timestamp/0
の返した値に5マイクロ秒の開きありますが、これは、2つの関数を同時ではなく順番に呼んだためです。
用途1:現在時刻を取得する
erlang:now/0
はいくつかの用途に使われてきました。最初に思い浮かぶ用途は、あたりまえですが「現在日時の取得」です。calendar
モジュールには、タイムスタンプを各種のカレンダー形式へ変換する関数が用意されています。
5> calendar:now_to_local_time(now()).
{{2015,12,6},{22,32,49}} %% 2015年12月6日 22時32分49秒
用途2:経過時間を計る
2つ目の用途は「経過時間の測定」です。timer
モジュールの関数を使うと、2つのタイムスタンプから経過時間を、マイクロ秒の分解能で求められます。
6> Start = now().
{1449,412383,80755}
7> End = now().
{1449,412387,489901}
8> timer:now_diff(End, Start).
4409146 %% 単位:マイクロ秒
9> timer:now_diff(End, Start) / 1000000.
4.409146 %% 単位:秒
これにより、ある一定の間隔で処理を実行したり、通信でタイムアウトを発生させたり、性能を測定したりといったことが実現できます。
用途3:ユニークな数値を生成する
3つめの用途は「ユニークな数値の生成」です。erlang:now/0
は、単に現在時刻を返すだけでなく、そのタイムスタンプが strictly monotonically increasing number(狭義の単調増加数)であることを保証します。これにより、複数のプロセスから同時に(1マイクロ秒未満の時差で)呼ばれても、必ず「前回のタイムスタンプ < 今回のタイムスタンプ」となる値を返します。
これにより、ユニークなトランザクションIDの生成などにも使うことができます。
時刻関連 API に求められてきた3つの要件
これらの用途から、時刻関連の API に求められる要件には、以下の3つがあると言えそうです。
| 要件 | 説明
:-:|:----|:----
1 | 現在時刻を正確に得られる | OS が提供するシステムクロックが示す時刻が、常に得られる
2 | 経過時間を正確に測定できる | 2つのタイムスタンプの差から、経過時間を計ることができる
3 | ユニークな数値を得られる | 関数を呼ぶ毎に、重複しない値が返されることが保証されている。一例として strictly monotonically increasing number がある
3は必ずしも時刻関連の API で実現する必要はありません。しかし OTP 18 より前のリリースでは erlang:now/0
がその役割を担ってきました。
erlang:now/0
はまもなく廃止される
このように、ある意味で便利に使われてきた erlang:now/0
ですが、OTP 18 では deprecated となりました。近々廃止される予定です。なぜでしょうか?
システムクロックの修正に対応しきれない
erlang:now/0
はマシンのシステムクロックが、いつも正確であることを前提に作られたような関数です。クロックが正確である限り、3つの要件を同時に満たすことができます。しかし、もしシステムクロックが大きくズレて、正しい時間に修正されたなら...、erlang:now/0
では数十分程度の修正なら対応できますが、それ以上だと厳しくなります。
システムクロックがいつも正確であれば良いのですが、現実はそうではありません。放っておけば少しずつ狂っていきますので、正しい時刻に合わせ直す必要があります。特に仮想マシンのゲスト側ではこの傾向が強いようです。もっと精度の高いクロック、例えば原子時計を搭載すればいいようにも思えますが、これで救えるのは仮想マシンのホスト側のみで、ソフトウェアでエミュレートされているゲスト側のクロックまでは直せません。そのため、NTPなどで補正するわけですが、これも常に利用可能なわけではありません。
さらに、今後は IoT(モノのインターネット)デバイスも増えてくるでしょう。そのようなデバイスでは、システムクロックのバッテリーバックアップを持たず、システム起動直後はクロックが初期状態になるものも多いです。アプリケーションが起動してしばらくしてから、NTPなどによって時刻が合う、なんてことが普通に行われているかもしれません。
OTP 18 の新しい時刻関連 API とタイムワープモードは、このシステムクロックの修正に関する問題を、根本的に解決するために導入されました。
実験1:システムクロックを狂わせてみる
新しい API を見る前に、まずは erlang:now/0
がどんな風に振る舞うか、そして、それがなぜ問題なのかを実験で確認しましょう。x86_64 アーキテクチャーの仮想マシンで GNU/Linux(CentOS 7)と Erlang/OTP を稼働させ、システムクロックを修正してみます。
この仮想マシンは ntpd による時刻合わせは行っていません。ntpdate
コマンドを実行し、OS のシステムクロックを合わせておきます。
$ sudo ntpdate -b jp.pool.ntp.org
6 Dec 22:36:37 ntpdate[2766]: step time server 129.250.35.251 offset 0.014679 sec
タイムワープモードがデフォルトの状態
OTP 18 では erl
の起動引数にタイムワープモード +C
が追加されました。
$ erl +C hoge
Invalid time warp mode: hoge
Usage: beam.smp [flags] [ -- [init_args] ]
The flags are:
...
-C mode set time warp mode; valid modes are:
no_time_warp|single_time_warp|multi_time_warp
タイムワープとは、Erlang 実行環境内のシステムクロックが、未来や過去の時間にジャンプすることを指しています。デフォルトは no_time_warp
でタイムワープは禁止されます。これは OTP 18 より前のリリースと互換性を保つためのモードで、この設定のまま使っても、新しい API の恩恵をフルに受けることはできません。まずは従来の動作を知るために、このモードで起動してみます。
また、過去のリリースからすでに +c
というフラグも用意されています。これは date/time correction (日付時刻の修正)機能のオン・オフを切り替えるためのもので、デフォルトは true
(修正機能をオンにする)になっています。こちらはデフォルトのままにしておいてください。もしオフにすると、no_time_warp
も含めて、時刻修正に関する機能が動作しなくなってしまいます。
なお、OTP は 2015年12月上旬時点で最新の 18.1.5 を使用しました。
$ cat /etc/centos-release
CentOS Linux release 7.1.1503 (Core)
$ kerl list installations
18.1.5_hipe /home/tatsuya/erlang/18.1.5_hipe
17.5.6.5_hipe /home/tatsuya/erlang/17.5.6.5_hipe
$ source ~/erlang/18.1.5_hipe/activate
$ kerl active
The current active installation is:
/home/tatsuya/erlang/18.1.5_hipe
$ erl
Erlang/OTP 18 [erts-7.1] [source] [64-bit] [smp:2:2] [async-threads:10] [hipe] [kernel-poll:false]
Eshell V7.1 (abort with ^G)
1> (Ctrl + G)
User switch command
--> q
$ curl -O https://raw.githubusercontent.com/tatsuya6502/erlang-examples/master/show-otp-version.escript
$ chmod +x show-otp-version.escript
$ echo $(./show-otp-version.escript)
18.1.5
動作確認のために、簡単なモジュールを用意しました。以下の関数を使用します。
-module(t1).
-compile(export_all).
-spec print_time_legacy() -> ok.
print_time_legacy() ->
OSTS = os:timestamp(),
Now = now(),
LocalTimeOSTS = calendar:now_to_local_time(OSTS),
LocalTimeNow = calendar:now_to_local_time(Now),
Diff = timer:now_diff(Now, OSTS),
io:format("---------~n"
"os:timestamp ~p -> ~p~n"
"erlang:now ~p -> ~p (~w us)~n",
[OSTS, LocalTimeOSTS,
Now, LocalTimeNow, Diff]).
-spec repeat_time_legacy() -> timer:tref().
repeat_time_legacy() ->
{ok, TRef} =
timer:apply_interval(1000, ?MODULE, print_time_legacy, []),
TRef.
コンパイルして実行します。print_time_legacy/0
は、os:timestamp/0
と erlang:now()/0
を順番に実行し、タイムスタンプと、calendar:now_to_localtime/1
で変換した現在時刻を表示します。そして、最後に、2つのタイムスタンプの時間差を、マイクロ秒の精度で表示します。
$ erl
1> c(t1).
t1.erl:7: Warning: erlang:now/0: Deprecated BIF. See the "Time and Time
Correction in Erlang" chapter of the ERTS User's Guide for more
information.
{ok,t1}
2> t1:print_time_legacy().
---------
os:timestamp {1449,412756,285759} -> {{2015,12,6},{22,39,16}}
erlang:now {1449,412756,285763} -> {{2015,12,6},{22,39,16}} (4 us)
ok
3>
repeat_time_legacy/0
は、print_time_legacy/0
が1秒間隔で実行されるよう、タイマーを設定します。戻り値は、タイマーの Ref です。
3> TR = t1:repeat_time_legacy().
interval,#Ref<0.0.1.97>
4> ---------
os:timestamp {1449,412765,128993} -> {{2015,12,6},{22,39,25}}
erlang:now {1449,412765,128997} -> {{2015,12,6},{22,39,25}} (4 us)
---------
os:timestamp {1449,412766,129985} -> {{2015,12,6},{22,39,26}}
erlang:now {1449,412766,129989} -> {{2015,12,6},{22,39,26}} (4 us)
---------
os:timestamp {1449,412767,130912} -> {{2015,12,6},{22,39,27}}
erlang:now {1449,412767,130915} -> {{2015,12,6},{22,39,27}} (3 us)
---------
os:timestamp {1449,412768,128955} -> {{2015,12,6},{22,39,28}}
erlang:now {1449,412768,128959} -> {{2015,12,6},{22,39,28}} (4 us)
4> timer:cancel(TR).
{ok,cancel}
5>
2つのタイムスタンプの差は数マイクロ秒におさまっています。
時刻を進ませてみる
では、repeat_time_legacy/0
が動作している状態で、システムクロックを約1分進めてみます。
$ date
Sun Dec 6 22:41:48 CST 2015
$ sudo date 12062243
Sun Dec 6 22:43:00 CST 2015
print_time_legacy/0
の表示を見ると、os:timestamp/0
側では、システムクロックの時刻がすぐに反映されました。一方で erlang:now/0
側の時刻は変わりません。
---------
os:timestamp {1449,412919,449076} -> {{2015,12,6},{22,41,59}}
erlang:now {1449,412919,449079} -> {{2015,12,6},{22,41,59}} (3 us)
---------
os:timestamp {1449,412920,448004} -> {{2015,12,6},{22,42,0}}
erlang:now {1449,412920,448008} -> {{2015,12,6},{22,42,0}} (4 us)
---------
os:timestamp {1449,412980,315715} -> {{2015,12,6},{22,43,0}} %% <-- 1分進んだ
erlang:now {1449,412921,448009} -> {{2015,12,6},{22,42,1}} (-58867706 us)
---------
os:timestamp {1449,412981,315559} -> {{2015,12,6},{22,43,1}}
erlang:now {1449,412922,447852} -> {{2015,12,6},{22,42,2}} (-58867707 us)
が、30秒ほど待つと、その差が少しずつ縮まり始めました!
os:timestamp {1449,413014,316449} -> {{2015,12,6},{22,43,34}}
erlang:now {1449,412955,448742} -> {{2015,12,6},{22,42,35}} (-58867707 us)
---------
os:timestamp {1449,413015,316755} -> {{2015,12,6},{22,43,35}}
erlang:now {1449,412956,449830} -> {{2015,12,6},{22,42,36}} (-58866925 us)
---------
os:timestamp {1449,413016,316950} -> {{2015,12,6},{22,43,36}}
erlang:now {1449,412957,459793} -> {{2015,12,6},{22,42,37}} (-58857157 us)
---------
os:timestamp {1449,413017,307114} -> {{2015,12,6},{22,43,37}}
erlang:now {1449,412958,459626} -> {{2015,12,6},{22,42,38}} (-58847488 us)
---------
os:timestamp {1449,413018,297016} -> {{2015,12,6},{22,43,38}}
erlang:now {1449,412959,459194} -> {{2015,12,6},{22,42,39}} (-58837822 us)
1分間につき、0.5秒くらいのペースで差が縮まっているようです。ということは、1分のズレなら、2時間ほどかければ実時間に追いつきそうです。
時刻を遅らせてみる
では、この「クロックが進んだ状態」から、正しい時刻に合わせ直します。これにより、時刻が約1分過去に戻ることになります。
$ sudo ntpdate -b jp.pool.ntp.org
...
---------
os:timestamp {1449,413191,594393} -> {{2015,12,6},{22,46,31}}
erlang:now {1449,413134,448930} -> {{2015,12,6},{22,45,34}} (-57145463 us)
---------
os:timestamp {1449,413192,587868} -> {{2015,12,6},{22,46,32}}
erlang:now {1449,413135,452106} -> {{2015,12,6},{22,45,35}} (-57135762 us)
---------
os:timestamp {1449,413134,760236} -> {{2015,12,6},{22,45,34}} %% <-- 1分遅れた
erlang:now {1449,413136,458810} -> {{2015,12,6},{22,45,36}} (1698574 us)
---------
os:timestamp {1449,413135,754355} -> {{2015,12,6},{22,45,35}}
erlang:now {1449,413137,462637} -> {{2015,12,6},{22,45,37}} (1708282 us)
---------
os:timestamp {1449,413136,742354} -> {{2015,12,6},{22,45,36}}
erlang:now {1449,413138,460285} -> {{2015,12,6},{22,45,38}} (1717931 us)
...(中略)...
---------
os:timestamp {1449,413365,422641} -> {{2015,12,6},{22,49,25}}
erlang:now {1449,413365,448937} -> {{2015,12,6},{22,49,25}} (26296 us)
---------
os:timestamp {1449,413366,432637} -> {{2015,12,6},{22,49,26}}
erlang:now {1449,413366,449071} -> {{2015,12,6},{22,49,26}} (16434 us)
---------
os:timestamp {1449,413367,442907} -> {{2015,12,6},{22,49,27}}
erlang:now {1449,413367,449472} -> {{2015,12,6},{22,49,27}} (6565 us)
---------
os:timestamp {1449,413368,451275} -> {{2015,12,6},{22,49,28}}
erlang:now {1449,413368,447995} -> {{2015,12,6},{22,49,28}} (-3280 us)
---------
os:timestamp {1449,413369,449201} -> {{2015,12,6},{22,49,29}}
erlang:now {1449,413369,449204} -> {{2015,12,6},{22,49,29}} (3 us)
---------
os:timestamp {1449,413370,450116} -> {{2015,12,6},{22,49,30}}
erlang:now {1449,413370,450119} -> {{2015,12,6},{22,49,30}} (3 us)
---------
os:timestamp {1449,413371,448543} -> {{2015,12,6},{22,49,31}}
erlang:now {1449,413371,448546} -> {{2015,12,6},{22,49,31}} (3 us)
os:timestamp/0
のタイムスタンプは過去に戻りましたが、erlang:now/0
のタイムスタンプは、絶対に過去へは戻りません。これは、要件3で挙げた、strictly monotonically increasing number を満たすためです。
やはり徐々に2つのタイムスタンプの差が狭まっていき、最後はズレがなくなりました。
erlang:now/0
では3つの用途を同時に満たせない
この実験で、以下のことがわかりました。
- 日付時刻の修正機能とタイムワープモードがデフォルト設定(
+c true +C no_time_warp
)で動作してる時にシステムクロックが変更されると、Erlang 実行環境は、内部クロックをわずかに早めたり遅らせたりすることで、徐々にシステムクロックに同期させていく - 約1分の差の時は、同期できるまで2時間ほどかかる
先ほど3つの用途を挙げましたが、この動作では、要件1が一時的に満たせなくなります。また、要件2にも多少の誤差の影響が出ます。
| 要件 | 満たせる? | 説明
:-:|:-----------------|:----------|:-----------------------------------
1 | 現在時刻を正確に得られる | 満たせない | 同期できるまで OS のシステムクロックとは異なる時間が返される
2 | 経過時間を正確に測定できる | ある程度満たせる | 実行環境のクロックが早まったり遅まったりするので、多少の誤差が生じる
3 | ユニークな数値を得られる | 満たせる |
今回のような約1分の修正なら問題ないかもしれませんが、これがもし数日、数カ月、数年だったら...、同期できるまで長い時間がかかることが予想されます。その場合は、緩やかな同期をあきらめて、Erlang 実行環境を再起動したほうがいいかもしれません。
実験2:erlang:now/0
のままタイムワープモードを multi_time_warp
にする
multi_time_warp
はタイムワープを何度でも許すモードです。3つの要件を同時に満たすために導入されました。ただし、新しい API を使うことが前提となっており、erlang:now/0
はうまく動きません。あえてどうなるか見てみましょう。まずはシステムクロックを約1分進めて様子を見ます。
$ erl +C multi_time_warp
1> TR = t1:repeat_time_legacy().
...(中略)...
---------
os:timestamp {1449,413463,778835} -> {{2015,12,6},{22,51,3}}
erlang:now {1449,413463,778838} -> {{2015,12,6},{22,51,3}} (3 us)
---------
os:timestamp {1449,413464,778928} -> {{2015,12,6},{22,51,4}}
erlang:now {1449,413464,778931} -> {{2015,12,6},{22,51,4}} (3 us)
---------
os:timestamp {1449,413520,586649} -> {{2015,12,6},{22,52,0}} %% <-- 1分進んだ
erlang:now {1449,413465,780749} -> {{2015,12,6},{22,51,5}} (-54805900 us)
---------
os:timestamp {1449,413521,584824} -> {{2015,12,6},{22,52,1}}
erlang:now {1449,413466,778924} -> {{2015,12,6},{22,51,6}} (-54805900 us)
---------
20秒ほど待つと erlang:now/0
に反映されました。1分ほど未来へタイムワープしたことになります。
---------
os:timestamp {1449,413539,584833} -> {{2015,12,6},{22,52,19}}
erlang:now {1449,413484,778933} -> {{2015,12,6},{22,51,24}} (-54805900 us)
---------
os:timestamp {1449,413540,584901} -> {{2015,12,6},{22,52,20}}
erlang:now {1449,413540,584904} -> {{2015,12,6},{22,52,20}} (3 us) %% <-- 1分進んだ
---------
os:timestamp {1449,413541,584880} -> {{2015,12,6},{22,52,21}}
erlang:now {1449,413541,584883} -> {{2015,12,6},{22,52,21}} (3 us)
今度はシステムクロックを約1分遅らせます。
---------
os:timestamp {1449,413579,584737} -> {{2015,12,6},{22,52,59}}
erlang:now {1449,413579,584740} -> {{2015,12,6},{22,52,59}} (3 us)
---------
os:timestamp {1449,413580,584721} -> {{2015,12,6},{22,53,0}}
erlang:now {1449,413580,584724} -> {{2015,12,6},{22,53,0}} (3 us)
---------
os:timestamp {1449,413526,650929} -> {{2015,12,6},{22,52,6}} %% <-- 1分遅れた
erlang:now {1449,413581,584852} -> {{2015,12,6},{22,53,1}} (54933923 us)
---------
os:timestamp {1449,413527,650829} -> {{2015,12,6},{22,52,7}}
erlang:now {1449,413582,584752} -> {{2015,12,6},{22,53,2}} (54933923 us)
20秒ほど待つと erlang:now/0
の表す現在時刻が {22,53,19}
のまま動かなくなってしまいました!
---------
os:timestamp {1449,413542,651066} -> {{2015,12,6},{22,52,22}}
erlang:now {1449,413597,584987} -> {{2015,12,6},{22,53,17}} (54933921 us)
---------
os:timestamp {1449,413543,649822} -> {{2015,12,6},{22,52,23}}
erlang:now {1449,413598,583745} -> {{2015,12,6},{22,53,18}} (54933923 us)
---------
os:timestamp {1449,413544,650759} -> {{2015,12,6},{22,52,24}}
erlang:now {1449,413599,584682} -> {{2015,12,6},{22,53,19}} (54933923 us) %% <-- 止まった!?
---------
os:timestamp {1449,413545,650699} -> {{2015,12,6},{22,52,25}}
erlang:now {1449,413599,584683} -> {{2015,12,6},{22,53,19}} (53933984 us)
---------
os:timestamp {1449,413546,650708} -> {{2015,12,6},{22,52,26}}
erlang:now {1449,413599,584684} -> {{2015,12,6},{22,53,19}} (52933976 us)
---------
os:timestamp {1449,413547,650583} -> {{2015,12,6},{22,52,27}}
erlang:now {1449,413599,584685} -> {{2015,12,6},{22,53,19}} (51934102 us)
---------
os:timestamp {1449,413548,650827} -> {{2015,12,6},{22,52,28}}
erlang:now {1449,413599,584686} -> {{2015,12,6},{22,53,19}} (50933859 us)
でもよく見ると、erlang:now/0
を呼ぶごとに1マイクロ秒だけ進んでます。これは要件3を満たすためですね。
%% `erlang:now/0` を呼ぶごとに1マイクロ秒だけ進んでる
erlang:now {1449,413599,584682} -> ...
erlang:now {1449,413599,584683} -> ...
erlang:now {1449,413599,584684} -> ...
erlang:now {1449,413599,584685} -> ...
erlang:now {1449,413599,584686} -> ...
たしかにこれでは使えない
タイムワープモードを multi_time_warp
にしたところ、erlang:now/0
では要件1が「ある程度」満たせるようになりましたが、それと引き換えに要件2が満たせなくなりました。
| 要件 | 満たせる? | 説明
:-:|:-----------------|:----------|:-----------------------------------
1 | 現在時刻を正確に得られる | 進ませた時は満たせる、 遅らせた時は満たせない | 遅らせた時は、システムクロックが追いついてくるまで、ほぼ同じ時刻を返し続ける(呼ぶ毎に1マイクロ秒だけ進むが)
2 | 経過時間を正確に測定できる | 満たせない | 進ませた時は進んだ分だけの時間が経過時間に上乗せされる。遅らせた時は、経過時間がほば0になる
3 | ユニークな数値を得られる | 満たせる |
スケーラビリティーも阻害される
実験1、実験2共に、要件3は常に満たされていました。erlang:now/0
をユニークな値の生成に使っているアプリケーションが多数存在するため、ここだけはどうしても満たさないといけません。一方、このことがアプリケーションの性能(スケーラビリティー)を阻害する要因にもなっています。
erlang:now/0
が複数の Erlang 軽量プロセスから同時に呼ばれた場合でも、タイムスタンプが strictly monotonically increasing number であることを保証しなければなりません。そのためには、ロックを導入して、複数の呼び出しを、順番に処理することになります。もし、たくさんの軽量プロセスから同時に呼び出されたら、この逐次処理が性能上のボトルネックになってしまいます。
もし用途が1の現在時刻とか2の経過時間だったとき、性能を犠牲にしてまで strictly monotonically increasing number を保証しても、無駄に終わってしまいます。
新しい API では経過時間と現在時刻を別管理
新しい API では、multi_time_warp
の時に、3つの要件が同時に満たせるようになっています。そのために、まず「経過時間」と「現在時刻」を別に管理するようになりました。前者を「Erlang monotonic time」、後者を「Erlang システムタイム」と呼びます。
経過時間:Erlang Monotonic Time
erlang:monotonic_time/0
と erlang:monotonic_time/1
は経過時間を返し、その値は monotonically increasing number(広義の単調増加数)となります。つまり「前回のタイムスタンプ ≦ 今回のタイムスタンプ」であることが保証されています。
ここで erlang:now/0
とは異なり、続けて呼んだ時に、同じタイムスタンプが返る場合があることに注目してください。要件を緩めたことによりロックが不用となり、スケーラビリティーの問題も解決します。
erlang:monotonic_time/0
は経過時間を Erlang 実行環境に依存するネイティブの分解能(resolution、または、time unit と呼びます)で返します。erlang:monotonic_time/1
は、ネイティブの time unit を、引数で与えた time unit に変換してから返します。
1> erlang:monotonic_time().
-576460745061874838
2> erlang:monotonic_time(nano_seconds).
-576460739326652626
3> erlang:monotonic_time(micro_seconds).
-576460732117796
4> erlang:monotonic_time(milli_seconds).
-576460727635
5> erlang:monotonic_time(seconds).
-576460724
ネイティブの分解能は erlang:convert_time_unit(1, seconds, native)
で確認できます。
6> erlang:convert_time_unit(1, seconds, native).
1000000000
この例では分解能は10の9乗で、最小単位は1秒 × 10のマイナス9乗、すなわちナノ秒だとわかります。なお分解能(resolution)は、精度(accuracy)とは別物ですので注意してくだい。monotonic time がナノ秒で返されるからといって、ナノ秒のレベルで正確に時を刻んでいるとは限りません。むしろ、そうでないことが普通です。
erlang:monotonic_time/0
の戻り値は整数なので、用途2の経過時間を計るには、単に大きいタイムスタンプから、小さいタイムスタンプを引けばいいです。ネイティブの time unit を使用した場合は、erlang:convert_time_unit/3
で目的の time unit に変換するといいでしょう。
7> Start = erlang:monotonic_time().
-576460698329582382
8> End = erlang:monotonic_time().
-576460692495322130
9> End - Start.
5834260252
10> erlang:convert_time_unit(End - Start, native, milli_seconds).
5834
なお、ある Erlang 実行環境で取得した monotonic time を、他の Erlang 実行環境で取得したそれと、前後の比較をすることはできません。monotonic time は「ある任意の時点」からの経過時間を表しているだけで、その起点がいつなのかは個々の実行環境に依存します。実行環境間でタイムスタンプの前後比較をしたいときは、次の項で紹介するオフセットを取得して、monotonic time から実際の時刻に変換する必要があります。
Erlang monotonic time はタイムワープの影響を受けません。OS のシステムクロックが変更されても、その影響を受けず、単調に増加し続けます。このことが、新しい API の重要なポイントとなります。
Erlang Monotonic Time から Erlang システムタイムへのオフセット
Erlang システムタイムは実際の時刻を表し、タイムワープの対象となります。multi_time_warp
モードの時に、OS のシステムクロックが過去や未来へ変更されたら、Erlang システムタイムも同じように変更されます。
erlang:time_offset/0
と erlang:time_offset/1
は Erlang monotonic time から Erlang システムタイムへのオフセットを返します。つまり erlang:monotonic_time/0
が返した値に、erlang:time_offset/0
が返した値を足すと、要件1の現在時刻(Erlang システムタイム、UNIX エポックからの経過時間)が、ネイティブの time unit で求められます。
このように書くと、Erlang 実行環境の中に monotonic time を実現するエンジンと、システムタイムを実現するエンジンの、2つのエンジンが入っているように思えますが、後者はあくまでも概念上のもので、コードで実装されているわけではありません。Erlang 実行環境に実装されているのは、monotonic time を刻み続けるエンジンと、この time offset だけです。
11> MT = erlang:monotonic_time().
-576460636631757928
12> OS = erlang:time_offset().
2025874384294795734
13> MT + OS.
1449413747663037806
14> erlang:convert_time_unit(MT + OS, native, milli_seconds).
1449413747663
この操作を合成した erlang:system_time/0
と erlang:system_time/1
も用意されているので、普段はそちらを使うことになるでしょう。また、さらにこれを erlang:now/0
形式のタイムスタンプに変換してから返す erlang:timestamp/0
もあります。
15> erlang:system_time(milli_seconds).
1449413805302
16> erlang:timestamp().
{1449,413821,303246}
17> calendar:now_to_local_time(erlang:timestamp()).
{{2015,12,6},{22,57,6}}
ただし、erlang:timestamp/0
が返す値はタイムワープの対象となりますので、要件3は満たしません。次の項で紹介する関数を使うことになります。
要件3を満たす専用関数
要件3を満たすために、専用の関数 erlang:unique_integer/0
と erlang:unique_integer/1
が用意されました。
18> erlang:unique_integer().
-576460752303423486
19> erlang:unique_integer().
-576460752303423482
20> erlang:unique_integer([positive]).
11
21> erlang:unique_integer([positive]).
15
22> erlang:unique_integer([positive, monotonic]).
1
23> erlang:unique_integer([positive, monotonic]).
2
24> erlang:unique_integer([positive, monotonic]).
3
erlang:unique_integer/0
はユニークな整数を返すことだけが保証されており、正の整数と負の整数が、その大小に関係なく返されます。オプションとして、positive
を与えると、正の整数だけを返すようになります。monotinic
を与えると、erlang:now/0
のような、「前回の値 < 今回の値」となる整数を返すようになります。
独立した関数にしたことで、システムクロックの影響を受けなくなりました。また、スケーラビリティーを改善するために、様々なテクニックが用いられているようです。
実験3:multi_time_warp
モードで新しい API を試す
新しい API を試してみましょう。動作確認のために、以下の関数を用意しました。
-module(t2).
-compile(export_all).
-spec print_time_otp18() -> ok.
print_time_otp18() ->
OSTS = os:timestamp(),
MT = erlang:monotonic_time(),
TOS = erlang:time_offset(),
LocalTimeOSTS = calendar:now_to_local_time(OSTS),
LocalTimeMT = calendar:now_to_local_time(system_time_to_now(MT + TOS)),
Diff = timer:now_diff(system_time_to_now(MT + TOS), OSTS),
io:format("---------~n"
"os:timestamp ~p -> ~p~n"
"monotonic_time ~w~n"
"time_offset ~w~n"
" -> ~p (~w us)~n",
[OSTS, LocalTimeOSTS,
MT, TOS, LocalTimeMT, Diff]).
-spec repeat_time_otp18() -> timer:tref().
repeat_time_otp18() ->
{ok, TRef} =
timer:apply_interval(1000, ?MODULE, print_time_otp18, []),
TRef.
-spec system_time_to_now(integer()) -> erlang:timestamp().
system_time_to_now(NativeSystemTime) ->
ST = erlang:convert_time_unit(NativeSystemTime, native, micro_seconds),
MegaSecs = ST div 1000000000000,
Secs = ST div 1000000 - MegaSecs * 1000000,
MicroSecs = ST rem 1000000,
{MegaSecs, Secs, MicroSecs}.
system_time_to_now/1
はネイティブ time unit の Erlang システムタイムを erlang:now/0
のタイムスタンプに変換するために作りました。実際の運用では、erlang:monotinic_time/0
と erlang:time_offset/0
を使わずに、erlang:timestamp/0
で一気に求めるほうが楽でしょう。
このモジュールの関数を実行すると、以下のように表示されます。
$ erl +C multi_time_warp
...
1> c(t2).
{ok,t2}
2> t2:print_time_otp18().
---------
os:timestamp {1449,414031,427546} -> {{2015,12,6},{23,0,31}}
monotonic_time -576460700481595263
time_offset 2025874731852149836
-> {{2015,12,6},{23,0,31}} (-56992 us)
ok
3> TR2 = t2:repeat_time_otp18().
{interval,#Ref<0.0.1.97>}
4> ---------
os:timestamp {1449,414049,442162} -> {{2015,12,6},{23,0,49}}
monotonic_time -576460682466981138
time_offset 2025874731909147872
-> {{2015,12,6},{23,0,49}} (4 us)
---------
os:timestamp {1449,414050,447735} -> {{2015,12,6},{23,0,50}}
monotonic_time -576460681461409266
time_offset 2025874731909147872
-> {{2015,12,6},{23,0,50}} (3 us)
時刻を進ませてみる
システムクロックを約1分進めます。
---------
os:timestamp {1449,414061,442729} -> {{2015,12,6},{23,1,1}}
monotonic_time -576460670466414376
time_offset 2025874731909147872
-> {{2015,12,6},{23,1,1}} (4 us)
---------
os:timestamp {1449,414120,165533} -> {{2015,12,6},{23,2,0}} %% <-- 1分進んだ
monotonic_time -576460669467591586
time_offset 2025874731909147872
-> {{2015,12,6},{23,1,2}} (-57723977 us)
---------
os:timestamp {1449,414121,165884} -> {{2015,12,6},{23,2,1}}
monotonic_time -576460668467240566
time_offset 2025874731909147872
-> {{2015,12,6},{23,1,3}} (-57723977 us)
以下のように、40秒ほど経ってから erlang:time_offset/0
が変更され、OS のシステムクロックと同じ時間が得られるようになりました。時刻を進めた時は、要件1の現在時刻の取得が満たされることが確認できました。
---------
os:timestamp {1449,414159,166963} -> {{2015,12,6},{23,2,39}}
monotonic_time -576460630466161469
time_offset 2025874731909147872
-> {{2015,12,6},{23,1,41}} (-57723977 us)
---------
os:timestamp {1449,414160,166153} -> {{2015,12,6},{23,2,40}}
monotonic_time -576460629466971281
time_offset 2025874789633128715 %% <-- 変わった
-> {{2015,12,6},{23,2,40}} (4 us) %% <-- 1分進んだ
---------
os:timestamp {1449,414161,167540} -> {{2015,12,6},{23,2,41}}
monotonic_time -576460628465584511
time_offset 2025874789633128715
-> {{2015,12,6},{23,2,41}} (4 us)
一方で、erlang:monotinic_time/0
はシステムクロック変更の影響を受けず、単調に増加し続けました。
1> erlang:convert_time_unit(-576460629466971281 - -576460630466161469,
1> native, micro_seconds).
999190
これにより要件2の経過時間を計ることも常に満たされます。
時刻を遅らせてみる
今度は時刻を戻します。システムクロックを約1分遅らせました。
---------
os:timestamp {1449,414352,166058} -> {{2015,12,6},{23,5,52}}
monotonic_time -576460437467066070
time_offset 2025874789633128715
-> {{2015,12,6},{23,5,52}} (4 us)
---------
os:timestamp {1449,414353,166167} -> {{2015,12,6},{23,5,53}}
monotonic_time -576460436466957641
time_offset 2025874789633128715
-> {{2015,12,6},{23,5,53}} (4 us)
---------
os:timestamp {1449,414296,450902} -> {{2015,12,6},{23,4,56}} %% <-- 1分遅れた
monotonic_time -576460435467079298
time_offset 2025874789633128715
-> {{2015,12,6},{23,5,54}} (57715147 us)
---------
os:timestamp {1449,414297,451731} -> {{2015,12,6},{23,4,57}}
monotonic_time -576460434466249931
time_offset 2025874789633128715
-> {{2015,12,6},{23,5,55}} (57715147 us)
45秒ほど経ってから、erlang:time_offset/0
にも反映されました。時刻を遅らせた時も、要件1の現在時刻の取得が満たされるようになっています。
---------
os:timestamp {1449,414341,454290} -> {{2015,12,6},{23,5,41}}
monotonic_time -576460390463691730
time_offset 2025874789633128715
-> {{2015,12,6},{23,6,39}} (57715146 us)
---------
os:timestamp {1449,414342,451029} -> {{2015,12,6},{23,5,42}}
monotonic_time -576460389466952117
time_offset 2025874731917985060 %% <-- 変わった
-> {{2015,12,6},{23,5,42}} (3 us) %% <-- 1分遅れた
---------
os:timestamp {1449,414343,450941} -> {{2015,12,6},{23,5,43}}
monotonic_time -576460388467040215
time_offset 2025874731917985060
-> {{2015,12,6},{23,5,43}} (3 us)
やはり erlang:monotinic_time/0
は影響を受けず、単調に増加し続けました。
1> erlang:convert_time_unit(-576460389466952117 - -576460390463691730,
1> native, micro_seconds).
996739
結論
タイムワープモードを multi_time_warp
にして、新しい API を試したところ、要件1と要件2が常に満たされることが確認できました。要件3については実験しませんでしたが、時刻から独立した関数が導入されたため、その効果は明確でしょう。まとめると以下のようになります。
| 要件 | 満たせる? | 説明
:-:|:-----------------|:----------|:-----------------------------------
1 | 現在時刻を正確に得られる | 満たせる | OS のシステムクロックが変更された時は、数十秒以内にオフセットに反映され、正しい時刻が得られる
2 | 経過時間を正確に測定できる | 満たせる | monotonic time はシステムクロックの影響を受けずに単調増加する
3 | ユニークな数値を得られる | 満たせる | 実験では未確認だが、時刻から独立した関数が導入されたため、システムクロックの影響を受けないと考えられる
なお、タイムワープモードがデフォルトの no_time_warp
のままだと、せっかく新しい API を使用しても、Erlang system clock が緩やかに同期されるようになってしまい、要件1が満たせなくなってしまいますので注意してくだい。(no_time_warp
では time offset は変わらずに、monotonic time の進行速度が調整されます)
タイムワープの検出
OTP 18 ではタイムワープが起こった時に、通知を受け取れるようになっています。
$ erl +C multi_time_warp
...
1> erlang:monitor(time_offset, clock_service).
#Ref<0.0.1.416>
2> receive Msg -> Msg end.
システムクロックを約1分進めると...
{'CHANGE',#Ref<0.0.1.416>,time_offset,clock_service,
2025874833587923080}
新しいオフセット 2025874833587923080
が通知されました。このように、クロックを監視し、タイムワープが起こるごとに新しい オフセットを受け取ることができます。
まとめ
OTP 18 より前のリリースでは erlang:now/0
に3つの要件が求められていたため、タイムワープを起こすとアプリケーション(および、OTP自体)が正常に動作しなくなる可能性がありました。そのため、Erlang 実行環境は、OS のシステムクロックが変更された時に、そのことをアプリケーションに隠しながら、正しい時刻へ緩やかに同期する仕組みになっていました。タイムワープが起こらないことにより、アプリケーションのロジックは簡略化されたかもしれませんが、一方で、ずれた時間が戻るまで、長い時間が(場合によっては何年間も)かかるという問題がありました。また、erlang:now/0
は内部でロックを使用しているため、スケーラビリティーの問題もありました。
OTP 18 では新しい時刻関連 API とタイムワープモードを導入したことによって、タイムワープが起こった時でも、3つの要件を満たしたまま、アプリケーション側で適切な対応ができるようになりました。Erlang 実行環境は、システムクロックの変更を隠すのではなく、アプリケーションに即座に通知して対応を委ねます。これによりアプリケーションのロジックは複雑になるかもしれませんが、ほとんどの場合、要件に即した、より堅牢なものになると期待されます。
「Erlang Run-Time System Application(ERTS) User's Guide」の「Time and Time Correction in Erlang」では、新しい API への切り替え方法を、以下のような具体例を挙げて解説しています。ぜひ一度、読んでみてください。
- Retrieve Erlang System Time(Erlang システムタイムを取得する)
- Measure Elapsed Time(経過時間を測定する)
- Determine Order of Events(イベントが発生した順序を決定する)
- Determine Order of Events With Time of the Event(イベントが発生した時刻を元に、その順序を決定する)
- Create a Unique Name(ユニークな名前を生成する)
- Seed Random Number Generation With a Unique Value(乱数生成器にユニークなシード値を与える)
最後の例は、random
モジュールが想定されていますが、そういう書き換えをするよりも、新たに導入された rand
モジュールに切り替えることが絶対お勧めです。
また、Time and Time Correction in Erlang では、もうひとつのタイムワープモード single_time_warp
についても解説されています。こちらは、既存のアプリケーションをほとんど変更せず IoT デバイスに対応させたい時などに役立ちそうです。