とあるプログラムのパフォーマンス測定をしていたら、 localtime() 関数の処理で予想外に時間がかかっていることが判明しました。
そこで、 localtime() 、 localtime_r() 、 gmtime() の３つについて、どれくらいの時間がかかっているのかを簡単に計測してみました。
$ gcc -Wall -O3 -x c - << "EOF"
#include <stdio.h>
#include <time.h>
int main(int argc, char *argv[])
{
int i;
time_t now = time(NULL);
struct tm tm0 = { };
struct tm *tm;
if (argc == 3)
for (i = 0; i < 100000000; i++)
tm = gmtime(&now);
else if (argc == 2)
for (i = 0; i < 100000000; i++)
tm = localtime_r(&now, &tm0);
else
for (i = 0; i < 100000000; i++)
tm = localtime(&now);
printf("%04u/%02u/%02u %02u:%02u:%02u\n",
tm->tm_year + 1900, tm->tm_mon + 1, tm->tm_mday, tm->tm_hour,
tm->tm_min, tm->tm_sec);
return 0;
}
EOF
|
| localtime() | localtime_r() | gmtime() |
|---|---|---|
| $ time ./a.out | $ time ./a.out 1 | $ time ./a.out 1 2 |
仮想化環境での簡単な計測なのであまり正確ではありませんが、確実に localtime() 関数は gmtime() 関数と比べて遅いようです。
| localtime() | localtime_r() | gmtime() |
|---|---|---|
| real 2m6.615s user 0m51.170s sys 1m15.550s |
real 0m38.278s user 0m38.309s sys 0m0.000s |
real 0m3.995s user 0m3.994s sys 0m0.002s |
この原因は、 localtime() 関数は呼び出しの度に、 /etc/localtime の内容が変化していないかどうかを確認するために stat() システムコールを発行しているためです。
CentOS 7 では /etc/localtime が ../usr/share/zoneinfo/Asia/Tokyo へのシンボリックリンクとなっているため、 stat() システムコールでの無駄を減らすために、 /etc/localtime を /usr/share/zoneinfo/Asia/Tokyo のコピーに置き換えて実験してみました。シンボリックリンクを辿らないで済む効果はあるようです。
| localtime() | localtime_r() | gmtime() |
|---|---|---|
| real 1m22.785s user 0m52.446s sys 0m30.407s |
real 0m37.940s user 0m37.970s sys 0m0.000s |
real 0m3.951s user 0m3.954s sys 0m0.000s |
次に、環境変数 TZ で zoneinfo ファイルの場所を指定（ export TZ=:Asia/Tokyo ）して実験してみました。すると、 stat() システムコールが発行されなくなくなった分、 localtime() 関数が速くなりました。
| localtime() | localtime_r() | gmtime() |
|---|---|---|
| real 0m39.887s user 0m39.919s sys 0m0.002s |
real 0m37.597s user 0m37.629s sys 0m0.000s |
real 0m3.970s user 0m3.971s sys 0m0.002s |
次に、環境変数 TZ でタイムゾーン情報を指定（ export TZ=JST-9 ）して実験してみました。すると、 localtime_r() 関数が gmtime() 関数と同じレベルまで速くなりました。
| localtime() | localtime_r() | gmtime() |
|---|---|---|
| real 0m8.735s user 0m8.740s sys 0m0.003s |
real 0m6.733s user 0m6.738s sys 0m0.000s |
real 0m6.647s user 0m6.651s sys 0m0.001s |
でも、ちょっと不思議なことが起きてますよね？何故か、 gmtime() 関数は環境変数 TZ にタイムゾーン情報が指定されていると遅くなってしまうようです。