From: Willy Tarreau Date: Thu, 23 Jul 2026 13:53:56 +0000 (+0200) Subject: OPTIM: tools: keep a cache of recent localtime() and gmtime() X-Git-Url: http://git.ipfire.org/gitweb/?a=commitdiff_plain;h=34b9b528e83e864170a773c66afc0cbca687c475;p=thirdparty%2Fhaproxy.git OPTIM: tools: keep a cache of recent localtime() and gmtime() The log subsystem already keeps a cache of the latest generated time header to avoid paying the price of snprintf() notably. However, as reported in GH issue #3444 by @zino7825, localtime() and gmtime() are affected (at least in glibc) by a tzset_lock held during the call to __tz_convert(), which ruins performance when logging time such as the accept date. Even just "option httplog" sees its performance divided by two on a 64-core machine, from 1.8M to 910k req/s. The following config even goes down to 388k req/s: defaults mode http frontend fe bind :8001 log 127.0.0.1:5514 len 8192 local0 log-format '{"t":"%t","tr":"%tr","ci":"%ci"}' http-request set-var(txn.now) date(),ltime("%Y-%m-%dT%H:%M:%S") option httplog default_backend be backend be server s1 198.18.0.31:8000 With native_queued_spin_lock_slowpath() taking 80% of the CPU, showing that it's also involved in futexes. This patch, suggested by @zino7825, implements a very simple thread- local cache for the 4 previously seen values for both localtime() and gmtime(). The cache is visited in reverse order so that most recently updated values are visited first (the most likely ones to be used). A test with the config above and 12.8M requests showed 38.4M lookups with only 12k total misses. A more naive scan from 0 to N caused 59M misses. With this patch, all variants of the tests above remain at native speed without native_queued_spin_lock_slowpath() being noticeable at all. If for any reason a log format was so complex that it needed more stored local times, it would be easy to change the cache size by redefining TIME_CACHE_BITS. The functions are no longer inlined, they were moved to tools.c since we'd rather avoid loops and complex constructs in inlined functions. Co-authored-by: Jinho Kong --- diff --git a/include/haproxy/defaults.h b/include/haproxy/defaults.h index 8a9062ea4..aec594e06 100644 --- a/include/haproxy/defaults.h +++ b/include/haproxy/defaults.h @@ -749,4 +749,13 @@ #define STKTABLE_MAX_UPDATES_AT_ONCE 100 #endif /* STKTABLE_MAX_UPDATES_AT_ONCE */ +/* number of time cache entries, must be a power of two, hence the setting in + * bits. Note that 2 or 4 slots is already sufficient in practice. + */ +#ifndef TIME_CACHE_BITS +# define TIME_CACHE_BITS 2 +#endif +#define TIME_CACHE_SLOTS (1U << TIME_CACHE_BITS) + + #endif /* _HAPROXY_DEFAULTS_H */ diff --git a/include/haproxy/tools.h b/include/haproxy/tools.h index b00c21b3b..148d56f13 100644 --- a/include/haproxy/tools.h +++ b/include/haproxy/tools.h @@ -602,25 +602,8 @@ static inline char *alltrim(char *s, char c) { return ltrim(s, c); } -/* This function converts the time_t value into a broken out struct tm - * which must be allocated by the caller. It is highly recommended to use this - * function instead of localtime() because that one requires a time_t* which - * is not always compatible with tv_sec depending on OS/hardware combinations. - */ -static inline void get_localtime(const time_t now, struct tm *tm) -{ - localtime_r(&now, tm); -} - -/* This function converts the time_t value into a broken out struct tm - * which must be allocated by the caller. It is highly recommended to use this - * function instead of gmtime() because that one requires a time_t* which - * is not always compatible with tv_sec depending on OS/hardware combinations. - */ -static inline void get_gmtime(const time_t now, struct tm *tm) -{ - gmtime_r(&now, tm); -} +void get_localtime(const time_t now, struct tm *tm); +void get_gmtime(const time_t now, struct tm *tm); /* Counts a number of elapsed days since 01/01/0000 based solely on elapsed * years and assuming the regular rule for leap years applies. It's fake but diff --git a/src/tools.c b/src/tools.c index 5b15905a8..afb29460b 100644 --- a/src/tools.c +++ b/src/tools.c @@ -3892,6 +3892,72 @@ size_t ipaddrcpy(unsigned char *buf, const struct sockaddr_storage *saddr) return p - buf; } +/* cache of conversions from time_t to struct tm via localtime() and gmtime(). */ +static THREAD_LOCAL struct { + time_t sec; + struct tm tm; +} localtime_cache[TIME_CACHE_SLOTS], gmtime_cache[TIME_CACHE_SLOTS]; + +/* slot where most recent value was stored */ +static THREAD_LOCAL uint localtime_cache_slot, gmtime_cache_slot; + +/* This function converts the time_t value into a broken out struct tm + * which must be allocated by the caller. It is highly recommended to use this + * function instead of localtime() because that one requires a time_t* which + * is not always compatible with tv_sec depending on OS/hardware combinations. + * Also it implements a cache that avoids internal libc contention on tz_lock + * when entering __tz_convert(). + */ +void get_localtime(const time_t now, struct tm *tm) +{ + uint32_t idx; + + /* visit recent entries in age order */ + idx = localtime_cache_slot; + do { + if (likely(localtime_cache[idx].sec == now)) { + /* that's a hit, return the cached entry */ + *tm = localtime_cache[idx].tm; + return; + } + idx = (idx - 1) % TIME_CACHE_SLOTS; + } while (idx != localtime_cache_slot); + + /* that's a miss, convert the time and cache it */ + localtime_r(&now, tm); + localtime_cache_slot = (localtime_cache_slot + 1) % TIME_CACHE_SLOTS; + localtime_cache[localtime_cache_slot].sec = now; + localtime_cache[localtime_cache_slot].tm = *tm; +} + +/* This function converts the time_t value into a broken out struct tm + * which must be allocated by the caller. It is highly recommended to use this + * function instead of gmtime() because that one requires a time_t* which + * is not always compatible with tv_sec depending on OS/hardware combinations. + * Also it implements a cache that avoids internal libc contention on tz_lock + * when entering __tz_convert(). + */ +void get_gmtime(const time_t now, struct tm *tm) +{ + uint32_t idx; + + /* visit recent entries in age order */ + idx = gmtime_cache_slot; + do { + if (likely(gmtime_cache[idx].sec == now)) { + /* that's a hit, return the cached entry */ + *tm = gmtime_cache[idx].tm; + return; + } + idx = (idx - 1) % TIME_CACHE_SLOTS; + } while (idx != gmtime_cache_slot); + + /* that's a miss, convert the time and cache it */ + gmtime_r(&now, tm); + gmtime_cache_slot = (gmtime_cache_slot + 1) % TIME_CACHE_SLOTS; + gmtime_cache[gmtime_cache_slot].sec = now; + gmtime_cache[gmtime_cache_slot].tm = *tm; +} char *human_time(int t, short hz_div) { static char rv[sizeof("24855d23h")+1]; // longest of "23h59m" and "59m59s"