Trace Context in Logs¶
Adding trace context to application logs provides the ability to correlate the log messages from a single transaction, and if sampled, the log messages to the transaction trace detail.
The AppOptics .NET agent offers several options to include trace context into logs managed by several popular .NET logging frameworks, and provides a custom SDK call which can be used if the automatic options do not support your logger.
How to Add Trace Context to Logs¶
There are 3 options to include trace context into logs:
Automatic Insert¶
When enabled, the .NET agent automatically inserts the trace context to the end of the layout’s output template. As a result, all log messages will have the Trace ID appended at the end.
This feature is disabled by default, more detail can be found in the Configuration section.
Automatic Attribute¶
.NET agent automatically adds %property{ao.traceId:long}
attribute for Log4net or {aoTraceIdLong}
attribute for Serilog
to the Logging Event object. The attribute contains the Trace ID value.
Such a value can then be included in the logging layout by using pattern such as %property{ao.traceId:long}
for
Log4net or {aoTraceIdLong}
for Serilog.
These features are disabled by default, more detail on how to enable these options can be found in the Configuration section.
Using the SDK¶
Trace context can be manually inserted into log messages; this can be used if your application logger is not supported by the automatic options above. The string value of the Trace context can be obtained using the SDK GetLogTraceId method. Note that if the agent is not available or not started propertly, the value will be an empty string.
Supported Frameworks¶
Log4net¶
When using automatic insert, the PatternLayout
is updated with %property{ao.traceId:long}
at the end and when a message is logged
the Trace ID will be at the end of the log message.
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date [%thread] %level %logger - %message %property{ao.traceId:long} %newline" />
</layout>
Output:
2019-05-23 15:02:49,708 [6] INFO WebApp.Controllers.HelloController - hello world ao.traceId=C2E7EA546BC9C31BC18E1877C3191A0C6E952C08-1
When using automatic attribute, the PatternLayout
layout must be manually updated %property{ao.traceId:long}
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date [%thread] %level %logger %property{ao.traceId:long} - %message%newline" />
</layout>
Output:
2019-05-23 15:02:49,708 [6] INFO WebApp.Controllers.HelloController ao.traceId=C2E7EA546BC9C31BC18E1877C3191A0C6E952C08-1 - hello world
The %property{ao.traceId:<format>}
allows the following formats:
%property{ao.traceId}
- output contains only the log Trace ID2019-05-23 15:02:49,708 [6] INFO WebApp.Controllers.HelloController C2E7EA546BC9C31BC18E1877C3191A0C6E952C08-1 - hello world
%property{ao.traceId:long}
- default format used for auto inserting, the log Trace ID is prefixed with ao.traceId=2019-05-23 15:02:49,708 [6] INFO WebApp.Controllers.HelloController ao.traceId=C2E7EA546BC9C31BC18E1877C3191A0C6E952C08-1 - hello world
%property{ao.traceId:json}
- output is a JSON object2019-05-23 15:02:49,708 [6] INFO WebApp.Controllers.HelloController {"ao":{"traceId":"C2E7EA546BC9C31BC18E1877C3191A0C6E952C08-1"}} - hello world
When using the XmlLayout layout and automatic attribute is enabled
<layout type="log4net.Layout.XmlLayout"></layout>
Output:
<log4net:event logger="WebApp.Controllers.HelloController" timestamp="2019-05-27T15:35:22.0626731-07:00" level="INFO" thread="6" domain="/LM/W3SVC/5/ROOT-1-132034701117372141" username="IIS APPPOOL\MVC5_TestLog4net">
<log4net:message>hello world</log4net:message>
<log4net:properties>
<log4net:data name="log4net:HostName" value="TEST-MACHINE" />
<log4net:data name="ao.traceId" value="C2E7EA546BC9C31BC18E1877C3191A0C6E952C08-1" />
</log4net:properties>
</log4net:event>
When using an SimpleLayout layout and automatic insert is enabled
<layout type="log4net.Layout.SimpleLayout"></layout>
Output:
INFO - hello world ao.traceId=C2E7EA546BC9C31BC18E1877C3191A0C6E952C08-1
Serilog 2.8.0¶
Note
This feature is only available when log events are enriched with built-in Serilog.Context.LogContext enricher. When creating logger object, a call to .Enrich.FromLogContext() method must be added.
When using automatic insert, the output template is updated at runtime to contain {aoTraceIdLong}
attribute
// Output template
string outTemplate = "{Timestamp:HH:mm} [{Level}] {Message}{NewLine}{Exception}";
// Create serilog logger using provided output template
Log.Logger = new LoggerConfiguration()
.Enrich.FromLogContext()
.WriteTo.File(logFile, rollingInterval: RollingInterval.Infinite, outputTemplate: outTemplate)
.CreateLogger();
Log.Information("hello world");
Output:
15:55 [Information] hello world ao.traceId=C2E7EA546BC9C31BC18E1877C3191A0C6E952C08-1
When using automatic attribute, the output template must be manually updated with {aoTraceIdLong}
attribute
// Output template
string outTemplate = "{Timestamp:HH:mm} [{Level}] {aoTraceIdLong} {Message}{NewLine}{Exception}";
// Create serilog logger using provided output template
Log.Logger = new LoggerConfiguration()
.Enrich.FromLogContext()
.WriteTo.File(logFile, rollingInterval: RollingInterval.Infinite, outputTemplate: outTemplate)
.CreateLogger();
Log.Information("hello world");
Output:
15:55 [Information] ao.traceId=C2E7EA546BC9C31BC18E1877C3191A0C6E952C08-1 hello world
The {aoTraceId<format>}
allows the following formats:
{aoTraceId}
- output contains only log trace context15:55 [Information] C2E7EA546BC9C31BC18E1877C3191A0C6E952C08-1 hello world
{aoTraceIdLong}
- default format used for auto inserting, the log Trace ID is prefixed with ao.traceId=15:55 [Information] ao.traceId=C2E7EA546BC9C31BC18E1877C3191A0C6E952C08-1 hello world
{aoTraceIdJson}
- output is a JSON object15:55 [Information] {"ao":{"traceId":"C2E7EA546BC9C31BC18E1877C3191A0C6E952C08-1"}} hello world
When using automatic attribute in combination with CompactJsonFormatter formatter class, trace context is added as aoTraceId property of the JSON record
Log.Logger = new LoggerConfiguration()
.Enrich.FromLogContext()
.WriteTo.File(new CompactJsonFormatter(), logFile)
.CreateLogger();
Log.Information("hello world");
Output:
{"@t":"2019-05-28T21:44:00.3293747Z","@mt":"hello world","aoTraceId":"C2E7EA546BC9C31BC18E1877C3191A0C6E952C08-1"}