Enrich Transactions with Context Data

CHANGELOG.md

@@ -1,5 +1,7 @@
 # Unreleased
 
+* Fix: Enrich Transactions with Context Data (#1469)
+
 # 5.0.0-beta.3
 
 * Fix: handling immutable collections on SentryEvent and protocol objects (#1468)

sentry/src/main/java/io/sentry/OutboxSender.java

@@ -7,6 +7,8 @@
 import io.sentry.hints.Resettable;
 import io.sentry.hints.Retryable;
 import io.sentry.hints.SubmissionResult;
+import io.sentry.protocol.SentryId;
+import io.sentry.protocol.SentryTransaction;
 import io.sentry.util.CollectionUtils;
 import io.sentry.util.LogUtils;
 import io.sentry.util.Objects;
@@ -107,13 +109,13 @@ private void processEnvelope(final @NotNull SentryEnvelope envelope, final @Null
         SentryLevel.DEBUG,
         "Processing Envelope with %d item(s)",
         CollectionUtils.size(envelope.getItems()));
-    int items = 0;
+    int currentItem = 0;
 
     for (final SentryEnvelopeItem item : envelope.getItems()) {
-      items++;
+      currentItem++;
 
       if (item.getHeader() == null) {
-        logger.log(SentryLevel.ERROR, "Item %d has no header", items);
+        logger.log(SentryLevel.ERROR, "Item %d has no header", currentItem);
         continue;
       }
       if (SentryItemType.Event.equals(item.getHeader().getType())) {
@@ -122,30 +124,50 @@ private void processEnvelope(final @NotNull SentryEnvelope envelope, final @Null
                 new InputStreamReader(new ByteArrayInputStream(item.getData()), UTF_8))) {
           SentryEvent event = serializer.deserialize(eventReader, SentryEvent.class);
           if (event == null) {
-            logger.log(
-                SentryLevel.ERROR,
-                "Item %d of type %s returned null by the parser.",
-                items,
-                item.getHeader().getType());
+            logEnvelopeItemNull(item, currentItem);
           } else {
             if (envelope.getHeader().getEventId() != null
                 && !envelope.getHeader().getEventId().equals(event.getEventId())) {
-              logger.log(
-                  SentryLevel.ERROR,
-                  "Item %d of has a different event id (%s) to the envelope header (%s)",
-                  items,
-                  envelope.getHeader().getEventId(),
-                  event.getEventId());
+              logUnexpectedEventId(envelope, event.getEventId(), currentItem);
               continue;
             }
             hub.captureEvent(event, hint);
-            logger.log(SentryLevel.DEBUG, "Item %d is being captured.", items);
+            logItemCaptured(currentItem);
 
             if (!waitFlush(hint)) {
-              logger.log(
-                  SentryLevel.WARNING,
-                  "Timed out waiting for event submission: %s",
-                  event.getEventId());
+              logTimeout(event.getEventId());
+              break;
+            }
+          }
+        } catch (Exception e) {
+          logger.log(ERROR, "Item failed to process.", e);
+        }
+      } else if (SentryItemType.Transaction.equals(item.getHeader().getType())) {
+        try (final Reader reader =
+            new BufferedReader(
+                new InputStreamReader(new ByteArrayInputStream(item.getData()), UTF_8))) {
+
+          final SentryTransaction transaction =
+              serializer.deserialize(reader, SentryTransaction.class);
+          if (transaction == null) {
+            logEnvelopeItemNull(item, currentItem);
+          } else {
+            if (envelope.getHeader().getEventId() != null
+                && !envelope.getHeader().getEventId().equals(transaction.getEventId())) {
+              logUnexpectedEventId(envelope, transaction.getEventId(), currentItem);
+              continue;
+            }
+
+            if (transaction.getContexts().getTrace() != null) {
+              // Hint: Set sampled in order for the transaction not to be dropped, as this is a
+              // transient property.
+              transaction.getContexts().getTrace().setSampled(true);
+            }
+            hub.captureTransaction(transaction, hint);
+            logItemCaptured(currentItem);
+
+            if (!waitFlush(hint)) {
+              logTimeout(transaction.getEventId());
               break;
             }
           }
@@ -162,7 +184,7 @@ private void processEnvelope(final @NotNull SentryEnvelope envelope, final @Null
             SentryLevel.DEBUG,
             "%s item %d is being captured.",
             item.getHeader().getType().getItemType(),
-            items);
+            currentItem);
 
         if (!waitFlush(hint)) {
           logger.log(
@@ -180,7 +202,7 @@ private void processEnvelope(final @NotNull SentryEnvelope envelope, final @Null
           logger.log(
               SentryLevel.WARNING,
               "Envelope had a failed capture at item %d. No more items will be sent.",
-              items);
+              currentItem);
           break;
         }
       }
@@ -192,6 +214,32 @@ private void processEnvelope(final @NotNull SentryEnvelope envelope, final @Null
     }
   }
 
+  private void logEnvelopeItemNull(final @NotNull SentryEnvelopeItem item, int itemIndex) {
+    logger.log(
+        SentryLevel.ERROR,
+        "Item %d of type %s returned null by the parser.",
+        itemIndex,
+        item.getHeader().getType());
+  }
+
+  private void logUnexpectedEventId(
+      final @NotNull SentryEnvelope envelope, final @Nullable SentryId eventId, int itemIndex) {
+    logger.log(
+        SentryLevel.ERROR,
+        "Item %d of has a different event id (%s) to the envelope header (%s)",
+        itemIndex,
+        envelope.getHeader().getEventId(),
+        eventId);
+  }
+
+  private void logItemCaptured(int itemIndex) {
+    logger.log(SentryLevel.DEBUG, "Item %d is being captured.", itemIndex);
+  }
+
+  private void logTimeout(final @Nullable SentryId eventId) {
+    logger.log(SentryLevel.WARNING, "Timed out waiting for event id submission: %s", eventId);
+  }
+
   private boolean waitFlush(final @Nullable Object hint) {
     if (hint instanceof Flushable) {
       return ((Flushable) hint).waitFlush();

sentry/src/test/java/io/sentry/OutboxSenderTest.kt

@@ -5,11 +5,13 @@ import com.nhaarman.mockitokotlin2.argWhere
 import com.nhaarman.mockitokotlin2.eq
 import com.nhaarman.mockitokotlin2.mock
 import com.nhaarman.mockitokotlin2.never
+import com.nhaarman.mockitokotlin2.spy
 import com.nhaarman.mockitokotlin2.verify
 import com.nhaarman.mockitokotlin2.whenever
 import io.sentry.cache.EnvelopeCache
 import io.sentry.hints.Retryable
 import io.sentry.protocol.SentryId
+import io.sentry.protocol.SentryTransaction
 import java.io.File
 import java.io.FileNotFoundException
 import java.nio.file.Files
@@ -24,6 +26,7 @@ import kotlin.test.assertTrue
 class OutboxSenderTest {
     private class Fixture {
 
+        val options = mock<SentryOptions>()
         val hub = mock<IHub>()
         var envelopeReader = mock<IEnvelopeReader>()
         val serializer = mock<ISerializer>()
@@ -73,6 +76,42 @@ class OutboxSenderTest {
         verify(fixture.logger, never()).log(eq(SentryLevel.ERROR), any<String>(), any())
     }
 
+    @Test
+    fun `when parser is EnvelopeReader and serializer return SentryTransaction, transaction captured, transactions sampled, file is deleted`() {
+        fixture.envelopeReader = EnvelopeReader()
+        whenever(fixture.options.maxSpans).thenReturn(1000)
+        whenever(fixture.hub.options).thenReturn(fixture.options)
+
+        val transactionContext = TransactionContext("fixture-name", "http")
+        transactionContext.description = "fixture-request"
+        transactionContext.status = SpanStatus.OK
+        transactionContext.setTag("fixture-tag", "fixture-value")
+
+        val sentryTracer = SentryTracer(transactionContext, fixture.hub)
+        val span = sentryTracer.startChild("child")
+        span.finish(SpanStatus.OK)
+        sentryTracer.finish()
+
+        val sentryTracerSpy = spy(sentryTracer)
+        whenever(sentryTracerSpy.eventId).thenReturn(SentryId("3367f5196c494acaae85bbbd535379ac"))
+
+        val expected = SentryTransaction(sentryTracerSpy)
+        whenever(fixture.serializer.deserialize(any(), eq(SentryTransaction::class.java))).thenReturn(expected)
+
+        val sut = fixture.getSut()
+        val path = getTempEnvelope(fileName = "envelope-transaction.txt")
+        assertTrue(File(path).exists())
+        sut.processEnvelopeFile(path, mock<Retryable>())
+
+        verify(fixture.hub).captureTransaction(eq(expected), any())
+        assertFalse(File(path).exists())
+        assertTrue(transactionContext.sampled ?: false)
+
+        // Additionally make sure we have no errors logged
+        verify(fixture.logger, never()).log(eq(SentryLevel.ERROR), any(), any<Any>())
+        verify(fixture.logger, never()).log(eq(SentryLevel.ERROR), any<String>(), any())
+    }
+
     @Test
     fun `when parser is EnvelopeReader and serializer returns SentryEnvelope, event captured, file is deleted `() {
         fixture.envelopeReader = EnvelopeReader()

sentry/src/test/resources/envelope-transaction.txt

@@ -0,0 +1,3 @@
+{"event_id":"3367f5196c494acaae85bbbd535379ac"}
+{"type":"transaction","length":640,"content_type":"application/json"}
+{"transaction":"a-transaction","type":"transaction","start_timestamp":"2020-10-23T10:24:01.791Z","timestamp":"2020-10-23T10:24:02.791Z","event_id":"3367f5196c494acaae85bbbd535379ac","contexts":{"trace":{"trace_id":"b156a475de54423d9c1571df97ec7eb6","span_id":"0a53026963414893","op":"http","status":"ok"},"custom":{"some-key":"some-value"}},"spans":[{"start_timestamp":"2021-03-05T08:51:12.838Z","timestamp":"2021-03-05T08:51:12.949Z","trace_id":"2b099185293344a5bfdd7ad89ebf9416","span_id":"5b95c29a5ded4281","parent_span_id":"a3b2d1d58b344b07","op":"PersonService.create","description":"desc","status":"aborted","tags":{"name":"value"}}]}