PostHog events for what visitors wait for on the analysis page

LOADING.md

@@ -1413,6 +1413,78 @@ loads both runtimes at once.
 **Not known yet:** how this behaves on real Android phones, and for real
 visitors. No field data was used. The iPhone numbers are one phone and few runs.
 
+### Round 11: what real visitors get, in PostHog
+
+Rounds 1–10 measured emulated devices and one iPhone. These events show real visitors,
+split by `engine`, `engine_build`, `is_phone`, `cores`, `release` and PostHog's own
+`$os` and `$browser`. Nothing reads the page: `src/lib/analysisTiming.ts` takes a few
+timestamps per engine update. Times are in milliseconds, and are left empty when the
+visitor moved on or hid the page first.
+
+| event                               | sent                                                | properties                                                                                                                                                                                        |
+| ----------------------------------- | --------------------------------------------------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- |
+| `analysis_engine_load`              | once a visit, for the first position                | `position_shown_ms`, `maia_first_ms`, `maia_chart_data_ms`, `chart_ms`, `stockfish_first_ms`, `d12_ms`, `d18_ms`, `lines_settled_ms`, `stockfish_done_ms`, `arrival`, `stockfish_ran`, `maia_ran` |
+| `analysis_engine_steps`             | when the page is hidden or left, and every 30 moves | `steps`, the `_median_ms` of `maia_first`, `chart`, `d12`, `d18`, `lines_settled`, `stockfish_done`, and how many positions `_reached` each Stockfish stage                                       |
+| `analysis_page_ended_unexpectedly`  | on the next analysis page in the tab                | `was_visible`, `seconds_since_it_started`                                                                                                                                                         |
+| `stockfish_engine_ready`, `_failed` | once an engine, as before                           | `load_time_seconds`, and now `engine` and `memory_retries`                                                                                                                                        |
+| `maia_engine_ready`, `_failed`      | once a page, when Maia starts from its saved model  | `load_time_seconds`, `restarts`                                                                                                                                                                   |
+
+Reading them:
+
+- **"d18" is not comparable across round 10:** use `lines_settled` for that. `d18_ms` says
+  when the best line got there.
+- **A crash:** `analysis_page_ended_unexpectedly` with `was_visible` true means the last
+  analysis page in this tab was on screen and never left. With it false, the browser may
+  just have dropped a page in the background. It undercounts: it can only report when the
+  visitor comes back to an analysis page in that tab, so one who leaves after a crash, or
+  sees Safari's "A problem repeatedly occurred", isn't counted until they return.
+- **Saved analysis:** `stockfish_ran` false means the search didn't run for that position,
+  so its times say nothing. Filter on it for engine times.
+- **Before and after round 10:** only `stockfish_engine_ready`, `stockfish_engine_failed`,
+  `$web_vitals` and `$exception` existed before it went live (2026-11-05 03:30 UTC). The
+  new events have no "before", so they compare later changes against round 10.
+
+Checked in a browser with PostHog's requests captured: the events and values above arrive;
+a normal reload reports no crash; and a page that loses its exit handlers, as a killed one
+would, is reported on the next load with `was_visible` true. PostHog ignores automated
+browsers, so this needed the test browser to hide that it is one.
+
+No slowdown within the noise, against the same code without these events: six paired
+loads per device (test browsers, whose events PostHog drops, so sending itself isn't
+counted). Desktop: first depth 0.00 s, depth 12 0.00 s, depth 18 0.00 s (paired medians).
+Phone: first depth 0.56 s, depth 12 0.61 s and depth 18 0.71 s sooner, which is noise in
+the build's favour (3–4 of 6 pairs).
+
+Queries for PostHog's SQL editor:
+
+```sql
+-- Crash rate: analysis pages lost on screen, per analysis page load, by day and phone
+SELECT toDate(timestamp) AS day, properties.is_phone AS phone,
+  countIf(event = 'analysis_page_ended_unexpectedly' AND properties.was_visible = true) AS lost_on_screen,
+  countIf(event = 'analysis_engine_load') AS loads
+FROM events
+WHERE event IN ('analysis_page_ended_unexpectedly', 'analysis_engine_load') AND timestamp > now() - INTERVAL 14 DAY
+GROUP BY day, phone ORDER BY day
+
+-- What a visitor waits for on a return visit, by phone and operating system
+SELECT properties.is_phone AS phone, properties.$os AS os, count() AS loads,
+  quantile(0.5)(toFloat(properties.stockfish_first_ms)) AS first_depth,
+  quantile(0.5)(toFloat(properties.lines_settled_ms)) AS lines_settled,
+  quantile(0.5)(toFloat(properties.chart_ms)) AS chart,
+  quantile(0.9)(toFloat(properties.lines_settled_ms)) AS lines_settled_p90
+FROM events
+WHERE event = 'analysis_engine_load' AND properties.stockfish_ran = true AND timestamp > now() - INTERVAL 14 DAY
+GROUP BY phone, os ORDER BY loads DESC
+
+-- Round 10, before and after: Stockfish's start, and how often it failed
+SELECT timestamp >= toDateTime('2026-11-05 03:30:00') AS after_round_10,
+  countIf(event = 'stockfish_engine_ready') AS ready, countIf(event = 'stockfish_engine_failed') AS failed,
+  quantileIf(0.5)(toFloat(properties.load_time_seconds), event = 'stockfish_engine_ready') AS median_ready_seconds
+FROM events
+WHERE event IN ('stockfish_engine_ready', 'stockfish_engine_failed') AND timestamp > now() - INTERVAL 30 DAY
+GROUP BY after_round_10
+```
+
 ## What changed
 
 | commit                    | change                                                                                                                                                                                                                                                                                                                        | effect                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                               |

src/components/Analysis/MovesByRating.tsx

@@ -1,5 +1,6 @@
 import dynamic from 'next/dynamic'
-import { memo, useMemo, useState } from 'react'
+import { memo, useEffect, useMemo, useState } from 'react'
+import { analysisChartDrawn } from 'src/lib/analysisTiming'
 import { ColorSanMapping } from 'src/types'
 import { useContentStable } from 'src/hooks/useContentStable'
 
@@ -35,6 +36,10 @@ const MovesByRatingChart: React.FC<Props> = ({
     setShown({ moves, colorSanMapping, positionKey })
   }
 
+  useEffect(() => {
+    if (shown.moves?.length) analysisChartDrawn(shown.positionKey)
+  }, [shown])
+
   const moveKeys = useMemo(() => {
     if (!shown.moves?.length) return []
     return Object.keys(shown.moves[0]).filter((move) => move !== 'rating')

src/constants/analysis.ts

@@ -17,6 +17,8 @@ export const MOVE_CLASSIFICATION_THRESHOLDS = {
   GOOD_THRESHOLD: -0.05,
 } as const
 
+// The build the analysis page runs, on PostHog's engine events.
+export const STOCKFISH_ENGINE = 'stockfish-19-smallnet' as const
 export const DEFAULT_MAIA_MODEL = 'maia_kdd_1500' as const
 export const MAIA_MIN_RATING = 600 as const
 export const MAIA_MAX_RATING = 2600 as const

src/contexts/MaiaEngineContext.tsx

@@ -1,3 +1,4 @@
+import { trackMaiaEngineFailed, trackMaiaEngineReady } from 'src/lib/analytics'
 import Maia from '../lib/engine/maia'
 import { MaiaStatus, MaiaEngine } from 'src/types'
 import React, {
@@ -63,6 +64,26 @@ export const MaiaEngineContextProvider: React.FC<{ children: ReactNode }> = ({
     return await maia.clearStorage()
   }, [maia])
 
+  // How Maia's start went, once a page (a download doesn't count as a start).
+  const startedAt = useRef(Date.now())
+  const startReported = useRef(false)
+  useEffect(() => {
+    if (status === 'no-cache' || status === 'downloading') {
+      startReported.current = true
+    }
+    if (startReported.current || (status !== 'ready' && status !== 'error')) {
+      return
+    }
+    startReported.current = true
+    const page = window.location.pathname.split('/')[1] || 'home'
+    const seconds = (Date.now() - startedAt.current) / 1000
+    if (status === 'ready') {
+      trackMaiaEngineReady(seconds, page, maia.restartCount)
+    } else {
+      trackMaiaEngineFailed(error ?? '', seconds, page, maia.restartCount)
+    }
+  }, [status, error, maia])
+
   // Toast notifications for Maia model status
   useEffect(() => {
     return () => {

src/contexts/StockfishEngineContext.tsx

@@ -17,7 +17,7 @@ import {
   STOCKFISH_DEBUG_RERUN_EVENT,
   STOCKFISH_DEBUG_RERUN_KEY,
 } from 'src/constants/analysis'
-import Engine from 'src/lib/engine/stockfish'
+import Engine, { stockfishMemoryRetries } from 'src/lib/engine/stockfish'
 import {
   trackStockfishEngineFailed,
   trackStockfishEngineReady,
@@ -112,12 +112,13 @@ const reportEngineOutcome = (engine: Engine, status: StockfishStatus) => {
   const page = window.location.pathname.split('/')[1] || 'home'
   const seconds = (Date.now() - startedAt) / 1000
   if (status === 'ready') {
-    trackStockfishEngineReady(seconds, page)
+    trackStockfishEngineReady(seconds, page, stockfishMemoryRetries())
   } else {
     trackStockfishEngineFailed(
       engine.initializationErrorDetail ?? engine.initializationError ?? '',
       seconds,
       page,
+      stockfishMemoryRetries(),
     )
   }
 }

src/hooks/useAnalysisController/useEngineAnalysis.ts

@@ -1,6 +1,12 @@
 import { Chess } from 'chess.ts'
 import { fetchOpeningBookMoves } from 'src/api'
 import { startTransition, useEffect, useContext, useRef, useState } from 'react'
+import {
+  analysisMaiaStage,
+  analysisPositionShown,
+  analysisStockfishUpdate,
+  startAnalysisTiming,
+} from 'src/lib/analysisTiming'
 import { MAIA_MODELS, MAIA_RATINGS } from 'src/constants/common'
 import {
   STOCKFISH_DEBUG_RERUN_EVENT,
@@ -87,6 +93,18 @@ export const useEngineAnalysis = (
     }
   }, [])
 
+  useEffect(() => {
+    if (!enabled || !window.location.pathname.startsWith('/analysis')) return
+    return startAnalysisTiming({ isPhone: isPhone() })
+  }, [enabled])
+
+  // Timed before the engine effects below, for the position they start on.
+  useEffect(() => {
+    // Full-game analysis moves through the game by itself, at other depths.
+    if (!currentNode || !enabled || targetDepth !== 18) return
+    analysisPositionShown(currentNode.fen)
+  }, [currentNode, enabled, targetDepth])
+
   async function inferenceMaiaModel(
     board: Chess,
     models: string[],
@@ -239,6 +257,7 @@ export const useEngineAnalysis = (
             { ...currentNode.analysis.maia, ...maiaEvaluations },
             currentMaiaModel,
           )
+          analysisMaiaStage(nodeFen, stages.indexOf(stage))
           if (stage === stages[0]) {
             setAnalysisState((state) => state + 1)
           } else {
@@ -380,6 +399,7 @@ export const useEngineAnalysis = (
               break
             }
             nodeForAnalysis.addStockfishAnalysis(evaluation, currentMaiaModel)
+            analysisStockfishUpdate(nodeForAnalysis.fen, evaluation)
             // The first update renders at once, later ones at most every
             // STOCKFISH_RENDER_INTERVAL_MS (the last one always renders).
             const wait =

src/lib/analysisTiming.test.ts

@@ -0,0 +1,181 @@
+import {
+  analysisChartDrawn,
+  analysisMaiaStage,
+  analysisPositionShown,
+  analysisStockfishUpdate,
+  startAnalysisTiming,
+} from './analysisTiming'
+import { capture } from 'src/lib/posthogClient'
+
+jest.mock('src/lib/posthogClient', () => ({ capture: jest.fn() }))
+
+const captured = capture as jest.Mock
+const events = (name: string) =>
+  captured.mock.calls.filter(([event]) => event === name).map(([, p]) => p)
+
+const A = 'a'
+const B = 'b'
+const C = 'c'
+
+const setVisibility = (state: 'visible' | 'hidden') => {
+  Object.defineProperty(document, 'visibilityState', {
+    configurable: true,
+    get: () => state,
+  })
+  document.dispatchEvent(new Event('visibilitychange'))
+}
+
+const search = (fen: string) => {
+  analysisStockfishUpdate(fen, { depth: 6, partial: true })
+  analysisMaiaStage(fen, 0)
+  analysisStockfishUpdate(fen, { depth: 18, partial: true })
+  analysisMaiaStage(fen, 1)
+  analysisChartDrawn(fen)
+  analysisStockfishUpdate(fen, { depth: 18, partial: true, lines_done: true })
+  analysisStockfishUpdate(fen, { depth: 18 })
+}
+
+describe('analysisTiming', () => {
+  let now = 0
+  let stop: () => void
+
+  beforeEach(() => {
+    now = 1000
+    captured.mockClear()
+    jest.spyOn(performance, 'now').mockImplementation(() => (now += 100))
+    sessionStorage.clear()
+    setVisibility('visible')
+    stop = startAnalysisTiming({ isPhone: true })
+  })
+
+  afterEach(() => {
+    stop()
+    jest.restoreAllMocks()
+  })
+
+  it('reports the first position as a load, once it ends', () => {
+    analysisPositionShown(A)
+    search(A)
+    expect(events('analysis_engine_load')).toHaveLength(0)
+    analysisPositionShown(B)
+
+    const [load] = events('analysis_engine_load')
+    expect(load).toMatchObject({
+      is_phone: true,
+      engine: 'stockfish-19-smallnet',
+      stockfish_first_ms: 100,
+      maia_first_ms: 200,
+      d12_ms: 300,
+      d18_ms: 300,
+      maia_chart_data_ms: 400,
+      chart_ms: 500,
+      lines_settled_ms: 600,
+      stockfish_done_ms: 700,
+      stockfish_ran: true,
+      maia_ran: true,
+    })
+  })
+
+  it('summarises later positions when the page is hidden', () => {
+    analysisPositionShown(A)
+    analysisPositionShown(B)
+    search(B)
+    analysisPositionShown(C)
+    analysisStockfishUpdate(C, { depth: 12, partial: true })
+    setVisibility('hidden')
+
+    const [steps] = events('analysis_engine_steps')
+    expect(steps).toMatchObject({
+      steps: 2,
+      d12_reached: 2,
+      d18_reached: 1,
+      lines_settled_reached: 1,
+      stockfish_done_reached: 1,
+      d18_median_ms: 300,
+    })
+  })
+
+  it('takes nothing that arrives after the page is hidden', () => {
+    analysisPositionShown(A)
+    analysisStockfishUpdate(A, { depth: 6, partial: true })
+    setVisibility('hidden')
+    analysisStockfishUpdate(A, { depth: 18 })
+
+    const [load] = events('analysis_engine_load')
+    expect(load.d18_ms).toBeNull()
+    expect(load.stockfish_done_ms).toBeNull()
+  })
+
+  it('leaves out a position where neither engine ran', () => {
+    analysisPositionShown(A)
+    analysisPositionShown(B)
+    analysisPositionShown(C)
+    setVisibility('hidden')
+    expect(events('analysis_engine_load')).toHaveLength(0)
+    expect(events('analysis_engine_steps')).toHaveLength(0)
+  })
+
+  it('ignores updates from a position no longer on show', () => {
+    analysisPositionShown(A)
+    analysisPositionShown(B)
+    analysisStockfishUpdate(A, { depth: 18 })
+    setVisibility('hidden')
+    expect(events('analysis_engine_steps')).toHaveLength(0)
+  })
+
+  it('reports nothing unexpected when a page was left normally', () => {
+    window.dispatchEvent(new Event('pagehide'))
+    stop()
+    stop = startAnalysisTiming({ isPhone: true })
+    expect(events('analysis_page_ended_unexpectedly')).toHaveLength(0)
+  })
+
+  it('reports nothing when the page is hidden after being left, as on a reload', () => {
+    window.dispatchEvent(new Event('pagehide'))
+    setVisibility('hidden')
+    expect(sessionStorage.getItem('maia.analysisPageAlive')).toBeNull()
+    setVisibility('visible')
+    stop()
+    stop = startAnalysisTiming({ isPhone: true })
+    expect(events('analysis_page_ended_unexpectedly')).toHaveLength(0)
+  })
+
+  it('marks the page alive again on coming back from the back/forward cache', () => {
+    window.dispatchEvent(new Event('pagehide'))
+    expect(sessionStorage.getItem('maia.analysisPageAlive')).toBeNull()
+    window.dispatchEvent(new Event('pageshow'))
+    expect(sessionStorage.getItem('maia.analysisPageAlive')).not.toBeNull()
+  })
+
+  it('reports an earlier page that was never left', () => {
+    // A page that dies runs no pagehide, and leaves its mark behind.
+    const mark = sessionStorage.getItem('maia.analysisPageAlive') as string
+    stop()
+    sessionStorage.setItem('maia.analysisPageAlive', mark)
+    stop = startAnalysisTiming({ isPhone: true })
+
+    const [ended] = events('analysis_page_ended_unexpectedly')
+    expect(ended).toMatchObject({ was_visible: true })
+  })
+
+  it('tells a page lost in the background from one lost on screen', () => {
+    setVisibility('hidden')
+    const mark = sessionStorage.getItem('maia.analysisPageAlive') as string
+    stop()
+    sessionStorage.setItem('maia.analysisPageAlive', mark)
+    setVisibility('visible')
+    stop = startAnalysisTiming({ isPhone: true })
+
+    const [ended] = events('analysis_page_ended_unexpectedly')
+    expect(ended).toMatchObject({ was_visible: false })
+  })
+
+  it('does nothing when no analysis page is mounted', () => {
+    stop()
+    analysisPositionShown(A)
+    search(A)
+    analysisPositionShown(B)
+    expect(events('analysis_engine_load')).toHaveLength(0)
+    stop = startAnalysisTiming({ isPhone: true })
+  })
+})