From b52c1d37fa04d52c2106f3af9a629d86d4c5010d Mon Sep 17 00:00:00 2001 From: disqualifier Date: Wed, 1 Jul 2026 00:28:18 -0400 Subject: [PATCH] =?UTF-8?q?fix:=20LOW/nit=20clearance=20=E2=80=94=20retier?= =?UTF-8?q?=20twin=20dedupe=20+=20same-second=20counter=20ordering,=20warn?= =?UTF-8?q?=20on=20unknown=20rotate?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - 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 --- README.md | 7 ++-- pyproject.toml | 2 +- src/log_setup/__init__.py | 2 +- src/log_setup/rotation.py | 77 ++++++++++++++++++++++++++++++++++++--- src/log_setup/setup.py | 8 ++++ 5 files changed, 86 insertions(+), 10 deletions(-) diff --git a/README.md b/README.md index f8c30d6..1ce6fdc 100644 --- a/README.md +++ b/README.md @@ -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@v0.4.2 +log_setup @ git+ssh://git@git.rethinkstudios.io/rethink-public/log_setup.git@v0.4.3 ``` No dependencies — stdlib only. -Drop the `@v0.4.2` 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 @@ -45,7 +45,8 @@ emits; the records land in the configured root. - **Rotation** (`rotate=`): - `"daily"` (default) — rolls at midnight, dated name into `log_dir`, keeps `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` (`run..log[.gz]`) and starts fresh; prunes to `backup_count`. - `None` — single file, no rotation. diff --git a/pyproject.toml b/pyproject.toml index 54431a6..db57c03 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -4,7 +4,7 @@ build-backend = "hatchling.build" [project] name = "log_setup" -version = "0.4.2" +version = "0.4.3" description = "stdlib app-entry-point logging setup: live run.log, rotation, gzip, retention, consistent format" requires-python = ">=3.10" dependencies = [] diff --git a/src/log_setup/__init__.py b/src/log_setup/__init__.py index 7324eec..8a961d8 100644 --- a/src/log_setup/__init__.py +++ b/src/log_setup/__init__.py @@ -19,4 +19,4 @@ from .setup import setup_logging __all__ = ["setup_logging"] -__version__ = "0.4.2" +__version__ = "0.4.3" diff --git a/src/log_setup/rotation.py b/src/log_setup/rotation.py index 467d9a9..f28f1a1 100644 --- a/src/log_setup/rotation.py +++ b/src/log_setup/rotation.py @@ -32,6 +32,24 @@ 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 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: """gzip source into dest then remove source (the rolled-file compression idiom) @@ -111,8 +129,11 @@ def make_rotator( return if tiered: # dest carries the namer's .gz suffix in compress mode; strip it so the - # freshly-rolled file lands plain and retier decides its tier - plain_dest = dest[:-3] if dest.endswith(".gz") else dest + # freshly-rolled file lands plain and retier decides its tier. disambiguate a + # 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) 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) @@ -183,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. "sub/run") must be matched by "run." here or nothing matches and retention silently 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..log / run..1.log) + still tiers newest-first correctly rather than falling back to arbitrary listdir order. """ stem = os.path.basename(stem) try: @@ -193,11 +218,26 @@ def retier(log_dir: str, stem: str, keep_uncompressed: int, keep_compressed: int except OSError: return 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)] - files.sort(key=lambda pair: pair[1], reverse=True) + # dedupe plain/gz twins FIRST (a crash between _gzip_file's write and its os.remove can + # leave .log beside .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 - for index, (path, _) in enumerate(files): + for index, (path, _, _) in enumerate(files): if index >= keep: try: os.remove(path) @@ -206,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"): dest = path + ".gz" 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 try: _gzip_file(path, dest) @@ -213,6 +261,25 @@ def retier(log_dir: str, stem: str, keep_uncompressed: int, keep_compressed: int 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: `.[.].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 (`.log.`) 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: """keep only the newest `backup_count` rolled files for a given stem in log_dir diff --git a/src/log_setup/setup.py b/src/log_setup/setup.py index 65f461f..22d2900 100644 --- a/src/log_setup/setup.py +++ b/src/log_setup/setup.py @@ -159,6 +159,14 @@ def _file_handler( else: rotate_on_start(live_path, log_dir, compress) 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") return handler