opentelemetry-instrument and logs SDK cause logs to be swallowed by default

[aabmass]

Linux, python3.9

Steps to reproduce
In a fresh venv

pip install opentelemetry-distro opentelemetry-instrumentation
opentelemetry-instrument python -c 'import logging; logger = logging.getLogger("foo"); logger.error("oh no")'

What is the expected behavior?
See the error printed to the console

What is the actual behavior?
No output

Additional context
I believe the LogHandler is being installed on the root logger, but there is no log processor/exporter. Which causes logging to be no-op!

[srikanthccv]

@aabmass You are using the logging.error instead of logger.error. Can you confirm "oh no" printed to console if logger is used? Still a bug though.

[aabmass]

Oops. Yes it's the same behavior. Updated the issue description

[srikanthccv]

I think I know what's happening. When we log a message, logging.basicConfig will be called and StreamHandler is added. But the basicConfig does nothing if there are some handlers already configured. Since we are adding OTELHandler during auto-instrumentation pipeline early any later call to basicConfig is ineffective and StreamHandler is never appended (unless someone calls basicConfig with force=True) Which is why error is not printed to console.

[srikanthccv]

catch-22 situation - If we add logging.basicConfig() call here this issue should get fixed but can be surprising for users who might have their custom logging.basicConfig(config) in application code. If we don't then the current issue exists and can be problematic. Any ideas?

[srikanthccv]

I can't think of any better solution than disabling the logging auto instrumentation. Does anyone have other ideas?

[moriyoshi]

Please do so and let me get some good sleep... Apologies for being unprofessional.

[aabmass]

catch-22 situation - If we add logging.basicConfig() call here this issue should get fixed but can be surprising for users who might have their custom logging.basicConfig(config) in application code.

@srikanthccv I think it's reasonable to expect autoinstrumentation to mess with existing logging pipelines. If they want to override, they can do force=True like you mentioned. OTOH, I think printing logs to stdout should still happen by default.

Maybe the least surprising behavior would be to have our log handler off by default, and only turn it on if an logs exporter is specifically configured (or have another flag). How important is it for first time autoinstrumentation users to have logs automagically sent to the collector?

[srikanthccv]

Maybe the least surprising behavior would be to have our log handler off by default, and only turn it on if an logs exporter is specifically configured (or have another flag).

Yes, we discussed this in today's meeting. We agreed on disabling the logging pipeline setup by default but introduce a flag or env which can be used to enable this with clear documentation until we find a clean solution. I think some people have applications where basicConfig is invoked prior to our _init_logging setup call and it's working fine for them.

How important is it for first time autoinstrumentation users to have logs automagically sent to the collector?

Not sure about the importance. We are doing this out of the box automatic pipeline setup for each signal as soon as they have good SDK support.

[aabmass]

Great thank you! Let's leave this issue open after the temp fix is made to see if someone has a better idea.

As a crazy idea, we could patch logging.basicConfig in the autoinstrumentation agent to make it do the behavior we want.