diff --git a/work/projects/cpm-web-extension-data-analysis-summary-2026-10-08.md b/work/projects/cpm-web-extension-data-analysis-summary-2026-10-08.md new file mode 100644 index 00000000..087ba8ad --- /dev/null +++ b/work/projects/cpm-web-extension-data-analysis-summary-2026-10-08.md @@ -0,0 +1,113 @@ +--- +title: CPM Web Extension failures — data analysis summary +date: '2026-10-08' +status: draft-for-asana +tags: + - work + - cpm + - webkit +--- + +# CPM Web Extension failures — data analysis summary + +Companion note: [[cpm-web-extension-repro-and-fixes-summary-2026-10-08]] (tests and fixes). Detailed working notes (Russian): [[cpm-web-extension-repro-and-fix-2026-10-08]], [[cpm-web-extension-breakage-session-summary-2026-10-07]]. + +## TL;DR + +- Most CPM "failures" are not a dead extension. The failure pixels mean that within 4 s after a page finished loading, the app received no `refreshCpmDashboardState` call from the extension. A late answer counts as a failure too. +- The largest cohort, a failure while the app-side state looks healthy, mostly happens right after WebKit wakes the extension's background after idle. A test reproduces it exactly when the background service worker takes longer than 4 s to start. Many of these failures are late responses, not lost ones. +- The second-largest cohort on iOS is WebKit error 6, where the background fails to load. Its root cause is in WebKit: the 30 s idle-unload timer starts before the background has finished loading. +- A Network process crash explains only 20–45% of the "healthy" stuck cases. It is the only mechanism that breaks every tab at once, including pages that were already open. +- New telemetry (phase 1) separates "slow start" from "lost message" and "late" from "lost". It is ready and should ship before or together with the fixes. + +## What the pixels measure + +- `initialization_failed_after_`: the first navigation with no CPM answer within 4 s. Sent once per day per reason. +- `messaging_stuck_`: a second failure in the same episode, from a navigation that started after the first failure. This triggers recovery M4, a reload of the extension. +- `recovered_without_extension_reload` and `recovered_after_extension_reload`: the episode closed because an answer finally arrived. +- Each failure pixel carries a snapshot of app state: whether the context is loaded, background view and process state, tab binding, context errors, and `bg_events`, a short timeline of background lifecycle events. + +## Scope + +- One UTC day, October 5, 2026. Only events after the release tag of iOS 7.240 and macOS 1.210. +- First `initialization_failed`, daily: 6,624 on iOS, 1,377 on macOS. +- `messaging_stuck`, daily: 1,440 on iOS, 487 on macOS. +- Daily pixels count installs per day, not users or episodes. + +## Cohorts of stuck reports + +These are snapshot states at the time of the timeout, not root causes. Each report is assigned to one cohort, by priority. + +1. **Healthy snapshot, no visible error.** iOS 1,410, macOS 705 (stuck counts); about 55% of iOS stuck daily. + - The Network process had changed since the context loaded in 17–21% of iOS and 30–45% of macOS reports. + - The rest is called **"group 1"** below: iOS 748, macOS 228 (daily). +2. **WebKit error 6** (`BackgroundContentFailedToLoad`). iOS 579, about a third of iOS stuck reports; macOS 3. +3. **No background view.** iOS 158, macOS 35. +4. **Tab not attached to the extension.** Wrong controller or missing content scripts. iOS 81, macOS 102. On macOS these appear only after the 1.210 release tag. +5. **Background process died** (`died_*`). iOS 14; 86% of these also had a Network process change, which looks like iOS killing both processes at once. + +## Group 1: the largest unexplained cohort + +- **About half follow a background wake.** The timeline tail is "old view deallocated, new view created", with the new view under 30 s old: iOS 373 of 748, macOS 120 of 228. +- **About a quarter on iOS and 15% on macOS follow a context load or reload**: `load → view` or `base_url_changed → view`. +- On macOS, 63% of reports were sent shortly after an app update, against 52% across all stuck reports. +- Memory pressure and context errors are almost always absent. +- Both macOS 26.7 and 27.0 are affected. The iOS OS-version split has not been queried yet. + +**Recoveries:** +- An `initialization_failed` episode recovers without a reload on 23% of iOS and 25% of macOS device-days. Counting only "other" navigations, the figure is 33% on both platforms. Recoveries repeat on the same devices, about 1.9 per device-day on iOS. +- After M4, a stuck episode recovers on 64% of iOS and 74% of macOS device-days. +- Recovery pixels do not yet say whether the answer was late or came from a later page. Phase 1 telemetry adds this. + +**Init failures compared with stuck reports, iOS healthy snapshots:** +- After a context load: 32% of init failures, 18% of stuck reports. +- After a wake: 44% of init failures, 61% of stuck reports. +- So failures after a context load usually clear on their own, while failures on wake more often escalate to stuck. + +## Theories and status + +- **Network process crash leaves a dead service worker.** Confirmed by test. Explains at most 20–45% of healthy stuck reports. Fixed in the app; fix not merged. +- **First-load message drop**, WebKit 317981-like. Confirmed by test. At launch the existing gate already covers it; mid-session install or upgrade was a gap, now fixed in the app (not merged). +- **Service worker dies while the Network process stays alive.** Confirmed by test, but the app cannot detect it. Mitigation: restart the background after the first failure. +- **Error 6.** Root cause found in WebKit source and reproduced on macOS. Not reproduced on an iPhone with iOS 26.7.1. Telemetry added. +- **Slow service-worker start on wake.** A start longer than 4 s reproduces the group 1 signature exactly. Why real devices are that slow is unknown; candidates are CPU contention with the loading tab, process launch, the extension process's priority, and a busy Network process. Telemetry added. +- **Context-load cleanup when the base URL changes** (WebKit 312231@main, bug 320812). Reproduced on macOS: with about 20–24k network-cache entries, content scripts are delayed by 0.75–1.35 s. Explains part of the "after load or reload" subset. Possible mitigation: give the extension a stable base URL. +- **Ruled out:** device lock and data protection, a stale iOS tab URL, a macOS feature-flag flip explaining the tab-binding cohort, the low-memory notification, background freezes of 10–75 s as a cascade trigger, and killing the background WebContent process. +- **Not reproduced yet:** + - the macOS tab-binding cohort; + - the "no background view" cohort; + - error code 7; + - Lockdown Mode; + - the first probe after M4 failing (670 on iOS, 232 on macOS). + +## Relevant WebKit bugs + +- **317981**: a message sent while the background is still loading is dropped. Reproduced on macOS 26.7.1 for the first load of a new extension identifier. Fixed in the `safari-7625` branch. +- **324743**: a service worker is treated as loaded before its registration completes. Fixed September 22, not in 26.7 or 27.0. Fits the wake path; no deterministic repro. +- **320812, introduced by 312231@main** (26.6+): when the base URL changes, context load deletes all website data of the previous origin, including the whole disk cache, before it injects content or loads the background. The DDG extension gets a new base URL on every launch and every reload. Fixed by 318756@main and cherry-picked to `safari-7625`; which OS build ships it is unverified. +- **314194** (open): Lockdown Mode blocks every service worker, so CPM cannot work. The share of affected users is unknown. +- **322881** (clients lost after reload) and **324754** (reloaded worker without extension bindings under site isolation): low relevance to CPM, unproven. +- **319976** (fixed): `loadBackgroundContent` completion called twice on error. We use this API. +- **To file:** + 1. A dead worker after a Network process crash goes unnoticed by `WebExtensionContext`. + 2. The 30 s unload timer is started before the background finishes loading, which causes error 6. + +## Telemetry added (phase 1, not merged) + +All values are buckets or enums, with no URLs or identifiers. + +- **On failure pixels:** + - `bg_ready_after`: whether the background had finished loading at the time of the failure, and how long the load took; + - `bg_view_age`: how long ago the current background view was created; + - `app_state`; + - `open_tabs` and `loading_tabs`; + - `bg_load_error_app_state` and `bg_load_error_after`: app state and timing for error 6. +- **On recovery pixels:** + - `recovery_document`: whether the failed navigation answered late, a later navigation answered, or the response matched no single tab; + - `recovery_after`: time from the episode's first failure to the recovery. + +**How to read the results:** +- `bg_ready_after=pending` with a young view means a slow wake. +- `bg_ready_after` loaded with no answer means a lost message. +- `recovery_document=failed_navigation` means a late answer, not a loss. +- For error 6, `bg_load_error_after=25s_to_35s` points at WebKit's unload timer. diff --git a/work/projects/cpm-web-extension-repro-and-fixes-summary-2026-10-08.md b/work/projects/cpm-web-extension-repro-and-fixes-summary-2026-10-08.md new file mode 100644 index 00000000..469a5d99 --- /dev/null +++ b/work/projects/cpm-web-extension-repro-and-fixes-summary-2026-10-08.md @@ -0,0 +1,98 @@ +--- +title: CPM Web Extension failures — reproduction, fixes and mitigations +date: '2026-10-08' +status: draft-for-asana +tags: + - work + - cpm + - webkit +--- + +# CPM Web Extension failures — reproduction, fixes and mitigations + +Companion note: [[cpm-web-extension-data-analysis-summary-2026-10-08]] (cohorts and theories). Detailed working notes (Russian): [[cpm-web-extension-repro-and-fix-2026-10-08]]. + +Status: nothing is committed or merged yet. Code lives in three local branches, listed at the end. + +## Test harness + +- XCTest suite against the **real system WebKit**. Tested on macOS 26.7.1. +- It loads the **production embedded extension** and drives the real `WebExtensionManager`, the lifecycle coordinator with the navigation gate, the CPM health monitor (4 s grace period), M4 recovery, and the production diagnostics recorder. Failures therefore produce the same pixel parameters as in production. +- Extension logic is unchanged. Faults are injected from outside: + - kill or freeze WebKit processes (`SIGKILL`, `SIGSTOP`); + - call WebKit SPI, such as terminating service workers; + - prepend delays to the extension scripts, either once at startup or only for one wake; + - fill the network cache; + - remove extension files. +- Opt-in, so it does not slow down CI: `CPM_REPRO=1 swift test --filter CPMRepro` in `SharedPackages/WebExtensions`. `CPM_REPRO_WEBKIT=1` adds tests that confirm the WebKit bugs are still present; they will fail once Apple ships fixes. +- The iOS Simulator is not representative: test processes get no RunningBoard assertions. Device checks used an iPhone 12 mini with iOS 26.7.1. + +## Failure modes reproduced + +1. **Lost first message on a new extension identifier** (first install or upgrade). WebKit loads the background eagerly, and an `init` sent before the background script has run is dropped. Without the gate, 14/20 messages were lost on install and 18/20 on upgrade. At launch the existing gate already prevents this; mid-session install or upgrade did not. +2. **Full failure after a Network process crash.** The background view and process survive, but the service worker is dead. Every tab loses CPM, including pages that were already open. M4 fixes new navigations only; pages opened before the crash stay broken. Reproduced 20 out of 20 times. +3. **Service worker dead while the Network process is alive.** Triggered by terminating service workers or removing their registrations. Same symptoms as above. The app cannot detect it: the registration still says "activated". +4. **Error 6.** A woken background that cannot finish loading within 30 s is closed by WebKit's idle-unload timer, which reports error 6. The test reproduces the production signature (`bg_load_error_after=25s_to_35s`). Not reproduced on the iPhone in four scenarios. +5. **Slow worker start on wake** (the group 1 signature). + - Start ≤ 2.5 s: messages are queued and delivered, nothing is lost. + - Start of 5 s: `initialization_failed` with a healthy snapshot and the production-like timeline tail, then the late answer arrives and the episode recovers without a reload. + - Start of 12 s plus a second navigation: `messaging_stuck`, then M4. M4 kills the slow but healthy worker, and the pending `init` messages of already-open pages are lost. +6. **Context-load cleanup delay** (WebKit 312231@main). With about 20–24k network-cache entries, content scripts ran 0.75–1.35 s late on relaunch and on reload, against 23 ms with an empty cache. That is under 4 s on a fast Mac; slow devices are still to be measured. + +**Recovery findings:** +- Killing only the background WebContent process makes WebKit start a fresh worker. It fixes every tab, including already-open pages. +- An extension reload (M4) fixes new navigations only. +- Calling `loadBackgroundContent` does nothing for a dead worker. + +**Readiness signals measured during a 5 s slow start:** +- The background view finishes its own page load after 0.1 s, so it says nothing about the worker. +- The `loadBackgroundContent` completion and the worker's first native message both arrive right after the worker's startup code has run. Both are accurate readiness signals. + +## Fixes (app side, branch `alex/cpm-web-extension-ready-handshake`) + +1. **Gate mid-session install and upgrade.** After a new embedded extension is installed, navigations wait (up to 5 s) for its first background load, as they already do at launch. +2. **Network process watchdog.** Records the Network process PID of the background. If it changes, the watchdog restarts only the background WebContent process. Checked on every navigation and every second. +3. **Restart the background on the first failure**, but only if the background process responds to a script call within 1 s. Killing a frozen process left the replacement worker deaf. +4. Items 2 and 3 share one switch, which is on by default and not yet tied to a remote flag. + +**Results, without fix → with fix:** +- Mid-session install: 3/3 lost → 5/5 delivered. +- Mid-session upgrade: 5/5 lost → 5/5 delivered. +- Network process crash with 4 tabs and open pages: all broken → all working, including already-open pages and with M4 disabled. +- Worker death without a Network process crash: two failures, then M4, and old pages stay broken → one lost navigation, then everything works without a reload. + +**Known gap:** fix 3 can hurt a slow wake. If the slow worker does not keep the CPU busy (for example it waits on I/O), the process still answers, gets restarted, and the late answer turns into a lost one. Restarts should be held back while the background is still starting. The phase 2 detector below covers this. + +## Telemetry (branch `alex/cpm-messaging-readiness-telemetry`, phase 1) + +- Telemetry only; the detector's behavior is unchanged. Ship it before the fixes, or together with them in an A/B experiment. +- **On failure pixels:** `bg_ready_after`, `bg_view_age`, `app_state`, `open_tabs`, `loading_tabs`, and the error 6 fields `bg_load_error_app_state` and `bg_load_error_after`. +- **On recovery pixels:** `recovery_document` (failed navigation answered late, later navigation, or unattributed) and `recovery_after`. +- **Readiness source:** the app calls `loadBackgroundContent` once, when WebKit creates a background view. The view already exists, so the call joins the load in progress and wakes nothing. It is behind the same remote flag as the existing background delegate proxy. +- Verified against real WebKit with a 5 s slow wake: `bg_ready_after=pending`, `bg_view_age=4s_to_8s`, then `recovery_document=failed_navigation`, `recovery_after=under_4s`. +- 677 package tests pass. SwiftLint is clean. Pixel definitions validate on iOS and macOS. Both apps build. + +## Mitigations still to decide + +- **Detector phase 2.** + - Start the 4 s grace period only once the background is ready. + - Report "background did not start within 30 s" as its own pixel. + - Escalate to stuck, M4 or a restart only for failures with a ready background. + - This removes slow-start false positives. +- **Wake the background early** when a navigation starts or the app comes to the foreground, without blocking the navigation. Wake-up time then overlaps with the page load. +- **Stable base URL** for embedded extensions (branch `alex/cpm-stable-base-url`). Removes the cleanup on every launch and reload. + - Privacy check: no embedded extension declares `web_accessible_resources`, and pages cannot see the URL. + - Still to verify: M4 and crash recovery with a stable URL, and the upgrade path. +- **Error 6:** once data shows the app state, restart the background when the app returns to the foreground if error 6 was recorded. +- **Extension side:** + - a retry handshake for `init`, covering lost and late messages whatever the cause; + - a ping or heartbeat channel, which would allow zero-loss detection of a dead worker. +- **Feature flags and A/B:** put the watchdog and the restart behind remote flags and expose the cohort in CPM pixels. Comparing release versions proved inconclusive. +- **Report to WebKit:** the dead worker after a Network process crash, and the 30 s unload timer that starts before the load finishes. + +## Branches (local, uncommitted) + +- `alex/cpm-web-extension-ready-handshake`: the fixes and the main test harness. +- `alex/cpm-web-extension-remaining-failures`: production code without fixes; the error 6 and slow-wake reproductions. +- `alex/cpm-messaging-readiness-telemetry`: phase 1 telemetry, based on current `main`. +- `alex/cpm-stable-base-url`: the stable base URL experiment.