diff --git a/packages/rum-core/src/bootstrap.js b/packages/rum-core/src/bootstrap.js index a3b448c83..573e0ce63 100644 --- a/packages/rum-core/src/bootstrap.js +++ b/packages/rum-core/src/bootstrap.js @@ -23,7 +23,7 @@ * */ -import { isPlatformSupported, isBrowser } from './common/utils' +import { isPlatformSupported, isBrowser, now } from './common/utils' import { patchAll } from './common/patching' import { state } from './state' @@ -32,6 +32,7 @@ export function bootstrap() { if (isPlatformSupported()) { patchAll() bootstrapPerf() + state.bootstrapTime = now() enabled = true } else if (isBrowser) { /** diff --git a/packages/rum-core/src/common/patching/index.js b/packages/rum-core/src/common/patching/index.js index bc33e6b34..e639cdd18 100644 --- a/packages/rum-core/src/common/patching/index.js +++ b/packages/rum-core/src/common/patching/index.js @@ -28,12 +28,11 @@ import { patchFetch } from './fetch-patch' import { patchHistory } from './history-patch' import { patchEventTarget } from './event-target-patch' import EventHandler from '../event-handler' - import { HISTORY, FETCH, XMLHTTPREQUEST, EVENT_TARGET } from '../constants' const patchEventHandler = new EventHandler() - let alreadyPatched = false + function patchAll() { if (!alreadyPatched) { alreadyPatched = true @@ -46,7 +45,6 @@ function patchAll() { patchHistory(function(event, task) { patchEventHandler.send(HISTORY, [event, task]) }) - patchEventTarget(function(event, task) { patchEventHandler.send(EVENT_TARGET, [event, task]) }) diff --git a/packages/rum-core/src/performance-monitoring/capture-navigation.js b/packages/rum-core/src/performance-monitoring/capture-navigation.js index 0d96eb4e6..bdf8e63f8 100644 --- a/packages/rum-core/src/performance-monitoring/capture-navigation.js +++ b/packages/rum-core/src/performance-monitoring/capture-navigation.js @@ -37,6 +37,7 @@ import { PERF, isPerfTimelineSupported } from '../common/utils' +import { state } from '../state' /** * Navigation Timing Spans @@ -119,60 +120,57 @@ function createResourceTimingSpan(resourceTimingEntry) { return span } -function createResourceTimingSpans(entries, filterUrls, trStart, trEnd) { +/** + * Checks if the span is already captured via XHR/Fetch patch by + * comparing the given resource startTime(fetchStart) aganist the + * patch code execution time. + */ +function isCapturedByPatching(resourceStartTime, requestPatchTime) { + return requestPatchTime != null && resourceStartTime > requestPatchTime +} + +/** + * Check if the given url matches APM Server's Intake + * API endpoint and ignore it from Spans + */ +function isIntakeAPIEndpoint(url) { + return /intake\/v\d+\/rum\/events/.test(url) +} + +function createResourceTimingSpans(entries, requestPatchTime, trStart, trEnd) { const spans = [] for (let i = 0; i < entries.length; i++) { - let { initiatorType, name, startTime, responseEnd } = entries[i] + const { initiatorType, name, startTime, responseEnd } = entries[i] /** - * Skipping the timing information of API calls because of auto patching XHR and Fetch + * Skip span creation if initiatorType is other than known types specified as part of RESOURCE_INITIATOR_TYPES + * The reason being, there are other types like embed, video, audio, navigation etc + * + * Check the below webplatform test to know more + * https://github.com/web-platform-tests/wpt/blob/b0020d5df18998609b38786878f7a0b92cc680aa/resource-timing/resource_initiator_types.html#L93 */ if ( - initiatorType === 'xmlhttprequest' || - initiatorType === 'fetch' || - !name + RESOURCE_INITIATOR_TYPES.indexOf(initiatorType) === -1 || + name == null ) { continue } + /** - * Create spans for all known resource initiator types + * Create Spans for API calls (XHR, Fetch) only if its not captured by the patch + * + * This would happen if our agent is downlaoded asyncrhonously and page does + * API requests before the agent patches the required modules. */ - if (RESOURCE_INITIATOR_TYPES.indexOf(initiatorType) !== -1) { - if (!shouldCreateSpan(startTime, responseEnd, trStart, trEnd)) { - continue - } - spans.push(createResourceTimingSpan(entries[i])) - } else { - /** - * Since IE does not support initiatorType in Resource timing entry, - * We have to manually filter the API calls from creating duplicate Spans - * - * Skip span creation if initiatorType is other than known types specified as part of RESOURCE_INITIATOR_TYPES - * The reason being, there are other types like embed, video, audio, navigation etc - * - * Check the below webplatform test to know more - * https://github.com/web-platform-tests/wpt/blob/b0020d5df18998609b38786878f7a0b92cc680aa/resource-timing/resource_initiator_types.html#L93 - */ - if (initiatorType != null) { - continue - } + if ( + (initiatorType === 'xmlhttprequest' || initiatorType === 'fetch') && + (isIntakeAPIEndpoint(name) || + isCapturedByPatching(startTime, requestPatchTime)) + ) { + continue + } - let foundAjaxReq = false - for (let j = 0; j < filterUrls.length; j++) { - const idx = name.lastIndexOf(filterUrls[j]) - if (idx > -1 && idx === name.length - filterUrls[j].length) { - foundAjaxReq = true - break - } - } - /** - * Create span if its not an ajax request - */ - if ( - !foundAjaxReq && - shouldCreateSpan(startTime, responseEnd, trStart, trEnd) - ) { - spans.push(createResourceTimingSpan(entries[i])) - } + if (shouldCreateSpan(startTime, responseEnd, trStart, trEnd)) { + spans.push(createResourceTimingSpan(entries[i])) } } return spans @@ -200,18 +198,6 @@ function createUserTimingSpans(entries, trStart, trEnd) { return userTimingSpans } -function getApiSpanNames({ spans }) { - const apiCalls = [] - - for (let i = 0; i < spans.length; i++) { - const span = spans[i] - if (span.type === 'external' && span.subtype === 'http') { - apiCalls.push(span.name.split(' ')[1]) - } - } - return apiCalls -} - /** * Navigation timing marks are reported only for page-load transactions * @@ -312,7 +298,6 @@ function captureNavigation(transaction) { * for few extra spans than soft navigations which * happens on single page applications */ - if (transaction.type === PAGE_LOAD) { /** * Adjust custom marks properly to fit in the transaction timeframe @@ -356,11 +341,9 @@ function captureNavigation(transaction) { * Capture resource timing information as spans */ const resourceEntries = PERF.getEntriesByType(RESOURCE) - const apiCalls = getApiSpanNames(transaction) - createResourceTimingSpans( resourceEntries, - apiCalls, + state.bootstrapTime, trStart, trEnd ).forEach(span => transaction.spans.push(span)) diff --git a/packages/rum-core/src/performance-monitoring/performance-monitoring.js b/packages/rum-core/src/performance-monitoring/performance-monitoring.js index ded33772a..72b2ea5d4 100644 --- a/packages/rum-core/src/performance-monitoring/performance-monitoring.js +++ b/packages/rum-core/src/performance-monitoring/performance-monitoring.js @@ -27,8 +27,8 @@ import { checkSameOrigin, isDtHeaderValid, parseDtHeaderValue, - stripQueryStringFromUrl, - getDtHeaderValue + getDtHeaderValue, + stripQueryStringFromUrl } from '../common/utils' import Url from '../common/url' import { patchEventHandler } from '../common/patching' diff --git a/packages/rum-core/src/state.js b/packages/rum-core/src/state.js index b6047b935..4fe8b5329 100644 --- a/packages/rum-core/src/state.js +++ b/packages/rum-core/src/state.js @@ -24,7 +24,11 @@ */ const __DEV__ = process.env.NODE_ENV !== 'production' +const state = { + // Time when agent is bootstrapped and patching of modules happens + bootstrapTime: null, + // Time when the document is last backgrounded + lastHiddenStart: Number.MIN_SAFE_INTEGER +} -export { __DEV__ } - -export const state = {} +export { __DEV__, state } diff --git a/packages/rum-core/test/fixtures/navigation-timing-span-snapshot.js b/packages/rum-core/test/fixtures/navigation-timing-span-snapshot.js index 6b039b931..8df61d727 100644 --- a/packages/rum-core/test/fixtures/navigation-timing-span-snapshot.js +++ b/packages/rum-core/test/fixtures/navigation-timing-span-snapshot.js @@ -26,128 +26,149 @@ export default [ { name: 'http://beacon.test', - type: 'resource.beacon', - ended: true, + type: 'resource', + subtype: 'beacon', _end: 168.25, _start: 25.220000000000002 }, { name: 'http://testing.com', - type: 'resource.script', - ended: true, + type: 'resource', + subtype: 'script', _end: 168.25, _start: 25.220000000000002 }, { name: 'http://localhost:9876/base/node_modules/karma-jasmine/lib/boot.js', - type: 'resource.script', - ended: true, + type: 'resource', + subtype: 'script', _end: 172.8, _start: 25.385 }, { name: 'http://localhost:9876/base/node_modules/karma-jasmine/lib/adapter.js', - type: 'resource.script', - ended: true, + type: 'resource', + subtype: 'script', _end: 174.04500000000002, _start: 25.515000000000004 }, { name: 'http://localhost:9876/base/tmp/globals.js', - type: 'resource.script', - ended: true, + type: 'resource', + subtype: 'script', _end: 175.33, _start: 25.640000000000004 }, { name: 'http://localhost:9876/base/node_modules/elastic-apm-js-zone/dist/zone.js', - type: 'resource.script', - ended: true, + type: 'resource', + subtype: 'script', _end: 176.12000000000003, _start: 25.76 }, { name: 'http://localhost:9876/base/test/utils/polyfill.js', - type: 'resource.script', - ended: true, + type: 'resource', + subtype: 'script', _end: 176.865, _start: 25.880000000000003 }, { name: 'http://localhost:9876/base/test/common/apm-server.spec.js', - type: 'resource.script', - ended: true, + type: 'resource', + subtype: 'script', _end: 340.65500000000003, _start: 26.000000000000004 }, { name: 'http://localhost:9876/base/test/common/config-service.spec.js', - type: 'resource.script', - ended: true, + type: 'resource', + subtype: 'script', _end: 178.85000000000002, _start: 26.150000000000002 }, { name: 'http://localhost:9876/base/test/common/service-factory.spec.js', - type: 'resource.script', - ended: true, + type: 'resource', + subtype: 'script', _end: 180.935, _start: 26.285000000000004 }, { name: 'http://localhost:9876/base/test/common/utils.spec.js', - type: 'resource.script', - ended: true, + type: 'resource', + subtype: 'script', _end: 181.735, _start: 26.405 }, { name: 'http://localhost:9876/base/test/error-logging/error-logging.spec.js', - type: 'resource.script', - ended: true, + type: 'resource', + subtype: 'script', _end: 349.685, _start: 26.520000000000003 }, { name: 'http://localhost:9876/base/test/error-logging/stack-trace-service.spec.js', - type: 'resource.script', - ended: true, + type: 'resource', + subtype: 'script', _end: 350.44000000000005, _start: 26.635 }, { name: 'http://localhost:9876/base/test/performance-monitoring/performance-monitoring.spec.js', - type: 'resource.script', - ended: true, + type: 'resource', + subtype: 'script', _end: 351.72, _start: 26.755000000000003 }, { name: 'http://localhost:9876/base/test/performance-monitoring/transaction-service.spec.js', - type: 'resource.script', - ended: true, + type: 'resource', + subtype: 'script', _end: 257.22, _start: 26.875000000000004 }, { name: 'http://localhost:9876/base/test/performance-monitoring/transaction.spec.js', - type: 'resource.script', - ended: true, + type: 'resource', + subtype: 'script', _end: 187.60500000000002, _start: 27.035000000000004 }, { name: 'http://localhost:9876/base/test/performance-monitoring/zone-service.spec.js', - type: 'resource.script', - ended: true, + type: 'resource', + subtype: 'script', _end: 188.72000000000003, _start: 27.180000000000003 + }, + { + name: 'http://non-existing.com/v1/client-side/transactions', + type: 'resource', + subtype: 'xmlhttprequest', + _end: 857.8950000000001, + _start: 707.23 + }, + { + name: 'http://localhost:8200/v1/client-side/errors', + type: 'resource', + subtype: 'xmlhttprequest', + _end: 1625.49, + _start: 1619.825 + }, + { + name: 'http://localhost:8200/v1/client-side/transactions', + type: 'resource', + subtype: 'fetch', + _end: 2832.545, + _start: 2796.3600000000006 } ] diff --git a/packages/rum-core/test/fixtures/resource-entries.js b/packages/rum-core/test/fixtures/resource-entries.js index e089faade..1225bc9f9 100644 --- a/packages/rum-core/test/fixtures/resource-entries.js +++ b/packages/rum-core/test/fixtures/resource-entries.js @@ -549,132 +549,12 @@ export default [ decodedBodySize: 0, serverTiming: [] }, - { - name: 'http://localhost:8200/v1/client-side/errors', - entryType: 'resource', - startTime: 1625.88, - duration: 4.135000000000218, - initiatorType: 'xmlhttprequest', - nextHopProtocol: 'http/1.1', - workerStart: 0, - redirectStart: 0, - redirectEnd: 0, - fetchStart: 1625.88, - domainLookupStart: 0, - domainLookupEnd: 0, - connectStart: 0, - connectEnd: 0, - secureConnectionStart: 0, - requestStart: 0, - responseStart: 0, - responseEnd: 1630.0150000000003, - transferSize: 0, - encodedBodySize: 0, - decodedBodySize: 0, - serverTiming: [] - }, - { - name: 'http://localhost:8200/v1/client-side/errors', - entryType: 'resource', - startTime: 1633.93, - duration: 5.349999999999909, - initiatorType: 'xmlhttprequest', - nextHopProtocol: 'http/1.1', - workerStart: 0, - redirectStart: 0, - redirectEnd: 0, - fetchStart: 1633.93, - domainLookupStart: 0, - domainLookupEnd: 0, - connectStart: 0, - connectEnd: 0, - secureConnectionStart: 0, - requestStart: 0, - responseStart: 0, - responseEnd: 1639.28, - transferSize: 0, - encodedBodySize: 0, - decodedBodySize: 0, - serverTiming: [] - }, - { - name: 'http://localhost:8200/v1/client-side/errors', - entryType: 'resource', - startTime: 1639.69, - duration: 6.430000000000064, - initiatorType: 'xmlhttprequest', - nextHopProtocol: 'http/1.1', - workerStart: 0, - redirectStart: 0, - redirectEnd: 0, - fetchStart: 1639.69, - domainLookupStart: 0, - domainLookupEnd: 0, - connectStart: 0, - connectEnd: 0, - secureConnectionStart: 0, - requestStart: 0, - responseStart: 0, - responseEnd: 1646.1200000000001, - transferSize: 0, - encodedBodySize: 0, - decodedBodySize: 0, - serverTiming: [] - }, - { - name: 'http://localhost:8200/v1/client-side/errors', - entryType: 'resource', - startTime: 1648.775, - duration: 8.569999999999936, - initiatorType: 'xmlhttprequest', - nextHopProtocol: 'http/1.1', - workerStart: 0, - redirectStart: 0, - redirectEnd: 0, - fetchStart: 1648.775, - domainLookupStart: 0, - domainLookupEnd: 0, - connectStart: 0, - connectEnd: 0, - secureConnectionStart: 0, - requestStart: 0, - responseStart: 0, - responseEnd: 1657.345, - transferSize: 0, - encodedBodySize: 0, - decodedBodySize: 0, - serverTiming: [] - }, - { - name: 'http://localhost:8200/v1/client-side/errors', - entryType: 'resource', - startTime: 1657.7600000000002, - duration: 8.294999999999845, - initiatorType: 'xmlhttprequest', - nextHopProtocol: 'http/1.1', - workerStart: 0, - redirectStart: 0, - redirectEnd: 0, - fetchStart: 1657.7600000000002, - domainLookupStart: 0, - domainLookupEnd: 0, - connectStart: 0, - connectEnd: 0, - secureConnectionStart: 0, - requestStart: 0, - responseStart: 0, - responseEnd: 1666.055, - transferSize: 0, - encodedBodySize: 0, - decodedBodySize: 0, - serverTiming: [] - }, { name: 'http://localhost:8200/v1/client-side/transactions', entryType: 'resource', startTime: 2796.3600000000006, duration: 36.18499999999949, - initiatorType: 'xmlhttprequest', + initiatorType: 'fetch', nextHopProtocol: 'http/1.1', workerStart: 0, redirectStart: 0, @@ -688,31 +568,7 @@ export default [ requestStart: 0, responseStart: 0, responseEnd: 2832.545, - transferSize: 0, - encodedBodySize: 0, - decodedBodySize: 0, - serverTiming: [] - }, - { - name: 'http://localhost:8200/v1/client-side/transactions', - entryType: 'resource', - startTime: 2833.295, - duration: 5.945000000000164, - initiatorType: 'xmlhttprequest', - nextHopProtocol: 'http/1.1', - workerStart: 0, - redirectStart: 0, - redirectEnd: 0, - fetchStart: 2833.295, - domainLookupStart: 0, - domainLookupEnd: 0, - connectStart: 0, - connectEnd: 0, - secureConnectionStart: 0, - requestStart: 0, - responseStart: 0, - responseEnd: 2839.2400000000002, - transferSize: 0, + transferSize: 3805, encodedBodySize: 0, decodedBodySize: 0, serverTiming: [] diff --git a/packages/rum-core/test/performance-monitoring/capture-navigation.spec.js b/packages/rum-core/test/performance-monitoring/capture-navigation.spec.js index 0f5b02c99..93c1e3122 100644 --- a/packages/rum-core/test/performance-monitoring/capture-navigation.spec.js +++ b/packages/rum-core/test/performance-monitoring/capture-navigation.spec.js @@ -154,7 +154,7 @@ describe('Capture hard navigation', function() { it('should createResourceTimingSpans', function() { const spans = createResourceTimingSpans( resourceEntries, - ['http://ajax-filter.test'], + null, transactionStart, transactionEnd ) @@ -164,9 +164,9 @@ describe('Capture hard navigation', function() { http: { url: jasmine.any(String), response: { - transfer_size: 420580, - encoded_body_size: 420379, - decoded_body_size: 420379 + transfer_size: 3805, + encoded_body_size: 0, + decoded_body_size: 0 } } }) @@ -175,6 +175,68 @@ describe('Capture hard navigation', function() { expect(spans.map(mapSpan)).toEqual(spanSnapshot) }) + it('should filter intake API calls from resource timing', function() { + const entries = [ + { + name: 'http://localhost:8200/intake/v2/rum/events', + initiatorType: 'fetch', + entryType: 'resource', + startTime: 25, + responseEnd: 120 + }, + { + name: 'http://apm-server:8200/intake/v3/rum/events', + initiatorType: 'xmlhttprequest', + entryType: 'resource', + startTime: 100, + responseEnd: 150 + } + ] + const spans = createResourceTimingSpans( + entries, + 150, + transactionStart, + transactionEnd + ) + expect(spans).toEqual([]) + }) + + it('should add/filter XHR/Fetch spans from RT data based on patch time', function() { + const entries = [ + { + name: 'http://localhost:8000/fetch', + initiatorType: 'fetch', + entryType: 'resource', + startTime: 25, + responseEnd: 120 + }, + { + name: 'http://localhost:8000/data?query=foo', + initiatorType: 'xmlhttprequest', + entryType: 'resource', + startTime: 100, + responseEnd: 150 + } + ] + const getCount = requestPatchTime => + createResourceTimingSpans( + entries, + requestPatchTime, + transactionStart, + transactionEnd + ).length + + expect(getCount(null)).toBe(2) + // same time as start of 1st resource + expect(getCount(25)).toBe(1) + // after first res start time + expect(getCount(30)).toBe(1) + // after both resources + expect(getCount(101)).toBe(2) + // before both resources + expect(getCount(10)).toBe(0) + }) + it('should createUserTimingSpans', function() { const spans = createUserTimingSpans( userTimingEntries, diff --git a/packages/rum-core/test/performance-monitoring/performance-monitoring.spec.js b/packages/rum-core/test/performance-monitoring/performance-monitoring.spec.js index e6658213d..495c4c6ba 100644 --- a/packages/rum-core/test/performance-monitoring/performance-monitoring.spec.js +++ b/packages/rum-core/test/performance-monitoring/performance-monitoring.spec.js @@ -46,6 +46,7 @@ import { TRANSACTION_END, TRANSACTIONS } from '../../src/common/constants' +import { state } from '../../src/state' import patchEventHandler from '../common/patch' import { mockGetEntriesByType } from '../utils/globals-mock' import resourceEntries from '../fixtures/resource-entries' @@ -300,6 +301,9 @@ describe('PerformanceMonitoring', function() { if (window.fetch) { it('should create fetch spans', function(done) { + const origBootstrapTime = state.bootstrapTime + // ignore capturing resource timing spans + state.bootstrapTime = 0 var fn = performanceMonitoring.getFetchSub() var dTHeaderValue const cancelFetchSub = patchEventHandler.observe(FETCH, function( @@ -343,6 +347,7 @@ describe('PerformanceMonitoring', function() { }) expect(dTHeaderValue).toBeDefined() cancelFetchSub() + state.bootstrapTime = origBootstrapTime done() }) }) @@ -372,6 +377,9 @@ describe('PerformanceMonitoring', function() { }) it('should not duplicate xhr spans if fetch is a polyfill', function(done) { + const origBootstrapTime = state.bootstrapTime + // ignore capturing resource timing spans + state.bootstrapTime = 0 const xhrFn = performanceMonitoring.getXHRSub() const fetchFn = performanceMonitoring.getFetchSub() @@ -449,6 +457,7 @@ describe('PerformanceMonitoring', function() { ]) cancelXHRSub() cancelFetchSub() + state.bootstrapTime = origBootstrapTime done() }) })