Ensure a console logging handler is set when using auto-instrumentation

[pmcollins]

If a user sets up auto-instrumentation and sets OTEL_PYTHON_LOGGING_AUTO_INSTRUMENTATION_ENABLED to true, any calls to logging.basicConfig() will be no-ops. This means that if console logging was previously enabled via basicConfig and logs were printed to the console, after turning on logging auto-instrumentation, logs will be exported to OTel and will no longer be printed to the console.

This change patches basicConfig so that before calling basicConfig, the patched version removes the OTel logging handler if it was added, then calls the original basicConfig, then re-adds the handler.

Addresses #4427

[jeremydvoss]

While I think we should make sure to keep the Streamlogger, I want to make sure the solution works for basicConfig in general. In other words, if a customer specifies the following with autoinstrumentation, their root logger should have filename and otel handlers the former with the CUSTOM FORMAT and the latter with the format specified by OTEL_PYTHON_LOG_FORMAT

basicConfig(
    filename='example.log',
    format="CUSTOM FORMAT %(levelname)s:%(name)s:%(message)s",
)

Furthermore, I like the idea of being able to enable/disable this feature. However, I don't understand tying it to OTEL_PYTHON_LOG_FORMAT

[jeremydvoss]

The more I think about this, it might be best to actually let the logging sdk not log to console but fix basicConfig so that customers can choose to keep a StreamHandler. Logging outputs to console if and only if there is no logging handler all the way from the triggered handler up to the root. However, it's not actually adding a StreamHandler it's just the default behavior when there is no handler. So, I don't think we should actively add a StreamHandler ourselves. (open to disagreement)

What if we instead keep that pythonic idea that console output should just be the default while allowing users to add the following manually if they want to keep console logs:

basicConfig(
    handlers= [StreamHandler()],
    format=...,
)

Then, we could monkey patch the logging library like so:

def basicConfig(**kwargs):
    ...
    try:
        ...
        # if len(root.handlers) == 0: #REPLACE THIS LINE
        no_handlers_besides_otel = True
        from opentelemetry.sdk._logs import LoggingHandler
        for handler in root.handlers:
            if not isinstance(handler, LoggingHandler):
                no_handlers_besides_otel = False
                break
        if no_handlers_besides_otel:
            # Do stuff

[pmcollins]

Thanks for the detailed feedback and the suggestions, @jeremydvoss. I hadn’t gone down this route initially because I wanted to explore approaches that didn’t involve monkey-patching, but I think this is a practical and customer-friendly way forward. I’ll look into updating the PR with a proposal.

[pmcollins]

Ok so now this PR patches basicConfig: the patch first removes any OTel LoggingHandler (OTel's implementation of Python's logging.Handler) added by auto-instrumentation, then calls the original basicConfig, then adds the LoggingHandler back again. Works on my machine 🎉. However, you can still see a difference in console logging behavior in that if you don't call basicConfig or set up a logging handler, you get unformatted logs, in which case if you then set up OTel logging, those unformatted logs will no longer be printed because now there's a handler (OTel). Not sure how important this case is, but I suppose we could consider patching additional parts of Python's logging code to handle it.

[pmcollins]

Just noticed there's a PR that uses the same env var I proposed above, but for a different purpose.

[xrmx]

Other than the small comment this looks fine to me. Tested with an aiohttp web app and behaves as advertised.

[aabmass]

LGTM but we should still consider moving this and LoggingHandler into an instrumentation (#4330)

[emdneto]

Also tested with flask/fastapi workloads and it's working as expected. Now I can see the logs in the console as well.