ObjectDisposedException in ASP.NET Core 8

[harrison314]

Hello, I have a problem using ZLogger in ASP.Net Core with AOT template. I regularly receive ObjectDisposedException internal exceptions when the address appears to be incorrect or an internal server error.

System.ObjectDisposedException: IFeatureCollection has been disposed.
Object name: 'Collection'.
   at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.ThrowContextDisposed()
   at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.ContextDisposed()
   at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.Fetch[TFeature](TFeature& cached, Func`2 factory)
   at Microsoft.AspNetCore.Http.DefaultHttpRequest.get_Method()
   at Microsoft.AspNetCore.Hosting.HostingRequestUnhandledLog.ToString()
   at ZLogger.LogStates.StringFormatterLogState`1.ToString() in D:\Programovanie\Repos\YATsDb\src\Src\ZLogger\LogStates\StringFormatterLogState.cs:line 44
   at ZLogger.LogStates.StringFormatterLogState`1.ToString(IBufferWriter`1 writer) in D:\Programovanie\Repos\YATsDb\src\Src\ZLogger\LogStates\StringFormatterLogState.cs:line 57
   at ZLogger.ZLoggerEntry`1.ToString(IBufferWriter`1 writer) in D:\Programovanie\Repos\YATsDb\src\Src\ZLogger\ZLoggerEntry.cs:line 67
   at ZLogger.Formatters.PlainTextZLoggerFormatter.FormatLogEntry[TEntry](IBufferWriter`1 writer, TEntry entry) in D:\Programovanie\Repos\YATsDb\src\Src\ZLogger\Formatters\PlainTextZLoggerFormatter.cs:line 45
   at ZLogger.ZLoggerEntry`1.FormatUtf8(IBufferWriter`1 writer, IZLoggerFormatter formatter) in D:\Programovanie\Repos\YATsDb\src\Src\ZLogger\ZLoggerEntry.cs:line 76
   at ZLogger.AsyncStreamLineMessageWriter.WriteLoop() in D:\Programovanie\Repos\YATsDb\src\Src\ZLogger\AsyncStreamLineMessageWriter.cs:line 139

The code I use is here: https://github.com/harrison314/YATsDb/blob/0f419455d87f2a8063964531def674195626ae41/src/Src/YATsDb.Lite/LoggingExtensions.cs#L45

What could be the problem?

[neuecc]

Are you capturing HttpContext or its equivalent? Since ZLogger output is performed on a separate thread, capturing these may cause incorrect behavior.

[harrison314]

Are you capturing HttpContext or its equivalent?

Not. It looks like it's happening directly in ASP.NET Core in at Microsoft.AspNetCore.Hosting.HostingRequestFinishedLog.ToString()

System.ObjectDisposedException: IFeatureCollection has been disposed.
Object name: 'Collection'.
   at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.ThrowContextDisposed()
   at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.ContextDisposed()
   at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.Fetch[TFeature](TFeature& cached, Func`2 factory)
   at Microsoft.AspNetCore.Http.DefaultHttpResponse.get_ContentLength()
   at Microsoft.AspNetCore.Hosting.HostingRequestFinishedLog.ToString()
   at ZLogger.LogStates.StringFormatterLogState`1.ToString()
   at ZLogger.LogStates.StringFormatterLogState`1.ToString(IBufferWriter`1 writer)
   at ZLogger.ZLoggerEntry`1.ToString(IBufferWriter`1 writer)
   at ZLogger.Formatters.PlainTextZLoggerFormatter.FormatLogEntry[TEntry](IBufferWriter`1 writer, TEntry entry)
   at ZLogger.ZLoggerEntry`1.FormatUtf8(IBufferWriter`1 writer, IZLoggerFormatter formatter)
   at ZLogger.AsyncStreamLineMessageWriter.WriteLoop()

Since ZLogger output is performed on a separate thread, capturing these may cause incorrect behavior.

You explained it.

So is ZLogger usable for ASP.NET Core? I mean things like UserId or requestId?

Couldn't you force the synchronous "materialization" of the logstate?

[neuecc]

Thanks for more details. HostingRequestFinishedLog seems capture HttpContext. https://github.com/dotnet/aspnetcore/blob/main/src/Hosting/Hosting/src/Internal/HostingRequestFinishedLog.cs

To be honest, capturing HttpContext is bad practice, and it's also a potentially dangerous act since HttpContext is a type that can be reused. At the same time, it could be said that delaying the rendering of logs, like ZLogger does, is also bad practice.

Instead of arguing about which is worse, should we look for a workaround? Where are you writing the logs? At the point where you're passing HostingRequestFinishedLog, you could either pass it as a string by calling ToString(), or based on the internal implementation, it might be sufficient to call ToString() once.

There's no problem at all if you retrieve UserId, RequestId, etc. without going through HttpContext when you're logging.

[harrison314]

Where are you writing the logs?

Into file and console. https://github.com/harrison314/YATsDb/blob/0f419455d87f2a8063964531def674195626ae41/src/Src/YATsDb.Lite/LoggingExtensions.cs#L11

At the point where you're passing HostingRequestFinishedLog, you could either pass it as a string by calling ToString(), or based on the internal implementation, it might be sufficient to call ToString() once.

The problem is that these logs are written outside my code. They are written by ASP.NET Core. So I can't do anything with them.

[neuecc]

thanks and find the issue in ASP.NET Core. https://github.com/dotnet/aspnetcore/issues/10556

I believe ASP.NET should be fixed, however I would like to explore a workaround. Please wait a bit.

[harrison314]

Thanks. So I'll suppress these specific errors for now. And I will wait for .NET 9.

[neuecc]

v2.5.0 format immediately so maybe solved this issue.