Timezone offsets in Apache error log #944
Description
Consider the following error log output from my virtual host:
2026-02-13 21:32:59.463827 [pid: 80724, tid: 36791697664] [wsgi:error] [client: 10.64.96.180:60290] [cid: EZfhATtQyyg, rid: aY-Yiy5JQIgCmRQLniLSUQAAFQI] 2026-02-13 21:32:59,463 INFO aY-Yiy5JQIgCmRQLniLSUQAAFQI c
2026-02-13 21:32:59.742106 [pid: 80724, tid: 36791697664] [wsgi:error] [client: 10.64.96.180:60290] [cid: EZfhATtQyyg, rid: aY-Yiy5JQIgCmRQLniLSUQAAFQI] 2026-02-13 21:32:59,741 INFO aY-Yiy5JQIgCmRQLniLSUQAAFQI c
2026-02-13 21:33:00.003303 [pid: 80724, tid: 36791697664] [wsgi:error] [client: 10.64.96.180:60290] [cid: EZfhATtQyyg, rid: aY-Yiy5JQIgCmRQLniLSUQAAFQI] 2026-02-13 21:33:00,003 INFO aY-Yiy5JQIgCmRQLniLSUQAAFQI c
2026-02-13 21:33:00.003628 [pid: 80724, tid: 36791697664] [wsgi:error] [client: 10.64.96.180:60290] [cid: EZfhATtQyyg, rid: aY-Yiy5JQIgCmRQLniLSUQAAFQI] 2026-02-13 21:33:00,003 INFO aY-Yiy5JQIgCmRQLniLSUQAAFQI v
2026-02-13 22:33:05.772974 [pid: 80725, tid: 36029507072] [ssl:info] [client: 10.64.3.70:63132] [cid: q1HGWXtTyyg, rid: -] AH01964: Connection to child 10 established (server kona-dev.innomotics.net:443)
2026-02-13 22:33:05.773162 [pid: 80725, tid: 36029507072] [ssl:info] [client: 10.64.3.70:63132] [cid: q1HGWXtTyyg, rid: -] AH01998: Connection closed to child 10 with abortive shutdown (server kona-dev.innomotic
2026-02-13 21:33:09.586188 [pid: 80724, tid: 36791697664] [wsgi:error] [client: 10.64.96.180:60290] [cid: EZfhATtQyyg, rid: aY-YlS5JQIgCmRQLniLSYQAAFQs] 2026-02-13 21:33:09,586 INFO aY-YlS5JQIgCmRQLniLSYQAAFQs c
2026-02-13 21:33:09.587527 [pid: 80724, tid: 36791697664] [wsgi:error] [client: 10.64.96.180:60290] [cid: EZfhATtQyyg, rid: aY-YlS5JQIgCmRQLniLSYQAAFQs] 2026-02-13 21:33:09,587 INFO aY-YlS5JQIgCmRQLniLSYQAAFQs c
2026-02-13 21:33:09.832441 [pid: 80724, tid: 36791697664] [wsgi:error] [client: 10.64.96.180:60290] [cid: EZfhATtQyyg, rid: aY-YlS5JQIgCmRQLniLSYQAAFQs] 2026-02-13 21:33:09,832 INFO aY-YlS5JQIgCmRQLniLSYQAAFQs c
2026-02-13 21:33:10.093599 [pid: 80724, tid: 36791697664] [wsgi:error] [client: 10.64.96.180:60290] [cid: EZfhATtQyyg, rid: aY-YlS5JQIgCmRQLniLSYQAAFQs] 2026-02-13 21:33:10,093 INFO aY-YlS5JQIgCmRQLniLSYQAAFQs c
2026-02-13 21:33:10.093889 [pid: 80724, tid: 36791697664] [wsgi:error] [client: 10.64.96.180:60290] [cid: EZfhATtQyyg, rid: aY-YlS5JQIgCmRQLniLSYQAAFQs] 2026-02-13 21:33:10,093 INFO aY-YlS5JQIgCmRQLniLSYQAAFQs v
2026-02-13 22:33:10.253850 [pid: 80725, tid: 36029507072] [ssl:info] [client: 10.64.3.54:50122] [cid: GLEKWntTyyg, rid: -] AH01964: Connection to child 10 established (server kona-dev.innomotics.net:443)
2026-02-13 22:33:10.254162 [pid: 80725, tid: 36029507072] [ssl:info] [client: 10.64.3.54:50122] [cid: GLEKWntTyyg, rid: -] AH01998: Connection closed to child 10 with abortive shutdown (server kona-dev.innomotic
2026-02-13 22:33:10.656928 [pid: 80725, tid: 36029507072] [ssl:info] [client: 10.64.90.165:47788] [cid: n9cQWntTyyg, rid: -] AH01964: Connection to child 10 established (server kona-dev.innomotics.net:443)
2026-02-13 22:33:10.657005 [pid: 80725, tid: 36029507072] [ssl:info] [client: 10.64.90.165:47788] [cid: n9cQWntTyyg, rid: -] AH01998: Connection closed to child 10 with abortive shutdown (server kona-dev.innomot
2026-02-13 21:33:19.584255 [pid: 80724, tid: 36791697664] [wsgi:error] [client: 10.64.96.180:60290] [cid: EZfhATtQyyg, rid: aY-Yny5JQIgCmRQLniLScAAAFQ4] 2026-02-13 21:33:19,584 INFO aY-Yny5JQIgCmRQLniLScAAAFQ4 c
2026-02-13 21:33:19.584574 [pid: 80724, tid: 36791697664] [wsgi:error] [client: 10.64.96.180:60290] [cid: EZfhATtQyyg, rid: aY-Yny5JQIgCmRQLniLScAAAFQ4] 2026-02-13 21:33:19,584 INFO aY-Yny5JQIgCmRQLniLScAAAFQ4 c
You'll notice that the time jumps an hour back and forth where "wsgi" appears. The server runs in Europe/Berlin, the Apache server hosts a Django application according to this TIME_ZONE set to UTC and then Django does the following: time.tzset(). It affects the entire physical daemon process. The parent process remains untouched, obviously the file handler is passed around processes and synched for wrinting somehow using each processes TZ settings:
47777 root 20 0 28912 17372 S 0.0 0.0 0:01.46 /usr/local/sbin/httpd -DNOHTTPACCEPT
47782 www 52 0 254M 34160 S 0.0 0.0 0:15.84 ├─ /usr/local/sbin/httpd -DNOHTTPACCEPT
68376 kona 52 0 3436M 241M S 0.8 0.2 0:13.84 ├─ httpd: (wsgi:kona)
47783 www 52 0 254M 33916 S 0.0 0.0 0:07.12 ├─ /usr/local/sbin/httpd -DNOHTTPACCEPT
47781 www 52 0 250M 33228 S 0.0 0.0 0:05.99 ├─ /usr/local/sbin/httpd -DNOHTTPACCEPT
47785 www 52 0 56384 23100 S 0.0 0.0 0:00.03 └─ /usr/local/sbin/httpd -DNOHTTPACCEPT
(PIDs don't match since the log is old)
I am quite certain that there is nothing mod_wsgi can do about and it logically covered here. It took me a bit of time understand the issue. Maybe one can elaborate on such a side effect in the mentioned docs section? Maybe even the MPM style influences the behavior...
FWIW:
# httpd -V
Server version: Apache/2.4.66 (FreeBSD)
Server built: unknown
Server's Module Magic Number: 20120211:141
Server loaded: APR 1.7.6, APR-UTIL 1.6.3, PCRE 10.47 2025-10-21
Compiled using: APR 1.7.5, APR-UTIL 1.6.3, PCRE 10.47 2025-10-21
Architecture: 64-bit
Server MPM: worker
threaded: yes (fixed thread count)
forked: yes (variable process count)
Server compiled with....
-D APR_HAS_SENDFILE
-D APR_HAS_MMAP
-D APR_HAVE_IPV6 (IPv4-mapped addresses disabled)
-D APR_USE_FLOCK_SERIALIZE
-D APR_USE_PTHREAD_SERIALIZE
-D SINGLE_LISTEN_UNSERIALIZED_ACCEPT
-D APR_HAS_OTHER_CHILD
-D AP_HAVE_RELIABLE_PIPED_LOGS
-D DYNAMIC_MODULE_LIMIT=256
-D HTTPD_ROOT="/usr/local"
-D SUEXEC_BIN="/usr/local/bin/suexec"
-D DEFAULT_PIDLOG="/var/run/httpd.pid"
-D DEFAULT_SCOREBOARD="/var/run/apache_runtime_status"
-D DEFAULT_ERRORLOG="/var/log/httpd-error.log"
-D AP_TYPES_CONFIG_FILE="etc/apache24/mime.types"
-D SERVER_CONFIG_FILE="etc/apache24/httpd.conf"