Slow load after a deploy (#911) - Test Plan and Findings

This is the INVESTIGATION run and it is frozen. The fix run, including the mechanism it settled on and the scenarios the fix has to pass, is 2026-08-20-fix.md in this folder. Scenario 4 below (observe a real hash-changing deploy) was answered there without waiting for one.

Field	Value
Issue	bug(web): the app loads very slowly after a deploy unless the browser cache is cleared manually (#911)
Branch / PR	fix/911-slow-load-after-deploy
Environment	Deployed dev, https://dev.ourlantern.app
Instrument	tooling/e2e/sw-update-cost.e2e.mjs, headless chromium, Pixel 7 profile, Slow 3G (400ms latency, 400kbps)
Builds observed	msxsov4c -> msyto7tz (2026-08-18 15:33Z)
Tester	agent measurements below; scenario 5 needs the operator
Date	2026-08-18

Summary

#	Scenario	Result	Notes
1	Worker stuck in waiting (shape A)	[x] ruled out	no waiting registration in any arm
2	App clears its own caches and reloads (shape C)	[x] confirmed, cheap	fires, costs 1.1s
3	Precache misses after a hash change (shape B)	[x] confirmed sufficient	~12s expected; simulation's 15.9s is an upper bound
4	Real hash-changing deploy observed end to end	[ ] pending	needs a web-touching deploy
4b	Does the slow state heal on the next open?	[x] yes, heals	16.8s then 1.1s, 1.1s
5	Operator confirms the symptom matches on her device	[ ] pass [ ] fail [ ] blocked

The measurements

All Slow 3G, Pixel 7 emulation, one run each, same session.

Condition	To interactive	/assets/ from network
Warm, no update	631ms	0 of 20
Warm, update path fires (shape C)	674ms, usable 1,730ms	0 of 39
Warm, caches cannot match the asset URLs (shape B)	16,972ms	30
Cold, first-ever visit	11,884ms	16 to 20

The cliff is warm-versus-cold, not update-versus-no-update. Anything that lands a returning user in an uncached state costs on the order of 12 seconds on this connection, against roughly 0.6 to 1.1 seconds when the caches match.

Correction, and the simulation's headline did not survive scrutiny. An earlier version of this document claimed a returning user is slower than a brand-new user (17.0s vs 12.0s) because the service worker re-precaches in the background. That is wrong on both counts.

Measuring who issued each request settled it: all 30 asset fetches in arm B were issued by the PAGE, none by the service worker. Splitting the URLs showed why there were 30: 16 carried the cache-busting query and 14 did not. The rewrite only touched the HTML, so the dynamic imports inside the JS bundles still referenced their original URLs, and the page fetched both sets.

A real hash change moves every URL together, so it would fetch roughly 16, not 30. Arm B therefore OVERSTATES the cost by downloading about twice the files a real deploy would, and the honest estimate for a real precache miss is close to the cold-load figure, around 12 seconds, rather than 17.

The cliff is still real and still explains the report: roughly 12 seconds against roughly 1 second when the caches match. What is not supported is "worse than a first-time visitor".

Method: attribute every number before building a story on it

Ask what produced this exact number, and answer it with an instrument rather than a guess. Three findings in this investigation were broken by that question, all three of them stories that a measurement had not established:

• 30 fetches "because the worker re-precaches" -> request.serviceWorker() showed all 30 issued by the page, none by the worker.
• "the update path did not fire" (four consecutive runs) -> every one was the harness, not the app.
• "usable in ~15s" across every arm -> a fixed waitForTimeout was being folded into the reported figure.

So before a count, a timing or a ratio goes into a report:

1. Attribute it. Which component issued this request, and how do you know? request.serviceWorker() for fetches, main-frame framenavigated for reloads, cache keys for storage.
2. Decompose it. 30 was not one population: 16 busted plus 14 un-busted. A total that hides two groups is a story waiting to be wrong.
3. Check the instrument can produce the opposite result. A number that cannot come back different is not a measurement.
4. Never let a sleep into a reported duration. Wait for the event, then measure.

Scenarios

1. Shape A: a new worker installs but sits in waiting

• Goal: Determine whether the old worker keeps serving because the new one never activates.
• Steps:
  1. Prime a persistent profile against the deployed build.
  2. After a deploy, reload the same profile.
  3. Read navigator.serviceWorker.getRegistrations() and report installing / waiting / active.
• Expected if present: a registration with a non-null waiting.
• Result: ruled out. No arm produced a waiting registration. Consistent with skipWaiting: true and clientsClaim: true in apps/web/vite.config.mjs, but measured rather than inferred from the config.

Result:    [x] ruled out
Actual:    waiting=null in every arm, active worker present and activated
Evidence:  /tmp/lantern-sw-after.json

---

2. Shape C: the app deletes its own caches and reloads

• Goal: apps/web/src/lib/versionCheck.js deletes every Cache API cache and reloads when buildId changes. Determine whether this fires, and what it costs.
• Steps:
  1. Load a warm profile and wait for the console to report Version check initialized.
  2. Only then intercept /version.json and answer with a different buildId.
  3. Call the app's own lantern.dev.versionCheck.force().
  4. Count main-frame navigations and measure time to usable.
• Expected if present: a second main-frame navigation.
• Result: confirmed, and cheap. The reload fires (2 navigations, 470ms recovery). Total cost 1.1s over the no-update control, and zero assets came from the network afterwards, so it does not produce a cold start.

Result:    [x] confirmed, not the cause
Actual:    674ms interactive, 1,730ms usable, reload observed, 0 of 39 assets from network
Evidence:  /tmp/lantern-sw-cost.json

---

3. Shape B: the new page references assets the caches cannot match

• Goal: Measure what a warm user pays when asset URLs stop matching the precache, which is what a hash change does.
• Steps:
  1. Prime a warm profile.
  2. Rewrite the served HTML so every /assets/ URL carries a query string. Workbox precache matching is URL-exact apart from a small ignore list, so this is a guaranteed miss that still resolves to the identical real file.
  3. Measure time to interactive and count assets served from the worker versus the network.
• Expected if present: a large penalty against the matching-precache control.
• Result: confirmed sufficient, with the cost overstated by the simulation. 16,972ms against a 1,109ms control. But 14 of the 30 fetches were un-busted dynamic imports the rewrite did not reach, so a real hash change would fetch about half as many. Read the cost as approximately the cold-load figure (~12s) rather than 17s.

Result:    [x] confirmed sufficient to explain the report
Actual:    16,972ms vs 1,109ms control vs 11,959ms cold ceiling; 30 assets from network
Evidence:  /tmp/lantern-shapeb.json
Driver:    all 30 fetches issued by the PAGE, 0 by the service worker (measured
           via request.serviceWorker()), so the double-fetch is NOT background
           re-precaching. It is 16 busted + 14 un-busted URLs, an artifact of
           rewriting only the HTML.
Follow-up: this CREATES the condition; scenario 4 observes it happening for real

---

4. Observe a real hash-changing deploy (pending)

• Goal: Confirm that a real deploy actually produces the shape-B condition, rather than only that the condition is expensive.

• Preconditions: a deploy that touches apps/web. The msxsov4c -> msyto7tz deploy did not: 0 of the new page's assets were absent from the old precache, and 40 of 40 were served by the worker.

  RETRACTED 2026-08-20. This reading was wrong, and it is the reason this scenario stayed open for two days. That deploy DID move every asset URL. The harness read the asset URLs off the LOADED document, and the service worker serves the previous build's index.html on the first open after a deploy, so it compared the old asset set against itself and found nothing changed. The correction and its evidence are in 2026-08-20-fix.md, scenarios 1 and 9.

• Steps:

  1. Before the deploy, run node tooling/e2e/sw-update-cost.e2e.mjs --prime to store the current precache manifest.
  2. After the deploy lands, first confirm the asset hashes actually changed by diffing the new page's /assets/ URLs against the stored manifest.
  3. If they changed, reload the primed profile under Slow 3G and record time to interactive and worker-versus-network counts.

• Expected: if the hashes changed, the primed profile should approach the scenario-3 number rather than the warm control.

• Verify: the hash diff is the precondition. A buildId change is not evidence of an asset change, which is the trap this scenario exists to avoid.

Result:    [ ] pass   [ ] fail   [ ] blocked
Actual:
Evidence:
Follow-up:

---

4b. Does the slow state HEAL on the next open? (answered)

• Goal: Scenario 5 asks the operator whether it is slow once or slow every time. Half of that is answerable here: if shape B self-heals, later opens must be fast.
• Steps: prime a warm profile, open once with asset URLs the caches cannot match, then open twice normally. Slow 3G throughout.
• Result: it heals.

Open	To interactive
1, caches cannot match	16,845ms
2, normal	1,104ms
3, normal	1,098ms

So shape B predicts "slow ONCE, then fine". That makes the operator's single observation decisive: if she reports slow on every open until a manual clear, shape B is not the mechanism and the diagnosis reopens rather than being confirmed.

Result:    [x] answered: shape B is self-healing
Actual:    16,845ms -> 1,104ms -> 1,098ms
Caveat:    RESOLVED, and it was the harness. The zeros came from closing the
           context before the worker finished precaching. Re-run holding each
           context open until the precache stopped being empty: 13 entries after
           priming, 13 again after recovering from the bad open. The app does
           repopulate; the earlier reading measured my own impatience.

           Incidental, and worth its own look: only 13 of 39 files had precached
           within a 90s window on Slow 3G, and the worker was still reported as
           `installing`. So after an update a user on a weak connection spends
           well over a minute with an INCOMPLETE precache. That is an
           observation, not a claim about the bug, and nothing here measures
           what it costs them.

---

5. Operator confirms the symptom matches (needs her device)

• Goal: Confirm the measured shape is the thing she experiences, rather than a different slow path that happens to also be slow.
• Steps:
  1. Next time the app feels slow after an update, note roughly how long before it is usable.
  2. Note whether it is slow once and then fine, or slow every time until you clear the cache.
  3. Note whether the app appears to reload itself while you are watching.
• Expected if shape B is the mechanism: slow once, in the 10 to 20 second range, then fast on subsequent opens without clearing anything. Scenario 4b measured exactly this behaviour, so a report of "slow every time until I clear it" excludes shape B rather than confirming it.
• Why it matters: if it stays slow on every open until a manual clear, that is a different mechanism from anything measured here, and the diagnosis needs reopening.

Result:    [ ] pass   [ ] fail   [ ] blocked
Actual:
Evidence:
Follow-up:

Harness traps, recorded because four runs reported a false product finding

Four consecutive runs reported "the update path did not fire". Every one was the harness, and every one would have shipped as a finding about the product.

1. page.route does not intercept requests that pass through the service worker. The spoofed /version.json never reached the app. Use context.route.
2. The spoof was installed before the app read its baseline. versionCheck captures currentBuildId from its first fetch, so both sides read the fake id, nothing differed, and the app correctly detected no change.
3. versionCheck initialises LAZILY (import('./lib/versionCheck') in main.jsx), so installing the spoof after first paint was still too early. Wait for the console line Version check initialized.
4. visibilitychange never fires headlessly, because the page is never hidden, and the fallback interval is one hour. Trigger through the app's own lantern.dev.versionCheck.force().

Additionally: a fixed waitForTimeout was being folded into the reported "usable" figure, which made every arm look like ~15 seconds regardless of what it did. Wait for the event, then measure; never add a sleep into a number you are going to report.

What is NOT established

• That a real deploy produces the shape-B condition. Scenario 4.
• The warm control in scenario 3 may be HTTP-cache-served rather than worker-served (fromSW read 0 where an earlier warm run read 20 of 20). It does not weaken the shape-B number, since a real hash change misses both caches, but "warm" there means browser-cached.
• The exact cost of a real hash change. The simulation over-fetches, so its 15.9s is an upper bound, not the expected value.
• Any figure for a real device on a real venue connection. All numbers here are emulated Slow 3G on a datacentre host, so device CPU is not represented.