From 717ccadd1032be019592d84849b492a6960260fc Mon Sep 17 00:00:00 2001 From: Maciej Walkowiak Date: Mon, 6 Sep 2021 10:04:22 +0200 Subject: [PATCH] Feat: Include unfinished spans in transaction. (#1699) Fixes #1690. --- CHANGELOG.md | 1 + .../src/main/java/io/sentry/SentryClient.java | 20 ------------------- .../src/main/java/io/sentry/SentryTracer.java | 19 ++++++++++++++++++ sentry/src/main/java/io/sentry/Span.java | 12 ++++++++++- .../io/sentry/protocol/SentryTransaction.java | 3 +-- .../test/java/io/sentry/SentryClientTest.kt | 19 ------------------ .../test/java/io/sentry/SentryTracerTest.kt | 15 ++++++++++++++ 7 files changed, 47 insertions(+), 42 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index a5b2a67f57..7928dba9fc 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -3,6 +3,7 @@ ## Unreleased * Feat: Add tracestate HTTP header support (#1683) +* Feat: Include unfinished spans in transaction (#1699) Breaking changes: diff --git a/sentry/src/main/java/io/sentry/SentryClient.java b/sentry/src/main/java/io/sentry/SentryClient.java index 03551ebb6d..75ceabfbbd 100644 --- a/sentry/src/main/java/io/sentry/SentryClient.java +++ b/sentry/src/main/java/io/sentry/SentryClient.java @@ -3,7 +3,6 @@ import io.sentry.hints.DiskFlushNotification; import io.sentry.protocol.Contexts; import io.sentry.protocol.SentryId; -import io.sentry.protocol.SentrySpan; import io.sentry.protocol.SentryTransaction; import io.sentry.transport.ITransport; import io.sentry.util.ApplyScopeUtils; @@ -434,8 +433,6 @@ public void captureSession(final @NotNull Session session, final @Nullable Objec return SentryId.EMPTY_ID; } - processTransaction(transaction); - try { final SentryEnvelope envelope = buildEnvelope( @@ -469,23 +466,6 @@ public void captureSession(final @NotNull Session session, final @Nullable Objec return attachmentsToSend; } - private @NotNull SentryTransaction processTransaction( - final @NotNull SentryTransaction transaction) { - final List unfinishedSpans = new ArrayList<>(); - for (SentrySpan span : transaction.getSpans()) { - if (!span.isFinished()) { - unfinishedSpans.add(span); - } - } - if (!unfinishedSpans.isEmpty()) { - options - .getLogger() - .log(SentryLevel.WARNING, "Dropping %d unfinished spans", unfinishedSpans.size()); - } - transaction.getSpans().removeAll(unfinishedSpans); - return transaction; - } - private @Nullable SentryEvent applyScope( @NotNull SentryEvent event, final @Nullable Scope scope, final @Nullable Object hint) { if (scope != null) { diff --git a/sentry/src/main/java/io/sentry/SentryTracer.java b/sentry/src/main/java/io/sentry/SentryTracer.java index ad4c280bc3..34438e8a27 100644 --- a/sentry/src/main/java/io/sentry/SentryTracer.java +++ b/sentry/src/main/java/io/sentry/SentryTracer.java @@ -207,6 +207,25 @@ public void finish(@Nullable SpanStatus status) { this.finishStatus = FinishStatus.finishing(status); if (!root.isFinished() && (!waitForChildren || hasAllChildrenFinished())) { root.finish(finishStatus.spanStatus); + + // finish unfinished children + Date finishTimestamp = root.getTimestamp(); + if (finishTimestamp == null) { + hub.getOptions() + .getLogger() + .log( + SentryLevel.WARNING, + "Root span - op: %s, description: %s - has no timestamp set, when finishing unfinished spans.", + root.getOperation(), + root.getDescription()); + finishTimestamp = DateUtils.getCurrentDateTime(); + } + for (final Span child : children) { + if (!child.isFinished()) { + child.finish(SpanStatus.DEADLINE_EXCEEDED, finishTimestamp); + } + } + hub.configureScope( scope -> { scope.withTransaction( diff --git a/sentry/src/main/java/io/sentry/Span.java b/sentry/src/main/java/io/sentry/Span.java index b065f78651..f47f4edc13 100644 --- a/sentry/src/main/java/io/sentry/Span.java +++ b/sentry/src/main/java/io/sentry/Span.java @@ -122,13 +122,23 @@ public void finish() { @Override public void finish(@Nullable SpanStatus status) { + finish(status, DateUtils.getCurrentDateTime()); + } + + /** + * Used to finish unfinished spans by {@link SentryTracer}. + * + * @param status - status to finish span with + * @param timestamp - the root span timestamp. + */ + void finish(@Nullable SpanStatus status, Date timestamp) { // the span can be finished only once if (!finished.compareAndSet(false, true)) { return; } this.context.setStatus(status); - timestamp = DateUtils.getCurrentDateTime(); + this.timestamp = timestamp; if (throwable != null) { hub.setSpanContext(throwable, this, this.transaction.getName()); } diff --git a/sentry/src/main/java/io/sentry/protocol/SentryTransaction.java b/sentry/src/main/java/io/sentry/protocol/SentryTransaction.java index 4abc9f7f91..06ebf79314 100644 --- a/sentry/src/main/java/io/sentry/protocol/SentryTransaction.java +++ b/sentry/src/main/java/io/sentry/protocol/SentryTransaction.java @@ -1,6 +1,5 @@ package io.sentry.protocol; -import io.sentry.DateUtils; import io.sentry.SentryBaseEvent; import io.sentry.SentryTracer; import io.sentry.Span; @@ -42,7 +41,7 @@ public SentryTransaction(final @NotNull SentryTracer sentryTracer) { super(sentryTracer.getEventId()); Objects.requireNonNull(sentryTracer, "sentryTracer is required"); this.startTimestamp = sentryTracer.getStartTimestamp(); - this.timestamp = DateUtils.getCurrentDateTime(); + this.timestamp = sentryTracer.getTimestamp(); this.transaction = sentryTracer.getName(); for (final Span span : sentryTracer.getChildren()) { this.spans.add(new SentrySpan(span)); diff --git a/sentry/src/test/java/io/sentry/SentryClientTest.kt b/sentry/src/test/java/io/sentry/SentryClientTest.kt index e77304a072..5eaab14138 100644 --- a/sentry/src/test/java/io/sentry/SentryClientTest.kt +++ b/sentry/src/test/java/io/sentry/SentryClientTest.kt @@ -893,25 +893,6 @@ class SentryClientTest { }, eq(null)) } - @Test - fun `when captureTransactions unfinished spans are removed`() { - val sut = fixture.getSut() - val transaction = SentryTracer(TransactionContext("a-transaction", "op"), fixture.hub) - val span1 = transaction.startChild("span1") - span1.finish() - val span2 = transaction.startChild("span2") - - sut.captureTransaction(SentryTransaction(transaction), Scope(fixture.sentryOptions), null) - verify(fixture.transport).send(check { - val sentTransaction = it.items.first().getTransaction(fixture.sentryOptions.serializer) - assertNotNull(sentTransaction) { tx -> - val sentSpanIds = tx.spans.map { span -> span.spanId } - assertTrue(sentSpanIds.contains(span1.spanContext.spanId)) - assertFalse(sentSpanIds.contains(span2.spanContext.spanId)) - } - }, eq(null)) - } - @Test fun `when captureTransaction with attachments`() { val transaction = SentryTransaction(fixture.sentryTracer) diff --git a/sentry/src/test/java/io/sentry/SentryTracerTest.kt b/sentry/src/test/java/io/sentry/SentryTracerTest.kt index ea9471f040..7caa76ea26 100644 --- a/sentry/src/test/java/io/sentry/SentryTracerTest.kt +++ b/sentry/src/test/java/io/sentry/SentryTracerTest.kt @@ -387,6 +387,21 @@ class SentryTracerTest { }, anyOrNull()) } + @Test + fun `finishing unfinished spans with the transaction timestamp`() { + val transaction = fixture.getSut() + transaction.startChild("op") + transaction.startChild("op2") + transaction.finish(SpanStatus.INVALID_ARGUMENT) + verify(fixture.hub, times(1)).captureTransaction(check { + val timestamp = it.timestamp + assertEquals(2, it.spans.size) + assertEquals(timestamp, it.spans[0].timestamp) + assertEquals(SpanStatus.DEADLINE_EXCEEDED, it.spans[0].status) + assertEquals(SpanStatus.DEADLINE_EXCEEDED, it.spans[1].status) + }, anyOrNull()) + } + @Test fun `returns trace state`() { val transaction = fixture.getSut({