Trace cold request waterfalls and isolate the layout discovery regression

perf/README.md

@@ -335,3 +335,14 @@ No product behavior changes are involved in these measurement corrections.
 Keep browser/build/test processes idle during full timing measurements. WebKit's
 zero long-task field means unavailable, not zero work. Autoplay-blocked/media-ready
 null results do not establish playback performance or iPhone audio continuity.
+
+### Cold waterfall diagnosis
+
+`--source-root perf/.tmp/<historical-worktree>` runs that worktree's matching
+frontend **and server**; `--frontend-commit` instead combines archived frontend
+with the current backend. Run historical comparisons sequentially to avoid CPU
+contention. The result records `sourceCommit`, `sourceRoot` and the served build.
+Every cold sample has `waterfalls`: proxy request order/start/headers/end times
+and page Resource Timing discovery/start/end times. Proxy times start when
+tracking begins; page times start at navigation. Compare within each clock,
+then use the page FCP to locate the rendering dependency.

perf/baseline.mjs

@@ -62,6 +62,7 @@ function parseArgs() {
     out: null,
     compare: null,
     frontendCommit: null,
+    sourceRoot: null,
   };
 
   for (let i = 0; i < args.length; i++) {
@@ -71,6 +72,7 @@ function parseArgs() {
     else if (a === '--profile' && i + 1 < args.length) options.profile = args[++i];
     else if (a === '--scenario' && i + 1 < args.length) options.scenario = args[++i];
     else if (a === '--out' && i + 1 < args.length) options.out = args[++i];
+    else if (a === '--source-root' && i + 1 < args.length) options.sourceRoot = path.resolve(args[++i]);
     else if (a === '--frontend-commit' && i + 1 < args.length) options.frontendCommit = args[++i];
     else if (a === '--compare' && i + 1 < args.length) options.compare = args[++i];
   }
@@ -151,7 +153,8 @@ async function seedDatabase(dbPath, mediaFiles) {
  * Bun Server Manager
  */
 class ServerManager {
-  constructor(scratchDir, publicDir) {
+  constructor(scratchDir, publicDir, sourceRoot = REPO_ROOT) {
+    this.sourceRoot = sourceRoot;
     this.scratchDir = scratchDir;
     this.publicDir = publicDir;
     this.dataDir = path.join(scratchDir, 'data');
@@ -184,7 +187,7 @@ class ServerManager {
       DB_PATH: this.dbPath,
     };
 
-    const serverScript = path.join(REPO_ROOT, 'server', 'server.js');
+    const serverScript = path.join(this.sourceRoot, 'server', 'server.js');
     this.serverProcess = spawn('bun', [serverScript], {
       cwd: srvCwd,
       env,
@@ -373,7 +376,7 @@ async function runColdScenario({ browserType, server, proxy, profile }) {
 
     return {
       initialJsCss: performance.getEntriesByType('resource').filter(entry=>/\.(?:js|css)(?:[?#]|$)/.test(entry.name)&&entry.startTime <= nav.domContentLoadedEventEnd&&['script','link','css'].includes(entry.initiatorType)).reduce((sum,entry)=>sum+entry.encodedBodySize,0),
-      initialAssetRequests: performance.getEntriesByType('resource').filter(entry=>/\.(?:js|css)(?:[?#]|$)/.test(entry.name)&&entry.startTime <= nav.domContentLoadedEventEnd&&['script','link','css'].includes(entry.initiatorType)).map(entry=>({url:entry.name,bytes:entry.encodedBodySize})),
+      initialAssetRequests: performance.getEntriesByType('resource').filter(entry=>/\.(?:js|css)(?:[?#]|$)/.test(entry.name)&&entry.startTime <= nav.domContentLoadedEventEnd&&['script','link','css'].includes(entry.initiatorType)).map(entry=>({url:entry.name,bytes:entry.encodedBodySize,start:entry.startTime,responseStart:entry.responseStart,end:entry.responseEnd,initiator:entry.initiatorType})),
       fcp: fcp ? Math.round(fcp.startTime) : null,
       lcp: window.__lcp ? Math.round(window.__lcp) : null,
       domContentLoaded: nav ? Math.round(nav.domContentLoadedEventEnd - nav.startTime) : null,
@@ -482,7 +485,7 @@ async function runWarmScenario({ browserType, server, proxy, profile }) {
 
     return {
       initialJsCss: performance.getEntriesByType('resource').filter(entry=>/\.(?:js|css)(?:[?#]|$)/.test(entry.name)&&entry.startTime <= nav.domContentLoadedEventEnd&&['script','link','css'].includes(entry.initiatorType)).reduce((sum,entry)=>sum+entry.encodedBodySize,0),
-      initialAssetRequests: performance.getEntriesByType('resource').filter(entry=>/\.(?:js|css)(?:[?#]|$)/.test(entry.name)&&entry.startTime <= nav.domContentLoadedEventEnd&&['script','link','css'].includes(entry.initiatorType)).map(entry=>({url:entry.name,bytes:entry.encodedBodySize})),
+      initialAssetRequests: performance.getEntriesByType('resource').filter(entry=>/\.(?:js|css)(?:[?#]|$)/.test(entry.name)&&entry.startTime <= nav.domContentLoadedEventEnd&&['script','link','css'].includes(entry.initiatorType)).map(entry=>({url:entry.name,bytes:entry.encodedBodySize,start:entry.startTime,responseStart:entry.responseStart,end:entry.responseEnd,initiator:entry.initiatorType})),
       fcp: fcp ? Math.round(fcp.startTime) : null,
       lcp: window.__lcp ? Math.round(window.__lcp) : null,
       domContentLoaded: nav ? Math.round(nav.domContentLoadedEventEnd - nav.startTime) : null,
@@ -563,7 +566,7 @@ async function runOfflineScenario({ browserType, server, proxy, profile }) {
 
     return {
       initialJsCss: performance.getEntriesByType('resource').filter(entry=>/\.(?:js|css)(?:[?#]|$)/.test(entry.name)&&entry.startTime <= nav.domContentLoadedEventEnd&&['script','link','css'].includes(entry.initiatorType)).reduce((sum,entry)=>sum+entry.encodedBodySize,0),
-      initialAssetRequests: performance.getEntriesByType('resource').filter(entry=>/\.(?:js|css)(?:[?#]|$)/.test(entry.name)&&entry.startTime <= nav.domContentLoadedEventEnd&&['script','link','css'].includes(entry.initiatorType)).map(entry=>({url:entry.name,bytes:entry.encodedBodySize})),
+      initialAssetRequests: performance.getEntriesByType('resource').filter(entry=>/\.(?:js|css)(?:[?#]|$)/.test(entry.name)&&entry.startTime <= nav.domContentLoadedEventEnd&&['script','link','css'].includes(entry.initiatorType)).map(entry=>({url:entry.name,bytes:entry.encodedBodySize,start:entry.startTime,responseStart:entry.responseStart,end:entry.responseEnd,initiator:entry.initiatorType})),
       fcp: fcp ? Math.round(fcp.startTime) : null,
       lcp: window.__lcp ? Math.round(window.__lcp) : null,
       domContentLoaded: nav ? Math.round(nav.domContentLoadedEventEnd - nav.startTime) : null,
@@ -717,7 +720,7 @@ async function main() {
   const treeUpdateCss = path.join(tmpRoot, 'tree-update-css');
   const treeUpdateFeature = path.join(tmpRoot, 'tree-update-feature');
 
-  let frontendSource=path.join(REPO_ROOT,'frontend');
+  let frontendSource=path.join(options.sourceRoot || REPO_ROOT,'frontend');
   if(options.frontendCommit) {
     const archive=path.join(tmpRoot,'frontend.tar');
     writeFileSync(archive,execFileSync('git',['archive',options.frontendCommit,'frontend'],{cwd:REPO_ROOT,maxBuffer:20*1024*1024}));
@@ -735,13 +738,15 @@ async function main() {
   const trees = { treeBase, treeUpdateJs, treeUpdateCss, treeUpdateFeature };
 
   const serverScratch = path.join(tmpRoot, 'server-run');
-  const server = new ServerManager(serverScratch, treeBase);
+  const server = new ServerManager(serverScratch, treeBase, options.sourceRoot || REPO_ROOT);
   await server.start();
   console.log(`Bun server running on ephemeral port ${server.port}`);
 
   const results = {
     date: new Date().toISOString(),
     frontendCommit: options.frontendCommit,
+    sourceRoot: options.sourceRoot,
+    sourceCommit: spawnSync('git', ['rev-parse','HEAD'], { cwd: options.sourceRoot || REPO_ROOT }).stdout.toString().trim(),
     frontendBuildTag: (await (await fetch('http://127.0.0.1:'+server.port+'/api/version')).json()).buildTag,
     commit: spawnSync('git', ['rev-parse', 'HEAD'], { cwd: REPO_ROOT }).stdout.toString().trim(),
     runsConfigured: options.runs,
@@ -791,6 +796,7 @@ async function main() {
             requests: coldRuns[0]?.requests || [],
             initialJsCss: summarizeList(coldRuns.map(r=>r.initialJsCss)),
             initialAssetRequests: coldRuns[0]?.initialAssetRequests || [],
+            waterfalls: coldRuns.map(r=>({fcp:r.fcp,requests:r.requests,page:r.initialAssetRequests})),
           };
         }
 

perf/proxy.mjs

@@ -47,6 +47,7 @@ export function categorizeContentType(contentType, urlPath) {
  */
 export function createThrottleProxy({ targetPort, profile = 'lte' }) {
   let activeTracking = false;
+  let trackingStart = 0;
   let requestCount = 0;
   let requests = [];
   let totalWireBytes = 0;
@@ -79,6 +80,7 @@ export function createThrottleProxy({ targetPort, profile = 'lte' }) {
       return;
     }
 
+    const requestStart = Date.now();
     reqIndex++;
     const currentReqIndex = reqIndex;
 
@@ -114,7 +116,8 @@ export function createThrottleProxy({ targetPort, profile = 'lte' }) {
         let recorded;
         if (activeTracking) {
           requestCount++;
-          recorded={url:clientReq.url,status:upRes.statusCode,bytes:0};
+          recorded={url:clientReq.url,status:upRes.statusCode,bytes:0,index:currentReqIndex,startMs:requestStart-trackingStart,headersMs:Date.now()-trackingStart};
+          clientRes.once('finish',()=>{recorded.endMs=Date.now()-trackingStart;});
           requests.push(recorded);
         }
 
@@ -176,6 +179,7 @@ export function createThrottleProxy({ targetPort, profile = 'lte' }) {
         server.close(resolve);
       }),
     startTracking: () => {
+      trackingStart = Date.now();
       activeTracking = true;
     },
     stopTracking: () => {

plans/phase6-investigation.md

@@ -0,0 +1,53 @@
+# Phase 6 investigation
+
+All comparisons use the current instrumented harness with matching frontend and
+server from detached worktrees beneath `perf/.tmp`. No production requests.
+Command template (three fresh contexts):
+
+```
+node perf/baseline.mjs --runs 3 --browser webkit --profile lte --scenario cold --source-root perf/.tmp/phase6-<variant> --out perf/results/phase6-<variant>.json
+```
+
+| Source | Commit | LTE FCP median ms | Wire bytes | app.js positive responses/sample |
+|---|---|---:|---:|---:|
+| Phase 2 | 4950d3e | 1044 | 1191063 | 2 |
+| Immediately before lazy layouts | d98d444 | 1032 | 1191686 | 2 |
+| First lazy-layout cut | 5d6a154 | 1615 | 1106796 | 2 |
+| Phase 3 tip | cd4a25a | 1646 | 1108191 | 2 |
+| Phase 5 tip (same product as Phase 4) | 21c1273 | 1736 | 1097007 | 2 |
+| Phase 5 + worker force-cache | scratch | 1745 | 1097006 | 2 |
+| Phase 5 + parser-owned classic CSS | scratch | 898 | 1097051 | 2 |
+| Phase 5 + classic preload | scratch | 909 | 1097032 | 2 |
+
+The adjacent-commit measurements isolate `5d6a154`, not the Phase 4 extraction.
+All three FCP samples, complete proxy waterfalls, and page Resource Timing are
+stored in each result. The first sample often includes startup compression cost;
+it is retained in every median, not discarded.
+
+Phase 3 sample 2: common styles finish around 880 ms. The parser-written classic
+stylesheet is discovered at 416 ms but reaches the proxy only at 1434 ms and
+finishes at 1607 ms. FCP is 1646 ms. Phase 5 sample 2: classic reaches the proxy
+at 1540 ms, finishes at 1711 ms, FCP is 1736 ms. Speculatively discovered body
+scripts already occupy the request queue when the selected stylesheet arrives.
+Phase 2 discovers its declarative styles together around 231 ms, FCP 1044 ms.
+
+The first service-worker request is at 2458 ms in Phase 3 and 2337 ms in Phase 5,
+AFTER paint. Worker install competition does not explain this FCP regression.
+Font preload URLs match the font CSS; late layout CSS is the final rendering
+barrier. Making classic CSS declarative again removes the delay without changing
+CSS bytes or cascade order. This scratch variant unconditionally applies classic
+and is diagnostic only; the shipping fix must retain selected-layout behavior.
+
+The modern synchronizer already uses default fetch caching. Changing it to
+force-cache has no effect: every WebKit sample still transfers app.js twice.
+The page and worker cannot reuse these HTTP-cache responses in this harness.
+A same-build page handoff can reuse the page HTTP cache instead. Worker validation
+must check both the X-Asset-Hash header and SHA-256 of the decoded bytes. It must
+strip compressed transport headers before constructing the cached Response.
+Updates and legacy migration must continue through their existing worker path.
+
+The shipping CSS fix is a preload, not an unconditional stylesheet. Its three-run
+FCP is 909 ms; the first classic request reaches the proxy at 250 ms and completes
+at 423 ms. Lazy still applies only the saved layout, in the original cascade order.
+Other selected layouts may speculatively download the small classic stylesheet;
+it never applies or blocks their rendering. No inline script or CSP change.