Skip to content

Propagate structlog records to the root handler and remove MemoryLoggerFactory - #405

Merged
lesnik512 merged 1 commit into
mainfrom
structlog-propagate-to-root
Oct 29, 2026
Merged

lesnik512 merged 1 commit into
mainfrom
structlog-propagate-to-root

Conversation

@lesnik512

Copy link
Copy Markdown
Member

Closes #381.

MemoryLoggerFactory gave every stdlib logger that structlog used its own StreamHandler and set propagate = False. Its formatter printed record.getMessage() as is, so once structlog had used a logger name, stdlib records on that logger and its children were printed as plain text, with no JSON and no traceback. FastStream hit this out of the box, because it logs through structlog.get_logger("faststream"). The check and the addHandler were also not atomic, so concurrent first use of a name could add two handlers and print every line twice.

structlog records now propagate to the root handler like any other record, and the factory is gone.

Code

  • The structlog chain ends with _mark_rendered, after JSONRenderer. It wraps the rendered line in _RenderedLine, an empty str subclass.
  • The root handler's formatter is _RenderedLinePassthroughFormatter, a ProcessorFormatter subclass. A record whose msg is a _RenderedLine is emitted as is. Any other record goes through the foreign chain as before.
  • LoggingInstrument and LitestarLoggingInstrument pass a plain structlog.stdlib.LoggerFactory(). MemoryLoggerFactory, _MemoryLoggerFactoryConfig, _RenderedLineFormatter, LoggingInstrument.memory_logger_factory and the factory step in teardown are removed.
  • Litestar's stdlib config sets propagate: True on the litestar logger. Its False came from fix: keep lite-bootstrap's root log handler on Litestar and write litestar records once #345, when lite-bootstrap's handler sat on that logger.
  • FastStreamLoggingInstrument sets propagate = True on the faststream logger after clearing its handlers, and restores the old value at teardown. FastStream ships that logger with propagate = False and a stderr handler, so without this its lines would go nowhere.
  • The factory used to set a level on each logger it created. Now those loggers inherit the root level, which LoggingInstrument sets to logging_log_level.

Tests

Written first, failing on main:

  • test_stdlib_lines_on_a_structlog_logger_name_stay_json: the issue's repro. Every line is JSON, and the exception line carries the traceback.
  • test_concurrent_first_use_of_a_logger_name_writes_each_line_once: 8 threads use a new name at once. The logger has no handlers, and each line appears once.
  • test_faststream_logging_replaces_faststream_stderr_handler now logs through structlog, the faststream stdlib logger and a child, checks all three reach stdout, and checks that handlers and propagate are restored.
  • test_litestar_access_log_is_written_once replaces test_litestar_access_log_has_one_handler: the litestar logger has no handlers, and the access log lines appear once on stdout.

The five test_memory_logger_factory_* tests and the two teardown tests that patched close_handlers are removed with the factory. test_unnamed_structlog_logger_is_named_after_its_caller keeps the one factory behaviour that still matters.

The suite passes, 587 tests at 100% coverage (just test-ci). just lint (including ty), just adr-check and just docs-build pass too. No floor changes.

Performance

Per log call, on macOS (Apple M2, CPython 3.14.7), with only lite-bootstrap's handler on root and output to /dev/null. Each value is the median of 7 rounds of 100,000 calls. Main and this branch were run alternately, 4 rounds each:

call main this branch
structlog.get_logger("bench").info("did a thing", a=1) 8.99 to 9.05 µs 9.22 to 9.25 µs
logging.getLogger("lib").info("did a thing %s", 1) 11.00 to 11.12 µs 11.11 to 11.18 µs

One branch round was an outlier at 10.67 µs and 11.66 µs, and is left out of the ranges. A structlog line costs about 0.2 µs more, for the walk up to root and the formatter's type check. A stdlib line costs the same.

I tried passing the flag as extra first. That cost about 0.7 µs per line, since makeRecord then sets each extra key on every record. The str subclass costs one string copy instead.

benchmarks/frameworks/bench.py logging can't show this comparison. one.py calls logging.basicConfig(stream=_Sink()) before every suite, so root has a second handler with a default Formatter. structlog records skipped it on main and reach it now, and that sink adds about 2 µs, which is in the harness, not in lite-bootstrap. On main, stdlib records already went through the sink, so the stdlib rows in section 8f include it. Fixing the harness changes the baseline of every suite, so it is not part of this PR.

Docs

  • configuration.md, "Structlog": says both kinds of record go through one root handler, so stdlib lines on a structlog name are JSON and a handler on root sees structlog records.
  • benchmarks/README.md, 8f: the chain description says records go through the root handler.

Breaking changes

  • Stdlib records on a logger name structlog has used, and on its children, are JSON lines now, instead of the bare message.
  • structlog records propagate to the root logger. A handler you add to root, or to a parent logger, now receives them.
  • MemoryLoggerFactory (lite_bootstrap.instruments.logging_instrument) and LoggingInstrument.memory_logger_factory are removed.
  • Loggers structlog uses no longer get their own level. They inherit root's.
  • On Litestar, the litestar logger propagates to root. On FastStream, the faststream logger propagates to root while bootstrapped.

…erFactory

Stdlib records on a logger name structlog has used now come out as JSON,
and concurrent first use of a name no longer adds a second handler.

Closes #381.
@lesnik512 lesnik512 added this to the 2.0.0 milestone Oct 29, 2026
@lesnik512
lesnik512 merged commit 032ffe8 into main Oct 29, 2026
35 checks passed
@lesnik512
lesnik512 deleted the structlog-propagate-to-root branch October 29, 2026 20:42
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.

Stop giving structlog loggers their own handler, so stdlib lines on the same names stay JSON

1 participant