azure-sdk-for-net icon indicating copy to clipboard operation
azure-sdk-for-net copied to clipboard

[BUG] Unable to filter SDK logs in Azure Function instances

Open MSIT-BPSC-IOT opened this issue 2 years ago • 10 comments
trafficstars

Library name and version

Azure.Messaging.ServiceBus and Azure.Storage.Blobs

Describe the bug

We are seeing few issues with the latest (5.x) version SDKs:

  1. Below lock renew happens constantly with 5.x sdk which we didn't see with the previous 4.x sdk. Request [a0294b3b-3aa4-4b65-9b35-20c2e0493ed3] PUT https://<>.blob.core.windows.net/azure-webjobs-hosts/locks/<>/host?comp=metadata image

  2. We are seeing 409 Conflict (Container already exists) Request [b4948ae8-cc71-4239-828f-bc7657391d0b] PUT https://dataqualityfnstorage.blob.core.windows.net/azure-webjobs-hosts?restype=container

  3. This event is flooding our logs every 10 seconds for ServiceBus trigger function. Receiver: ReceiveBatchAsync start. MessageCount = 1.

We tried setting the loglevel in both host.json and appsettings.json

Host.json:

{
  "version": "2.0",
  "functionTimeout": "00:55:00",
  "logging": {
    "logLevel": {
      "Default": "Warning",
      "System": "Warning",
      "Microsoft": "Warning",
      "Azure.Messaging.ServiceBus": "Error",
      "Azure.Storage.Blobs": "Error",
      "Azure.Core": "Error",
      "Microsoft.Azure.WebJobs.Extensions.Storage": "Error",
      "Microsoft.Azure.WebJobs.Extensions.ServiceBus": "Error",
      "Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics.SystemLoggerProvider": "Error",
      "Azure.Functions.Cli.Diagnostics.ColoredConsoleLoggerProvider": "Error",
      "Microsoft.Azure.WebJobs.Logging.ApplicationInsights.ApplicationInsightsLoggerProvider": "Error"
    }
  }
}

local.appsettings.json

{
  "IsEncrypted": false,
  "Values": {
    "AzureFunctionsJobHost_logging_LogLevel_Default": "Error",
    "APP_INSIGHTS_NAMESPACE": "functions",
	"AzureWebJobsStorage": "",
    "FUNCTIONS_EXTENSION_VERSION": "~4",
    "FUNCTIONS_WORKER_RUNTIME": "dotnet",
    "WEBSITE_FIRST_PARTY_ID": "AntMDS",
    "WEBSITE_NODE_DEFAULT_VERSION": "~10",
    "Logging:LogLevel:Azure.Messaging.ServiceBus": "Error",
    "Logging:LogLevel:Azure.Core": "Error",
    "Logging:LogLevel:Azure.Storage.Blobs": "Error",
    "Logging:LogLevel:Microsoft.Azure.WebJobs.Extensions.Storage": "Error",
    "Logging:LogLevel:Microsoft.Azure.WebJobs.Extensions.ServiceBus": "Error",
    "applicationInsights:logLevel:default": "Error",
    "Logging:LogLevel:Serilog.Extensions.Logging.SerilogLoggerProvider": "Error",
    "Logging:LogLevel:Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics.SystemLoggerProvider": "Error",
    "Logging:LogLevel:Azure.Functions.Cli.Diagnostics.ColoredConsoleLoggerProvider": "Error",
    "Logging:LogLevel:Microsoft.Azure.WebJobs.Logging.ApplicationInsights.ApplicationInsightsLoggerProvider": "Error",
    "Serilog.Extensions.Logging.SerilogLoggerProvider": "Error",
    "Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics.SystemLoggerProvider": "Error",
    "Azure.Functions.Cli.Diagnostics.ColoredConsoleLoggerProvider": "Error",
    "Microsoft.Azure.WebJobs.Logging.ApplicationInsights.ApplicationInsightsLoggerProvider": "Error"
  },
  "Logging": {
    "LogLevel": {
      "Default": "Debug",
      "System": "Warning",
      "Microsoft": "Warning",
      "Azure.Messaging.ServiceBus": "Error",
      "Azure.Storage.Blobs": "Error",
      "Azure.Core": "Error",
      "Microsoft.Azure.WebJobs.Extensions.Storage": "Error",
      "Microsoft.Azure.WebJobs.Extensions.ServiceBus": "Error",
      "Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics.SystemLoggerProvider": "Error",
      "Azure.Functions.Cli.Diagnostics.ColoredConsoleLoggerProvider": "Error",
      "Microsoft.Azure.WebJobs.Logging.ApplicationInsights.ApplicationInsightsLoggerProvider": "Error"
    }
  }
}

Expected behavior

These logs doens't happen with 4.x. So, we don't expect this to happen in 5.x as well

Actual behavior

As mentioned in the issue section, we are seeing unwanted logs

Reproduction Steps

Upgrade 4.x to 5.x

Environment

PROD

MSIT-BPSC-IOT avatar Feb 10 '23 16:02 MSIT-BPSC-IOT

//cc: @tg-msft (Storage + 409s awareness)

jsquire avatar Feb 10 '23 17:02 jsquire

Thank you for your feedback. Tagging and routing to the team member best able to assist.

jsquire avatar Feb 10 '23 17:02 jsquire

Hi @MSIT-BPSC-IOT, Can you clarify whether you are seeing the behavior locally or in a deployed app?

JoshLove-msft avatar Feb 10 '23 17:02 JoshLove-msft

I see this behavior both locally and in the deployed app.

Even after adding the below code in my Configure, i still see the logs:

builder.Services.AddAzureClients(azureBuilder =>
            {
                azureBuilder.AddServiceBusClient(
                    Environment.GetEnvironmentVariable("ServiceBusConnectionString"),
                azureBuilder.UseCredential(new DefaultAzureCredential());
            });

MSIT-BPSC-IOT avatar Feb 10 '23 17:02 MSIT-BPSC-IOT

Is there a minimal repro function app that you can share?

JoshLove-msft avatar Feb 10 '23 18:02 JoshLove-msft

I was able to fix this issue. The solutions provided by others on various bugs works fine (adding loglevel in host.json). However it didnt work for me because i was using serilog. Here is what i did which fixed my issue:

host.json file change

{ "version": "2.0", "functionTimeout": "00:55:00", "Serilog": { "MinimumLevel": { "Default": "Information", "Override": { "Azure.Messaging.ServiceBus": "Error", "Azure.Storage.Blobs": "Error", "Azure.Core": "Error", "Microsoft.Azure.WebJobs.Extensions.Storage": "Error", "Microsoft.Azure.WebJobs.Extensions.ServiceBus": "Error" } } } }

Corresponding Startup.cs change to load this settings: var logger = new LoggerConfiguration()
.ReadFrom.Configuration(hostConfig, sectionName: "AzureFunctionsJobHost:Serilog") .WriteTo.Console() .WriteTo.ApplicationInsights(telemetryConfiguration, TelemetryConverter.Traces) .CreateLogger(); services.AddLogging(lb => lb.AddSerilog(logger));

MSIT-BPSC-IOT avatar Feb 11 '23 17:02 MSIT-BPSC-IOT

Issue is fixed

MSIT-BPSC-IOT avatar Feb 11 '23 17:02 MSIT-BPSC-IOT

The solution I posted only works on a local environment. However, after i deployed the application, i see the same error/logs

MSIT-BPSC-IOT avatar Feb 14 '23 00:02 MSIT-BPSC-IOT

Hi @MSIT-BPSC-IOT. The Aure SDKs emit ETW events which are captured by a listener and forwarded to the ILogger implementation that is registered with DI. At that point, it is up to the logger to apply any filtering that has been defined.

Unfortunately, because you're using a third-party library (Serilog), there is little additional assistance that we can provide. I'd suggest engaging Serilog's support process. If they have questions about the implementation for the Azure client libraries or extension packages, we'd be happy to provide information to assist in troubleshooting.

I'm going to mark this as addressed, as I do not believe there are additional steps that can be taken. Please feel free to unresolve if you'd like to continue the conversation.

jsquire avatar Feb 14 '23 15:02 jsquire

Hi @MSIT-BPSC-IOT. Thank you for opening this issue and giving us the opportunity to assist. We believe that this has been addressed. If you feel that further discussion is needed, please add a comment with the text “/unresolve” to remove the “issue-addressed” label and continue the conversation.

ghost avatar Feb 14 '23 15:02 ghost

Hi @MSIT-BPSC-IOT, since you haven’t asked that we “/unresolve” the issue, we’ll close this out. If you believe further discussion is needed, please add a comment “/unresolve” to reopen the issue.

ghost avatar Feb 21 '23 16:02 ghost