fix: LS-1 close queued handlers on re-setup; LS-2 register atexit once

LS-1: re-setup closes the QueueListener's wrapped file/console handlers after stopping it
(was: relied on GC). LS-2: atexit registration guarded by a module flag so repeated
queue=True re-setups don't stack callbacks. JSON formatter caches the rendered traceback on
the record (no per-handler re-render); _move dest precondition documented.

Signed-off-by: disqualifier <dev@disqualifier.me>
This commit is contained in:
disqualifier 2026-06-29 21:35:21 -04:00
parent 011588a712
commit fc0898d70e
3 changed files with 25 additions and 3 deletions

View File

@ -46,7 +46,11 @@ class JsonLinesFormatter(logging.Formatter):
if key not in _RESERVED and key not in _OUTPUT_KEYS and not key.startswith("_"):
payload[key] = value
if record.exc_info:
payload["exc_info"] = self.formatException(record.exc_info)
# cache the rendered traceback on the record (as stdlib Formatter does) so a
# second handler/format() of the same record doesn't re-render it
if not record.exc_text:
record.exc_text = self.formatException(record.exc_info)
payload["exc_info"] = record.exc_text
elif record.exc_text:
payload["exc_info"] = record.exc_text
if record.stack_info:

View File

@ -20,6 +20,11 @@ def _move(source: str, dest: str) -> None:
different filesystems exactly the container bind-mount / separate-logs-volume
case this lib targets. fall back to shutil.move (copy+unlink) so the roll still
lands instead of failing every rotation via the handler's silent handleError.
precondition: `dest` is a free, non-directory path (all call sites generate a unique
timestamped/dated dest). os.replace and shutil.move differ on a dest that already
exists as a directory, so this helper is not safe for arbitrary dests only the
rotation paths that guarantee a fresh file dest.
"""
try:
os.replace(source, dest)

View File

@ -22,6 +22,7 @@ log = logging.getLogger(__name__)
_MARKER = "_log_setup_owned"
_listener = None
_atexit_registered = False
def _level_value(level: Union[int, str]) -> int:
@ -80,6 +81,14 @@ def _clear_owned(root: logging.Logger) -> None:
global _listener
if _listener is not None:
_listener.stop()
# the listener owns the real file/console handlers (only the QueueHandler is
# root-attached + marked); stopping it doesn't close them, so close them here
# to avoid relying on GC finalizers across a re-setup
for wrapped in getattr(_listener, "handlers", ()):
try:
wrapped.close()
except Exception:
log.warning("log_setup: failed to close queued handler %r", wrapped, exc_info=True)
_listener = None
for handler in list(root.handlers):
if getattr(handler, _MARKER, False):
@ -160,7 +169,7 @@ def setup_logging(
unwritable `log_dir` falls back to console-only with a warning even when `console` is
off, so output is never silently lost; an unknown `output` falls back to text.
"""
global _listener
global _listener, _atexit_registered
root = logging.getLogger()
root.setLevel(_level_value(level))
@ -197,7 +206,11 @@ def setup_logging(
root.addHandler(qh)
_listener = logging.handlers.QueueListener(record_queue, *handlers, respect_handler_level=True)
_listener.start()
atexit.register(_stop_listener)
if not _atexit_registered:
# register once — atexit doesn't dedupe, so repeated queue re-setups would
# otherwise stack identical callbacks (harmless but unbounded)
atexit.register(_stop_listener)
_atexit_registered = True
else:
for handler in handlers:
root.addHandler(_tag(handler))