repowise-dev / repowise-dev/repowise

silence_logs_for_machine_output mutates global logger levels with no restore, so caplog assertions fail only in a full test run

Open
#1,976 5 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

bug
Dominant language
Python
Stars
6.7k
Forks
711
Avg merge
1d 13h
Merged PRs (30d)
439

Description

silence_logs_for_machine_output in packages/cli/src/repowise/cli/helpers.py:75 raises the level on two ancestor loggers and never restores it:

logging.getLogger("httpx").setLevel(logging.ERROR)
logging.getLogger("httpcore").setLevel(logging.ERROR)
for _name in ("repowise.core", "repowise.server"):
    logging.getLogger(_name).setLevel(logging.ERROR)

That is correct for the command that calls it, which is emitting JSON or Markdown on stdout and cannot have log lines corrupting it. The problem is that logger levels are process-global and there is no teardown, so in a test session the mutation outlives the test that triggered it.

Any later test asserting on a logging record from a module under repowise.core or repowise.server reads an empty caplog. The module's own logger has no level set, so its effective level is inherited from repowise.core, which is now ERROR, and logger.warning(...) is dropped before any handler runs. The test passes when the file is run alone and fails in a full run, depending only on whether a --format json command has executed yet.

tests/conftest.py already has an autouse _isolate_structlog_config fixture that snapshots and restores structlog config for exactly this reason, and its docstring describes the same failure:

a filtering logger drops the event before LogCapture ever runs and the test reads an empty list. Tests collected after tests/unit/cli therefore pass alone and fail in a full run.

There is no stdlib equivalent, which is the gap.

Seen in the wild. PR #1882 added a guard around LanceDBVectorStore.list_page_ids with a test asserting the warning is emitted. The behaviour assertion passes; the caplog assertion fails on all three Pythons in CI and passes locally on a focused run. The contributor ran 49 relevant tests green and had no way to see it.

Two things worth doing, probably together:

  1. An autouse fixture in tests/conftest.py that snapshots the levels of the loggers this helper touches and restores them after each test, mirroring _isolate_structlog_config. Cheap and fixes every future instance.

  2. Give silence_logs_for_machine_output a restore path so it is not a one-way door outside tests either. A context manager, or a companion that puts the previous levels back, would mean a library caller invoking a repowise command in-process does not permanently silence their own logging. That is arguably the real bug, and the test breakage is a symptom.

Worth adding a note to CONTRIBUTING.md too: a test asserting on a log record needs caplog.set_level(..., logger="<the module's full logger name>"), because setting the root is not enough when an ancestor is raised.

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start with packages/cli/src/repowise/cli/helpers.py:75 and inspect callers of silence_logs_for_machine_output. Read the _isolate_structlog_config fixture in tests/conftest.py and the caplog-related tests described in the issue. Done means logger state is isolated after tests, in-process command use has a restore path, and the relevant warning assertion passes in a full test run.

Written by the indexing model from the issue text.

Assessment

Tech stack
python
Domain
cli, documentation, testing-qa
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Active
Clarity
Mostly clear
Newbie friendliness
57/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.