Skip to content
This repository has been archived by the owner on Dec 13, 2018. It is now read-only.

Logging after dispose issues? #563

Closed
davidfowl opened this issue Feb 23, 2017 · 6 comments
Closed

Logging after dispose issues? #563

davidfowl opened this issue Feb 23, 2017 · 6 comments
Assignees

Comments

@davidfowl
Copy link
Member

davidfowl commented Feb 23, 2017

Seems like kestrel tries to log during shutdown if there's a critical error and that explodes in a weird way because we're trying to write to a blocking collection that has had CompleteAdding called on it.

C:\Users\dfowler\Documents\Visual Studio 2017\Projects\WebApplication24\WebApplication24>dotnet run
Hosting environment: Production
Content root path: C:\Users\dfowler\Documents\Visual Studio 2017\Projects\WebApplication24\WebApplication24
Now listening on: http://localhost:5000
Application started. Press Ctrl+C to shut down.
fail: Microsoft.AspNetCore.Server.Kestrel[0]
      UvTimerCb
System.MissingMethodException: Method not found: 'System.Span`1<Byte> System.Buffers.IOutput.get_Buffer()'.
   at Microsoft.AspNetCore.Server.Kestrel.Internal.KestrelThread.<>c.<.cctor>b__74_0(IntPtr ptr, IntPtr arg)
   at Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.Libuv.NativeMethods.uv_walk(UvLoopHandle loop, uv_walk_cb walk_cb, IntPtr arg)
   at Microsoft.AspNetCore.Server.Kestrel.Internal.KestrelThread.OnHeartbeat(UvTimerHandle timer)
   at Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvTimerHandle.UvTimerCb(IntPtr handle)

Unhandled Exception: System.AggregateException: An error occurred while writing to logger(s). (The collection has been marked as complete with regards to additions.) ---> System.InvalidOperationException: The collection has been marked as complete with regards to additions.
   at System.Collections.Concurrent.BlockingCollection`1.TryAddWithNoTimeValidation(T item, Int32 millisecondsTimeout, CancellationToken cancellationToken)
   at Microsoft.Extensions.Logging.Console.Internal.ConsoleLoggerProcessor.EnqueueMessage(LogMessageEntry message)
   at Microsoft.Extensions.Logging.Console.ConsoleLogger.WriteMessage(LogLevel logLevel, String logName, Int32 eventId, String message, Exception exception)
   at Microsoft.Extensions.Logging.Console.ConsoleLogger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.Extensions.Logging.Logger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   --- End of inner exception stack trace ---
   at Microsoft.Extensions.Logging.Logger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.AspNetCore.Server.Kestrel.Internal.KestrelTrace.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.Extensions.Logging.LoggerExtensions.LogCritical(ILogger logger, String message, Object[] args)
   at Microsoft.AspNetCore.Server.Kestrel.Internal.KestrelEngine.Dispose()
   at Microsoft.AspNetCore.Server.Kestrel.KestrelServer.Dispose()
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.Dispose()
   at Microsoft.AspNetCore.Hosting.Internal.WebHost.Dispose()
   at Microsoft.AspNetCore.Hosting.WebHostExtensions.Run(IWebHost host, CancellationToken token, String shutdownMessage)
   at Microsoft.AspNetCore.Hosting.WebHostExtensions.Run(IWebHost host)
   at WebApplication24.Program.Main(String[] args) in C:\Users\dfowler\Documents\Visual Studio 2017\Projects\WebApplication24\WebApplication24\Program.cs:line 22

/cc @BrennanConroy

@glennc glennc added this to the 2.0.0 milestone Mar 5, 2017
@BrennanConroy
Copy link
Member

We were going to wait for this aspnet/DependencyInjection#463 which would solve the issue

@BrennanConroy
Copy link
Member

Should be gone now

@halter73
Copy link
Member

This isn't fixed 😢

Unhandled Exception: System.AggregateException: An error occurred while writing to logger(s). (The collection has been marked as complete with regards to additions.) ---> System.InvalidOperationException: The collection has been marked as complete with regards to additions.

   at System.Collections.Concurrent.BlockingCollection`1.TryAddWithNoTimeValidation(T item, Int32 millisecondsTimeout, CancellationToken cancellationToken)
   at Microsoft.Extensions.Logging.Console.Internal.ConsoleLoggerProcessor.EnqueueMessage(LogMessageEntry message)
   at Microsoft.Extensions.Logging.Console.ConsoleLogger.WriteMessage(LogLevel logLevel, String logName, Int32 eventId, String message, Exception exception)
   at Microsoft.Extensions.Logging.Console.ConsoleLogger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.Extensions.Logging.Logger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   --- End of inner exception stack trace ---
   at Microsoft.Extensions.Logging.Logger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.AspNetCore.Server.Kestrel.Internal.KestrelTrace.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter) in C:\Users\shalter\dev\Universe\KestrelHttpServer\src\Microsoft.AspNetCore.Server.Kestrel\Internal\Infrastructure\KestrelTrace.cs:line 192
   at Microsoft.Extensions.Logging.LoggerExtensions.LogCritical(ILogger logger, String message, Object[] args)
   at Microsoft.AspNetCore.Server.Kestrel.Internal.KestrelEngine.Dispose() in C:\Users\shalter\dev\Universe\KestrelHttpServer\src\Microsoft.AspNetCore.Server.Kestrel\Internal\KestrelEngine.cs:line 65
   at Microsoft.AspNetCore.Server.Kestrel.KestrelServer.Dispose() in C:\Users\shalter\dev\Universe\KestrelHttpServer\src\Microsoft.AspNetCore.Server.Kestrel\KestrelServer.cs:line 236
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.Dispose()
   at Microsoft.AspNetCore.Hosting.Internal.WebHost.Dispose()
   at Microsoft.AspNetCore.Hosting.WebHostExtensions.Run(IWebHost host, CancellationToken token, String shutdownMessage)
   at Microsoft.AspNetCore.Hosting.WebHostExtensions.Run(IWebHost host)
   at SampleApp.Startup.Main(String[] args) in C:\Users\shalter\dev\Universe\KestrelHttpServer\samples\SampleApp\Startup.cs:line 74

@davidfowl
Copy link
Member Author

I think we need to fix both bugs. This shouldn't throw, it should just noop

@moozzyk
Copy link
Contributor

moozzyk commented Mar 28, 2017

Same here:

PS C:\Source\SignalR-Core\samples\SocketsSample>
Unhandled Exception: System.AggregateException: An error occurred while writing to logger(s). (The collection has been marked as complete with regards to additions.) ---> System.InvalidOperationException: The collection has been marked as complete with regards to additions.
   at System.Collections.Concurrent.BlockingCollection`1.TryAddWithNoTimeValidation(T item, Int32 millisecondsTimeout, CancellationToken cancellationToken)
   at Microsoft.Extensions.Logging.Console.Internal.ConsoleLoggerProcessor.EnqueueMessage(LogMessageEntry message)
   at Microsoft.Extensions.Logging.Console.ConsoleLogger.WriteMessage(LogLevel logLevel, String logName, Int32 eventId, String message, Exception exception)
   at Microsoft.Extensions.Logging.Console.ConsoleLogger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.Extensions.Logging.Logger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   --- End of inner exception stack trace ---
   at Microsoft.Extensions.Logging.Logger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.AspNetCore.Server.Kestrel.Internal.KestrelTrace.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.Extensions.Logging.LoggerExtensions.LogCritical(ILogger logger, String message, Object[] args)
   at Microsoft.AspNetCore.Server.Kestrel.Internal.KestrelEngine.Dispose()
   at Microsoft.AspNetCore.Server.Kestrel.KestrelServer.Dispose()
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.Dispose()
   at Microsoft.AspNetCore.Hosting.Internal.WebHost.Dispose()
   at Microsoft.AspNetCore.Hosting.WebHostExtensions.Run(IWebHost host, CancellationToken token, String shutdownMessage)
   at Microsoft.AspNetCore.Hosting.WebHostExtensions.Run(IWebHost host)
   at SocketsSample.Program.Main(String[] args) in C:\Source\SignalR-Core\samples\SocketsSample\Program.cs:line 24

@BrennanConroy
Copy link
Member

Fixed via ab43352

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

5 participants