docs: correct portal-prefetch root cause (h2, server-side queue) + measured outcome

The HTTP/1.1 / six-connection-cap claim was wrong — it came from the
Schannel curl build that cannot speak HTTP/2. ALPN (openssl s_client)
and .NET HttpClient confirm the portal negotiates h2; the queue is
server-side in the SWA SSR runtime. Doc, index, log and the
GlobalSidebar comment now describe the real mechanism.

Adds the 2026-07-28 outcome section: Standard plan changed nothing
(stratified p50s match, Mann-Whitney p=0.81); prefetch={false} removed
the freezes (worst totalDuration 225s -> 4.9s) and also removed an
accidental keep-alive (~150ms added to cold navigations).

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
Oliver Kieselbach
2026-07-28 16:52:19 +02:00
parent 249c20e15a
commit 21b8e054df
4 changed files with 50 additions and 17 deletions
+1 -1
View File
@@ -44,7 +44,7 @@ https://docs.autopilotmonitor.com (separate repository).
# Web Portal
* [Portal Navigation Prefetch & the SWA Runtime Bottleneck](web/portal-navigation-prefetch.md) - Why every navigation Link sets `prefetch={false}`: the App Router's viewport prefetch fans out one RSC request per visible link against an HTTP/1.1 Static Web Apps runtime, and its latency tail starves the six connections that also serve the document and the route chunks. Includes where browser telemetry actually lives.
* [Portal Navigation Prefetch & the SWA Runtime Bottleneck](web/portal-navigation-prefetch.md) - Why every navigation Link sets `prefetch={false}`: the App Router's viewport prefetch fans out one RSC request per visible link and the Static Web Apps SSR runtime queues them server-side into a multi-minute tail. Records the follow-up measurement (the Standard plan changed nothing; the prefetch storm was an accidental keep-alive), where browser telemetry actually lives, and why this curl build cannot be trusted for HTTP versions.
# Security & Identity
+3 -1
View File
@@ -6,9 +6,11 @@
* **Creation**: Added `agent/gather-rule-debug-log.md` — the new per-tenant setting `EnableGatherRuleDebugLog` (ConfigVersion 35 → 36, portal toggle under Settings → Agent, `EnableImeMatchLog`-style bool→path projection in `RemoteConfigMerger`). When enabled, the agent writes `%ProgramData%\AutopilotMonitor\Logs\gather_rules_debug.log`: one pipe-delimited line per evaluation decision across ten previously silent "produced nothing" exits — disabled rules, `interval` without `intervalSeconds` (never runs), the first-tick-after-one-full-interval window, phase-scope skips incl. `currentPhase=Unknown`, per-(rule, phase) dedup, empty collector results (`emitOnlyIfExists`), `on_change` hash suppression (hash prefix + streak), guard blocks, logparser per-file outcomes (position skips, parse failures with a `format=text` hint when every line fails CMTrace parsing, `maxLines`/wildcard caps), and full exception stacks that the agent log drops. 10 MB cap + one `.old` generation; no hot-reload (per-enrollment lifecycle); flag survives the offline config cache; `--run-gather-rules` always traces and echoes under `--console`; zero-rules delivery leaves a one-line file instead of nothing. Side fix: `GatherRuleExecutorHost` now passes the logger into `InformationalEventPost`, so gather-event emissions appear in the agent DEBUG log.
* **Correction + Update**: `web/portal-navigation-prefetch.md`. The HTTP/1.1 claim in the 2026-07-27 entry below is **wrong** and has been struck from the document: `portal.autopilotmonitor.com` negotiates **h2**, verified by `openssl s_client -alpn h2,http/1.1` and a .NET `HttpClient` returning `HTTP/2.0`. The false reading came from the Windows/Schannel curl build in this environment, which has no HTTP/2 support and therefore always reports `1.1` — do not use it to determine HTTP versions. There is no six-connection cap in play; the queue is server-side in the SWA SSR runtime, which does not change the fix or the evidence, only the mechanism. Added an `Outcome` section with 20 h of post-change telemetry: the Free → Standard plan change (16:02:44 UTC) produced **no measurable latency gain** once stratified by the gap to the previous request (p50 Free → Standard: `<10s` 85 → 95 ms, `5-30min` 429 → 441 ms; tail rates 1.64 %/0.374 % over 2 s/10 s vs 6 and 1 events at n = 258 against 4.2 and 1.0 expected; `browserTimings` Mann-Whitney z = −0.24, p = 0.81). The freezes were removed by `prefetch={false}` (16:34:13 UTC): worst `browserTimings.totalDuration` 225,277 → 4,856 ms. The prefetch storm was also an **accidental keep-alive** — requests under 10 s apart fell from 85 % to 46 %, and on the identical never-cacheable `/sessions/{id}` route the median rose 87 → 211 ms and p90 465 → 1,480 ms, with one 11,441 ms abandoned request (`resultCode 0`) after 517 minutes idle. Synthetic bursts warm the runtime and must not be used to benchmark this (round 1 p50 288 ms vs rounds 4–25 p50 113 ms).
## 2026-07-27
* **Creation**: Added `web/portal-navigation-prefetch.md` (and a `Web Portal` section to the index) — root cause of the minute-long portal freezes. `GlobalSidebar` and `Navbar` render the whole navigation on every page, so the App Router's default viewport prefetch issued one `?_rsc=` request per visible link against `portal.autopilotmonitor.com` (~10,400 in 14 days). That origin serves the document, the route chunks and the RSC payloads over **HTTP/1.1**, so the six-connection-per-origin cap applies; when the Static Web Apps managed runtime queued the prefetches (p50 91 ms, p95 896 ms, but max 234 s / 21 samples over 30 s), the in-flight prefetches held every socket and the navigation the user wanted could not get one. Measured on the 2026-07-27 17:25 CEST incident: `/admin/presence?_rsc=` 151 s, three siblings finishing within 340 ms of each other at ~37.5 s, all `200`, while the backend API answered in 1.6–2.2 s and `browserTimings` showed `networkDuration` 16 ms against `processingDuration` 225 s. Every navigation Link now sets `prefetch={false}` — these routes are client components behind `ProtectedRoute` that fetch their own data, so the prefetched RSC payload carried no benefit. The doc also records that browser telemetry lives in a **separate** App Insights resource (`AUTOPILOT_MONITOR_WEB_APPINSIGHTS_ID`) that the MCP `query_backend_logs` tool cannot reach, which is why the freezes left no trace in the backend logs.
* **Creation**: Added `web/portal-navigation-prefetch.md` (and a `Web Portal` section to the index) — root cause of the minute-long portal freezes. `GlobalSidebar` and `Navbar` render the whole navigation on every page, so the App Router's default viewport prefetch issued one `?_rsc=` request per visible link against `portal.autopilotmonitor.com` (~10,400 in 14 days). *(The original entry attributed the freeze to HTTP/1.1 and a six-connection-per-origin cap — see the 2026-07-28 correction; the queue is server-side.)* When the Static Web Apps managed runtime queued the prefetches (p50 91 ms, p95 896 ms, but max 234 s / 21 samples over 30 s), the navigation the user wanted was stuck behind that queue. Measured on the 2026-07-27 17:25 CEST incident: `/admin/presence?_rsc=` 151 s, three siblings finishing within 340 ms of each other at ~37.5 s, all `200`, while the backend API answered in 1.6–2.2 s and `browserTimings` showed `networkDuration` 16 ms against `processingDuration` 225 s. Every navigation Link now sets `prefetch={false}` — these routes are client components behind `ProtectedRoute` that fetch their own data, so the prefetched RSC payload carried no benefit. The doc also records that browser telemetry lives in a **separate** App Insights resource (`AUTOPILOT_MONITOR_WEB_APPINSIGHTS_ID`) that the MCP `query_backend_logs` tool cannot reach, which is why the freezes left no trace in the backend logs.
* **Creation**: Added `backend/rule-regression-radar.md` — F3 regression radar (analyze rules only; gather rules wait for their per-batch stats dedup fix): per (tenant, rule) daily hit rate from `RuleStats`, firing only when the trailing 7-day window has ≥5 hit sessions and ≥20 evaluated sessions, the rate is ≥2× the prior 28-day baseline AND the Wilson 95 % intervals are disjoint (deterministic `MetricsMath` primitive with hand-computed test vectors). Suppressed for deleted rules, rules younger than baseline+window (`CreatedAt` grace), rules edited inside the window (`UpdatedAt`), empty baselines, and the `RuleRegressionRadarDisabled` app-setting kill switch. Alert episodes live as `ruleregression|{ruleId}` tracker rows (one bell + one `RuleFrequencyRegression` ops event per episode; numbers refreshed while active; re-armed under 1.5× baseline, on fire-stop, or by the 30-day tracker retention). On-fire dimension correlation over osBuild/model/agentVersion/imeVersion with the "correlated, not necessarily causal" wording contract. Surfaces: `regressions[]` in the rule-stats response (MCP inherits), the analyze-rules page's 30-day sparkline and regression badge.
+43 -11
View File
@@ -1,7 +1,7 @@
---
type: Concept
title: Portal Navigation Prefetch & the SWA Runtime Bottleneck
description: Why every navigation Link in the portal sets prefetch={false} — the App Router's viewport prefetch fires one RSC request per visible link against an HTTP/1.1 Static Web Apps runtime, and its latency tail starves the connection pool that serves the document and the route chunks.
description: Why every navigation Link in the portal sets prefetch={false} — the App Router's viewport prefetch fires one RSC request per visible link, and the Static Web Apps SSR runtime queues them server-side into a multi-minute latency tail. Also records what the follow-up measurement showed about the Standard SKU and the keep-alive side effect.
resource: src/Web/autopilot-monitor-web/components/GlobalSidebar.tsx
tags:
- web
@@ -25,21 +25,26 @@ it enters the viewport.
# Mechanism
Three properties combine into a portal-wide freeze:
Two properties combine into a portal-wide freeze:
1. **Fan-out.** The navigation is fully rendered on each page load, so a single navigation issues one
RSC request per visible link — measured at ~10,400 requests over 14 days.
2. **Shared origin over HTTP/1.1.** `portal.autopilotmonitor.com` serves the document, the JS route
chunks *and* the RSC payloads, and it negotiates HTTP/1.1 — not HTTP/2. Browsers cap concurrent
connections per origin at six.
3. **A heavy latency tail on the SSR runtime.** RSC responses are prerendered and edge-cached
2. **A heavy latency tail on the SSR runtime.** RSC responses are prerendered and edge-cached
(`x-nextjs-cache: HIT`, `s-maxage=31536000`), so the median is fast. On a cache miss or cold start
the Static Web Apps managed runtime queues them.
the Static Web Apps managed runtime queues them **server-side**, and the queue drains all at once.
When the tail hits, the in-flight prefetches hold all six connections. The document request and the
route chunks of the page the user actually wants then have no socket available, and the tab shows a
loading spinner or a blank page until the queue drains. Nothing fails — the requests eventually
return `200`, which is why the failure leaves no error trace anywhere.
The navigation the user wants is then stuck behind that queue and the tab shows a loading spinner or a
blank page until it drains. Nothing fails — the requests eventually return `200`, which is why the
failure leaves no error trace anywhere.
> **Correction (2026-07-28).** The original version of this document named a third property: that
> `portal.autopilotmonitor.com` negotiates HTTP/1.1 and the prefetches exhaust the six-connection
> browser cap. **That is wrong.** It came from `curl -w '%{http_version}'` on a Windows build of curl
> whose Schannel backend has no HTTP/2 support, so it can only ever report `1.1`. ALPN says otherwise:
> `openssl s_client -alpn h2,http/1.1` negotiates **h2** on the portal host, confirmed by a .NET
> `HttpClient` request returning `HTTP/2.0`. There is no six-connection cap and connection starvation
> was never the mechanism — the queue is server-side. Verify HTTP versions with `openssl s_client
> -alpn` or `HttpClient`, never with this curl build.
# Evidence
@@ -62,6 +67,33 @@ document immediately and the browser then waited nearly four minutes for the `lo
Fourteen-day distribution of RSC prefetches: n = 10,428, p50 = 91 ms, p95 = 896 ms, max = 234,230 ms,
38 over 10 s, 21 over 30 s.
# Outcome, measured 2026-07-28
Two changes landed within half an hour of each other on 2026-07-27: the SWA plan went Free → Standard
at 16:02:44 UTC, and `prefetch={false}` went live at 16:34:13 UTC. Twenty hours of production
telemetry separate their effects.
**The Standard plan produced no measurable latency gain.** Latency is governed almost entirely by the
gap to the previous request — the SSR runtime cools down — so raw percentiles only measure the traffic
mix. Stratified by that gap, the two eras are indistinguishable (p50, Free → Standard): `<10s`
85 → 95 ms · `10-60s` 100 → 117 ms · `1-5min` 295 → 310 ms · `5-30min` 429 → 441 ms. Tail rates match
too: Free ran 1.64 % over 2 s and 0.374 % over 10 s (n = 10,163); Standard produced 6 and 1 events at
n = 258 against 4.2 and 1.0 expected. `browserTimings.totalDuration` by Mann-Whitney: n = 436 vs 48,
z = −0.24, **p = 0.81**.
**The prefetch fix is what removed the freezes** — worst `browserTimings.totalDuration` fell from
225,277 ms to 4,856 ms, and the 30-second events stopped.
**It also removed an accidental keep-alive.** The prefetch storm kept the SSR runtime warm: 85 % of
requests used to arrive less than 10 s apart, now 46 % do. On an identical never-cacheable route
(`/sessions/{id}`) the median rose from 87 ms to 211 ms and p90 from 465 ms to 1,480 ms. After 517
minutes idle, one request took 11,441 ms and was abandoned (`resultCode 0`). The trade — minute-long
freezes gone, ~150 ms added to a cold navigation — is worth it, but it is a trade.
Do not benchmark this with a synthetic burst. Firing requests in quick succession warms the runtime
and measures the best case: in a 25-round `curl --parallel-max 6` run, round 1 came in at p50 288 ms
and rounds 4–25 at p50 113 ms.
# Diagnosing this class of problem
The backend Application Insights resource is the wrong place to look — a freeze appears there as an
@@ -315,10 +315,9 @@ export function GlobalSidebar({ children }: { children: ReactNode }) {
// Every nav Link below sets prefetch={false} on purpose. The sidebar renders the whole
// navigation on every page, so the App Router's default viewport prefetch fires one RSC
// request per visible link against the SWA-hosted Next.js runtime on each page load
// (measured: ~10k requests / 14 days). That host speaks HTTP/1.1, so those prefetches
// occupy the browser's 6 connections to the SAME origin that serves the document and the
// route chunks — when the runtime queues them (p95 ~0.9s but a tail reaching 150s+), the
// portal freezes until the queue drains. Every route here is a client component behind
// (measured: ~10k requests / 14 days). The SSR runtime queues that burst server-side and
// drains it all at once (p95 ~0.9s but a tail reaching 150s+), so the navigation the user
// actually wants is stuck behind it and the portal freezes. Every route here is a client component behind
// ProtectedRoute that fetches its own data after mount, so the prefetched RSC payload
// buys nothing. See docs/web/portal-navigation-prefetch.md.
// --- Render a global nav link ---