'How to avoid excessive stat(/etc/localtime) calls in strftime() on linux?
I left a record processing program of mine running for a few minutes under strace.
This showed in those minutes over 200 000 000 calls to stat("/etc/localtime",..) which sounds a bit excessive and unneeded.
The strace output looks like this:
write(1, "C137015 393393093052629137110 47"..., 16384) = 16384
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2225, ...}) = 0
read(0, "\224q\1\207\0\0\202\1\4\203\1\4\204\1\1\205\1\1\206\1\7\207\1\6\211\1\22\212\1\22\213\1"..., 16384) = 16384
Essentially it turned out to be 1 stat() call for every record processed and the culprit turned out to be this quite ordinary line of code
strftime(call->date_time,DATELEN,"%Y%m%d %H%M%S",&tm_buf);
So - how can I avoid strftime() calling stat(/etc/localtime) at every call?
Solution 1:[1]
With GNU libc library, here is another tip to solve this when /etc/localtime is not configured (this is often the case on tiny embedded systems). This consists to set TZ environment variable to the empty string. This makes the library default to the UTC.
Here is an example strace output on some embedded system calling a logging function which calls localtime() and strftime() when neither /etc/localtime nor TZ are set. With glibc 2.23, this triggers several unsuccessful calls to "openat(/etc/localtime)":
[...]
[pid 200113] gettid() = 200113
[pid 200113] openat(AT_FDCWD, "/etc/localtime", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
[pid 200113] openat(AT_FDCWD, "/etc/localtime", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
[pid 200113] gettid() = 200113
[pid 200113] openat(AT_FDCWD, "/etc/localtime", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
[pid 200113] openat(AT_FDCWD, "/etc/localtime", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
[pid 200113] getpid() = 200113
[pid 200113] writev(4, [{iov_base="DUH\1\1\0\0\0", iov_len=8}, {iov_base="=\2\0\261ECU1\0\3\r\261\r\32\265\3431\2SWMCSWMC", iov_len=26}, {iov_base="\0\2\0\0'\0Tue Mar 1 13:49:20 2022 _"..., iov_len=151}], 3) = 185
[pid 200113] gettid() = 200113
[pid 200113] openat(AT_FDCWD, "/etc/localtime", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
[pid 200113] openat(AT_FDCWD, "/etc/localtime", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
[pid 200113] gettid() = 200113
[...]
And here is the same program's output with strace when TZ is set to the empty string:
$ export TZ=
[...]
[pid 201837] gettid() = 201837
[pid 201837] gettid() = 201837
[pid 201837] getpid() = 201837
[pid 201837] writev(4, [{iov_base="DUH\1\1\0\0\0", iov_len=8}, {iov_base="=\2\0\261ECU1\0\3\24m\r7\253\3171\2SWMCSWMC", iov_len=26}, {iov_base="\0\2\0\0'\0Tue Mar 1 13:52:30 2022 _"..., iov_len=151}], 3) = 185
[pid 201837] gettid() = 201837
[pid 201857] <... read resumed>"DUH\1\f\0\0\0\0DUH\1\6\0\0\0\5\0\0\0\0\0DUH\1\6\0\0\0\5"..., 10024) = 37
[pid 201837] gettid( <unfinished ...>
[pid 201857] read(3, <unfinished ...>
[pid 201837] <... gettid resumed>) = 201837
[pid 201837] getpid() = 201837
[pid 201837] writev(4, [{iov_base="DUH\1\1\0\0\0", iov_len=8}, {iov_base="=\3\0\257ECU1\0\3\24m\r7\253\364A\2SWMCSWMC", iov_len=26}, {iov_base="\0\2\0\0'\0Tue Mar 1 13:52:30 2022 _"..., iov_len=149}], 3) = 183
[...]
N.B.: Here is the corresponding glibc's source code snippet in time/tzset.c which sets UTC when TZ is empty:
/* Interpret the TZ envariable. */
static void
internal_function
tzset_internal (int always, int explicit)
{
static int is_initialized;
const char *tz;
if (is_initialized && !always)
return;
is_initialized = 1;
/* Examine the TZ environment variable. */
tz = getenv ("TZ");
if (tz == NULL && !explicit)
/* Use the site-wide default. This is a file name which means we
would not see changes to the file if we compare only the file
name for change. We want to notice file changes if tzset() has
been called explicitly. Leave TZ as NULL in this case. */
tz = TZDEFAULT;
if (tz && *tz == '\0')
/* User specified the empty string; use UTC explicitly. */
tz = "Universal";
[...]
Sources
This article follows the attribution requirements of Stack Overflow and is licensed under CC BY-SA 3.0.
Source: Stack Overflow
| Solution | Source |
|---|---|
| Solution 1 |
