Azure / azure-functions-dotnet-worker

Azure Functions out-of-process .NET language worker
MIT License
414 stars 181 forks source link

Application Insights shows everything as "Trace: Information" log level #2216

Open drew-fc opened 8 months ago

drew-fc commented 8 months ago

hi,

I have a .NET 8 Isolated function using v4. I am following this guide here to get AppInsights working and using the latest AppInsights from Nuget. My Program.cs looks nearly identical to this: https://github.com/devops-circle/Azure-Functions-Logging-Tests/blob/master/Func.Isolated.Net7.With.AI/Program.cs

In my function, I do something simple like this to test logging:

            _logger.LogTrace("TestLog Trace");
            _logger.LogInformation("TestLog Information");
            _logger.LogError( "TestLog Error");
            _logger.LogError(new Exception("something wrong"),"TestLog ErrorWithException");

The logs show up in the Transaction search in Application insights, but they all show up as Trace entries, and the Severity level is always "Information"

image

Here is my apsettings.json:

{
  "IsEncrypted": false,
  "Values": {
    SNIPPED
  },
  "logging": {
    "fileLoggingMode": "always",
    "applicationInsights": {
      "samplingSettings": {
        "isEnabled": true,
        "excludedTypes": "Request"
      }
    },
    "logLevel": {
      "default": "Trace",
      "xxFunction.DoSomeAction": "Debug",
      "xxFunction.Login": "Debug",
      "xxFunction.WelcomeGiftQueue": "Debug"
    },
    "extensions": {
      "queues": {
        "maxPollingInterval": "00:00:10",
        "visibilityTimeout": "00:00:30",
        "batchSize": 16,
        "maxDequeueCount": 5,
        "newBatchThreshold": 8,
        "messageEncoding": "base64"
      }
    }
  },
  "ApplicationInsights": {
    "LogLevel": {
      "Default": "Trace"
    }
  }
}

And here is my Program.cs:


using Application.Interfaces;
using AzureFunctionApp.Functions.Middleware;
using Infrastructure;
using Microsoft.Azure.Functions.Worker;
using Microsoft.Extensions.Caching.Memory;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Hosting;
using Microsoft.Extensions.Logging;
using System.Linq;
using Newtonsoft.Json;
using Newtonsoft.Json.Serialization;
using Azure.Core.Serialization;
using Newtonsoft.Json.Converters;

public class Program
{

    static ILogger _logger;

    public Program(ILoggerFactory loggerFactory)
    {
        _logger = loggerFactory.CreateLogger<Program>();
    }

    public static void Main()
    {
        var host = new HostBuilder()

    .ConfigureFunctionsWorkerDefaults(builder =>
    {
        //put this first before any other middelware so those other middleware log exceptions
        builder
            .UseMiddleware<ExceptionLoggingMiddleware>();

        //wire up Auth middleware LAST because then if there's any issues, it will
        //at least get caught in the exception logging middleware and logged
        //middelware fires in the sequence it is added
        builder.UseWhen<AuthenticationMiddleware>(ctx =>
        {
            // We want to use this middleware only for http trigger invocations.
            // on a Queue trigger for example, it will cause all of the queue function logic
            //to be skipped over. It will also not log anything because the logging hasn't been injected yet
            //This was  REALLY hard and confusing to find bug
            return ctx.FunctionDefinition.InputBindings.Values
                          .First(a => a.Type.EndsWith("Trigger")).Type == "httpTrigger";
        });

    })
    .ConfigureServices((ctx, serviceProvider) =>
    {
        // You will need extra configuration because above will only log per default Warning (default AI configuration) and above because of following line:
        // https://github.com/microsoft/ApplicationInsights-dotnet/blob/main/NETCORE/src/Shared/Extensions/ApplicationInsightsExtensions.cs#L427
        // This is documented here:
        // https://github.com/microsoft/ApplicationInsights-dotnet/issues/2610#issuecomment-1316672650
        // So remove the default logger rule (warning and above). This will result that the default will be Information.
        //serviceProvider.Configure<LoggerFilterOptions>(options =>
        //{
        //    var toRemove = options.Rules.FirstOrDefault(rule => rule.ProviderName
        //        == "Microsoft.Extensions.Logging.ApplicationInsights.ApplicationInsightsLoggerProvider");

        //    if (toRemove is not null)
        //    {
        //        options.Rules.Remove(toRemove);
        //    }

        //    //var lf  = new LoggerFactory();  
        //    //var logger = lf.CreateLogger("Startup");  
        //    //logger.LogInformation("Got Here in Startup");

        //    //Genlog.Configure(logger);            

        //});

        //new setup is based on the original thread above which linked to this sample project
        //https://github.com/devops-circle/Azure-Functions-Logging-Tests/blob/master/Func.Isolated.Net7.With.AI/Program.cs
        serviceProvider.AddApplicationInsightsTelemetryWorkerService();

        // Add function app specific ApplicationInsights services.
        // See https://learn.microsoft.com/en-us/azure/azure-functions/dotnet-isolated-process-guide#application-insights
        serviceProvider.ConfigureFunctionsApplicationInsights();

        //from https://github.com/Azure/azure-functions-dotnet-worker/issues/2131
        //this is how to force the isolated .NET 7 core azure function to actually use Newtonsoft for serialization
        //took a full day to figure this one out
        //otherwise it will always use System.Text.Json
        //this also was a possible solution but did not work: https://stackoverflow.com/questions/77066296/enabling-newtonsoft-json-with-net-7-isolated-azure-function
        //wound up needing the assembly Microsoft.Azure.Core.NewtonsoftJson -Version 2.0.0
        serviceProvider.Configure<WorkerOptions>(workerOptions =>
        {
            JsonSerializerSettings settings = NewtonsoftJsonObjectSerializer.CreateJsonSerializerSettings();
            settings.ContractResolver = new CamelCasePropertyNamesContractResolver();
            settings.NullValueHandling = NullValueHandling.Ignore;

            //this setting StringEnumConverted is only needed if you want ALL enums to be strings
            //otherwise we can individually set it at the class level with the [JsonConverter(typeof(StringEnumConverter))] attribute
            //its probably best to be explicit here so we don't do it automatically for every enum and bloat the files
            //settings.Converters.Add(new StringEnumConverter());
            workerOptions.Serializer = new NewtonsoftJsonObjectSerializer(settings);

        });

        serviceProvider.AddInfrastructureServices(ctx.Configuration);
    })
    .ConfigureAppConfiguration((hostContext, config) =>
    {
        // Add appsettings.json configuration so we can set logging in configuration.
        // Add in example a file called appsettings.json to the root and set the properties to:
        // Build Action: Content
        // Copy to Output Directory: Copy if newer
        //
        // Content:
        // {
        //   "Logging": {
        //     "LogLevel": {
        //       "Default": "Error" // Change this to ie Trace for more logging
        //     }
        //   }
        // }
        config.AddJsonFile("appsettings.json", optional: true);
    })
    .ConfigureLogging((hostingContext, logging) =>
    {

        //this is required to see the logs while running locally
        //logging.AddConsole()
        logging.ClearProviders();
        //see https://github.com/dotnet/AspNetCore.Docs/issues/21469
        logging.AddSimpleConsole(console =>
        {
            console.IncludeScopes = true;
            //console.ColorBehavior = LoggerColorBehavior.Disabled;
            //console.IncludeScopes = true;
        });

        // Make sure the configuration of the appsettings.json file is picked up.
        logging.AddConfiguration(hostingContext.Configuration.GetSection("Logging"));
    })
    .Build();

        host.Run();
    }
}
Markz878 commented 7 months ago

I have been fighting with .NET Azure Function logging with Application Insights for six months (packages and default behavior have changed) and still not clear what is the correct way to see for example application logs in info but set EF Core logs to warning. How to setup app config code and host.json/appsettings.json (which is not part of the default template since even though it's needed for this?) sections correctly.

Could Azure Function team please solve this and add some actual documentation about this somewhere obvious (not hidden in GH issue comments)?

vienleidl commented 2 months ago

As a workaround, I managed to reduce the Information logs sent to TRACE of App Insights by adding the following environment variables in the Function App on Azure portal:

[ { "name": "AzureFunctionsJobHost:Logging:ApplicationInsights:LogLevel:Default", "value": "Warning", "slotSetting": false }, { "name": "AzureFunctionsJobHost:Logging:Console:LogLevel:Default", "value": "Warning", "slotSetting": false }, { "name": "AzureFunctionsJobHost:Logging:Debug:LogLevel:Default", "value": "Warning", "slotSetting": false }, { "name": "AzureFunctionsJobHost:Logging:LogLevel:Default", "value": "Warning", "slotSetting": false } ]