feat: Add autoPop parameter and add debug logs (getsentry#2459)

HazAT · kamilogorek · web-flow · commit bc5ee8f618c1 · 2020-02-28T12:40:08.000+01:00
* feat: Add autopop parameter, Add debug loggings

* fix: Breadcrumbs type

* fix: Breadcrumb types for transaction/events

* ref: Add typedoc

* ref: PushActivity options

* ref: Switch to DeadlineExceeded status

* ref: Allow 0 as autopop

* fix: Number check

* github plz

Co-authored-by: Kamil Ogórek &lt;kamil.ogorek@gmail.com&gt;
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -6,6 +6,8 @@
 - [node] ref: Drop Node v6, add Node v12 to test matrix, move all scripts to Node v12 (#2455)
 - [apm] fix: Use monotonic clock to compute durations (#2441)
 - [utils] ref: Prevent instantiating unnecessary Date objects in `timestampWithMs` (#2442)
+- [apm] feat: Add `options.autoPopAfter` parameter to `pushActivity` to prevent never-ending spans (#2459)
+- [browser] fix: Mark transactions as event.transaction in breadcrumbs correctly
 
 ## 5.12.5
 
diff --git a/packages/apm/src/integrations/tracing.ts b/packages/apm/src/integrations/tracing.ts
@@ -162,9 +162,9 @@ export class Tracing implements Integration {
 
     if (this._emitOptionsWarning) {
       logger.warn(
-        'Sentry: You need to define `tracingOrigins` in the options. Set an array of urls or patterns to trace.',
+        '[Tracing] You need to define `tracingOrigins` in the options. Set an array of urls or patterns to trace.',
       );
-      logger.warn(`Sentry: We added a reasonable default for you: ${defaultTracingOrigins}`);
+      logger.warn(`[Tracing] We added a reasonable default for you: ${defaultTracingOrigins}`);
     }
 
     if (!Tracing._isEnabled()) {
@@ -255,6 +255,8 @@ export class Tracing implements Integration {
     // b) A activity wasn't popped correctly and therefore the transaction is stalling
     Tracing.finishIdleTransaction();
 
+    logger.log('[Tracing] startIdleTransaction, name:', name);
+
     const _getCurrentHub = Tracing._getCurrentHub;
     if (!_getCurrentHub) {
       return undefined;
@@ -296,6 +298,7 @@ export class Tracing implements Integration {
    * @deprecated
    */
   public static updateTransactionName(name: string): void {
+    logger.log('[Tracing] DEPRECATED, use Sentry.configureScope => scope.setTransaction instead', name);
     const _getCurrentHub = Tracing._getCurrentHub;
     if (_getCurrentHub) {
       const hub = _getCurrentHub();
@@ -313,6 +316,7 @@ export class Tracing implements Integration {
   public static finishIdleTransaction(): void {
     const active = Tracing._activeTransaction as SpanClass;
     if (active) {
+      logger.log('[Tracing] finishIdleTransaction', active.transaction);
       // true = use timestamp of last span
       active.finish(true);
     }
@@ -324,14 +328,25 @@ export class Tracing implements Integration {
   public static setTransactionStatus(status: SpanStatus): void {
     const active = Tracing._activeTransaction;
     if (active) {
+      logger.log('[Tracing] setTransactionStatus', status);
       active.setStatus(status);
     }
   }
 
   /**
    * Starts tracking for a specifc activity
+   *
+   * @param name Name of the activity, can be any string (Only used internally to identify the activity)
+   * @param spanContext If provided a Span with the SpanContext will be created.
+   * @param options _autoPopAfter_ | Time in ms, if provided the activity will be popped automatically after this timeout. This can be helpful in cases where you cannot gurantee your application knows the state and calls `popActivity` for sure.
    */
-  public static pushActivity(name: string, spanContext?: SpanContext): number {
+  public static pushActivity(
+    name: string,
+    spanContext?: SpanContext,
+    options?: {
+      autoPopAfter?: number;
+    },
+  ): number {
     if (!Tracing._isEnabled()) {
       // Tracing is not enabled
       return 0;
@@ -355,6 +370,18 @@ export class Tracing implements Integration {
       };
     }
 
+    logger.log(`[Tracing] pushActivity: ${name}#${Tracing._currentIndex}`);
+    logger.log('[Tracing] activies count', Object.keys(Tracing._activities).length);
+    if (options && typeof options.autoPopAfter === 'number') {
+      logger.log(`[Tracing] auto pop of: ${name}#${Tracing._currentIndex} in ${options.autoPopAfter}ms`);
+      const index = Tracing._currentIndex;
+      setTimeout(() => {
+        Tracing.popActivity(index, {
+          autoPop: true,
+          status: SpanStatus.DeadlineExceeded,
+        });
+      }, options.autoPopAfter);
+    }
     return Tracing._currentIndex++;
   }
 
@@ -368,7 +395,9 @@ export class Tracing implements Integration {
     }
 
     const activity = Tracing._activities[id];
+
     if (activity) {
+      logger.log(`[Tracing] popActivity ${activity.name}#${id}`);
       const span = activity.span;
       if (span) {
         if (spanData) {
@@ -377,6 +406,9 @@ export class Tracing implements Integration {
             if (key === 'status_code') {
               span.setHttpStatus(spanData[key] as number);
             }
+            if (key === 'status') {
+              span.setStatus(spanData[key] as SpanStatus);
+            }
           });
         }
         span.finish();
@@ -388,8 +420,11 @@ export class Tracing implements Integration {
     const count = Object.keys(Tracing._activities).length;
     clearTimeout(Tracing._debounce);
 
+    logger.log('[Tracing] activies count', count);
+
     if (count === 0) {
       const timeout = Tracing.options && Tracing.options.idleTimeout;
+      logger.log(`[Tracing] Flushing Transaction in ${timeout}ms`);
       Tracing._debounce = (setTimeout(() => {
         Tracing.finishIdleTransaction();
       }, timeout) as any) as number;
diff --git a/packages/browser/src/integrations/breadcrumbs.ts b/packages/browser/src/integrations/breadcrumbs.ts
@@ -317,7 +317,7 @@ function addSentryBreadcrumb(serializedData: string): void {
     const event = JSON.parse(serializedData);
     getCurrentHub().addBreadcrumb(
       {
-        category: `sentry.${event.transaction ? 'transaction' : 'event'}`,
+        category: `sentry.${event.type === 'transaction' ? 'transaction' : 'event'}`,
         event_id: event.event_id,
         level: event.level || Severity.fromString('error'),
         message: getEventDescription(event),
diff --git a/packages/browser/test/integration/suites/breadcrumbs.js b/packages/browser/test/integration/suites/breadcrumbs.js
@@ -121,7 +121,7 @@ describe("breadcrumbs", function() {
 
   it(
     optional(
-      "should transform XMLHttpRequests with transactions to the Sentry store endpoint as sentry.transaction type breadcrumb",
+      "should transform XMLHttpRequests with transactions type to the Sentry store endpoint as sentry.transaction type breadcrumb",
       IS_LOADER
     ),
     function() {
@@ -137,7 +137,7 @@ describe("breadcrumbs", function() {
         var xhr = new XMLHttpRequest();
         xhr.open("POST", store);
         xhr.send(
-          '{"message":"someMessage","transaction":"wat","level":"warning"}'
+          '{"message":"someMessage","transaction":"wat","level":"warning", "type": "transaction"}'
         );
         waitForXHR(xhr, function() {
           Sentry.captureMessage("test");
@@ -156,6 +156,43 @@ describe("breadcrumbs", function() {
     }
   );
 
+  it(
+    optional(
+      "should not transform XMLHttpRequests with transactions attribute to the Sentry store endpoint as sentry.transaction type breadcrumb",
+      IS_LOADER
+    ),
+    function() {
+      return runInSandbox(sandbox, { manual: true }, function() {
+        var store =
+          document.location.protocol +
+          "//" +
+          document.location.hostname +
+          (document.location.port ? ":" + document.location.port : "") +
+          "/api/1/store/" +
+          "?sentry_key=1337";
+
+        var xhr = new XMLHttpRequest();
+        xhr.open("POST", store);
+        xhr.send(
+          '{"message":"someMessage","transaction":"wat","level":"warning"}'
+        );
+        waitForXHR(xhr, function() {
+          Sentry.captureMessage("test");
+          window.finalizeManualTest();
+        });
+      }).then(function(summary) {
+        // The async loader doesn't wrap XHR
+        if (IS_LOADER) {
+          return;
+        }
+        assert.equal(summary.breadcrumbs.length, 1);
+        assert.equal(summary.breadcrumbs[0].category, "sentry.event");
+        assert.equal(summary.breadcrumbs[0].level, "warning");
+        assert.equal(summary.breadcrumbs[0].message, "someMessage");
+      });
+    }
+  );
+
   it("should record a fetch request", function() {
     return runInSandbox(sandbox, { manual: true }, function() {
       fetch("/base/subjects/example.json", {

Original file line number	Diff line number	Diff line change
`@@ -317,7 +317,7 @@ function addSentryBreadcrumb(serializedData: string): void {`
`317`	`317`	`const event = JSON.parse(serializedData);`
`318`	`318`	`getCurrentHub().addBreadcrumb(`
`319`	`319`	`{`
`320`		- category: `sentry.${event.transaction ? 'transaction' : 'event'}`,
	`320`	+ category: `sentry.${event.type === 'transaction' ? 'transaction' : 'event'}`,
`321`	`321`	`event_id: event.event_id,`
`322`	`322`	`level: event.level \|\| Severity.fromString('error'),`
`323`	`323`	`message: getEventDescription(event),`