Skip to content

Commit da83b18

Browse files
Flash0veralexsohn1126
authored andcommitted
fix(logs): Structured Logs do not send ParentSpanId when no Span was active (#4565)
1 parent e8033b6 commit da83b18

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)
@@ -28,28 +28,6 @@ private static void CaptureStructuredLog(IHub hub, SentryOptions options, LogEve
2828
hub.Logger.CaptureLog(log);
2929
}
3030

31-
private static void GetTraceIdAndSpanId(IHub hub, out SentryId traceId, out SpanId? spanId)
32-
{
33-
var span = hub.GetSpan();
34-
if (span is not null)
35-
{
36-
traceId = span.TraceId;
37-
spanId = span.SpanId;
38-
return;
39-
}
40-
41-
var scope = hub.GetScope();
42-
if (scope is not null)
43-
{
44-
traceId = scope.PropagationContext.TraceId;
45-
spanId = scope.PropagationContext.SpanId;
46-
return;
47-
}
48-
49-
traceId = SentryId.Empty;
50-
spanId = null;
51-
}
52-
5331
private static void GetStructuredLoggingParametersAndAttributes(LogEvent logEvent, out ImmutableArray<KeyValuePair<string, object>> parameters, out List<KeyValuePair<string, object>> attributes)
5432
{
5533
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;
@@ -248,4 +249,29 @@ internal void WriteTo(Utf8JsonWriter writer, IDiagnosticLogger? logger)
248249

249250
writer.WriteEndObject();
250251
}
252+
253+
internal static void GetTraceIdAndSpanId(IHub hub, out SentryId traceId, out SpanId? spanId)
254+
{
255+
var activeSpan = hub.GetSpan();
256+
if (activeSpan is not null)
257+
{
258+
traceId = activeSpan.TraceId;
259+
spanId = activeSpan.SpanId;
260+
return;
261+
}
262+
263+
// set "sentry.trace.parent_span_id" to the ID of the Span that was active when the Log was collected
264+
// do not set "sentry.trace.parent_span_id" if there was no active Span
265+
spanId = null;
266+
267+
var scope = hub.GetScope();
268+
if (scope is not null)
269+
{
270+
traceId = scope.PropagationContext.TraceId;
271+
return;
272+
}
273+
274+
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.");
275+
traceId = SentryId.Empty;
276+
}
251277
}

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");
@@ -128,15 +130,18 @@ public void Log_LogLevelNone_DoesNotCaptureLog()
128130
}
129131

130132
[Fact]
131-
public void Log_WithoutTraceHeader_CaptureLog()
133+
public void Log_WithoutActiveSpan_CaptureLog()
132134
{
135+
var scope = new Scope(_fixture.Options.Value);
136+
_fixture.Hub.GetSpan().Returns((ISpan?)null);
137+
_fixture.Hub.SubstituteConfigureScope(scope);
133138
var logger = _fixture.GetSut();
134139

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

137142
var log = _fixture.CapturedLogs.Dequeue();
138-
log.TraceId.Should().Be(SentryTraceHeader.Empty.TraceId);
139-
log.ParentSpanId.Should().Be(SentryTraceHeader.Empty.SpanId);
143+
log.TraceId.Should().Be(scope.PropagationContext.TraceId);
144+
log.ParentSpanId.Should().BeNull();
140145
}
141146

142147
[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
@@ -409,6 +409,58 @@ public void WriteTo_Attributes_AsJson()
409409
entry => entry.Message.Should().Match("*null*is not supported*ignored*")
410410
);
411411
}
412+
413+
[Fact]
414+
public void GetTraceIdAndSpanId_WithActiveSpan_HasBothTraceIdAndSpanId()
415+
{
416+
// Arrange
417+
var span = Substitute.For<ISpan>();
418+
span.TraceId.Returns(SentryId.Create());
419+
span.SpanId.Returns(SpanId.Create());
420+
421+
var hub = Substitute.For<IHub>();
422+
hub.GetSpan().Returns(span);
423+
424+
// Act
425+
SentryLog.GetTraceIdAndSpanId(hub, out var traceId, out var spanId);
426+
427+
// Assert
428+
traceId.Should().Be(span.TraceId);
429+
spanId.Should().Be(span.SpanId);
430+
}
431+
432+
[Fact]
433+
public void GetTraceIdAndSpanId_WithoutActiveSpan_HasOnlyTraceIdButNoSpanId()
434+
{
435+
// Arrange
436+
var hub = Substitute.For<IHub>();
437+
hub.GetSpan().Returns((ISpan)null);
438+
439+
var scope = new Scope();
440+
hub.SubstituteConfigureScope(scope);
441+
442+
// Act
443+
SentryLog.GetTraceIdAndSpanId(hub, out var traceId, out var spanId);
444+
445+
// Assert
446+
traceId.Should().Be(scope.PropagationContext.TraceId);
447+
spanId.Should().BeNull();
448+
}
449+
450+
[Fact]
451+
public void GetTraceIdAndSpanId_WithoutIds_ShouldBeUnreachable()
452+
{
453+
// Arrange
454+
var hub = Substitute.For<IHub>();
455+
hub.GetSpan().Returns((ISpan)null);
456+
457+
// Act
458+
SentryLog.GetTraceIdAndSpanId(hub, out var traceId, out var spanId);
459+
460+
// Assert
461+
traceId.Should().Be(SentryId.Empty);
462+
spanId.Should().BeNull();
463+
}
412464
}
413465

414466
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)