Skip to content

Commit 20e6136

Browse files
Flash0verFlash0ver
authored
fix(logs): Structured Logs do not send ParentSpanId when no Span was active (#4565)
1 parent c4fe48f commit 20e6136

File tree

9 files changed

+112
-45
lines changed

9 files changed

+112
-45
lines changed

‎CHANGELOG.md‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@
1010
### Fixes
1111

1212
- Templates are no longer sent with Structured Logs that have no parameters ([#4544](https://github.com/getsentry/sentry-dotnet/pull/4544))
13+
- Parent-Span-IDs are no longer sent with Structured Logs when recorded without an active Span ([#4565](https://github.com/getsentry/sentry-dotnet/pull/4565))
1314
- Upload linked PDBs to fix non-IL-stripped symbolication for iOS ([#4527](https://github.com/getsentry/sentry-dotnet/pull/4527))
1415
- In MAUI Android apps, generate and inject UUID to APK and upload ProGuard mapping to Sentry with the UUID ([#4532](https://github.com/getsentry/sentry-dotnet/pull/4532))
1516
- Fixed WASM0001 warning when building Blazor WebAssembly projects ([#4519](https://github.com/getsentry/sentry-dotnet/pull/4519))

‎src/Sentry.Extensions.Logging/SentryStructuredLogger.cs‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -42,7 +42,7 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except
4242
}
4343

4444
var timestamp = _clock.GetUtcNow();
45-
var traceHeader = _hub.GetTraceHeader() ?? SentryTraceHeader.Empty;
45+
SentryLog.GetTraceIdAndSpanId(_hub, out var traceId, out var spanId);
4646

4747
var level = logLevel.ToSentryLogLevel();
4848
Debug.Assert(level != default);
@@ -81,11 +81,11 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except
8181
}
8282
}
8383

84-
SentryLog log = new(timestamp, traceHeader.TraceId, level, message)
84+
SentryLog log = new(timestamp, traceId, level, message)
8585
{
8686
Template = template,
8787
Parameters = parameters.DrainToImmutable(),
88-
ParentSpanId = traceHeader.SpanId,
88+
ParentSpanId = spanId,
8989
};
9090

9191
log.SetDefaultAttributes(_options, _sdk);

‎src/Sentry.Serilog/SentrySink.Structured.cs‎

Lines changed: 1 addition & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -7,7 +7,7 @@ internal sealed partial class SentrySink
77
{
88
private static void CaptureStructuredLog(IHub hub, SentryOptions options, LogEvent logEvent, string formatted, string? template)
99
{
10-
GetTraceIdAndSpanId(hub, out var traceId, out var spanId);
10+
SentryLog.GetTraceIdAndSpanId(hub, out var traceId, out var spanId);
1111
GetStructuredLoggingParametersAndAttributes(logEvent, out var parameters, out var attributes);
1212

1313
SentryLog log = new(logEvent.Timestamp, traceId, logEvent.Level.ToSentryLogLevel(), formatted)
@@ -27,28 +27,6 @@ private static void CaptureStructuredLog(IHub hub, SentryOptions options, LogEve
2727
hub.Logger.CaptureLog(log);
2828
}
2929

30-
private static void GetTraceIdAndSpanId(IHub hub, out SentryId traceId, out SpanId? spanId)
31-
{
32-
var span = hub.GetSpan();
33-
if (span is not null)
34-
{
35-
traceId = span.TraceId;
36-
spanId = span.SpanId;
37-
return;
38-
}
39-
40-
var scope = hub.GetScope();
41-
if (scope is not null)
42-
{
43-
traceId = scope.PropagationContext.TraceId;
44-
spanId = scope.PropagationContext.SpanId;
45-
return;
46-
}
47-
48-
traceId = SentryId.Empty;
49-
spanId = null;
50-
}
51-
5230
private static void GetStructuredLoggingParametersAndAttributes(LogEvent logEvent, out ImmutableArray<KeyValuePair<string, object>> parameters, out List<KeyValuePair<string, object>> attributes)
5331
{
5432
var propertyNames = new HashSet<string>();

‎src/Sentry/Internal/DefaultSentryStructuredLogger.cs‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -27,7 +27,7 @@ internal DefaultSentryStructuredLogger(IHub hub, SentryOptions options, ISystemC
2727
private protected override void CaptureLog(SentryLogLevel level, string template, object[]? parameters, Action<SentryLog>? configureLog)
2828
{
2929
var timestamp = _clock.GetUtcNow();
30-
var traceHeader = _hub.GetTraceHeader() ?? SentryTraceHeader.Empty;
30+
SentryLog.GetTraceIdAndSpanId(_hub, out var traceId, out var spanId);
3131

3232
string message;
3333
try
@@ -51,11 +51,11 @@ private protected override void CaptureLog(SentryLogLevel level, string template
5151
@params = builder.DrainToImmutable();
5252
}
5353

54-
SentryLog log = new(timestamp, traceHeader.TraceId, level, message)
54+
SentryLog log = new(timestamp, traceId, level, message)
5555
{
5656
Template = template,
5757
Parameters = @params,
58-
ParentSpanId = traceHeader.SpanId,
58+
ParentSpanId = spanId,
5959
};
6060

6161
try

‎src/Sentry/SentryLog.cs‎

Lines changed: 26 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,5 @@
11
using Sentry.Extensibility;
2+
using Sentry.Internal;
23
using Sentry.Protocol;
34

45
namespace Sentry;
@@ -243,4 +244,29 @@ internal void WriteTo(Utf8JsonWriter writer, IDiagnosticLogger? logger)
243244

244245
writer.WriteEndObject();
245246
}
247+
248+
internal static void GetTraceIdAndSpanId(IHub hub, out SentryId traceId, out SpanId? spanId)
249+
{
250+
var activeSpan = hub.GetSpan();
251+
if (activeSpan is not null)
252+
{
253+
traceId = activeSpan.TraceId;
254+
spanId = activeSpan.SpanId;
255+
return;
256+
}
257+
258+
// set "sentry.trace.parent_span_id" to the ID of the Span that was active when the Log was collected
259+
// do not set "sentry.trace.parent_span_id" if there was no active Span
260+
spanId = null;
261+
262+
var scope = hub.GetScope();
263+
if (scope is not null)
264+
{
265+
traceId = scope.PropagationContext.TraceId;
266+
return;
267+
}
268+
269+
Debug.Assert(hub is not Hub, "In case of a 'full' Hub, there is always a Scope. Otherwise (disabled) there is no Scope, but this branch should be unreachable.");
270+
traceId = SentryId.Empty;
271+
}
246272
}

‎test/Sentry.Extensions.Logging.Tests/SentryStructuredLoggerTests.cs‎

Lines changed: 12 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -51,10 +51,12 @@ public Fixture()
5151
public void EnableLogs(bool isEnabled) => Options.Value.Experimental.EnableLogs = isEnabled;
5252
public void SetMinimumLogLevel(LogLevel logLevel) => Options.Value.ExperimentalLogging.MinimumLogLevel = logLevel;
5353

54-
public void WithTraceHeader(SentryId traceId, SpanId parentSpanId)
54+
public void WithActiveSpan(SentryId traceId, SpanId parentSpanId)
5555
{
56-
var traceHeader = new SentryTraceHeader(traceId, parentSpanId, null);
57-
Hub.GetTraceHeader().Returns(traceHeader);
56+
var span = Substitute.For<ISpan>();
57+
span.TraceId.Returns(traceId);
58+
span.SpanId.Returns(parentSpanId);
59+
Hub.GetSpan().Returns(span);
5860
}
5961

6062
public SentryStructuredLogger GetSut()
@@ -83,7 +85,7 @@ public void Log_LogLevel_CaptureLog(LogLevel logLevel, SentryLogLevel expectedLe
8385
{
8486
var traceId = SentryId.Create();
8587
var parentSpanId = SpanId.Create();
86-
_fixture.WithTraceHeader(traceId, parentSpanId);
88+
_fixture.WithActiveSpan(traceId, parentSpanId);
8789
var logger = _fixture.GetSut();
8890

8991
EventId eventId = new(123, "EventName");
@@ -127,15 +129,18 @@ public void Log_LogLevelNone_DoesNotCaptureLog()
127129
}
128130

129131
[Fact]
130-
public void Log_WithoutTraceHeader_CaptureLog()
132+
public void Log_WithoutActiveSpan_CaptureLog()
131133
{
134+
var scope = new Scope(_fixture.Options.Value);
135+
_fixture.Hub.GetSpan().Returns((ISpan?)null);
136+
_fixture.Hub.SubstituteConfigureScope(scope);
132137
var logger = _fixture.GetSut();
133138

134139
logger.Log(LogLevel.Information, new EventId(123, "EventName"), new InvalidOperationException("message"), "Message with {Argument}.", "argument");
135140

136141
var log = _fixture.CapturedLogs.Dequeue();
137-
log.TraceId.Should().Be(SentryTraceHeader.Empty.TraceId);
138-
log.ParentSpanId.Should().Be(SentryTraceHeader.Empty.SpanId);
142+
log.TraceId.Should().Be(scope.PropagationContext.TraceId);
143+
log.ParentSpanId.Should().BeNull();
139144
}
140145

141146
[Fact]

‎test/Sentry.Serilog.Tests/SentrySinkTests.Structured.cs‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -112,7 +112,7 @@ public void Emit_StructuredLogging_LogEvent(bool withActiveSpan)
112112
log.Parameters[1].Should().BeEquivalentTo(new KeyValuePair<string, string>("Sequence", "[41, 42, 43]"));
113113
log.Parameters[2].Should().BeEquivalentTo(new KeyValuePair<string, string>("Dictionary", """[("key": "value")]"""));
114114
log.Parameters[3].Should().BeEquivalentTo(new KeyValuePair<string, string>("Structure", """[42, "42"]"""));
115-
log.ParentSpanId.Should().Be(withActiveSpan ? _fixture.Hub.GetSpan()!.SpanId : _fixture.Scope.PropagationContext.SpanId);
115+
log.ParentSpanId.Should().Be(withActiveSpan ? _fixture.Hub.GetSpan()!.SpanId : null);
116116

117117
log.TryGetAttribute("sentry.environment", out object? environment).Should().BeTrue();
118118
environment.Should().Be("test-environment");

‎test/Sentry.Tests/SentryLogTests.cs‎

Lines changed: 52 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -406,6 +406,58 @@ public void WriteTo_Attributes_AsJson()
406406
entry => entry.Message.Should().Match("*null*is not supported*ignored*")
407407
);
408408
}
409+
410+
[Fact]
411+
public void GetTraceIdAndSpanId_WithActiveSpan_HasBothTraceIdAndSpanId()
412+
{
413+
// Arrange
414+
var span = Substitute.For<ISpan>();
415+
span.TraceId.Returns(SentryId.Create());
416+
span.SpanId.Returns(SpanId.Create());
417+
418+
var hub = Substitute.For<IHub>();
419+
hub.GetSpan().Returns(span);
420+
421+
// Act
422+
SentryLog.GetTraceIdAndSpanId(hub, out var traceId, out var spanId);
423+
424+
// Assert
425+
traceId.Should().Be(span.TraceId);
426+
spanId.Should().Be(span.SpanId);
427+
}
428+
429+
[Fact]
430+
public void GetTraceIdAndSpanId_WithoutActiveSpan_HasOnlyTraceIdButNoSpanId()
431+
{
432+
// Arrange
433+
var hub = Substitute.For<IHub>();
434+
hub.GetSpan().Returns((ISpan)null);
435+
436+
var scope = new Scope();
437+
hub.SubstituteConfigureScope(scope);
438+
439+
// Act
440+
SentryLog.GetTraceIdAndSpanId(hub, out var traceId, out var spanId);
441+
442+
// Assert
443+
traceId.Should().Be(scope.PropagationContext.TraceId);
444+
spanId.Should().BeNull();
445+
}
446+
447+
[Fact]
448+
public void GetTraceIdAndSpanId_WithoutIds_ShouldBeUnreachable()
449+
{
450+
// Arrange
451+
var hub = Substitute.For<IHub>();
452+
hub.GetSpan().Returns((ISpan)null);
453+
454+
// Act
455+
SentryLog.GetTraceIdAndSpanId(hub, out var traceId, out var spanId);
456+
457+
// Assert
458+
traceId.Should().Be(SentryId.Empty);
459+
spanId.Should().BeNull();
460+
}
409461
}
410462

411463
file static class AssertExtensions

‎test/Sentry.Tests/SentryStructuredLoggerTests.cs‎

Lines changed: 13 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -26,8 +26,10 @@ public Fixture()
2626

2727
Hub.IsEnabled.Returns(true);
2828

29-
var traceHeader = new SentryTraceHeader(TraceId, ParentSpanId.Value, null);
30-
Hub.GetTraceHeader().Returns(traceHeader);
29+
var span = Substitute.For<ISpan>();
30+
span.TraceId.Returns(TraceId);
31+
span.SpanId.Returns(ParentSpanId.Value);
32+
Hub.GetSpan().Returns(span);
3133

3234
ExpectedAttributes = new Dictionary<string, string>(1)
3335
{
@@ -46,11 +48,14 @@ public Fixture()
4648

4749
public Dictionary<string, string> ExpectedAttributes { get; }
4850

49-
public void WithoutTraceHeader()
51+
public void WithoutActiveSpan()
5052
{
51-
Hub.GetTraceHeader().Returns((SentryTraceHeader?)null);
52-
TraceId = SentryId.Empty;
53-
ParentSpanId = SpanId.Empty;
53+
Hub.GetSpan().Returns((ISpan?)null);
54+
55+
var scope = new Scope();
56+
Hub.SubstituteConfigureScope(scope);
57+
TraceId = scope.PropagationContext.TraceId;
58+
ParentSpanId = null;
5459
}
5560

5661
public SentryStructuredLogger GetSut() => SentryStructuredLogger.Create(Hub, Options, Clock, BatchSize, BatchTimeout);
@@ -93,9 +98,9 @@ public void Create_Disabled_CachedDisabledInstance()
9398
}
9499

95100
[Fact]
96-
public void Log_WithoutTraceHeader_CapturesEnvelope()
101+
public void Log_WithoutActiveSpan_CapturesEnvelope()
97102
{
98-
_fixture.WithoutTraceHeader();
103+
_fixture.WithoutActiveSpan();
99104
_fixture.Options.Experimental.EnableLogs = true;
100105
var logger = _fixture.GetSut();
101106

0 commit comments

Comments
 (0)