[RPP] Calculate TTFB even for older traces

TTFB relied on an M116 addition (receiveHeadersStart), but
receiveHeadersEnd is close enough for our purposes. While broader
support for historical traces is nice, this is especially useful since
many of our test fixtures are pre-M116.

Bug: none
Change-Id: I44eb0da2cf7596b0027bfcda7e80e42e5bc393c7
Reviewed-on: https://chromium-review.googlesource.com/c/devtools/devtools-frontend/+/6876549
Auto-Submit: Connor Clark <cjamcl@chromium.org>
Reviewed-by: Paul Irish <paulirish@chromium.org>
Commit-Queue: Connor Clark <cjamcl@chromium.org>

Author: Connor Clark

front_end/models/ai_assistance/data_formatters/PerformanceTraceFormatter.snapshot.txt

@@ -495,11 +495,13 @@ CPU throttling: none
 Network throttling: none
 Metrics:
   - LCP: 118 ms, event: (eventKey: r-1802, ts: 1020034953358)
+    - TTFB: 31.3 ms, bounds: {min: 1020034834921, max: 1020034866264}
+    - Render delay: 87 ms, bounds: {min: 1020034866264, max: 1020034953358}
   - CLS: 0
 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: 1020034834921, max: 1020036087961}
+    relevant trace bounds: {min: 1020034834921, max: 1020034953358}
     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?

front_end/models/ai_assistance/data_formatters/PerformanceTraceFormatter.test.ts

@@ -34,10 +34,6 @@ describeWithEnvironment('PerformanceTraceFormatter', () => {
 
   describe('formatTraceSummary', () => {
     it('web-dev.json.gz', async function() {
-      // TODO(b/425270067): in LCPBreakdown, `anyValuesNaN` is true, so the summary
-      // does not include LCP phases. Investigate this.
-      // LOG: Object{min: 1020034834921, max: NaN, range: NaN, label: 'Time to first byte'}
-      // LOG: Object{min: NaN, max: 1020034953358, range: NaN, label: 'Element render delay'}
       const {formatter} = await createFormatter(this, 'web-dev.json.gz');
       const output = formatter.formatTraceSummary();
       snapshotTester.assert(this, output);

front_end/models/trace/LanternComputationData.ts

@@ -102,6 +102,7 @@ function createLanternRequest(
     // These two timings are not included in the trace.
     workerFetchStart: -1,
     workerRespondWithSettled: -1,
+    receiveHeadersStart: -1,
     ...request.args.data.timing,
   } :
                                             undefined;

front_end/models/trace/insights/Common.ts

@@ -411,3 +411,24 @@ export function estimateCompressionRatioForScript(script: Handlers.ModelHandlers
   const compressionRatio = compressedSize / contentLength;
   return compressionRatio;
 }
+
+export function calculateDocFirstByteTs(docRequest: Types.Events.SyntheticNetworkRequest): Types.Timing.Micro|null {
+  if (docRequest.args.data.protocol === 'file') {
+    // file: requests do not have timings
+    return docRequest.ts;
+  }
+
+  const timing = docRequest.args.data.timing;
+  if (!timing) {
+    // Older traces do not have timings.
+    return null;
+  }
+
+  // Time that first byte (headers) are received.
+  // For older traces, receiveHeadersStart can be missing (ex: web.dev.json.gz).
+  // In that case use the headers end timing, which should be pretty close to when
+  // the headers start.
+  return Types.Timing.Micro(
+      Helpers.Timing.secondsToMicro(timing.requestTime) +
+      Helpers.Timing.milliToMicro(timing.receiveHeadersStart ?? timing.receiveHeadersEnd));
+}

front_end/models/trace/insights/LCPBreakdown.test.ts

@@ -22,6 +22,20 @@ describeWithEnvironment('LCPBreakdown', function() {
     assert.deepEqual(actual, {ttfb: wantTtfb, renderDelay: wantRenderDelay});
   });
 
+  it('calculates text lcp breakdown (doc missing receiveHeadersStart)', async () => {
+    const {data, insights} = await processTrace(this, 'web-dev.json.gz');
+    const firstNav = getFirstOrError(data.Meta.navigationsByNavigationId.values());
+    const insight = getInsightOrError('LCPBreakdown', insights, firstNav);
+
+    assert.strictEqual(insight.lcpMs, 118.437);
+
+    const wantTtfb = Types.Timing.Micro(31343);
+    const wantRenderDelay = Types.Timing.Micro(87094);
+    assert.exists(insight.subparts);
+    const actual = Object.fromEntries(Object.entries(insight.subparts).map(([key, value]) => [key, value.range]));
+    assert.deepEqual(actual, {ttfb: wantTtfb, renderDelay: wantRenderDelay});
+  });
+
   it('calculates image lcp breakdown', async () => {
     const {data, insights} = await processTrace(this, 'lcp-images.json.gz');
     const firstNav = getFirstOrError(data.Meta.navigationsByNavigationId.values());
@@ -42,6 +56,26 @@ describeWithEnvironment('LCPBreakdown', function() {
     assert.deepEqual(subparts, {ttfb: '6.94', loadTime: '12.10', loadDelay: '33.74', renderDelay: '56.85'});
   });
 
+  it('calculates image lcp breakdown (doc missing receiveHeadersStart)', async () => {
+    const {data, insights} = await processTrace(this, 'multiple-navigations.json.gz');
+    const firstNav = getFirstOrError(data.Meta.navigationsByNavigationId.values());
+    const insight = getInsightOrError('LCPBreakdown', insights, firstNav);
+
+    assert.strictEqual(insight.lcpMs, 118.677);
+
+    if (!insight.subparts) {
+      throw new Error('No LCP subparts');
+    }
+
+    const subparts = {
+      ttfb: Helpers.Timing.microToMilli(insight.subparts.ttfb?.range).toFixed(2),
+      loadTime: Helpers.Timing.microToMilli(insight.subparts.loadDuration?.range as Types.Timing.Micro).toFixed(2),
+      loadDelay: Helpers.Timing.microToMilli(insight.subparts.loadDelay?.range as Types.Timing.Micro).toFixed(2),
+      renderDelay: Helpers.Timing.microToMilli(insight.subparts.renderDelay?.range).toFixed(2),
+    };
+    assert.deepEqual(subparts, {ttfb: '61.47', loadTime: '0.19', loadDelay: '47.74', renderDelay: '9.28'});
+  });
+
   describe('warnings', function() {
     it('warns when there is no lcp', async () => {
       const {data, insights} = await processTrace(this, 'user-timings.json.gz');
@@ -63,12 +97,4 @@ describeWithEnvironment('LCPBreakdown', function() {
       assert.strictEqual(insight.warnings?.[0], 'NO_DOCUMENT_REQUEST');
     });
   });
-
-  it('can handle old traces with missing data and return null for breakdowns of the subparts', async () => {
-    const {data, insights} = await processTrace(this, 'multiple-navigations.json.gz');
-    const firstNav = getFirstOrError(data.Meta.navigationsByNavigationId.values());
-    const insight = getInsightOrError('LCPBreakdown', insights, firstNav);
-    // This insight has invalid subparts, so we expect the value to be undefined.
-    assert.isUndefined(insight.subparts);
-  });
 });

front_end/models/trace/insights/LCPBreakdown.ts

@@ -8,6 +8,7 @@ import * as Handlers from '../handlers/handlers.js';
 import * as Helpers from '../helpers/helpers.js';
 import * as Types from '../types/types.js';
 
+import {calculateDocFirstByteTs} from './Common.js';
 import {
   InsightCategory,
   InsightKeys,
@@ -113,15 +114,9 @@ function determineSubparts(
     nav: Types.Events.NavigationStart, docRequest: Types.Events.SyntheticNetworkRequest,
     lcpEvent: Types.Events.LargestContentfulPaintCandidate,
     lcpRequest: Types.Events.SyntheticNetworkRequest|undefined): LCPSubparts|null {
-  const docReqTiming = docRequest.args.data.timing;
-
-  let firstDocByteTs;
-  if (docReqTiming) {
-    firstDocByteTs = Types.Timing.Micro(
-        Helpers.Timing.secondsToMicro(docReqTiming.requestTime) +
-        Helpers.Timing.milliToMicro(docReqTiming.receiveHeadersStart));
-  } else {
-    firstDocByteTs = docRequest.ts;  // file:
+  const firstDocByteTs = calculateDocFirstByteTs(docRequest);
+  if (firstDocByteTs === null) {
+    return null;
   }
 
   const ttfb = Helpers.Timing.traceWindowFromMicroSeconds(nav.ts, firstDocByteTs) as Subpart;

front_end/models/trace/insights/LCPDiscovery.ts

@@ -7,6 +7,7 @@ import * as Handlers from '../handlers/handlers.js';
 import * as Helpers from '../helpers/helpers.js';
 import * as Types from '../types/types.js';
 
+import {calculateDocFirstByteTs} from './Common.js';
 import {
   type Checklist,
   InsightCategory,
@@ -135,11 +136,8 @@ export function generateInsight(
 
   const imageLoadingAttr = lcpEvent.args.data?.loadingAttr;
   const imageFetchPriorityHint = lcpRequest?.args.data.fetchPriorityHint;
-  // This is the earliest discovery time an LCP request could have - it's TTFB.
-  const earliestDiscoveryTime = docRequest?.args.data.timing ?
-      Helpers.Timing.secondsToMicro(docRequest.args.data.timing.requestTime) +
-          Helpers.Timing.milliToMicro(docRequest.args.data.timing.receiveHeadersStart) :
-      undefined;
+  // This is the earliest discovery time an LCP request could have - it's TTFB (as an absolute timestamp).
+  const earliestDiscoveryTime = calculateDocFirstByteTs(docRequest);
 
   const priorityHintFound = imageFetchPriorityHint === 'high';
 

front_end/models/trace/types/TraceEvents.ts

@@ -389,7 +389,7 @@ export interface SyntheticNetworkRequest extends Complete, SyntheticBased<Phase.
        *
        * Note, this is not the same as URL.protocol.
        *
-       * Example values (not exhaustive): http/0.9, http/1.0, http/1.1, http, h2, h3-Q050, data, blob
+       * Example values (not exhaustive): http/0.9, http/1.0, http/1.1, http, h2, h3-Q050, data, blob, file
        */
       protocol: string,
       redirects: SyntheticNetworkRedirect[],
@@ -1115,7 +1115,8 @@ interface ResourceReceiveResponseTimingData {
   pushEnd: Milli;
   pushStart: Milli;
   receiveHeadersEnd: Milli;
-  receiveHeadersStart: Milli;
+  /** M116. */
+  receiveHeadersStart?: Milli;
   /** When the network service is about to handle a request, ie. just before going to the HTTP cache or going to the network for DNS/connection setup. */
   requestTime: Seconds;
   sendEnd: Milli;