Logs created by SLF4J in azure functions are duplicated. Also, "operation_Name" is missing in some of them

[evkaky]

Hi there!
Just created a simple azure function in java and I observe 2 issues:

1. logs generated by SLF4J are duplicated in app insight
2. there is no operation_Name (which should be the name of my function - HttpTriggerJava in example below) attached to my SLF4J logs in app insight.

Here is my host.json:

{
  "version": "2.0",
  "extensionBundle": {
    "id": "Microsoft.Azure.Functions.ExtensionBundle",
    "version": "[4.0.0, 5.0.0)"
  } 
}

And I have the following settings in my function app:

[
  {
    "name": "APPINSIGHTS_INSTRUMENTATIONKEY",
    "value": "...",
    "slotSetting": true
  },
  {
    "name": "APPLICATIONINSIGHTS_CONNECTION_STRING",
    "value": "...",
    "slotSetting": false
  },
  {
    "name": "APPLICATIONINSIGHTS_ENABLE_AGENT",
    "value": "true",
    "slotSetting": false
  },
  {
    "name": "AzureWebJobsStorage",
    "value": "...",
    "slotSetting": false
  },
  {
    "name": "FUNCTIONS_EXTENSION_VERSION",
    "value": "~4",
    "slotSetting": false
  },
  {
    "name": "FUNCTIONS_WORKER_RUNTIME",
    "value": "java",
    "slotSetting": false
  },
  {
    "name": "WEBSITE_CONTENTAZUREFILECONNECTIONSTRING",
    "value": "...",
    "slotSetting": false
  },
  {
    "name": "WEBSITE_CONTENTSHARE",
    "value": "evkaky11func19f66",
    "slotSetting": false
  },
  {
    "name": "WEBSITE_RUN_FROM_PACKAGE",
    "value": "1",
    "slotSetting": false
  }
]

Btw is APPLICATIONINSIGHTS_ENABLE_AGENT app setting set to true is necessary to have my java code instrumented for tracing / logging ?

And the function itself

import org.slf4j.LoggerFactory;

public class HttpTriggerJava {
    @FunctionName("HttpTriggerJava")
    public HttpResponseMessage run(
            @HttpTrigger(
                name = "req",
                methods = {HttpMethod.GET, HttpMethod.POST},
                authLevel = AuthorizationLevel.FUNCTION
            ) HttpRequestMessage<Optional<String>> request) {

        LoggerFactory.getLogger(HttpTriggerJava.class).info("hi1");

        // ...
    }
}

The first problem:

If I then search by hi1 in app insight, I see it twice (but formatted differently)

The first one looks much more useful to me since it doesn't mess all MDCs in the message but put them into customDimensions
But why there is a second one? Does that mean I will be charged x2 for all my logs?

The second problem:

Looking closer at the first log in app insight:

You can see there is no operation_Name field pointing to the name of my function. Why so? If I use an instance of java.util.Logger obtained from ExectionContext - the operation_Name is attached to such logs.

public class HttpTriggerJava {
    @FunctionName("HttpTriggerJava")
    public HttpResponseMessage run(
            @HttpTrigger(
                name = "req",
                methods = {HttpMethod.GET, HttpMethod.POST},
                authLevel = AuthorizationLevel.FUNCTION
            ) HttpRequestMessage<Optional<String>> request, ExecutionContext context) {
        context.getLogger().info("this logger is terrible as it forces me to pass it explicitly as a parameter into every single function down to stack");
    }
}

Why not attaching operation_Name to SLF4J logs too?

[evkaky]

Hi there.
Any updates on this?
Lack of operation_Name in logs generated by SLF4J is somewhat critical for our team as we heavily use azure functions & java

[heyams]

Hi @evkaky, I was working with Azure Function team to come up with a better doc.
It's a known issue to have duplicate logs in this case. But a workaround might work. Can you try to turn off SLF4J to print to console? I'll look into why SLF4J is missing operation_name. Do you have a repro app available for me to further investigate? You can push it to https://github.com/microsoft/ApplicationInsights-Java-Repros.

[heyams]

Hi @evkaky assuming you're using logback, can you share your logback appender config file?

For the missing operation_name, it's actually a known issue. I will reach out to Function team to see if they can pass operation_name to java agent so that we can stamp it into function log.

[microsoft-github-policy-service]

This issue has been automatically marked as stale because it has been marked as requiring author feedback but has not had any activity for 7 days. It will be closed if no further activity occurs within 7 days of this comment.

[trask]

For the missing operation_name, it's actually a known issue

re-opening since we haven't resolved this yet