rollbar / Rollbar.NET

Rollbar for .NET
https://docs.rollbar.com/docs/dotnet
MIT License
65 stars 44 forks source link

RollbarLogger.LogTState exception and other middleware exceptions #346

Closed moxplod closed 5 years ago

moxplod commented 5 years ago

Hi i am seeing certain rollbar middleware exceptions getting generated as a separate item on top of an error getting logged. The following are the titles of these that i have seen -

System.Exception: The included internal exception processed by the Rollbar middleware

RollbarLogger.LogTState exception

How do i stop these from being generated from the latest asp.net core sdk

akornich commented 5 years ago

@moxplod, how does the inner exception of that wrapper exception look like? Please, post call stacks of all exceptions starting from the most outer one. Nothing really changed recently in that area. Rollbar middleware watches the subsequently called middleware chain and reports (to Rollbar API server) any uncaught exceptions generated within the chain. Then, it wraps that exception in its own (just to reflect that it did encounter that enclosed exception) and throws the wrapper exception farther.

moxplod commented 5 years ago

Here is the raw exception from one of them --

Traceback (most recent call last): 1 at Rollbar.NetCore.AspNet.RollbarMiddleware+<Invoke>d__4.MoveNext() in "Rollbar.NetCore.AspNet.RollbarMiddleware+<Invoke>d__4" line 776 2 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() in "System.Runtime.ExceptionServices.ExceptionDispatchInfo" line 12 3 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task) in "System.Runtime.CompilerServices.TaskAwaiter" line 46 4 at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware+<Invoke>d__6.MoveNext() in "Microsoft.AspNetCore.Authentication.AuthenticationMiddleware+<Invoke>d__6" line 900 5 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() in "System.Runtime.ExceptionServices.ExceptionDispatchInfo" line 12 6 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task) in "System.Runtime.CompilerServices.TaskAwaiter" line 46 7 at Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware+<Invoke>d__7.MoveNext() in "Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware+<Invoke>d__7" line 1086 8 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() in "System.Runtime.ExceptionServices.ExceptionDispatchInfo" line 12 9 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task) in "System.Runtime.CompilerServices.TaskAwaiter" line 46 10 at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware+<Invoke>d__6.MoveNext() in "Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware+<Invoke>d__6" line 130 System.Exception: The included internal exception processed by the Rollbar middleware Traceback (most recent call last): 1 at System.Reflection.CustomAttribute._CreateCaObject(System.Reflection.RuntimeModule pModule, System.IRuntimeMethodInfo pCtor, System.Byte** ppBlob, System.Byte* pEndBlob, System.Int32* pcNamedArgs) in "System.Reflection.CustomAttribute" line 0 2 at System.Reflection.CustomAttribute.CreateCaObject(System.Reflection.RuntimeModule module, System.IRuntimeMethodInfo ctor, System.IntPtr& blob, System.IntPtr blobEnd, System.Int32& namedArgs) in "System.Reflection.CustomAttribute" line 30 3 at System.Reflection.CustomAttribute.GetCustomAttributes(System.Reflection.RuntimeModule decoratedModule, System.Int32 decoratedMetadataToken, System.Int32 pcaCount, System.RuntimeType attributeFilterType, System.Boolean mustBeInheritable, System.Collections.IList derivedAttributes) in "System.Reflection.CustomAttribute" line 259 4 at System.Reflection.CustomAttribute.GetCustomAttributes(System.RuntimeType type, System.RuntimeType caType, System.Boolean inherit) in "System.Reflection.CustomAttribute" line 213 5 at Microsoft.AspNetCore.Razor.Hosting.DefaultRazorCompiledItem.get_Metadata() in "Microsoft.AspNetCore.Razor.Hosting.DefaultRazorCompiledItem" line 8 6 at Microsoft.AspNetCore.Razor.Hosting.RazorCompiledItemExtensions.GetChecksumMetadata(Microsoft.AspNetCore.Razor.Hosting.RazorCompiledItem item) in "Microsoft.AspNetCore.Razor.Hosting.RazorCompiledItemExtensions" line 14 7 at Microsoft.AspNetCore.Mvc.Razor.Internal.ChecksumValidator.IsRecompilationSupported(Microsoft.AspNetCore.Razor.Hosting.RazorCompiledItem item) in "Microsoft.AspNetCore.Mvc.Razor.Internal.ChecksumValidator" line 32 8 at Microsoft.AspNetCore.Mvc.Razor.Internal.RazorViewCompiler.CreatePrecompiledWorkItem(System.String normalizedPath, Microsoft.AspNetCore.Mvc.Razor.Compilation.CompiledViewDescriptor precompiledView) in "Microsoft.AspNetCore.Mvc.Razor.Internal.RazorViewCompiler" line 0 9 at Microsoft.AspNetCore.Mvc.Razor.Internal.RazorViewCompiler.OnCacheMiss(System.String normalizedPath) in "Microsoft.AspNetCore.Mvc.Razor.Internal.RazorViewCompiler" line 71 10 at Microsoft.AspNetCore.Mvc.Razor.Internal.RazorViewCompiler.CompileAsync(System.String relativePath) in "Microsoft.AspNetCore.Mvc.Razor.Internal.RazorViewCompiler" line 58 11 at Microsoft.AspNetCore.Mvc.Razor.Internal.DefaultRazorPageFactoryProvider.CreateFactory(System.String relativePath) in "Microsoft.AspNetCore.Mvc.Razor.Internal.DefaultRazorPageFactoryProvider" line 28 12 at Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine.CreateCacheResult(System.Collections.Generic.HashSet1[Microsoft.Extensions.Primitives.IChangeToken] expirationTokens, System.String relativePath, System.Boolean isMainPage) in "Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine" line 0 13 at Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine.OnCacheMiss(Microsoft.AspNetCore.Mvc.Razor.ViewLocationExpanderContext expanderContext, Microsoft.AspNetCore.Mvc.Razor.Internal.ViewLocationCacheKey cacheKey) in "Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine" line 130 14 at Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine.LocatePageFromViewLocations(Microsoft.AspNetCore.Mvc.ActionContext actionContext, System.String pageName, System.Boolean isMainPage) in "Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine" line 256 15 at Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine.FindView(Microsoft.AspNetCore.Mvc.ActionContext context, System.String viewName, System.Boolean isMainPage) in "Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine" line 66 16 at Microsoft.AspNetCore.Mvc.ViewEngines.CompositeViewEngine.FindView(Microsoft.AspNetCore.Mvc.ActionContext context, System.String viewName, System.Boolean isMainPage) in "Microsoft.AspNetCore.Mvc.ViewEngines.CompositeViewEngine" line 126 17 at Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor.FindView(Microsoft.AspNetCore.Mvc.ActionContext actionContext, Microsoft.AspNetCore.Mvc.ViewResult viewResult) in "Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor" line 89 18 at Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor+d6.MoveNext() in "Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor+d6" line 66 19 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() in "System.Runtime.ExceptionServices.ExceptionDispatchInfo" line 12 20 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task) in "System.Runtime.CompilerServices.TaskAwaiter" line 46 21 at Microsoft.AspNetCore.Mvc.ViewResult+d26.MoveNext() in "Microsoft.AspNetCore.Mvc.ViewResult+d26" line 144 22 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() in "System.Runtime.ExceptionServices.ExceptionDispatchInfo" line 12 23 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task) in "System.Runtime.CompilerServices.TaskAwaiter" line 46 24 at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+d20.MoveNext() in "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+d20" line 165 25 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() in "System.Runtime.ExceptionServices.ExceptionDispatchInfo" line 12 26 at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+d28`2.MoveNext() in "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+d282" line 166 27 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() in "System.Runtime.ExceptionServices.ExceptionDispatchInfo" line 12 28 at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Rethrow(Microsoft.AspNetCore.Mvc.Filters.ResultExecutedContext context) in "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker" line 21 29 at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.ResultNext(Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+State& next, Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+Scope& scope, System.Object& state, System.Boolean& isCompleted) in "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker" line 991 30 at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeResultFilters>d__26.MoveNext() in "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeResultFilters>d__26" line 48 31 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() in "System.Runtime.ExceptionServices.ExceptionDispatchInfo" line 12 32 at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeNextResourceFilter>d__23.MoveNext() in "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeNextResourceFilter>d__23" line 166 33 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() in "System.Runtime.ExceptionServices.ExceptionDispatchInfo" line 12 34 at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Rethrow(Microsoft.AspNetCore.Mvc.Filters.ResourceExecutedContext context) in "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker" line 21 35 at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Next(Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+State& next, Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+Scope& scope, System.Object& state, System.Boolean& isCompleted) in "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker" line 2123 36 at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeFilterPipelineAsync>d__18.MoveNext() in "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeFilterPipelineAsync>d__18" line 47 37 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() in "System.Runtime.ExceptionServices.ExceptionDispatchInfo" line 12 38 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task) in "System.Runtime.CompilerServices.TaskAwaiter" line 46 39 at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeAsync>d__16.MoveNext() in "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeAsync>d__16" line 302 40 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() in "System.Runtime.ExceptionServices.ExceptionDispatchInfo" line 12 41 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task) in "System.Runtime.CompilerServices.TaskAwaiter" line 46 42 at Microsoft.AspNetCore.Builder.RouterMiddleware+<Invoke>d__4.MoveNext() in "Microsoft.AspNetCore.Builder.RouterMiddleware+<Invoke>d__4" line 459 43 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() in "System.Runtime.ExceptionServices.ExceptionDispatchInfo" line 12 44 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task) in "System.Runtime.CompilerServices.TaskAwaiter" line 46 45 at Rollbar.NetCore.AspNet.RollbarMiddleware+<Invoke>d__4.MoveNext() in "Rollbar.NetCore.AspNet.RollbarMiddleware+<Invoke>d__4" line 502 System.Reflection.CustomAttributeFormatException: Binary format of the specified custom attribute was invalid.

akornich commented 5 years ago

@moxplod , thanks! The way I read this trace is: the Rollbar middleware did process an uncaught exception coming from some other middleware components "guarded" by the Rollbar middleware. The original exception seems to be generated somewhere within Razor view engine while attempting to find requested view. I do not see any trace of your actual application code - only the Asp.Net Core and Razor "plumbing" code. Could it be that your application is missing some expected resources/files related to Razor views?

akornich commented 5 years ago

348

akornich commented 5 years ago

@moxplod, do you still need help with this issue or we can close it now?

akornich commented 5 years ago

closing due to no responses...

jbwps commented 5 years ago

I am still seeing this issue in 3.0.6. Some exceptions are still getting wrapped in "System.Exception: The included internal exception processed by the Rollbar middleware", and then the actual exception is in the inner exception. This can be reproduced by simply throwing a new exception from a controller.

moxplod commented 5 years ago

Yes - I am seeing this exception still. Sorry for no response earlier.

akornich commented 5 years ago

@moxplod and @jbwps , the way it is designed to work, the RollbarMiddleware is the last chance guard for any uncaught exception within the HTTP processing pipeline guarded by the middleware. If it catches an exception it reports the exception to the Rollbar API service so you can see it on the Project Dashboard, wraps it as RollbarMiddlewareException and re-throws since we have no idea what the recovery scenario should be for each specific case. The reason we wrap it into Rollbar specific exception is to let you (a developer) know: "look, you had some unhandled exception that we intercepted and reported at the last line of defense. You may want to know about it". What would be your expectation/suggestion on how to handle such cases? We are open to any ideas.

jbwps commented 5 years ago

Thanks! I'd like to be able to register the Rollbar middleware and not have to wrap every controller action in a try/catch to log exceptions. I'd also like the original exception to be preserved in the title so that the alerting is clear and grouping on the Rollbar dashboard is correct. Having the exception wrapped in a Rollbar exception isn't as important for me, because in this scenario basically anything that makes it's way to Rollbar in this way is an uncaught exception, so I already know that it is unhandled. I haven't been using Rollbar for that long, so if there is a best practice that I'm not aware of please let me know.

akornich commented 5 years ago

@jbwps , of cause when you do not care handling exceptions on your own in the code and never care to recover/retry in case of an exception then you can say: "Having the exception wrapped in a Rollbar exception isn't as important for me, because in this scenario basically anything that makes it's way to Rollbar in this way is an uncaught exception, so I already know that it is unhandled". But that is not the most common scenario for handling exceptions - in fact, it is not handling at all - but just letting it fail and, by capturing unhandled exceptions at the last point, only reporting them. In most scenarios applications are trying to monitor for possible exceptions on different levels and handle them as soon as possible and even trying all sorts of recovery/retry scenarios in response to a detected exception (while also reporting the exception). And they would also like to have the "last resort" solution for capturing unhandled exceptions and reporting them as such in case anything like this happen. This gives them an opportunity to follow-up the problem and to either fix or handle the problem properly in the next release. It looks that the main inconvenience for you is the fact that we always assign a payload item's title as "RollbarMiddleware processed uncaught exception." that breaks grouping functionality for you. Correct?

akornich commented 5 years ago

@jbwps , may I ask you to post here a link to the item that you say is wrongfully grouped based on the identical title that we assign within the middleware?

akornich commented 5 years ago

@jbwps , just a ping in case you missed my previous question notification...

akornich commented 5 years ago

closing due to no clear issue and no responses.

jbwps commented 5 years ago

Thanks for investigating this!

Here's a good example: https://rollbar.com/WPS/WPS-Watch/items/652/

Also of note, the inner exception also triggered the creation of a separate Rollbar item: https://rollbar.com/WPS/WPS-Watch/items/651/

These Rollbar items are for a null reference exception - a pretty common example of an uncaught error.

Again, what I'd expect to see is a title/grouping like:

651 System.NullReferenceException: Object reference not set to an instance of an object.

I just saw that you closed this as I was typing my response. I hope you'll keep it open - I think this is an important issue. I apologize for any slow replies - I am often away from my computer for a week or more at a time, but I will get you any feedback you need as soon as I am I able.

akornich commented 5 years ago

got a response, reopening...

akornich commented 5 years ago

@jbwps, thanks for the details! I have no access to the items you referenced here. May I ask you to post here screenshots of the items? Thank you!

akornich commented 5 years ago

@jbwps, regarding your expectation of grouping for common exceptions: I just want to make sure (unless I misread what you are actually saying there) that you realize that grouping of common occurrences primarily happens based on the similarity of the complete call stack/trace and not just on the similarity of the exception type.

jbwps commented 5 years ago

Yes, my expectation would be that a null reference exception from a different place in the code base with a different stack would be grouped as a different item.

akornich commented 5 years ago

@jbwps, got it. What about the screenshots of sample occurrences that you would expect to be grouped that were not actually grouped? Thanks!

jbwps commented 5 years ago

I don't think that is as much of an issue

poroszd commented 5 years ago

Hi @moxplod and @jbwps, Rollbar engineer here. I checked the two items linked by @jbwps and it seems all of their occurrences correspond in time, but #651 is reported explicitly from your code while #652 is reported by the Rollbar middleware. I guess the middleware triggers because you re-throw the exception.

I would suggest to make sure you report an exception only once: if you catch and handle the exception, don't re-throw; or if you catch and don't handle it, do not report explicitly to Rollbar (because the middleware will do that for you).

On the other hand, thanks for pointing out the title problem of #652. We will work on making the title less generic.

jbwps commented 5 years ago

We don't currently have any lines of code explicitly reporting anything to Rollbar - it all goes through the middleware. This exception wasn't caught and re-thrown, either. Since we aren't always seeing this duplicate behavior, my best guess is that it might occur when an exception is raised from code within objects that are registered for dependency injection.

jbwps commented 5 years ago

@poroszd I just confirmed my hunch above. Here's a link to a repo that reproduces the problem: https://github.com/jbwps/rollbar-test

akornich commented 5 years ago

yes, @jbwps, you are absolutely correct. in the sample app, you are registering RollbarLogger (as an implementation of Asp.Net Core's ILogger) and adding the use of RollbarMiddleware (within Startup.cs). These are the right things to do. And it looks that Asp.Net Core's dependency injection infrastructure is performing somewhat similar steps to what @poroszd mentioned (but not your code explicitly) - it detects the exception, logs it via ILogger infrastructure (hence via RollbarLogger that was registered with it) and rethrows. Then, RollbarMiddleware picks it up from there. I just tried a similar scenario with one of our sample apps, where I did not register RollbarLogger, so, as expected I got only one instance of the exception logged (the one via the RollbarMiddleware). However, to make it work, first, I had to make some small code changes within our middleware implementation by disabling its dependency on some data that is only initialized by the RollbarLogger:Ilogger (that was not registered now).
That said, I would not recommend to any of our customers to do a similar "solution" to this occasional exception "duplication" problem, because it would significantly reduce the level of integration with Asp.Net Core logging infrastructure and losing ability to seamlessly forward explicit logging of errors (via that infrastructure) to the Rollbar API.

poroszd commented 5 years ago

@jbwps Ah ok, sorry for my false assumption. Honestly I don't have domain knowledge in the .NET/Asp realm, I'm sure @akornich has a better understanding on your problem.

akornich commented 5 years ago

@poroszd , you were on the right track with your assumptions. one thing we did not realize right away that the dependency injection part of the framework code could also have a way to catch an exception, report it via its generic logging (hence, via Rollbar) and rethrow.

akornich commented 5 years ago

Looks like there are no questions anymore. Closing...

jbwps commented 5 years ago

I don't feel like this is resolved and this issue really hurts the usability of Rollbar on the .NET Core Web API stack. Still hoping to see a fix in the future.

jbwps commented 5 years ago

For example, this is not a useful report:

Capture

akornich commented 5 years ago

@jbwps , how would you like it to be handled instead? what's your expectation on how these types of cases should be presented? As long as all the occurrences of each item are properly grouped into the items, I am not sure what could be fixed here.

poroszd commented 5 years ago

@jbwps @akornich My understanding is that there are two problems here:

  1. The same exception gets reported both from RollbarLogger and RollbarMiddleware, but the one from RollbarMiddleware gets wrapped, so these two occurrences will not be grouped to one item in Rollbar. Unfortunately I can't help with that, because from the payload currently we can't recognize that these are actually the same exceptions. In our current setup this has to be addressed client-side (either by Rollbar.NET or your app).

  2. All the occurrences reported by RollbarMiddleware will create items with the same title. This is not an issue with Rollbar.NET but actually a bug in the service that should be fixed soon.

akornich commented 5 years ago

@poroszd , i think for the second item you mentioned, on the SDK side, we can suffix the current title with the message and/or type of the exception immediately wrapped by the RollbarMiddlewareException.

poroszd commented 5 years ago

Well, I just noticed that the payload already contains the title field. Ok, in this case the second problem has to be addressed client-side, too.

jbwps commented 5 years ago

Thanks for considering this again. As discussed above, the ideal reporting would be that the title of the exception that is getting wrapped is what is displayed, and ideally the item is not duplicated from both the RollbarLogger and the RollbarMiddlewar. It sounds like there are some challenges to implement this, but from my perspective that would provide the most useful reporting.

JakeJ commented 5 years ago

Hi there,

I'm seeing the same thing with my dashboard, and would like to weigh in a few bits of info that could hopefully help target the issue here.

Firstly, here's my dashboard view:

Screenshot 2019-06-07 at 16 00 37

One thing to note here is that I'm seemingly getting dual reports of each error, one at 'Error' level and another at 'Critical' level. Now I'm not certain if this is an issue with my configuration or not, but I haven't been able to see an obvious fix for this on my side.

The other thing is that, even though the errors themselves are grouped together, they all have the same error message. Everything saying 'RollbarMiddleware processed uncaught exception.' kinda makes this the 'Item' column here an unhelpful column just because it's the same thing every time.

Secondly, let's look at the Traceback of item #843

Screenshot 2019-06-07 at 16 19 56

The latest Exception in this stack seems to be the RollbarMiddlewareException itself, with an InnerException again of RollbarMiddlewareException. After this we get the actual exception that had caused the Rollbar logger to propagate this to Rollbar itself which is just a simple System.ArgumentException.

Ideally, I would actually like to see this exception name and/or exception message as the title of the item itself

Secondly, let's look at the Traceback of item #844

Screenshot 2019-06-07 at 16 24 18

Interestingly enough, this is exactly what I'd like to see the Traceback to be. The latest Exception in this stack is the item that actually caused Rollbar to run in the first place, again as before it would be ideal if the name or message of this Exception could be used as the item's title.

Everything else is absolutely perfect and even though it's unclear at first what the error is using the item's title, the Traceback has always been a point that can help us.

Edit: The screenshots of the Traceback do continue further to provide information about where it is in my application code, however I left that part cropped out

akornich commented 5 years ago

@JakeJ , the reason you are getting some exceptions reported twice (once explicitly, and one more time wrapped in the Rollbar Middleware exception) is because you have a code path somewhere in either your code or within the ASP.NET Core infrastructure that catches the exception and either reports it directly to Rollbar or logs it via ASP.NET Core logging mechanism (that redirects it to Rollbar as well). Then, it does not handle the exception and rethrows it - basically letting it bubble up further. Eventually, Rollbar Middleware component that is configured to guard your HTTP request processing pipeline picks it up and reports it again, but now wrapped in its own dedicated exception that signifies the fact that it was able to intercept an unhandled exception on its "last-chance" level. If the exception were properly handled the first time it was reported it would not make it to the Rollbar Middleware level (to be reported once more). That is exactly by the currently intended design of the Rollbar ASP.NET Core extension component:

This design provides you, a developer, with a better context about an exception. For example, if you see an exception reported with no extra Rollbar Middleware Exception wrapper it means it was caught somewhere in your (or ASP.NET Core infrastructure) code, reported (most likely via common ASP.NET Core logging means), and either swallowed or properly handled after reporting (in other words the exception was expected by the code author and there was a plan to handle and recover from it). When you see the same exception with the same call stack reported also wrapped in the Rollbar Middleware Exception - it means it was never properly handled and has to get the highest level of attention.

@JakeJ , may I ask you to post here raw (JSON) presentation of the items 843 and 844? Please, remember to scrub any sensitive/confidential data before posting. I want to double check why the RollbarMiddlewareException shows up twice in 843 and call stack correlations between 843 and 844.

Thank you for your feedback and input!

jessicahsieh commented 5 years ago

internal conversation - https://app.intercom.io/a/apps/rlisg82q/inbox/inbox/488687/conversations/22192298109

AFDevMike commented 5 years ago

Am watching this with interest as well. ASP.Net Core uncaught exceptions are logged twice. One is Level Error. And the next is a wrapping of that Error and Label with Level Critical.

akornich commented 5 years ago

@AFDevMike, can you post here sample JSON of both (duplicated) instances? Please, make sure you mask out any sensitive data. Thank you!

AFDevMike commented 5 years ago

Sure, let me know if there is anything else you need:

{
  "body": {
    "trace": {
      "frames": [
        {
          "method": "AutoFluent.AFSharedAPI.Controllers.TestController.Test()", 
          "lineno": 23, 
          "colno": 13, 
          "filename": "C:\\Users\\Work\\source\\repos\\autofluent-cloud\\AutoFluent-Servers\\NetCoreApp21\\APIServers\\AFSharedAPI\\Controllers\\TestController.cs"
        }, 
        {
          "method": "lambda_method(System.Runtime.CompilerServices.Closure , System.Object , System.Object[] )", 
          "lineno": 45, 
          "colno": 0, 
          "filename": "(unknown)"
        }, 
        {
          "method": "Microsoft.Extensions.Internal.ObjectMethodExecutor.Execute(System.Object target, System.Object[] parameters)", 
          "lineno": 0, 
          "colno": 0, 
          "filename": "Microsoft.Extensions.Internal.ObjectMethodExecutor"
        }, 
        {
          "method": "Microsoft.AspNetCore.Mvc.Internal.ActionMethodExecutor+SyncActionResultExecutor.Execute(Microsoft.AspNetCore.Mvc.Infrastructure.IActionResultTypeMapper mapper, Microsoft.Extensions.Internal.ObjectMethodExecutor executor, System.Object controller, System.Object[] arguments)", 
          "lineno": 0, 
          "colno": 0, 
          "filename": "Microsoft.AspNetCore.Mvc.Internal.ActionMethodExecutor+SyncActionResultExecutor"
        }, 
        {
          "method": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+<InvokeActionMethodAsync>d__12.MoveNext()", 
          "lineno": 198, 
          "colno": 0, 
          "filename": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+<InvokeActionMethodAsync>d__12"
        }, 
        {
          "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
          "lineno": 12, 
          "colno": 0, 
          "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
        }, 
        {
          "method": "System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)", 
          "lineno": 46, 
          "colno": 0, 
          "filename": "System.Runtime.CompilerServices.TaskAwaiter"
        }, 
        {
          "method": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+<InvokeNextActionFilterAsync>d__10.MoveNext()", 
          "lineno": 165, 
          "colno": 0, 
          "filename": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+<InvokeNextActionFilterAsync>d__10"
        }, 
        {
          "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
          "lineno": 12, 
          "colno": 0, 
          "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
        }, 
        {
          "method": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Rethrow(Microsoft.AspNetCore.Mvc.Filters.ActionExecutedContext context)", 
          "lineno": 32, 
          "colno": 0, 
          "filename": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker"
        }, 
        {
          "method": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+State& next, Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+Scope& scope, System.Object& state, System.Boolean& isCompleted)", 
          "lineno": 905, 
          "colno": 0, 
          "filename": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker"
        }, 
        {
          "method": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+<InvokeInnerFilterAsync>d__13.MoveNext()", 
          "lineno": 47, 
          "colno": 0, 
          "filename": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+<InvokeInnerFilterAsync>d__13"
        }, 
        {
          "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
          "lineno": 12, 
          "colno": 0, 
          "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
        }, 
        {
          "method": "System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)", 
          "lineno": 46, 
          "colno": 0, 
          "filename": "System.Runtime.CompilerServices.TaskAwaiter"
        }, 
        {
          "method": "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeFilterPipelineAsync>d__18.MoveNext()", 
          "lineno": 159, 
          "colno": 0, 
          "filename": "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeFilterPipelineAsync>d__18"
        }, 
        {
          "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
          "lineno": 12, 
          "colno": 0, 
          "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
        }, 
        {
          "method": "System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)", 
          "lineno": 46, 
          "colno": 0, 
          "filename": "System.Runtime.CompilerServices.TaskAwaiter"
        }, 
        {
          "method": "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeAsync>d__16.MoveNext()", 
          "lineno": 302, 
          "colno": 0, 
          "filename": "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeAsync>d__16"
        }, 
        {
          "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
          "lineno": 12, 
          "colno": 0, 
          "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
        }, 
        {
          "method": "System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)", 
          "lineno": 46, 
          "colno": 0, 
          "filename": "System.Runtime.CompilerServices.TaskAwaiter"
        }, 
        {
          "method": "Microsoft.AspNetCore.Routing.EndpointMiddleware+<Invoke>d__3.MoveNext()", 
          "lineno": 202, 
          "colno": 0, 
          "filename": "Microsoft.AspNetCore.Routing.EndpointMiddleware+<Invoke>d__3"
        }, 
        {
          "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
          "lineno": 12, 
          "colno": 0, 
          "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
        }, 
        {
          "method": "System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)", 
          "lineno": 46, 
          "colno": 0, 
          "filename": "System.Runtime.CompilerServices.TaskAwaiter"
        }, 
        {
          "method": "Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware+<Invoke>d__6.MoveNext()", 
          "lineno": 388, 
          "colno": 0, 
          "filename": "Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware+<Invoke>d__6"
        }, 
        {
          "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
          "lineno": 12, 
          "colno": 0, 
          "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
        }, 
        {
          "method": "System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)", 
          "lineno": 46, 
          "colno": 0, 
          "filename": "System.Runtime.CompilerServices.TaskAwaiter"
        }, 
        {
          "method": "AutoFluent.SharedLibrary.NetCoreApp21.Infrastructure.Logging.Middlewares.RequestLoggingMiddleware+<Invoke>d__3.MoveNext()", 
          "lineno": 44, 
          "colno": 13, 
          "filename": "C:\\Users\\Work\\source\\repos\\autofluent-cloud\\AutoFluent-Servers\\NetCoreApp21\\SharedLibraryNetCoreApp21\\Infrastructure\\Logging\\Middlewares\\RequestLoggingMiddleware.cs"
        }, 
        {
          "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
          "lineno": 12, 
          "colno": 0, 
          "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
        }, 
        {
          "method": "System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)", 
          "lineno": 46, 
          "colno": 0, 
          "filename": "System.Runtime.CompilerServices.TaskAwaiter"
        }, 
        {
          "method": "Rollbar.NetCore.AspNet.RollbarMiddleware+<Invoke>d__4.MoveNext()", 
          "lineno": 521, 
          "colno": 0, 
          "filename": "Rollbar.NetCore.AspNet.RollbarMiddleware+<Invoke>d__4"
        }
      ], 
      "exception": {
        "message": "Ex Logging Foo", 
        "class": "System.Exception"
      }
    }
  }, 
  "uuid": "■■■■■■■■■■■■■■■■■■■■■■■■■■■", 
  "language": "c#", 
  "level": "critical", 
  "timestamp": 1561070602, 
  "title": "RollbarMiddleware processed uncaught exception.", 
  "request": {
    "url": "localhost:59879/api/Test/Test", 
    "query_string": "", 
    "params": null, 
    "method": "GET", 
    "headers": {
      "Accept-Encoding": "gzip, deflate", 
      "Host": "localhost:59879", 
      "Accept": "*/*", 
      "User-Agent": "PostmanRuntime/7.15.0", 
      "Connection": "keep-alive", 
      "Cache-Control": "no-cache", 
      "Postman-Token": "■■■■■■■■■■■■■■■■■■■■■■■■■■■"
    }
  }, 
  "custom": {}, 
  "environment": "Development", 
  "platform": "Microsoft Windows 10.0.17763 ", 
  "framework": ".NETCoreApp,Version=v2.2", 
  "notifier": {
    "version": "3.2.0", 
    "name": "Rollbar.NET"
  }, 
  "metadata": {
    "customer_timestamp": 1561070602
  }
}

AND

{
  "body": {
    "trace_chain": [
      {
        "frames": [
          {
            "method": "Rollbar.NetCore.AspNet.RollbarMiddleware+<Invoke>d__4.MoveNext()", 
            "lineno": 787, 
            "colno": 0, 
            "filename": "Rollbar.NetCore.AspNet.RollbarMiddleware+<Invoke>d__4"
          }, 
          {
            "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
            "lineno": 12, 
            "colno": 0, 
            "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
          }, 
          {
            "method": "System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)", 
            "lineno": 46, 
            "colno": 0, 
            "filename": "System.Runtime.CompilerServices.TaskAwaiter"
          }, 
          {
            "method": "Microsoft.AspNetCore.Authentication.AuthenticationMiddleware+<Invoke>d__6.MoveNext()", 
            "lineno": 900, 
            "colno": 0, 
            "filename": "Microsoft.AspNetCore.Authentication.AuthenticationMiddleware+<Invoke>d__6"
          }, 
          {
            "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
            "lineno": 12, 
            "colno": 0, 
            "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
          }, 
          {
            "method": "Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol+<ProcessRequests>d__185`1.MoveNext()", 
            "lineno": 391, 
            "colno": 0, 
            "filename": "Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol+<ProcessRequests>d__185`1"
          }
        ], 
        "exception": {
          "message": "The included internal exception processed by the Rollbar middleware", 
          "class": "Rollbar.NetCore.AspNet.RollbarMiddlewareException"
        }
      }, 
      {
        "frames": [
          {
            "method": "AutoFluent.AFSharedAPI.Controllers.TestController.Test()", 
            "lineno": 23, 
            "colno": 13, 
            "filename": "C:\\Users\\Work\\source\\repos\\autofluent-cloud\\AutoFluent-Servers\\NetCoreApp21\\APIServers\\AFSharedAPI\\Controllers\\TestController.cs"
          }, 
          {
            "method": "lambda_method(System.Runtime.CompilerServices.Closure , System.Object , System.Object[] )", 
            "lineno": 45, 
            "colno": 0, 
            "filename": "(unknown)"
          }, 
          {
            "method": "Microsoft.Extensions.Internal.ObjectMethodExecutor.Execute(System.Object target, System.Object[] parameters)", 
            "lineno": 0, 
            "colno": 0, 
            "filename": "Microsoft.Extensions.Internal.ObjectMethodExecutor"
          }, 
          {
            "method": "Microsoft.AspNetCore.Mvc.Internal.ActionMethodExecutor+SyncActionResultExecutor.Execute(Microsoft.AspNetCore.Mvc.Infrastructure.IActionResultTypeMapper mapper, Microsoft.Extensions.Internal.ObjectMethodExecutor executor, System.Object controller, System.Object[] arguments)", 
            "lineno": 0, 
            "colno": 0, 
            "filename": "Microsoft.AspNetCore.Mvc.Internal.ActionMethodExecutor+SyncActionResultExecutor"
          }, 
          {
            "method": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+<InvokeActionMethodAsync>d__12.MoveNext()", 
            "lineno": 198, 
            "colno": 0, 
            "filename": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+<InvokeActionMethodAsync>d__12"
          }, 
          {
            "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
            "lineno": 12, 
            "colno": 0, 
            "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
          }, 
          {
            "method": "System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)", 
            "lineno": 46, 
            "colno": 0, 
            "filename": "System.Runtime.CompilerServices.TaskAwaiter"
          }, 
          {
            "method": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+<InvokeNextActionFilterAsync>d__10.MoveNext()", 
            "lineno": 165, 
            "colno": 0, 
            "filename": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+<InvokeNextActionFilterAsync>d__10"
          }, 
          {
            "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
            "lineno": 12, 
            "colno": 0, 
            "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
          }, 
          {
            "method": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Rethrow(Microsoft.AspNetCore.Mvc.Filters.ActionExecutedContext context)", 
            "lineno": 32, 
            "colno": 0, 
            "filename": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker"
          }, 
          {
            "method": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+State& next, Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+Scope& scope, System.Object& state, System.Boolean& isCompleted)", 
            "lineno": 905, 
            "colno": 0, 
            "filename": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker"
          }, 
          {
            "method": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+<InvokeInnerFilterAsync>d__13.MoveNext()", 
            "lineno": 47, 
            "colno": 0, 
            "filename": "Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker+<InvokeInnerFilterAsync>d__13"
          }, 
          {
            "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
            "lineno": 12, 
            "colno": 0, 
            "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
          }, 
          {
            "method": "System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)", 
            "lineno": 46, 
            "colno": 0, 
            "filename": "System.Runtime.CompilerServices.TaskAwaiter"
          }, 
          {
            "method": "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeFilterPipelineAsync>d__18.MoveNext()", 
            "lineno": 159, 
            "colno": 0, 
            "filename": "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeFilterPipelineAsync>d__18"
          }, 
          {
            "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
            "lineno": 12, 
            "colno": 0, 
            "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
          }, 
          {
            "method": "System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)", 
            "lineno": 46, 
            "colno": 0, 
            "filename": "System.Runtime.CompilerServices.TaskAwaiter"
          }, 
          {
            "method": "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeAsync>d__16.MoveNext()", 
            "lineno": 302, 
            "colno": 0, 
            "filename": "Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker+<InvokeAsync>d__16"
          }, 
          {
            "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
            "lineno": 12, 
            "colno": 0, 
            "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
          }, 
          {
            "method": "System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)", 
            "lineno": 46, 
            "colno": 0, 
            "filename": "System.Runtime.CompilerServices.TaskAwaiter"
          }, 
          {
            "method": "Microsoft.AspNetCore.Routing.EndpointMiddleware+<Invoke>d__3.MoveNext()", 
            "lineno": 202, 
            "colno": 0, 
            "filename": "Microsoft.AspNetCore.Routing.EndpointMiddleware+<Invoke>d__3"
          }, 
          {
            "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
            "lineno": 12, 
            "colno": 0, 
            "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
          }, 
          {
            "method": "System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)", 
            "lineno": 46, 
            "colno": 0, 
            "filename": "System.Runtime.CompilerServices.TaskAwaiter"
          }, 
          {
            "method": "Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware+<Invoke>d__6.MoveNext()", 
            "lineno": 388, 
            "colno": 0, 
            "filename": "Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware+<Invoke>d__6"
          }, 
          {
            "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
            "lineno": 12, 
            "colno": 0, 
            "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
          }, 
          {
            "method": "System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)", 
            "lineno": 46, 
            "colno": 0, 
            "filename": "System.Runtime.CompilerServices.TaskAwaiter"
          }, 
          {
            "method": "AutoFluent.SharedLibrary.NetCoreApp21.Infrastructure.Logging.Middlewares.RequestLoggingMiddleware+<Invoke>d__3.MoveNext()", 
            "lineno": 44, 
            "colno": 13, 
            "filename": "C:\\Users\\Work\\source\\repos\\autofluent-cloud\\AutoFluent-Servers\\NetCoreApp21\\SharedLibraryNetCoreApp21\\Infrastructure\\Logging\\Middlewares\\RequestLoggingMiddleware.cs"
          }, 
          {
            "method": "System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()", 
            "lineno": 12, 
            "colno": 0, 
            "filename": "System.Runtime.ExceptionServices.ExceptionDispatchInfo"
          }, 
          {
            "method": "System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)", 
            "lineno": 46, 
            "colno": 0, 
            "filename": "System.Runtime.CompilerServices.TaskAwaiter"
          }, 
          {
            "method": "Rollbar.NetCore.AspNet.RollbarMiddleware+<Invoke>d__4.MoveNext()", 
            "lineno": 521, 
            "colno": 0, 
            "filename": "Rollbar.NetCore.AspNet.RollbarMiddleware+<Invoke>d__4"
          }
        ], 
        "exception": {
          "message": "Ex Logging Foo", 
          "class": "System.Exception"
        }
      }
    ]
  }, 
  "uuid": "■■■■■■■■■■■■■■■■■■■■■■■■■■■", 
  "language": "c#", 
  "level": "error", 
  "timestamp": 1561070602, 
  "title": "The included internal exception processed by the Rollbar middleware", 
  "request": {
    "httpRequestTimestamp": "2019-06-20T15:38:35.7751064-07:00", 
    "protocol": "HTTP/1.1", 
    "headers": {
      "Accept-Encoding": "gzip, deflate", 
      "Host": "localhost:59879", 
      "Accept": "*/*", 
      "User-Agent": "PostmanRuntime/7.15.0", 
      "Connection": "keep-alive", 
      "Cache-Control": "no-cache", 
      "Postman-Token": "■■■■■■■■■■■■■■■■■■■■■■■■■■■"
    }, 
    "url": "localhost:59879/api/Test/Test", 
    "httpRequestID": "0HLNLQ041IOVI:00000003", 
    "params": null, 
    "query_string": "", 
    "scheme": "http", 
    "method": "GET", 
    "statusCode": 200
  }, 
  "custom": {
    "LogMessage": "Connection id \"0HLNLQ041IOVI\", Request id \"0HLNLQ041IOVI:00000003\": An unhandled exception was thrown by the application.", 
    "LogEventID": "13 (ApplicationError)"
  }, 
  "environment": "Development", 
  "platform": "Microsoft Windows 10.0.17763 ", 
  "framework": ".NETCoreApp,Version=v2.2", 
  "notifier": {
    "version": "3.2.0", 
    "name": "Rollbar.NET"
  }, 
  "metadata": {
    "customer_timestamp": 1561070602
  }
}
akornich commented 5 years ago

@AFDevMike, thank you so much for posting these! You probably integrated Rollbar SDK into the application (that sourced these exceptions) by modifying two methods of the application Startup class: ConfigureServices(...) and Configure(...). May I ask you post here complete implementations of these methods?

AFDevMike commented 5 years ago

Sure:

        public static IServiceCollection AddAFRollbarLogging(this IServiceCollection services)
        {
            services.AddHttpContextAccessor();  // I vaguely recall having an issue and needing to add this.
            services.AddRollbarLogger(loggerOptions =>
            {
                loggerOptions.Filter = (loggerName, loglevel) => loglevel >= LogLevel.Error;
            });

            var rollbarCfg = new RollbarConfig(SharedConfig.RollbarCredentials.ServerPostToken);
            rollbarCfg.Environment = SharedConfig.CurrentEnvironment;
            rollbarCfg.CaptureUncaughtExceptions = true;
            RollbarLocator.RollbarInstance.Configure(rollbarCfg);

            return services;
        }

AND

        public static IApplicationBuilder UseAFRollbarMiddleware(this IApplicationBuilder app)
        {
            app.UseRollbarMiddleware();

            return app;
        }
akornich commented 5 years ago

@AFDevMike , thanks! And the methods where you are calling these methods from, please...

AFDevMike commented 5 years ago

Yep:

        public void ConfigureServices(IServiceCollection services)
        {
            services.AddAFApplicationInsights(Configuration);
            services.AddAFRollbarLogging();
            services.AddAFSpaFileServer();

            // DbContexts
            services.AddCrmDbContext();
            services.AddAFSharedDbContext();

            // Core Functionality
            services.AddAFTokenValidation();
            services.AddAFMvc();
            services.AddCors();

            // Misc..
            services.AddSingleton<TestingServicePlanWorker>();
            services.AddSingleton(Configuration);
            services.AddSingleton<RequestLoggingMiddleware>();

            services.AddScoped<AFSharedFilter>();
            services.AddScoped<RequestLogAggregator>();
            services.AddScoped<BlobStorageBackupService>();
            services.AddScoped<TwilioService>();

            // Background task handling
            services.AddSingleton<IScheduledTask, RequestLogAggregatorScheduledTask>();
            services.AddSingleton<IScheduledTask, AutoInspectUsageEmailTask>();
            services.AddSingleton<IRunOnceTask, DeleteBlobStorageContainerRunOnceTask>();
            services.AddSingleton<IRunOnceTask, HibernateTestingRunOnceTask>();
            services.InitBackgroundService();
        }

        public void Configure(IApplicationBuilder app, IServiceScopeFactory serviceScopeFactory,
            RunOnceTaskQueue runOnceTaskQueue, TestingServicePlanWorker tspWorker)
        {
            DIServiceFactory.Init(serviceScopeFactory);

            AFCacheRedisDbCtx.Init();

            tspWorker.Init();

            app.UseAuthentication();

            app.UseCorsForAF();

            app.UseAFRollbarMiddleware();

            app.UseMiddleware<RequestLoggingMiddleware>();

            app.UseMvc();

            app.InitializeAFStaticFileServer(AuthConfigHelper.GetAFShared().ApiURL);

            GitHubService.Init();

            AFSharedRedisDbCtx.Init();
        }
akornich commented 5 years ago

@AFDevMike , thank you! What happens when you comment out app.UseMiddleware(); line? Will you still see the double reporting of exceptions from the test case?

AFDevMike commented 5 years ago

// app.UseAFRollbarMiddleware(); <- results in no error logs. app.UseAFRollbarMiddleware(); <-results in 2 error logs.. (but only see 1 in console, if that helps)

akornich commented 5 years ago

Oops, sorry, that was a typo on my part. I meant if you comment out app.UseMiddleware<RequestLoggingMiddleware>();

AFDevMike commented 5 years ago

// app.UseMiddleware<RequestLoggingMiddleware>(); produces 2 logs as well.

AFDevMike commented 5 years ago

Just a shot in the dark but here is a link to a breaking change for Asp.Net core 2.0 and logging / DI https://github.com/aspnet/Announcements/issues/255

Additional info, prior to using Rollbar, we used Serilog and a sink to table storage. I know it used to only log once per uncaught Exception then. -Not sure if that helps at all.