Dispatcharr/dispatcharr/display_timezone.py
nagelm fd8e787104 fix(logging): render log timestamps in the system display timezone
Application log timestamps are pinned to UTC no matter what the operator
configures, while nginx in the same container honors TZ - one container,
two timezones (issue 1439). Two mechanisms force this:

1. docker/entrypoint.sh launches the app tree via `su - dispatch`,
   which strips the environment; only whitelisted vars are re-exported
   through /etc/environment and /etc/profile.d, and TZ is not among
   them, so no app process ever sees the operator's declared zone.

2. Whitelisting TZ alone cannot fix Django-managed processes anyway:
   Django's settings loader unconditionally re-stamps os.environ["TZ"]
   = TIME_ZONE ("UTC") and calls time.tzset() in every uwsgi, celery
   and management-command process. Stdlib logging's %(asctime)s renders
   via time.localtime(), so it can never show local time in a Django
   process regardless of the environment.

The fix, keeping TIME_ZONE = "UTC" / USE_TZ untouched (DB truth and
every wire surface - XMLTV offsets, XC server_info/time_now/EPG
timestamps - stay UTC by design):

- entrypoint: normalize a DISPATCHARR_TIME_ZONE bootstrap var from the
  standard TZ env and whitelist it. TZ itself is deliberately NOT
  whitelisted: pam_env would hand it to every su- child including
  initdb/postgres, silently flipping the database server timezone on
  fresh installs - the precondition for the EPG-offset corruption
  class tracked in issue 651, and (with an invalid zone) a source of
  psycopg "unknown PostgreSQL timezone" warnings emitted while the
  connection lock is held. Verified empirically: with TZ whitelisted,
  a fresh install ran its sessions at the container zone; without it,
  the server default stays UTC.

- settings: capture DISPATCHARR_DISPLAY_TZ at module import, before
  Django's tzset re-stamp, as the pre-database display default.

- logging: the verbose formatter renders timestamps with
  datetime/ZoneInfo from an in-process cached zone - never
  time.localtime(), and never a database query at emit time. An
  emit-time query can self-deadlock: a log record that originates
  inside a psycopg call (e.g. its timezone warning) would re-enter the
  same non-reentrant connection lock the ORM query then needs. The
  cache is refreshed out-of-band from provably safe contexts instead:
  request_started, celery task_prerun, and a CoreSettings post_save
  receiver (immediate in the process that saves the UI setting). The
  zone resolves to the UI's System > Time Zone setting - already
  canonical for DVR rules, celery crontabs and backup naming - with
  the env capture as the value before the first refresh, and any
  database error or invalid stored zone keeps the previous value.

- first-boot seed: the fresh-install default that the settings
  consolidation migration writes for the system time zone now derives
  from the same env capture (validated against zoneinfo, falling back
  to UTC) instead of a hardcoded "UTC", so a new install honors the
  declared container timezone from first boot. Existing installs are
  untouched: the migration only manufactures a default when no stored
  value exists, and installs that already ran it never re-run it.

Known residuals: uWSGI's native request log renders its own C-level
ftime outside Python logging and keeps UTC, as do celery's internal
worker_log_format lines; idle workers adopt a changed UI zone on their
next request/task. All documented rather than patched.
2026-07-15 13:32:36 +12:00

49 lines
1.6 KiB
Python

import logging
import time
from datetime import datetime
from zoneinfo import ZoneInfo
_REFRESH_INTERVAL_SECONDS = 5.0
_cache = {"zone": None, "checked": 0.0}
def _env_zone():
from django.conf import settings
try:
return ZoneInfo(getattr(settings, "DISPATCHARR_DISPLAY_TZ", "UTC"))
except Exception:
return ZoneInfo("UTC")
def refresh_display_zone(force=False):
"""Refresh the cached display zone from CoreSettings.
Only call from contexts that may safely run a database query
(request/task start, settings writes) — never from the logging path:
an emit-time query deadlocks on the psycopg connection lock when the
log record itself originates inside a database call.
"""
now = time.monotonic()
if not force and now - _cache["checked"] < _REFRESH_INTERVAL_SECONDS:
return
_cache["checked"] = now
try:
from core.models import CoreSettings
_cache["zone"] = ZoneInfo(CoreSettings.get_system_time_zone())
except Exception:
# Database or app registry not ready, or an invalid stored zone —
# keep the previous value (the env capture until a refresh lands).
pass
class DisplayTimezoneFormatter(logging.Formatter):
def __init__(self, format=None, datefmt=None, style="%"):
super().__init__(fmt=format, datefmt=datefmt, style=style)
def formatTime(self, record, datefmt=None):
dt = datetime.fromtimestamp(record.created, tz=_cache["zone"] or _env_zone())
if datefmt:
return dt.strftime(datefmt)
return f"{dt.strftime('%Y-%m-%d %H:%M:%S')},{int(record.msecs):03d}"