4 Commits
Author SHA1 Message Date
dsql b4fd31dddc docs: one process per live file, a distinct history_name per service
Signed-off-by: disqualifier <dev@disqualifier.me>
2026-10-16 04:40:13 -04:00
dsql 5b27df65e7 refactor: collapse prune, _free_dest and the on_start collision loop
T3-21: prune() is retier() with no compressed tier (keeping its
backup_count <= 0 no-op); _free_dest was a no-op behind the tiered namer,
which already mints a free plain name; rotate_on_start repeated
make_history_namer's stamp + collision loop and now calls it. every
retention scenario (on_start/size/daily, legacy and tiered, same-second
collisions, foreign and legacy names) lists identically. one difference: a
crash-left plain twin of a .gz is now dropped before counting, so prune keeps
backup_count real logs instead of spending a slot on the duplicate.

Signed-off-by: disqualifier <dev@disqualifier.me>
2026-10-16 04:40:06 -04:00
dsql 5e53a7cd6c chore: bump to 1.1.0
Signed-off-by: disqualifier <dev@disqualifier.me>
2026-10-16 03:57:59 -04:00
dsql 76d3efad96 fix: daily roll spares cwd, failed roll keeps logging, queue formats at call
T1-2: TimedRotatingFileHandler(backupCount=N) on py3.10/3.11 runs the
stdlib's own retention over the live file's dir (cwd) and deleted unrelated
files. pass backupCount=0; make_rotator's prune already owns retention.

T1-3: an OSError from move/gzip/prune escaped into doRollover, rolloverAt
never advanced and every later record was dropped. the rotator now writes
one line to stderr and returns, and the stdlib reopens the live file.

T2-6: queue=True deferred %-formatting to the listener thread, so a mutable
arg logged its mutated value. prepare() merges msg+args on the calling
thread; exc_info stays for the listener's formatter.

Signed-off-by: disqualifier <dev@disqualifier.me>
2026-10-16 03:57:59 -04:00
4 changed files with 39 additions and 57 deletions

No files matched your search

+8 -2
View File
@@ -13,12 +13,12 @@ and emit; their records flow into the handlers `log_setup` wired.
## Install
```
log_setup @ git+ssh://git@git.rethinkstudios.io/rethink-public/log_setup.git@v1.0.0
log_setup @ git+ssh://git@git.rethinkstudios.io/rethink-public/log_setup.git@v1.1.0
```
No dependencies — stdlib only.
Drop the `@v1.0.0` suffix from the line above to install the latest unpinned.
Drop the `@v1.1.0` suffix from the line above to install the latest unpinned.
## Quick start
@@ -85,6 +85,12 @@ setup_logging(name="latest", rotate="daily")
- Retention (tier counts / `backup_count`) is unchanged — it's just keyed to the project
stem now.
**One process per live file, one `history_name` per service.** Rotation and retention
assume a single writer: two processes writing the same live file both try to roll it, and
two services sharing a `log_dir` with the same history stem prune each other's history
(each counts the other's rolls against its own `backup_count`). Give each process its own
live file, and give services that share a cwd or `log_dir` distinct `history_name`s.
## Tiered retention (`keep_uncompressed` / `keep_compressed`)
The default is a flat `backup_count`: every rolled file is gzipped on roll and the oldest
+1 -1
View File
@@ -4,7 +4,7 @@ build-backend = "hatchling.build"
[project]
name = "log_setup"
version = "1.0.0"
version = "1.1.0"
description = "stdlib app-entry-point logging setup: live run.log, rotation, gzip, retention, consistent format"
requires-python = ">=3.10"
dependencies = []
+21 -52
View File
@@ -16,6 +16,7 @@ import gzip
import os
import re
import shutil
import sys
import time
from typing import Callable, Optional, Tuple
@@ -34,22 +35,6 @@ def _move(source: str, dest: str) -> None:
shutil.move(source, dest)
def _free_dest(dest: str) -> str:
"""return `dest`, or a `.N`-suffixed variant if it (or its .gz twin) already exists
used by the tiered rotator so a second same-stamp roll doesn't clobber the earlier
file; checks both the plain and .gz forms of each candidate.
"""
if not os.path.exists(dest) and not os.path.exists(dest + ".gz"):
return dest
counter = 1
while True:
candidate = f"{dest}.{counter}"
if not os.path.exists(candidate) and not os.path.exists(candidate + ".gz"):
return candidate
counter += 1
def _gzip_file(source: str, dest: str) -> None:
"""atomically gzip source into dest, then remove source - or leave source untouched
@@ -150,17 +135,27 @@ def make_rotator(
tiered mode (when `keep_uncompressed`/`keep_compressed` are given): land the rolled
file PLAIN and re-tier `log_dir` - newest `keep_uncompressed` stay uncompressed, next
`keep_compressed` gzipped, rest deleted. `compress`/`backup_count` are ignored.
a failed roll (OSError from move/gzip/prune, e.g. `log_dir` deleted) is reported on
stderr and swallowed: raising into the stdlib doRollover would leave the handler
retrying the roll and dropping every later record. the stdlib then reopens the live
file and logging continues there. stderr, not logging - this runs inside emit.
"""
tiered = keep_uncompressed is not None or keep_compressed is not None
def rotator(source: str, dest: str) -> None:
try:
_roll(source, dest)
except OSError as error:
sys.stderr.write(f"log_setup: rotation of {source!r} failed, still logging to it: {error}\n")
def _roll(source: str, dest: str) -> None:
if not os.path.exists(source):
return
if tiered:
# strip the namer's .gz suffix so the roll lands plain and retier decides
# its tier; disambiguate a same-interval collision via _free_dest
plain_dest = _free_dest(dest[:-3] if dest.endswith(".gz") else dest)
_move(source, plain_dest)
# the tiered namer (plain=True) already minted a free, plain .log name;
# retier decides its tier
_move(source, dest)
if log_dir is not None and prune_stem is not None:
retier(log_dir, prune_stem, keep_uncompressed or 0, keep_compressed or 0, live_stem)
return
@@ -202,21 +197,8 @@ def rotate_on_start(
tiered = keep_uncompressed is not None or keep_compressed is not None
live_stem = os.path.splitext(os.path.basename(live_path))[0]
stem = os.path.basename(history_stem) if history_stem else live_stem
stamp = time.strftime("%Y-%m-%d_%H-%M-%S", clock())
suffix = ".log.gz" if (compress and not tiered) else ".log"
# a 1-second stamp collision (rapid crash-restart) is disambiguated with a
# counter; check BOTH .log and .log.gz since a tiered same-stamp roll may
# already be compressed
def _taken(path: str) -> bool:
base = path[:-3] if path.endswith(".gz") else path
return os.path.exists(base) or os.path.exists(base + ".gz")
dest = os.path.join(log_dir, f"{stem}.{stamp}{suffix}")
counter = 1
while _taken(dest):
dest = os.path.join(log_dir, f"{stem}.{stamp}.{counter}{suffix}")
counter += 1
# same name + same-second collision counter as the size/daily rolls
dest = make_history_namer(stem, log_dir, compress, plain=tiered, clock=clock)(live_path)
if compress and not tiered:
_gzip_file(live_path, dest)
else:
@@ -356,26 +338,13 @@ def prune(log_dir: str, stem: str, backup_count: int, live_stem: Optional[str] =
(`<stem>.<stamp>[.N].log[.gz]`, see `_is_rolled_name`) - a foreign file that only
shares the `<stem>.` prefix (e.g. a project's own `<stem>.audit.log` dropped into
the same log_dir) is left alone rather than counted and deleted as a roll.
this is `retier` with no compressed tier (so a crash-left plain twin of a .gz is
dropped first, not counted); `backup_count <= 0` leaves history alone.
"""
if backup_count <= 0:
return
stem = os.path.basename(stem)
live_stem = os.path.basename(live_stem) if live_stem else None
try:
entries = [
os.path.join(log_dir, name)
for name in os.listdir(log_dir)
if name != f"{stem}.log" and _is_rolled_name(stem, name, live_stem)
]
except OSError:
return
files = [(p, _safe_mtime(p), _roll_counter(p)) for p in entries if os.path.isfile(p)]
files.sort(key=lambda t: (t[1], t[2]), reverse=True)
for path, _, _ in files[backup_count:]:
try:
os.remove(path)
except OSError:
pass
retier(log_dir, stem, backup_count, 0, live_stem)
def _safe_mtime(path: str) -> float:
+9 -2
View File
@@ -38,10 +38,15 @@ class _PreservingQueueHandler(logging.handlers.QueueHandler):
listener's real formatter ever sees the record. that behavior exists to keep a
record picklable across a multiprocessing.Queue; this lib only ever uses an
in-process queue.Queue, so there is nothing to pickle and nothing to strip -
the listener's handler formats the untouched record exactly once.
the listener's handler formats the record exactly once, exc_info intact.
the message IS merged with its args here, on the calling thread: deferring that to
the listener would log a mutable arg with whatever value it holds by then.
"""
def prepare(self, record: logging.LogRecord) -> logging.LogRecord:
record.msg = record.getMessage()
record.args = None
return record
@@ -168,8 +173,10 @@ def _file_handler(
tiered=tiered, rotate_mode=rotate,
)
elif rotate == "daily":
# backupCount=0: on py3.10/3.11 the stdlib's own retention scans the live file's
# dir (cwd) and deletes unrelated files; make_rotator's prune owns retention
handler = logging.handlers.TimedRotatingFileHandler(
live_path, when="midnight", backupCount=backup_count, encoding="utf-8",
live_path, when="midnight", backupCount=0, encoding="utf-8",
)
attach_rolling(
handler, log_dir, compress, prune_stem=history_stem, backup_count=backup_count,