Verbose logs are emitted at INFO level when telemetry is sent to Application Insights

[shingotoda]

• Package Name: azure-monitor-opentelemetry
• Package Version: 1.1.1
• Operating System: MacOS, Debian (bullseye)
• Python Version: 3.11

Describe the bug
I am writing Django app and implementing instrumentation with azure-monitor-opentelemetry. I set it up to have a named logger and set log level to WARNING. The following is the code to do this.

    from azure.monitor.opentelemetry import configure_azure_monitor
    configure_azure_monitor(logger_name='myapp')
    logger = logging.getLogger('myapp')
    logger.setLevel(logging.WARNING)

But I see the following message is emitted to stdout then results in being ingested to Log Analytics workspace, looks like this is a HTTP request log to send telemetry to application insights.

INFO Request URL: 'https://japaneast-1.in.applicationinsights.azure.com//v2.1/track'
Request method: 'POST'
Request headers:
    'Content-Type': 'application/json'
    'Content-Length': '893'
    'Accept': 'application/json'
    'x-ms-client-request-id': 'e164e506-9b7e-11ee-94dd-92dfbd47e697'
    'User-Agent': 'azsdk-python-azuremonitorclient/unknown Python/3.11.7 (Linux-5.15.0-1052-azure-x86_64-with-glibc2.31)'
A body is sent with the request
INFO Response status: 200
Response headers:
    'Content-Type': 'application/json; charset=utf-8'
    'Server': 'Microsoft-HTTPAPI/2.0'
    'Strict-Transport-Security': 'REDACTED'
    'X-Content-Type-Options': 'REDACTED'
    'Date': 'Fri, 15 Dec 2023 19:19:33 GMT'
    'Content-Length': '49'
INFO Transmission succeeded: Item received: 1. Items accepted: 1

After I debugged with pdb, it looks that this line is processed when telemetry is sent to Application Insights.

https://github.com/Azure/azure-sdk-for-python/blob/d8bcdc57c0287dca6b6bdc192c9255616c4f36d3/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py#L509C1-L512C23

            if http_request.body:
                log_string += "\nA body is sent with the request"
                logger.info(log_string)
                return

This logger has root as parent.

(Pdb) logger.name
'azure.core.pipeline.policies.http_logging_policy'
(Pdb) logger.parent
<RootLogger root (INFO)>

I would personally think that since this message is too verbose from application perspective and it takes root logger, this should call logger.debug() instead of info() like other lines of this code like this.

azure-sdk-for-python/sdk/core/azure-core/azure/core/pipeline/policies/_universal.py

Line 324 in d8bcdc5

_LOGGER.debug(log_string)

Though it, I'm new to this codebase so my assumption might be wrong. Please let me know if there is a workaround to suppress this message.

Expected behavior
HTTP log is too verbose as it emits logs every time telemetry is sent to application insights. This should be debug log.

[github-actions]

Thanks for the feedback! We are routing this to the appropriate team for follow-up. cc @azmonapplicationinsights @jeremydvoss @lzchen.

[lzchen]

Could you paste/give a link to your django app? I am running your instrumented code as a standalone Python app and cannot replicate the behavior you are experiencing above:

configure_azure_monitor(
    logger_name="myapp",
)

logger = logging.getLogger('myapp')
logger.setLevel(logging.WARNING)

logger.warning("test log")

I only see test log appear in AppInsights and nothing printed to the console.

[shingotoda]

@lzchen Could you set root logger's log level to INFO? Here is my snippet of logging configuration.

# Logger
LOGGING = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "simple": {
            "format": "{levelname} {message}",
            "style": "{",
        },
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "formatter": "simple",
            "stream": sys.stdout
        }
    },
    "root": {
        "handlers": ["console"],
        "level": 'INFO'
    }
}

Our app uses root logger for most of logging so INFO level is enabled.

[lzchen]

@shingotoda

I am able to replicate the logs showing up printed to stdout but these logs are not captured and sent to App Insights. Please confirm whether these logs are simply showing up in console (which is expected behavior) or is it doing that AND being collected as telemetry and sent to your AppInsights instance?