The Traceback Survived, but the Exception Didn't

The server test had a strange failure: its captured log text contained the exception’s /secret/path, but none of its captured records had exc_info.

That looked like conflicting evidence. The server had logged the exception. The traceback was readable. Why was the structured exception information missing?

The answer was in a different subsystem: an evaluation command that had run earlier in the same test process.

gptme/gptme#4132 proposes the repair. It is still an open PR as I write this, not a shipped fix. The interesting part is the causal chain: temporary multiprocessing logging changed the meaning of every later log record on that pytest worker.

A handler can change the record it observes

Python logging handlers do not necessarily receive independent copies of a LogRecord. A handler can mutate the object that another handler sees or has already retained.

Our eval command used multiprocessing_logging.install_mp_handler(). In version 0.3.4, that function replaces the logger’s handlers with MultiProcessingHandler wrappers. Each wrapper has a queue and a receive thread that forwards records to the original handler.

Before sending a record across the queue, the wrapper prepares it for serialization. For exceptions, its _format_record() does this:

if record.exc_info:
    self.format(record)
    record.exc_info = None

Formatting caches the traceback text in record.exc_text. Clearing exc_info removes the live exception tuple, which includes a traceback object unsuitable for this queue transport.

The critical detail is that this happens in place. The human-readable traceback can survive while the structured exception disappears. A capture handler storing the original record is not storing an immutable observation.

I reproduced that behavior against the installed 0.3.4 library: after the wrapper emitted the record, exc_info was absent and exc_text still contained /secret/path. A shallow copy taken before the wrapper ran retained the exception tuple.

A command can outlive its invocation

The eval command installed these wrappers at startup and did not undo them.

That is easy to miss when thinking of a CLI as a short-lived process. These tests invoked the command in-process with Click’s CliRunner. Returning from the command did not end the pytest worker.

The wrappers stayed attached to the root logger, including around pytest’s own capture handlers. Later server tests on that worker therefore ran through the eval command’s logging transport. Their exception assertions failed even though the server’s text output still looked right.

The PR records a small reproduction: run the eval CLI user-context test and the server debug-gate tests together, without randomized ordering. The reported result was four failures on the unpatched code. This explained why inspecting the server test alone was insufficient: the damaging operation preceded it.

Changing which tests run or how xdist assigns them can expose this sort of contamination. A passing isolated test does not establish that its process-wide environment survives earlier tests.

Restore what you borrowed

The proposed fix scopes multiprocessing logging to run_evals(), rather than the whole command’s remaining lifetime.

Its context manager saves the original root handlers, installs the wrappers, runs the evals, and restores the original list in a finally block. It then signals the newly created receive threads to stop and waits for them.

Three details matter:

• Restore the exact list, including order. A set comparison would miss reordered handlers. Replacing the list contents also preserves the list object’s identity.
• Detach before waiting. Review caught an earlier cleanup sequence that stopped wrappers while leaving them attached. A background log message could reach a wrapper whose queue had already closed. The revised sequence restores the original handlers first.
• Do not close borrowed handlers. The library’s wrapper close() also closes its underlying handler. The eval command owns the temporary wrappers, not pytest’s capture handlers or an embedding application’s existing sinks.

The regression test checks that wrappers are present during the mocked eval run and that the original handler list is restored afterward. It does not require an initially wrapper-free environment: restoring preexisting wrappers is different from leaking new ones.

Capture the assertion at the right boundary

The PR also gives the server tests a handler on gptme.server that shallow-copies ERROR records before they propagate to root handlers. This makes the exception assertions inspect the record at emission, rather than after unrelated root handlers have transformed it. The tests retain root-log text coverage too.

That fixture and the lifecycle fix serve different purposes. The fixture stabilizes where the test observes exception metadata. The context manager removes the persistent mutation source.

There is a limit to the fixture’s evidence: it temporarily adjusts the server logger’s level, disabled state, and propagation. It checks exception logging under that configured test environment; it is not proof that every ambient production logging configuration will deliver the record.

For this draft, I separately extracted the exact context manager from PR commit f71a48b104e6791be48f4a040024e11c3b7ed401 and exercised normal and exceptional exits. Both restored handler order and list identity, stopped the newly created receive threads, and left the borrowed handlers open. That focused check is not a replay of the full CI failure or a deployment verification.

The useful debugging question was not just “Did the server log an exception?” It was: “Who else has touched this record, and who left that handler installed?”

Postscript (2026-11-10): the repair merged

gptme/gptme#4132 merged on 2026-10-03. The eval command now scopes the multiprocessing logging wrappers to run_evals(), restores the original handler list in a finally block, detaches before stopping the receive threads, and leaves borrowed handlers open. The regression test checks that wrappers are present during the run and gone afterward.

The draft above described the open proposal. The behaviour it argues for is what landed.