fix(auto-instrumentation): print debug startup messages

[pmcollins]

Description

Writes auto-instrumentation startup debug messages to stderr when OTEL_LOG_LEVEL=debug or OTEL_LOG_LEVEL=trace is set. This makes it easier to see which distro and instrumentors were loaded during opentelemetry-instrument startup.

If Python logging is already configured to handle these debug messages, the new stderr output is suppressed to avoid double logging.

Fixes #4540

Type of change

• Bug fix (non-breaking change which fixes an issue)

How Has This Been Tested?

• Ran python -m unittest opentelemetry-python-contrib/opentelemetry-instrumentation/tests/auto_instrumentation/test_load.py
• Ran oteltest with local packages and confirmed the expected stderr debug messages

Does This PR Require a Core Repo Change?

• No.

Checklist:

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

[emdneto]

Thanks for the PR!

Just a heads-up: we no longer update CHANGELOG.md directly. The changelog is now generated from changelog fragments using Towncrier.

Please add the appropriate changelog fragment for this change instead of editing CHANGELOG.md manually. You can find the instructions and expected format in CONTRIBUTING.md.

[Copilot]

Pull request overview

Adds early-startup visibility for auto-instrumentation by emitting selected debug startup messages to stderr when OTEL_LOG_LEVEL requests debug/trace, while suppressing stderr output if Python logging is already configured to emit those messages.

Changes:

• Introduces _OtelLogLevelLoggerAdapter to mirror startup debug logs to stderr when they would otherwise be dropped.
• Adds unit tests covering stderr emission/suppression based on OTEL_LOG_LEVEL and logger handler hierarchy.
• Adds a changelog fragment documenting the fix.

Reviewed changes

Copilot reviewed 3 out of 3 changed files in this pull request and generated 1 comment.

File	Description
opentelemetry-instrumentation/src/opentelemetry/instrumentation/auto_instrumentation/_load.py	Adds a logger adapter that conditionally writes startup debug messages to stderr based on OTEL_LOG_LEVEL and handler configuration.
opentelemetry-instrumentation/tests/auto_instrumentation/test_load.py	Adds tests validating stderr output behavior and suppression when logging handlers would emit.
.changelog/4542.fixed	Documents the new stderr startup debug output behavior.

Comments suppressed due to low confidence (2)

opentelemetry-instrumentation/src/opentelemetry/instrumentation/auto_instrumentation/_load.py:73

• The adapter manually formats messages via % to build the stderr output. If a call site passes mismatched format args (or mapping-style args), this will raise and could break auto-instrumentation startup, whereas the standard logging pipeline typically swallows formatting errors inside handlers. Consider using a LogRecord/Formatter (e.g., record.getMessage()) or guarding the formatting with a try/except fallback so stderr emission can’t crash startup.

        message = msg
        if args:
            message = message % tuple(_format_log_arg(arg) for arg in args)

        stderr.write(f"DEBUG:{self.logger.name}:{message}\n")
        stderr.flush()

opentelemetry-instrumentation/src/opentelemetry/instrumentation/auto_instrumentation/_load.py:58

• The docstring says this writes “the same startup messages” to stderr, but _format_log_arg() wraps string args with repr(), so stderr output will differ from the normal logging output for the same call (%s becomes quoted). Either adjust the wording to reflect that stderr output is intentionally different, or change formatting so both channels render the same message.

    """Write startup debug messages to stderr when logging would drop them.

    Auto-instrumentation usually runs from sitecustomize before the
    application configures logging, so normal logger.debug calls are often
    not visible even when OTEL_LOG_LEVEL=debug. This adapter keeps normal
    logging behavior, but also writes the same startup messages to stderr when
    OTEL_LOG_LEVEL asks for debug output and Python logging would not emit them.
    """

[aabmass]

does this behave the same as usual logging calls like logging.info() calls work?

[pmcollins]

Not quite -- it's simplified and tweaked a little just for this narrow, local use case. It puts quotes around string arguments so the output looks like this:

DEBUG:opentelemetry.instrumentation.auto_instrumentation._load:Distribution 'distro' will be configured
DEBUG:opentelemetry.instrumentation.auto_instrumentation._load:Instrumented 'requests'

I added a catch all exceptions guard though.

[aabmass]

I guess that's ok, but we could use a real handler in theory. Just wondering why you didn't take that approach

[aabmass]

I think the default in python is warning and above. Does this handle just debug or does it also print info level?

[pmcollins]

It doesn't print at info level, but maybe it should -- idk. WDYT?

[aabmass]

If we print debug logs, I would expect debug and higher to also print

[xrmx]

Maybe a silly question: why are we not setting up our own handler?

[herin049]

Maybe a silly question: why are we not setting up our own handler?

Presumably to prevent double logging if there is also a user-defined handler.

[pmcollins]

Maybe a silly question: why are we not setting up our own handler?

Not a silly question -- I'm happy to set up a handler if folks prefer, but my understanding is that that would be more within the purview of the application, and that we, as a library, should just call the logging API and not attempt to configure logging. For this issue, we're in a middle ground, where we want to log, but we don't want to configure logging, and the application typically hasn't had a chance to do so either, so we just print these startup messages to stderr.