Nlog: Formatting async stack traces in ${exception}

[biiiipy]

Type: Feature request

NLog version: 4.5.0-alpha04

In .NET, when using async code, stack traces contain a lot of helper methods (ala garbage).
Someone made a project that formats stack traces - https://github.com/aelij/AsyncFriendlyStackTrace
Example:

System.Exception: Crash! Boom! Bang!
   at AsyncFriendlyStackTrace.Test.Example1.<C>d__3.MoveNext() in C:\Source\Repos\AsyncFriendlyStackTrace\src\AsyncFriendlyStackTrace.Test\Example1.cs:line 26
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at AsyncFriendlyStackTrace.Test.Example1.<B>d__2.MoveNext() in C:\Source\Repos\AsyncFriendlyStackTrace\src\AsyncFriendlyStackTrace.Test\Example1.cs:line 20
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at AsyncFriendlyStackTrace.Test.Example1.<A>d__1.MoveNext() in C:\Source\Repos\AsyncFriendlyStackTrace\src\AsyncFriendlyStackTrace.Test\Example1.cs:line 15
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at AsyncFriendlyStackTrace.Test.Example1.<Run>d__0.MoveNext() in C:\Source\Repos\AsyncFriendlyStackTrace\src\AsyncFriendlyStackTrace.Test\Example1.cs:line 10
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at AsyncFriendlyStackTrace.Test.Program.Run[TExample](TextWriter writer) in C:\Source\Repos\AsyncFriendlyStackTrace\src\AsyncFriendlyStackTrace.Test\Program.cs:line 45

formated:

System.Exception: Crash! Boom! Bang!
   at async AsyncFriendlyStackTrace.Test.Example1.C(?) in C:\Source\Repos\AsyncFriendlyStackTrace\src\AsyncFriendlyStackTrace.Test\Example1.cs:line 26
   at async AsyncFriendlyStackTrace.Test.Example1.B(?) in C:\Source\Repos\AsyncFriendlyStackTrace\src\AsyncFriendlyStackTrace.Test\Example1.cs:line 20
   at async AsyncFriendlyStackTrace.Test.Example1.A(?) in C:\Source\Repos\AsyncFriendlyStackTrace\src\AsyncFriendlyStackTrace.Test\Example1.cs:line 15
   at async AsyncFriendlyStackTrace.Test.Example1.Run(?) in C:\Source\Repos\AsyncFriendlyStackTrace\src\AsyncFriendlyStackTrace.Test\Example1.cs:line 10
   at AsyncFriendlyStackTrace.Test.Program.Run[TExample](TextWriter writer) in C:\Source\Repos\AsyncFriendlyStackTrace\src\AsyncFriendlyStackTrace.Test\Program.cs:line 45

Maybe a similar feature could be integrated into NLog?

[304NotModified]

I'm not sure if we could include 3th party code (code licenses), but we could make it injectable? (inject AsyncFriendlyStackTrace package into NLog)

[snakefoot]

It should be "easy" to implement your own layout-renderer that performs the wanted formatting of the Exception-stack-trace.

[biiiipy]

Yes, it could be done with a custom renderer, I just think this is really useful as a built-in feature, because async code is getting more popular.
AsyncFriendlyStackTrace's code is MIT licensed, is there any issues with licensing?
I could create a PR with reimplementation of this if you want. It would be an option for stacktrace and exception layout renderers.

[304NotModified]

Good one.

You could copy/extends this class https://github.com/NLog/NLog/blob/master/src/NLog/LayoutRenderers/CallSiteLayoutRenderer.cs

And see https://github.com/nlog/nlog/wiki/Register-your-custom-component

[biiiipy]

I maybe misunderstood - do you want me take a stab at it and make a PR? If so, not sure why you linked those two items...

[304NotModified]

Ow I missed your previous comment.

Not sure about the PR. Also I prefer to keep NLog with zero dependencies.

The linked code was for your custom implementation. (Which could be registered into NLog)

[biiiipy]

There wouldn't be any dependencies. The relevant formatting code would be added straight into NLog code in stacktrace and exception renderers.

[304NotModified]

Well I don't know exactly what the license consequences are of copying the code into NLog.

[snakefoot]

Another approach:

https://docs.particular.net/samples/logging/stack-trace-cleaning/

[snakefoot]

Maybe resolved with #2292 ?

[biiiipy]

It is implemented for ${callsite}, which is nice but not critical. It sadly doesn't apply to ${exception} where we have a lot of garbage async text.

[304NotModified]

that was also not clear to me, updated the title

[snakefoot]

Maybe a new external exception-layout-renderer can be implemented with dependency on this:

https://github.com/benaadams/Ben.Demystifier

Must I admit I don't like the approach of ExceptionExtentions.Demystify to modify the original exception using reflection.

But one can use EnhancedStackTrace without modifying the original exception.

[biiiipy]

That looks like a great library, probably makes sense at least for us to implement a custom renderer around it.

Are you considering it including in NLog in any form? Ben Adams makes a great point that new C# language features (not only async) have made stack traces completely unreadable.

[304NotModified]

A new NLog package could be an option, an extra on dependency on the current package isn't.

[biiiipy]

Or the source could be adapted for inclusion in core NLog package (that library is licensed under apache 2.0), it depends on how you view this - as a core feature or a nice-to-have. I think, agreeing with Ben Adams view, C# has become so complex, that this is valuable for everybody who uses this library.

[304NotModified]

Or the source could be adapted for inclusion in core NLog package (that library is licensed under apache 2.0), it depends on how you view this

yeah also doubting about that. What do you think @snakefoot?

[snakefoot]

What do you think @snakefoot?

I would probably do like everyone else, and make an additional nuget package:

https://github.com/nblumhardt/serilog-enrichers-demystify
https://github.com/MNie/Log4Net.Demystifier

If it takes off for a great success that everyone wants, then one might consider to include it in NLog-core.

[304NotModified]

:+1: agree on these approach

[304NotModified]

FYI,

the easiest approach is here to write a new layout renderer by inheriting the ExceptionLayoutRenderer class and overwrite the AppendStackTrace method

[304NotModified]

I would probably do like everyone else, and make an additional nuget package:

https://github.com/nblumhardt/serilog-enrichers-demystify

BTW, that's a really nice usage of the enricher, which is kinda missing in NLog

[eddiegroves]

I was looking for this too, but as mentioned above, it's pretty straight forward to do yourself.

    public class CustomExceptionLayoutRenderer : ExceptionLayoutRenderer
    {
        protected override void AppendToString(StringBuilder sb, Exception ex)
        {
            // Install https://github.com/benaadams/Ben.Demystifier
            // The extension is under System.Diagnostics
            sb.Append(ex.Demystify());
        }
    }

... somewhere else e.g app startup

    // Make sure no loggers are created first! :)
    LayoutRenderer.Register<CustomExceptionLayoutRenderer>("custom-exception");

[304NotModified]

Fyi, related news: https://www.ageofascent.com/2018/01/26/stack-trace-for-exceptions-in-dotnet-core-2.1/