2 Commits
Author SHA1 Message Date
dsql b52c1d37fa fix: LOW/nit clearance — retier twin dedupe + same-second counter ordering, warn on unknown rotate
- logsetup-2: retier drops a plain file whose .gz twin exists (crash-between-write-and-remove
  residue) up front, so the phantom twin never occupies a retention slot / evicts a real roll.
- logsetup-5: retier breaks mtime ties by the roll counter parsed from the name, so a
  same-second on_start burst tiers newest-first instead of arbitrary listdir order.
- logsetup-3: tiered daily rotator disambiguates an existing dated dest with a counter (no
  clobber on a second same-interval roll).
- logsetup-6: unknown rotate value warns (matching the unknown-output convention) instead of
  silently degrading to a non-rotating file.
- README: size-mode backup naming clarified (numbered flat vs timestamped tiered).
verified stdlib-only; v0.4.0/v0.4.1/size suites still pass. bump v0.4.2 -> v0.4.3

Signed-off-by: disqualifier <dev@disqualifier.me>
2026-07-01 00:28:18 -04:00
dsql 6a10f3acc0 fix: tiered rotate='size' actually rotates and tiers (logsetup-1, logsetup-4)
tiered size mode was broken two ways: (1) stdlib RotatingFileHandler's numbered .1/.2 shift
can't manage files redirected into log_dir, so every roll overwrote slot 1 -> ~99% of
history silently lost; (2) doRollover is gated on backupCount>0, so backup_count=0 (which
the docstring says is ignored in tiered mode) meant NO rotation + unbounded live file.

fix: tiered size now uses a timestamped per-roll namer (make_size_namer) like daily/on_start
so retier manages the pile, and forces a nonzero internal backupCount so the roll always
fires (retier bounds retention, not backupCount). non-tiered size unchanged.

verified: tiered size rotates + bounds to tier total (was stuck at 1); backup_count=0 rotates
+ live file bounded (was unbounded); legacy size back-compat intact; v0.4.0/v0.4.1 suites
still pass. bump v0.4.1 -> v0.4.2

Signed-off-by: disqualifier <dev@disqualifier.me>
2026-06-30 21:04:58 -04:00
5 changed files with 127 additions and 12 deletions
+4 -3
View File
@@ -13,12 +13,12 @@ and emit; their records flow into the handlers `log_setup` wired.
## Install ## Install
``` ```
log_setup @ git+ssh://git@git.rethinkstudios.io/rethink-public/log_setup.git@v0.4.1 log_setup @ git+ssh://git@git.rethinkstudios.io/rethink-public/log_setup.git@v0.4.3
``` ```
No dependencies — stdlib only. No dependencies — stdlib only.
Drop the `@v0.4.1` suffix from the line above to install the latest unpinned. Drop the `@v0.4.3` suffix from the line above to install the latest unpinned.
## Quick start ## Quick start
@@ -45,7 +45,8 @@ emits; the records land in the configured root.
- **Rotation** (`rotate=`): - **Rotation** (`rotate=`):
- `"daily"` (default) — rolls at midnight, dated name into `log_dir`, keeps - `"daily"` (default) — rolls at midnight, dated name into `log_dir`, keeps
`backup_count` days. `backup_count` days.
- `"size"` — rolls at `max_bytes`, numbered backups in `log_dir`. - `"size"` — rolls at `max_bytes`; numbered backups (`run.log.1`, `.2`, …) in `log_dir`
for the default flat retention, or timestamped names when tiered retention is on (below).
- `"on_start"` — on startup, moves an existing `run.log` into `log_dir` - `"on_start"` — on startup, moves an existing `run.log` into `log_dir`
(`run.<timestamp>.log[.gz]`) and starts fresh; prunes to `backup_count`. (`run.<timestamp>.log[.gz]`) and starts fresh; prunes to `backup_count`.
- `None` — single file, no rotation. - `None` — single file, no rotation.
+1 -1
View File
@@ -4,7 +4,7 @@ build-backend = "hatchling.build"
[project] [project]
name = "log_setup" name = "log_setup"
version = "0.4.1" version = "0.4.3"
description = "stdlib app-entry-point logging setup: live run.log, rotation, gzip, retention, consistent format" description = "stdlib app-entry-point logging setup: live run.log, rotation, gzip, retention, consistent format"
requires-python = ">=3.10" requires-python = ">=3.10"
dependencies = [] dependencies = []
+1 -1
View File
@@ -19,4 +19,4 @@ from .setup import setup_logging
__all__ = ["setup_logging"] __all__ = ["setup_logging"]
__version__ = "0.4.1" __version__ = "0.4.3"
+106 -6
View File
@@ -32,6 +32,24 @@ def _move(source: str, dest: str) -> None:
shutil.move(source, dest) 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 roll landing on the same dated/stamped name
(e.g. two daily rolls in one day) doesn't clobber the earlier file. the suffix goes
before nothing here (dest is already the plain path) — 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: def _gzip_file(source: str, dest: str) -> None:
"""gzip source into dest then remove source (the rolled-file compression idiom) """gzip source into dest then remove source (the rolled-file compression idiom)
@@ -62,6 +80,30 @@ def make_namer(log_dir: str, compress: bool) -> Callable[[str], str]:
return namer return namer
def make_size_namer(
stem: str, log_dir: str, clock=time.localtime,
) -> Callable[[str], str]:
"""namer for tiered SIZE mode: a unique timestamped dest per roll, plain (no .gz)
stdlib RotatingFileHandler names rolls `<live>.1`, `<live>.2`, ... and shifts them —
a scheme that breaks once files are redirected into log_dir (the shift can't find
them, so every roll reuses slot 1). tiered retention wants unique per-roll names it
can rank + tier like the daily/on_start paths, so ignore the handler's `.N` suffix
entirely and mint `<stem>.<Y-m-d_H-M-S>.log`, disambiguating a same-second collision
(against both the .log and .log.gz forms) with a counter. always plain — retier
decides compression.
"""
def namer(default_name: str) -> str:
stamp = time.strftime("%Y-%m-%d_%H-%M-%S", clock())
dest = os.path.join(log_dir, f"{stem}.{stamp}.log")
counter = 1
while os.path.exists(dest) or os.path.exists(dest + ".gz"):
dest = os.path.join(log_dir, f"{stem}.{stamp}.{counter}.log")
counter += 1
return dest
return namer
def make_rotator( def make_rotator(
compress: bool, log_dir: Optional[str] = None, compress: bool, log_dir: Optional[str] = None,
prune_stem: Optional[str] = None, backup_count: int = 0, prune_stem: Optional[str] = None, backup_count: int = 0,
@@ -87,8 +129,11 @@ def make_rotator(
return return
if tiered: if tiered:
# dest carries the namer's .gz suffix in compress mode; strip it so the # dest carries the namer's .gz suffix in compress mode; strip it so the
# freshly-rolled file lands plain and retier decides its tier # freshly-rolled file lands plain and retier decides its tier. disambiguate a
plain_dest = dest[:-3] if dest.endswith(".gz") else dest # dest that already exists (a second same-interval daily roll reuses the same
# dated name) with a counter, checking both .log and .log.gz forms, so the
# earlier roll isn't clobbered.
plain_dest = _free_dest(dest[:-3] if dest.endswith(".gz") else dest)
_move(source, plain_dest) _move(source, plain_dest)
if log_dir is not None and prune_stem is not None: 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) retier(log_dir, prune_stem, keep_uncompressed or 0, keep_compressed or 0)
@@ -159,6 +204,10 @@ def retier(log_dir: str, stem: str, keep_uncompressed: int, keep_compressed: int
(the namer/rotate_on_start basename them), so a `name` containing a directory (e.g. (the namer/rotate_on_start basename them), so a `name` containing a directory (e.g.
"sub/run") must be matched by "run." here or nothing matches and retention silently "sub/run") must be matched by "run." here or nothing matches and retention silently
never fires (unbounded pileup). never fires (unbounded pileup).
ordering is by mtime, then by the roll counter parsed from the name so a same-second
burst (tied mtimes, counter-disambiguated stamps like run.<t>.log / run.<t>.1.log)
still tiers newest-first correctly rather than falling back to arbitrary listdir order.
""" """
stem = os.path.basename(stem) stem = os.path.basename(stem)
try: try:
@@ -169,11 +218,26 @@ def retier(log_dir: str, stem: str, keep_uncompressed: int, keep_compressed: int
except OSError: except OSError:
return return
entries = [os.path.join(log_dir, name) for name in names] entries = [os.path.join(log_dir, name) for name in names]
files = [(p, _safe_mtime(p)) for p in entries if os.path.isfile(p)] # dedupe plain/gz twins FIRST (a crash between _gzip_file's write and its os.remove can
files.sort(key=lambda pair: pair[1], reverse=True) # leave <x>.log beside <x>.log.gz). drop the redundant plain copy up front so the
# phantom twin never occupies a retention slot and evicts a distinct older roll.
present = set(entries)
kept = []
for p in entries:
if not p.endswith(".gz") and (p + ".gz") in present:
try:
os.remove(p)
except OSError:
kept.append(p) # couldn't remove — keep it in the accounting
continue
kept.append(p)
files = [(p, _safe_mtime(p), _roll_counter(p)) for p in kept if os.path.isfile(p)]
# newest-first: higher mtime first, and within a tied second the higher roll counter
# (a later same-second roll) is newer
files.sort(key=lambda t: (t[1], t[2]), reverse=True)
keep = keep_uncompressed + keep_compressed keep = keep_uncompressed + keep_compressed
for index, (path, _) in enumerate(files): for index, (path, _, _) in enumerate(files):
if index >= keep: if index >= keep:
try: try:
os.remove(path) os.remove(path)
@@ -182,6 +246,14 @@ def retier(log_dir: str, stem: str, keep_uncompressed: int, keep_compressed: int
elif index >= keep_uncompressed and not path.endswith(".gz"): elif index >= keep_uncompressed and not path.endswith(".gz"):
dest = path + ".gz" dest = path + ".gz"
if os.path.exists(dest): if os.path.exists(dest):
# a crash/power-loss between _gzip_file's write and its os.remove can leave
# a plain source beside a fresh .gz. don't keep both (they'd double-count
# toward retention and evict a distinct older roll) — drop the redundant
# plain twin, keeping the compressed copy.
try:
os.remove(path)
except OSError:
pass
continue continue
try: try:
_gzip_file(path, dest) _gzip_file(path, dest)
@@ -189,6 +261,25 @@ def retier(log_dir: str, stem: str, keep_uncompressed: int, keep_compressed: int
pass pass
def _roll_counter(path: str) -> int:
"""parse the same-second disambiguation counter out of a rolled filename
only the on_start / size-namer shape carries a counter: `<stem>.<stamp>[.<counter>].log`
(optionally `.gz`), where a colliding same-second roll gets `.1`, `.2`, ... and a higher
counter is the later (newer) roll. the first roll of a second has no counter (0).
daily's dated names (`<stem>.log.<Y-m-d>`) do NOT end in `.log` and are second+-granular
(distinct mtimes), so they never need the counter tie-break — return 0 for them rather
than misparsing the trailing date component as a counter.
"""
base = path[:-3] if path.endswith(".gz") else path
if not base.endswith(".log"):
return 0
base = base[:-4]
tail = base.rsplit(".", 1)[-1]
return int(tail) if tail.isdigit() else 0
def prune(log_dir: str, stem: str, backup_count: int) -> None: def prune(log_dir: str, stem: str, backup_count: int) -> None:
"""keep only the newest `backup_count` rolled files for a given stem in log_dir """keep only the newest `backup_count` rolled files for a given stem in log_dir
@@ -231,6 +322,7 @@ def attach_rolling(
handler, log_dir: str, compress: bool, handler, log_dir: str, compress: bool,
prune_stem: Optional[str] = None, backup_count: int = 0, prune_stem: Optional[str] = None, backup_count: int = 0,
keep_uncompressed: Optional[int] = None, keep_compressed: Optional[int] = None, keep_uncompressed: Optional[int] = None, keep_compressed: Optional[int] = None,
size_tiered: bool = False,
) -> Tuple[Callable, Callable]: ) -> Tuple[Callable, Callable]:
"""wire the custom namer + rotator onto a rotating handler; return them """wire the custom namer + rotator onto a rotating handler; return them
@@ -238,8 +330,16 @@ def attach_rolling(
(the handler's own retention can't see the redirected rolled files). pass (the handler's own retention can't see the redirected rolled files). pass
`keep_uncompressed`/`keep_compressed` instead to use tiered retention (newest plain, `keep_uncompressed`/`keep_compressed` instead to use tiered retention (newest plain,
next gzipped, rest deleted) — see make_rotator. next gzipped, rest deleted) — see make_rotator.
`size_tiered` uses a timestamped per-roll namer (make_size_namer) instead of the
default one, for a tiered RotatingFileHandler (size mode): stdlib's `.1/.2` numbered
shift can't manage files redirected into log_dir, so each roll gets a unique dated
name that retier ranks/tiers like the daily/on_start paths.
""" """
namer = make_namer(log_dir, compress) if size_tiered:
namer = make_size_namer(os.path.basename(prune_stem or ""), log_dir)
else:
namer = make_namer(log_dir, compress)
rotator = make_rotator( rotator = make_rotator(
compress, log_dir, prune_stem, backup_count, keep_uncompressed, keep_compressed, compress, log_dir, prune_stem, backup_count, keep_uncompressed, keep_compressed,
) )
+15 -1
View File
@@ -128,12 +128,18 @@ def _file_handler(
"""build the configured file handler with custom rolling into log_dir""" """build the configured file handler with custom rolling into log_dir"""
tiered = keep_uncompressed is not None or keep_compressed is not None tiered = keep_uncompressed is not None or keep_compressed is not None
if rotate == "size": if rotate == "size":
# stdlib doRollover is a no-op when backupCount == 0, and its numbered .1/.2 shift
# can't manage files redirected into log_dir. in tiered size mode force a nonzero
# backupCount so the roll always fires (retier bounds retention, not backupCount)
# and use the timestamped size-namer (size_tiered) instead of the .N shift.
size_backup = backup_count if not tiered else max(backup_count, 1)
handler = logging.handlers.RotatingFileHandler( handler = logging.handlers.RotatingFileHandler(
live_path, maxBytes=max_bytes, backupCount=backup_count, encoding="utf-8", live_path, maxBytes=max_bytes, backupCount=size_backup, encoding="utf-8",
) )
attach_rolling( attach_rolling(
handler, log_dir, compress, prune_stem=name, backup_count=backup_count, handler, log_dir, compress, prune_stem=name, backup_count=backup_count,
keep_uncompressed=keep_uncompressed, keep_compressed=keep_compressed, keep_uncompressed=keep_uncompressed, keep_compressed=keep_compressed,
size_tiered=tiered,
) )
elif rotate == "daily": elif rotate == "daily":
handler = logging.handlers.TimedRotatingFileHandler( handler = logging.handlers.TimedRotatingFileHandler(
@@ -153,6 +159,14 @@ def _file_handler(
else: else:
rotate_on_start(live_path, log_dir, compress) rotate_on_start(live_path, log_dir, compress)
prune(log_dir, name, backup_count) prune(log_dir, name, backup_count)
elif rotate is not None:
# a typo'd rotate value (e.g. "hourly") would otherwise silently fall through
# to a non-rotating FileHandler and grow forever — warn, matching the
# unknown-`output` convention, rather than degrade silently
log.warning(
"log_setup: unknown rotate %r; expected 'daily'/'size'/'on_start'/None — "
"no rotation applied (single growing file)", rotate,
)
handler = logging.FileHandler(live_path, encoding="utf-8") handler = logging.FileHandler(live_path, encoding="utf-8")
return handler return handler