Extensions: Logger error on Azure: The process cannot access the file

[razzemans]

Description

We get random intervals where the logging framework on our production environment on Azure will start throwing exceptions, The only way to resolve this issue is by rebooting our web app:

An error occurred while writing to logger(s). (The process cannot access the file because it is being used by another process.) The process cannot access the file because it is being used by another process.

System.AggregateException:
   at Microsoft.Extensions.Logging.Logger.ThrowLoggingError (Microsoft.Extensions.Logging, Version=3.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.Extensions.Logging.Logger.Log (Microsoft.Extensions.Logging, Version=3.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.Extensions.Logging.Logger`1.Microsoft.Extensions.Logging.ILogger.Log (Microsoft.Extensions.Logging.Abstractions, Version=3.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.Extensions.Logging.LoggerMessage+<>c__DisplayClass6_0`2.<Define>g__Log|0 (Microsoft.Extensions.Logging.Abstractions, Version=3.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.Extensions.Logging.LoggerMessage+<>c__DisplayClass6_0`2.<Define>b__1 (Microsoft.Extensions.Logging.Abstractions, Version=3.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.Extensions.Diagnostics.HealthChecks.DefaultHealthCheckService+Log.HealthCheckError (Microsoft.Extensions.Diagnostics.HealthChecks, Version=3.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.Extensions.Diagnostics.HealthChecks.DefaultHealthCheckService+<RunCheckAsync>d__5.MoveNext (Microsoft.Extensions.Diagnostics.HealthChecks, Version=3.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.Extensions.Diagnostics.HealthChecks.DefaultHealthCheckService+<CheckHealthAsync>d__4.MoveNext (Microsoft.Extensions.Diagnostics.HealthChecks, Version=3.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Diagnostics.HealthChecks.HealthCheckMiddleware+<InvokeAsync>d__4.MoveNext (Microsoft.AspNetCore.Diagnostics.HealthChecks, Version=3.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Builder.Extensions.MapWhenMiddleware+<Invoke>d__3.MoveNext (Microsoft.AspNetCore.Http.Abstractions, Version=3.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Diagnostics.StatusCodePagesMiddleware+<Invoke>d__3.MoveNext (Microsoft.AspNetCore.Diagnostics, Version=3.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware+<<Invoke>g__Awaited|6_0>d.MoveNext (Microsoft.AspNetCore.Diagnostics, Version=3.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
Inner exception System.ComponentModel.Win32Exception handled at Microsoft.Extensions.Logging.Logger.ThrowLoggingError:
   at System.Diagnostics.EventLogInternal.InternalWriteEvent (System.Diagnostics.EventLog, Version=4.0.2.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51)
   at System.Diagnostics.EventLogInternal.WriteEvent (System.Diagnostics.EventLog, Version=4.0.2.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51)
   at Microsoft.Extensions.Logging.EventLog.WindowsEventLog.WriteEntry (Microsoft.Extensions.Logging.EventLog, Version=3.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.Extensions.Logging.EventLog.EventLogLogger.WriteMessage (Microsoft.Extensions.Logging.EventLog, Version=3.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.Extensions.Logging.EventLog.EventLogLogger.Log (Microsoft.Extensions.Logging.EventLog, Version=3.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)
   at Microsoft.Extensions.Logging.Logger.<Log>g__LoggerLog|12_0 (Microsoft.Extensions.Logging, Version=3.1.1.0, Culture=neutral, PublicKeyToken=adb9793829ddae60)

To Reproduce

It is not known to me how to reproduce this. It seems to happen randomly.

Further technical details

ASP.NET Core version 3.1
Azure App Service Windows
Microsoft.ApplicationInsights.AspNetCore version 2.12.1

[emilssonn]

I have the same error sometime. From what I can see ASP.Net Core writes logs to the eventlog.xml in Azure when this happens.

Since when does ASP.Net Core write to eventlog in Azure? Using standard "ConfigureWebHostDefaults".

[razzemans]

@anurse our production environment is currently down and has been for over an hour because of this locking error. I believe it is because of writing to the eventlog. How can I disable writing to the eventlog?

[razzemans]

Also to add, this started when our production environment started getting massive server load (ten thousands to hundred thousands of concurrent users).

[razzemans]

I take it adding:

ConfigureLogging(logging =>
{
    logging.ClearProviders();
})

Should at least remove the EventLog logging

[anurse]

@razzemans correct, that should wipe the providers clear and you can add back the ones you want.

Sounds like there is likely an issue with the EventLog and concurrent writes. @noahfalk are you able to help (or bring in someone to help) understand why System.Diagnostics.EventLog.WriteEvent might throw a file locking issue?

Since when does ASP.Net Core write to eventlog in Azure? Using standard "ConfigureWebHostDefaults".

This was added in 3.0, if you are running on Windows and use the newer Generic Host-based model (Host.CreateDefaultBuilder instead of WebHost.CreateDefaultBuilder).

[razzemans]

I just released a hotfix to production with the ClearProviders() and the issue seems to have gone away. For my understanding, if I add Application Insights using UseApplicationInsights(), do I miss out on any logging (except the EventLog) that I am now missing but haven't noticed yet?

[anurse]

@razzemans you can find the full set of providers enabled by Host.CreateDefaultBuilder here: https://github.com/dotnet/extensions/blob/8d0fa056d78af506e3218af056c92930e8a5d5c1/src/Hosting/Hosting/src/Host.cs#L107-L115

Any provider in that list that you don't re-enable would be lost. If you're already using App Insights and getting that data then you should continue to get all the data.

[Tino92]

Any updates on this bug? We have also seen the same exact issue happen in several different Azure app services.

[anurse]

Triage: App Service redirects EventLog to a file, so we believe this is actually an issue in App Service rather than the runtime. @shirhatti is going to follow up with that team.

[jonsagara]

I'm also seeing this exception. FWIW, it seems to appear whenever we swap deployment slots in App Service.

[anurse]

We’ll be following up on our end, but if you are encountering this issue in your apps on app service, I’d suggest opening a support ticket with Azure Support as well.

[erick2red]

I just had this happen to me today for the second time. The app just stops working and this error from Microsoft.Extensions.Logging.ILogger.Log something I'm not even using.

Does this code:

ConfigureLogging(logging =>
{
    logging.ClearProviders();
})

disables App Insights in any way?

[razzemans]

@erick2red It does not disable Application Insights if you have that configured. This is code from our production environment, which gets rid of the issue:

public static IHostBuilder RemoveEventlogLogger(this IHostBuilder hostBuilder)
{
    hostBuilder.ConfigureLogging((context, logging) =>
    {
        // This removes the eventlog logger that causes the application to crash
        logging.ClearProviders();
        if (context.HostingEnvironment.IsDevelopment())
        {
            logging.AddDebug();
            logging.AddConsole();
        }
        logging.AddEventSourceLogger();
    });

    return hostBuilder;
}

[erick2red]

Thanks. I'll skip

        if (context.HostingEnvironment.IsDevelopment())
        {
            logging.AddDebug();
            logging.AddConsole();
        }
        logging.AddEventSourceLogger();

I don't need any logging whatsoever. I have my own logging setup.

[rencoding]

I also got the same exception while the application writing logs.

Exception: System.ComponentModel.Win32Exception
ErrorMessage : An error occurred while writing to logger(s). (The process cannot access the file because it is being used by another process.) The process cannot access the file because it is being used by another process.

....at Microsoft.Extensions.Logging.EventLog.EventLogLogger.Log

Environment:
Asp.Net Core 3.1
Azure App Service Windows

May I know any further updates to this issue?

[shirhatti]

This issue has been fixed in Azure App Service and the patch is currently rolling out globally. We expected it to be fully deployed by the end of this month.