TL;DR
『環境変数を設定するだけでRuby on Railsサーバが10%高速化する(かもしれない)話』 でRailsを高速化させる素晴らしいハックが紹介されましたが。いまや有効なハックではなくなりました。
TZハックさん、ながい間(2日間)おつかれさまでした。
はじめに
アカツキさまで技術顧問をさせていただいている小崎です。
このエントリは『環境変数を設定するだけでRuby on Railsサーバが10%高速化する(かもしれない)話』をRubyコミッタが読んだらこうなったというアンサーソングになっています。合わせてお読みください
TZ環境変数でTime.newが10倍近く速くなるのは素晴らしい発見ですが、コミッタとしてはTZなしでも速くなって欲しいなと思いました。だってめんどうだし。
現状分析
まず問題のテストプログラムを軽く分析してみましょう
% strace -c ruby ../t.rb % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 99.86 4.248080 11 400076 1 stat 0.03 0.001304 3 458 319 openat 0.02 0.000786 2 362 7 lstat 0.02 0.000682 4 184 read 0.01 0.000407 3 141 close 0.01 0.000390 11 34 mmap ...
Time.new 10万回に対し、statが40万回、つまりTime.new1回あたり4回のstatが呼ばれていることが分かります。
ltraceでも確認してみます
% ltrace -c ./miniruby ../t.rb % time seconds usecs/call calls function ------ ----------- ----------- --------- -------------------- 30.97 47.608101 158 300000 tzset 25.24 38.804739 129 300000 localtime_r 16.28 25.027547 120 207016 malloc_usable_size 10.51 16.163021 161 100000 mktime 8.31 12.781192 123 103912 calloc 8.26 12.698693 123 103204 strlen 0.18 0.282174 77 3645 memcpy 0.13 0.204240 76 2674 malloc 0.08 0.129064 80 1601 memcmp ..
おや?tzset(), lcoaltime_r() 呼び出しが30万回しか呼ばれておらず数が合いません。
が、よく訓練された低レイヤー開発者は glibcの__tzfile_read() が呼ばれるのはtzset(3)が呼ばれたときだけだけども、tzset(3)はmktimeが呼ばれたときにも内部的に呼ばれていることを知っています。
つまり、Time.newするたびに、tzsetを3回、mktimeを1回呼んでおり、それがstat 4回につながります。
だいたい計算があってきました。
余談
tzset()とはTZ環境変数にもとづいてlibcのタイムゾーン初期化する関数ですが、TZ環境変数が未設定の場合は処理系依存です。
glibcの場合は /etc/localtimeのファイルに従いタイムゾーン情報を使って初期化します(まあ妥当ですよね)。ところがお節介なことに、glibcは /etc/localtime があとから変更された場合に備え、tzset()が呼ばれるたびに、 /etc/localtimeをstatして変更がないかチェックし、変更があれば再初期化するという実装になっています。
ほとんど使い道のないお節介のために遅くなっているのですから、余計なことをしてくれたものです。
localtime_r 問題(すでに解決済みでした)
さて、Rubyのtime.c をみると
#define LOCALTIME(tm, result) (tzset(),rb_localtime_r((tm), &(result)))
のような行があり、ようするに localtime_r()を呼ぶときには毎回 tzset()を呼んでいることがわかります。
これはlibcのマニュアルの
https://linuxjm.osdn.jp/html/LDP_man-pages/man3/ctime.3.html
POSIX.1-2004 によると、 localtime() はあたかも tzset(3) が呼ばれたかのように振舞うことが要求されているが、 localtime_r() にはこの要件はない。 移植性が必要なコードでは、 localtime_r() の前に tzset(3) を呼び出しておくべきである。
の記述に従っているためです。
・・・・と言いたいところですが、別に毎回呼べとは書いてありませんね。最初に一回だけ呼べばいいのでは?
とここまで調べたところで、実はこの問題はRuby 2.6で解決済みであったことに気がつきます。一番悔しいパターンです。元blogにあわせて Ruby 2.5で調査していたための不覚でした。
修正は以下のコミットです。
commit 4bc16691279e98ecdb3e19ff23902be671d46307 Author: nobu <nobu@b2dd03c8-39d4-4d8f-98ff-823fe69b080e> Date: Wed Jul 18 10:30:41 2018 +0000 reduce tzset * time.c (rb_localtime_r): call tzset() only after TZ environment variable is changed.
ところで、さきほどの localtime_r の man を注意深く読まれた読者は、あれ? localtime_r も tzset()を内部的に呼びだすっぽいこと書いてあるけど?と思うかもしれません。賢いですね。
関数 localtime() は、カレンダー時刻 timep を ユーザーが指定したタイムゾーンでの時刻要素別の表現へ変換する。 この関数は tzset(3) を呼び出したかのように振舞い、 大域変数 tzname に現在のタイムゾーンの情報を設定する。 また、timezone に協定世界時 (UTC) とローカル標準時との 時差の秒数を設定し、 一年の一部で夏時間が適用される場合は daylight に 0 が設定される。 返り値は静的に確保された構造体を指しており、この後で 日付や時刻に関する関数のいずれかが呼び出されると 上書きされる可能性がある。 localtime_r() も同様だが、 データはユーザーが用意した構造体に格納される。 この関数は tzname, timezone, and daylight を設定する必要はない。
実は glibc は localtime() は毎回 tzset() を呼び出すが、localtime_r() は最初の1回だけtzset() を呼び出すという最適化をしています。
具体的には glibcのソースコード中の time/tzset.c の以下のあたりで切り分けています。
tzset_internal()の引数が0になると最初の一回のみ初期化という意味、tp == &_tmbuf はlocaltime()のとき1、 use_localtime はlocaltime(),localtime_r()どちらでも1です(gmtimeなどのときに0になります)
/* Return the `struct tm' representation of TIMER in the local timezone. Use local time if USE_LOCALTIME is nonzero, UTC otherwise. */ struct tm * __tz_convert (__time64_t timer, int use_localtime, struct tm *tp) { long int leap_correction; int leap_extra_secs; __libc_lock_lock (tzset_lock); /* Update internal database according to current TZ setting. POSIX.1 8.3.7.2 says that localtime_r is not required to set tzname. This is a good idea since this allows at least a bit more parallelism. */ tzset_internal (tp == &_tmbuf && use_localtime);
コメントに理由が書いてありますね。つまり、tzset() で毎回 /etc/localtimeをstatするのはタイムゾーン処理のためで、localtime_r()はタイムゾーンまわりの処理が不要だから、ということのようです。
mktime問題
残った mktime 問題ですが、grepすると呼び出し箇所は簡単に見つかります。
time.c
static const char * find_time_t(struct tm *tptr, int utc_p, time_t *tp) { (snip) #if defined(HAVE_MKTIME) tm0 = *tptr; if (!utc_p && (guess = mktime(&tm0)) != -1) { tm = GUESS(&guess); if (tm && tmcmp(tptr, tm) == 0) { goto found; } } #endif
これはラッキーです。mktime() があれば使うが、なければないで特に困らないという実装になっています。このような実装になっている理由については
『APIデザインケーススタディ ~Rubyの実例から学ぶ。問題に即したデザインと普遍の考え方』
という本に解説があるので興味がある人は一読するといいと思います。このケースに限らずRubyのいろいろなAPIデザインの知見がつまったとてもいい本です。
要約すると mktime() があれば使うが、なかったり信用できなかったりした場合は、64bit integerの全空間を二分探索でlocaltime_r() を使って力業で探索するということです。
ふつうに考えれば、前者のほうが明らかに速いのですが、今回我々は、mktimeは毎回tzset() を呼ぶが、localtime_r () は最初の一回のみ tzset() を呼ぶ。そして tzset() はとても遅い、ということを学びました。
つまり、毎回力業探索をしたほうが速いと言うことは十分ありえるとことです。やってみましょう!
結果測定
t = Time.now; 100000.times { Time.new(2019) }; Time.now - t
のケースで
Ruby 2.6: 0.387sec
Ruby 2.6 + TZ環境変数: 0.197sec
Ruby 2.7開発ツリー: 0.162sec
Ruby 2.7開発ツリー+TZ環境変数: 0.165sec
と約2倍の高速化を達成し、かつTZ環境変数ありなしで速度が同等になりました。
さらに検討をすすめる
じゃあ、削ろうかなと準備していたところに、オリジナル作者のakrさんから
mktime が tzset する副作用は意図して使っていたわけじゃないけど、ユーザから見ると /etc/localtime の変化に自動的に追従する挙動を提供していたと思う。
追従しない挙動に変えるのなら、代替手段が存在した方が説明しやすいと思う。
誰も気にしない可能性もあるけど。
というコメントをいただきました。その後しばらくコミッタ同士で議論して、
ENV['TZ'] = nil
したら、次のTime.newはtzsetを呼びなおすという挙動にすることにしました。これはRuby 2.6でのlocaltime_rの高速化をした
commit 4bc16691279e98ecdb3e19ff23902be671d46307 Author: nobu <nobu@b2dd03c8-39d4-4d8f-98ff-823fe69b080e> Date: Wed Jul 18 10:30:41 2018 +0000 reduce tzset * time.c (rb_localtime_r): call tzset() only after TZ environment variable is changed.
において、TZ環境変数を設定したらtzset()を呼びなおすという実装がすでに入っていたため、それを素直に拡張して、ENV['TZ'] = nil のときは元々nilだったとしてtzset()をしなおす(/etc/localtimeが変更されていればtimezoneは変わる)という挙動にしました。
まとめ
今回議論した mktime削除パッチは
https://github.com/ruby/ruby/commit/4d7a6d04b2c71aabb9d6e619f4405887806a5be8
としてコミット済みのため、とくに問題なければRuby 2.7に含まれるはずです。
よって要約すると
- Ruby 2.6ではTime.newが3倍ぐらい速くなった
- Ruby 2.7ではさらに2倍ぐらい速くなる(予定)
- そのため、2.7以降では、TZ環境変数を設定する必要はまったくない
ということになります。
アカツキさまのおかげで全世界のRailsアプリが高速化されました。このような改善につながるバグ報告は大変ありがたく、とても素晴らしい貢献だと思います。