Azure / azure-webjobs-sdk

Azure WebJobs SDK
MIT License
737 stars 358 forks source link

Improve re-throwing exceptions by using ExceptionDispatchInfo throughout #2445

Open macrogreg opened 4 years ago

macrogreg commented 4 years ago

At many places the SDK uses the following pattern:

try
{
    // Do stuff
}
catch (Exception ex)
{
    if (SomeCondition())
    {
        // Handle ex
    }
    else
    {
        throw;
    }
}

The way the exception being re thrown is problematic. The resulting stack trace only shows the like on the respective method that contains the throw statement. A better way to re-thrown exceptions exists since NetFx version 4.5: ExceptionDispatchInfo.Capture(ex).Throw(). That approach will include richer stack trace information: bith,m the line where the exception originally occured, and where it was re-thrown.

We should move to using the ExceptionDispatchInfo-based approach throughout. Unless someone is parsing the exception stack trace, this is not a breaking change.

macrogreg commented 4 years ago

I have a PR for this locally, but I am having trouble pushing a private branch. Perhaps I am missing some permissions issue?

macrogreg commented 4 years ago

PR ready for review. I am working thought learning how to deal with the tests. Seems to be an infra issue. :)

macrogreg commented 4 years ago

@brettsam asked to provide a demo of how ExceptionDispatchInfo.Capture(ex).Throw(); improves things compared to throw;. Here is an example:

I provide some source code below as an image, so that you can easily see the line numbers. Then I provide the output. It should make things clear.

image

First we run this with line 54 uncommented and line 55 commented. So we use throw. The output is:

Sum: 0.
Executing DoStuff1.
Value: 1, Sum: 0.
Executing DoStuff2.

Caught exception in DoAllTheStuff:
System.Exception: Throwing an exception from within DoStuff2
   at ExceptionDispatchInfoDemo.Program.DoStuff2() in C:\00\Code\Sandbox\ExceptionDispatchInfoDemo\Program.cs:line 17
   at ExceptionDispatchInfoDemo.Program.DoAllTheStuff() in C:\00\Code\Sandbox\ExceptionDispatchInfoDemo\Program.cs:line 40
Rethrowing..

Caught exception in Exec:
System.Exception: Throwing an exception from within DoStuff2
   at ExceptionDispatchInfoDemo.Program.DoStuff2() in C:\00\Code\Sandbox\ExceptionDispatchInfoDemo\Program.cs:line 17
   at ExceptionDispatchInfoDemo.Program.DoAllTheStuff() in C:\00\Code\Sandbox\ExceptionDispatchInfoDemo\Program.cs:line 40
   at ExceptionDispatchInfoDemo.Program.Exec() in C:\00\Code\Sandbox\ExceptionDispatchInfoDemo\Program.cs:line 65

Next, we run this with line 54 commented and line 55 uncommented. So we use ExceptionDispatchInfo.Capture(ex).Throw(). The output is:

Sum: 0.
Executing DoStuff1.
Value: 1, Sum: 0.
Executing DoStuff2.

Caught exception in DoAllTheStuff:
System.Exception: Throwing an exception from within DoStuff2
   at ExceptionDispatchInfoDemo.Program.DoStuff2() in C:\00\Code\Sandbox\ExceptionDispatchInfoDemo\Program.cs:line 17
   at ExceptionDispatchInfoDemo.Program.DoAllTheStuff() in C:\00\Code\Sandbox\ExceptionDispatchInfoDemo\Program.cs:line 40
Rethrowing..

Caught exception in Exec:
System.Exception: Throwing an exception from within DoStuff2
   at ExceptionDispatchInfoDemo.Program.DoStuff2() in C:\00\Code\Sandbox\ExceptionDispatchInfoDemo\Program.cs:line 17
   at ExceptionDispatchInfoDemo.Program.DoAllTheStuff() in C:\00\Code\Sandbox\ExceptionDispatchInfoDemo\Program.cs:line 40
--- End of stack trace from previous location where exception was thrown ---
   at ExceptionDispatchInfoDemo.Program.DoAllTheStuff() in C:\00\Code\Sandbox\ExceptionDispatchInfoDemo\Program.cs:line 55
   at ExceptionDispatchInfoDemo.Program.Exec() in C:\00\Code\Sandbox\ExceptionDispatchInfoDemo\Program.cs:line 65

Let's examine the difference. In real life you do not expect to see the lines printed in DoAllTheStuff(..), you are likely to see just the stack trace as printed in Exec(..).

When using throw, you can see that the exception originated in line 17, and then passed through line 40 and finally ended up in line 65. There is no way to tell that it was caught and later re-thrown, and that the execution was affected accordingly. If something interesting has happened inside of the catch block of DoAllTheStuff(..), it is very hard to find out, unless you are very familiar with the code.

On contrary, when using ExceptionDispatchInfo.Capture(ex).Throw() you see some additional information. Specifically, it is evident that the exception came through line 40 and then was rethrown on line 55. You are pointed directly to the catch block, and in case that it has some complex logic you know exactly where the rethrowing occurred.

Background: We added this feature to the .NET Fx in version 4.5 when working on async/await. In async/await it is very common that an exception is captured in one place and is rethrown somewhere else. Potentially on a completely different stack or thread. Some very exotic applications parse exception stacks, so we decided for adding a new API rather than for improving the behavior of existing mechanisms. However, in this case the proposed change is completely safe, because the "improved" exceptions are not passed to user code. We merely improve our own ability to diagnose runtime issues.

Please let me know whether this helps. :)

brettsam commented 4 years ago

Here's some more examples: https://berserkerdotnet.github.io/blog/rethrow-exception-correctly-in-dotnet/