Skip to content

Evaluate every rotation condition so a skipped one cannot fire spuriously - #1515

Open
januththedev wants to merge 1 commit into
Delgan:masterfrom
januththedev:fix/rotation-evaluate-all-conditions
Open

januththedev wants to merge 1 commit into
Delgan:masterfrom
januththedev:fix/rotation-evaluate-all-conditions

Conversation

@januththedev

Copy link
Copy Markdown

Rotation: every condition is now evaluated, so a skipped one cannot fire spuriously

Disclosure, as required by the Automated Contributions Policy in CONTRIBUTING.rst: this bug was found, proved, and fixed with the assistance of an LLM. I have reviewed the change line by line and verified the tests myself. There is no LLM co-author on the commit.

Description

A list of rotation conditions is combined with any():

def __call__(self, message, file) -> bool:
    return any(rotation(message, file) for rotation in self._rotations)

any() over a generator short-circuits. That is fine for the return value, but each RotationTime condition is stateful: it lazily computes self._limit on first call and then advances it as a side effect of being invoked (loguru/_file_sink.py:154-157, the while self._limit <= record_time: self._step_forward(...) catch-up loop).

When the first condition returns True, the remaining conditions are never invoked, so their _limit is never advanced past the current time. A skipped condition is left holding a limit that is now in the past, and it therefore fires on the very next logged message — producing a second, immediate, spurious rotation.

Reproduction

logger.add(path, rotation=["13:00", "12:00"]), file created at 06:00, process idle until 13:00:01, then two messages:

before — 3 files (BUG):
  file.2020-01-01_06-00-00_000000.log     'a\n'
  file.2020-01-01_13-00-01_000000.log     'b\n'    <-- spurious extra rotation
  file.log                                'c\n'

after — 2 files (correct):
  file.2020-01-01_06-00-00_000000.log     'a\n'
  file.log                                'b\nc\n'

Message "b" legitimately rotates at 13:00:01; "c" should not. The "12:00" condition's stale 2020-01-01 12:00 limit is what caused the second rotation.

The change

# Note that the conditions must all be evaluated, even after one of them returned
# True, because "RotationTime" instances keep their limit up-to-date as a side-effect
# of being called. Skipping them would leave a stale limit in the past, causing a
# spurious extra rotation on the next logged message.
should_rotate = False
for rotation in self._rotations:
    if rotation(message, file):
        should_rotate = True
return should_rotate

This keeps the documented "any of which can trigger the rotation" contract for the return value while restoring the side effect the conditions rely on.

Tests

test_multiple_rotation_conditions_all_evaluated is added to tests/test_filesink_rotation.py.

  • Fails before the change with assert 3 == 2; passes after.
  • pytest tests/test_filesink_rotation.py → 147 passed, 4 skipped (146 before).
  • Filesink suites → 251 passed, 6 skipped.
  • Full suite → 1646 passed, 70 skipped, 0 failed. The baseline on unmodified HEAD was 1645 passed, 0 failed, so the delta is exactly this one test.
  • ruff check clean.

One note: ruff format --check reports one pre-existing trailing-comma difference at _file_sink.py:189 (**kwargs vs **kwargs,) because my ruff differs from the pinned v0.15.7. I left it untouched.

The list-of-conditions feature itself is unreleased (still in Unreleased from #1174), so the changelog entry is filed under that issue rather than needing a new one.

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant