Runtime: Add support for the InnerException(s) logging into Microsoft.Extensions.Logging.Console json formatter.

[dmitriyse]

Background and Motivation

In the .Net 5.0 JSON formatter was added to the console logger.
But it's current implementation lacks the output of the Exception.InnerException information which is 100% useful.
See https://github.com/dotnet/runtime/issues/34742

Proposed API

Add Exception.ToString() into additional JSON field (FullExceptionDetail).
Optionally this feature can be controlled by some flag in the JsonConsoleFormatterOptions
For example: IncludeFullExceptionDetail

Alternative

Add recursion into Exception.InnerException formatting.

[Dotnet-GitSync-Bot]

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

[msftbot[bot]]

Tagging subscribers to this area: @maryamariyan
See info in area-owners.md if you want to be subscribed.

[KalleOlaviNiemitalo]

If you're changing JsonConsoleFormatter to format Exception.InnerException (recursively or as a string), then I think it should use AggregateException.InnerExceptions instead when available.

[WernerMairl]

Note:
AggregatedException.ToString() is implemented [here].

(https://github.com/dotnet/runtime/blob/fb18a11af37209018899ed31470bd639fb9fc9b6/src/libraries/System.Private.CoreLib/src/System/AggregateException.cs#L434)

behavior: merge and print out distinct (innerexception+InnerExceptions) by calling .ToString() for each of them!

[maryamariyan]

@dmitriyse for this proposal it would help if you could please provide an example logging usage and expected/actual output for it.

[maryamariyan]

Seems like the best way forward for issue is if we changed the output from

To rather just have

"Exception" : "X"

where X is the exception.ToString() content (similar to what is done in SystemdConsoleFormatter or SimpleConsoleFormatter) and when FormatterOptions.JsonWriterOptions.Indented is false for JsonConsoleFormatter to write the exception.ToString() content in single line changing new lines to a whitespace otherwise with \n.

[WernerMairl]

@maryamariyan your proposal looks nice and simple but i think the main purpose of this logger was providing output with more (predictable) structured output details specially for other engines that are interpreting logs (ApplicationInsights et.al)

the more complex way (and not easy to implement) may be using the full capabilities to implement hierarchies inside Json:

   "Exception": {
        "Message": "Root",
        "Type": "System.Exception",
        "StackTrace": [
            "   at Microsoft.Extensions.Logging.Console.Test.JsonConsoleFormatterTests.EnsureStackTrace(Exception[] exceptions) in C:\\work\\dev\\runtime\\src\\libraries\\Microsoft.Extensions.Logging.Console\\tests\\JsonConsoleFormatterTests.cs:line 62"
        ],
        "HResult": -2146233088,
        "InnerExceptions" : [
            {
             "Message": "InnerException1",
             "Type": "System.Exception",
             "InnerExceptions" : []
            },
            {
                "Message": "InnerException2",
                "Type": "System.Exception",
                "InnerExceptions" : []
            }
        ]
    }

using "InnerExceptions" (plural) as array allows to implement BOTH core usecases:

• Exception.InnerException
• AggregatedException.InnerExceptions

btw.: Exception.Data should also be added on every level of exception...(#35922 )

[WernerMairl]

i have created a first draft that implements InnerExceptions AND Exception.Data output:

https://github.com/WernerMairl/runtime/commit/39235faa027d7a0bf1339c2eec516318e2c8babf

The test is creating the following exception hierarchy:

            Exception innerException = new Exception("InnerException");
            innerException.Data.Add("innerKey1", "innerExceptionDictionaryEntry1");
            innerException.Data.Add("innerKey2", "innerExceptionDictionaryEntry2");

            Exception rootException = new Exception("Root",innerException);
            rootException.Data.Add("rootKey1", "rootExceptionDictionaryEntry1");
            rootException.Data.Add("rootKey2", "rootExceptionDictionaryEntry2");

and the reuslting json looks like:

{
    "Timestamp": null,
    "EventId": 0,
    "LogLevel": "Error",
    "Category": "category",
    "Message": "mystate",
    "Exception": {
        "Message": "Root",
        "Type": "System.Exception",
        "StackTrace": [
            "   at Microsoft.Extensions.Logging.Console.Test.JsonConsoleFormatterTests.EnsureStackTrace(Exception[] exceptions) in C:\\work\\dev\\runtime\\src\\libraries\\Microsoft.Extensions.Logging.Console\\tests\\JsonConsoleFormatterTests.cs:line 62"
        ],
        "HResult": -2146233088,
        "Data": {
            "rootKey1": "rootExceptionDictionaryEntry1",
            "rootKey2": "rootExceptionDictionaryEntry2"
        },
        "InnerExceptions": [
            {
                "Message": "InnerException",
                "Type": "System.Exception",
                "StackTrace": [
                    "   at Microsoft.Extensions.Logging.Console.Test.JsonConsoleFormatterTests.EnsureStackTrace(Exception[] exceptions) in C:\\work\\dev\\runtime\\src\\libraries\\Microsoft.Extensions.Logging.Console\\tests\\JsonConsoleFormatterTests.cs:line 62"
                ],
                "HResult": -2146233088,
                "Data": {
                    "innerKey1": "innerExceptionDictionaryEntry1",
                    "innerKey2": "innerExceptionDictionaryEntry2"
                }
            }
        ]
    }
}

if we agree to go this way, i can polish the code and prepare a PR

[maryamariyan]

@WernerMairl the proposal looks good and is an improvement to what is already there.

A limitation to it though is that sometimes different exception types may embed extra content into exception.ToString that would otherwise get lost if we not use ToString instead.
maryamariyan@f214269fd29a7ac19e59245ac426d025ec319a54

cc: @tarekgh @eerhardt @davidfowl

[tarekgh]

I am wondering, do we also handle the AggregateException?

[WernerMairl]

Yes, AggregateException is covered by the implementation!

[WernerMairl]

About exception.ToString() and extra content
Yes, I see the same concerns....

On the other side, we have a lot of problems/risks with Exception.ToString:
Each ToString() override does his own formatting for stacktrace, innerexceptions etc...
this does not looks like a consistent output
and now we are working on adding Exception.Data output on top of this....

Assuming that we cannot do significant changes on System.Exception.ToString() I'm proposing the following

a) logging extension should ignore Exception.ToString() because output content and format is not predictable.
b) logging extension should print out all the properties implemented in System.Exception (Message, Stacktrace, HResult, Data) in a consisten way
c) logging extension is traversing the innerException(s) hierarchy
c) logging extension has a few customization points where the user can
- enable Exception.Data output
- implement logging for custom exception properties

For the moment the Jsonformatter is following exactly the way proposed above, and maybe we should follow the same way for the other Console Loggers....

just my 2 cent...

[maryamariyan]

a) logging extension should ignore Exception.ToString() because output content and format is not predictable.

It would be as unpredictable for SystemdConsoleFormatter and SimpleConsoleFormatter, and we would still be left inconsistent if we keep using exception.ToString() for the other two formatter.

c) logging extension has a few customization points where the user can

• enable Exception.Data output
• implement logging for custom exception properties

I think you're thinking in terms of using JsonConsoleFormatterOptions for further customization. If so, I believe there is no such customization yet for Exception.Data.

Your PR is a definite improvement to what is already in the code base, which is not using System.Exception.ToString(). I think for us to completely move away from exception.ToString, a little bit more design discussion needs to happen, perhaps coming up with some customization as you said.

My thought process is for 5.0 maybe we can switch back to using ToString instead. Perhaps we could move away from it in 6.0 timeframe when we have properly designed it and have clear ideas for the other two formatters as well.

That said if others provide approvals for the PR then we could go right ahead with your approach.