RehanSaeed/Serilog.Exceptions

Not showing Exception stack trace in "Exception" field of the log

jaslam94 opened this issue · 13 comments

Describe the feature

Here is an exception logged using Seriolog.Exceptions in a json file:

image

A part of my logger configuration with ExceptionDetails and RollingFile configuration is:

.Enrich.WithExceptionDetails( new DestructuringOptionsBuilder() .WithDefaultDestructurers()) .WriteTo.RollingFile(new JsonFormatter(","), HttpContext.Current.Server.MapPath($"~/logs/log-.json"));

With the above configuration, the stack trace displays inside the "ExceptionDetails" section which is just right.

I understand that I am using the new JsonFormatter() in the RollingFile sink, hence the Exception field inside the LogEvent object gets logged as Exception.ToString() and the stack trace becomes a part of the value of the "Exception" field in the log. But there is no need to display stack trace there when it can be shown as a separate field inside the "ExceptionDetails".

There should be an option in Exception Destructuring to show stack trace as a part of the value of the "Exception" or remove the "Exception" field altogether when the "ExceptionDetails" section is being written to the log.

Exception.StackTrace is logged in Serilog and is not owned by our project. There are other Serilog packages that can allow you to omit it. If you'd like Serilog.Exceptions to do the same, we'd take a PR.

Can you please let me know which package would allow me to omit it?

I believe it was called Serilog Expressions. The creator of Serilog blogged about it.

@jaslam94 https://github.com/destructurama and ByIgnoring project I guess would be a start point.

You could also write one yourself, it seems it would not be much more than:

logEvent.RemovePropertyIfPresent("StackTrace");

@RehanSaeed do you think we should include this function in the package. I could provide PR, which seems straighforward.

@krajek Adding another boolean option to remove it from ``Exception.StackTrace` seems sensible.

@jaslam94 https://github.com/destructurama and ByIgnoring project I guess would be a start point.

You could also write one yourself, it seems it would not be much more than:

logEvent.RemovePropertyIfPresent("StackTrace");

@RehanSaeed do you think we should include this function in the package. I could provide PR, which seems straighforward.

Correct me if I am wrong, but this would be used to remove a field from the Properties section of the log, not the Exception field which is a separate field. I have already tried it before opening the issue.

In the above example, there is one field called Exception and the other is called ExceptionDetails. ExceptionDetails is a child of Properties. By default, ExceptionDetails does not contain stack trace. I have added it myself to it by using .WithDefaultDestructurers() because it gets written as property under ExceptionDetails and this is what I need.

The issue, however, is that the stack trace gets stringified in the value of the Exception field. Hence the only solution I could think of is to prevent the Exception field from being written to the log altogether or not include stack trace to Exception field of the log.

@jaslam94 I haven't tried it, but wouldn't that be enough to remove the Exception and keep just the ExceptionDetails.StackTrace?

logEvent.RemovePropertyIfPresent("Exception");

@jaslam94 I haven't tried it, but wouldn't that be enough to remove the Exception and keep just the ExceptionDetails.StackTrace?

logEvent.RemovePropertyIfPresent("Exception");

Nope. It won't work. That would remove any given field under Properties section of the log. While I want to remove the Exception field that is not a part of Properties.

Check the following JSON:

{
  "Timestamp": "2021-09-02T15:04:02.4469999+05:00",
  "Level": "Error",
  "MessageTemplate": "Unhandled Exception",
  "Exception": "System.NullReferenceException: Object reference not set to an instance of an object.\r\n   at AppV2.Controllers.BaseController.Initialize(RequestContext requestContext) in E:\\Workspace\\AppV2\\AppV2\\Controllers\\BaseController.cs:line 115\r\n   at System.Web.Mvc.Controller.BeginExecute(RequestContext requestContext, AsyncCallback callback, Object state)\r\n   at System.Web.Mvc.Controller.System.Web.Mvc.Async.IAsyncController.BeginExecute(RequestContext requestContext, AsyncCallback callback, Object state)\r\n   at System.Web.Mvc.MvcHandler.<BeginProcessRequest>b__4(AsyncCallback asyncCallback, Object asyncState, ProcessRequestState innerState)\r\n   at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid`1.CallBeginDelegate(AsyncCallback callback, Object callbackState)\r\n   at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase`1.Begin(AsyncCallback callback, Object state, Int32 timeout)\r\n   at System.Web.Mvc.MvcHandler.BeginProcessRequest(HttpContextBase httpContext, AsyncCallback callback, Object state)\r\n   at System.Web.Mvc.MvcHandler.BeginProcessRequest(HttpContext httpContext, AsyncCallback callback, Object state)\r\n   at System.Web.Mvc.MvcHandler.System.Web.IHttpAsyncHandler.BeginProcessRequest(HttpContext context, AsyncCallback cb, Object extraData)\r\n   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()\r\n   at System.Web.HttpApplication.ExecuteStepImpl(IExecutionStep step)\r\n   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)",
  "Properties": {
    "UserName": "adminuser@mail.com",
    "ThreadId": 5,
    "Caller": "AppV2.Extensions.Logger.LogError(System.Exception, System.String, System.Object[])",
    "MachineName": "DESKTOP-GHV3V41",
    "HttpRequestId": "e9922caf-7e25-47f8-9941-263ba1ec4278",
    "HttpRequestNumber": 1,
    "HttpRequestClientHostIP": "::1",
    "HttpRequestType": "GET",
    "HttpRequestRawUrl": "/",
    "ExceptionDetails": {
      "Type": "System.NullReferenceException",
      "HResult": -2147467261,
      "Message": "Object reference not set to an instance of an object.",
      "Source": "Boilerplate.Web.Mvc5.Sample",
      "StackTrace": "   at AppV2.Controllers.BaseController.Initialize(RequestContext requestContext) in E:\\Workspace\\AppV2\\AppV2\\Controllers\\BaseController.cs:line 115\r\n   at System.Web.Mvc.Controller.BeginExecute(RequestContext requestContext, AsyncCallback callback, Object state)\r\n   at System.Web.Mvc.Controller.System.Web.Mvc.Async.IAsyncController.BeginExecute(RequestContext requestContext, AsyncCallback callback, Object state)\r\n   at System.Web.Mvc.MvcHandler.<BeginProcessRequest>b__4(AsyncCallback asyncCallback, Object asyncState, ProcessRequestState innerState)\r\n   at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid`1.CallBeginDelegate(AsyncCallback callback, Object callbackState)\r\n   at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase`1.Begin(AsyncCallback callback, Object state, Int32 timeout)\r\n   at System.Web.Mvc.MvcHandler.BeginProcessRequest(HttpContextBase httpContext, AsyncCallback callback, Object state)\r\n   at System.Web.Mvc.MvcHandler.BeginProcessRequest(HttpContext httpContext, AsyncCallback callback, Object state)\r\n   at System.Web.Mvc.MvcHandler.System.Web.IHttpAsyncHandler.BeginProcessRequest(HttpContext context, AsyncCallback cb, Object extraData)\r\n   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()\r\n   at System.Web.HttpApplication.ExecuteStepImpl(IExecutionStep step)\r\n   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)",
      "TargetSite": "Void Initialize(System.Web.Routing.RequestContext)"
    }
  }
}

See Properties field and then Exception field above it. I want to remove the Exception field or stack trace from the stringified value of the Exception field.

By default, the ExceptionDetails field comes under Properties.

The logEvent.RemovePropertyIfPresent("Exception"); would not be able to remove anything from the above JSON output.

I have also asked a question on SO, kindly check it as well: https://stackoverflow.com/questions/69028506/log-without-exception-stack-trace-in-serilog

@jaslam94 you are right, thanks for the explanation.
I have recalled that we had a similar discussion a long time ago and that is why we decided to omit StackTrace and TargetSite from ExceptionDetails by default. I think that there is no way to remove Exception from LogEvent. It is a getter without a setter.

Ok, that said, can you explain why would you want something else than default behavior. At the point when we decided on that set up, it seemed reasonable, because no information is lost and no memory/bandwith/storage is wasted. Could you elaborate a little bit on your scenario?

StackTrace is a property of Exception object in C#.

The field StackTrace in ExceptionDetails is logged as property and that's how an exception object should be logged. The structure of the exception object should be preserved. Your package does it just right.

I think rather than removing StackTrace from ExceptionDetails based on the reason that it is already logged in by the default Serilog implementation, overlooks the fact that the default exception logging by Serilog is simply unstructured and looks ugly.

Here is how it looks:

"System.NullReferenceException: Object reference not set to an instance of an object.\r\n at AppV2.Controllers.BaseController.Initialize(RequestContext requestContext) in E:\\Workspace\\AppV2\\AppV2\\Controllers\\BaseController.cs:line 115\r\n at System.Web.Mvc.Controller.BeginExecute(RequestContext requestContext, AsyncCallback callback, Object state)\r\n at System.Web.Mvc.Controller.System.Web.Mvc.Async.IAsyncController.BeginExecute(RequestContext requestContext, AsyncCallback callback, Object state)\r\n at System.Web.Mvc.MvcHandler.<BeginProcessRequest>b__4(AsyncCallback asyncCallback, Object asyncState, ProcessRequestState innerState)\r\n at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid`1.CallBeginDelegate(AsyncCallback callback, Object callbackState)\r\n at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase`1.Begin(AsyncCallback callback, Object state, Int32 timeout)\r\n at System.Web.Mvc.MvcHandler.BeginProcessRequest(HttpContextBase httpContext, AsyncCallback callback, Object state)\r\n at System.Web.Mvc.MvcHandler.BeginProcessRequest(HttpContext httpContext, AsyncCallback callback, Object state)\r\n at System.Web.Mvc.MvcHandler.System.Web.IHttpAsyncHandler.BeginProcessRequest(HttpContext context, AsyncCallback cb, Object extraData)\r\n at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()\r\n at System.Web.HttpApplication.ExecuteStepImpl(IExecutionStep step)\r\n at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)"

The above "default behaviour" contains the exception name, message and stack trace all joined and written together. It is unstructured.

Don't get me wrong but what's the point in using a separate package which logs the exception object in its structure but also having to keep the unstructured implementation in the log as well?

As a user, I would want to see one structured section in the log that shows me everything related to the exception object. i.e. ExceptionDetails. BTW, your package also allows renaming ExceptionDetails section. I can rename it to Exception only.

Second, if both the default Serilog implementation and Serilog.Exceptions implementation are logged together, the size of a log object increases as it contains redundant information, which in turn makes the size of my log file bigger as well.

Would this solve this issue?

#397 (comment)