localtime() takes 24 times more than gmtime() performance issue on linux

Question

Due to performance issues on a project I made the following test program (even used different variables for sanity check):

int main()
{

struct tm *timeinfo;
time_t rawtime;
clock_t begin, end, begin1, end1,begin2,end2;
double time_spent;

begin = clock();

for (int i = 0; i < 1000000; i++){
    time ( &rawtime );
    timeinfo = localtime(&rawtime);
}

end = clock();
time_spent = (double)(end - begin) / CLOCKS_PER_SEC;
printf("Time elapsed using localtime()      : %fs\n", time_spent);    
//--------------------------------

begin1 = clock();

for (int i = 0; i < 1000000; i++){
    time ( &rawtime );
    timeinfo = gmtime(&rawtime);
}

end1 = clock();
time_spent = (double)(end1 - begin1) / CLOCKS_PER_SEC;
printf("Time elapsed using gmtime()         : %fs\n", time_spent);           
//--------------------------------

begin2 = clock();

for (int i = 0; i < 1000000; i++){
    time ( &rawtime );
    localtime_r( &rawtime, timeinfo);
}

end2 = clock();
time_spent = (double)(end2 - begin2) / CLOCKS_PER_SEC;
printf("Time elapsed using localtime_r()    : %fs\n", time_spent);


return 0;
}

The results I get are very strange, localtime takes ~24 times more time, the localtime_r() function seems to take less than localtime(), but still a lot more than gmtime():

Time elapsed using localtime()      : 0.958033s
Time elapsed using gmtime()         : 0.038769s
Time elapsed using localtime_r()    : 0.860276s

I've compiled it with gcc 5 as well as 4.x version, I've used linux Mint (updated to this day) and CentOS5. Also it's been tested on different physical machines and the performance difference is similar.

Why is there such a (huge) performance difference?

Answer 1

If you run this code under perf record and then do perf report you will notice that localtime calls getenv("TZ") on each iteration. Whereas gmtime does not.

Looking into the source code of glibc confirms the callgraphs:

gmtime
    __tz_convert(, 0, )
       tzset_internal(0, 1)
mktime
    __tz_convert(, 1, )
       tzset_internal(1, 1)
           getenv("TZ")

See glibc source code of localtime, gmtime and __tz_convert.

perf report:

Samples: 78K of event 'cycles:u', Event count (approx.): 21051445406
  Children      Self       Samples  Command  Shared Object      Symbol                          ▒
+   99.48%     0.59%           349  test     test               [.] main                        ▒
+   99.48%     0.00%             0  test     libc-2.23.so       [.] __libc_start_main           ▒
+   99.48%     0.00%             0  test     test               [.] _start                      ▒
+   98.02%     7.07%          4208  test     libc-2.23.so       [.] __tz_convert                ◆
-   24.51%    23.87%         20812  test     libc-2.23.so       [.] getenv                      ▒
   - 23.87% _start                                                                              ▒
        __libc_start_main                                                                       ▒
        main                                                                                    ▒
        __tz_convert                                                                            ▒
        getenv                                                                                  ▒
   + 0.64% getenv                                                                               ▒
+   22.41%    12.75%          9877  test     libc-2.23.so       [.] __tzfile_compute            ▒
+   15.49%    15.49%          8025  test     libc-2.23.so       [.] __offtime                   ▒
+   12.72%     6.28%          5476  test     libc-2.23.so       [.] __tzfile_read               ▒
+    9.66%     3.54%          3086  test     libc-2.23.so       [.] __tzstring                  ▒
+    8.36%     1.40%          1221  test     libc-2.23.so       [.] __strdup                    ▒
+    7.68%     3.38%          2946  test     libc-2.23.so       [.] free                        ▒
+    5.98%     3.07%          2682  test     libc-2.23.so       [.] malloc                      ▒
+    4.96%     0.68%           611  test     libc-2.23.so       [.] __xstat64                   ▒
+    4.30%     4.30%          3750  test     libc-2.23.so       [.] _int_free                   ▒
+    4.28%     4.28%          3731  test     [kernel.kallsyms]  [k] entry_SYSCALL_64            ▒
+    4.08%     4.08%          3564  test     libc-2.23.so       [.] strlen                      ▒
+    3.64%     3.64%          3168  test     libc-2.23.so       [.] __memcmp_sse2               ▒
+    2.91%     2.91%          2561  test     libc-2.23.so       [.] _int_malloc                 ▒
+    1.25%     1.25%          1094  test     libc-2.23.so       [.] __memcpy_sse2               ▒
+    0.68%     0.68%           587  test     libc-2.23.so       [.] localtime                   ▒
     0.26%     0.26%           222  test     libc-2.23.so       [.] 0x000000000001f910          ▒
     0.18%     0.18%            37  test     test               [.] gmtime@plt                  ▒
     0.15%     0.15%           126  test     test               [.] localtime@plt               ▒
     0.11%     0.11%            23  test     libc-2.23.so       [.] gmtime                      ▒
     0.01%     0.01%             6  test     [kernel.kallsyms]  [k] __irqentry_text_start       ▒
     0.00%     0.00%             3  test     ld-2.23.so         [.] _dl_lookup_symbol_x         ▒
     0.00%     0.00%             5  test     ld-2.23.so         [.] do_lookup_x                 ▒
     0.00%     0.00%             2  test     ld-2.23.so         [.] _dl_relocate_object         ▒
     0.00%     0.00%             1  test     libc-2.23.so       [.] 0x000000000001f8e8          ▒
     0.00%     0.00%             1  test     ld-2.23.so         [.] strlen                      ▒
     0.00%     0.00%             1  test     ld-2.23.so         [.] _dl_debug_initialize        ▒
     0.00%     0.00%             1  test     ld-2.23.so         [.] _dl_start                   ▒
     0.00%     0.00%             1  test     [kernel.kallsyms]  [k] page_fault                  ▒
     0.00%     0.00%             6  test     ld-2.23.so         [.] _start     

Answer 2

Parts of the work of localtime and gmtime are cached.

So only the first call to one of these functions does the real work, i.e. read /etc/localtime to get the local timezone. This action is performed also for gmtime(), even if it might not be necessary.

To get reliable results place a call to gmtime or localtime before the first measuring. The performance of both functions should be similar then.