Skip to content

Commit

Permalink
Serilog dupe stackframe fix (#1076)
Browse files Browse the repository at this point in the history
* Checks if the log message is a duplicate using StackFrames

* Handle additional stackframe case

* Adds Serilog Asp.NET Core integration test covering duplicate log event

* Update CHANGELOG.md
  • Loading branch information
jaffinito authored May 4, 2022
1 parent b9d2a8a commit d594aa8
Show file tree
Hide file tree
Showing 8 changed files with 327 additions and 82 deletions.
9 changes: 9 additions & 0 deletions src/Agent/CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,10 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/),
and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html).

## [Unreleased] changes

### APM logs in context
Automatic application log forwarding is now enabled by default. This version of the agent will automatically send enriched application logs to New Relic. To learn more about about this feature see [here](https://docs.newrelic.com/docs/apm/new-relic-apm/getting-started/get-started-logs-context/), and additional configuration options are available [here](https://docs.newrelic.com/docs/logs/logs-context/net-configure-logs-context-all). To learn about how to toggle log ingestion on or off by account see [here](https://docs.newrelic.com/docs/logs/logs-context/disable-automatic-logging).

### New Features
* Error messages in error traces and error events now retain up to 1023 characters instead of 255 characters. [#1058](https://github.com/newrelic/newrelic-dotnet-agent/pull/1058)
* New environment variables have been added for AllowAllHeaders and Attributes configuration settings. See our [documentation](https://docs.newrelic.com/docs/apm/agents/net-agent/configuration/net-agent-configuration/#optional-environment-variables) for more details. [#1059](https://github.com/newrelic/newrelic-dotnet-agent/pull/1059)
Expand All @@ -14,6 +18,11 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0

### Fixes
* Fixes Agent fails to execute explain plan for parameterized stored procedure. ([#1066](https://github.com/newrelic/newrelic-dotnet-agent/pull/1066))
* Fixes getting duplicate logs using log forwarding and Serilog. [#1076](https://github.com/newrelic/newrelic-dotnet-agent/pull/1076)

### Deprecations
Microsoft has officially EOL .NET Framework versions 4.5.1, 4.5.2, and 4.6.1 on Apr 26, 2022.
The informational blog can be found [here](https://devblogs.microsoft.com/dotnet/net-framework-4-5-2-4-6-4-6-1-will-reach-end-of-support-on-april-26-2022). The official product lifecycle start and end dates can be found [here](https://docs.microsoft.com/en-us/lifecycle/products/microsoft-net-framework). The dotnet agent support of these framework versions is will continue as is with the released versions. In a future major release, we will target .NET framework 4.6.2 onwards.

## [9.7.1] - 2022-04-13
### Fixes
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@ public class SerilogWrapper : IWrapper
public bool IsTransactionRequired => false;

private const string WrapperName = "serilog";
private const string DispatchName = "Dispatch";

public CanWrapResponse CanWrap(InstrumentedMethodInfo methodInfo)
{
Expand All @@ -37,6 +38,29 @@ public CanWrapResponse CanWrap(InstrumentedMethodInfo methodInfo)

public AfterWrappedMethodDelegate BeforeWrappedMethod(InstrumentedMethodCall instrumentedMethodCall, IAgent agent, ITransaction transaction)
{
// This block works around an issue we are seeing in Serilog where Dispatch is called up to 3 times for each log message
// When looking at a stack trace for the problem, the you will see up to 3 Dispatch methods one after the other
// This detects the duplicates and noops.
var frame7 = new System.Diagnostics.StackFrame(7, false).GetMethod().Name;
string potentialDispatchFrame;
if (frame7 != DispatchName)
{
// Frame 7 is not Dispatch. This means that an extra frame was in the stack called "UnsafeInvokeInternal" at frame 6
// Look at frame 9 for duplicates instead of at frame 8
potentialDispatchFrame = new System.Diagnostics.StackFrame(9, false).GetMethod().Name;
}
else
{
// Frame 7 is Dispatch, no extra frames
// Look at frame 8 for duplicates
potentialDispatchFrame = new System.Diagnostics.StackFrame(8, false).GetMethod().Name;
}

if (potentialDispatchFrame == DispatchName)
{
return Delegates.NoOp;
}

var logEvent = instrumentedMethodCall.MethodCall.MethodArguments[0];

RecordLogMessage(logEvent, agent);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ public enum LoggingFramework
{
Log4net,
Serilog,
MicrosoftLogging
MicrosoftLogging,
SerilogWeb
}
}
Loading

0 comments on commit d594aa8

Please sign in to comment.