Azure Application Insights log is getting logged twice in trace table

[jos-h]

Requirements

• azure-monitor-opentelemetry==1.6.0
• Django==4.2.15
• python == 3.11.9

Issue

1. I have configured the Azure monitor inside the Django manage.py file configure_azure_monitor(). Below is the configuration for the same configure_azure_monitor(connection_string=os.environ.get("APPLICATIONINSIGHTS_CONNECTION_STRING"), enable_live_metrics=True, logger_name="app_logger")
2. I have customized the Django Logger using the LOGGING dict. Below is my logging configuration. `LOGGING = { "version": 1, "disable_existing_loggers": False, "formatters": { "verbose": { "format": "%(asctime)s : %(name)s : %(levelname)s - %(message)s", "datefmt": "%Y/%b/%d %H:%M:%S", }, "simple": {"format": "%(levelname)s %(message)s"}, }, "handlers": { "console": { "class": "logging.StreamHandler", "formatter": "verbose", }, "opentelemetry": { "class": "opentelemetry.sdk._logs.handler", "formatter": "verbose", }, }, "loggers": { "azure": { "level": "WARNING", "handlers": [], "propagate": False, }, "azure.core.pipeline.policies.http_logging_policy": { "level": "CRITICAL", "handlers": [], "propagate": False, }, "azure.monitor.opentelemetry.exporter.export._base": { "level": "WARNING", "handlers": [], "propagate": False, }, "app_logger": { "level": "INFO", "handlers": ["opentelemetry"] if os.getenv("APPLICATIONINSIGHTS_CONNECTION_STRING") else ["console"], "propagate": False, }, }, }

logging.config.dictConfig(LOGGING)`

3. Inside one of my views.py, I am getting a logger object using logging.getLogger("app_logger") and added logger.info("Testing logs"). When querying the traces table from the Application Insights using the query editor, I see the above log getting logged twice.

I am following the below links to configure the Azure monitor with Opentelemetery

1. https://learn.microsoft.com/en-us/azure/azure-monitor/app/opentelemetry-enable?tabs=python to enable the Azure Monitor Opentelemetry.
2. https://github.com/Azure/azure-sdk-for-python/blob/main/sdk/monitor/azure-monitor-opentelemetry/samples/tracing/django/sample/manage.py

Output: ` Testing logs

Testing logs ` NOTE:- I can't share the exact output log due to compliance policy. Sorry for the inconvenience

[xiangyan99]

Thanks for the feedback, we’ll investigate asap.

[jos-h]

@lzchen Any update on the above?

[lzchen]

@jos-h

Taking a look.

[lzchen]

@jos-h

I am not able to replicate your behavior. Could you try doing the following:

1. enable_live_metrics=True
2. Change

   "opentelemetry": {
   "class": "opentelemetry.sdk._logs.handler",
   "formatter": "verbose",
   },

   to be

   "opentelemetry": {
   "class": "opentelemetry.sdk._logs.LoggingHandler",
   "formatter": "verbose",
   },

3. Remove logging.config.dictConfig(LOGGING)

[jos-h]

@jos-h

I am not able to replicate your behavior. Could you try doing the following:

1. enable_live_metrics=True
2. Change

"opentelemetry": {
"class": "opentelemetry.sdk._logs.handler",
"formatter": "verbose",
},

to be

"opentelemetry": {
"class": "opentelemetry.sdk._logs.LoggingHandler",
"formatter": "verbose",
},

3. Remove logging.config.dictConfig(LOGGING)

@lzchen, I modified the code and tried it again based on your steps. But still, logs are getting logged twice. Would you let me know what steps you followed while trying to replicate the issue? Do we need to make some updations in the Azure Portal like in Diagnostic Settings etc?

[lzchen]

@jos-h

1. Apologies can you set enable_live_metrics=False.

2. Are you also running the Django app standalone? With python manage.py runserver?

3. In your views.py, how and when are you instantiating the logger object with name app_logger?

Below is the code I have that only produces one trace telemetry entry:

manage.py

from azure.monitor.opentelemetry import configure_azure_monitor
...
def main():
"""Run administrative tasks."""
    os.environ.setdefault("DJANGO_SETTINGS_MODULE", "sample.settings")

    configure_azure_monitor(
        logger_name="app_logger",
    )
...

views.py

...
logger = logging.getLogger("app_logger")

# Requests sent to the django application will be automatically captured
def index(request):
    logger.info("index page")
    return HttpResponse("Hello, world.")
...

settings.py

...
LOGGING = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "verbose": {
            "format": "%(asctime)s : %(name)s : %(levelname)s - %(message)s",
            "datefmt": "%Y/%b/%d %H:%M:%S",
        },
        "simple": {"format": "%(levelname)s %(message)s"},
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "formatter": "verbose",
        },
        "opentelemetry": {
            "class": "opentelemetry.sdk._logs.LoggingHandler",
            "formatter": "verbose",
        },
    },
    "loggers": {
        "azure": {
            "level": "WARNING",
            "handlers": [],
            "propagate": False,
        },
        "azure.core.pipeline.policies.http_logging_policy": {
            "level": "CRITICAL",
            "handlers": [],
            "propagate": False,
        },
        "azure.monitor.opentelemetry.exporter.export._base": {
            "level": "WARNING",
            "handlers": [],
            "propagate": False,
        },
        "app_logger": {
            "level": "INFO",
            "handlers": ["opentelemetry"],
            "propagate": False,
        },
    },
}
...

[github-actions[bot]]

Hi @jos-h. Thank you for opening this issue and giving us the opportunity to assist. To help our team better understand your issue and the details of your scenario please provide a response to the question asked above or the information requested above. This will help us more accurately address your issue.

[jos-h]

@jos-h

1. Apologies can you set enable_live_metrics=False.
2. Are you also running the Django app standalone? With python manage.py runserver?
3. In your views.py, how and when are you instantiating the logger object with name app_logger?

Below is the code I have that only produces one trace telemetry entry:

manage.py

from azure.monitor.opentelemetry import configure_azure_monitor
...
def main():
"""Run administrative tasks."""
    os.environ.setdefault("DJANGO_SETTINGS_MODULE", "sample.settings")

    configure_azure_monitor(
        logger_name="app_logger",
    )
...

views.py

...
logger = logging.getLogger("app_logger")

# Requests sent to the django application will be automatically captured
def index(request):
    logger.info("index page")
    return HttpResponse("Hello, world.")
...

settings.py

...
LOGGING = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "verbose": {
            "format": "%(asctime)s : %(name)s : %(levelname)s - %(message)s",
            "datefmt": "%Y/%b/%d %H:%M:%S",
        },
        "simple": {"format": "%(levelname)s %(message)s"},
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "formatter": "verbose",
        },
        "opentelemetry": {
            "class": "opentelemetry.sdk._logs.LoggingHandler",
            "formatter": "verbose",
        },
    },
    "loggers": {
        "azure": {
            "level": "WARNING",
            "handlers": [],
            "propagate": False,
        },
        "azure.core.pipeline.policies.http_logging_policy": {
            "level": "CRITICAL",
            "handlers": [],
            "propagate": False,
        },
        "azure.monitor.opentelemetry.exporter.export._base": {
            "level": "WARNING",
            "handlers": [],
            "propagate": False,
        },
        "app_logger": {
            "level": "INFO",
            "handlers": ["opentelemetry"],
            "propagate": False,
        },
    },
}
...

@lzchen Thank you for the quick update. Below are my answers to your queries

1. I have set enable_live_metrics=False
2. I am running the Django app from my local machine using python manage.py runserver.
3. In my views.py, after all the import statements end, I am instantiating the logger object using logger=logging.getLogger("app_logger")

I tried sending logs to Application Insights with your code changes, but I still see duplicate logs. Is it related to some configuration issue while setting up the Application Insights? In the Diagnostic settings, send logs to the Log Analytics Workspace checkbox is enabled. Will it cause any issues?

[lzchen]

@jos-h

In the Diagnostic settings, send logs to the Log Analytics Workspace checkbox is enabled. Will it cause any issues?

In my testing, my appinsights resource has no diagnostic settings defined.

Perhaps uncheck this and try this out? Otherwise, could you try this with a fresh Appinsights resource and note down any extraneous configuration settings you use?

[jos-h]

@jos-h

In the Diagnostic settings, send logs to the Log Analytics Workspace checkbox is enabled. Will it cause any issues?

In my testing, my appinsights resource has no diagnostic settings defined.

Perhaps uncheck this and try this out? Otherwise, could you try this with a fresh Appinsights resource and note down any extraneous configuration settings you use?

@lzchen Sure I will try and get back to you

[github-actions[bot]]

Hi @jos-h. Thank you for opening this issue and giving us the opportunity to assist. To help our team better understand your issue and the details of your scenario please provide a response to the question asked above or the information requested above. This will help us more accurately address your issue.

[github-actions[bot]]

Hi @jos-h, we're sending this friendly reminder because we haven't heard back from you in 7 days. We need more information about this issue to help address it. Please be sure to give us your input. If we don't hear back from you within 14 days of this comment the issue will be automatically closed. Thank you!