Update Fireperf logging to use sendBeacon only if the payload is under the 64KB limit

.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

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 () => {

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

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);
   }

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,