Last update: 20-May-2022
Author: R. Koucha
Making localtime() faster
Introduction

When using strace tool on an embedded system to spy the execution of processes, we can see the following failing open() system call in many of them:

[pid  4951] openat(AT_FDCWD, "/etc/localtime", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
Most of the time, this comes from trace libraries which call localtime() to format the timestamp of the traces.

Manual of localtime()

The manual of localtime() service says:

The localtime() function converts the calendar time [...] to broken-down time representation, expressed relative to the user's specified timezone.

To get the current timezone, the function looks at /etc/localtime file. If the latter is missing, the default "UTC" timezone is used.

Source code of localtime()

localtime() is provided by the C library. In the GLIBC version 2.34, it is defined in time/localtime.c:

/* Return the `struct tm' representation of *T in local time.  */
struct tm *
__localtime64 (const __time64_t *t)
{
  return __tz_convert (*t, 1, &_tmbuf);
}
libc_hidden_def (__localtime64)

struct tm *
localtime (const time_t *t)
{
  __time64_t t64 = *t;
  return __localtime64 (&t64);
}
libc_hidden_def (localtime)

The function calls __tz_convert() defined in time/tzset.c:

/* Interpret the TZ envariable.  */
static void
tzset_internal (int always)
{
  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 && *tz == '\0')
    /* User specified the empty string; use UTC explicitly.  */
    tz = "Universal";

  /* A leading colon means "implementation defined syntax".
     We ignore the colon and always use the same algorithm:
     try a data file, and if none exists parse the 1003.1 syntax.  */
  if (tz && *tz == ':')
    ++tz;

  /* Check whether the value changed since the last run.  */
  if (old_tz != NULL && tz != NULL && strcmp (tz, old_tz) == 0)
    /* No change, simply return.  */
    return;

  if (tz == NULL)
    /* No user specification; use the site-wide default.  */
    tz = TZDEFAULT;

  tz_rules[0].name = NULL;
  tz_rules[1].name = NULL;

  /* Save the value of `tz'.  */
  free (old_tz);
  old_tz = tz ? __strdup (tz) : NULL;

  /* Try to read a data file.  */
  __tzfile_read (tz, 0, NULL);
  if (__use_tzfile)
    return;

  /* No data file found.  Default to UTC if nothing specified.  */

  if (tz == NULL || *tz == '\0'
      || (TZDEFAULT != NULL && strcmp (tz, TZDEFAULT) == 0))
    {
      memset (tz_rules, '\0', sizeof tz_rules);
      tz_rules[0].name = tz_rules[1].name = "UTC";
      if (J0 != 0)
    tz_rules[0].type = tz_rules[1].type = J0;
      tz_rules[0].change = tz_rules[1].change = -1;
      update_vars ();
      return;
    }

  __tzset_parse_tz (tz);
}


/* 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);

  if (__use_tzfile)
    __tzfile_compute (timer, use_localtime, &leap_correction,
              &leap_extra_secs, tp);
  else
    {
      if (! __offtime (timer, 0, tp))
    tp = NULL;
      else
    __tz_compute (timer, tp, use_localtime);
      leap_correction = 0L;
      leap_extra_secs = 0;
    }

  __libc_lock_unlock (tzset_lock);

  if (tp)
    {
      if (! use_localtime)
    {
      tp->tm_isdst = 0;
      tp->tm_zone = "GMT";
      tp->tm_gmtoff = 0L;
    }

      if (__offtime (timer, tp->tm_gmtoff - leap_correction, tp))
        tp->tm_sec += leap_extra_secs;
      else
    tp = NULL;
    }

  return tp;
}

The function first checks tzset_internal() which checks the TZ environment variable. On the target system, the latter is not set. Hence, the function ends by setting the tz string with TZDEFAULT. This constant is defined in the time/Makefile with the content of the localtime-file variable:

tz-cflags = -DTZDIR='"$(zonedir)"' \
            -DTZDEFAULT='"$(localtime-file)"' \
            -DTZDEFRULES='"$(posixrules-file)"'

In the configuration of the glibc package, the variable is by default $(sysconfdir)/localtime which is typically /etc/localtime if the build does not redefine sysconfdir.
Then, __tzfile_read() defined in time/tzfile.c is called to open the file. As it is is not installed on the target's file system, fopen() fails. Hence, the failing underlying open() system call upon each call to localtime().

void
__tzfile_read (const char *file, size_t extra, char **extrap)
{
  static const char default_tzdir[] = TZDIR;
  size_t num_isstd, num_isgmt;
  FILE *f;
  struct tzhead tzhead;
  size_t chars;
  size_t i;
  int was_using_tzfile = __use_tzfile;
  int trans_width = 4;
  char *new = NULL;

  _Static_assert (sizeof (__time64_t) == 8,
		  "__time64_t must be eight bytes");

  __use_tzfile = 0;

  if (file == NULL)
    /* No user specification; use the site-wide default.  */
    file = TZDEFAULT;
  else if (*file == '\0')
    /* User specified the empty string; use UTC with no leap seconds.  */
    goto ret_free_transitions;
  else
    {
      /* We must not allow to read an arbitrary file in a setuid
	 program.  So we fail for any file which is not in the
	 directory hierachy starting at TZDIR
	 and which is not the system wide default TZDEFAULT.  */
      if (__libc_enable_secure
	  && ((*file == '/'
	       && memcmp (file, TZDEFAULT, sizeof TZDEFAULT)
	       && memcmp (file, default_tzdir, sizeof (default_tzdir) - 1))
	      || strstr (file, "../") != NULL))
	/* This test is certainly a bit too restrictive but it should
	   catch all critical cases.  */
	goto ret_free_transitions;
    }

  if (*file != '/')
    {
      const char *tzdir;

      tzdir = getenv ("TZDIR");
      if (tzdir == NULL || *tzdir == '\0')
	tzdir = default_tzdir;
      if (__asprintf (&new, "%s/%s", tzdir, file) == -1)
	goto ret_free_transitions;
      file = new;
    }

  /* If we were already using tzfile, check whether the file changed.  */
  struct __stat64_t64 st;
  if (was_using_tzfile
      && __stat64_time64 (file, &st) == 0
      && tzfile_ino == st.st_ino && tzfile_dev == st.st_dev
      && tzfile_mtime == st.st_mtime)
    goto done;  /* Nothing to do.  */

  /* Note the file is opened with cancellation in the I/O functions
     disabled and if available FD_CLOEXEC set.  */
  f = fopen (file, "rce");
  if (f == NULL)
    goto ret_free_transitions;

[...]
 done:
  __use_tzfile = 1;
  free (new);
  return;

 lose:
  fclose (f);
 ret_free_transitions:
  free (new);
  free ((void *) transitions);
  transitions = NULL;
}
Tip to avoid the failing "open(/etc/localtime)"

The preceding analysis of the glibc's source code shows that TZ environment variable is checked first. Setting the environment variable to the empty string makes the glibc use the universal time (i.e. UTC). This makes disappear the numerous unsuccessful "open(/etc/localtime)" system calls at process runtime.

Below is a process execution without /etc/localtime installed and TZ environment variable unset. strace shows lots of failing calls to openat(AT_FDCWD, "/etc/localtime", O_RDONLY|O_CLOEXEC) upon each calls to the tracing services. The ENOENT error means that the file does not exist in the target's rootfs.

[root@bsrf-yocto spys]# strace -f /usr/bin/ota/smm ipc0_addr 192.168.170.4 ipc0_port 1213 ipc0_role server num_of_ipc_connections 2
[…]
[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
[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="=\3\0\257ECU1\0\3\r\261\r\32\265\354A\2SWMCSWMC", iov_len=26}, {iov_base="\0\2\0\0'\0Tue Mar  1 13:49:20 2022 _"..., iov_len=149}], 3) = 183
[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
[...]

Below is the same with TZ set to the empty string (we no longer see the failing open() system calls upon each calls to the trace service):

[root@bsrf-yocto spys]# export TZ=
[root@bsrf-yocto spys]# strace -f /usr/bin/ota/smm ipc0_addr 192.168.170.4 ipc0_port 1213 ipc0_role server num_of_ipc_connections 2
[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( 
[pid 201857] read(3,  
[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
[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="=\4\0\222ECU1\0\3\24m\r7\270\335A\2SWMCSWMC", iov_len=26}, {iov_base="\0\2\0\0'\0Tue Mar  1 13:52:30 2022 _"..., iov_len=120}], 3) = 154
[pid 201837] getpid()                   = 201837
[pid 201837] writev(4, [{iov_base="DUH\1\5\0\0\0", iov_len=8}, {iov_base="SWMC\0\0\0\0m\24\3\0", iov_len=12}], 2) = 20
[pid 201837] gettid()                   = 201837
[pid 201837] gettid()                   = 201837
[pid 201837] getpid()                   = 201837
[...]
Proposed changes

As the target is running systemd, TZ environment variable should be set in both:

The environment variables of the processes can be viewed in /proc/<pid>/environ. For example:

[root@sa515m ~]# pidof nfs_fe
1609
[root@sa515m ~]# cat /proc/1609/environ | tr '\0' '\n'
LANG=C.UTF-8
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
TZ=
LISTEN_PID=1609
LISTEN_FDS=1
LISTEN_FDNAMES=nfs-front-end-srv.socket
HOME=/root
LOGNAME=root
USER=root
SHELL=/bin/sh
INVOCATION_ID=c6bb61e29a0e45fe94fb8da7eb8533d7 JOURNAL_STREAM=9:32444
About the author

The author is an engineer in computer sciences located in France. He can be contacted here.