Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Capture Activity trace and span ids when present #56

Merged
merged 4 commits into from
Jan 25, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
12 changes: 12 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -114,6 +114,18 @@ var json = "{\"A\": 42}";
_logger.LogInformation("The answer is {Answer}", new JsonSafeString(json));
```

### Trace and span correlation

The Seq logger provider automatically adds trace and span ids to events when present, enabling the _Trace_ drop-down menu in Seq's expanded event view.

ASP.NET Core may add additional top-level `TraceId`, `SpanId`, and `ParentId` properties in its default configuration. You can remove these if you wish, using `ILoggingBuilder.Configure()`:

```csharp
builder.Logging.Configure(opts => {
opts.ActivityTrackingOptions = ActivityTrackingOptions.None;
});
```

### Troubleshooting

> Nothing showed up, what can I do?
Expand Down
2 changes: 1 addition & 1 deletion example/WebExample/Controllers/HomeController.cs
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,7 @@ namespace WebExample.Controllers;

public class HomeController : Controller
{
private readonly ILogger<HomeController> _logger;
readonly ILogger<HomeController> _logger;

public HomeController(ILogger<HomeController> logger)
{
Expand Down
7 changes: 5 additions & 2 deletions example/WebExample/Program.cs
Original file line number Diff line number Diff line change
Expand Up @@ -4,8 +4,11 @@
builder.Services.AddControllersWithViews();

// Use the Seq logging configuration in appsettings.json
builder.Host.ConfigureLogging(loggingBuilder =>
loggingBuilder.AddSeq());
builder.Logging.AddSeq();

// Don't log redundant top-level `TraceId` and `SpanId` properties, these are handled implicitly
// by the Seq logger.
builder.Logging.Configure(opts => opts.ActivityTrackingOptions = ActivityTrackingOptions.None);

var app = builder.Build();

Expand Down
1 change: 1 addition & 0 deletions seq-extensions-logging.sln.DotSettings
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
<s:String x:Key="/Default/CodeStyle/Naming/CSharpNaming/PredefinedNamingRules/=PrivateInstanceFields/@EntryIndexedValue">&lt;Policy Inspect="True" Prefix="_" Suffix="" Style="aaBb"&gt;&lt;ExtraRule Prefix="" Suffix="" Style="AaBb" /&gt;&lt;/Policy&gt;</s:String>
<s:Boolean x:Key="/Default/UserDictionary/Words/=appsettings/@EntryIndexedValue">True</s:Boolean>
<s:Boolean x:Key="/Default/UserDictionary/Words/=Datalust/@EntryIndexedValue">True</s:Boolean>
<s:Boolean x:Key="/Default/UserDictionary/Words/=Destructurer/@EntryIndexedValue">True</s:Boolean>
<s:Boolean x:Key="/Default/UserDictionary/Words/=Enricher/@EntryIndexedValue">True</s:Boolean>
<s:Boolean x:Key="/Default/UserDictionary/Words/=Formattable/@EntryIndexedValue">True</s:Boolean>
<s:Boolean x:Key="/Default/UserDictionary/Words/=Serilog/@EntryIndexedValue">True</s:Boolean></wpf:ResourceDictionary>
5 changes: 0 additions & 5 deletions src/Seq.Extensions.Logging/Serilog/Events/LevelAlias.cs
Original file line number Diff line number Diff line change
Expand Up @@ -28,9 +28,4 @@ static class LevelAlias
/// The least significant level of event.
/// </summary>
public const LogLevel Minimum = LogLevel.Trace;

/// <summary>
/// The most significant level of event.
/// </summary>
public const LogLevel Maximum = LogLevel.Critical;
}
31 changes: 27 additions & 4 deletions src/Seq.Extensions.Logging/Serilog/Events/LogEvent.cs
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@
// See the License for the specific language governing permissions and
// limitations under the License.

using System.Diagnostics;
using Microsoft.Extensions.Logging;

namespace Serilog.Events;
Expand All @@ -22,6 +23,8 @@ namespace Serilog.Events;
class LogEvent
{
readonly Dictionary<string, LogEventPropertyValue> _properties;
ActivityTraceId _traceId;
ActivitySpanId _spanId;

/// <summary>
/// Construct a new <seealso cref="LogEvent"/>.
Expand All @@ -31,14 +34,24 @@ class LogEvent
/// <param name="exception">An exception associated with the event, or null.</param>
/// <param name="messageTemplate">The message template describing the event.</param>
/// <param name="properties">Properties associated with the event, including those presented in <paramref name="messageTemplate"/>.</param>
public LogEvent(DateTimeOffset timestamp, LogLevel level, Exception exception, MessageTemplate messageTemplate, IEnumerable<LogEventProperty> properties)
/// <param name="traceId">The id of the trace that was active when the event was created, if any.</param>
/// <param name="spanId">The id of the span that was active when the event was created, if any.</param>
public LogEvent(
DateTimeOffset timestamp,
LogLevel level,
Exception exception,
MessageTemplate messageTemplate,
IEnumerable<LogEventProperty> properties,
ActivityTraceId traceId,
ActivitySpanId spanId)
{
if (messageTemplate == null) throw new ArgumentNullException(nameof(messageTemplate));
if (properties == null) throw new ArgumentNullException(nameof(properties));
_traceId = traceId;
_spanId = spanId;
Timestamp = timestamp;
Level = level;
Exception = exception;
MessageTemplate = messageTemplate;
MessageTemplate = messageTemplate ?? throw new ArgumentNullException(nameof(messageTemplate));
_properties = new Dictionary<string, LogEventPropertyValue>();
foreach (var p in properties)
AddOrUpdateProperty(p);
Expand All @@ -54,6 +67,16 @@ public LogEvent(DateTimeOffset timestamp, LogLevel level, Exception exception, M
/// </summary>
public LogLevel Level { get; }

/// <summary>
/// The id of the trace that was active when the event was created, if any.
/// </summary>
public ActivityTraceId? TraceId => _traceId == default ? null : _traceId;

/// <summary>
/// The id of the span that was active when the event was created, if any.
/// </summary>
public ActivitySpanId? SpanId => _spanId == default ? null : _spanId;

/// <summary>
/// The message template describing the event.
/// </summary>
Expand Down Expand Up @@ -122,4 +145,4 @@ public void RemovePropertyIfPresent(string propertyName)
{
_properties.Remove(propertyName);
}
}
}
Original file line number Diff line number Diff line change
@@ -1,26 +1,32 @@
// Copyright (c) .NET Foundation. All rights reserved.
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.

using System.Diagnostics;
using Microsoft.Extensions.Logging;
using Serilog.Core;
using Serilog.Events;
using FrameworkLogger = Microsoft.Extensions.Logging.ILogger;
using System.Reflection;
using Serilog.Parsing;

#nullable enable
// ReSharper disable ConditionIsAlwaysTrueOrFalse
// ReSharper disable ConditionIsAlwaysTrueOrFalseAccordingToNullableAPIContract
// ReSharper disable ConstantNullCoalescingCondition

namespace Serilog.Extensions.Logging;

class SerilogLogger : FrameworkLogger
{
readonly SerilogLoggerProvider _provider;
readonly Logger _logger;

static readonly MessageTemplateParser _messageTemplateParser = new MessageTemplateParser();
static readonly MessageTemplateParser MessageTemplateParser = new();

public SerilogLogger(
SerilogLoggerProvider provider,
Logger logger,
string name = null)
string? name = null)
{
if (logger == null) throw new ArgumentNullException(nameof(logger));
_provider = provider ?? throw new ArgumentNullException(nameof(provider));
Expand All @@ -38,42 +44,39 @@ public bool IsEnabled(LogLevel logLevel)
return _logger.IsEnabled(logLevel);
}

public IDisposable BeginScope<TState>(TState state)
public IDisposable? BeginScope<TState>(TState state) where TState : notnull
{
return _provider.BeginScope(state);
}

public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
{
if (!_logger.IsEnabled(logLevel))
{
return;
}

var logger = _logger;
string messageTemplate = null;
string? messageTemplate = null;

var properties = new List<LogEventProperty>();

var structure = state as IEnumerable<KeyValuePair<string, object>>;
if (structure != null)
if (state is IEnumerable<KeyValuePair<string, object>> structure)
{
foreach (var property in structure)
{
if (property.Key == SerilogLoggerProvider.OriginalFormatPropertyName && property.Value is string)
if (property is { Key: SerilogLoggerProvider.OriginalFormatPropertyName, Value: string })
{
messageTemplate = (string)property.Value;
}
else if (property.Key.StartsWith("@"))
{
LogEventProperty destructured;
if (logger.BindProperty(property.Key.Substring(1), property.Value, true, out destructured))
if (logger.BindProperty(property.Key.Substring(1), property.Value, true, out var destructured))
properties.Add(destructured);
}
else
{
LogEventProperty bound;
if (logger.BindProperty(property.Key, property.Value, false, out bound))
if (logger.BindProperty(property.Key, property.Value, false, out var bound))
properties.Add(bound);
}
}
Expand All @@ -84,15 +87,14 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except
if (messageTemplate == null && !stateTypeInfo.IsGenericType)
{
messageTemplate = "{" + stateType.Name + ":l}";
LogEventProperty stateTypeProperty;
if (logger.BindProperty(stateType.Name, AsLoggableValue(state, formatter), false, out stateTypeProperty))
if (logger.BindProperty(stateType.Name, AsLoggableValue(state, formatter), false, out var stateTypeProperty))
properties.Add(stateTypeProperty);
}
}

if (messageTemplate == null)
{
string propertyName = null;
string? propertyName = null;
if (state != null)
{
propertyName = "State";
Expand All @@ -106,26 +108,26 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except

if (propertyName != null)
{
LogEventProperty property;
if (logger.BindProperty(propertyName, AsLoggableValue(state, formatter), false, out property))
if (logger.BindProperty(propertyName, AsLoggableValue(state, formatter!), false, out var property))
properties.Add(property);
}
}

if (eventId.Id != 0 || eventId.Name != null)
properties.Add(CreateEventIdProperty(eventId));

var parsedTemplate = _messageTemplateParser.Parse(messageTemplate ?? "");
var evt = new LogEvent(DateTimeOffset.Now, logLevel, exception, parsedTemplate, properties);
var parsedTemplate = MessageTemplateParser.Parse(messageTemplate ?? "");
var currentActivity = Activity.Current;
var evt = new LogEvent(DateTimeOffset.Now, logLevel, exception, parsedTemplate, properties, currentActivity?.TraceId ?? default, currentActivity?.SpanId ?? default);
logger.Write(evt);
}

static object AsLoggableValue<TState>(TState state, Func<TState, Exception, string> formatter)
static object? AsLoggableValue<TState>(TState state, Func<TState, Exception?, string> formatter)
{
object sobj = state;
object? stateObject = state;
if (formatter != null)
sobj = formatter(state, null);
return sobj;
stateObject = formatter(state, null);
return stateObject;
}

static LogEventProperty CreateEventIdProperty(EventId eventId)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@
using Serilog.Formatting.Json;
using Serilog.Parsing;
using Microsoft.Extensions.Logging;
// ReSharper disable PossibleMultipleEnumeration

namespace Serilog.Formatting.Compact;

Expand Down Expand Up @@ -72,6 +73,20 @@ public static void FormatEvent(LogEvent logEvent, TextWriter output, JsonValueFo
JsonValueFormatter.WriteQuotedJsonString(logEvent.Exception.ToString(), output);
}

if (logEvent.TraceId != null)
{
output.Write(",\"@tr\":\"");
output.Write(logEvent.TraceId.Value.ToHexString());
output.Write('\"');
}

if (logEvent.SpanId != null)
{
output.Write(",\"@sp\":\"");
output.Write(logEvent.SpanId.Value.ToHexString());
output.Write('\"');
}

foreach (var property in logEvent.Properties)
{
var name = property.Key;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -196,7 +196,7 @@ LogEventPropertyValue CreatePropertyValue(object value, Destructuring destructur
return new ScalarValue(value.ToString());
}

private LogEventPropertyValue Stringify(object value)
LogEventPropertyValue Stringify(object value)
{
var stringified = value.ToString();
var truncated = TruncateIfNecessary(stringified);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,8 @@
<AssemblyOriginatorKeyFile>../../asset/seqext.snk</AssemblyOriginatorKeyFile>
<SignAssembly>true</SignAssembly>
<PublicSign Condition=" '$(OS)' != 'Windows_NT' ">true</PublicSign>
<RootNamespace>Tests</RootNamespace>
<LangVersion>latest</LangVersion>
</PropertyGroup>

<ItemGroup>
Expand All @@ -18,6 +20,7 @@
<IncludeAssets>runtime; build; native; contentfiles; analyzers; buildtransitive</IncludeAssets>
</PackageReference>
<PackageReference Include="xunit" Version="2.4.1" />
<PackageReference Include="Nullable" Version="1.3.1" PrivateAssets="all" />
</ItemGroup>

</Project>
Loading