Skip to content

fix(logging): restore handlers and formatters on uninstrument - #4982

Draft
sidsri14 wants to merge 2 commits into
open-telemetry:mainfrom
sidsri14:fix/logging-uninstrument-restore-format
Draft

fix(logging): restore handlers and formatters on uninstrument#4982
sidsri14 wants to merge 2 commits into
open-telemetry:mainfrom
sidsri14:fix/logging-uninstrument-restore-format

Conversation

@sidsri14

Copy link
Copy Markdown

Description

Fixes #4949.

When LoggingInstrumentor().instrument(set_logging_format=True) is called, logging.basicConfig() configures or attaches root handlers with a format string interpolating OpenTelemetry trace context fields (%(otelTraceID)s, %(otelSpanID)s, etc.).

During _uninstrument(), the log record factory was restored to _old_factory, but the format string remained active on the root logger's handlers. Because newly created LogRecord instances no longer carried otelTraceID, any record logged after uninstrument() failed to format, causing silent log dropping and ValueError: Formatting field not found in record: 'otelTraceID' via Handler.handleError.

Changes

  1. In _instrument(): When set_logging_format is active, capture the pre-instrumentation root logger state (level, handlers, and existing formatters).
  2. In _uninstrument(): Restore the root logger level, restore previous formatters on pre-existing handlers, and remove any handlers added during instrumentation.
  3. In tests/test_logging.py: Added unit tests verifying:
    • Logging after uninstrument() succeeds without KeyError / ValueError on formatting.
    • Pre-existing handler formatters are accurately restored after an instrument/uninstrument cycle.

Type of change

  • Bug fix (non-breaking change which fixes an issue)
  • New feature (non-breaking change which adds functionality)
  • Breaking change (fix or feature that would cause existing functionality to not work as expected)
  • This change requires a documentation update

How Has This Been Tested?

  • Ran pytest instrumentation/opentelemetry-instrumentation-logging/tests: all 73 tests passed.
  • Added regression tests covering both freshly configured and pre-configured logging handlers across instrument/uninstrument cycles.

Checklist:

  • Followed the style guidelines of this project
  • Unit tests have been added
  • Documentation has been updated

When LoggingInstrumentor.instrument(set_logging_format=True) is called, basicConfig adds or configures root handlers with a format string interpolating %(otelTraceID)s, %(otelSpanID)s, etc.

During _uninstrument, the log record factory is restored to the old factory, so subsequent log records no longer contain otelTraceID.
However, because the format string remained in place on root handlers, any record logged after uninstrument failed to format with a KeyError/ValueError.

This captures the root level, handlers, and formatters before basicConfig and restores them upon _uninstrument.
@HarperZ9

Copy link
Copy Markdown

Nice, this is a real gap (#4949). Two things I noticed:

The cleanup removes more than it should — old_handlers is snapshotted before basicConfig, and uninstrument drops everything not in that set. So if the app adds its own handler after instrument(), uninstrument silently removes it too (on a handler-less root old_handlers is empty, so both the otel handler and the user's get dropped). Better to record just what basicConfig actually added (diff the root's handlers right after the basicConfig call) and remove only those.

The formatter-restore test also doesn't exercise the restore: test_uninstrument_restores_preexisting_handler_formatter adds the handler before instrument(), and basicConfig no-ops when the root already has handlers, so the formatter is never changed — the assertion passes even with the restore branch deleted. Starting from a handler-less root (so basicConfig runs), then checking the added handler is gone and root.level is restored, would actually test it.

Addresses review feedback on open-telemetry#4982: the previous approach snapshotted
all root handlers before basicConfig and dropped anything not in that
set on uninstrument, silently removing handlers the application added
while instrumented. Record only the handlers basicConfig actually added
and remove exactly those. Rewrite the test to start from a handler-less
root so basicConfig runs, and verify the app-added handler survives
uninstrument while the root level is restored.

Assisted-by: Claude Sonnet 4.6
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.

LoggingInstrumentor: uninstrument() leaves the basicConfig format string asking for otel fields, so every later record fails to format

2 participants