From e1cb176bdb951614242cd4e4d9dc4ec5aeb89c2a Mon Sep 17 00:00:00 2001 From: Bryan Atkinson Date: Wed, 13 Nov 2024 20:36:33 +0000 Subject: [PATCH 01/15] Add support for capturing web vitals metrics in Firebase performance for Web. Modifies export to use sendBeacon instead of fetch API, and shifts the upload time to the first time the page is hidden or unloaded. --- packages/performance/package.json | 9 +- packages/performance/src/constants.ts | 9 ++ packages/performance/src/resources/trace.ts | 48 ++++++- .../performance/src/resources/web_vitals.ts | 27 ++++ .../src/services/oob_resources_service.ts | 121 +++++++++++++----- .../performance/src/services/perf_logger.ts | 36 +++--- .../src/services/transport_service.ts | 96 +++++--------- .../performance/src/utils/metric_utils.ts | 10 +- yarn.lock | 5 + 9 files changed, 237 insertions(+), 124 deletions(-) create mode 100644 packages/performance/src/resources/web_vitals.ts diff --git a/packages/performance/package.json b/packages/performance/package.json index c613ac66877..6bf5588b272 100644 --- a/packages/performance/package.json +++ b/packages/performance/package.json @@ -14,9 +14,7 @@ }, "./package.json": "./package.json" }, - "files": [ - "dist" - ], + "files": ["dist"], "scripts": { "lint": "eslint -c .eslintrc.js '**/*.ts' --ignore-path '../../.gitignore'", "lint:fix": "eslint --fix -c .eslintrc.js '**/*.ts' --ignore-path '../../.gitignore'", @@ -43,6 +41,7 @@ "@firebase/util": "1.10.3", "@firebase/component": "0.6.12", "tslib": "^2.1.0" + "web-vitals": "^4.2.4" }, "license": "Apache-2.0", "devDependencies": { @@ -62,9 +61,7 @@ }, "typings": "dist/src/index.d.ts", "nyc": { - "extension": [ - ".ts" - ], + "extension": [".ts"], "reportDir": "./coverage/node" } } diff --git a/packages/performance/src/constants.ts b/packages/performance/src/constants.ts index 2cac126da97..66350190603 100644 --- a/packages/performance/src/constants.ts +++ b/packages/performance/src/constants.ts @@ -33,6 +33,15 @@ export const FIRST_CONTENTFUL_PAINT_COUNTER_NAME = '_fcp'; export const FIRST_INPUT_DELAY_COUNTER_NAME = '_fid'; +export const LARGEST_CONTENTFUL_PAINT_METRIC_NAME = '_lcp'; +export const LARGEST_CONTENTFUL_PAINT_ATTRIBUTE_NAME = 'lcp_element'; + +export const INTERACTION_TO_NEXT_PAINT_METRIC_NAME = '_inp'; +export const INTERACTION_TO_NEXT_PAINT_ATTRIBUTE_NAME = 'inp_interactionTarget'; + +export const CUMULATIVE_LAYOUT_SHIFT_METRIC_NAME = '_cls'; +export const CUMULATIVE_LAYOUT_SHIFT_ATTRIBUTE_NAME = 'cls_largestShiftTarget'; + export const CONFIG_LOCAL_STORAGE_KEY = '@firebase/performance/config'; export const CONFIG_EXPIRY_LOCAL_STORAGE_KEY = diff --git a/packages/performance/src/resources/trace.ts b/packages/performance/src/resources/trace.ts index 792bf1677ea..d6657f14ba6 100644 --- a/packages/performance/src/resources/trace.ts +++ b/packages/performance/src/resources/trace.ts @@ -22,10 +22,16 @@ import { OOB_TRACE_PAGE_LOAD_PREFIX, FIRST_PAINT_COUNTER_NAME, FIRST_CONTENTFUL_PAINT_COUNTER_NAME, - FIRST_INPUT_DELAY_COUNTER_NAME + FIRST_INPUT_DELAY_COUNTER_NAME, + LARGEST_CONTENTFUL_PAINT_METRIC_NAME, + LARGEST_CONTENTFUL_PAINT_ATTRIBUTE_NAME, + INTERACTION_TO_NEXT_PAINT_METRIC_NAME, + INTERACTION_TO_NEXT_PAINT_ATTRIBUTE_NAME, + CUMULATIVE_LAYOUT_SHIFT_METRIC_NAME, + CUMULATIVE_LAYOUT_SHIFT_ATTRIBUTE_NAME } from '../constants'; import { Api } from '../services/api_service'; -import { logTrace } from '../services/perf_logger'; +import { logTrace, flushLogs } from '../services/perf_logger'; import { ERROR_FACTORY, ErrorCode } from '../utils/errors'; import { isValidCustomAttributeName, @@ -37,6 +43,7 @@ import { } from '../utils/metric_utils'; import { PerformanceTrace } from '../public_types'; import { PerformanceController } from '../controllers/perf'; +import { CoreVitalMetric, WebVitalMetrics } from './web_vitals'; const enum TraceState { UNINITIALIZED = 1, @@ -279,6 +286,7 @@ export class Trace implements PerformanceTrace { performanceController: PerformanceController, navigationTimings: PerformanceNavigationTiming[], paintTimings: PerformanceEntry[], + webVitalMetrics: WebVitalMetrics, firstInputDelay?: number ): void { const route = Api.getInstance().getUrl(); @@ -340,7 +348,43 @@ export class Trace implements PerformanceTrace { } } + this.addWebVitalMetric( + trace, + LARGEST_CONTENTFUL_PAINT_METRIC_NAME, + LARGEST_CONTENTFUL_PAINT_ATTRIBUTE_NAME, + webVitalMetrics.lcp + ); + this.addWebVitalMetric( + trace, + CUMULATIVE_LAYOUT_SHIFT_METRIC_NAME, + CUMULATIVE_LAYOUT_SHIFT_ATTRIBUTE_NAME, + webVitalMetrics.cls + ); + this.addWebVitalMetric( + trace, + INTERACTION_TO_NEXT_PAINT_METRIC_NAME, + INTERACTION_TO_NEXT_PAINT_ATTRIBUTE_NAME, + webVitalMetrics.inp + ); + + // Page load logs are sent at unload time and so should be logged and + // flushed immediately. logTrace(trace); + flushLogs(); + } + + static addWebVitalMetric( + trace: Trace, + metricKey: string, + attributeKey: string, + metric?: CoreVitalMetric + ): void { + if (metric) { + trace.putMetric(metricKey, Math.floor(metric.value * 1000)); + if (metric.elementAttribution) { + trace.putAttribute(attributeKey, metric.elementAttribution); + } + } } static createUserTimingTrace( diff --git a/packages/performance/src/resources/web_vitals.ts b/packages/performance/src/resources/web_vitals.ts new file mode 100644 index 00000000000..850768b4655 --- /dev/null +++ b/packages/performance/src/resources/web_vitals.ts @@ -0,0 +1,27 @@ +/** + * @license + * Copyright 2024 Google LLC + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +export interface CoreVitalMetric { + value: number; + elementAttribution?: string; +} + +export interface WebVitalMetrics { + cls?: CoreVitalMetric; + inp?: CoreVitalMetric; + lcp?: CoreVitalMetric; +} diff --git a/packages/performance/src/services/oob_resources_service.ts b/packages/performance/src/services/oob_resources_service.ts index aede0fa85c9..a681d005418 100644 --- a/packages/performance/src/services/oob_resources_service.ts +++ b/packages/performance/src/services/oob_resources_service.ts @@ -21,9 +21,22 @@ import { createNetworkRequestEntry } from '../resources/network_request'; import { TRACE_MEASURE_PREFIX } from '../constants'; import { getIid } from './iid_service'; import { PerformanceController } from '../controllers/perf'; +import { WebVitalMetrics } from '../resources/web_vitals'; +import { + onCLS, + onLCP, + onINP, + LCPMetricWithAttribution, + CLSMetricWithAttribution, + INPMetricWithAttribution +} from 'web-vitals/attribution'; const FID_WAIT_TIME_MS = 5000; +const webVitalMetrics: WebVitalMetrics = {}; + +let sentPageLoadTrace: boolean = false; + export function setupOobResources( performanceController: PerformanceController ): void { @@ -53,41 +66,40 @@ function setupNetworkRequests( function setupOobTraces(performanceController: PerformanceController): void { const api = Api.getInstance(); - const navigationTimings = api.getEntriesByType( - 'navigation' - ) as PerformanceNavigationTiming[]; - const paintTimings = api.getEntriesByType('paint'); - // If First Input Delay polyfill is added to the page, report the fid value. - // https://github.com/GoogleChromeLabs/first-input-delay - if (api.onFirstInputDelay) { - // If the fid call back is not called for certain time, continue without it. - // eslint-disable-next-line @typescript-eslint/no-explicit-any - let timeoutId: any = setTimeout(() => { - Trace.createOobTrace( - performanceController, - navigationTimings, - paintTimings - ); - timeoutId = undefined; - }, FID_WAIT_TIME_MS); - api.onFirstInputDelay((fid: number) => { - if (timeoutId) { - clearTimeout(timeoutId); - Trace.createOobTrace( - performanceController, - navigationTimings, - paintTimings, - fid - ); - } - }); + // Better support for Safari + if ('onpagehide' in window) { + api.document.addEventListener('pagehide', () => + sendOobTrace(performanceController) + ); } else { - Trace.createOobTrace( - performanceController, - navigationTimings, - paintTimings + api.document.addEventListener('unload', () => + sendOobTrace(performanceController) ); } + api.document.addEventListener('visibilitychange', () => { + if (api.document.visibilityState === 'hidden') { + sendOobTrace(performanceController); + } + }); + + onLCP((metric: LCPMetricWithAttribution) => { + webVitalMetrics.lcp = { + value: metric.value, + elementAttribution: metric.attribution.element + }; + }); + onCLS((metric: CLSMetricWithAttribution) => { + webVitalMetrics.cls = { + value: metric.value, + elementAttribution: metric.attribution.largestShiftTarget + }; + }); + onINP((metric: INPMetricWithAttribution) => { + webVitalMetrics.inp = { + value: metric.value, + elementAttribution: metric.attribution.interactionTarget + }; + }); } function setupUserTimingTraces( @@ -119,3 +131,48 @@ function createUserTimingTrace( } Trace.createUserTimingTrace(performanceController, measureName); } + +function sendOobTrace(performanceController: PerformanceController): void { + if (!sentPageLoadTrace) { + sentPageLoadTrace = true; + const api = Api.getInstance(); + const navigationTimings = api.getEntriesByType( + 'navigation' + ) as PerformanceNavigationTiming[]; + const paintTimings = api.getEntriesByType('paint'); + // If First Input Delay polyfill is added to the page, report the fid value. + // https://github.com/GoogleChromeLabs/first-input-delay + if (api.onFirstInputDelay) { + // If the fid call back is not called for certain time, continue without it. + // eslint-disable-next-line @typescript-eslint/no-explicit-any + let timeoutId: any = setTimeout(() => { + Trace.createOobTrace( + performanceController, + navigationTimings, + paintTimings, + webVitalMetrics + ); + timeoutId = undefined; + }, FID_WAIT_TIME_MS); + api.onFirstInputDelay((fid: number) => { + if (timeoutId) { + clearTimeout(timeoutId); + Trace.createOobTrace( + performanceController, + navigationTimings, + paintTimings, + webVitalMetrics, + fid + ); + } + }); + } else { + Trace.createOobTrace( + performanceController, + navigationTimings, + paintTimings, + webVitalMetrics + ); + } + } +} diff --git a/packages/performance/src/services/perf_logger.ts b/packages/performance/src/services/perf_logger.ts index 60bffb051e9..c51f3e8640e 100644 --- a/packages/performance/src/services/perf_logger.ts +++ b/packages/performance/src/services/perf_logger.ts @@ -23,14 +23,13 @@ import { SettingsService } from './settings_service'; import { getServiceWorkerStatus, getVisibilityState, - VisibilityState, getEffectiveConnectionType } from '../utils/attributes_utils'; import { isPerfInitialized, getInitializationPromise } from './initialization_service'; -import { transportHandler } from './transport_service'; +import { transportHandler, flushQueuedEvents } from './transport_service'; import { SDK_VERSION } from '../constants'; import { FirebaseApp } from '@firebase/app'; import { getAppId } from '../utils/app_utils'; @@ -85,19 +84,25 @@ interface TraceMetric { custom_attributes?: { [key: string]: string }; } -let logger: ( - resource: NetworkRequest | Trace, - resourceType: ResourceType -) => void | undefined; +interface Logger { + send: (resource: NetworkRequest | Trace, resourceType: ResourceType) => void | undefined; + flush: () => void; +} + +let logger: Logger; +// // This method is not called before initialization. function sendLog( resource: NetworkRequest | Trace, resourceType: ResourceType ): void { if (!logger) { - logger = transportHandler(serializer); + logger = { + send: transportHandler(serializer), + flush: flushQueuedEvents, + }; } - logger(resource, resourceType); + logger.send(resource, resourceType); } export function logTrace(trace: Trace): void { @@ -115,11 +120,6 @@ export function logTrace(trace: Trace): void { return; } - // Only log the page load auto traces if page is visible. - if (trace.isAuto && getVisibilityState() !== VisibilityState.VISIBLE) { - return; - } - if (isPerfInitialized()) { sendTraceLog(trace); } else { @@ -132,6 +132,12 @@ export function logTrace(trace: Trace): void { } } +export function flushLogs(): void { + if (logger) { + logger.flush(); + } +} + function sendTraceLog(trace: Trace): void { if (!getIid()) { return; @@ -145,7 +151,7 @@ function sendTraceLog(trace: Trace): void { return; } - setTimeout(() => sendLog(trace, ResourceType.Trace), 0); + sendLog(trace, ResourceType.Trace); } export function logNetworkRequest(networkRequest: NetworkRequest): void { @@ -177,7 +183,7 @@ export function logNetworkRequest(networkRequest: NetworkRequest): void { return; } - setTimeout(() => sendLog(networkRequest, ResourceType.NetworkRequest), 0); + sendLog(networkRequest, ResourceType.NetworkRequest); } function serializer( diff --git a/packages/performance/src/services/transport_service.ts b/packages/performance/src/services/transport_service.ts index b90090e3209..d075d30775f 100644 --- a/packages/performance/src/services/transport_service.ts +++ b/packages/performance/src/services/transport_service.ts @@ -21,14 +21,7 @@ import { consoleLogger } from '../utils/console_logger'; const DEFAULT_SEND_INTERVAL_MS = 10 * 1000; const INITIAL_SEND_TIME_DELAY_MS = 5.5 * 1000; -// If end point does not work, the call will be tried for these many times. -const DEFAULT_REMAINING_TRIES = 3; const MAX_EVENT_COUNT_PER_REQUEST = 1000; -let remainingTries = DEFAULT_REMAINING_TRIES; - -interface LogResponseDetails { - responseAction?: string; -} interface BatchEvent { message: string; @@ -76,17 +69,10 @@ export function resetTransportService(): void { function processQueue(timeOffset: number): void { setTimeout(() => { - // If there is no remainingTries left, stop retrying. - if (remainingTries === 0) { - return; + if (queue.length > 0) { + dispatchQueueEvents(); } - - // If there are no events to process, wait for DEFAULT_SEND_INTERVAL_MS and try again. - if (!queue.length) { - return processQueue(DEFAULT_SEND_INTERVAL_MS); - } - - dispatchQueueEvents(); + processQueue(DEFAULT_SEND_INTERVAL_MS); }, timeOffset); } @@ -114,60 +100,26 @@ function dispatchQueueEvents(): void { }; /* eslint-enable camelcase */ - sendEventsToFl(data, staged).catch(() => { - // If the request fails for some reason, add the events that were attempted - // back to the primary queue to retry later. - queue = [...staged, ...queue]; - remainingTries--; - consoleLogger.info(`Tries left: ${remainingTries}.`); - processQueue(DEFAULT_SEND_INTERVAL_MS); - }); -} - -function sendEventsToFl( - data: TransportBatchLogFormat, - staged: BatchEvent[] -): Promise { - return postToFlEndpoint(data) - .then(res => { - if (!res.ok) { - consoleLogger.info('Call to Firebase backend failed.'); - } - return res.json(); - }) - .then(res => { - // Find the next call wait time from the response. - const transportWait = Number(res.nextRequestWaitMillis); - let requestOffset = DEFAULT_SEND_INTERVAL_MS; - if (!isNaN(transportWait)) { - requestOffset = Math.max(transportWait, requestOffset); - } - - // Delete request if response include RESPONSE_ACTION_UNKNOWN or DELETE_REQUEST action. - // Otherwise, retry request using normal scheduling if response include RETRY_REQUEST_LATER. - const logResponseDetails: LogResponseDetails[] = res.logResponseDetails; - if ( - Array.isArray(logResponseDetails) && - logResponseDetails.length > 0 && - logResponseDetails[0].responseAction === 'RETRY_REQUEST_LATER' - ) { - queue = [...staged, ...queue]; - consoleLogger.info(`Retry transport request later.`); - } - - remainingTries = DEFAULT_REMAINING_TRIES; - // Schedule the next process. - processQueue(requestOffset); - }); + postToFlEndpoint(data); } -function postToFlEndpoint(data: TransportBatchLogFormat): Promise { +function postToFlEndpoint(data: TransportBatchLogFormat): boolean { const flTransportFullUrl = SettingsService.getInstance().getFlTransportFullUrl(); - return fetch(flTransportFullUrl, { - method: 'POST', - body: JSON.stringify(data) - }); + for (const event of data.log_event) { + const ext = JSON.parse(event.source_extension_json_proto3); + if (ext.network_request_metric) { + consoleLogger.info( + ` >>>>>> network_request: ${ext.network_request_metric.url}` + ); + } + if (ext.trace_metric) { + consoleLogger.info( + ` >>>>>> trace: ${JSON.stringify(ext.trace_metric)}` + ); + } + } + return navigator.sendBeacon(flTransportFullUrl, JSON.stringify(data)); } function addToQueue(evt: BatchEvent): void { @@ -191,3 +143,13 @@ export function transportHandler( }); }; } + +/** + * Force flush the queued events. Useful at page unload time to ensure all + * events are uploaded. + */ +export function flushQueuedEvents(): void { + while (queue.length > 0) { + dispatchQueueEvents(); + } +} diff --git a/packages/performance/src/utils/metric_utils.ts b/packages/performance/src/utils/metric_utils.ts index 9bbc4886aef..699fb83da3a 100644 --- a/packages/performance/src/utils/metric_utils.ts +++ b/packages/performance/src/utils/metric_utils.ts @@ -19,7 +19,10 @@ import { FIRST_PAINT_COUNTER_NAME, FIRST_CONTENTFUL_PAINT_COUNTER_NAME, FIRST_INPUT_DELAY_COUNTER_NAME, - OOB_TRACE_PAGE_LOAD_PREFIX + OOB_TRACE_PAGE_LOAD_PREFIX, + CUMULATIVE_LAYOUT_SHIFT_METRIC_NAME, + INTERACTION_TO_NEXT_PAINT_METRIC_NAME, + LARGEST_CONTENTFUL_PAINT_METRIC_NAME } from '../constants'; import { consoleLogger } from '../utils/console_logger'; @@ -28,7 +31,10 @@ const RESERVED_AUTO_PREFIX = '_'; const oobMetrics = [ FIRST_PAINT_COUNTER_NAME, FIRST_CONTENTFUL_PAINT_COUNTER_NAME, - FIRST_INPUT_DELAY_COUNTER_NAME + FIRST_INPUT_DELAY_COUNTER_NAME, + LARGEST_CONTENTFUL_PAINT_METRIC_NAME, + CUMULATIVE_LAYOUT_SHIFT_METRIC_NAME, + INTERACTION_TO_NEXT_PAINT_METRIC_NAME ]; /** diff --git a/yarn.lock b/yarn.lock index 910f54284fe..a7f5a7208dd 100644 --- a/yarn.lock +++ b/yarn.lock @@ -17834,6 +17834,11 @@ wcwidth@^1.0.0, wcwidth@^1.0.1: dependencies: defaults "^1.0.3" +web-vitals@^4.2.4: + version "4.2.4" + resolved "https://registry.npmjs.org/web-vitals/-/web-vitals-4.2.4.tgz#1d20bc8590a37769bd0902b289550936069184b7" + integrity sha512-r4DIlprAGwJ7YM11VZp4R884m0Vmgr6EAKe3P+kO0PPj3Unqyvv59rczf6UiGcb9Z8QxZVcqKNwv/g0WNdWwsw== + webdriver-js-extender@2.1.0: version "2.1.0" resolved "https://registry.npmjs.org/webdriver-js-extender/-/webdriver-js-extender-2.1.0.tgz" From 7d4d75cfa9498ff2513b62494874999ed9ceb5e9 Mon Sep 17 00:00:00 2001 From: Bryan Atkinson Date: Mon, 18 Nov 2024 20:36:35 +0000 Subject: [PATCH 02/15] Add unit tests for oob_resource_service changes to include web vitals. --- .../performance/src/services/api_service.ts | 14 ++ .../services/oob_resources_service.test.ts | 224 +++++++++++++++++- .../src/services/oob_resources_service.ts | 88 +++---- 3 files changed, 275 insertions(+), 51 deletions(-) diff --git a/packages/performance/src/services/api_service.ts b/packages/performance/src/services/api_service.ts index 494574f650c..97c3f2943c4 100644 --- a/packages/performance/src/services/api_service.ts +++ b/packages/performance/src/services/api_service.ts @@ -18,6 +18,14 @@ import { ERROR_FACTORY, ErrorCode } from '../utils/errors'; import { isIndexedDBAvailable, areCookiesEnabled } from '@firebase/util'; import { consoleLogger } from '../utils/console_logger'; +import { + CLSMetricWithAttribution, + INPMetricWithAttribution, + LCPMetricWithAttribution, + onCLS as vitalsOnCLS, + onINP as vitalsOnINP, + onLCP as vitalsOnLCP +} from 'web-vitals/attribution'; declare global { interface Window { @@ -47,6 +55,9 @@ export class Api { private readonly PerformanceObserver: typeof PerformanceObserver; private readonly windowLocation: Location; readonly onFirstInputDelay?: (fn: (fid: number) => void) => void; + readonly onLCP: (fn: (metric: LCPMetricWithAttribution) => void) => void; + readonly onINP: (fn: (metric: INPMetricWithAttribution) => void) => void; + readonly onCLS: (fn: (metric: CLSMetricWithAttribution) => void) => void; readonly localStorage?: Storage; readonly document: Document; readonly navigator: Navigator; @@ -68,6 +79,9 @@ export class Api { if (window.perfMetrics && window.perfMetrics.onFirstInputDelay) { this.onFirstInputDelay = window.perfMetrics.onFirstInputDelay; } + this.onLCP = vitalsOnLCP; + this.onINP = vitalsOnINP; + this.onCLS = vitalsOnCLS; } getUrl(): string { diff --git a/packages/performance/src/services/oob_resources_service.test.ts b/packages/performance/src/services/oob_resources_service.test.ts index 6f8ba259a94..f01fa1505d6 100644 --- a/packages/performance/src/services/oob_resources_service.test.ts +++ b/packages/performance/src/services/oob_resources_service.test.ts @@ -18,6 +18,7 @@ import { spy, stub, + restore as sinonRestore, SinonSpy, SinonStub, useFakeTimers, @@ -26,12 +27,21 @@ import { import { expect } from 'chai'; import { Api, setupApi, EntryType } from './api_service'; import * as iidService from './iid_service'; -import { setupOobResources } from './oob_resources_service'; +import { setupOobResources, resetForUnitTests } from './oob_resources_service'; import { Trace } from '../resources/trace'; import '../../test/setup'; import { PerformanceController } from '../controllers/perf'; import { FirebaseApp } from '@firebase/app'; import { FirebaseInstallations } from '@firebase/installations-types'; +import { WebVitalMetrics } from '../resources/web_vitals'; +import { + CLSAttribution, + CLSMetricWithAttribution, + INPAttribution, + INPMetricWithAttribution, + LCPAttribution, + LCPMetricWithAttribution +} from 'web-vitals/attribution'; describe('Firebase Performance > oob_resources_service', () => { const MOCK_ID = 'idasdfsffe'; @@ -82,23 +92,36 @@ describe('Firebase Performance > oob_resources_service', () => { let getIidStub: SinonStub<[], string | undefined>; let apiGetInstanceSpy: SinonSpy<[], Api>; + let eventListenerSpy: SinonSpy< + [ + type: string, + listener: EventListenerOrEventListenerObject, + options?: boolean | AddEventListenerOptions | undefined + ], + void + >; let getEntriesByTypeStub: SinonStub<[EntryType], PerformanceEntry[]>; let setupObserverStub: SinonStub< [EntryType, (entry: PerformanceEntry) => void], void >; - let createOobTraceStub: SinonStub< + let createOobTraceStub: SinonSpy< [ PerformanceController, PerformanceNavigationTiming[], PerformanceEntry[], + WebVitalMetrics, (number | undefined)? ], void >; let clock: SinonFakeTimers; + let lcpSpy: SinonSpy<[(m: LCPMetricWithAttribution) => void], void>; + let inpSpy: SinonSpy<[(m: INPMetricWithAttribution) => void], void>; + let clsSpy: SinonSpy<[(m: CLSMetricWithAttribution) => void], void>; - setupApi(self); + const mockWindow = { ...self }; + setupApi(mockWindow); const fakeFirebaseConfig = { apiKey: 'api-key', @@ -120,9 +143,22 @@ describe('Firebase Performance > oob_resources_service', () => { fakeInstallations ); + function callEventListener(name: string): void { + for (let i = eventListenerSpy.callCount; i > 0; i--) { + const [eventName, eventFn] = eventListenerSpy.getCall(i - 1).args; + if (eventName === name) { + if (typeof eventFn === 'function') { + eventFn(new CustomEvent(name)); + } + } + } + } + beforeEach(() => { + resetForUnitTests(); getIidStub = stub(iidService, 'getIid'); - apiGetInstanceSpy = spy(Api, 'getInstance'); + eventListenerSpy = spy(mockWindow.document, 'addEventListener'); + clock = useFakeTimers(); getEntriesByTypeStub = stub(Api.prototype, 'getEntriesByType').callsFake( entry => { @@ -133,14 +169,24 @@ describe('Firebase Performance > oob_resources_service', () => { } ); setupObserverStub = stub(Api.prototype, 'setupObserver'); - createOobTraceStub = stub(Trace, 'createOobTrace'); + createOobTraceStub = spy(Trace, 'createOobTrace'); + const api = Api.getInstance(); + lcpSpy = spy(api, 'onLCP'); + inpSpy = spy(api, 'onINP'); + clsSpy = spy(api, 'onCLS'); + apiGetInstanceSpy = spy(Api, 'getInstance'); }); afterEach(() => { clock.restore(); + sinonRestore(); + const api = Api.getInstance(); + //@ts-ignore Assignment to read-only property. + api.onFirstInputDelay = undefined; }); - describe('setupOobResources', () => { + // eslint-disable-next-line no-restricted-properties + describe.only('setupOobResources', () => { it('does not start if there is no iid', () => { getIidStub.returns(undefined); setupOobResources(performanceController); @@ -158,18 +204,49 @@ describe('Firebase Performance > oob_resources_service', () => { expect(setupObserverStub).to.be.calledWith('resource'); }); - it('sets up page load trace collection', () => { + it('does not create page load trace before hidden', () => { getIidStub.returns(MOCK_ID); setupOobResources(performanceController); clock.tick(1); expect(apiGetInstanceSpy).to.be.called; + expect(createOobTraceStub).not.to.be.called; + }); + + it('creates page load trace after hidden', () => { + getIidStub.returns(MOCK_ID); + setupOobResources(performanceController); + clock.tick(1); + + stub(mockWindow.document, 'visibilityState').value('hidden'); + callEventListener('visibilitychange'); + expect(getEntriesByTypeStub).to.be.calledWith('navigation'); expect(getEntriesByTypeStub).to.be.calledWith('paint'); expect(createOobTraceStub).to.be.calledWithExactly( performanceController, [NAVIGATION_PERFORMANCE_ENTRY], - [PAINT_PERFORMANCE_ENTRY] + [PAINT_PERFORMANCE_ENTRY], + {}, + undefined + ); + }); + + it('creates page load trace after pagehide', () => { + getIidStub.returns(MOCK_ID); + setupOobResources(performanceController); + clock.tick(1); + + callEventListener('pagehide'); + + expect(getEntriesByTypeStub).to.be.calledWith('navigation'); + expect(getEntriesByTypeStub).to.be.calledWith('paint'); + expect(createOobTraceStub).to.be.calledWithExactly( + performanceController, + [NAVIGATION_PERFORMANCE_ENTRY], + [PAINT_PERFORMANCE_ENTRY], + {}, + undefined ); }); @@ -181,13 +258,19 @@ describe('Firebase Performance > oob_resources_service', () => { setupOobResources(performanceController); clock.tick(1); + // Force the page load event to be sent + stub(mockWindow.document, 'visibilityState').value('hidden'); + callEventListener('visibilitychange'); + expect(api.onFirstInputDelay).to.be.called; expect(createOobTraceStub).not.to.be.called; clock.tick(5000); expect(createOobTraceStub).to.be.calledWithExactly( performanceController, [NAVIGATION_PERFORMANCE_ENTRY], - [PAINT_PERFORMANCE_ENTRY] + [PAINT_PERFORMANCE_ENTRY], + {}, + undefined ); }); @@ -206,10 +289,15 @@ describe('Firebase Performance > oob_resources_service', () => { clock.tick(1); firstInputDelayCallback(FIRST_INPUT_DELAY); + // Force the page load event to be sent + stub(mockWindow.document, 'visibilityState').value('hidden'); + callEventListener('visibilitychange'); + expect(createOobTraceStub).to.be.calledWithExactly( performanceController, [NAVIGATION_PERFORMANCE_ENTRY], [PAINT_PERFORMANCE_ENTRY], + {}, FIRST_INPUT_DELAY ); }); @@ -223,5 +311,123 @@ describe('Firebase Performance > oob_resources_service', () => { expect(getEntriesByTypeStub).to.be.calledWith('measure'); expect(setupObserverStub).to.be.calledWith('measure'); }); + + it('sends LCP metrics with attribution', () => { + getIidStub.returns(MOCK_ID); + setupOobResources(performanceController); + clock.tick(1); + + lcpSpy.getCall(-1).args[0]({ + value: 12.34, + attribution: { + element: 'some-element' + } as LCPAttribution + } as LCPMetricWithAttribution); + + // Force the page load event to be sent + stub(mockWindow.document, 'visibilityState').value('hidden'); + callEventListener('visibilitychange'); + + expect(createOobTraceStub).to.be.calledWithExactly( + performanceController, + [NAVIGATION_PERFORMANCE_ENTRY], + [PAINT_PERFORMANCE_ENTRY], + { + lcp: { value: 12.34, elementAttribution: 'some-element' } + }, + undefined + ); + }); + + it('sends INP metrics with attribution', () => { + getIidStub.returns(MOCK_ID); + setupOobResources(performanceController); + clock.tick(1); + + inpSpy.getCall(-1).args[0]({ + value: 0.198, + attribution: { + interactionTarget: 'another-element' + } as INPAttribution + } as INPMetricWithAttribution); + + // Force the page load event to be sent + stub(mockWindow.document, 'visibilityState').value('hidden'); + callEventListener('visibilitychange'); + + expect(createOobTraceStub).to.be.calledWithExactly( + performanceController, + [NAVIGATION_PERFORMANCE_ENTRY], + [PAINT_PERFORMANCE_ENTRY], + { + inp: { value: 0.198, elementAttribution: 'another-element' } + }, + undefined + ); + }); + + it('sends CLS metrics with attribution', () => { + getIidStub.returns(MOCK_ID); + setupOobResources(performanceController); + clock.tick(1); + + clsSpy.getCall(-1).args[0]({ + value: 0.3, + // eslint-disable-next-line + attribution: { + largestShiftTarget: 'large-shift-element' + } as CLSAttribution + } as CLSMetricWithAttribution); + + // Force the page load event to be sent + stub(mockWindow.document, 'visibilityState').value('hidden'); + callEventListener('visibilitychange'); + + expect(createOobTraceStub).to.be.calledWithExactly( + performanceController, + [NAVIGATION_PERFORMANCE_ENTRY], + [PAINT_PERFORMANCE_ENTRY], + { + cls: { value: 0.3, elementAttribution: 'large-shift-element' } + }, + undefined + ); + }); + + it('sends all core web vitals metrics', () => { + getIidStub.returns(MOCK_ID); + setupOobResources(performanceController); + clock.tick(1); + + lcpSpy.getCall(-1).args[0]({ + value: 5.91, + attribution: { element: 'an-element' } as LCPAttribution + } as LCPMetricWithAttribution); + inpSpy.getCall(-1).args[0]({ + value: 0.1 + } as INPMetricWithAttribution); + clsSpy.getCall(-1).args[0]({ + value: 0.3, + attribution: { + largestShiftTarget: 'large-shift-element' + } as CLSAttribution + } as CLSMetricWithAttribution); + + // Force the page load event to be sent + stub(mockWindow.document, 'visibilityState').value('hidden'); + callEventListener('visibilitychange'); + + expect(createOobTraceStub).to.be.calledWithExactly( + performanceController, + [NAVIGATION_PERFORMANCE_ENTRY], + [PAINT_PERFORMANCE_ENTRY], + { + lcp: { value: 5.91, elementAttribution: 'an-element' }, + inp: { value: 0.1, elementAttribution: undefined }, + cls: { value: 0.3, elementAttribution: 'large-shift-element' } + }, + undefined + ); + }); }); }); diff --git a/packages/performance/src/services/oob_resources_service.ts b/packages/performance/src/services/oob_resources_service.ts index a681d005418..bf9bf620c22 100644 --- a/packages/performance/src/services/oob_resources_service.ts +++ b/packages/performance/src/services/oob_resources_service.ts @@ -15,27 +15,26 @@ * limitations under the License. */ -import { Api } from './api_service'; -import { Trace } from '../resources/trace'; -import { createNetworkRequestEntry } from '../resources/network_request'; -import { TRACE_MEASURE_PREFIX } from '../constants'; -import { getIid } from './iid_service'; -import { PerformanceController } from '../controllers/perf'; -import { WebVitalMetrics } from '../resources/web_vitals'; import { - onCLS, - onLCP, - onINP, - LCPMetricWithAttribution, CLSMetricWithAttribution, - INPMetricWithAttribution + INPMetricWithAttribution, + LCPMetricWithAttribution, } from 'web-vitals/attribution'; -const FID_WAIT_TIME_MS = 5000; +import { TRACE_MEASURE_PREFIX } from '../constants'; +import { PerformanceController } from '../controllers/perf'; +import { createNetworkRequestEntry } from '../resources/network_request'; +import { Trace } from '../resources/trace'; +import { WebVitalMetrics } from '../resources/web_vitals'; + +import { Api } from './api_service'; +import { getIid } from './iid_service'; -const webVitalMetrics: WebVitalMetrics = {}; +const FID_WAIT_TIME_MS = 5000; +let webVitalMetrics: WebVitalMetrics = {}; let sentPageLoadTrace: boolean = false; +let firstInputDelay: number | undefined; export function setupOobResources( performanceController: PerformanceController @@ -44,8 +43,9 @@ export function setupOobResources( if (!getIid()) { return; } - // The load event might not have fired yet, and that means performance navigation timing - // object has a duration of 0. The setup should run after all current tasks in js queue. + // The load event might not have fired yet, and that means performance + // navigation timing object has a duration of 0. The setup should run after + // all current tasks in js queue. setTimeout(() => setupOobTraces(performanceController), 0); setTimeout(() => setupNetworkRequests(performanceController), 0); setTimeout(() => setupUserTimingTraces(performanceController), 0); @@ -82,22 +82,28 @@ function setupOobTraces(performanceController: PerformanceController): void { } }); - onLCP((metric: LCPMetricWithAttribution) => { + if (api.onFirstInputDelay) { + api.onFirstInputDelay((fid: number) => { + firstInputDelay = fid; + }); + } + + api.onLCP((metric: LCPMetricWithAttribution) => { webVitalMetrics.lcp = { value: metric.value, - elementAttribution: metric.attribution.element + elementAttribution: metric.attribution?.element }; }); - onCLS((metric: CLSMetricWithAttribution) => { + api.onCLS((metric: CLSMetricWithAttribution) => { webVitalMetrics.cls = { value: metric.value, - elementAttribution: metric.attribution.largestShiftTarget + elementAttribution: metric.attribution?.largestShiftTarget }; }); - onINP((metric: INPMetricWithAttribution) => { + api.onINP((metric: INPMetricWithAttribution) => { webVitalMetrics.inp = { value: metric.value, - elementAttribution: metric.attribution.interactionTarget + elementAttribution: metric.attribution?.interactionTarget }; }); } @@ -122,7 +128,8 @@ function createUserTimingTrace( measure: PerformanceEntry ): void { const measureName = measure.name; - // Do not create a trace, if the user timing marks and measures are created by the sdk itself. + // Do not create a trace, if the user timing marks and measures are created by + // the sdk itself. if ( measureName.substring(0, TRACE_MEASURE_PREFIX.length) === TRACE_MEASURE_PREFIX @@ -142,37 +149,34 @@ function sendOobTrace(performanceController: PerformanceController): void { const paintTimings = api.getEntriesByType('paint'); // If First Input Delay polyfill is added to the page, report the fid value. // https://github.com/GoogleChromeLabs/first-input-delay - if (api.onFirstInputDelay) { - // If the fid call back is not called for certain time, continue without it. - // eslint-disable-next-line @typescript-eslint/no-explicit-any - let timeoutId: any = setTimeout(() => { + if (api.onFirstInputDelay && !firstInputDelay) { + setTimeout(() => { Trace.createOobTrace( performanceController, navigationTimings, paintTimings, - webVitalMetrics + webVitalMetrics, + firstInputDelay ); - timeoutId = undefined; }, FID_WAIT_TIME_MS); - api.onFirstInputDelay((fid: number) => { - if (timeoutId) { - clearTimeout(timeoutId); - Trace.createOobTrace( - performanceController, - navigationTimings, - paintTimings, - webVitalMetrics, - fid - ); - } - }); } else { Trace.createOobTrace( performanceController, navigationTimings, paintTimings, - webVitalMetrics + webVitalMetrics, + firstInputDelay ); } } } + +/** + * This service will only export the page load trace once. This function allows + * resetting it for unit tests + */ +export function resetForUnitTests(): void { + sentPageLoadTrace = false; + firstInputDelay = undefined; + webVitalMetrics = {}; +} From 7a39d7d707e6e9def11c413d1ebcb0e69f77b6ba Mon Sep 17 00:00:00 2001 From: Bryan Atkinson Date: Mon, 18 Nov 2024 21:33:57 +0000 Subject: [PATCH 03/15] Update perf_logger tests. --- .../src/services/perf_logger.test.ts | 19 +++++++++++++++++-- 1 file changed, 17 insertions(+), 2 deletions(-) diff --git a/packages/performance/src/services/perf_logger.test.ts b/packages/performance/src/services/perf_logger.test.ts index f0b167707b1..4f4068831b8 100644 --- a/packages/performance/src/services/perf_logger.test.ts +++ b/packages/performance/src/services/perf_logger.test.ts @@ -36,7 +36,7 @@ describe('Performance Monitoring > perf_logger', () => { const IID = 'idasdfsffe'; const PAGE_URL = 'http://mock-page.com'; const APP_ID = '1:123:web:2er'; - const VISIBILITY_STATE = 3; + const VISIBILITY_STATE = attributeUtils.VisibilityState.UNKNOWN; const EFFECTIVE_CONNECTION_TYPE = 2; const SERVICE_WORKER_STATUS = 3; const TIME_ORIGIN = 1556512199893.9033; @@ -54,6 +54,7 @@ describe('Performance Monitoring > perf_logger', () => { Array<{ message: string; eventTime: number }>, void >; + const flushQueuedEventsStub = stub(transportService, 'flushQueuedEvents'); let getIidStub: SinonStub<[], string | undefined>; let clock: SinonFakeTimers; @@ -141,6 +142,8 @@ describe('Performance Monitoring > perf_logger', () => { expect(addToQueueStub.getCall(0).args[0].message).to.be.equal( EXPECTED_TRACE_MESSAGE ); + // Only page load traces should be immediately flushed + expect(flushQueuedEventsStub).not.to.be.called; }); it('does not log an event if cookies are disabled in the browser', () => { @@ -182,6 +185,8 @@ describe('Performance Monitoring > perf_logger', () => { expect(addToQueueStub.getCall(0).args[0].message).to.be.equal( EXPECTED_TRACE_MESSAGE ); + // Only page load traces should be immediately flushed + expect(flushQueuedEventsStub).not.to.be.called; }); it('ascertains that the max number of custom attributes allowed is 5', () => { @@ -207,6 +212,8 @@ describe('Performance Monitoring > perf_logger', () => { expect(addToQueueStub.getCall(0).args[0].message).to.be.equal( EXPECTED_TRACE_MESSAGE ); + // Only page load traces should be immediately flushed + expect(flushQueuedEventsStub).not.to.be.called; }); }); @@ -222,7 +229,9 @@ describe('Performance Monitoring > perf_logger', () => { "application_process_state":0},"trace_metric":{"name":"_wt_${PAGE_URL}","is_auto":true,\ "client_start_time_us":${flooredStartTime},"duration_us":${DURATION * 1000},\ "counters":{"domInteractive":10000,"domContentLoadedEventEnd":20000,"loadEventEnd":10000,\ -"_fp":40000,"_fcp":50000,"_fid":90000}}}`; +"_fp":40000,"_fcp":50000,"_fid":90000,"_lcp":3999,"_cls":250,"_inp":100},\ +"custom_attributes":{"lcp_element":"lcp-element","cls_largestShiftTarget":"cls-element",\ +"inp_interactionTarget":"inp-element"}}}`; stub(initializationService, 'isPerfInitialized').returns(true); getIidStub.returns(IID); SettingsService.getInstance().loggingEnabled = true; @@ -275,6 +284,11 @@ describe('Performance Monitoring > perf_logger', () => { performanceController, navigationTimings, paintTimings, + { + lcp: { value: 3.999, elementAttribution: 'lcp-element' }, + inp: { value: 0.1, elementAttribution: 'inp-element' }, + cls: { value: 0.250, elementAttribution: 'cls-element' }, + }, 90 ); clock.tick(1); @@ -283,6 +297,7 @@ describe('Performance Monitoring > perf_logger', () => { expect(addToQueueStub.getCall(0).args[0].message).to.be.equal( EXPECTED_TRACE_MESSAGE ); + expect(flushQueuedEventsStub).to.be.called; }); }); From 7ad639a444885e87d165b885627490565a535b66 Mon Sep 17 00:00:00 2001 From: Bryan Atkinson Date: Mon, 18 Nov 2024 21:34:43 +0000 Subject: [PATCH 04/15] Remove .only in test. --- .../performance/src/services/oob_resources_service.test.ts | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/packages/performance/src/services/oob_resources_service.test.ts b/packages/performance/src/services/oob_resources_service.test.ts index f01fa1505d6..4b9f685fcbf 100644 --- a/packages/performance/src/services/oob_resources_service.test.ts +++ b/packages/performance/src/services/oob_resources_service.test.ts @@ -185,8 +185,7 @@ describe('Firebase Performance > oob_resources_service', () => { api.onFirstInputDelay = undefined; }); - // eslint-disable-next-line no-restricted-properties - describe.only('setupOobResources', () => { + describe('setupOobResources', () => { it('does not start if there is no iid', () => { getIidStub.returns(undefined); setupOobResources(performanceController); From 61295c56f01adf4907c9a4ec8036523ffee1b3e7 Mon Sep 17 00:00:00 2001 From: Bryan Atkinson Date: Mon, 18 Nov 2024 21:57:11 +0000 Subject: [PATCH 05/15] Update transport_service test. --- .../src/services/transport_service.test.ts | 85 ++++--------------- .../src/services/transport_service.ts | 14 --- 2 files changed, 16 insertions(+), 83 deletions(-) diff --git a/packages/performance/src/services/transport_service.test.ts b/packages/performance/src/services/transport_service.test.ts index c249206c33e..f5990b3e887 100644 --- a/packages/performance/src/services/transport_service.test.ts +++ b/packages/performance/src/services/transport_service.test.ts @@ -15,7 +15,7 @@ * limitations under the License. */ -import { stub, useFakeTimers, SinonStub, SinonFakeTimers, match } from 'sinon'; +import { spy, useFakeTimers, SinonFakeTimers } from 'sinon'; import { use, expect } from 'chai'; import sinonChai from 'sinon-chai'; import { @@ -27,15 +27,12 @@ import { SettingsService } from './settings_service'; use(sinonChai); -describe('Firebase Performance > transport_service', () => { - let fetchStub: SinonStub< - [RequestInfo | URL, RequestInit?], - Promise - >; +// eslint-disable-next-line no-restricted-properties +describe.only('Firebase Performance > transport_service', () => { + const sendBeaconSpy = spy(navigator, 'sendBeacon'); const INITIAL_SEND_TIME_DELAY_MS = 5.5 * 1000; const DEFAULT_SEND_INTERVAL_MS = 10 * 1000; const MAX_EVENT_COUNT_PER_REQUEST = 1000; - const TRANSPORT_DELAY_INTERVAL = 10000; // Starts date at timestamp 1 instead of 0, otherwise it causes validation errors. let clock: SinonFakeTimers; const testTransportHandler = transportHandler((...args) => { @@ -43,15 +40,14 @@ describe('Firebase Performance > transport_service', () => { }); beforeEach(() => { - fetchStub = stub(window, 'fetch'); clock = useFakeTimers(1); setupTransportService(); }); afterEach(() => { - fetchStub.restore(); clock.restore(); resetTransportService(); + sendBeaconSpy.resetHistory(); }); it('throws an error when logging an empty message', () => { @@ -61,43 +57,21 @@ describe('Firebase Performance > transport_service', () => { }); it('does not attempt to log an event after INITIAL_SEND_TIME_DELAY_MS if queue is empty', () => { - fetchStub.resolves( - new Response('', { - status: 200, - headers: { 'Content-type': 'application/json' } - }) - ); - clock.tick(INITIAL_SEND_TIME_DELAY_MS); - expect(fetchStub).to.not.have.been.called; + expect(sendBeaconSpy).to.not.have.been.called; }); it('attempts to log an event after DEFAULT_SEND_INTERVAL_MS if queue not empty', async () => { - fetchStub.resolves( - new Response('', { - status: 200, - headers: { 'Content-type': 'application/json' } - }) - ); - clock.tick(INITIAL_SEND_TIME_DELAY_MS); testTransportHandler('someEvent'); clock.tick(DEFAULT_SEND_INTERVAL_MS); - expect(fetchStub).to.have.been.calledOnce; + expect(sendBeaconSpy).to.have.been.calledOnce; }); it('successful send a message to transport', () => { - const setting = SettingsService.getInstance(); - const flTransportFullUrl = - setting.flTransportEndpointUrl + '?key=' + setting.transportKey; - fetchStub.withArgs(flTransportFullUrl, match.any).resolves( - // DELETE_REQUEST means event dispatch is successful. - generateSuccessResponse() - ); - testTransportHandler('event1'); clock.tick(INITIAL_SEND_TIME_DELAY_MS); - expect(fetchStub).to.have.been.calledOnce; + expect(sendBeaconSpy).to.have.been.calledOnce; }); it('sends up to the maximum event limit in one request', async () => { @@ -106,11 +80,6 @@ describe('Firebase Performance > transport_service', () => { const flTransportFullUrl = setting.flTransportEndpointUrl + '?key=' + setting.transportKey; - // Returns successful response from fl for logRequests. - const response = generateSuccessResponse(); - stub(response, 'json').resolves(JSON.parse(generateSuccessResponseBody())); - fetchStub.resolves(response); - // Act // Generate 1020 events, which should be dispatched in two batches (1000 events and 20 events). for (let i = 0; i < 1020; i++) { @@ -131,10 +100,10 @@ describe('Firebase Performance > transport_service', () => { 'event_time_ms': '1' }); } - expect(fetchStub).which.to.have.been.calledWith(flTransportFullUrl, { - method: 'POST', - body: JSON.stringify(firstLogRequest) - }); + expect(sendBeaconSpy).which.to.have.been.calledWith( + flTransportFullUrl, + JSON.stringify(firstLogRequest) + ); // Expects the second logRequest which contains remaining 20 events; const secondLogRequest = generateLogRequest('15501'); for (let i = 0; i < 20; i++) { @@ -144,10 +113,10 @@ describe('Firebase Performance > transport_service', () => { 'event_time_ms': '1' }); } - expect(fetchStub).calledWith(flTransportFullUrl, { - method: 'POST', - body: JSON.stringify(secondLogRequest) - }); + expect(sendBeaconSpy).calledWith( + flTransportFullUrl, + JSON.stringify(secondLogRequest) + ); }); function generateLogRequest(requestTimeMs: string): any { @@ -161,26 +130,4 @@ describe('Firebase Performance > transport_service', () => { 'log_event': [] as any }; } - - function generateSuccessResponse(): Response { - return new Response(generateSuccessResponseBody(), { - status: 200, - headers: { 'Content-type': 'application/json' } - }); - } - - function generateSuccessResponseBody(): string { - return ( - '{\ - "nextRequestWaitMillis": "' + - TRANSPORT_DELAY_INTERVAL + - '",\ - "logResponseDetails": [\ - {\ - "responseAction": "DELETE_REQUEST"\ - }\ - ]\ - }' - ); - } }); diff --git a/packages/performance/src/services/transport_service.ts b/packages/performance/src/services/transport_service.ts index d075d30775f..b29f3541c5d 100644 --- a/packages/performance/src/services/transport_service.ts +++ b/packages/performance/src/services/transport_service.ts @@ -17,7 +17,6 @@ import { SettingsService } from './settings_service'; import { ERROR_FACTORY, ErrorCode } from '../utils/errors'; -import { consoleLogger } from '../utils/console_logger'; const DEFAULT_SEND_INTERVAL_MS = 10 * 1000; const INITIAL_SEND_TIME_DELAY_MS = 5.5 * 1000; @@ -106,19 +105,6 @@ function dispatchQueueEvents(): void { function postToFlEndpoint(data: TransportBatchLogFormat): boolean { const flTransportFullUrl = SettingsService.getInstance().getFlTransportFullUrl(); - for (const event of data.log_event) { - const ext = JSON.parse(event.source_extension_json_proto3); - if (ext.network_request_metric) { - consoleLogger.info( - ` >>>>>> network_request: ${ext.network_request_metric.url}` - ); - } - if (ext.trace_metric) { - consoleLogger.info( - ` >>>>>> trace: ${JSON.stringify(ext.trace_metric)}` - ); - } - } return navigator.sendBeacon(flTransportFullUrl, JSON.stringify(data)); } From 51104e804da43a6b81bccb53099f09ec439a175f Mon Sep 17 00:00:00 2001 From: Bryan Atkinson Date: Mon, 18 Nov 2024 22:12:47 +0000 Subject: [PATCH 06/15] Remove flush from tests due to globals conflict. --- .../src/services/oob_resources_service.test.ts | 1 + packages/performance/src/services/perf_logger.test.ts | 9 +-------- .../performance/src/services/transport_service.test.ts | 3 +-- 3 files changed, 3 insertions(+), 10 deletions(-) diff --git a/packages/performance/src/services/oob_resources_service.test.ts b/packages/performance/src/services/oob_resources_service.test.ts index 4b9f685fcbf..57de44a19e4 100644 --- a/packages/performance/src/services/oob_resources_service.test.ts +++ b/packages/performance/src/services/oob_resources_service.test.ts @@ -43,6 +43,7 @@ import { LCPMetricWithAttribution } from 'web-vitals/attribution'; +// eslint-disable-next-line no-restricted-properties describe('Firebase Performance > oob_resources_service', () => { const MOCK_ID = 'idasdfsffe'; diff --git a/packages/performance/src/services/perf_logger.test.ts b/packages/performance/src/services/perf_logger.test.ts index 4f4068831b8..f9f69af3c8b 100644 --- a/packages/performance/src/services/perf_logger.test.ts +++ b/packages/performance/src/services/perf_logger.test.ts @@ -32,6 +32,7 @@ import { mergeStrings } from '../utils/string_merger'; import { FirebaseInstallations } from '@firebase/installations-types'; import { PerformanceController } from '../controllers/perf'; +// eslint-disable-next-line no-restricted-properties describe('Performance Monitoring > perf_logger', () => { const IID = 'idasdfsffe'; const PAGE_URL = 'http://mock-page.com'; @@ -54,7 +55,6 @@ describe('Performance Monitoring > perf_logger', () => { Array<{ message: string; eventTime: number }>, void >; - const flushQueuedEventsStub = stub(transportService, 'flushQueuedEvents'); let getIidStub: SinonStub<[], string | undefined>; let clock: SinonFakeTimers; @@ -142,8 +142,6 @@ describe('Performance Monitoring > perf_logger', () => { expect(addToQueueStub.getCall(0).args[0].message).to.be.equal( EXPECTED_TRACE_MESSAGE ); - // Only page load traces should be immediately flushed - expect(flushQueuedEventsStub).not.to.be.called; }); it('does not log an event if cookies are disabled in the browser', () => { @@ -185,8 +183,6 @@ describe('Performance Monitoring > perf_logger', () => { expect(addToQueueStub.getCall(0).args[0].message).to.be.equal( EXPECTED_TRACE_MESSAGE ); - // Only page load traces should be immediately flushed - expect(flushQueuedEventsStub).not.to.be.called; }); it('ascertains that the max number of custom attributes allowed is 5', () => { @@ -212,8 +208,6 @@ describe('Performance Monitoring > perf_logger', () => { expect(addToQueueStub.getCall(0).args[0].message).to.be.equal( EXPECTED_TRACE_MESSAGE ); - // Only page load traces should be immediately flushed - expect(flushQueuedEventsStub).not.to.be.called; }); }); @@ -297,7 +291,6 @@ describe('Performance Monitoring > perf_logger', () => { expect(addToQueueStub.getCall(0).args[0].message).to.be.equal( EXPECTED_TRACE_MESSAGE ); - expect(flushQueuedEventsStub).to.be.called; }); }); diff --git a/packages/performance/src/services/transport_service.test.ts b/packages/performance/src/services/transport_service.test.ts index f5990b3e887..c606aa42ee0 100644 --- a/packages/performance/src/services/transport_service.test.ts +++ b/packages/performance/src/services/transport_service.test.ts @@ -27,8 +27,7 @@ import { SettingsService } from './settings_service'; use(sinonChai); -// eslint-disable-next-line no-restricted-properties -describe.only('Firebase Performance > transport_service', () => { +describe('Firebase Performance > transport_service', () => { const sendBeaconSpy = spy(navigator, 'sendBeacon'); const INITIAL_SEND_TIME_DELAY_MS = 5.5 * 1000; const DEFAULT_SEND_INTERVAL_MS = 10 * 1000; From 0158070f6def8794bf38858923fff785d74ef922 Mon Sep 17 00:00:00 2001 From: Bryan Atkinson Date: Tue, 19 Nov 2024 14:31:04 +0000 Subject: [PATCH 07/15] Run format --- packages/performance/src/services/oob_resources_service.ts | 2 +- packages/performance/src/services/perf_logger.test.ts | 2 +- packages/performance/src/services/perf_logger.ts | 7 +++++-- 3 files changed, 7 insertions(+), 4 deletions(-) diff --git a/packages/performance/src/services/oob_resources_service.ts b/packages/performance/src/services/oob_resources_service.ts index bf9bf620c22..4747b3aa72a 100644 --- a/packages/performance/src/services/oob_resources_service.ts +++ b/packages/performance/src/services/oob_resources_service.ts @@ -18,7 +18,7 @@ import { CLSMetricWithAttribution, INPMetricWithAttribution, - LCPMetricWithAttribution, + LCPMetricWithAttribution } from 'web-vitals/attribution'; import { TRACE_MEASURE_PREFIX } from '../constants'; diff --git a/packages/performance/src/services/perf_logger.test.ts b/packages/performance/src/services/perf_logger.test.ts index f9f69af3c8b..3116769f7e1 100644 --- a/packages/performance/src/services/perf_logger.test.ts +++ b/packages/performance/src/services/perf_logger.test.ts @@ -281,7 +281,7 @@ describe('Performance Monitoring > perf_logger', () => { { lcp: { value: 3.999, elementAttribution: 'lcp-element' }, inp: { value: 0.1, elementAttribution: 'inp-element' }, - cls: { value: 0.250, elementAttribution: 'cls-element' }, + cls: { value: 0.25, elementAttribution: 'cls-element' } }, 90 ); diff --git a/packages/performance/src/services/perf_logger.ts b/packages/performance/src/services/perf_logger.ts index c51f3e8640e..57bd7cdeca4 100644 --- a/packages/performance/src/services/perf_logger.ts +++ b/packages/performance/src/services/perf_logger.ts @@ -85,7 +85,10 @@ interface TraceMetric { } interface Logger { - send: (resource: NetworkRequest | Trace, resourceType: ResourceType) => void | undefined; + send: ( + resource: NetworkRequest | Trace, + resourceType: ResourceType + ) => void | undefined; flush: () => void; } @@ -99,7 +102,7 @@ function sendLog( if (!logger) { logger = { send: transportHandler(serializer), - flush: flushQueuedEvents, + flush: flushQueuedEvents }; } logger.send(resource, resourceType); From 66ffeb0f8704c4d76132815fb2116c5a86faf258 Mon Sep 17 00:00:00 2001 From: Bryan Atkinson Date: Tue, 26 Nov 2024 19:50:53 +0000 Subject: [PATCH 08/15] Remove FID wait timeout on OOB trace send. This gets sent at first unload now, so no need to add additional timeouts. --- .../services/oob_resources_service.test.ts | 24 --------------- .../src/services/oob_resources_service.ts | 30 +++++-------------- 2 files changed, 7 insertions(+), 47 deletions(-) diff --git a/packages/performance/src/services/oob_resources_service.test.ts b/packages/performance/src/services/oob_resources_service.test.ts index 57de44a19e4..13b844512d1 100644 --- a/packages/performance/src/services/oob_resources_service.test.ts +++ b/packages/performance/src/services/oob_resources_service.test.ts @@ -250,30 +250,6 @@ describe('Firebase Performance > oob_resources_service', () => { ); }); - it('waits for first input delay if polyfill is available', () => { - getIidStub.returns(MOCK_ID); - const api = Api.getInstance(); - //@ts-ignore Assignment to read-only property. - api.onFirstInputDelay = stub(); - setupOobResources(performanceController); - clock.tick(1); - - // Force the page load event to be sent - stub(mockWindow.document, 'visibilityState').value('hidden'); - callEventListener('visibilitychange'); - - expect(api.onFirstInputDelay).to.be.called; - expect(createOobTraceStub).not.to.be.called; - clock.tick(5000); - expect(createOobTraceStub).to.be.calledWithExactly( - performanceController, - [NAVIGATION_PERFORMANCE_ENTRY], - [PAINT_PERFORMANCE_ENTRY], - {}, - undefined - ); - }); - it('logs first input delay if polyfill is available and callback is called', () => { getIidStub.returns(MOCK_ID); const api = Api.getInstance(); diff --git a/packages/performance/src/services/oob_resources_service.ts b/packages/performance/src/services/oob_resources_service.ts index 4747b3aa72a..16bc096d1fb 100644 --- a/packages/performance/src/services/oob_resources_service.ts +++ b/packages/performance/src/services/oob_resources_service.ts @@ -30,8 +30,6 @@ import { WebVitalMetrics } from '../resources/web_vitals'; import { Api } from './api_service'; import { getIid } from './iid_service'; -const FID_WAIT_TIME_MS = 5000; - let webVitalMetrics: WebVitalMetrics = {}; let sentPageLoadTrace: boolean = false; let firstInputDelay: number | undefined; @@ -147,27 +145,13 @@ function sendOobTrace(performanceController: PerformanceController): void { 'navigation' ) as PerformanceNavigationTiming[]; const paintTimings = api.getEntriesByType('paint'); - // If First Input Delay polyfill is added to the page, report the fid value. - // https://github.com/GoogleChromeLabs/first-input-delay - if (api.onFirstInputDelay && !firstInputDelay) { - setTimeout(() => { - Trace.createOobTrace( - performanceController, - navigationTimings, - paintTimings, - webVitalMetrics, - firstInputDelay - ); - }, FID_WAIT_TIME_MS); - } else { - Trace.createOobTrace( - performanceController, - navigationTimings, - paintTimings, - webVitalMetrics, - firstInputDelay - ); - } + Trace.createOobTrace( + performanceController, + navigationTimings, + paintTimings, + webVitalMetrics, + firstInputDelay + ); } } From 19cf2c41ceb31288492b39ea71a040ea1fa6daf8 Mon Sep 17 00:00:00 2001 From: Bryan Atkinson Date: Wed, 27 Nov 2024 14:37:25 +0000 Subject: [PATCH 09/15] Queue OOB trace instead of sending right away. The web vitals library often updates the values at unload time, and os queuing this until the end means those latest values get captured. --- .../services/oob_resources_service.test.ts | 7 +++++++ .../src/services/oob_resources_service.ts | 19 ++++++++++++------- 2 files changed, 19 insertions(+), 7 deletions(-) diff --git a/packages/performance/src/services/oob_resources_service.test.ts b/packages/performance/src/services/oob_resources_service.test.ts index 13b844512d1..05205f75a88 100644 --- a/packages/performance/src/services/oob_resources_service.test.ts +++ b/packages/performance/src/services/oob_resources_service.test.ts @@ -220,6 +220,7 @@ describe('Firebase Performance > oob_resources_service', () => { stub(mockWindow.document, 'visibilityState').value('hidden'); callEventListener('visibilitychange'); + clock.tick(1); expect(getEntriesByTypeStub).to.be.calledWith('navigation'); expect(getEntriesByTypeStub).to.be.calledWith('paint'); @@ -238,6 +239,7 @@ describe('Firebase Performance > oob_resources_service', () => { clock.tick(1); callEventListener('pagehide'); + clock.tick(1); expect(getEntriesByTypeStub).to.be.calledWith('navigation'); expect(getEntriesByTypeStub).to.be.calledWith('paint'); @@ -268,6 +270,7 @@ describe('Firebase Performance > oob_resources_service', () => { // Force the page load event to be sent stub(mockWindow.document, 'visibilityState').value('hidden'); callEventListener('visibilitychange'); + clock.tick(1); expect(createOobTraceStub).to.be.calledWithExactly( performanceController, @@ -303,6 +306,7 @@ describe('Firebase Performance > oob_resources_service', () => { // Force the page load event to be sent stub(mockWindow.document, 'visibilityState').value('hidden'); callEventListener('visibilitychange'); + clock.tick(1); expect(createOobTraceStub).to.be.calledWithExactly( performanceController, @@ -330,6 +334,7 @@ describe('Firebase Performance > oob_resources_service', () => { // Force the page load event to be sent stub(mockWindow.document, 'visibilityState').value('hidden'); callEventListener('visibilitychange'); + clock.tick(1); expect(createOobTraceStub).to.be.calledWithExactly( performanceController, @@ -358,6 +363,7 @@ describe('Firebase Performance > oob_resources_service', () => { // Force the page load event to be sent stub(mockWindow.document, 'visibilityState').value('hidden'); callEventListener('visibilitychange'); + clock.tick(1); expect(createOobTraceStub).to.be.calledWithExactly( performanceController, @@ -392,6 +398,7 @@ describe('Firebase Performance > oob_resources_service', () => { // Force the page load event to be sent stub(mockWindow.document, 'visibilityState').value('hidden'); callEventListener('visibilitychange'); + clock.tick(1); expect(createOobTraceStub).to.be.calledWithExactly( performanceController, diff --git a/packages/performance/src/services/oob_resources_service.ts b/packages/performance/src/services/oob_resources_service.ts index 16bc096d1fb..7e27e247b8d 100644 --- a/packages/performance/src/services/oob_resources_service.ts +++ b/packages/performance/src/services/oob_resources_service.ts @@ -145,13 +145,18 @@ function sendOobTrace(performanceController: PerformanceController): void { 'navigation' ) as PerformanceNavigationTiming[]; const paintTimings = api.getEntriesByType('paint'); - Trace.createOobTrace( - performanceController, - navigationTimings, - paintTimings, - webVitalMetrics, - firstInputDelay - ); + + // On page unload web vitals may be updated so queue the oob trace creation + // so that these updates have time to be included. + setTimeout(() => { + Trace.createOobTrace( + performanceController, + navigationTimings, + paintTimings, + webVitalMetrics, + firstInputDelay + ); + }, 0); } } From b033187f5331f0f6c45abcfa1e3bc71c88b31596 Mon Sep 17 00:00:00 2001 From: Bryan Atkinson Date: Tue, 10 Dec 2024 12:36:10 -0500 Subject: [PATCH 10/15] Update tests --- .../services/oob_resources_service.test.ts | 20 ++--- .../src/services/transport_service.test.ts | 73 ++++++++++++++++--- .../src/services/transport_service.ts | 34 ++++++++- 3 files changed, 105 insertions(+), 22 deletions(-) diff --git a/packages/performance/src/services/oob_resources_service.test.ts b/packages/performance/src/services/oob_resources_service.test.ts index 05205f75a88..e927d21fd09 100644 --- a/packages/performance/src/services/oob_resources_service.test.ts +++ b/packages/performance/src/services/oob_resources_service.test.ts @@ -106,7 +106,7 @@ describe('Firebase Performance > oob_resources_service', () => { [EntryType, (entry: PerformanceEntry) => void], void >; - let createOobTraceStub: SinonSpy< + let createOobTraceSpy: SinonSpy< [ PerformanceController, PerformanceNavigationTiming[], @@ -170,7 +170,7 @@ describe('Firebase Performance > oob_resources_service', () => { } ); setupObserverStub = stub(Api.prototype, 'setupObserver'); - createOobTraceStub = spy(Trace, 'createOobTrace'); + createOobTraceSpy = spy(Trace, 'createOobTrace'); const api = Api.getInstance(); lcpSpy = spy(api, 'onLCP'); inpSpy = spy(api, 'onINP'); @@ -210,7 +210,7 @@ describe('Firebase Performance > oob_resources_service', () => { clock.tick(1); expect(apiGetInstanceSpy).to.be.called; - expect(createOobTraceStub).not.to.be.called; + expect(createOobTraceSpy).not.to.be.called; }); it('creates page load trace after hidden', () => { @@ -224,7 +224,7 @@ describe('Firebase Performance > oob_resources_service', () => { expect(getEntriesByTypeStub).to.be.calledWith('navigation'); expect(getEntriesByTypeStub).to.be.calledWith('paint'); - expect(createOobTraceStub).to.be.calledWithExactly( + expect(createOobTraceSpy).to.be.calledWithExactly( performanceController, [NAVIGATION_PERFORMANCE_ENTRY], [PAINT_PERFORMANCE_ENTRY], @@ -243,7 +243,7 @@ describe('Firebase Performance > oob_resources_service', () => { expect(getEntriesByTypeStub).to.be.calledWith('navigation'); expect(getEntriesByTypeStub).to.be.calledWith('paint'); - expect(createOobTraceStub).to.be.calledWithExactly( + expect(createOobTraceSpy).to.be.calledWithExactly( performanceController, [NAVIGATION_PERFORMANCE_ENTRY], [PAINT_PERFORMANCE_ENTRY], @@ -272,7 +272,7 @@ describe('Firebase Performance > oob_resources_service', () => { callEventListener('visibilitychange'); clock.tick(1); - expect(createOobTraceStub).to.be.calledWithExactly( + expect(createOobTraceSpy).to.be.calledWithExactly( performanceController, [NAVIGATION_PERFORMANCE_ENTRY], [PAINT_PERFORMANCE_ENTRY], @@ -308,7 +308,7 @@ describe('Firebase Performance > oob_resources_service', () => { callEventListener('visibilitychange'); clock.tick(1); - expect(createOobTraceStub).to.be.calledWithExactly( + expect(createOobTraceSpy).to.be.calledWithExactly( performanceController, [NAVIGATION_PERFORMANCE_ENTRY], [PAINT_PERFORMANCE_ENTRY], @@ -336,7 +336,7 @@ describe('Firebase Performance > oob_resources_service', () => { callEventListener('visibilitychange'); clock.tick(1); - expect(createOobTraceStub).to.be.calledWithExactly( + expect(createOobTraceSpy).to.be.calledWithExactly( performanceController, [NAVIGATION_PERFORMANCE_ENTRY], [PAINT_PERFORMANCE_ENTRY], @@ -365,7 +365,7 @@ describe('Firebase Performance > oob_resources_service', () => { callEventListener('visibilitychange'); clock.tick(1); - expect(createOobTraceStub).to.be.calledWithExactly( + expect(createOobTraceSpy).to.be.calledWithExactly( performanceController, [NAVIGATION_PERFORMANCE_ENTRY], [PAINT_PERFORMANCE_ENTRY], @@ -400,7 +400,7 @@ describe('Firebase Performance > oob_resources_service', () => { callEventListener('visibilitychange'); clock.tick(1); - expect(createOobTraceStub).to.be.calledWithExactly( + expect(createOobTraceSpy).to.be.calledWithExactly( performanceController, [NAVIGATION_PERFORMANCE_ENTRY], [PAINT_PERFORMANCE_ENTRY], diff --git a/packages/performance/src/services/transport_service.test.ts b/packages/performance/src/services/transport_service.test.ts index c606aa42ee0..c288a4cbe8a 100644 --- a/packages/performance/src/services/transport_service.test.ts +++ b/packages/performance/src/services/transport_service.test.ts @@ -15,7 +15,7 @@ * limitations under the License. */ -import { spy, useFakeTimers, SinonFakeTimers } from 'sinon'; +import { stub, useFakeTimers, SinonFakeTimers } from 'sinon'; import { use, expect } from 'chai'; import sinonChai from 'sinon-chai'; import { @@ -27,8 +27,10 @@ import { SettingsService } from './settings_service'; use(sinonChai); -describe('Firebase Performance > transport_service', () => { - const sendBeaconSpy = spy(navigator, 'sendBeacon'); +/* eslint-disable no-restricted-properties */ +describe.only('Firebase Performance > transport_service', () => { + const sendBeaconStub = stub(navigator, 'sendBeacon'); + const fetchStub = stub(window, 'fetch'); const INITIAL_SEND_TIME_DELAY_MS = 5.5 * 1000; const DEFAULT_SEND_INTERVAL_MS = 10 * 1000; const MAX_EVENT_COUNT_PER_REQUEST = 1000; @@ -41,12 +43,14 @@ describe('Firebase Performance > transport_service', () => { beforeEach(() => { clock = useFakeTimers(1); setupTransportService(); + sendBeaconStub.returns(true); }); afterEach(() => { clock.restore(); resetTransportService(); - sendBeaconSpy.resetHistory(); + sendBeaconStub.restore(); + fetchStub.restore(); }); it('throws an error when logging an empty message', () => { @@ -57,20 +61,23 @@ describe('Firebase Performance > transport_service', () => { it('does not attempt to log an event after INITIAL_SEND_TIME_DELAY_MS if queue is empty', () => { clock.tick(INITIAL_SEND_TIME_DELAY_MS); - expect(sendBeaconSpy).to.not.have.been.called; + expect(sendBeaconStub).to.not.have.been.called; + expect(fetchStub).to.not.have.been.called; }); it('attempts to log an event after DEFAULT_SEND_INTERVAL_MS if queue not empty', async () => { clock.tick(INITIAL_SEND_TIME_DELAY_MS); testTransportHandler('someEvent'); clock.tick(DEFAULT_SEND_INTERVAL_MS); - expect(sendBeaconSpy).to.have.been.calledOnce; + expect(sendBeaconStub).to.have.been.calledOnce; + expect(fetchStub).to.not.have.been.called; }); it('successful send a message to transport', () => { testTransportHandler('event1'); clock.tick(INITIAL_SEND_TIME_DELAY_MS); - expect(sendBeaconSpy).to.have.been.calledOnce; + expect(sendBeaconStub).to.have.been.calledOnce; + expect(fetchStub).to.not.have.been.called; }); it('sends up to the maximum event limit in one request', async () => { @@ -99,7 +106,7 @@ describe('Firebase Performance > transport_service', () => { 'event_time_ms': '1' }); } - expect(sendBeaconSpy).which.to.have.been.calledWith( + expect(sendBeaconStub).which.to.have.been.calledWith( flTransportFullUrl, JSON.stringify(firstLogRequest) ); @@ -112,7 +119,55 @@ describe('Firebase Performance > transport_service', () => { 'event_time_ms': '1' }); } - expect(sendBeaconSpy).calledWith( + expect(sendBeaconStub).calledWith( + flTransportFullUrl, + JSON.stringify(secondLogRequest) + ); + expect(fetchStub).to.not.have.been.called; + }); + + it('falls back to fetch if sendBeacon fails.', async () => { + sendBeaconStub.returns(false); + // Arrange + const setting = SettingsService.getInstance(); + const flTransportFullUrl = + setting.flTransportEndpointUrl + '?key=' + setting.transportKey; + + // Act + // Generate 1020 events, which should be dispatched in two batches (1000 events and 20 events). + for (let i = 0; i < 1020; i++) { + testTransportHandler('event' + i); + } + // Wait for first and second event dispatch to happen. + clock.tick(INITIAL_SEND_TIME_DELAY_MS); + // This is to resolve the floating promise chain in transport service. + await Promise.resolve().then().then().then(); + clock.tick(DEFAULT_SEND_INTERVAL_MS); + + // Assert + // Expects the first logRequest which contains first 1000 events. + const firstLogRequest = generateLogRequest('5501'); + for (let i = 0; i < MAX_EVENT_COUNT_PER_REQUEST; i++) { + firstLogRequest['log_event'].push({ + 'source_extension_json_proto3': 'event' + i, + 'event_time_ms': '1' + }); + } + expect(fetchStub).to.not.have.been.called; + expect(sendBeaconStub).which.to.have.been.calledWith( + flTransportFullUrl, + JSON.stringify(firstLogRequest) + ); + // Expects the second logRequest which contains remaining 20 events; + const secondLogRequest = generateLogRequest('15501'); + for (let i = 0; i < 20; i++) { + secondLogRequest['log_event'].push({ + 'source_extension_json_proto3': + 'event' + (MAX_EVENT_COUNT_PER_REQUEST + i), + 'event_time_ms': '1' + }); + } + expect(sendBeaconStub).calledWith( flTransportFullUrl, JSON.stringify(secondLogRequest) ); diff --git a/packages/performance/src/services/transport_service.ts b/packages/performance/src/services/transport_service.ts index b29f3541c5d..cf5e3972972 100644 --- a/packages/performance/src/services/transport_service.ts +++ b/packages/performance/src/services/transport_service.ts @@ -17,10 +17,14 @@ import { SettingsService } from './settings_service'; import { ERROR_FACTORY, ErrorCode } from '../utils/errors'; +import { consoleLogger } from '../utils/console_logger'; const DEFAULT_SEND_INTERVAL_MS = 10 * 1000; const INITIAL_SEND_TIME_DELAY_MS = 5.5 * 1000; const MAX_EVENT_COUNT_PER_REQUEST = 1000; +const DEFAULT_REMAINING_TRIES = 3; + +let remainingTries = DEFAULT_REMAINING_TRIES; interface BatchEvent { message: string; @@ -68,6 +72,11 @@ export function resetTransportService(): void { function processQueue(timeOffset: number): void { setTimeout(() => { + // If there is no remainingTries left, stop retrying. + if (remainingTries === 0) { + return; + } + if (queue.length > 0) { dispatchQueueEvents(); } @@ -99,13 +108,32 @@ function dispatchQueueEvents(): void { }; /* eslint-enable camelcase */ - postToFlEndpoint(data); + postToFlEndpoint(data) + .then(() => { + remainingTries = DEFAULT_REMAINING_TRIES; + }) + .catch(() => { + // If the request fails for some reason, add the events that were attempted + // back to the primary queue to retry later. + queue = [...staged, ...queue]; + remainingTries--; + consoleLogger.info(`Tries left: ${remainingTries}.`); + processQueue(DEFAULT_SEND_INTERVAL_MS); + }); } -function postToFlEndpoint(data: TransportBatchLogFormat): boolean { +function postToFlEndpoint(data: TransportBatchLogFormat): Promise { const flTransportFullUrl = SettingsService.getInstance().getFlTransportFullUrl(); - return navigator.sendBeacon(flTransportFullUrl, JSON.stringify(data)); + const body = JSON.stringify(data); + + return navigator.sendBeacon && navigator.sendBeacon(flTransportFullUrl, body) + ? Promise.resolve() + : fetch(flTransportFullUrl, { + method: 'POST', + body, + keepalive: true + }).then(); } function addToQueue(evt: BatchEvent): void { From 841fd9e9695379fb0fc102715c50b0567b1a09a9 Mon Sep 17 00:00:00 2001 From: Bryan Atkinson Date: Thu, 19 Dec 2024 09:52:37 -0500 Subject: [PATCH 11/15] Update tests --- .../src/services/transport_service.test.ts | 58 ++++--------------- 1 file changed, 12 insertions(+), 46 deletions(-) diff --git a/packages/performance/src/services/transport_service.test.ts b/packages/performance/src/services/transport_service.test.ts index c288a4cbe8a..b1107a07b76 100644 --- a/packages/performance/src/services/transport_service.test.ts +++ b/packages/performance/src/services/transport_service.test.ts @@ -15,7 +15,7 @@ * limitations under the License. */ -import { stub, useFakeTimers, SinonFakeTimers } from 'sinon'; +import { stub, useFakeTimers, SinonFakeTimers, SinonStub } from 'sinon'; import { use, expect } from 'chai'; import sinonChai from 'sinon-chai'; import { @@ -28,9 +28,9 @@ import { SettingsService } from './settings_service'; use(sinonChai); /* eslint-disable no-restricted-properties */ -describe.only('Firebase Performance > transport_service', () => { - const sendBeaconStub = stub(navigator, 'sendBeacon'); - const fetchStub = stub(window, 'fetch'); +describe('Firebase Performance > transport_service', () => { + let sendBeaconStub: SinonStub<[url: string | URL, data?: BodyInit | null | undefined], boolean>; + let fetchStub: SinonStub<[RequestInfo | URL, RequestInit?], Promise>; const INITIAL_SEND_TIME_DELAY_MS = 5.5 * 1000; const DEFAULT_SEND_INTERVAL_MS = 10 * 1000; const MAX_EVENT_COUNT_PER_REQUEST = 1000; @@ -43,7 +43,9 @@ describe.only('Firebase Performance > transport_service', () => { beforeEach(() => { clock = useFakeTimers(1); setupTransportService(); + sendBeaconStub = stub(navigator, 'sendBeacon'); sendBeaconStub.returns(true); + fetchStub = stub(window, 'fetch'); }); afterEach(() => { @@ -128,49 +130,13 @@ describe.only('Firebase Performance > transport_service', () => { it('falls back to fetch if sendBeacon fails.', async () => { sendBeaconStub.returns(false); - // Arrange - const setting = SettingsService.getInstance(); - const flTransportFullUrl = - setting.flTransportEndpointUrl + '?key=' + setting.transportKey; - - // Act - // Generate 1020 events, which should be dispatched in two batches (1000 events and 20 events). - for (let i = 0; i < 1020; i++) { - testTransportHandler('event' + i); - } - // Wait for first and second event dispatch to happen. + fetchStub.resolves(new Response('{}', { + status: 200, + headers: { 'Content-type': 'application/json' } + })); + testTransportHandler('event1'); clock.tick(INITIAL_SEND_TIME_DELAY_MS); - // This is to resolve the floating promise chain in transport service. - await Promise.resolve().then().then().then(); - clock.tick(DEFAULT_SEND_INTERVAL_MS); - - // Assert - // Expects the first logRequest which contains first 1000 events. - const firstLogRequest = generateLogRequest('5501'); - for (let i = 0; i < MAX_EVENT_COUNT_PER_REQUEST; i++) { - firstLogRequest['log_event'].push({ - 'source_extension_json_proto3': 'event' + i, - 'event_time_ms': '1' - }); - } - expect(fetchStub).to.not.have.been.called; - expect(sendBeaconStub).which.to.have.been.calledWith( - flTransportFullUrl, - JSON.stringify(firstLogRequest) - ); - // Expects the second logRequest which contains remaining 20 events; - const secondLogRequest = generateLogRequest('15501'); - for (let i = 0; i < 20; i++) { - secondLogRequest['log_event'].push({ - 'source_extension_json_proto3': - 'event' + (MAX_EVENT_COUNT_PER_REQUEST + i), - 'event_time_ms': '1' - }); - } - expect(sendBeaconStub).calledWith( - flTransportFullUrl, - JSON.stringify(secondLogRequest) - ); + expect(fetchStub).to.have.been.calledOnce; }); function generateLogRequest(requestTimeMs: string): any { From 3440ead937214bd220e570287ff92fdcd5f605d5 Mon Sep 17 00:00:00 2001 From: Bryan Atkinson Date: Thu, 19 Dec 2024 09:55:11 -0500 Subject: [PATCH 12/15] Run format --- .../src/services/transport_service.test.ts | 20 +++++++++++++------ 1 file changed, 14 insertions(+), 6 deletions(-) diff --git a/packages/performance/src/services/transport_service.test.ts b/packages/performance/src/services/transport_service.test.ts index b1107a07b76..124ce1f415b 100644 --- a/packages/performance/src/services/transport_service.test.ts +++ b/packages/performance/src/services/transport_service.test.ts @@ -29,8 +29,14 @@ use(sinonChai); /* eslint-disable no-restricted-properties */ describe('Firebase Performance > transport_service', () => { - let sendBeaconStub: SinonStub<[url: string | URL, data?: BodyInit | null | undefined], boolean>; - let fetchStub: SinonStub<[RequestInfo | URL, RequestInit?], Promise>; + let sendBeaconStub: SinonStub< + [url: string | URL, data?: BodyInit | null | undefined], + boolean + >; + let fetchStub: SinonStub< + [RequestInfo | URL, RequestInit?], + Promise + >; const INITIAL_SEND_TIME_DELAY_MS = 5.5 * 1000; const DEFAULT_SEND_INTERVAL_MS = 10 * 1000; const MAX_EVENT_COUNT_PER_REQUEST = 1000; @@ -130,10 +136,12 @@ describe('Firebase Performance > transport_service', () => { it('falls back to fetch if sendBeacon fails.', async () => { sendBeaconStub.returns(false); - fetchStub.resolves(new Response('{}', { - status: 200, - headers: { 'Content-type': 'application/json' } - })); + fetchStub.resolves( + new Response('{}', { + status: 200, + headers: { 'Content-type': 'application/json' } + }) + ); testTransportHandler('event1'); clock.tick(INITIAL_SEND_TIME_DELAY_MS); expect(fetchStub).to.have.been.calledOnce; From bbbfc06b92160ab2182b0e5f3adbe5d7fff50981 Mon Sep 17 00:00:00 2001 From: Bryan Atkinson Date: Mon, 6 Jan 2025 15:25:39 -0500 Subject: [PATCH 13/15] Add changeset --- .changeset/kind-dingos-work.md | 5 +++++ 1 file changed, 5 insertions(+) create mode 100644 .changeset/kind-dingos-work.md diff --git a/.changeset/kind-dingos-work.md b/.changeset/kind-dingos-work.md new file mode 100644 index 00000000000..a553a678221 --- /dev/null +++ b/.changeset/kind-dingos-work.md @@ -0,0 +1,5 @@ +--- +'@firebase/performance': minor +--- + +Collect web vital metrics (INP,CLS,LCP) as part of page load event. From bc86a9e5fd24261642b58d001d98116ea3cf2861 Mon Sep 17 00:00:00 2001 From: Bryan Atkinson Date: Tue, 7 Jan 2025 09:29:09 -0500 Subject: [PATCH 14/15] Update changeset to include firebase --- .changeset/kind-dingos-work.md | 1 + 1 file changed, 1 insertion(+) diff --git a/.changeset/kind-dingos-work.md b/.changeset/kind-dingos-work.md index a553a678221..486a6dfb6cf 100644 --- a/.changeset/kind-dingos-work.md +++ b/.changeset/kind-dingos-work.md @@ -1,5 +1,6 @@ --- '@firebase/performance': minor +'firebase': minor --- Collect web vital metrics (INP,CLS,LCP) as part of page load event. From 140f3c35ea34d7257410fb61d996fc9709f9ae38 Mon Sep 17 00:00:00 2001 From: Bryan Atkinson Date: Tue, 21 Jan 2025 16:41:35 -0500 Subject: [PATCH 15/15] Fix package.json --- packages/performance/package.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/performance/package.json b/packages/performance/package.json index 6bf5588b272..493ccc46dc3 100644 --- a/packages/performance/package.json +++ b/packages/performance/package.json @@ -40,7 +40,7 @@ "@firebase/installations": "0.6.12", "@firebase/util": "1.10.3", "@firebase/component": "0.6.12", - "tslib": "^2.1.0" + "tslib": "^2.1.0", "web-vitals": "^4.2.4" }, "license": "Apache-2.0",