localtime_r multiple times slower for Europe/Moscow timezone

[Dmitry Nesterov]

In version tzdata-2011j (tzdata-2011k also affected) was founded strange bug in russian timezones.
Because of a law "On the Calculation of Time" there were changes in zone like:
3:00 Russia MSK/MSD 2011
changed to:
3:00 Russia MSK/MSD 2011 Mar 27 2:00s
4:00 - MSK
But if no rule used for this change (using "-" instead of rule "Russia"), calling of system function localtime_r() takes more time (takes more than 40% time longer).
I used following code for measuring:
==============================
#include <time.h>
#include <stdio.h>

int main() {
  time_t t = time(0);
  int i;
  struct tm result;
  for(i=0; i < 10000000; i++)
    localtime_r(&t, &result);
  puts(ctime(&t));
  return 0;
}
==============================
and also this sql code in mysql db:
select benchmark(1000000, from_unixtime(1317044847));
For example, when I'm using new tzdata-2011j results are:
1. time ./a.out (c code)
real 0m5.165s
user 0m5.140s
sys 0m0.000s
2. sql query
mysql> select benchmark(1000000, from_unixtime(1317044847));
+-----------------------------------------------+
| benchmark(1000000, from_unixtime(1317044847)) |
+-----------------------------------------------+
| 0 |
+-----------------------------------------------+
1 row in set (1.03 sec).
And when I'm using old tzdata-2008b:
1. time ./a.out (c code)
real 0m1.675s
user 0m1.450s
sys 0m0.000s
2. sql query
mysql> select benchmark(1000000, from_unixtime(1317044847));
+-----------------------------------------------+
| benchmark(1000000, from_unixtime(1317044847)) |
+-----------------------------------------------+
| 0 |
+-----------------------------------------------+
1 row in set (0.65 sec)

This bug seemed critical on high loaded systems (for example, for databases that using unix timestamps).

My configuration was:
Description: Ubuntu 8.04.1
Release: 8.04
Packages: 2011j~repack-0ubuntu0.8.04 and 2008b-1ubuntu1

[Ubuntu Foundations Team Bug Bot (crichton)]

The attachment "Difference that makes 2011 work better" of this bug report has been identified as being a patch. The ubuntu-reviewers team has been subscribed to the bug report so that they can review the patch. In the event that this is in fact not a patch you can resolve this situation by removing the tag 'patch' from the bug report and editing the attachment so that it is not flagged as a patch. Additionally, if you are member of the ubuntu-sponsors please also unsubscribe the team from this bug report.

[This is an automated message performed by a Launchpad user owned by Brian Murray. Please contact him regarding any issues with the action taken in this bug report.]

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Dmitry Nesterov (keyd)]

We have found that this bug occurs because of bug in glibc.
Version of glibc used: 2.7-10ubuntu3

The problem is that glibc uses function __tzfile_compute() if no rules are present in compiled binary zone file (usually, /etc/localtime).
If that occurs we may see while profiling (bad case):
samples % image name app name symbol name
63893 44.1876 libc-2.13.so libc-2.13.so _IO_vfscanf <-- this one
15824 10.9437 libc-2.13.so libc-2.13.so __offtime
7527 5.2056 libc-2.13.so libc-2.13.so __tzset_parse_tz
6295 4.3535 libc-2.13.so libc-2.13.so __strcmp_sse2
4781 3.3065 no-vmlinux no-vmlinux /no-vmlinux
4484 3.1011 libxul.so libxul.so /opt/firefox/libxul.so
3799 2.6273 libc-2.13.so libc-2.13.so ____strtoull_l_internal
3309 2.2885 libc-2.13.so libc-2.13.so compute_change
2803 1.9385 libc-2.13.so libc-2.13.so _IO_old_init
2317 1.6024 libc-2.13.so libc-2.13.so __tz_compute
2312 1.5989 libc-2.13.so libc-2.13.so _IO_str_init_static_internal
2225 1.5388 libc-2.13.so libc-2.13.so __tzfile_compute

When rules are present in compiled binary zone we have (good case):
samples % image name app name symbol name
15592 25.2322 libc-2.13.so libc-2.13.so __strcmp_sse2
10024 16.2216 no-vmlinux no-vmlinux /no-vmlinux
6336 10.2534 libc-2.13.so libc-2.13.so __offtime
5398 8.7355 libc-2.13.so libc-2.13.so __tzfile_compute
4961 8.0283 libc-2.13.so libc-2.13.so __tzstring
1361 2.2025 libc-2.13.so libc-2.13.so __tz_convert
1240 2.0067 libc-2.13.so libc-2.13.so __strlen_sse2
455 0.7363 test test main
253 0.4094 libc-2.13.so libc-2.13.so tzset_internal

[Qd-feng (qd-feng)]

There is one thread in our application frequently call the localtime_r. We found the thread performance has 20% drop when change the timezone from the America/New_york to Asia/Shanghai from the system(Redhat 6,). After profile, we found it is the localtime_r cause the difference.

When set the timezone as America/New_york, the __tzfile_compute mainly call the __tzstring. While when set the timezone as the Asia/Shanghai the __tzfile_compute call the __tzset_parse_tz which consume most of the CPU time.

I also do an simple test on our HP G8 server.

  1 #include <time.h>
  2 #include <stdio.h>
  3
  4 int main(void)
  5 {
  6 struct tm newtime;
  7 time_t ltime;
  8 char buf[50];
  9
 10 for(int i=0;i<=1000000;i++)
 11 {
 12 ltime=time(&ltime);
 13
 14 localtime_r(&ltime, &newtime);
 15 }
 16 }

After compile and run command time ./a.out with the timezone as Asia/Shanghai or
America/New_York.
Asia/Shanghai
real 0m1.838s
user 0m1.628s
sys 0m0.206s

America/New_York
real 0m0.608s
user 0m0.395s
sys 0m0.211s

There is no TZ env been set on both cases. I wonder what causes the performance so difference, is it an designed behavior?

Steven

[Andreas Schwab (schwab-linux-m68k)]

How do you set the timezone?

[Qd-feng (qd-feng)]

link the /etc/localtime to time zone under usr/share/zoneinfo/
e.g.
ln -sf /usr/share/zoneinfo/America/New_York /etc/localtime

[Dmitry Nesterov (keyd)]

Year 2014. Bug is still here.

Buggy version:
keyd@keyd-desktop:~$ dpkg -l | grep tzdata
ii tzdata 2014i-0ubuntu0.12.04 time zone and daylight-saving time data
ii tzdata-java 2014i-0ubuntu0.12.04 time zone and daylight-saving time data for use by java runtimes
keyd@keyd-desktop:~$ time ./a.out
Mon Oct 27 16:46:13 2014
real 0m4.061s
user 0m4.048s
sys 0m0.000s
keyd@keyd-desktop:~$

Patched version:
keyd@keyd-desktop:~$ dpkg -l | grep tzdata
ii tzdata 2014i-0ubuntu0.12.04-yandex1 time zone and daylight-saving time data
ii tzdata-java 2014i-0ubuntu0.12.04-yandex1 time zone and daylight-saving time data for use by java runtimes
keyd@keyd-desktop:~$ time ./a.out
Mon Oct 27 16:47:58 2014
real 0m1.263s
user 0m1.256s
sys 0m0.000s
keyd@keyd-desktop:~$

[Dmitry Nesterov (keyd)]

2016b. Long live to the bug!

Buggy:
$ dpkg -l | grep tzdata
ii tzdata 2016b-0ubuntu0.12.04 time zone and daylight-saving time data
ii tzdata-java 2016b-0ubuntu0.12.04 time zone and daylight-saving time data for use by java runtimes
$ cat ./bug.c
#include <time.h>
#include <stdio.h>

int main() {
 time_t t = time(0);
 int i;
 struct tm result;
 for(i=0; i < 10000000; i++)
  localtime_r(&t, &result);
 puts(ctime(&t));
 return 0;
}
$ gcc ./bug.c
$ time ./a.out
Mon Mar 21 23:56:11 2016

real 0m4.607s
user 0m4.599s
sys 0m0.002s
$

Patched:
$ dpkg -l | grep tzdata
ii tzdata 2016b-0ubuntu0.12.04-yandex1 time zone and daylight-saving time data
ii tzdata-java 2016b-0ubuntu0.12.04-yandex1 time zone and daylight-saving time data for use by java runtimes
$ cat ./bug.c
#include <time.h>
#include <stdio.h>

int main() {
 time_t t = time(0);
 int i;
 struct tm result;
 for(i=0; i < 10000000; i++)
  localtime_r(&t, &result);
 puts(ctime(&t));
 return 0;
}
$ gcc ./bug.c
$ time ./a.out
Mon Mar 21 23:58:19 2016

real 0m1.296s
user 0m1.292s
sys 0m0.002s
$

[Anat-mazurov (anat-mazurov)]

Please, have a look at this thread: https://bugs.launchpad.net/ubuntu/+source/tzdata/+bug/868395

Don't know if it's the same bug, but seems to be very similar.

There is a workaround that involves patching tzdata package (comment #6), which helped in that case with Russian timezones, and maybe will do for you. But I really think that fixing glibc is a correct way to resolve the problem, as it significantly affects performance under some workloads.

Also there is some technical info mentioned in comment #4 that may help in resolving this bug.

[Andreas Schwab (schwab-linux-m68k)]

The difference between America/New_York and Asia/Shanghai is that the former has transitions until far in the future, whereas the last transition of the latter was 1991, and later timestamps are computed from the embedded POSIX TZ string.

[Benjamin Drung (bdrung)]

I can reproduce this slowdown in a Ubuntu jammy chroot:

```
apt install -y gcc tzdata
printf '#include <time.h>\n#include <stdio.h>\n\nint main() {\n time_t t = time(0);\n int i;\n struct tm result;\n for(i=0; i < 10000000; i++)\n localtime_r(&t, &result);\n puts(ctime(&t));\n return 0;\n}\n' > bug.c
gcc ./bug.c
time ./a.out
ln -sf /usr/share/zoneinfo/Europe/Moscow /etc/localtime
dpkg-reconfigure --frontend noninteractive tzdata
time ./a.out
```

On my machine it takes 0.284s for Etc/UTC but 1.276s for Europe/Moscow. Europe/Berlin takes 0.378s. This needs to be reported upstream.

[Benjamin Drung (bdrung)]

Can be reproduces with just setting the TZ environment variable:

```
apt install -y gcc tzdata
printf '#include <time.h>\n#include <stdio.h>\n\nint main() {\n time_t t = time(0);\n int i;\n struct tm result;\n for(i=0; i < 10000000; i++)\n localtime_r(&t, &result);\n puts(ctime(&t));\n return 0;\n}\n' > bug.c
gcc -o bug ./bug.c
time ./bug
time TZ=Europe/Moscow ./bug
```

[Benjamin Drung (bdrung)]

Forwarded to the upstream mailing list: https://mm.icann.org/pipermail/tz/2023-January/032522.html

[Guy Harris (guyharris)]

Not just Russia - on 22.04:

$ time TZ=Etc/UTC ./bug
Tue Jan 10 23:46:13 2023

real 0m0.537s
user 0m0.529s
sys 0m0.004s
$ time TZ=Europe/Berlin ./bug
Wed Jan 11 00:46:31 2023

real 0m0.677s
user 0m0.670s
sys 0m0.004s
$ time TZ=Europe/Moscow ./bug
Wed Jan 11 02:46:50 2023

real 0m1.908s
user 0m1.902s
sys 0m0.000s
$ time TZ=America/Los_Angeles ./bug
Tue Jan 10 15:55:52 2023

real 0m0.673s
user 0m0.663s
sys 0m0.004s
$ time TZ=Asia/Tokyo ./bug
Wed Jan 11 08:58:32 2023

real 0m1.807s
user 0m1.795s
sys 0m0.005s

[Guy Harris (guyharris)]

See https://sourceware.org/bugzilla/show_bug.cgi?id=15943.

[Paul Eggert (eggert-cs)]

This glibc performance bug came up recently on the tz mailing list; see the thread "[tz] localtime_r multiple times slower for Europe/Moscow timezone" starting here:

https://mm.icann.org/pipermail/tz/2023-January/032522.html

That thread stems from the following Ubuntu bug report:

https://bugs.launchpad.net/ubuntu/+source/tzdata/+bug/868395

Guy Harris diagnosed the problem as glibc not properly caching the expansion of the TZ string at the end of the TZif file. See:

https://mm.icann.org/pipermail/tz/2023-January/032529.html

This problem has grown in importance as many jurisdictions are now like Moscow, as they formerly had daylight saving but now no longer do. So this performance bug is more important now than it was years ago.

[Guy Harris (guyharris)]

Most if not all of China and India are also now no longer on DST, which is why it happens with Asia/Shanghai.