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

Finish unfinished Spans on Transaction completion #1296

Merged
merged 22 commits into from
Nov 8, 2021
Merged
Show file tree
Hide file tree
Changes from 15 commits
Commits
Show all changes
22 commits
Select commit Hold shift + click to select a range
c2d186b
add test case.
lucas-zimerman Nov 2, 2021
872c2c1
Update test.
lucas-zimerman Nov 2, 2021
e2a32d1
removed some moqs
lucas-zimerman Nov 2, 2021
5591695
Code cleanup
lucas-zimerman Nov 2, 2021
34c498a
Close spans with events without exceptions.
lucas-zimerman Nov 3, 2021
ae96241
Format code
getsentry-bot Nov 3, 2021
cfb2519
rollback Hub CaptureEvent, removed `A` and implemented close unfinish…
lucas-zimerman Nov 4, 2021
9d3ddeb
typo.
lucas-zimerman Nov 4, 2021
d04bf92
Tests fixes.
lucas-zimerman Nov 4, 2021
8038daa
Merge branch 'main' into fix/message-only-errors-not-closing-span
lucas-zimerman Nov 4, 2021
657c9b5
small refactor
lucas-zimerman Nov 5, 2021
3c943fd
Merge branch 'fix/message-only-errors-not-closing-span' of https://gi…
lucas-zimerman Nov 5, 2021
0bd5097
Merge branch 'main' into fix/message-only-errors-not-closing-span
lucas-zimerman Nov 5, 2021
272eece
Update changelog.
lucas-zimerman Nov 5, 2021
07374b2
Self code review fixes.
lucas-zimerman Nov 5, 2021
f30239b
Moved OR condition to the left side.
lucas-zimerman Nov 5, 2021
a92e53c
Removed unneeded Span close.
lucas-zimerman Nov 8, 2021
1223d3d
Merge branch 'main' into fix/message-only-errors-not-closing-span
lucas-zimerman Nov 8, 2021
dc2895a
Format code
getsentry-bot Nov 8, 2021
bb0063e
Merge branch 'main' into fix/message-only-errors-not-closing-span
lucas-zimerman Nov 8, 2021
fa2aa9e
Removed unused extension.
lucas-zimerman Nov 8, 2021
b25266a
Merge branch 'fix/message-only-errors-not-closing-span' of https://gi…
lucas-zimerman Nov 8, 2021
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
6 changes: 6 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
@@ -1,5 +1,11 @@
# Changelog

## Unreleased

### Fixes

- Finish unfinished Spans on Transaction completion ([#1296](https://github.com/getsentry/sentry-dotnet/pull/1296))

## 3.11.1

### Fixes
Expand Down
4 changes: 3 additions & 1 deletion src/Sentry/SentryEventExtensions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,8 @@ namespace Sentry
public static class SentryEventExtensions
{
internal static bool IsErrored(this SentryEvent @event)
=> @event.Exception is not null || @event.SentryExceptions?.Any() == true;
=> @event.Level >= SentryLevel.Error ||
@event.Exception is not null ||
@event.SentryExceptionValues?.Values.Any() == true;
}
}
2 changes: 1 addition & 1 deletion src/Sentry/Transaction.cs
Original file line number Diff line number Diff line change
Expand Up @@ -225,7 +225,7 @@ public Transaction(ITransaction tracer)
_breadcrumbs = tracer.Breadcrumbs.ToList();
_extra = tracer.Extra.ToDictionary();
_tags = tracer.Tags.ToDictionary();
_spans = tracer.Spans.Where(s => s.IsFinished).Select(s => new Span(s)).ToArray();
_spans = tracer.Spans.Select(s => new Span(s)).ToArray();
lucas-zimerman marked this conversation as resolved.
Show resolved Hide resolved
}

/// <inheritdoc />
Expand Down
8 changes: 8 additions & 0 deletions src/Sentry/TransactionTracer.cs
Original file line number Diff line number Diff line change
Expand Up @@ -225,6 +225,14 @@ public void Finish()
Status ??= SpanStatus.UnknownError;
EndTimestamp = DateTimeOffset.UtcNow;

foreach (var span in _spans)
{
if (!span.IsFinished)
{
span.Finish(SpanStatus.DeadlineExceeded);
}
}

// Clear the transaction from the scope
_hub.ConfigureScope(scope => scope.ResetTransaction(this));

Expand Down
53 changes: 52 additions & 1 deletion test/Sentry.Tests/HubTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -284,7 +284,7 @@ public void CaptureEvent_ExceptionWithOpenSpan_SpanFinishedWithInternalError()

var hub = new Hub(new SentryOptions
{
Dsn = DsnSamples.ValidDsnWithSecret,
Dsn = DsnSamples.ValidDsnWithSecret
}, client);
var scope = new Scope();
scope.Transaction = hub.StartTransaction("transaction", "operation");
Expand Down Expand Up @@ -1016,5 +1016,56 @@ public void ResumeSession_NoPausedSession_DoesNothing()
// Assert
client.DidNotReceive().CaptureSession(Arg.Is<SessionUpdate>(s => s.EndStatus != null));
}

[Theory]
[InlineData(SentryLevel.Error)]
[InlineData(SentryLevel.Fatal)]
public void CaptureEvent_ErroredMessageWithoutException_ClosesCurrentSpanAsInternalError(SentryLevel level)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not sure we should close the span. This will affect the end timestamp by setting the end of the span to the time the error happened, even if the span was still running for a long time after.

Capturing the even should include the trace information, which will help Sentry show in the span that there was a related error. The time the span finishes shouldn't be affected. I believe neither should the status. Say there was a try/catch. The user logged the error, but handled it, and had a retry logic that then succeeded. The overall span was OK, it took longer because it did more things than it needed if it had succeeded in the first place though.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Since spans are getting closed once the Transaction is concluded, I have removed the special code that was closing the spans if none of them were sampled.

{
// Arrange
var client = Substitute.For<ISentryClient>();

var hub = new Hub(new SentryOptions
{
Dsn = DsnSamples.ValidDsnWithSecret
}, client);
var scope = new Scope();
scope.Transaction = hub.StartTransaction("transaction", "operation");

var child = scope.Transaction.StartChild("child", "child");

// Act
hub.CaptureEvent(new SentryEvent() { Message = "Logger error", Level = level }, scope);

// Assert
Assert.Equal(SpanStatus.InternalError, child.Status);
Assert.True(child.IsFinished);
}

[Theory]
[InlineData(SentryLevel.Warning)]
[InlineData(SentryLevel.Info)]
[InlineData(SentryLevel.Debug)]
public void CaptureEvent_InfoMessageWithoutException_SpanNotChanged(SentryLevel level)
{
// Arrange
var client = Substitute.For<ISentryClient>();

var hub = new Hub(new SentryOptions
{
Dsn = DsnSamples.ValidDsnWithSecret
}, client);
var scope = new Scope();
scope.Transaction = hub.StartTransaction("transaction", "operation");

var child = scope.Transaction.StartChild("child", "child");

// Act
hub.CaptureEvent(new SentryEvent() { Message = "Logger error", Level = level }, scope);

// Assert
Assert.Null(child.Status);
Assert.False(child.IsFinished);
}
}
}
37 changes: 17 additions & 20 deletions test/Sentry.Tests/Protocol/TransactionTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -235,46 +235,43 @@ public void Finish_RecordsTime()
}

[Fact]
public void Finish_CapturesTransaction()
public void Finish_UnfinishedSpansGetsFinishedWithDeadlineStatus()
{
// Arrange
var client = Substitute.For<ISentryClient>();
var options = new SentryOptions { Dsn = DsnSamples.ValidDsnWithoutSecret };
var hub = new Hub(options, client);

var transaction = new TransactionTracer(hub, "my name", "my op");
var transaction = new TransactionTracer(DisabledHub.Instance, "my name", "my op");
transaction.StartChild("children1");
transaction.StartChild("children2");
transaction.StartChild("children3.finished").Finish(SpanStatus.Ok);
transaction.StartChild("children4");

// Act
transaction.Finish();

// Assert
client.Received(1).CaptureTransaction(Arg.Any<Transaction>());

Assert.All(transaction.Spans.Where(span => !span.Operation.EndsWith("finished")), span =>
{
Assert.True(span.IsFinished);
Assert.Equal(SpanStatus.DeadlineExceeded, span.Status);
});
Assert.Single(transaction.Spans.Where(span => span.Operation.EndsWith("finished") && span.Status == SpanStatus.Ok));
}

[Fact]
public void Finish_DropsUnfinishedSpans()
public void Finish_CapturesTransaction()
{
// Arrange
var client = Substitute.For<ISentryClient>();
var hub = new Hub(new SentryOptions { Dsn = DsnSamples.ValidDsnWithoutSecret }, client);
var options = new SentryOptions { Dsn = DsnSamples.ValidDsnWithoutSecret };
var hub = new Hub(options, client);

var transaction = new TransactionTracer(hub, "my name", "my op");

transaction.StartChild("op1").Finish();
transaction.StartChild("op2");
transaction.StartChild("op3").Finish();

// Act
transaction.Finish();

// Assert
client.Received(1).CaptureTransaction(
Arg.Is<Transaction>(t =>
t.Spans.Count == 2 &&
t.Spans.Any(s => s.Operation == "op1") &&
t.Spans.All(s => s.Operation != "op2") &&
t.Spans.Any(s => s.Operation == "op3")
));
client.Received(1).CaptureTransaction(Arg.Any<Transaction>());
}

[Fact]
Expand Down