Closed msxdan closed 2 years ago
can you share your code for StudyController
?
so it seems most member of DefaultHttpRequest can throw a nullref if accessed concurrently https://github.com/dotnet/aspnetcore/issues/42040 so we can handle that. However i am unable to work out why this would be an infinite loop, nor repro it. @mattjohnsonpint thoughts?
Do we know why there's concurrent access? A null check isn't enough to fix it.
However i am unable to work out why this would be an infinite loop, nor repro it
Concurrent access to dictionaries.
@davidfowl at the moment no. the code in question is here https://github.com/getsentry/sentry-dotnet/tree/main/src/Sentry.AspNetCore which i am reviewing for this scenario.
but you will notice the original stack trace does not occur from within sentry
2022-06-06 10:25:29.7338|ERROR|App.Controllers.StudyController|Unhandled controller exception: Object reference not set to an instance of an object.|System.NullReferenceException: Object reference not set to an instance of an object.
at Microsoft.AspNetCore.Http.DefaultHttpRequest.get_BodyReader()
at Microsoft.AspNetCore.Http.Features.FormFeature.InnerReadFormAsync(CancellationToken cancellationToken)
at Microsoft.AspNetCore.Mvc.ModelBinding.FormValueProviderFactory.AddValueProviderAsync(ValueProviderFactoryContext context)
at Microsoft.AspNetCore.Mvc.ModelBinding.CompositeValueProvider.CreateAsync(ActionContext actionContext, IList`1 factories)
at Microsoft.AspNetCore.Mvc.ModelBinding.CompositeValueProvider.TryCreateAsync(ActionContext actionContext, IList`1 factories)
at Microsoft.AspNetCore.Mvc.Controllers.ControllerBinderDelegateProvider.<>c__DisplayClass0_0.<<CreateBinderDelegate>g__Bind|0>d.MoveNext()
--- End of stack trace from previous location ---
at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeInnerFilterAsync>g__Awaited|13_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeNextExceptionFilterAsync>g__Awaited|26_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
So i am unsure if the sentry integration is causing this, or if it is just hitting some other underlying issue.
@msxdan how often does this occur?
@davidfowl
Concurrent access to dictionaries.
not that i can find
but you will notice the original stack trace does not occur from within sentry
Turn off the sentry and see if it repros?
There's a common pattern where this happens around usage of the IHttpContextAccessor
.
@davidfowl
Turn off the sentry and see if it repros?
yeah i was intending to ask @msxdan this based on the answer to "how often does this occur?"
I'm working with @msxdan on this issue. I'll try to clarify some points.
StudyController
has much to do with this controller specifically (it happened on other controllers). Maybe there's some issue on our middleware or binding logic that causes the NRE. Actually, we have another trace with an OperationCancelledException
that is not related to any specific controller.Debug
property in Sentry options to see if the issue is solved as the message Failed to extract body.
is logged only when the Debug flag is set (that's what I understood reading the code).From what I see in the log, those are written on disk through NLog, which seems to work and from what I figured out, then NLog sends the exception to the Sentry target that fails reading the Form
property and then logs this exception again on NLog and enters a loop. But I may be wrong.
I add this excerpt from the thread dump we captured in Azure, originally has more than 80K lines with the same over and over:
...
NLog.Logger.Log(System.Type, NLog.LogEventInfo)+78
NLog.Extensions.Logging.NLogLogger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3)+7f
Microsoft.Extensions.Logging.Logger.g__LoggerLog|12_0[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.ILogger, System.Exception, System.Func`3, System.Collections.Generic.List`1 ByRef, Microsoft.Extensions.Logging.FormattedLogValues ByRef)+4e
Microsoft.Extensions.Logging.Logger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3)+6e
Microsoft.Extensions.Logging.Logger`1[[System.__Canon, System.Private.CoreLib]].Microsoft.Extensions.Logging.ILogger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3)+3c
Microsoft.Extensions.Logging.LoggerExtensions.Log(Microsoft.Extensions.Logging.ILogger, Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, System.Exception, System.String, System.Object[])+5f
Sentry.Extensions.Logging.MelDiagnosticLogger.Log(Sentry.SentryLevel, System.String, System.Exception, System.Object[])+42
Sentry.Extensibility.DiagnosticLoggerExtensions.LogError(Sentry.SentryOptions, System.String, System.Exception)+4b
Sentry.AspNetCore.ScopeExtensions.Populate(Sentry.Scope, Microsoft.AspNetCore.Http.HttpContext, Sentry.AspNetCore.SentryAspNetCoreOptions)+16f
Sentry.AspNetCore.SentryMiddleware.PopulateScope(Microsoft.AspNetCore.Http.HttpContext, Sentry.Scope)+bf
Sentry.AspNetCore.SentryMiddleware+<>c__DisplayClass8_2.b__5(System.Object, System.EventArgs)+2a
Sentry.Scope.Evaluate()+82
Sentry.SentryClient.DoSendEvent(Sentry.SentryEvent, Sentry.Scope)+242
Sentry.SentryClient.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)+5d
Sentry.Internal.Hub.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)+15a
Sentry.Extensibility.HubAdapter.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)+17
Sentry.NLog.SentryTarget.Write(NLog.LogEventInfo)+459
NLog.Targets.Target.Write(NLog.Common.AsyncLogEventInfo)+23
NLog.Targets.Target.WriteAsyncThreadSafe(NLog.Common.AsyncLogEventInfo)+72
NLog.Targets.Target.WriteAsyncLogEvent(NLog.Common.AsyncLogEventInfo)+112
NLog.LoggerImpl.WriteToTargetWithFilterChain(NLog.Targets.Target, NLog.Filters.FilterResult, NLog.LogEventInfo, NLog.Common.AsyncContinuation)+60
NLog.LoggerImpl.Write(System.Type, NLog.Internal.TargetWithFilterChain, NLog.LogEventInfo, NLog.LogFactory)+e5
NLog.Logger.Log(System.Type, NLog.LogEventInfo)+78
NLog.Extensions.Logging.NLogLogger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3)+7f
Microsoft.Extensions.Logging.Logger.g__LoggerLog|12_0[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.ILogger, System.Exception, System.Func`3, System.Collections.Generic.List`1 ByRef, Microsoft.Extensions.Logging.FormattedLogValues ByRef)+4e
Microsoft.Extensions.Logging.Logger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3)+6e
Microsoft.Extensions.Logging.Logger`1[[System.__Canon, System.Private.CoreLib]].Microsoft.Extensions.Logging.ILogger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3)+3c
Microsoft.Extensions.Logging.LoggerExtensions.Log(Microsoft.Extensions.Logging.ILogger, Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, System.Exception, System.String, System.Object[])+5f
Sentry.Extensions.Logging.MelDiagnosticLogger.Log(Sentry.SentryLevel, System.String, System.Exception, System.Object[])+42
Sentry.Extensibility.DiagnosticLoggerExtensions.LogError(Sentry.SentryOptions, System.String, System.Exception)+4b
Sentry.AspNetCore.ScopeExtensions.Populate(Sentry.Scope, Microsoft.AspNetCore.Http.HttpContext, Sentry.AspNetCore.SentryAspNetCoreOptions)+16f
Sentry.AspNetCore.SentryMiddleware.PopulateScope(Microsoft.AspNetCore.Http.HttpContext, Sentry.Scope)+bf
Sentry.AspNetCore.SentryMiddleware+<>c__DisplayClass8_2.b__5(System.Object, System.EventArgs)+2a
Sentry.Scope.Evaluate()+82
Sentry.SentryClient.DoSendEvent(Sentry.SentryEvent, Sentry.Scope)+242
Sentry.SentryClient.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)+5d
Sentry.Internal.Hub.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)+15a
Sentry.Extensibility.HubAdapter.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)+17
Sentry.NLog.SentryTarget.Write(NLog.LogEventInfo)+459
NLog.Targets.Target.Write(NLog.Common.AsyncLogEventInfo)+23
NLog.Targets.Target.WriteAsyncThreadSafe(NLog.Common.AsyncLogEventInfo)+72
NLog.Targets.Target.WriteAsyncLogEvent(NLog.Common.AsyncLogEventInfo)+112
NLog.LoggerImpl.WriteToTargetWithFilterChain(NLog.Targets.Target, NLog.Filters.FilterResult, NLog.LogEventInfo, NLog.Common.AsyncContinuation)+60
NLog.LoggerImpl.Write(System.Type, NLog.Internal.TargetWithFilterChain, NLog.LogEventInfo, NLog.LogFactory)+e5
NLog.Logger.Log(System.Type, NLog.LogEventInfo)+78
NLog.Extensions.Logging.NLogLogger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3)+7f
Microsoft.Extensions.Logging.Logger.g__LoggerLog|12_0[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.ILogger, System.Exception, System.Func`3, System.Collections.Generic.List`1 ByRef, Microsoft.Extensions.Logging.FormattedLogValues ByRef)+4e
Microsoft.Extensions.Logging.Logger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3)+6e
Microsoft.Extensions.Logging.Logger`1[[System.__Canon, System.Private.CoreLib]].Microsoft.Extensions.Logging.ILogger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3)+3c
Microsoft.Extensions.Logging.LoggerExtensions.Log(Microsoft.Extensions.Logging.ILogger, Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, System.Exception, System.String, System.Object[])+5f
Sentry.Extensions.Logging.MelDiagnosticLogger.Log(Sentry.SentryLevel, System.String, System.Exception, System.Object[])+42
Sentry.Extensibility.DiagnosticLoggerExtensions.LogError(Sentry.SentryOptions, System.String, System.Exception)+4b
Sentry.AspNetCore.ScopeExtensions.Populate(Sentry.Scope, Microsoft.AspNetCore.Http.HttpContext, Sentry.AspNetCore.SentryAspNetCoreOptions)+16f
Sentry.AspNetCore.SentryMiddleware.PopulateScope(Microsoft.AspNetCore.Http.HttpContext, Sentry.Scope)+bf
Sentry.AspNetCore.SentryMiddleware+<>c__DisplayClass8_2.b__5(System.Object, System.EventArgs)+2a
Sentry.Scope.Evaluate()+82
Sentry.SentryClient.DoSendEvent(Sentry.SentryEvent, Sentry.Scope)+242
Sentry.SentryClient.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)+5d
Sentry.Internal.Hub.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)+15a
Sentry.Extensibility.HubAdapter.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)+17
Sentry.NLog.SentryTarget.Write(NLog.LogEventInfo)+459
NLog.Targets.Target.Write(NLog.Common.AsyncLogEventInfo)+23
NLog.Targets.Target.WriteAsyncThreadSafe(NLog.Common.AsyncLogEventInfo)+72
NLog.Targets.Target.WriteAsyncLogEvent(NLog.Common.AsyncLogEventInfo)+112
NLog.LoggerImpl.WriteToTargetWithFilterChain(NLog.Targets.Target, NLog.Filters.FilterResult, NLog.LogEventInfo, NLog.Common.AsyncContinuation)+60
NLog.LoggerImpl.Write(System.Type, NLog.Internal.TargetWithFilterChain, NLog.LogEventInfo, NLog.LogFactory)+e5
NLog.Logger.Log(System.Type, NLog.LogEventInfo)+78
...
I hope this helps.
Is this happening on windows?
Is this happening on windows?
Azure AppService, but they run in windows
That stack is helpful but the redaction makes it hard to figure out what the bottom of the stack is. Does this app use the IHttpContextAccessor anywhere in the logging stack?
As addition to the first log, this is the log of the second time this happened
Looks like after cancelling a task Sentry tries to catch the exception and enters an infinite loop again, this time the exception was thrown by System.Type
As metioned above, we've disabled the debug
property in Sentry and we'll be monitoring our app to see if this happens again.
2022-06-08 10:00:35.4185|WARN|Sentry.ISentryClient|The attempt to queue the event failed. Items in queue: 1|
2022-06-08 10:00:37.3207|WARN|Microsoft.AspNetCore.Authentication.OpenIdConnect.OpenIdConnectHandler|'.AspNetCore.Correlation.QjrP-RVLxZ8zXBwxzSn886LULZJA7LchkYn6mVAdfT4' cookie not found.|
2022-06-08 10:00:37.3434|ERROR|System.Type|Correlation failed.|System.Exception: Correlation failed.
2022-06-08 10:00:37.4749|WARN|Sentry.ISentryClient|The attempt to queue the event failed. Items in queue: 1|
2022-06-08 10:00:50.5459|INFO|App.Infrastructure.Implementation.Caching.InMemoryCache|Cache hit ...
2022-06-08 10:00:50.5622|INFO|App.Infrastructure.Implementation.Caching.InMemoryCache|Cache hit ...
2022-06-08 10:00:50.5821|INFO|App.Infrastructure.Implementation.Caching.InMemoryCache|Cache hit ...
2022-06-08 10:00:50.5997|INFO|App.Infrastructure.Implementation.Caching.InMemoryCache|Cache hit ...
2022-06-08 10:00:50.6219|INFO|App.Infrastructure.Implementation.Caching.InMemoryCache|Cache hit ...
2022-06-08 10:00:50.6384|INFO|App.Infrastructure.Implementation.Caching.InMemoryCache|Cache hit ...
2022-06-08 10:00:57.8516|ERROR|System.Type|The operation was canceled.|System.OperationCanceledException: The operation was canceled.
at System.Threading.CancellationToken.ThrowOperationCanceledException()
at System.IO.Pipelines.Pipe.GetReadAsyncResult()
at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
at Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext.ReadAsync(Memory`1 memory, CancellationToken cancellationToken)
at Microsoft.AspNetCore.Server.IIS.Core.HttpRequestStream.ReadAsyncInternal(Memory`1 buffer, CancellationToken cancellationToken)
at Microsoft.AspNetCore.WebUtilities.FileBufferingReadStream.ReadAsync(Memory`1 buffer, CancellationToken cancellationToken)
at System.IO.Pipelines.StreamPipeReader.<ReadAsync>g__Core|36_0(StreamPipeReader reader, CancellationTokenSource tokenSource, CancellationToken cancellationToken)
at Microsoft.AspNetCore.WebUtilities.FormPipeReader.ReadFormAsync(CancellationToken cancellationToken)
at Microsoft.AspNetCore.Http.Features.FormFeature.InnerReadFormAsync(CancellationToken cancellationToken)
at Microsoft.AspNetCore.Authentication.OpenIdConnect.OpenIdConnectHandler.HandleRemoteAuthenticateAsync()
at Microsoft.AspNetCore.Authentication.RemoteAuthenticationHandler`1.HandleRequestAsync()
2022-06-08 10:00:59.0323|INFO|App.Infrastructure.Implementation.Caching.InMemoryCache|Cache hit ...
2022-06-08 10:00:59.1004|INFO|App.Infrastructure.Implementation.Caching.InMemoryCache|Cache hit ...
2022-06-08 10:00:59.1177|INFO|App.Infrastructure.Implementation.Caching.InMemoryCache|Cache hit ...
2022-06-08 10:01:06.3987|ERROR|Sentry.ISentryClient|Failed to extract body.|System.OperationCanceledException: The operation was canceled.
at System.Threading.CancellationToken.ThrowOperationCanceledException()
at System.IO.Pipelines.Pipe.GetReadAsyncResult()
at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
at Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext.ReadAsync(Memory`1 memory, CancellationToken cancellationToken)
at Microsoft.AspNetCore.Server.IIS.Core.HttpRequestStream.ReadAsyncInternal(Memory`1 buffer, CancellationToken cancellationToken)
at Microsoft.AspNetCore.WebUtilities.FileBufferingReadStream.ReadAsync(Memory`1 buffer, CancellationToken cancellationToken)
at System.IO.Pipelines.StreamPipeReader.<ReadAsync>g__Core|36_0(StreamPipeReader reader, CancellationTokenSource tokenSource, CancellationToken cancellationToken)
at Microsoft.AspNetCore.WebUtilities.FormPipeReader.ReadFormAsync(CancellationToken cancellationToken)
at Microsoft.AspNetCore.Http.Features.FormFeature.InnerReadFormAsync(CancellationToken cancellationToken)
at Microsoft.AspNetCore.Http.Features.FormFeature.ReadForm()
at Microsoft.AspNetCore.Http.DefaultHttpRequest.get_Form()
at Sentry.AspNetCore.HttpRequestAdapter.get_Form() in /_/src/Sentry.AspNetCore/HttpRequestAdapter.cs:line 17
at Sentry.Extensibility.FormRequestPayloadExtractor.DoExtractPayLoad(IHttpRequest request) in /_/src/Sentry/Extensibility/FormRequestPayloadExtractor.cs:line 24
at Sentry.Extensibility.BaseRequestPayloadExtractor.ExtractPayload(IHttpRequest request) in /_/src/Sentry/Extensibility/BaseRequestPayloadExtractor.cs:line 33
at Sentry.Extensibility.RequestBodyExtractionDispatcher.ExtractPayload(IHttpRequest request) in /_/src/Sentry/Extensibility/RequestBodyExtractionDispatcher.cs:line 53
at Sentry.AspNetCore.ScopeExtensions.SetBody(Scope scope, HttpContext context, SentryAspNetCoreOptions options) in /_/src/Sentry.AspNetCore/ScopeExtensions.cs:line 163
at Sentry.AspNetCore.ScopeExtensions.Populate(Scope scope, HttpContext context, SentryAspNetCoreOptions options) in /_/src/Sentry.AspNetCore/ScopeExtensions.cs:line 55
2022-06-08 10:01:06.4582|ERROR|Sentry.ISentryClient|Failed to extract body.|System.OperationCanceledException: The operation was canceled.
at System.Threading.CancellationToken.ThrowOperationCanceledException()
at System.IO.Pipelines.Pipe.GetReadAsyncResult()
at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
at Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext.ReadAsync(Memory`1 memory, CancellationToken cancellationToken)
at Microsoft.AspNetCore.Server.IIS.Core.HttpRequestStream.ReadAsyncInternal(Memory`1 buffer, CancellationToken cancellationToken)
at Microsoft.AspNetCore.WebUtilities.FileBufferingReadStream.ReadAsync(Memory`1 buffer, CancellationToken cancellationToken)
at System.IO.Pipelines.StreamPipeReader.<ReadAsync>g__Core|36_0(StreamPipeReader reader, CancellationTokenSource tokenSource, CancellationToken cancellationToken)
at Microsoft.AspNetCore.WebUtilities.FormPipeReader.ReadFormAsync(CancellationToken cancellationToken)
at Microsoft.AspNetCore.Http.Features.FormFeature.InnerReadFormAsync(CancellationToken cancellationToken)
at Microsoft.AspNetCore.Http.Features.FormFeature.ReadForm()
at Microsoft.AspNetCore.Http.DefaultHttpRequest.get_Form()
at Sentry.AspNetCore.HttpRequestAdapter.get_Form() in /_/src/Sentry.AspNetCore/HttpRequestAdapter.cs:line 17
at Sentry.Extensibility.FormRequestPayloadExtractor.DoExtractPayLoad(IHttpRequest request) in /_/src/Sentry/Extensibility/FormRequestPayloadExtractor.cs:line 24
at Sentry.Extensibility.BaseRequestPayloadExtractor.ExtractPayload(IHttpRequest request) in /_/src/Sentry/Extensibility/BaseRequestPayloadExtractor.cs:line 33
at Sentry.Extensibility.RequestBodyExtractionDispatcher.ExtractPayload(IHttpRequest request) in /_/src/Sentry/Extensibility/RequestBodyExtractionDispatcher.cs:line 53
at Sentry.AspNetCore.ScopeExtensions.SetBody(Scope scope, HttpContext context, SentryAspNetCoreOptions options) in /_/src/Sentry.AspNetCore/ScopeExtensions.cs:line 163
at Sentry.AspNetCore.ScopeExtensions.Populate(Scope scope, HttpContext context, SentryAspNetCoreOptions options) in /_/src/Sentry.AspNetCore/ScopeExtensions.cs:line 55
2022-06-08 10:01:10.7522|ERROR|Sentry.ISentryClient|Failed to extract body.|System.OperationCanceledException: The operation was canceled.
at System.Threading.CancellationToken.ThrowOperationCanceledException()
at System.IO.Pipelines.Pipe.GetReadAsyncResult()
at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
at Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext.ReadAsync(Memory`1 memory, CancellationToken cancellationToken)
at Microsoft.AspNetCore.Server.IIS.Core.HttpRequestStream.ReadAsyncInternal(Memory`1 buffer, CancellationToken cancellationToken)
at Microsoft.AspNetCore.WebUtilities.FileBufferingReadStream.ReadAsync(Memory`1 buffer, CancellationToken cancellationToken)
at System.IO.Pipelines.StreamPipeReader.<ReadAsync>g__Core|36_0(StreamPipeReader reader, CancellationTokenSource tokenSource, CancellationToken cancellationToken)
at Microsoft.AspNetCore.WebUtilities.FormPipeReader.ReadFormAsync(CancellationToken cancellationToken)
at Microsoft.AspNetCore.Http.Features.FormFeature.InnerReadFormAsync(CancellationToken cancellationToken)
at Microsoft.AspNetCore.Http.Features.FormFeature.ReadForm()
at Microsoft.AspNetCore.Http.DefaultHttpRequest.get_Form()
at Sentry.AspNetCore.HttpRequestAdapter.get_Form() in /_/src/Sentry.AspNetCore/HttpRequestAdapter.cs:line 17
at Sentry.Extensibility.FormRequestPayloadExtractor.DoExtractPayLoad(IHttpRequest request) in /_/src/Sentry/Extensibility/FormRequestPayloadExtractor.cs:line 24
at Sentry.Extensibility.BaseRequestPayloadExtractor.ExtractPayload(IHttpRequest request) in /_/src/Sentry/Extensibility/BaseRequestPayloadExtractor.cs:line 33
at Sentry.Extensibility.RequestBodyExtractionDispatcher.ExtractPayload(IHttpRequest request) in /_/src/Sentry/Extensibility/RequestBodyExtractionDispatcher.cs:line 53
at Sentry.AspNetCore.ScopeExtensions.SetBody(Scope scope, HttpContext context, SentryAspNetCoreOptions options) in /_/src/Sentry.AspNetCore/ScopeExtensions.cs:line 163
at Sentry.AspNetCore.ScopeExtensions.Populate(Scope scope, HttpContext context, SentryAspNetCoreOptions options) in /_/src/Sentry.AspNetCore/ScopeExtensions.cs:line 55
2022-06-08 10:01:10.7786|INFO|App.Infrastructure.Implementation.LockService.LockService|
2022-06-08 10:01:10.7951|ERROR|Sentry.ISentryClient|Failed to extract body.|System.OperationCanceledException: The operation was canceled.
at System.Threading.CancellationToken.ThrowOperationCanceledException()
at System.IO.Pipelines.Pipe.GetReadAsyncResult()
at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
at Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext.ReadAsync(Memory`1 memory, CancellationToken cancellationToken)
at Microsoft.AspNetCore.Server.IIS.Core.HttpRequestStream.ReadAsyncInternal(Memory`1 buffer, CancellationToken cancellationToken)
at Microsoft.AspNetCore.WebUtilities.FileBufferingReadStream.ReadAsync(Memory`1 buffer, CancellationToken cancellationToken)
at System.IO.Pipelines.StreamPipeReader.<ReadAsync>g__Core|36_0(StreamPipeReader reader, CancellationTokenSource tokenSource, CancellationToken cancellationToken)
at Microsoft.AspNetCore.WebUtilities.FormPipeReader.ReadFormAsync(CancellationToken cancellationToken)
at Microsoft.AspNetCore.Http.Features.FormFeature.InnerReadFormAsync(CancellationToken cancellationToken)
at Microsoft.AspNetCore.Http.Features.FormFeature.ReadForm()
at Microsoft.AspNetCore.Http.DefaultHttpRequest.get_Form()
at Sentry.AspNetCore.HttpRequestAdapter.get_Form() in /_/src/Sentry.AspNetCore/HttpRequestAdapter.cs:line 17
at Sentry.Extensibility.FormRequestPayloadExtractor.DoExtractPayLoad(IHttpRequest request) in /_/src/Sentry/Extensibility/FormRequestPayloadExtractor.cs:line 24
at Sentry.Extensibility.BaseRequestPayloadExtractor.ExtractPayload(IHttpRequest request) in /_/src/Sentry/Extensibility/BaseRequestPayloadExtractor.cs:line 33
at Sentry.Extensibility.RequestBodyExtractionDispatcher.ExtractPayload(IHttpRequest request) in /_/src/Sentry/Extensibility/RequestBodyExtractionDispatcher.cs:line 53
at Sentry.AspNetCore.ScopeExtensions.SetBody(Scope scope, HttpContext context, SentryAspNetCoreOptions options) in /_/src/Sentry.AspNetCore/ScopeExtensions.cs:line 163
at Sentry.AspNetCore.ScopeExtensions.Populate(Scope scope, HttpContext context, SentryAspNetCoreOptions options) in /_/src/Sentry.AspNetCore/ScopeExtensions.cs:line 55
That stack is helpful but the redaction makes it hard to figure out what the bottom of the stack is. Does this app use the IHttpContextAccessor anywhere in the logging stack?
My teammate @mcliment knows better how it's done, he will reply asap
I add the very beginning of the stack trace until it starst looping (cc @davidfowl):
....
NLog.Extensions.Logging.NLogLogger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3<Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.String>)
Microsoft.Extensions.Logging.Logger.<Log>g__LoggerLog|12_0[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.ILogger, System.Exception, System.Func`3<Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.String>, System.Collections.Generic.List`1<System.Exception>ByRef, Microsoft.Extensions.Logging.FormattedLogValuesByRef)
Microsoft.Extensions.Logging.Logger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3<Microsoft.Extensions.Logging.FormattedLogValues,System.Exception,System.String>)+6e
Microsoft.Extensions.Logging.Logger`1[[System.__Canon, System.Private.CoreLib]].Microsoft.Extensions.Logging.ILogger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3<Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.String>)
Microsoft.Extensions.Logging.LoggerExtensions.Log(Microsoft.Extensions.Logging.ILogger, Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, System.Exception, System.String, System.Object[])+5f
Microsoft.Extensions.Logging.LoggerExtensions.Log(Microsoft.Extensions.Logging.ILogger, Microsoft.Extensions.Logging.LogLevel, System.Exception, System.String, System.Object[])
Sentry.Extensions.Logging.MelDiagnosticLogger.Log(Sentry.SentryLevel, System.String, System.Exception, System.Object[])
Sentry.Extensibility.DiagnosticLoggerExtensions.LogIfEnabled(Sentry.Extensibility.IDiagnosticLogger, Sentry.SentryLevel, System.Exception, System.String)+32
Sentry.Extensibility.DiagnosticLoggerExtensions.LogError(Sentry.SentryOptions, System.String, System.Exception)
Sentry.AspNetCore.ScopeExtensions.Populate(Sentry.Scope, Microsoft.AspNetCore.Http.HttpContext, Sentry.AspNetCore.SentryAspNetCoreOptions)
Sentry.AspNetCore.SentryMiddleware.PopulateScope(Microsoft.AspNetCore.Http.HttpContext, Sentry.Scope)
Sentry.AspNetCore.SentryMiddleware+<>c__DisplayClass8_2.<InvokeAsync>b__5(System.Object, System.EventArgs)
Sentry.Scope.Evaluate()
Sentry.SentryClient.DoSendEvent(Sentry.SentryEvent, Sentry.Scope)+242
Sentry.SentryClient.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)
Sentry.Internal.Hub.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)
Sentry.SentrySdk.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)
Sentry.Extensibility.HubAdapter.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)
Sentry.NLog.SentryTarget.Write(NLog.LogEventInfo)+459
NLog.Targets.Target.Write(NLog.Common.AsyncLogEventInfo)
NLog.Targets.Target.WriteAsyncThreadSafe(NLog.Common.AsyncLogEventInfo)
NLog.Targets.Target.WriteAsyncLogEvent(NLog.Common.AsyncLogEventInfo)+ffffffffc48f0f5e
NLog.LoggerImpl.WriteToTargetWithFilterChain(NLog.Targets.Target, NLog.Filters.FilterResult, NLog.LogEventInfo, NLog.Common.AsyncContinuation)+ffffffffc48f0db4
NLog.LoggerImpl.Write(System.Type, NLog.Internal.TargetWithFilterChain, NLog.LogEventInfo, NLog.LogFactory)+e5
NLog.Logger.WriteToTargets(System.Type, NLog.LogEventInfo, NLog.Internal.TargetWithFilterChain)+ffffffffc252d5a0
NLog.Logger.Log(System.Type, NLog.LogEventInfo)+ffffffffc252d4ef
NLog.Extensions.Logging.NLogLogger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3<Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.String>)
Microsoft.Extensions.Logging.Logger.<Log>g__LoggerLog|12_0[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.ILogger, System.Exception, System.Func`3<Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.String>, System.Collections.Generic.List`1<System.Exception>ByRef, Microsoft.Extensions.Logging.FormattedLogValuesByRef)
Microsoft.Extensions.Logging.Logger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3<Microsoft.Extensions.Logging.FormattedLogValues,System.Exception,System.String>)+6e
Microsoft.Extensions.Logging.Logger`1[[System.__Canon, System.Private.CoreLib]].Microsoft.Extensions.Logging.ILogger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3<Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.String>)
Microsoft.Extensions.Logging.LoggerExtensions.Log(Microsoft.Extensions.Logging.ILogger, Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, System.Exception, System.String, System.Object[])+5f
Microsoft.Extensions.Logging.LoggerExtensions.Log(Microsoft.Extensions.Logging.ILogger, Microsoft.Extensions.Logging.LogLevel, System.Exception, System.String, System.Object[])
Sentry.Extensions.Logging.MelDiagnosticLogger.Log(Sentry.SentryLevel, System.String, System.Exception, System.Object[])
Sentry.Extensibility.DiagnosticLoggerExtensions.LogIfEnabled(Sentry.Extensibility.IDiagnosticLogger, Sentry.SentryLevel, System.Exception, System.String)+32
Sentry.Extensibility.DiagnosticLoggerExtensions.LogError(Sentry.SentryOptions, System.String, System.Exception)
Sentry.AspNetCore.ScopeExtensions.Populate(Sentry.Scope, Microsoft.AspNetCore.Http.HttpContext, Sentry.AspNetCore.SentryAspNetCoreOptions)
Sentry.AspNetCore.SentryMiddleware.PopulateScope(Microsoft.AspNetCore.Http.HttpContext, Sentry.Scope)
Sentry.AspNetCore.SentryMiddleware+<>c__DisplayClass8_2.<InvokeAsync>b__5(System.Object, System.EventArgs)
Sentry.Scope.Evaluate()
Sentry.SentryClient.DoSendEvent(Sentry.SentryEvent, Sentry.Scope)+242
Sentry.SentryClient.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)
Sentry.Internal.Hub.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)
Sentry.SentrySdk.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)
Sentry.Extensibility.HubAdapter.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)
Sentry.NLog.SentryTarget.Write(NLog.LogEventInfo)+459
NLog.Targets.Target.Write(NLog.Common.AsyncLogEventInfo)
NLog.Targets.Target.WriteAsyncThreadSafe(NLog.Common.AsyncLogEventInfo)
NLog.Targets.Target.WriteAsyncLogEvent(NLog.Common.AsyncLogEventInfo)+ffffffffc48f0f5e
NLog.LoggerImpl.WriteToTargetWithFilterChain(NLog.Targets.Target, NLog.Filters.FilterResult, NLog.LogEventInfo, NLog.Common.AsyncContinuation)+ffffffffc48f0db4
NLog.LoggerImpl.Write(System.Type, NLog.Internal.TargetWithFilterChain, NLog.LogEventInfo, NLog.LogFactory)+e5
NLog.Logger.WriteToTargets(System.Type, NLog.LogEventInfo, NLog.Internal.TargetWithFilterChain)+ffffffffc252d5a0
NLog.Logger.Log(System.Type, NLog.LogEventInfo)+ffffffffc252d4ef
NLog.Extensions.Logging.NLogLogger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3<Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.String>)
Microsoft.Extensions.Logging.Logger.<Log>g__LoggerLog|12_0[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.ILogger, System.Exception, System.Func`3<Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.String>, System.Collections.Generic.List`1<System.Exception>ByRef, Microsoft.Extensions.Logging.FormattedLogValuesByRef)
Microsoft.Extensions.Logging.Logger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3<Microsoft.Extensions.Logging.FormattedLogValues,System.Exception,System.String>)+6e
Microsoft.Extensions.Logging.Logger`1[[System.__Canon, System.Private.CoreLib]].Microsoft.Extensions.Logging.ILogger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3<Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.String>)
Microsoft.Extensions.Logging.LoggerExtensions.Log(Microsoft.Extensions.Logging.ILogger, Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, System.Exception, System.String, System.Object[])+5f
Microsoft.Extensions.Logging.LoggerExtensions.Log(Microsoft.Extensions.Logging.ILogger, Microsoft.Extensions.Logging.LogLevel, System.Exception, System.String, System.Object[])
Sentry.Extensions.Logging.MelDiagnosticLogger.Log(Sentry.SentryLevel, System.String, System.Exception, System.Object[])
Sentry.Extensibility.DiagnosticLoggerExtensions.LogIfEnabled(Sentry.Extensibility.IDiagnosticLogger, Sentry.SentryLevel, System.Exception, System.String)+32
Sentry.Extensibility.DiagnosticLoggerExtensions.LogError(Sentry.SentryOptions, System.String, System.Exception)
Sentry.AspNetCore.ScopeExtensions.Populate(Sentry.Scope, Microsoft.AspNetCore.Http.HttpContext, Sentry.AspNetCore.SentryAspNetCoreOptions)
Sentry.AspNetCore.SentryMiddleware.PopulateScope(Microsoft.AspNetCore.Http.HttpContext, Sentry.Scope)
Sentry.AspNetCore.SentryMiddleware+<>c__DisplayClass8_2.<InvokeAsync>b__5(System.Object, System.EventArgs)
Sentry.Scope.Evaluate()
Sentry.SentryClient.DoSendEvent(Sentry.SentryEvent, Sentry.Scope)+242
Sentry.SentryClient.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)
Sentry.Internal.Hub.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)
Sentry.SentrySdk.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)
Sentry.Extensibility.HubAdapter.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)
Sentry.NLog.SentryTarget.Write(NLog.LogEventInfo)+459
NLog.Targets.Target.Write(NLog.Common.AsyncLogEventInfo)
NLog.Targets.Target.WriteAsyncThreadSafe(NLog.Common.AsyncLogEventInfo)
NLog.Targets.Target.WriteAsyncLogEvent(NLog.Common.AsyncLogEventInfo)+ffffffffc48f0f5e
NLog.LoggerImpl.WriteToTargetWithFilterChain(NLog.Targets.Target, NLog.Filters.FilterResult, NLog.LogEventInfo, NLog.Common.AsyncContinuation)+ffffffffc48f0db4
NLog.LoggerImpl.Write(System.Type, NLog.Internal.TargetWithFilterChain, NLog.LogEventInfo, NLog.LogFactory)+e5
NLog.Logger.WriteToTargets(System.Type, NLog.LogEventInfo, NLog.Internal.TargetWithFilterChain)+ffffffffc252d5a0
NLog.Logger.Log(System.Type, NLog.LogEventInfo)+ffffffffc252d4ef
NLog.Extensions.Logging.NLogLogger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3<Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.String>)
Microsoft.Extensions.Logging.Logger.<Log>g__LoggerLog|12_0[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.ILogger, System.Exception, System.Func`3<Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.String>, System.Collections.Generic.List`1<System.Exception>ByRef, Microsoft.Extensions.Logging.FormattedLogValuesByRef)
Microsoft.Extensions.Logging.Logger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3<Microsoft.Extensions.Logging.FormattedLogValues,System.Exception,System.String>)+6e
Microsoft.Extensions.Logging.Logger`1[[System.__Canon, System.Private.CoreLib]].Microsoft.Extensions.Logging.ILogger.Log[[Microsoft.Extensions.Logging.FormattedLogValues, Microsoft.Extensions.Logging.Abstractions]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.Func`3<Microsoft.Extensions.Logging.FormattedLogValues, System.Exception, System.String>)
Microsoft.Extensions.Logging.LoggerExtensions.Log(Microsoft.Extensions.Logging.ILogger, Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, System.Exception, System.String, System.Object[])+5f
Microsoft.Extensions.Logging.LoggerExtensions.Log(Microsoft.Extensions.Logging.ILogger, Microsoft.Extensions.Logging.LogLevel, System.Exception, System.String, System.Object[])
Sentry.Extensions.Logging.MelDiagnosticLogger.Log(Sentry.SentryLevel, System.String, System.Exception, System.Object[])
Sentry.Extensibility.DiagnosticLoggerExtensions.LogIfEnabled(Sentry.Extensibility.IDiagnosticLogger, Sentry.SentryLevel, System.Exception, System.String)+32
Sentry.Extensibility.DiagnosticLoggerExtensions.LogError(Sentry.SentryOptions, System.String, System.Exception)
Sentry.AspNetCore.ScopeExtensions.Populate(Sentry.Scope, Microsoft.AspNetCore.Http.HttpContext, Sentry.AspNetCore.SentryAspNetCoreOptions)
Sentry.AspNetCore.SentryMiddleware.PopulateScope(Microsoft.AspNetCore.Http.HttpContext, Sentry.Scope)
Sentry.AspNetCore.SentryMiddleware+<>c__DisplayClass8_2.<InvokeAsync>b__5(System.Object, System.EventArgs)
Sentry.Scope.Evaluate()
Sentry.SentryClient.DoSendEvent(Sentry.SentryEvent, Sentry.Scope)+242
Sentry.SentryClient.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)
Sentry.Internal.Hub.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)
Sentry.SentrySdk.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)
Sentry.Extensibility.HubAdapter.CaptureEvent(Sentry.SentryEvent, Sentry.Scope)
Sentry.NLog.SentryTarget.Write(NLog.LogEventInfo)+459
NLog.Targets.Target.Write(NLog.Common.AsyncLogEventInfo)
NLog.Targets.Target.WriteAsyncThreadSafe(NLog.Common.AsyncLogEventInfo)
NLog.Targets.Target.WriteAsyncLogEvent(NLog.Common.AsyncLogEventInfo)+ffffffffc48f0f5e
NLog.LoggerImpl.WriteToTargetWithFilterChain(NLog.Targets.Target, NLog.Filters.FilterResult, NLog.LogEventInfo, NLog.Common.AsyncContinuation)+ffffffffc48f0db4
NLog.LoggerImpl.Write(System.Type, NLog.Internal.TargetWithFilterChain, NLog.LogEventInfo, NLog.LogFactory)+e5
NLog.Logger.WriteToTargets(System.Type, NLog.LogEventInfo, NLog.Internal.TargetWithFilterChain)+ffffffffc252d5a0
NLog.Logger.Log(System.Type, NLog.LogEventInfo)+ffffffffc252d4ef
MyApp.Logging.NLogLogger.Error(System.Exception, System.String, System.Object[])
MyApp.Corporate.Identity.Registries.CorporateIdentityServiceCollectionExtensions+<>c.<AddLuceraCorporateIdentityAuthentication>b__0_3(Microsoft.AspNetCore.Authentication.RemoteFailureContext)
Microsoft.AspNetCore.Authentication.RemoteAuthenticationEvents.RemoteFailure(Microsoft.AspNetCore.Authentication.RemoteFailureContext)
Microsoft.AspNetCore.Authentication.RemoteAuthenticationHandler`1+<HandleRequestAsync>d__11[[System.__Canon, System.Private.CoreLib]].MoveNext()
System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[Microsoft.AspNetCore.Authentication.RemoteAuthenticationHandler`1+<HandleRequestAsync>d__11[[System.__Canon, System.Private.CoreLib]], Microsoft.AspNetCore.Authentication]](<HandleRequestAsync>d__11<System.__Canon>ByRef)
System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1[[System.Boolean, System.Private.CoreLib]].Start[[Microsoft.AspNetCore.Authentication.RemoteAuthenticationHandler`1+<HandleRequestAsync>d__11[[System.__Canon, System.Private.CoreLib]], Microsoft.AspNetCore.Authentication]](<HandleRequestAsync>d__11<System.__Canon>ByRef)
Microsoft.AspNetCore.Authentication.RemoteAuthenticationHandler`1[[System.__Canon, System.Private.CoreLib]].HandleRequestAsync()
Microsoft.AspNetCore.Authentication.OpenIdConnect.OpenIdConnectHandler.HandleRequestAsync()
Microsoft.AspNetCore.Authentication.AuthenticationMiddleware+<Invoke>d__6.MoveNext()
System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[Microsoft.AspNetCore.Authentication.AuthenticationMiddleware+<Invoke>d__6, Microsoft.AspNetCore.Authentication]](<Invoke>d__6 ByRef)+1adb891c
System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[[Microsoft.AspNetCore.Authentication.AuthenticationMiddleware+<Invoke>d__6, Microsoft.AspNetCore.Authentication]](<Invoke>d__6 ByRef)+1adb88cc
Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext)+1adb8900
MyApp.Infrastructure.MultiTenant.AspNetCore.MultiTenantMiddleware+<Invoke>d__2.MoveNext()+ffffffffc2ac04a9
System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[MyApp.Infrastructure.MultiTenant.AspNetCore.MultiTenantMiddleware+<Invoke>d__2, MyApp.Infrastructure.MultiTenant.AspNetCore]](<Invoke>d__2 ByRef)+1a86729c
System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[[MyApp.Infrastructure.MultiTenant.AspNetCore.MultiTenantMiddleware+<Invoke>d__2, MyApp.Infrastructure.MultiTenant.AspNetCore]](<Invoke>d__2 ByRef)+1a866f74
MyApp.Infrastructure.MultiTenant.AspNetCore.MultiTenantMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext)+1a866fa9
Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext)
NWebsec.AspNetCore.Middleware.Middleware.MiddlewareBase+<Invoke>d__2.MoveNext()
System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[NWebsec.AspNetCore.Middleware.Middleware.MiddlewareBase+<Invoke>d__2, NWebsec.AspNetCore.Middleware]](<Invoke>d__2ByRef)
NWebsec.AspNetCore.Middleware.Middleware.MiddlewareBase.Invoke(Microsoft.AspNetCore.Http.HttpContext)
NWebsec.AspNetCore.Middleware.Middleware.MiddlewareBase+<Invoke>d__2.MoveNext()
System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[NWebsec.AspNetCore.Middleware.Middleware.MiddlewareBase+<Invoke>d__2, NWebsec.AspNetCore.Middleware]](<Invoke>d__2ByRef)
NWebsec.AspNetCore.Middleware.Middleware.MiddlewareBase.Invoke(Microsoft.AspNetCore.Http.HttpContext)
NWebsec.AspNetCore.Middleware.Middleware.MiddlewareBase+<Invoke>d__2.MoveNext()
System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[NWebsec.AspNetCore.Middleware.Middleware.MiddlewareBase+<Invoke>d__2, NWebsec.AspNetCore.Middleware]](<Invoke>d__2ByRef)
NWebsec.AspNetCore.Middleware.Middleware.MiddlewareBase.Invoke(Microsoft.AspNetCore.Http.HttpContext)
Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext)
Microsoft.AspNetCore.Localization.RequestLocalizationMiddleware+<Invoke>d__5.MoveNext()+3eb
System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[Microsoft.AspNetCore.Localization.RequestLocalizationMiddleware+<Invoke>d__5, Microsoft.AspNetCore.Localization]](<Invoke>d__5ByRef)
Microsoft.AspNetCore.Localization.RequestLocalizationMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext)
Microsoft.AspNetCore.CookiePolicy.CookiePolicyMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext)
Microsoft.AspNetCore.HttpOverrides.ForwardedHeadersMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext)
MyApp.Web.Common.Middleware.ErrorLoggingMiddleware+<InvokeAsync>d__3.MoveNext()
System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[MyApp.Web.Common.Middleware.ErrorLoggingMiddleware+<InvokeAsync>d__3, MyApp.Web.Common]](<InvokeAsync>d__3ByRef)
MyApp.Web.Common.Middleware.ErrorLoggingMiddleware.InvokeAsync(Microsoft.AspNetCore.Http.HttpContext)
Microsoft.Azure.AppConfiguration.AspNetCore.AzureAppConfigurationRefreshMiddleware+<InvokeAsync>d__5.MoveNext()+a2
System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[Microsoft.Azure.AppConfiguration.AspNetCore.AzureAppConfigurationRefreshMiddleware+<InvokeAsync>d__5, Microsoft.Azure.AppConfiguration.AspNetCore]](<InvokeAsync>d__5ByRef)
Microsoft.Azure.AppConfiguration.AspNetCore.AzureAppConfigurationRefreshMiddleware.InvokeAsync(Microsoft.AspNetCore.Http.HttpContext)
Microsoft.AspNetCore.Builder.Extensions.MapWhenMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext)
Microsoft.AspNetCore.Builder.Extensions.MapWhenMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext)
Microsoft.AspNetCore.Builder.Extensions.MapWhenMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext)
Microsoft.AspNetCore.Diagnostics.StatusCodePagesMiddleware+<Invoke>d__3.MoveNext()
System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[Microsoft.AspNetCore.Diagnostics.StatusCodePagesMiddleware+<Invoke>d__3, Microsoft.AspNetCore.Diagnostics]](<Invoke>d__3ByRef)
Microsoft.AspNetCore.Diagnostics.StatusCodePagesMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext)
Sentry.AspNetCore.SentryMiddleware+<InvokeAsync>d__8.MoveNext()
System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[Sentry.AspNetCore.SentryMiddleware+<InvokeAsync>d__8, Sentry.AspNetCore]](<InvokeAsync>d__8ByRef)
Sentry.AspNetCore.SentryMiddleware.InvokeAsync(Microsoft.AspNetCore.Http.HttpContext)
Microsoft.AspNetCore.HostFiltering.HostFilteringMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext)
Microsoft.AspNetCore.Hosting.HostingApplication.ProcessRequestAsync(Context)
System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT`1+<ProcessRequestAsync>d__2[[System.__Canon, System.Private.CoreLib]], Microsoft.AspNetCore.Server.IIS]](<ProcessRequestAsync>d__2<System.__Canon>ByRef)
System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1[[System.Boolean, System.Private.CoreLib]].Start[[Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT`1+<ProcessRequestAsync>d__2[[System.__Canon, System.Private.CoreLib]], Microsoft.AspNetCore.Server.IIS]](<ProcessRequestAsync>d__2<System.__Canon>ByRef)
Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT`1[[System.__Canon, System.Private.CoreLib]].ProcessRequestAsync()
Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext+<HandleRequest>d__183.MoveNext()
System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext+<HandleRequest>d__183, Microsoft.AspNetCore.Server.IIS]](<HandleRequest>d__183ByRef)
Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext.HandleRequest()
Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext.Execute()
System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart()+159
System.Threading.Thread.StartCallback()
coreclr!CallDescrWorkerInternal+34
coreclr!CallDescrWorkerWithHandler+66
coreclr!DispatchCallSimple+7f
coreclr!ThreadNative::KickOffThread_Worker+4b
coreclr!ManagedThreadBase_DispatchMiddle+8c
coreclr!ManagedThreadBase_DispatchOuter+62
coreclr!ThreadNative::KickOffThread+7f
kernel32!BaseThreadInitThunk+24
ntdll!__RtlUserThreadStart+2f
ntdll!_RtlUserThreadStart+1b
@mcliment are you using any of nlog's extensiblity?
That stack is helpful but the redaction makes it hard to figure out what the bottom of the stack is. Does this app use the IHttpContextAccessor anywhere in the logging stack?
This is a very good question... indeed we use aspnet-request-posted-body
property in one target and I've just seen the notice here to use it at your own risk: https://github.com/NLog/NLog/wiki/AspNet-Request-posted-body-layout-renderer
I see that we have been using aspnet-request-posted-body
for quite some time (many years and many .NET versions). It should have failed but as Sentry enables request buffering in the middleware we didn't notice any issue with NLog.
It makes complete sense: it's a concurrency problem and only happens to us when we have a lot of traffic.
I've already deployed a version without this NLog template, let's see how it performs.
Thanks for your tips.
This was removed outright in NLog.Web.AspNetCore 5.0 due to these issues. I added a PR to fix aspnet-request-posted-body for NLog.Web.AspNetCore 5.1, it requires you to install an ASP.NET Middleware class we added the NLog.Web.AspnetCore to capture the request, that way it is thread safe. I have been using that way to capture both the request and response body at my work for that past 2 years and have had no issues under load. Just remember to use it for requests only less than 30 KB in length. Above that ASP.NET Core HttpRequest.EnableBuffering() writes to TEMP files, according to its documentation. Therefore, our default request length above which we refuse to capture the request body is therefore 30 KB, but you could override that if you want to live dangerously. (I also added about a dozen more layout renderers for asp.net and asp.net core for the upcoming release). We are also adding an example to the wiki for response body capturing middleware. If you need it re-activated before the release I can show you how to add the request middleware class and log the request body to HttpContext.Items, then use one of the existing layout renders that prints an HttpContext.Item out.
Sounds like this bug is only related to the NLog issues mentioned, so I'll close this issue. If I'm mistaken and there's something more you need Sentry to investigate, please let me know and I'll re-open. Thanks.
Thanks to @bakgerman now NLog.Web.AspNetCore v5.1 re-introduces ${aspnet-request-posted-body} with help from middleware:
app.UseMiddleware<NLog.Web.NLogRequestPostedBodyMiddleware>();
It is no longer necessary to explict call context.Request.EnableBuffering();
as it is handled by the NLog-middleware.
Package
Sentry.AspNetCore
.NET Flavor
.NET
.NET Version
6.0.201
OS
Windows
SDK Version
3.16.0
Self-Hosted Sentry Version
No response
Steps to Reproduce
We could not reproduce the issue, it happens randomly and seldomly but it makes the server crash
Expected Result
The error should be triggered only once
Actual Result
It seems that NLog logs properly but when sending the log to Sentry it enters in a infinite loop.