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 <zino7825@users.noreply.github.com>