diff --git a/work/projects/cpm-web-extension-breakage-findings.md b/work/projects/cpm-web-extension-breakage-findings.md index 93f1b1b2..6ac5c00a 100644 --- a/work/projects/cpm-web-extension-breakage-findings.md +++ b/work/projects/cpm-web-extension-breakage-findings.md @@ -571,3 +571,93 @@ Debug-simulation shape. Any one-off `_loadServiceWorker` failure (Network-proces | `errors == []`, probe `runtime.sendMessage` resolves `undefined`, no "Tab not found" log, SW inspector target gone | Dead worker under loaded view (chains 1, 2) | | `errors` contains `BackgroundContentFailedToLoad`, repeating every ~30 s | Repeatable registration failure (chain 5) | | Content script rejected with `tab not found`, log "Tab not found for message for content script message" | Routing (chain 4) | + + +## Diagnostics: what we have and what WebKit lets us add (2026-09-09) + +### What Site Breakage Reports carry today + +`BrokenSiteReport.swift:309-321` serialises `CookieConsentInfo`: + +| Param | Source | Discriminating power for the stuck state | +|---|---|---| +| `consentManaged`, `consentOptoutFailed`, `consentSelftestFailed`, `consentReloadLoop`, `consentRule`, `consentHeuristicEnabled` | background → native `refreshDashboardState` | Only populated if the background processed `init`. In every stuck chain they stay at defaults. | +| `cpmDashboardState` | `.waiting` set per navigation (`PrivacyDashboardTabExtension.swift:185`), `.applied` when the background answers | `waiting` = "background never processed `init` for this document". Cannot say why. | +| `cpmStage` | background (`not_started`, `config_unavailable`, `settings_missing`, `setting_disabled`, `site_disabled`, `init_received`, `popup_found`, `optout_failed`, `done`) | `not_started` in every stuck chain (it is the app default, never overwritten). | +| `cpmErrors` | background: `tab_` / `glob_` native-messaging timeouts, `multiple_cmps` (`background-embedded.js:2926, 2803`) | Background → native failures only. Empty in every content→background failure. | +| `cpmQueueSize`, `cpmConfigVersion` | background | Same — absent when the background is silent. | +| `cpmExtensionLoaded` | `controller.extensionContexts` contains the embedded type (`WebExtensionManaging.swift:174`) | UIProcess "context loaded". **True in chains 1, 2, 4, 5** — it does not see a dead worker, a retained failed view, or a missing tab. Only false during the Fire/reload window. | +| `cpmExtensionDroppedCallbacks` | `WebExtensionEventsListener` calls made while `controller == nil` | Only meaningful for chain 4 (missed `didOpenTab`), and only if the drop happened while `controller` was nil. | + +Net: a stuck-state report reads `cpmDashboardState=waiting, cpmStage=not_started, cpmExtensionLoaded=1, cpmErrors=""` for chains 1, 2, 4, 5 alike, and also for "content script never injected" (chain 3). **Nothing in the report separates the five.** Everything below is about adding that separation. + +### Hooks per hypothesis + +Legend: **P** = public API, **S** = SPI (same class as the `_webExtensionController:didCreateBackgroundWebView:` selector the app already uses), **L** = readable from the app's own `OSLogStore`, **E** = extension (JS) change. + +#### Chain 1/2 — worker terminated under a "loaded" background view + +WebKit gives the app nothing directly: no delegate, no notification, no error. Indirect signals: + +- **S** `WKWebExtensionContext._backgroundWebView` (`WKWebExtensionContextPrivate.h:38`), or keep the `WKWebView` handed to `didCreateBackgroundWebView` (the app already receives it). Then, with **P** `callAsyncJavaScript` on that view (it is the generated SW *page*, main world): + `const r = await navigator.serviceWorker.getRegistration(); return { hasRegistration: !!r, state: r?.active?.state ?? null, controller: !!navigator.serviceWorker.controller }` + – `hasRegistration == false` while `context.errors` is empty ⇒ **chain 2** (registration was in-memory in the dead Network process). + – `hasRegistration == true, state == "activated"` while the content-script probe (below) gets `undefined` ⇒ **chain 1** (worker killed, registration intact). The client-side `ServiceWorker.state` does not reflect termination, so this needs the probe pair, not the state alone. + Pixel params: `cpmBgViewExists`, `cpmBgSwRegistration`, `cpmBgSwState`. +- **S** `WKWebsiteDataStore.default()._networkProcessIdentifier` / `_networkProcessExists` (`WKWebsiteDataStorePrivate.h:124-126`, macOS 12+). Record at context load; on a stuck episode compare. PID changed ⇒ Network process restarted ⇒ chain 2. Param: `cpmNetworkProcessRestarted` (+ seconds since). +- **L** `NetworkProcessProxy::didClose` logs `RELEASE_LOG_ERROR(Process, "... NetworkProcessProxy::didClose (Network Process %d crash)")` (`NetworkProcessProxy.cpp:525`) and `didBecomeUnresponsive` logs an error too (`:183`). These run **in the app process**, so `OSLogStore(scope: .currentProcessIdentifier)` with predicate `subsystem == "com.apple.WebKit" AND category == "Process"` returns them without entitlements. Param: `cpmNetworkProcessCrashCount` in the last N minutes. +- **P** app-side `DispatchSource.makeMemoryPressureSource(eventMask: [.warning, .critical])` — the same kernel event the WebProcess reacts to in chain 1. Record timestamp of last `.critical`. Params: `cpmMemPressureCriticalRecently`, `cpmSecondsSinceCritical`. This is the single most valuable new field for chain 1 and costs nothing. +- **S** `WKWebView._webProcessIdentifier` (`WKWebViewPrivate.h:226`) on the retained background view: `0` ⇒ SW-page process gone (WebKit *does* handle that case via `webViewWebContentProcessDidTerminate`, so it should be rare — useful as a sanity check). Param: `cpmBgProcessAlive`. +- **P** `WKWebExtensionContext.loadBackgroundContent(completionHandler:)` — returns immediately with `nil` in chains 1/2 (WebKit thinks it is loaded), with the load error in chain 5, never/late in chain 6. Param: `cpmBgLoadProbe` = `ok | error: | timeout`. +- **E + P** Content-script probe: evaluate in the extension's content world from the app — `WKContentWorld.world(name: "WebExtension-\(context.uniqueIdentifier)")` maps to the same `API::ContentWorld::sharedWorldWithName` WebKit uses for injection (`WebExtensionContextCocoa.mm:293`, `WKContentWorld.mm:59-64`). Have `cpm.js` publish `globalThis.__ddgCPM = { injectedAt, lifecycle, initSentAt, initResp: bool, lastSendError }` (a few lines; `sendContentMessage` currently `await`s without a catch, `cpm.js:3393-3398`). Then `evaluateJavaScript("globalThis.__ddgCPM", in: nil, in: world)` from the tab yields: + – `undefined` ⇒ content script never injected ⇒ **chain 3** (startup/Fire window) — `cpmContentScriptInjected=0`. + – `lifecycle == "waitingForInitResponse"`, `lastSendError == null` ⇒ background silent ⇒ chains 1/2/5 (use the other params to split). + – `lastSendError` contains `tab not found` ⇒ **chain 4**. + Do not use `typeof chrome` as the marker: evaluating in the world can itself trigger `globalObjectIsAvailableForFrame` and inject the `browser` namespace. + +**Recovery, not just diagnosis (chain 1):** from the SW page, `r.active.postMessage({type:"ping"})` goes through the SW server (`SWServer::runServiceWorkerIfNecessary`, `SWServer.cpp:1221`), which starts a not-running worker. On start, `ServiceWorkerGlobalScope::notifyServiceWorkerPageOfCreationIfNecessary` re-binds the page and fires `dispatchServiceWorkerGlobalObjectAvailable` → `serviceWorkerGlobalObjectIsAvailableForFrame` re-installs `browser` (`ServiceWorkerGlobalScope.cpp:118-132`, `WebLocalFrameLoaderClient.cpp:1968-1980`) and the background script re-runs, re-registering `onMessage`. That would revive CPM without unloading the context. Needs a manual test; if it works it is a one-line remediation on `cpmMessagingStuck`. It cannot help chain 2 (no registration) — that needs the context reload. + +#### Chain 3 — content script not injected (startup / Fire / reload window) + +- **P** `WKWebExtensionContext.isLoaded` and `hasInjectedContent(for: url)` at `navigationCommitted`. Param: `cpmContextLoadedAtCommit`, `cpmInjectedContentForURL`. +- **E + P** the content-world probe above (`cpmContentScriptInjected`). +- **P** timing: `Date()` at `controller.load(context)` minus the first `loadBackgroundContent` completion = time the `_renameOrigin` gate held the load. Param: `cpmContextReadyMs`. Expect this to collapse once `baseURL` is set. +- Already available: `WebExtensionLifecycleEvent` stream (`loaded/willReload/reloaded/reloadFailed`) — attach `cpmMsSinceLastReload` to the report. + +#### Chain 4 — tab not resolvable + +- **P** `WKWebExtensionContext.openTabs` (`WKWebExtensionContext.h:683`) → `openTabs.contains { $0 === currentTab }`. This is exactly the set `getCurrentTab` searches. Param: `cpmTabKnownToWebKit`. Also `openWindows.contains(windowController)`: `cpmWindowKnownToWebKit`. +- **L** `RELEASE_LOG_ERROR(Extensions, "Tab not found for message for content script message")` (`WebExtensionContextAPIRuntimeCocoa.mm:144`) is emitted in the app process → `OSLogStore` predicate `category == "Extensions" AND eventMessage CONTAINS "Tab not found"`. Param: `cpmTabNotFoundLogCount`. +- Already available: `cpmExtensionDroppedCallbacks` (keep). + +#### Chain 5 — repeatable registration failure + +- **P** `WKWebExtensionContext.errors` + `WKWebExtensionContext.errorsDidUpdateNotification` (`WKWebExtensionContext.h:73, 179`). Serialise `code` (`WKWebExtensionContextErrorBackgroundContentFailedToLoad = 6`) and the underlying `NSError` domain/code (`NSURLErrorFileDoesNotExist`, etc.). Param: `cpmContextErrors` = `"6:NSURLErrorDomain/-1100"`. +- **S** count `didCreateBackgroundWebView` callbacks per context lifetime: >1 means WebKit is retrying background loads. Param: `cpmBgViewCreateCount`. +- **L** `WebExtensionContext::recordError` logs `RELEASE_LOG_ERROR(Extensions, "Error recorded: …")` (`WebExtensionContextCocoa.mm:283`) — redundant with `errors`, but timestamps each retry. +- **P** `FileManager.default.isReadableFile(atPath: installedPath/public/js/background-embedded.js)` at report time. Param: `cpmBundleReadable`. + +#### Chain 6 — transient registration failure + +Covered by `cpmContextErrors` + `cpmBgViewCreateCount`; the health monitor's `recoveredWithoutExtensionReload` closes it. + +#### Chain 7 — listener gating + +No hook; `m_backgroundContentEventListeners` is not exposed. If everything else reads healthy (`cpmBgSwRegistration=1`, content-script probe shows `waitingForInitResponse`, `errors == []`, no memory pressure, no Network restart, background revives on `postMessage`), this is the residual bucket. + +### What is *not* catchable from the app + +- SW-server side logs (`SWServer::terminateIdleServiceWorkers`, `runRegisterJob`) live in the Network process; `OSLogStore` only covers our own PID without the `com.apple.private.logging.*` entitlement. `log collect` from users' machines is the only route. +- `RELEASE_LOG_DEBUG` lines ("Loading background content", "Background content loaded", "Scheduling background content to unload") are debug level and not persisted unless the device has WebKit logging enabled; do not depend on them. +- There is no notification for background-view unload/reload or for worker start/stop. + +### Suggested minimal pixel/report additions (ranked by value ÷ cost) + +1. `cpmMemPressureCriticalRecently` + `cpmSecondsSinceCritical` — public, in-app, ~20 lines. Separates chain 1. +2. `cpmNetworkProcessRestarted` (PID compare) or `cpmNetworkProcessCrashCount` (OSLogStore) — separates chain 2. +3. `cpmContextErrors` + `cpmBgViewCreateCount` — separates chains 5/6. +4. `cpmTabKnownToWebKit` + `cpmTabNotFoundLogCount` — separates chain 4. +5. `cpmContentScriptInjected` / `cpmContentScriptLifecycle` / `cpmLastSendError` via the content-world probe — separates chain 3 and confirms "background silent" for the rest. Needs the small `cpm.js` global. +6. `cpmBgSwRegistration` / `cpmBgSwState` via the SW-page probe — confirms 1 vs 2. SPI-adjacent (needs the background `WKWebView` reference). + +Items 1–4 are enough to attribute the current stuck pixels; 5–6 turn the health monitor into a classifier instead of a timer.