microsoft / ApplicationInsights-dotnet

ApplicationInsights-dotnet
MIT License
565 stars 287 forks source link

Flush/Wait at the end of the process #2565

Open drauch opened 2 years ago

drauch commented 2 years ago

In https://docs.microsoft.com/en-us/azure/azure-monitor/app/worker-service#net-corenet-framework-console-application it says that console applications should use a combination of Flush/Wait at the end of the program to ensure all log statements have been properly sent to the server.

Two questions regarding this: 1) This is only necessary for console applications? Hosted services and ASP.NET Core web apps do not need to do this? 2) Is there no better way than the Flush/Wait combination? It looks like it is a) flaky, because sometimes the 5 seconds might not be enough time and b) unnecessary long in most cases where the remaining HTTP requests might only take some milliseconds.

Best regards, D.R.

TimothyMothra commented 2 years ago

We're working on doc improvements to clearly describe flushing recommendations.

If you're using the latest version of the SDK, you can await FlushAsync()

drauch commented 2 years ago

So you're saying in console applications we should use FlushAsync() instead and it waits just as much as it absolutely needs to?

What about other types of applications, do we need any manual code for ASP.NET Core web apps as well or does it happen automagically if you use the correct registration techniques for ASP.NET Core web apps? And "hosted services"?

drauch commented 2 years ago

Ping, any more on this? Do we need to call FlushAsync also in non-console applications? ASP.NET Core web apps or ASP.NET core hosted services?

pizzaz93 commented 2 years ago

Current guidance: https://docs.microsoft.com/en-us/azure/azure-monitor/app/api-custom-events-metrics#flushing-data

drauch commented 2 years ago

It's a pity that this doesn't happen automagically somehow.

github-actions[bot] commented 1 year ago

This issue is stale because it has been open 300 days with no activity. Remove stale label or this will be closed in 7 days. Commenting will instruct the bot to automatically remove the label.

drauch commented 1 year ago

Is this something that could be taken into consideration as a feature request for a future version?

Best regards, D.R.

github-actions[bot] commented 10 months ago

This issue is stale because it has been open 300 days with no activity. Remove stale label or this will be closed in 7 days. Commenting will instruct the bot to automatically remove the label.

fschmied commented 10 months ago

Not stale. Thanks for pointing to the improved docs, but can't this mechanism be improved? And what about the OP's question about whether this is also necessary in ASP.NET Core applications and hosted services?

fschmied commented 9 months ago

I've now learned that the ApplicationInsightsLoggerProvider will automatically flush on Dispose, but without the sleeping (link): image

So if this was changed to DisposeAsync and FlushAsync (or if Flush could itself wait until the flushing is done), I guess it would solve the problem in all applications that use the Application Insights/Microsoft.Extensions.Logging integration (i.e., most .NET Core applications, unless they use a custom logging solution).

feO2x commented 6 months ago

Hey everybody,

yesterday, I also stumbled upon this problem that apps, no matter whether they are ASP.NET Core based or not, will not send out all telemetry messages that are held in the buffer during shutdown. At the time of writing, we need to explicitly call TelemetryClient.FlushAsync during shutdown to not lose data (especially log messages).

Reproducing the issue

For a Minimal Complete Verifiable Example (MCVE), I created this small ASP.NET Core 8 app:

<Project Sdk="Microsoft.NET.Sdk.Web">

    <PropertyGroup>
        <TargetFramework>net8.0</TargetFramework>
        <Nullable>enable</Nullable>
    </PropertyGroup>

    <ItemGroup>
        <PackageReference Include="Microsoft.ApplicationInsights.AspNetCore" Version="2.22.0" />
    </ItemGroup>

</Project>
using System.Threading.Tasks;
using Microsoft.AspNetCore.Builder;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;

namespace AppInsightsTest;

public sealed class Program
{
    public static async Task Main(string[] args)
    {
        var builder = WebApplication.CreateBuilder(args);
        builder
           .Services
           .AddApplicationInsightsTelemetry();
        var app = builder.Build();

        await app.StartAsync();
        try
        {
            var logger = app.Services.GetRequiredService<ILogger<Program>>();
            logger.LogDebug("Test Debug");
            logger.LogInformation("Test Info");
            logger.LogWarning("Test Warning");
            logger.LogError("Test Error");
            logger.LogCritical("Test Critical");
        }
        finally
        {
            await app.StopAsync();
            await app.DisposeAsync();
        }
    }
}
{
    "Logging": {
        "LogLevel": {
            "Default": "Information"
        },
        "ApplicationInsights": {
            "LogLevel": {
                "Default": "Information"
            }
        }
    },
    "AllowedHosts": "*"
}

The App Insights Connection string is specified via user secrets or environment variables.

According to this setup, the LogDebug call should be completely omitted, but I should see the Information, Warning, Error, and Critical messages (besides some additional Microsoft.Hosting.Lifetime log messages) both on the console and on App Insights.

What I observed

Testing this several times, I see the following behavior:

Inconsistent delivery of log messages to App Insights

A possible solution?

Is it possible that we introduce an ASP.NET Core Hosted Service which simply calls TelemetryClient.FlushAsync? An implementation could look like this:

public sealed class FlushTelemetryClientHostedService : IHostedService
{
    private readonly TelemetryClient _telemetryClient;

    public FlushTelemetryClientHostedService(TelemetryClient telemetryClient)
    {
        _telemetryClient = telemetryClient;
    }

    public Task StartAsync(CancellationToken cancellationToken) => Task.CompletedTask;

    public Task StopAsync(CancellationToken cancellationToken) =>
        _telemetryClient.FlushAsync(cancellationToken);
}

When the app is shut down, this hosted service could simply flush the telemetry client. Maybe we would want to add some error handling to the StopAsync method, but this could solve the issue in my opinion. This hosted service could be registered with the DI container when AddApplicationInsightsTelemetry executes.