Closed Lobosque closed 3 years ago
Lobosque
commented
3 years ago This TooManyRequests error also makes me wonder:
1 - Is there an option to send errors in batches?
2 - Is there a way to throttle requests to sentry to avoid the TooManyRequests scenario? Having bursts of errors is a common scenario.
Tyrrrz
commented
3 years ago @Lobosque hi. Are you running on .net5.0?
Tyrrrz
commented
3 years ago Ok I'm able to reproduce this bug and this is the weirdest shit I've ever seen.
So the main point of interest are the following lines:
Notice that the response is wrapped in a using, so it should be disposed after the execution scope is popped. In any case, the Dispose() method should not be called earlier than await _httpClient.SendAsync(request, cancellationToken) finishes, right? Well, somehow it does.
When it gets a unsuccessful error from relay (429 error in this case), await _httpClient.SendAsync(request, cancellationToken) somehow finishes executing BEFORE the response is fully processed. To illustrate what I mean, on a request that results in an error, the following breakpoint is hit FIRST:
And only then, after that, it hits this one:
If I put a breakpoint on HttpContent.Dispose(), I can see that all calls come from end of the scope here: https://github.com/getsentry/sentry-dotnet/blob/54af283fa2c788e5416c23dbba5f55c6698c5b94/src/Sentry/Internal/Http/HttpTransport.cs#L161
Additionally, if I remove using var response and replace it with var response, then the bug disappears.
My guess at the moment is that it's a bug, either in .NET or C# compiler. It never is, but right now I don't have a better explanation.
Tyrrrz
commented
3 years ago Another interesting find: on .net461 and .netcoreapp3.1 (i.e. not net5.0) the same code results in a NullReferenceException rather than ObjectDisposedException
Lobosque
commented
3 years ago @Tyrrrz is sentry-dotnet/src/Sentry/Internal/Http/HttpTransport.cs the only point where there is a manual disposal?
@Tyrrrz Should we work on a POC to post on the dotnet repository?
@Tyrrrz Is there any configuration I can use to throttle calls so I can avoid the 429 altogether?
Tyrrrz
commented
3 years ago Here is a breakpoint inside HttpClient.SendAsyncCore(...) (which is called by HttpClient.SendAsync(...)) where it gets the response and the content inside is already disposed. It can't get disposed by us at this point, because this method has not finished yet.
My new guess is that it could be possible that it reuses EmptyContent and when we get one and dispose it, it stays disposed and causes an error later?
Tyrrrz
commented
3 years ago @Lobosque
is sentry-dotnet/src/Sentry/Internal/Http/HttpTransport.cs the only point where there is a manual disposal?
Yes, that's the only point. The response object is scoped to that method and is not shared.
Should we work on a POC to post on the dotnet repository?
It seems to be leading us in that direction. I will try to pinpoint the bug as close as possible.
Is there any configuration I can use to throttle calls so I can avoid the 429 altogether?
Setting SentryOptions.MaxQueueItems to something lower than the default 30 should help. You can set it either in appsettings.json or via UseSentry(o => o.MaxQueueItems = 15). Let me know if it helps.
Tyrrrz
commented
3 years ago Okay, yeah, it looks like the instance is shared.
Basically, we get a response with EmptyContent once, dispose it, then we get another response and HttpClient reuses the same instance of EmptyContent, which is already disposed. I think it's fair to say at this point that it's a bug in .NET.
We can temporarily work around it by not disposing the response at all or by checking if the type of content is EmptyContent and not disposing only in that case.
Tyrrrz
commented
3 years ago After 3 hours of debugging, it turns out it's not a bug in .NET :D
The error is, in fact, in RetryAfterHandler here: https://github.com/getsentry/sentry-dotnet/blob/a757f981a8197215a28de038f318cae0ad313b07/src/Sentry/Internal/Http/RetryAfterHandler.cs#L53-L62
It reuses the same instance of HttpResponseMessage which, in turn, reuses the same instance of EmptyContent:
Will make a PR with a fix shortly.
Lobosque
commented
3 years ago @Tyrrrz thanks for digging into that and filling a PR so quickly!
Tyrrrz
commented
3 years ago No problem :)
bruno-garcia
commented
3 years ago Awesome debugging session!
Thanks @Tyrrrz for figuring out.
@Lobosque valeu por ter aberto o issue! ❤️
Environment
How do you use Sentry? Sentry.io
Which SDK and version?
Steps to Reproduce
Expected Result
I expected that the Sentry sink would work fine with my _logger singleton. I expect to use the same _logger instance in many different lifetime scope, even concurrently.
Actual Result
After a few runs of the scheduled job on step three, which logs stuff successfully, something gets disposed inside the Sentry worker, and then nothing gets sent to sentry.io anymore. Apparently things start to go south after a
TooManyRequestserror (line 535 of the debug output)Complete Log
``` ------------------------------------------------------------------- You may only use the Microsoft .NET Core Debugger (vsdbg) with Visual Studio Code, Visual Studio or Visual Studio for Mac software to help you develop and test your applications. ------------------------------------------------------------------- Using launch settings from '/home/lobosque/ts/backend/Frontend/Properties/launchSettings.json' [Profile 'Frontend']... Loaded '/usr/share/dotnet/shared/Microsoft.NETCore.App/5.0.0/System.Private.CoreLib.dll'. Skipped loading symbols. Module is optimized and the debugger option 'Just My Code' is enabled. Loaded '/home/lobosque/ts/backend/Frontend/bin/Debug/net5.0/Frontend.dll'. Symbols loaded. Loaded '/usr/share/dotnet/shared/Microsoft.NETCore.App/5.0.0/System.Runtime.dll'. Skipped loading symbols. Module is optimized and the debugger option 'Just My Code' is enabled. Step into: Stepping over non-user code 'Frontend.Program.