serilog-contrib / serilog-sinks-applicationinsights

A Serilog sink that writes events to Microsoft Azure Application Insights
Apache License 2.0
220 stars 71 forks source link

Upgrade from v3.1.0 to v4.0.0 causes greatly increased thread count and caused thread starvation in Azure Durable Functions #210

Open PauloSRH opened 1 year ago

PauloSRH commented 1 year ago

Description After upgrading Serilog.Sinks.ApplicationInsights to v4.0.0 and implementing the corresponding changes, I noticed a great increase in thread count in my azure durable function that caused thread starvation. This behavior did not happen in the the v3.1.0.

Reproduction The only noticeable code change that maybe can be the source for this issue is changing the setup for the application insights from instrumentationKey to connectionString:

// In v3.1.0

ITelemetryConverter telemetryConverter = new CustomTraceTelemetryConverter();
string instrumentationKey = hostContext.Configuration[ConfigurationConstants.ApplicationInsightsInstrumentationKey];

Logger logger = new LoggerConfiguration()
                    .MinimumLevel.Is(logEventMinimumLevel)
                    .WriteTo.Console(outputTemplate: consoleSinkOutputTemplate)
                    .WriteTo.ApplicationInsights(instrumentationKey, telemetryConverter, restrictedToMinimumLevel: applicationInsightsMinimumLevel)
                    .Enrich.FromLogContext()
                    .Enrich.WithProperty("Environment", environment)
                    .Enrich.WithProperty("Version", version)
                    .CreateLogger();

// In v4.0.0
ITelemetryConverter telemetryConverter = new CustomTraceTelemetryConverter();
string connectionString = hostContext.Configuration[ConfigurationConstants.ApplicationInsightsConnectionString];

Logger logger = new LoggerConfiguration()
                    .MinimumLevel.Is(logEventMinimumLevel)
                    .WriteTo.Console(outputTemplate: consoleSinkOutputTemplate)
                    .WriteTo.ApplicationInsights(connectionString, telemetryConverter, restrictedToMinimumLevel: applicationInsightsMinimumLevel)
                    .Enrich.FromLogContext()
                    .Enrich.WithProperty("Environment", environment)
                    .Enrich.WithProperty("Version", version)
                    .CreateLogger();

// This is executed in the Startup.cs of the azure durable function

I also tested the function with both nuget package versions and only changing that part of the code and the results were the following: Thread count during execution with v3.1.0: v3 0 1

Thread count during execution with v4.0.0: v4 0 0

Expected behavior The expected beahvior should be the graph shown previously for the thread count while executing with the v3.1.0

Relevant package, tooling and runtime versions Serilog.Sinks.ApplicationInsights 4.0.0 / 3.1.0 Serilog 2.12.0 Serilog.Extensions.Logging 3.1.0 Serilog.Sinks.Console 4.0.1 Microsoft.Azure.Functions.Extensions 1.1.0 Microsoft.NET.Sdk.Functions 4.1.3 Microsoft.Azure.WebJobs.Extensions.DurableTask 2.8.1 Microsoft.ApplicationInsights.WorkerService Version 2.21.0 .NET 6

nblumhardt commented 1 year ago

No ideas here, unfortunately - the newer package includes a new set of app insights dependencies so the issue could be somewhere in there.

Just to check - is each function invocation using only a single Logger instance (not multiple calls to CreateLogger), and is the logger disposed properly when the function returns/exits? HTH!

andrepiresrep commented 1 year ago

Hi @nblumhardt could you clarify what dependencies where added? In our Startup class we are configuring some telemetry initializers/processors as well, so now I wonder if we have to filter these out from being stored:

public class Startup : FunctionsStartup 
{

    public override void Configure(IFunctionsHostBuilder hostBuilder)
    {
            hostBuilder.Services.AddSingleton<ITelemetryInitializer, ExternalDataInitializer>();
            hostBuilder.Services.AddSingleton<ITelemetryInitializer, NoSensitiveDataInitializer>();
            hostBuilder.Services.AddApplicationInsightsTelemetryWorkerService(
                  hostBuilder.GetApplicationInsightsServiceOptions());
            hostBuilder.Services.AddApplicationInsightsTelemetryProcessor<FastSqlDependencyProcessor>();
            hostBuilder.Services.AddApplicationInsightsTelemetryProcessor<FastDependencyProcessor>();          
            hostBuilder.Services.AddApplicationInsightsTelemetryProcessor
                <OnlyMemoryAndCpuUsagePerformanceCountersProcessor>();
    }

    public static ApplicationInsightsServiceOptions GetApplicationInsightsServiceOptions(this IFunctionsHostBuilder hostBuilder)
    {
            return new ApplicationInsightsServiceOptions
            {
                AddAutoCollectedMetricExtractor = false,
                EnableEventCounterCollectionModule = false,
                EnableDiagnosticsTelemetryModule = false,
                EnablePerformanceCounterCollectionModule = true,
                EnableDependencyTrackingTelemetryModule = true,
                ConnectionString = hostBuilder.GetContext().Configuration[ConfigurationConstants.ApplicationInsightsConnectionString]
            };
    }
}