Wrong exception stacktrace sent to Seq

[dabide]

We are experiencing something very strange when logging to Seq: When catching an exception, then logging it, and then rethrowing it, the exception stacktrace seems to be overwritten by a later log statement in an outer try/catch.

This is the code:

try
{
    throw new Exception("Why");
}
catch (Exception e)
{
    _logger.Error(e, "Something bad happened: {@ImageRequest}", imageRequest);
    throw;
}

When logging to the console, this expectedly results in the following:

[15:08:34 ERR] ImageService Something bad happened: {"Id": "e1005724-f7cd-4de1-93ff-54dd5eda11fc", "$type": "ImageRequest"}
System.Exception: Why
   at ImageService.<Get>d__4.MoveNext() in C:\...\ImageService.cs:line 34
[15:08:36 ERR] ServiceStack.ServiceStackHost ServiceBase<TRequest>::Service Exception
System.Exception: Why
   at ImageService.<Get>d__4.MoveNext() in C:\...\ImageService.cs:line 39

However, in Seq, it looks like this:

As you can see, the stacktrace of the former exception is replaced with the latter one. (Notice the line number.)

[dabide]

This looks like the same problem: serilog/serilog#399 (comment)

[nblumhardt]

Thanks for the report and the follow-up info, David. Yes, I think this is an instance of that behaviour.

It's a tricky one - I'm not sure that cost/benefit wise, it's going to make sense to change Serilog's exception capturing to better-support this case.

Addressing it in the sink directly might be a better bet; we could "capture" the stack trace before passing the event through to PeriodicBatchingSink. I'll need to give some thought to how we might do it.

[dabide]

Getting the wrong line number makes debugging much more difficult, so from our perspective, this makes sense cost/benefit wise. :-)

[nblumhardt]

@dabide I think a solution to this needs to be driven from Serilog core, so I've raised an issue over there. Input/ideas/feedback much appreciated :-)

serilog/serilog#1029