fix: rework performance parsing & error handling

src/tools/performance.ts

@@ -11,6 +11,7 @@ import {
   getTraceSummary,
   InsightName,
   parseRawTraceBuffer,
+  traceResultIsSuccess,
 } from '../trace-processing/parse.js';
 import {logger} from '../logger.js';
 import {Page} from 'puppeteer-core';
@@ -160,22 +161,26 @@ async function stopTracingAndAppendOutput(
     const traceEventsBuffer = await page.tracing.stop();
     const result = await parseRawTraceBuffer(traceEventsBuffer);
     response.appendResponseLine('The performance trace has been stopped.');
-    if (result) {
+    if (traceResultIsSuccess(result)) {
       context.storeTraceRecording(result);
-      const insightText = getTraceSummary(result);
-      if (insightText) {
-        response.appendResponseLine('Insights with performance opportunities:');
-        response.appendResponseLine(insightText);
-      } else {
-        response.appendResponseLine(
-          'No insights have been found. The performance looks good!',
-        );
-      }
+      response.appendResponseLine(
+        'Here is a high level summary of the trace and the Insights that were found:',
+      );
+      const traceSummaryText = getTraceSummary(result);
+      response.appendResponseLine(traceSummaryText);
+    } else {
+      response.appendResponseLine(
+        'There was an unexpected error parsing the trace:',
+      );
+      response.appendResponseLine(result.error);
     }
   } catch (e) {
-    logger(
-      `Error stopping performance trace: ${e instanceof Error ? e.message : JSON.stringify(e)}`,
+    const errorText = e instanceof Error ? e.message : JSON.stringify(e);
+    logger(`Error stopping performance trace: ${errorText}`);
+    response.appendResponseLine(
+      'An error occured generating the response for this trace:',
     );
+    response.appendResponseLine(errorText);
   } finally {
     context.setIsRunningPerformanceTrace(false);
   }

src/trace-processing/parse.ts

@@ -14,19 +14,33 @@ const engine = TraceEngine.TraceModel.Model.createWithAllHandlers();
 
 export interface TraceResult {
   parsedTrace: TraceEngine.TraceModel.ParsedTrace;
-  insights: TraceEngine.Insights.Types.TraceInsightSets;
+  insights: TraceEngine.Insights.Types.TraceInsightSets | null;
+}
+
+export function traceResultIsSuccess(
+  x: TraceResult | TraceParseError,
+): x is TraceResult {
+  return 'parsedTrace' in x;
+}
+
+export interface TraceParseError {
+  error: string;
 }
 
 export async function parseRawTraceBuffer(
   buffer: Uint8Array<ArrayBufferLike> | undefined,
-): Promise<TraceResult | null> {
+): Promise<TraceResult | TraceParseError> {
   engine.resetProcessor();
   if (!buffer) {
-    return null;
+    return {
+      error: 'No buffer was provided.',
+    };
   }
   const asString = new TextDecoder().decode(buffer);
   if (!asString) {
-    return null;
+    return {
+      error: 'Decoding the trace buffer returned an empty string.',
+    };
   }
   try {
     const data = JSON.parse(asString) as
@@ -39,25 +53,23 @@ export async function parseRawTraceBuffer(
     await engine.parse(events);
     const parsedTrace = engine.parsedTrace();
     if (!parsedTrace) {
-      return null;
+      return {
+        error: 'No parsed trace was returned from the trace engine.',
+      };
     }
 
-    const insights = parsedTrace?.insights;
-    if (!insights) {
-      return null;
-    }
+    const insights = parsedTrace?.insights ?? null;
 
     return {
       parsedTrace,
       insights,
     };
   } catch (e) {
-    if (e instanceof Error) {
-      logger(`Error parsing trace: ${e.message}`);
-    } else {
-      logger(`Error parsing trace: ${JSON.stringify(e)}`);
-    }
-    return null;
+    const errorText = e instanceof Error ? e.message : JSON.stringify(e);
+    logger(`Unexpeced error parsing trace: ${errorText}`);
+    return {
+      error: errorText,
+    };
   }
 }
 
@@ -76,6 +88,12 @@ export function getInsightOutput(
   result: TraceResult,
   insightName: InsightName,
 ): InsightOutput {
+  if (!result.insights) {
+    return {
+      error: 'No Performance insights are available for this trace.',
+    };
+  }
+
   // Currently, we do not support inspecting traces with multiple navigations. We either:
   // 1. Find Insights from the first navigation (common case: user records a trace with a page reload to test load performance)
   // 2. Fall back to finding Insights not associated with a navigation (common case: user tests an interaction without a page load).

tests/tools/performance.test.js.snapshot

@@ -40,3 +40,56 @@ We can break this time down into the 4 phases that combine to make the LCP time:
 - https://web.dev/articles/lcp
 - https://web.dev/articles/optimize-lcp
 `;
+
+exports[`performance > performance_stop_trace > returns an error message if parsing the trace buffer fails 1`] = `
+The performance trace has been stopped.
+There was an unexpected error parsing the trace:
+No buffer was provided.
+`;
+
+exports[`performance > performance_stop_trace > returns the high level summary of the performance trace 1`] = `
+The performance trace has been stopped.
+Here is a high level summary of the trace and the Insights that were found:
+URL: https://web.dev/
+Bounds: {min: 122410994891, max: 122416385853}
+CPU throttling: none
+Network throttling: none
+Metrics (lab / observed):
+  - LCP: 129 ms, event: (eventKey: r-6063, ts: 122411126100)
+  - LCP breakdown:
+    - TTFB: 8 ms, bounds: {min: 122410996889, max: 122411004828}
+    - Load delay: 33 ms, bounds: {min: 122411004828, max: 122411037986}
+    - Load duration: 15 ms, bounds: {min: 122411037986, max: 122411052690}
+    - Render delay: 73 ms, bounds: {min: 122411052690, max: 122411126100}
+  - CLS: 0.00
+Metrics (field / real users): n/a – no data for this page in CrUX
+Available insights:
+  - insight name: LCPBreakdown
+    description: Each [subpart has specific improvement strategies](https://web.dev/articles/optimize-lcp#lcp-breakdown). Ideally, most of the LCP time should be spent on loading the resources, not within delays.
+    relevant trace bounds: {min: 122410996889, max: 122411126100}
+    example question: Help me optimize my LCP score
+    example question: Which LCP phase was most problematic?
+    example question: What can I do to reduce the LCP time for this page load?
+  - insight name: LCPDiscovery
+    description: Optimize LCP by making the LCP image [discoverable](https://web.dev/articles/optimize-lcp#1_eliminate_resource_load_delay) from the HTML immediately, and [avoiding lazy-loading](https://web.dev/articles/lcp-lazy-loading)
+    relevant trace bounds: {min: 122411004828, max: 122411055039}
+    example question: Suggest fixes to reduce my LCP
+    example question: What can I do to reduce my LCP discovery time?
+    example question: Why is LCP discovery time important?
+  - insight name: RenderBlocking
+    description: Requests are blocking the page's initial render, which may delay LCP. [Deferring or inlining](https://web.dev/learn/performance/understanding-the-critical-path#render-blocking_resources) can move these network requests out of the critical path.
+    relevant trace bounds: {min: 122411037528, max: 122411053852}
+    example question: Show me the most impactful render blocking requests that I should focus on
+    example question: How can I reduce the number of render blocking requests?
+  - insight name: DocumentLatency
+    description: Your first network request is the most important.  Reduce its latency by avoiding redirects, ensuring a fast server response, and enabling text compression.
+    relevant trace bounds: {min: 122410998910, max: 122411043781}
+    estimated metric savings: FCP 0 ms, LCP 0 ms
+    estimated wasted bytes: 77.1 kB
+    example question: How do I decrease the initial loading time of my page?
+    example question: Did anything slow down the request for this document?
+  - insight name: ThirdParties
+    description: 3rd party code can significantly impact load performance. [Reduce and defer loading of 3rd party code](https://web.dev/articles/optimizing-content-efficiency-loading-third-party-javascript/) to prioritize your page's content.
+    relevant trace bounds: {min: 122411037881, max: 122416229595}
+    example question: Which third parties are having the largest impact on my page performance?
+`;

tests/tools/performance.test.ts

@@ -17,6 +17,7 @@ import {loadTraceAsBuffer} from '../trace-processing/fixtures/load.js';
 import {
   parseRawTraceBuffer,
   TraceResult,
+  traceResultIsSuccess,
 } from '../../src/trace-processing/parse.js';
 
 describe('performance', () => {
@@ -141,7 +142,9 @@ describe('performance', () => {
     async function parseTrace(fileName: string): Promise<TraceResult> {
       const rawData = loadTraceAsBuffer(fileName);
       const result = await parseRawTraceBuffer(rawData);
-      assert.ok(result);
+      if (!traceResultIsSuccess(result)) {
+        assert.fail(`Unexpected trace parse error: ${result.error}`);
+      }
       return result;
     }
 
@@ -238,5 +241,30 @@ describe('performance', () => {
         sinon.assert.calledOnce(stopTracingStub);
       });
     });
+
+    it('returns an error message if parsing the trace buffer fails', async t => {
+      await withBrowser(async (response, context) => {
+        context.setIsRunningPerformanceTrace(true);
+        const selectedPage = context.getSelectedPage();
+        sinon
+          .stub(selectedPage.tracing, 'stop')
+          .returns(Promise.resolve(undefined));
+        await stopTrace.handler({params: {}}, response, context);
+        t.assert.snapshot(response.responseLines.join('\n'));
+      });
+    });
+
+    it('returns the high level summary of the performance trace', async t => {
+      const rawData = loadTraceAsBuffer('web-dev-with-commit.json.gz');
+      await withBrowser(async (response, context) => {
+        context.setIsRunningPerformanceTrace(true);
+        const selectedPage = context.getSelectedPage();
+        sinon.stub(selectedPage.tracing, 'stop').callsFake(async () => {
+          return rawData;
+        });
+        await stopTrace.handler({params: {}}, response, context);
+        t.assert.snapshot(response.responseLines.join('\n'));
+      });
+    });
   });
 });

tests/trace-processing/parse.test.ts

@@ -15,17 +15,30 @@ describe('Trace parsing', async () => {
   it('can parse a Uint8Array from Tracing.stop())', async () => {
     const rawData = loadTraceAsBuffer('basic-trace.json.gz');
     const result = await parseRawTraceBuffer(rawData);
+    if ('error' in result) {
+      assert.fail(`Unexpected parse failure: ${result.error}`);
+    }
     assert.ok(result?.parsedTrace);
     assert.ok(result?.insights);
   });
 
   it('can format results of a trace', async t => {
     const rawData = loadTraceAsBuffer('web-dev-with-commit.json.gz');
     const result = await parseRawTraceBuffer(rawData);
+    if ('error' in result) {
+      assert.fail(`Unexpected parse failure: ${result.error}`);
+    }
     assert.ok(result?.parsedTrace);
     assert.ok(result?.insights);
 
     const output = getTraceSummary(result);
     t.assert.snapshot(output);
   });
+
+  it('will return a message if there is an error', async () => {
+    const result = await parseRawTraceBuffer(undefined);
+    assert.deepEqual(result, {
+      error: 'No buffer was provided.',
+    });
+  });
 });