Performance Monitoring transport format upgrade from proto2 to proto3 (#2525)

* Update the Fireperf's log fromat from proto2 to proto3.

* Add CHANGELOG for Fireperf transport update from proto2 to proto3 (#2492)

* Add unit tests with the new proto format change. (#2516)

Author: zijianjoy

packages/performance/CHANGELOG.md

@@ -0,0 +1,2 @@
+# Unreleased
+- [changed] Internal transport protocol update from proto2 to proto3.

packages/performance/src/resources/trace.test.ts

@@ -138,6 +138,7 @@ describe('Firebase Performance > trace', () => {
 
     it('throws error if metric doesnt exist and has invalid name', () => {
       expect(() => trace.putMetric('_invalidMetric', 1)).to.throw();
+      expect(() => trace.putMetric('_fid', 1)).to.throw();
     });
   });
 

packages/performance/src/services/perf_logger.test.ts

@@ -40,6 +40,12 @@ describe('Performance Monitoring > perf_logger', () => {
   const TRACE_NAME = 'testTrace';
   const START_TIME = 12345;
   const DURATION = 321;
+  // Perf event header which is constant across tests in this file.
+  const WEBAPP_INFO = `"application_info":{"google_app_id":"${APP_ID}",\
+"app_instance_id":"${IID}","web_app_info":{"sdk_version":"${SDK_VERSION}",\
+"page_url":"${PAGE_URL}","service_worker_status":${SERVICE_WORKER_STATUS},\
+"visibility_state":${VISIBILITY_STATE},"effective_connection_type":${EFFECTIVE_CONNECTION_TYPE}},\
+"application_process_state":0}`;
 
   let addToQueueStub: SinonStub<
     Array<{ message: string; eventTime: number }>,
@@ -69,7 +75,6 @@ describe('Performance Monitoring > perf_logger', () => {
     stub(Api.prototype, 'getUrl').returns(PAGE_URL);
     stub(Api.prototype, 'getTimeOrigin').returns(TIME_ORIGIN);
     stub(initializationService, 'isPerfInitialized').returns(true);
-    stub(attributeUtils, 'getVisibilityState').returns(VISIBILITY_STATE);
     stub(attributeUtils, 'getEffectiveConnectionType').returns(
       EFFECTIVE_CONNECTION_TYPE
     );
@@ -83,17 +88,20 @@ describe('Performance Monitoring > perf_logger', () => {
   });
 
   describe('logTrace', () => {
-    it('creates, serializes and sends a trace to cc service', () => {
-      const EXPECTED_TRACE_MESSAGE = `{"application_info":{"google_app_id":"${APP_ID}",\
-"app_instance_id":"${IID}","web_app_info":{"sdk_version":"${SDK_VERSION}",\
-"page_url":"${PAGE_URL}","service_worker_status":${SERVICE_WORKER_STATUS},\
-"visibility_state":${VISIBILITY_STATE},"effective_connection_type":${EFFECTIVE_CONNECTION_TYPE}},\
-"application_process_state":0},"trace_metric":{"name":"${TRACE_NAME}","is_auto":false,\
-"client_start_time_us":${START_TIME * 1000},"duration_us":${DURATION * 1000}}}`;
+    it('creates, serializes and sends a trace to transport service', () => {
+      const EXPECTED_TRACE_MESSAGE =
+        `{` +
+        WEBAPP_INFO +
+        `,"trace_metric":{"name":"${TRACE_NAME}","is_auto":false,\
+"client_start_time_us":${START_TIME * 1000},"duration_us":${DURATION * 1000},\
+"counters":{"counter1":3},"custom_attributes":{"attr":"val"}}}`;
       getIidStub.returns(IID);
+      stub(attributeUtils, 'getVisibilityState').returns(VISIBILITY_STATE);
       SettingsService.getInstance().loggingEnabled = true;
       SettingsService.getInstance().logTraceAfterSampling = true;
       const trace = new Trace(TRACE_NAME);
+      trace.putAttribute('attr', 'val');
+      trace.putMetric('counter1', 3);
       trace.record(START_TIME, DURATION);
       clock.tick(1);
 
@@ -105,16 +113,140 @@ describe('Performance Monitoring > perf_logger', () => {
 
     it('does not log an event if cookies are disabled in the browser', () => {
       stub(Api.prototype, 'requiredApisAvailable').returns(false);
+      stub(attributeUtils, 'getVisibilityState').returns(VISIBILITY_STATE);
       const trace = new Trace(TRACE_NAME);
       trace.record(START_TIME, DURATION);
       clock.tick(1);
 
       expect(addToQueueStub).not.to.be.called;
     });
+
+    it('ascertains that the max number of customMetric allowed is 32', () => {
+      const EXPECTED_TRACE_MESSAGE =
+        `{` +
+        WEBAPP_INFO +
+        `,"trace_metric":{"name":"${TRACE_NAME}","is_auto":false,\
+"client_start_time_us":${START_TIME * 1000},"duration_us":${DURATION * 1000},\
+"counters":{"counter1":1,"counter2":2,"counter3":3,"counter4":4,"counter5":5,"counter6":6,\
+"counter7":7,"counter8":8,"counter9":9,"counter10":10,"counter11":11,"counter12":12,\
+"counter13":13,"counter14":14,"counter15":15,"counter16":16,"counter17":17,"counter18":18,\
+"counter19":19,"counter20":20,"counter21":21,"counter22":22,"counter23":23,"counter24":24,\
+"counter25":25,"counter26":26,"counter27":27,"counter28":28,"counter29":29,"counter30":30,\
+"counter31":31,"counter32":32}}}`;
+      getIidStub.returns(IID);
+      stub(attributeUtils, 'getVisibilityState').returns(VISIBILITY_STATE);
+      SettingsService.getInstance().loggingEnabled = true;
+      SettingsService.getInstance().logTraceAfterSampling = true;
+      const trace = new Trace(TRACE_NAME);
+      for (let i = 1; i <= 32; i++) {
+        trace.putMetric('counter' + i, i);
+      }
+      trace.record(START_TIME, DURATION);
+      clock.tick(1);
+
+      expect(addToQueueStub).to.be.called;
+      expect(addToQueueStub.getCall(0).args[0].message).to.be.equal(
+        EXPECTED_TRACE_MESSAGE
+      );
+    });
+
+    it('ascertains that the max number of custom attributes allowed is 5', () => {
+      const EXPECTED_TRACE_MESSAGE =
+        `{` +
+        WEBAPP_INFO +
+        `,"trace_metric":{"name":"${TRACE_NAME}","is_auto":false,\
+"client_start_time_us":${START_TIME * 1000},"duration_us":${DURATION * 1000},\
+"custom_attributes":{"attr1":"val1","attr2":"val2","attr3":"val3","attr4":"val4","attr5":"val5"}}}`;
+      getIidStub.returns(IID);
+      stub(attributeUtils, 'getVisibilityState').returns(VISIBILITY_STATE);
+      SettingsService.getInstance().loggingEnabled = true;
+      SettingsService.getInstance().logTraceAfterSampling = true;
+      const trace = new Trace(TRACE_NAME);
+      for (let i = 1; i <= 5; i++) {
+        trace.putAttribute('attr' + i, 'val' + i);
+      }
+      trace.record(START_TIME, DURATION);
+      clock.tick(1);
+
+      expect(addToQueueStub).to.be.called;
+      expect(addToQueueStub.getCall(0).args[0].message).to.be.equal(
+        EXPECTED_TRACE_MESSAGE
+      );
+    });
+  });
+
+  describe('logPageLoadTrace', () => {
+    it('creates, serializes and sends a page load trace to cc service', () => {
+      const flooredStartTime = Math.floor(TIME_ORIGIN * 1000);
+      const EXPECTED_TRACE_MESSAGE = `{"application_info":{"google_app_id":"${APP_ID}",\
+"app_instance_id":"${IID}","web_app_info":{"sdk_version":"${SDK_VERSION}",\
+"page_url":"${PAGE_URL}","service_worker_status":${SERVICE_WORKER_STATUS},\
+"visibility_state":${
+        attributeUtils.VisibilityState.VISIBLE
+      },"effective_connection_type":${EFFECTIVE_CONNECTION_TYPE}},\
+"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}}}`;
+      getIidStub.returns(IID);
+      SettingsService.getInstance().loggingEnabled = true;
+      SettingsService.getInstance().logTraceAfterSampling = true;
+
+      stub(attributeUtils, 'getVisibilityState').returns(
+        attributeUtils.VisibilityState.VISIBLE
+      );
+
+      const navigationTiming: PerformanceNavigationTiming = {
+        domComplete: 100,
+        domContentLoadedEventEnd: 20,
+        domContentLoadedEventStart: 10,
+        domInteractive: 10,
+        loadEventEnd: 10,
+        loadEventStart: 10,
+        redirectCount: 10,
+        type: 'navigate',
+        unloadEventEnd: 10,
+        unloadEventStart: 10,
+        duration: DURATION
+      } as PerformanceNavigationTiming;
+
+      const navigationTimings: PerformanceNavigationTiming[] = [
+        navigationTiming
+      ];
+
+      const firstPaint: PerformanceEntry = {
+        name: 'first-paint',
+        startTime: 40,
+        duration: 100,
+        entryType: 'url',
+        toJSON() {}
+      };
+
+      const firstContentfulPaint: PerformanceEntry = {
+        name: 'first-contentful-paint',
+        startTime: 50,
+        duration: 100,
+        entryType: 'url',
+        toJSON() {}
+      };
+
+      const paintTimings: PerformanceEntry[] = [
+        firstPaint,
+        firstContentfulPaint
+      ];
+
+      Trace.createOobTrace(navigationTimings, paintTimings, 90);
+      clock.tick(1);
+
+      expect(addToQueueStub).to.be.called;
+      expect(addToQueueStub.getCall(0).args[0].message).to.be.equal(
+        EXPECTED_TRACE_MESSAGE
+      );
+    });
   });
 
   describe('logNetworkRequest', () => {
-    it('creates, serializes and sends a network request to cc service', () => {
+    it('creates, serializes and sends a network request to transport service', () => {
       const RESOURCE_PERFORMANCE_ENTRY: PerformanceResourceTiming = {
         connectEnd: 0,
         connectStart: 0,
@@ -147,17 +279,17 @@ describe('Performance Monitoring > perf_logger', () => {
           RESOURCE_PERFORMANCE_ENTRY.startTime) *
           1000
       );
-      const EXPECTED_NETWORK_MESSAGE = `{"application_info":{"google_app_id":"${APP_ID}",\
-"app_instance_id":"${IID}","web_app_info":{"sdk_version":"${SDK_VERSION}",\
-"page_url":"${PAGE_URL}","service_worker_status":${SERVICE_WORKER_STATUS},\
-"visibility_state":${VISIBILITY_STATE},"effective_connection_type":${EFFECTIVE_CONNECTION_TYPE}},\
-"application_process_state":0},\
+      const EXPECTED_NETWORK_MESSAGE =
+        `{` +
+        WEBAPP_INFO +
+        `,\
 "network_request_metric":{"url":"${RESOURCE_PERFORMANCE_ENTRY.name}",\
 "http_method":0,"http_response_code":200,\
 "response_payload_bytes":${RESOURCE_PERFORMANCE_ENTRY.transferSize},\
 "client_start_time_us":${START_TIME},\
 "time_to_response_completed_us":${TIME_TO_RESPONSE_COMPLETED}}}`;
       getIidStub.returns(IID);
+      stub(attributeUtils, 'getVisibilityState').returns(VISIBILITY_STATE);
       SettingsService.getInstance().loggingEnabled = true;
       SettingsService.getInstance().logNetworkAfterSampling = true;
       // Calls logNetworkRequest under the hood.

packages/performance/src/services/perf_logger.ts

@@ -79,8 +79,8 @@ interface TraceMetric {
   is_auto: boolean;
   client_start_time_us: number;
   duration_us: number;
-  counters?: Array<{ key: string; value: number }>;
-  custom_attributes?: Array<{ key: string; value: string }>;
+  counters?: { [key: string]: number };
+  custom_attributes?: { [key: string]: string };
 }
 
 /* eslint-enble camelcase */
@@ -201,11 +201,11 @@ function serializeTrace(trace: Trace): string {
   };
 
   if (Object.keys(trace.counters).length !== 0) {
-    traceMetric.counters = convertToKeyValueArray(trace.counters);
+    traceMetric.counters = trace.counters;
   }
   const customAttributes = trace.getAttributes();
   if (Object.keys(customAttributes).length !== 0) {
-    traceMetric.custom_attributes = convertToKeyValueArray(customAttributes);
+    traceMetric.custom_attributes = customAttributes;
   }
 
   const perfMetric: PerfTraceLog = {
@@ -229,13 +229,3 @@ function getApplicationInfo(): ApplicationInfo {
     application_process_state: 0
   };
 }
-
-function convertToKeyValueArray<T>(obj: {
-  [key: string]: T;
-}): Array<{
-  key: string;
-  value: T;
-}> {
-  const keys = Object.keys(obj);
-  return keys.map(key => ({ key, value: obj[key] }));
-}

packages/performance/src/services/transport_service.ts

@@ -45,7 +45,7 @@ interface ClientInfo {
 }
 
 interface Log {
-  source_extension_json: string;
+  source_extension_json_proto3: string;
   event_time_ms: string;
 }
 /* eslint-enable camelcase */
@@ -79,8 +79,8 @@ function processQueue(timeOffset: number): void {
 
     /* eslint-disable camelcase */
     // We will pass the JSON serialized event to the backend.
-    const log_event = staged.map(evt => ({
-      source_extension_json: evt.message,
+    const log_event: Log[] = staged.map(evt => ({
+      source_extension_json_proto3: evt.message,
       event_time_ms: String(evt.eventTime)
     }));