From 4d5944d9c43b015c1e6b991c1b3d89fd4e507065 Mon Sep 17 00:00:00 2001 From: Daniel Griesser Date: Fri, 6 Mar 2020 09:26:33 +0100 Subject: [PATCH 1/7] feat: Use performance api --- packages/apm/src/integrations/tracing.ts | 126 +++++++++++++++++++++++ packages/apm/src/span.ts | 2 +- 2 files changed, 127 insertions(+), 1 deletion(-) diff --git a/packages/apm/src/integrations/tracing.ts b/packages/apm/src/integrations/tracing.ts index 7248649fa46b..026f11f9610d 100644 --- a/packages/apm/src/integrations/tracing.ts +++ b/packages/apm/src/integrations/tracing.ts @@ -138,6 +138,9 @@ export class Tracing implements Integration { * @param _options TracingOptions */ public constructor(_options?: Partial) { + if (global.performance) { + global.performance.mark('sentry-tracing-init'); + } const defaults = { discardBackgroundSpans: true, idleTimeout: 500, @@ -236,6 +239,7 @@ export class Tracing implements Integration { event.timestamp - event.start_timestamp < 0); if (Tracing.options.maxTransactionDuration !== 0 && event.type === 'transaction' && isOutdatedTransaction) { + logger.log('[Tracing] Discarded transaction since it maxed out maxTransactionDuration'); return null; } } @@ -336,11 +340,133 @@ export class Tracing implements Integration { const active = Tracing._activeTransaction as SpanClass; if (active) { logger.log('[Tracing] finishIdleTransaction', active.transaction); + Tracing._addPerformance(active); // true = use timestamp of last span active.finish(true); } } + /** Adds spans for performamce TODO */ + private static _addPerformance(transactionSpan: SpanClass): void { + // tslint:disable-next-line: completed-docs + function addSpan(span: SpanClass): void { + // tslint:disable-next-line: no-non-null-assertion + transactionSpan.spanRecorder!.finishSpan(span); + } + + // tslint:disable-next-line: completed-docs + function addPerformanceNavigationTiming(parent: SpanClass, entry: any, op: string): void { + const span = parent.child({ + op, + }); + // tslint:disable: no-unsafe-any + span.startTimestamp = parent.startTimestamp + (entry[`${op}Start`] as number) / 1000; + span.timestamp = parent.startTimestamp + (entry[`${op}End`] as number) / 1000; + // tslint:enable: no-unsafe-any + addSpan(span); + } + + // tslint:disable-next-line: completed-docs + function addRequest(parent: SpanClass, entry: any): void { + const request = parent.child({ + op: 'request', + }); + // tslint:disable: no-unsafe-any + request.startTimestamp = parent.startTimestamp + (entry.requestStart as number) / 1000; + request.timestamp = parent.startTimestamp + (entry.responseEnd as number) / 1000; + // tslint:enable: no-unsafe-any + addSpan(request); + const response = parent.child({ + op: 'response', + }); + // tslint:disable: no-unsafe-any + response.startTimestamp = parent.startTimestamp + (entry.responseStart as number) / 1000; + response.timestamp = parent.startTimestamp + (entry.responseEnd as number) / 1000; + // tslint:enable: no-unsafe-any + addSpan(response); + } + + let entryScriptSrc: string | undefined; + + if (global.document) { + // tslint:disable-next-line: prefer-for-of + for (let i = 0; i < document.scripts.length; i++) { + if (document.scripts[i].getAttribute('data-entry') === 'true') { + entryScriptSrc = document.scripts[i].src; + break; + } + } + } + + let entryScriptStartEndTime: number | undefined; + let tracingInitMarkStartTime: number | undefined; + + // tslint:disable: no-unsafe-any + performance.getEntries().forEach((entry: any) => { + switch (entry.entryType) { + case 'navigation': + addPerformanceNavigationTiming(transactionSpan, entry, 'unloadEvent'); + addPerformanceNavigationTiming(transactionSpan, entry, 'domContentLoadedEvent'); + addPerformanceNavigationTiming(transactionSpan, entry, 'loadEvent'); + addPerformanceNavigationTiming(transactionSpan, entry, 'connect'); + addPerformanceNavigationTiming(transactionSpan, entry, 'domainLookup'); + addRequest(transactionSpan, entry); + break; + case 'mark': + case 'paint': + case 'measure': + const mark = transactionSpan.child({ + description: entry.name, + op: 'mark', + }); + mark.startTimestamp = transactionSpan.startTimestamp + (entry.startTime as number) / 1000; + mark.timestamp = mark.startTimestamp + (entry.duration as number) / 1000; + if (tracingInitMarkStartTime === undefined && entry.name === 'sentry-tracing-init') { + tracingInitMarkStartTime = mark.startTimestamp; + } + addSpan(mark); + break; + case 'resource': + const resourceName = entry.name.replace(window.location.origin, ''); + if (entry.initiatorType === 'xmlhttprequest' || entry.initiatorType === 'fetch') { + // We need to update existing spans with new timing info + // tslint:disable-next-line: no-non-null-assertion + transactionSpan.spanRecorder!.finishedSpans.map((finishedSpan: SpanClass) => { + if (finishedSpan.description && finishedSpan.description.indexOf(resourceName) !== -1) { + finishedSpan.startTimestamp = transactionSpan.startTimestamp + (entry.startTime as number) / 1000; + finishedSpan.timestamp = finishedSpan.startTimestamp + (entry.duration as number) / 1000; + } + }); + } else { + const resource = transactionSpan.child({ + description: `${resourceName}`, + op: `resource.${entry.initiatorType}`, + }); + resource.startTimestamp = transactionSpan.startTimestamp + (entry.startTime as number) / 1000; + resource.timestamp = resource.startTimestamp + (entry.duration as number) / 1000; + // We remeber the entry script end time to calculate the difference to the first init mark + if (entryScriptStartEndTime === undefined && entryScriptSrc && entryScriptSrc.indexOf(resourceName) > -1) { + entryScriptStartEndTime = resource.timestamp; + } + addSpan(resource); + } + break; + default: + // Yo + } + }); + if (entryScriptStartEndTime !== undefined && tracingInitMarkStartTime !== undefined) { + const evaluation = transactionSpan.child({ + op: `script.evaluation`, + }); + evaluation.startTimestamp = entryScriptStartEndTime; + evaluation.timestamp = tracingInitMarkStartTime; + addSpan(evaluation); + } + + // tslint:enable: no-unsafe-any + } + /** * Sets the status of the current active transaction (if there is one) */ diff --git a/packages/apm/src/span.ts b/packages/apm/src/span.ts index f86b340161ff..f5ae63c2ed0c 100644 --- a/packages/apm/src/span.ts +++ b/packages/apm/src/span.ts @@ -108,7 +108,7 @@ export class Span implements SpanInterface, SpanContext { /** * Timestamp when the span was created. */ - public readonly startTimestamp: number = timestampWithMs(); + public startTimestamp: number = timestampWithMs(); /** * Internal start time tracked with a monotonic clock. From 8f28d7557e9c6563e8d76b83949f495bdc028935 Mon Sep 17 00:00:00 2001 From: Daniel Griesser Date: Fri, 6 Mar 2020 10:37:18 +0100 Subject: [PATCH 2/7] feat: Update ops & descriptions --- packages/apm/src/integrations/tracing.ts | 43 ++++++++++++++++++------ 1 file changed, 32 insertions(+), 11 deletions(-) diff --git a/packages/apm/src/integrations/tracing.ts b/packages/apm/src/integrations/tracing.ts index 026f11f9610d..b3daeda02e55 100644 --- a/packages/apm/src/integrations/tracing.ts +++ b/packages/apm/src/integrations/tracing.ts @@ -355,13 +355,14 @@ export class Tracing implements Integration { } // tslint:disable-next-line: completed-docs - function addPerformanceNavigationTiming(parent: SpanClass, entry: any, op: string): void { + function addPerformanceNavigationTiming(parent: SpanClass, entry: any, event: string): void { const span = parent.child({ - op, + description: event, + op: 'browser', }); // tslint:disable: no-unsafe-any - span.startTimestamp = parent.startTimestamp + (entry[`${op}Start`] as number) / 1000; - span.timestamp = parent.startTimestamp + (entry[`${op}End`] as number) / 1000; + span.startTimestamp = parent.startTimestamp + (entry[`${event}Start`] as number) / 1000; + span.timestamp = parent.startTimestamp + (entry[`${event}End`] as number) / 1000; // tslint:enable: no-unsafe-any addSpan(span); } @@ -369,7 +370,8 @@ export class Tracing implements Integration { // tslint:disable-next-line: completed-docs function addRequest(parent: SpanClass, entry: any): void { const request = parent.child({ - op: 'request', + description: 'request', + op: 'browser', }); // tslint:disable: no-unsafe-any request.startTimestamp = parent.startTimestamp + (entry.requestStart as number) / 1000; @@ -377,7 +379,8 @@ export class Tracing implements Integration { // tslint:enable: no-unsafe-any addSpan(request); const response = parent.child({ - op: 'response', + description: 'response', + op: 'browser', }); // tslint:disable: no-unsafe-any response.startTimestamp = parent.startTimestamp + (entry.responseStart as number) / 1000; @@ -439,8 +442,8 @@ export class Tracing implements Integration { }); } else { const resource = transactionSpan.child({ - description: `${resourceName}`, - op: `resource.${entry.initiatorType}`, + description: `${entry.initiatorType} ${resourceName}`, + op: `resource`, }); resource.startTimestamp = transactionSpan.startTimestamp + (entry.startTime as number) / 1000; resource.timestamp = resource.startTimestamp + (entry.duration as number) / 1000; @@ -455,9 +458,11 @@ export class Tracing implements Integration { // Yo } }); + if (entryScriptStartEndTime !== undefined && tracingInitMarkStartTime !== undefined) { const evaluation = transactionSpan.child({ - op: `script.evaluation`, + description: 'evaluation', + op: `script`, }); evaluation.startTimestamp = entryScriptStartEndTime; evaluation.timestamp = tracingInitMarkStartTime; @@ -508,9 +513,19 @@ export class Tracing implements Integration { if (spanContext && _getCurrentHub) { const hub = _getCurrentHub(); if (hub) { + const span = hub.startSpan(spanContext); + if (global.performance) { + const measureName = `#sentry-${name}${Tracing._currentIndex}`; + performance.measure(measureName); + const measure = performance.getEntriesByName(measureName).pop(); + if (measure) { + span.setData('offset', measure.duration / 1000); + } + performance.clearMeasures(measureName); + } Tracing._activities[Tracing._currentIndex] = { name, - span: hub.startSpan(spanContext), + span, }; } } else { @@ -550,7 +565,7 @@ export class Tracing implements Integration { if (activity) { logger.log(`[Tracing] popActivity ${activity.name}#${id}`); - const span = activity.span; + const span = activity.span as SpanClass; if (span) { if (spanData) { Object.keys(spanData).forEach((key: string) => { @@ -564,6 +579,12 @@ export class Tracing implements Integration { }); } span.finish(); + // If there is an offset in data, we need to shift timestamps towards it + if (span.data && typeof span.data.offset === 'number') { + span.startTimestamp += span.data.offset; + // tslint:disable-next-line: no-non-null-assertion + span.timestamp! += span.data.offset; + } } // tslint:disable-next-line: no-dynamic-delete delete Tracing._activities[id]; From 861bb37ef938373f8b90448e345e791d9bf64d1f Mon Sep 17 00:00:00 2001 From: Daniel Griesser Date: Fri, 6 Mar 2020 12:58:49 +0100 Subject: [PATCH 3/7] feat: Handle navigation changes correctly --- packages/apm/src/integrations/tracing.ts | 184 ++++++++++++++--------- 1 file changed, 116 insertions(+), 68 deletions(-) diff --git a/packages/apm/src/integrations/tracing.ts b/packages/apm/src/integrations/tracing.ts index b3daeda02e55..acc4d4ad336b 100644 --- a/packages/apm/src/integrations/tracing.ts +++ b/packages/apm/src/integrations/tracing.ts @@ -132,6 +132,8 @@ export class Tracing implements Integration { private readonly _emitOptionsWarning: boolean = false; + private static _performanceCursor: number = 0; + /** * Constructor for Tracing * @@ -299,6 +301,7 @@ export class Tracing implements Integration { ); Tracing._activeTransaction = span; + Tracing._addOffsetToSpan(`idleTransactionStarted-${Tracing._currentIndex}`, span as SpanClass); // We need to do this workaround here and not use configureScope // Reason being at the time we start the inital transaction we do not have a client bound on the hub yet @@ -340,14 +343,22 @@ export class Tracing implements Integration { const active = Tracing._activeTransaction as SpanClass; if (active) { logger.log('[Tracing] finishIdleTransaction', active.transaction); - Tracing._addPerformance(active); + Tracing._addPerformanceEntries(active); // true = use timestamp of last span active.finish(true); } } /** Adds spans for performamce TODO */ - private static _addPerformance(transactionSpan: SpanClass): void { + private static _addPerformanceEntries(transactionSpan: SpanClass): void { + let navigationOffset = 0; + if ( + transactionSpan.op === 'navigation' && + transactionSpan.data && + typeof transactionSpan.data.offset === 'number' + ) { + navigationOffset = transactionSpan.data.offset; + } // tslint:disable-next-line: completed-docs function addSpan(span: SpanClass): void { // tslint:disable-next-line: no-non-null-assertion @@ -361,8 +372,8 @@ export class Tracing implements Integration { op: 'browser', }); // tslint:disable: no-unsafe-any - span.startTimestamp = parent.startTimestamp + (entry[`${event}Start`] as number) / 1000; - span.timestamp = parent.startTimestamp + (entry[`${event}End`] as number) / 1000; + span.startTimestamp = parent.startTimestamp + Tracing._msToSec(entry[`${event}Start`] as number); + span.timestamp = parent.startTimestamp + Tracing._msToSec(entry[`${event}End`] as number); // tslint:enable: no-unsafe-any addSpan(span); } @@ -374,8 +385,8 @@ export class Tracing implements Integration { op: 'browser', }); // tslint:disable: no-unsafe-any - request.startTimestamp = parent.startTimestamp + (entry.requestStart as number) / 1000; - request.timestamp = parent.startTimestamp + (entry.responseEnd as number) / 1000; + request.startTimestamp = parent.startTimestamp + Tracing._msToSec(entry.requestStart as number); + request.timestamp = parent.startTimestamp + Tracing._msToSec(entry.responseEnd as number); // tslint:enable: no-unsafe-any addSpan(request); const response = parent.child({ @@ -383,8 +394,8 @@ export class Tracing implements Integration { op: 'browser', }); // tslint:disable: no-unsafe-any - response.startTimestamp = parent.startTimestamp + (entry.responseStart as number) / 1000; - response.timestamp = parent.startTimestamp + (entry.responseEnd as number) / 1000; + response.startTimestamp = parent.startTimestamp + Tracing._msToSec(entry.responseStart as number); + response.timestamp = parent.startTimestamp + Tracing._msToSec(entry.responseEnd as number); // tslint:enable: no-unsafe-any addSpan(response); } @@ -394,6 +405,9 @@ export class Tracing implements Integration { if (global.document) { // tslint:disable-next-line: prefer-for-of for (let i = 0; i < document.scripts.length; i++) { + // We go through all scripts on the page and look for 'data-entry' + // We remember the name and measure the time between this script finished loading and + // our mark 'sentry-tracing-init' if (document.scripts[i].getAttribute('data-entry') === 'true') { entryScriptSrc = document.scripts[i].src; break; @@ -405,59 +419,69 @@ export class Tracing implements Integration { let tracingInitMarkStartTime: number | undefined; // tslint:disable: no-unsafe-any - performance.getEntries().forEach((entry: any) => { - switch (entry.entryType) { - case 'navigation': - addPerformanceNavigationTiming(transactionSpan, entry, 'unloadEvent'); - addPerformanceNavigationTiming(transactionSpan, entry, 'domContentLoadedEvent'); - addPerformanceNavigationTiming(transactionSpan, entry, 'loadEvent'); - addPerformanceNavigationTiming(transactionSpan, entry, 'connect'); - addPerformanceNavigationTiming(transactionSpan, entry, 'domainLookup'); - addRequest(transactionSpan, entry); - break; - case 'mark': - case 'paint': - case 'measure': - const mark = transactionSpan.child({ - description: entry.name, - op: 'mark', - }); - mark.startTimestamp = transactionSpan.startTimestamp + (entry.startTime as number) / 1000; - mark.timestamp = mark.startTimestamp + (entry.duration as number) / 1000; - if (tracingInitMarkStartTime === undefined && entry.name === 'sentry-tracing-init') { - tracingInitMarkStartTime = mark.startTimestamp; - } - addSpan(mark); - break; - case 'resource': - const resourceName = entry.name.replace(window.location.origin, ''); - if (entry.initiatorType === 'xmlhttprequest' || entry.initiatorType === 'fetch') { - // We need to update existing spans with new timing info - // tslint:disable-next-line: no-non-null-assertion - transactionSpan.spanRecorder!.finishedSpans.map((finishedSpan: SpanClass) => { - if (finishedSpan.description && finishedSpan.description.indexOf(resourceName) !== -1) { - finishedSpan.startTimestamp = transactionSpan.startTimestamp + (entry.startTime as number) / 1000; - finishedSpan.timestamp = finishedSpan.startTimestamp + (entry.duration as number) / 1000; - } - }); - } else { - const resource = transactionSpan.child({ - description: `${entry.initiatorType} ${resourceName}`, - op: `resource`, + performance + .getEntries() + .slice(Tracing._performanceCursor) + .forEach((entry: any) => { + const startTime = Tracing._msToSec(entry.startTime as number); + const duration = Tracing._msToSec(entry.duration as number); + + switch (entry.entryType) { + case 'navigation': + addPerformanceNavigationTiming(transactionSpan, entry, 'unloadEvent'); + addPerformanceNavigationTiming(transactionSpan, entry, 'domContentLoadedEvent'); + addPerformanceNavigationTiming(transactionSpan, entry, 'loadEvent'); + addPerformanceNavigationTiming(transactionSpan, entry, 'connect'); + addPerformanceNavigationTiming(transactionSpan, entry, 'domainLookup'); + addRequest(transactionSpan, entry); + break; + case 'mark': + case 'paint': + case 'measure': + const mark = transactionSpan.child({ + description: `${entry.entryType} ${entry.name}`, + op: 'mark', }); - resource.startTimestamp = transactionSpan.startTimestamp + (entry.startTime as number) / 1000; - resource.timestamp = resource.startTimestamp + (entry.duration as number) / 1000; - // We remeber the entry script end time to calculate the difference to the first init mark - if (entryScriptStartEndTime === undefined && entryScriptSrc && entryScriptSrc.indexOf(resourceName) > -1) { - entryScriptStartEndTime = resource.timestamp; + mark.startTimestamp = transactionSpan.startTimestamp + startTime - navigationOffset; + mark.timestamp = mark.startTimestamp + duration; + if (tracingInitMarkStartTime === undefined && entry.name === 'sentry-tracing-init') { + tracingInitMarkStartTime = mark.startTimestamp; } - addSpan(resource); - } - break; - default: - // Yo - } - }); + addSpan(mark); + break; + case 'resource': + const resourceName = entry.name.replace(window.location.origin, ''); + if (entry.initiatorType === 'xmlhttprequest' || entry.initiatorType === 'fetch') { + // We need to update existing spans with new timing info + // tslint:disable-next-line: no-non-null-assertion + transactionSpan.spanRecorder!.finishedSpans.map((finishedSpan: SpanClass) => { + if (finishedSpan.description && finishedSpan.description.indexOf(resourceName) !== -1) { + finishedSpan.startTimestamp = transactionSpan.startTimestamp + startTime - navigationOffset; + finishedSpan.timestamp = finishedSpan.startTimestamp + duration; + } + }); + } else { + const resource = transactionSpan.child({ + description: `${entry.initiatorType} ${resourceName}`, + op: `resource`, + }); + resource.startTimestamp = transactionSpan.startTimestamp + startTime - navigationOffset; + resource.timestamp = resource.startTimestamp + duration; + // We remeber the entry script end time to calculate the difference to the first init mark + if ( + entryScriptStartEndTime === undefined && + entryScriptSrc && + entryScriptSrc.indexOf(resourceName) > -1 + ) { + entryScriptStartEndTime = resource.timestamp; + } + addSpan(resource); + } + break; + default: + // Yo + } + }); if (entryScriptStartEndTime !== undefined && tracingInitMarkStartTime !== undefined) { const evaluation = transactionSpan.child({ @@ -468,6 +492,12 @@ export class Tracing implements Integration { evaluation.timestamp = tracingInitMarkStartTime; addSpan(evaluation); } + if (global.performance) { + performance.clearMarks(); + performance.clearMeasures(); + performance.clearResourceTimings(); + Tracing._performanceCursor = Math.max(performance.getEntries().length - 1, 0); + } // tslint:enable: no-unsafe-any } @@ -483,6 +513,32 @@ export class Tracing implements Integration { } } + /** + * Adds offset to the span + * + * @param measureName name of the performance measure + * @param span Span to add data.offset to + */ + private static _addOffsetToSpan(measureName: string, span: SpanClass): void { + if (global.performance) { + const name = `#sentry-${measureName}`; + performance.measure(name); + const measure = performance.getEntriesByName(name).pop(); + if (measure) { + span.setData('offset', Tracing._msToSec(measure.duration)); + } + performance.clearMeasures(name); + } + } + + /** + * Converys ms time to s with ms precison + * @param time time in ms + */ + private static _msToSec(time: number): number { + return time / 1000; + } + /** * Starts tracking for a specifc activity * @@ -514,15 +570,7 @@ export class Tracing implements Integration { const hub = _getCurrentHub(); if (hub) { const span = hub.startSpan(spanContext); - if (global.performance) { - const measureName = `#sentry-${name}${Tracing._currentIndex}`; - performance.measure(measureName); - const measure = performance.getEntriesByName(measureName).pop(); - if (measure) { - span.setData('offset', measure.duration / 1000); - } - performance.clearMeasures(measureName); - } + Tracing._addOffsetToSpan(`${name}${Tracing._currentIndex}`, span as SpanClass); Tracing._activities[Tracing._currentIndex] = { name, span, From e29e6ff1914892fd34398e8c32e5002886ddfa99 Mon Sep 17 00:00:00 2001 From: Daniel Griesser Date: Fri, 6 Mar 2020 13:11:24 +0100 Subject: [PATCH 4/7] chore: Code comments --- CHANGELOG.md | 2 ++ packages/apm/src/integrations/tracing.ts | 8 +++++++- 2 files changed, 9 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index d5d9ecdae634..10c8dd712c88 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,8 @@ - "You miss 100 percent of the chances you don't take. — Wayne Gretzky" — Michael Scott +- [apm] feat: Make use of the `performance` browser API to provide better instrumentation (#2474) + ## 5.13.2 - [apm] feat: Add `discardBackgroundSpans` to discard background spans by default diff --git a/packages/apm/src/integrations/tracing.ts b/packages/apm/src/integrations/tracing.ts index acc4d4ad336b..1586cc71a583 100644 --- a/packages/apm/src/integrations/tracing.ts +++ b/packages/apm/src/integrations/tracing.ts @@ -349,7 +349,13 @@ export class Tracing implements Integration { } } - /** Adds spans for performamce TODO */ + /** + * This uses `performance.getEntries()` to add additional spans to the active transaction. + * Also, we update our timings since we consider the timings in this API to be more correct than our manual + * measurements. + * + * @param transactionSpan The transaction span + */ private static _addPerformanceEntries(transactionSpan: SpanClass): void { let navigationOffset = 0; if ( From 789ee31f315a3526b3c071cc4e00892932c9cdb2 Mon Sep 17 00:00:00 2001 From: Daniel Griesser Date: Mon, 9 Mar 2020 11:01:20 +0100 Subject: [PATCH 5/7] Apply suggestions from code review Co-Authored-By: Rodolfo Carvalho --- packages/apm/src/integrations/tracing.ts | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/packages/apm/src/integrations/tracing.ts b/packages/apm/src/integrations/tracing.ts index 1586cc71a583..1753820a7146 100644 --- a/packages/apm/src/integrations/tracing.ts +++ b/packages/apm/src/integrations/tracing.ts @@ -473,7 +473,7 @@ export class Tracing implements Integration { }); resource.startTimestamp = transactionSpan.startTimestamp + startTime - navigationOffset; resource.timestamp = resource.startTimestamp + duration; - // We remeber the entry script end time to calculate the difference to the first init mark + // We remember the entry script end time to calculate the difference to the first init mark if ( entryScriptStartEndTime === undefined && entryScriptSrc && @@ -485,7 +485,7 @@ export class Tracing implements Integration { } break; default: - // Yo + // Ignore other entry types. } }); @@ -538,7 +538,7 @@ export class Tracing implements Integration { } /** - * Converys ms time to s with ms precison + * Converts from milliseconds to seconds * @param time time in ms */ private static _msToSec(time: number): number { From eb55285c3a7c52f2e33358d54ce51afb5842ed5f Mon Sep 17 00:00:00 2001 From: Daniel Griesser Date: Mon, 9 Mar 2020 11:15:38 +0100 Subject: [PATCH 6/7] chore: CodeReview --- packages/apm/src/integrations/tracing.ts | 57 ++++++++++-------------- 1 file changed, 24 insertions(+), 33 deletions(-) diff --git a/packages/apm/src/integrations/tracing.ts b/packages/apm/src/integrations/tracing.ts index 1753820a7146..dee82682e32d 100644 --- a/packages/apm/src/integrations/tracing.ts +++ b/packages/apm/src/integrations/tracing.ts @@ -367,42 +367,37 @@ export class Tracing implements Integration { } // tslint:disable-next-line: completed-docs function addSpan(span: SpanClass): void { - // tslint:disable-next-line: no-non-null-assertion - transactionSpan.spanRecorder!.finishSpan(span); + if (transactionSpan.spanRecorder) { + transactionSpan.spanRecorder.finishSpan(span); + } } // tslint:disable-next-line: completed-docs - function addPerformanceNavigationTiming(parent: SpanClass, entry: any, event: string): void { + function addPerformanceNavigationTiming(parent: SpanClass, entry: { [key: string]: number }, event: string): void { const span = parent.child({ description: event, op: 'browser', }); - // tslint:disable: no-unsafe-any - span.startTimestamp = parent.startTimestamp + Tracing._msToSec(entry[`${event}Start`] as number); - span.timestamp = parent.startTimestamp + Tracing._msToSec(entry[`${event}End`] as number); - // tslint:enable: no-unsafe-any + span.startTimestamp = parent.startTimestamp + Tracing._msToSec(entry[`${event}Start`]); + span.timestamp = parent.startTimestamp + Tracing._msToSec(entry[`${event}End`]); addSpan(span); } // tslint:disable-next-line: completed-docs - function addRequest(parent: SpanClass, entry: any): void { + function addRequest(parent: SpanClass, entry: { [key: string]: number }): void { const request = parent.child({ description: 'request', op: 'browser', }); - // tslint:disable: no-unsafe-any - request.startTimestamp = parent.startTimestamp + Tracing._msToSec(entry.requestStart as number); - request.timestamp = parent.startTimestamp + Tracing._msToSec(entry.responseEnd as number); - // tslint:enable: no-unsafe-any + request.startTimestamp = parent.startTimestamp + Tracing._msToSec(entry.requestStart); + request.timestamp = parent.startTimestamp + Tracing._msToSec(entry.responseEnd); addSpan(request); const response = parent.child({ description: 'response', op: 'browser', }); - // tslint:disable: no-unsafe-any - response.startTimestamp = parent.startTimestamp + Tracing._msToSec(entry.responseStart as number); - response.timestamp = parent.startTimestamp + Tracing._msToSec(entry.responseEnd as number); - // tslint:enable: no-unsafe-any + response.startTimestamp = parent.startTimestamp + Tracing._msToSec(entry.responseStart); + response.timestamp = parent.startTimestamp + Tracing._msToSec(entry.responseEnd); addSpan(response); } @@ -414,7 +409,7 @@ export class Tracing implements Integration { // We go through all scripts on the page and look for 'data-entry' // We remember the name and measure the time between this script finished loading and // our mark 'sentry-tracing-init' - if (document.scripts[i].getAttribute('data-entry') === 'true') { + if (document.scripts[i].dataset.entry === 'true') { entryScriptSrc = document.scripts[i].src; break; } @@ -459,13 +454,14 @@ export class Tracing implements Integration { const resourceName = entry.name.replace(window.location.origin, ''); if (entry.initiatorType === 'xmlhttprequest' || entry.initiatorType === 'fetch') { // We need to update existing spans with new timing info - // tslint:disable-next-line: no-non-null-assertion - transactionSpan.spanRecorder!.finishedSpans.map((finishedSpan: SpanClass) => { - if (finishedSpan.description && finishedSpan.description.indexOf(resourceName) !== -1) { - finishedSpan.startTimestamp = transactionSpan.startTimestamp + startTime - navigationOffset; - finishedSpan.timestamp = finishedSpan.startTimestamp + duration; - } - }); + if (transactionSpan.spanRecorder) { + transactionSpan.spanRecorder.finishedSpans.map((finishedSpan: SpanClass) => { + if (finishedSpan.description && finishedSpan.description.indexOf(resourceName) !== -1) { + finishedSpan.startTimestamp = transactionSpan.startTimestamp + startTime - navigationOffset; + finishedSpan.timestamp = finishedSpan.startTimestamp + duration; + } + }); + } } else { const resource = transactionSpan.child({ description: `${entry.initiatorType} ${resourceName}`, @@ -474,18 +470,14 @@ export class Tracing implements Integration { resource.startTimestamp = transactionSpan.startTimestamp + startTime - navigationOffset; resource.timestamp = resource.startTimestamp + duration; // We remember the entry script end time to calculate the difference to the first init mark - if ( - entryScriptStartEndTime === undefined && - entryScriptSrc && - entryScriptSrc.indexOf(resourceName) > -1 - ) { + if (entryScriptStartEndTime === undefined && (entryScriptSrc || '').includes(resourceName)) { entryScriptStartEndTime = resource.timestamp; } addSpan(resource); } break; default: - // Ignore other entry types. + // Ignore other entry types. } }); @@ -634,10 +626,9 @@ export class Tracing implements Integration { } span.finish(); // If there is an offset in data, we need to shift timestamps towards it - if (span.data && typeof span.data.offset === 'number') { + if (span.data && typeof span.data.offset === 'number' && typeof span.timestamp === 'number') { span.startTimestamp += span.data.offset; - // tslint:disable-next-line: no-non-null-assertion - span.timestamp! += span.data.offset; + span.timestamp += span.data.offset; } } // tslint:disable-next-line: no-dynamic-delete From 4f78e543451932276a1fea4c72a1ad87c7a2e0b1 Mon Sep 17 00:00:00 2001 From: Daniel Griesser Date: Mon, 9 Mar 2020 11:40:20 +0100 Subject: [PATCH 7/7] ref: Check for performance API --- packages/apm/src/integrations/tracing.ts | 17 +++++++++++------ 1 file changed, 11 insertions(+), 6 deletions(-) diff --git a/packages/apm/src/integrations/tracing.ts b/packages/apm/src/integrations/tracing.ts index dee82682e32d..bec5ef4178b3 100644 --- a/packages/apm/src/integrations/tracing.ts +++ b/packages/apm/src/integrations/tracing.ts @@ -357,6 +357,11 @@ export class Tracing implements Integration { * @param transactionSpan The transaction span */ private static _addPerformanceEntries(transactionSpan: SpanClass): void { + if (!global.performance) { + // Gatekeeper if performance API not available + return; + } + logger.log('[Tracing] Adding & adjusting spans using Performance API'); let navigationOffset = 0; if ( transactionSpan.op === 'navigation' && @@ -490,12 +495,12 @@ export class Tracing implements Integration { evaluation.timestamp = tracingInitMarkStartTime; addSpan(evaluation); } - if (global.performance) { - performance.clearMarks(); - performance.clearMeasures(); - performance.clearResourceTimings(); - Tracing._performanceCursor = Math.max(performance.getEntries().length - 1, 0); - } + + logger.log('[Tracing] Clearing most performance marks'); + performance.clearMarks(); + performance.clearMeasures(); + performance.clearResourceTimings(); + Tracing._performanceCursor = Math.max(performance.getEntries().length - 1, 0); // tslint:enable: no-unsafe-any }