diff --git a/.changeset/nervous-needles-sit.md b/.changeset/nervous-needles-sit.md new file mode 100644 index 00000000000..77594e263b0 --- /dev/null +++ b/.changeset/nervous-needles-sit.md @@ -0,0 +1,5 @@ +--- +'@firebase/performance': patch +--- + +Fix bug where events are not sent if they exceed sendBeacon payload limit diff --git a/packages/performance/src/services/remote_config_service.test.ts b/packages/performance/src/services/remote_config_service.test.ts index 78f1b1b4462..49b8893140f 100644 --- a/packages/performance/src/services/remote_config_service.test.ts +++ b/packages/performance/src/services/remote_config_service.test.ts @@ -40,7 +40,8 @@ describe('Performance Monitoring > remote_config_service', () => { "fpr_log_endpoint_url":"https://firebaselogging.test.com",\ "fpr_log_transport_key":"pseudo-transport-key",\ "fpr_log_source":"2","fpr_vc_network_request_sampling_rate":"0.250000",\ - "fpr_vc_session_sampling_rate":"0.250000","fpr_vc_trace_sampling_rate":"0.500000"},\ + "fpr_vc_session_sampling_rate":"0.250000","fpr_vc_trace_sampling_rate":"0.500000", + "fpr_log_max_flush_size":"10"},\ "state":"UPDATE"}`; const PROJECT_ID = 'project1'; const APP_ID = '1:23r:web:fewq'; @@ -80,6 +81,7 @@ describe('Performance Monitoring > remote_config_service', () => { settingsService.loggingEnabled = false; settingsService.networkRequestsSamplingRate = 1; settingsService.tracesSamplingRate = 1; + settingsService.logMaxFlushSize = 40; } // parameterized beforeEach. Should be called at beginning of each test. @@ -150,6 +152,7 @@ describe('Performance Monitoring > remote_config_service', () => { expect(SettingsService.getInstance().tracesSamplingRate).to.equal( TRACE_SAMPLING_RATE ); + expect(SettingsService.getInstance().logMaxFlushSize).to.equal(10); }); it('does not call remote config if a valid config is in local storage', async () => { @@ -190,6 +193,7 @@ describe('Performance Monitoring > remote_config_service', () => { expect(SettingsService.getInstance().tracesSamplingRate).to.equal( TRACE_SAMPLING_RATE ); + expect(SettingsService.getInstance().logMaxFlushSize).to.equal(10); }); it('does not change the default config if call to RC fails', async () => { @@ -207,6 +211,7 @@ describe('Performance Monitoring > remote_config_service', () => { await getConfig(performanceController, IID); expect(SettingsService.getInstance().loggingEnabled).to.equal(false); + expect(SettingsService.getInstance().logMaxFlushSize).to.equal(40); }); it('uses secondary configs if the response does not have all the fields', async () => { diff --git a/packages/performance/src/services/remote_config_service.ts b/packages/performance/src/services/remote_config_service.ts index 13787e2b693..1641b3b953b 100644 --- a/packages/performance/src/services/remote_config_service.ts +++ b/packages/performance/src/services/remote_config_service.ts @@ -38,6 +38,7 @@ interface SecondaryConfig { transportKey?: string; tracesSamplingRate?: number; networkRequestsSamplingRate?: number; + logMaxFlushSize?: number; } // These values will be used if the remote config object is successfully @@ -56,6 +57,7 @@ interface RemoteConfigTemplate { fpr_vc_network_request_sampling_rate?: string; fpr_vc_trace_sampling_rate?: string; fpr_vc_session_sampling_rate?: string; + fpr_log_max_flush_size?: string; } /* eslint-enable camelcase */ @@ -221,6 +223,14 @@ function processConfig( settingsServiceInstance.tracesSamplingRate = DEFAULT_CONFIGS.tracesSamplingRate; } + + if (entries.fpr_log_max_flush_size) { + settingsServiceInstance.logMaxFlushSize = Number( + entries.fpr_log_max_flush_size + ); + } else if (DEFAULT_CONFIGS.logMaxFlushSize) { + settingsServiceInstance.logMaxFlushSize = DEFAULT_CONFIGS.logMaxFlushSize; + } // Set the per session trace and network logging flags. settingsServiceInstance.logTraceAfterSampling = shouldLogAfterSampling( settingsServiceInstance.tracesSamplingRate diff --git a/packages/performance/src/services/settings_service.ts b/packages/performance/src/services/settings_service.ts index 83e08bd53d5..dbaed32a537 100644 --- a/packages/performance/src/services/settings_service.ts +++ b/packages/performance/src/services/settings_service.ts @@ -54,6 +54,10 @@ export class SettingsService { // TTL of config retrieved from remote config in hours. configTimeToLive = 12; + // The max number of events to send during a flush. This number is kept low to since Chrome has a + // shared payload limit for all sendBeacon calls in the same nav context. + logMaxFlushSize = 40; + getFlTransportFullUrl(): string { return this.flTransportEndpointUrl.concat('?key=', this.transportKey); } diff --git a/packages/performance/src/services/transport_service.test.ts b/packages/performance/src/services/transport_service.test.ts index 124ce1f415b..4f46205958d 100644 --- a/packages/performance/src/services/transport_service.test.ts +++ b/packages/performance/src/services/transport_service.test.ts @@ -21,7 +21,8 @@ import sinonChai from 'sinon-chai'; import { transportHandler, setupTransportService, - resetTransportService + resetTransportService, + flushQueuedEvents } from './transport_service'; import { SettingsService } from './settings_service'; @@ -88,14 +89,15 @@ describe('Firebase Performance > transport_service', () => { expect(fetchStub).to.not.have.been.called; }); - it('sends up to the maximum event limit in one request', async () => { + it('sends up to the maximum event limit in one request if payload is under 64 KB', async () => { // 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). + // Generate 1020 events with small payloads, which should be dispatched in two batches + // (1000 events and 20 events). for (let i = 0; i < 1020; i++) { testTransportHandler('event' + i); } @@ -134,6 +136,58 @@ describe('Firebase Performance > transport_service', () => { expect(fetchStub).to.not.have.been.called; }); + it('sends fetch if payload is above 64 KB', async () => { + // Arrange + const setting = SettingsService.getInstance(); + const flTransportFullUrl = + setting.flTransportEndpointUrl + '?key=' + setting.transportKey; + fetchStub.resolves( + new Response('{}', { + status: 200, + headers: { 'Content-type': 'application/json' } + }) + ); + + // Act + // Generate 1020 events with a large payload. The total size of the payload will be > 65 KB + const payload = 'a'.repeat(300); + for (let i = 0; i < 1020; i++) { + testTransportHandler(payload + 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': payload + i, + 'event_time_ms': '1' + }); + } + expect(fetchStub).calledWith(flTransportFullUrl, { + method: 'POST', + body: 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': + payload + (MAX_EVENT_COUNT_PER_REQUEST + i), + 'event_time_ms': '1' + }); + } + expect(sendBeaconStub).calledWith( + flTransportFullUrl, + JSON.stringify(secondLogRequest) + ); + }); + it('falls back to fetch if sendBeacon fails.', async () => { sendBeaconStub.returns(false); fetchStub.resolves( @@ -147,6 +201,98 @@ describe('Firebase Performance > transport_service', () => { expect(fetchStub).to.have.been.calledOnce; }); + it('flushes the queue with multiple sendBeacons in batches of 40', async () => { + // Arrange + const setting = SettingsService.getInstance(); + const flTransportFullUrl = + setting.flTransportEndpointUrl + '?key=' + setting.transportKey; + fetchStub.resolves( + new Response('{}', { + status: 200, + headers: { 'Content-type': 'application/json' } + }) + ); + + const payload = 'a'.repeat(300); + // Act + // Generate 80 events + for (let i = 0; i < 80; i++) { + testTransportHandler(payload + i); + } + + flushQueuedEvents(); + + // Assert + const firstLogRequest = generateLogRequest('1'); + const secondLogRequest = generateLogRequest('1'); + for (let i = 0; i < 40; i++) { + firstLogRequest['log_event'].push({ + 'source_extension_json_proto3': payload + (i + 40), + 'event_time_ms': '1' + }); + secondLogRequest['log_event'].push({ + 'source_extension_json_proto3': payload + i, + 'event_time_ms': '1' + }); + } + expect(sendBeaconStub).calledWith( + flTransportFullUrl, + JSON.stringify(firstLogRequest) + ); + expect(sendBeaconStub).calledWith( + flTransportFullUrl, + JSON.stringify(secondLogRequest) + ); + expect(fetchStub).to.not.have.been.called; + }); + + it('flushes the queue with fetch for sendBeacons that failed', async () => { + // Arrange + const setting = SettingsService.getInstance(); + const flTransportFullUrl = + setting.flTransportEndpointUrl + '?key=' + setting.transportKey; + fetchStub.resolves( + new Response('{}', { + status: 200, + headers: { 'Content-type': 'application/json' } + }) + ); + + const payload = 'a'.repeat(300); + // Act + // Generate 80 events + for (let i = 0; i < 80; i++) { + testTransportHandler(payload + i); + } + sendBeaconStub.onCall(0).returns(true); + sendBeaconStub.onCall(1).returns(false); + flushQueuedEvents(); + + // Assert + const firstLogRequest = generateLogRequest('1'); + const secondLogRequest = generateLogRequest('1'); + for (let i = 40; i < 80; i++) { + firstLogRequest['log_event'].push({ + 'source_extension_json_proto3': payload + i, + 'event_time_ms': '1' + }); + } + for (let i = 0; i < 40; i++) { + secondLogRequest['log_event'].push({ + 'source_extension_json_proto3': payload + i, + 'event_time_ms': '1' + }); + } + expect(sendBeaconStub).calledWith( + flTransportFullUrl, + JSON.stringify(firstLogRequest) + ); + expect(fetchStub).calledWith(flTransportFullUrl, { + method: 'POST', + body: JSON.stringify(secondLogRequest) + }); + }); + function generateLogRequest(requestTimeMs: string): any { return { 'request_time_ms': requestTimeMs, diff --git a/packages/performance/src/services/transport_service.ts b/packages/performance/src/services/transport_service.ts index 8577fd3a128..46c9930210a 100644 --- a/packages/performance/src/services/transport_service.ts +++ b/packages/performance/src/services/transport_service.ts @@ -24,6 +24,11 @@ const INITIAL_SEND_TIME_DELAY_MS = 5.5 * 1000; const MAX_EVENT_COUNT_PER_REQUEST = 1000; const DEFAULT_REMAINING_TRIES = 3; +// Most browsers have a max payload of 64KB for sendbeacon/keep alive payload. +const MAX_SEND_BEACON_PAYLOAD_SIZE = 65536; + +const TEXT_ENCODER = new TextEncoder(); + let remainingTries = DEFAULT_REMAINING_TRIES; interface BatchEvent { @@ -90,14 +95,31 @@ function dispatchQueueEvents(): void { // for next attempt. const staged = queue.splice(0, MAX_EVENT_COUNT_PER_REQUEST); + const data = buildPayload(staged); + + 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 buildPayload(events: BatchEvent[]): string { /* eslint-disable camelcase */ // We will pass the JSON serialized event to the backend. - const log_event: Log[] = staged.map(evt => ({ + const log_event: Log[] = events.map(evt => ({ source_extension_json_proto3: evt.message, event_time_ms: String(evt.eventTime) })); - const data: TransportBatchLogFormat = { + const transportBatchLog: TransportBatchLogFormat = { request_time_ms: String(Date.now()), client_info: { client_type: 1, // 1 is JS @@ -108,32 +130,27 @@ function dispatchQueueEvents(): void { }; /* eslint-enable camelcase */ - 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); - }); + return JSON.stringify(transportBatchLog); } -function postToFlEndpoint(data: TransportBatchLogFormat): Promise { +/** Sends to Firelog. Atempts to use sendBeacon otherwsise uses fetch. */ +function postToFlEndpoint(body: string): Promise { const flTransportFullUrl = SettingsService.getInstance().getFlTransportFullUrl(); - const body = JSON.stringify(data); - - return navigator.sendBeacon && navigator.sendBeacon(flTransportFullUrl, body) - ? Promise.resolve() - : fetch(flTransportFullUrl, { - method: 'POST', - body, - keepalive: true - }).then(); + const size = TEXT_ENCODER.encode(body).length; + + if ( + size <= MAX_SEND_BEACON_PAYLOAD_SIZE && + navigator.sendBeacon && + navigator.sendBeacon(flTransportFullUrl, body) + ) { + return Promise.resolve(); + } else { + return fetch(flTransportFullUrl, { + method: 'POST', + body + }); + } } function addToQueue(evt: BatchEvent): void { @@ -159,11 +176,36 @@ export function transportHandler( } /** - * Force flush the queued events. Useful at page unload time to ensure all - * events are uploaded. + * Force flush the queued events. Useful at page unload time to ensure all events are uploaded. + * Flush will attempt to use sendBeacon to send events async and defaults back to fetch as soon as a + * sendBeacon fails. Firefox */ export function flushQueuedEvents(): void { + const flTransportFullUrl = + SettingsService.getInstance().getFlTransportFullUrl(); + while (queue.length > 0) { - dispatchQueueEvents(); + // Send the last events first to prioritize page load traces + const staged = queue.splice(-SettingsService.getInstance().logMaxFlushSize); + const body = buildPayload(staged); + + if ( + navigator.sendBeacon && + navigator.sendBeacon(flTransportFullUrl, body) + ) { + continue; + } else { + queue = [...queue, ...staged]; + break; + } + } + if (queue.length > 0) { + const body = buildPayload(queue); + fetch(flTransportFullUrl, { + method: 'POST', + body + }).catch(() => { + consoleLogger.info(`Failed flushing queued events.`); + }); } }