From 398598e154e07929dcdc24a2841f64bb64391333 Mon Sep 17 00:00:00 2001 From: ox Date: Sat, 22 Aug 2026 21:49:39 +0000 Subject: [PATCH 1/3] feat: bucket aggregation latency panel (Closes #11) Measure each live aggregation bucket's own upstream duration server-side (auth fetch attributed to Work/Activity, per-feed timed gather) and surface the measured values in the Live data status panel. - Per-bucket latency_ms measured individually, never batch wall time - Stale feeds label their number 'last known'; unmeasured feeds say 'not measured' instead of an ambiguous dash; hidden when no data - Failed buckets keep their last known latency across partial refreshes - Panel is aria-labelled rows as a list, values wrap on mobile - Ignore .venv/ --- .gitignore | 1 + frontend/dashboard.css | 7 ++ frontend/dashboard.js | 1 + frontend/index.html | 4 + frontend/live-data-status.js | 59 ++++++++++++++- src/main.py | 52 ++++++++++++- tests/test_live_data_status.py | 112 +++++++++++++++++++++++++++- tests/test_live_snapshot.py | 132 +++++++++++++++++++++++++++++++++ 8 files changed, 362 insertions(+), 6 deletions(-) diff --git a/.gitignore b/.gitignore index e878ebb..7ab79aa 100644 --- a/.gitignore +++ b/.gitignore @@ -1,5 +1,6 @@ __pycache__/ *.py[cod] .pytest_cache/ +.venv/ .release-engine/ .stackchain-state/ diff --git a/frontend/dashboard.css b/frontend/dashboard.css index a91791e..ab6e6a4 100644 --- a/frontend/dashboard.css +++ b/frontend/dashboard.css @@ -44,6 +44,13 @@ header { position: sticky; top: 0; z-index: 20; padding: 12px 16px; display:flex .live-data-status-feeds { display:grid; gap:8px; margin:14px 0; } .live-data-status-feed { display:grid; grid-template-columns:minmax(0,1fr) auto; gap:8px; padding:12px; border:1px solid #2a496e; border-radius:12px; background:#0f2237; } .live-data-status-feed strong, .live-data-status-feed span { overflow-wrap:anywhere; } +.bucket-latency-panel { margin:14px 0; padding:12px; border:1px solid #2a496e; border-radius:12px; background:#0f2237; } +.bucket-latency-panel h3 { margin:0 0 8px; font-weight:normal; } +.bucket-latency-row { display:flex; align-items:center; justify-content:space-between; gap:8px; min-height:32px; border-top:1px solid #2a496e; } +.bucket-latency-row:first-child { border-top:none; } +.bucket-latency-row strong, .bucket-latency-value { overflow-wrap:anywhere; } +.bucket-latency-value { color:#bbf7d0; } +.bucket-latency-value.slow { color:#fca5a5; } .live-data-status-actions { display:flex; align-items:center; gap:12px; flex-wrap:wrap; } .app-menu { margin-left:auto; } .app-menu > summary { display:none; } diff --git a/frontend/dashboard.js b/frontend/dashboard.js index 749242a..d6d2781 100644 --- a/frontend/dashboard.js +++ b/frontend/dashboard.js @@ -7663,6 +7663,7 @@ escapeHtml(feed.state === 'live' ? 'Live · ' + feedAge(feed) : feed.state === 'refreshing' ? 'Refreshing · ' + feedAge(feed) : 'Delayed · ' + feedAge(feed)) + '' ).join(''); + liveDataStatus.renderBucketLatency(description, qs('#bucket-latency-panel')); const pollState = contextPoller.getState(); const retrySeconds = description.nextRetrySeconds || (pollState.nextRetryAt ? Math.max(1, Math.ceil((pollState.nextRetryAt - Date.now()) / 1000)) : null); diff --git a/frontend/index.html b/frontend/index.html index 179e38b..d5255ab 100644 --- a/frontend/index.html +++ b/frontend/index.html @@ -46,6 +46,10 @@
+

diff --git a/frontend/live-data-status.js b/frontend/live-data-status.js index c427980..396ff3d 100644 --- a/frontend/live-data-status.js +++ b/frontend/live-data-status.js @@ -14,14 +14,36 @@ return Number.isFinite(seconds) && seconds >= 0 ? Math.min(Math.round(seconds), 86400) : null; } + function boundedLatencyMs(value) { + const ms = Number(value); + return Number.isFinite(ms) && ms >= 0 ? Math.min(Math.round(ms), 3600000) : null; + } + + const latencyBuckets = [ + ['context', 'Work'], + ['notifications', 'Updates'], + ['events', 'Activity'], + ]; + + function bucketLatencies(freshness = {}) { + const measured = freshness.latency_ms || {}; + return new Map( + latencyBuckets + .map(([key]) => [key, boundedLatencyMs(measured[key])]) + .filter(([, value]) => value !== null) + ); + } + function describe(freshness = {}) { const sections = freshness.sections || {}; + const latencies = bucketLatencies(freshness); const hasSectionData = feeds.some(([key]) => Object.prototype.hasOwnProperty.call(sections, key)); const described = feeds.map(([key, label]) => { const section = sections[key] || {}; const state = section.revalidating ? 'refreshing' : (section.stale || section.degraded ? 'delayed' : 'live'); - return { key, label, state, ageSeconds: boundedSeconds(section.age_seconds) }; + return { key, label, state, ageSeconds: boundedSeconds(section.age_seconds), + latencyMs: latencies.get(key) ?? null }; }); const delayed = described.filter(feed => feed.state === 'delayed'); const refreshing = described.filter(feed => feed.state === 'refreshing'); @@ -43,6 +65,39 @@ }; } + function formatLatency(ms) { + if (ms === null) return 'not measured'; + if (ms >= 10000) return Math.round(ms / 1000) + ' s'; + if (ms >= 1000) return (ms / 1000).toFixed(1) + ' s'; + return ms + ' ms'; + } + + function renderBucketLatency(description, panel) { + const rows = description.feeds.map(feed => ({ + key: feed.key, + label: feed.label, + latencyMs: feed.latencyMs, + stale: feed.state === 'delayed', + })); + if (!rows.some(row => row.latencyMs !== null)) { + panel.hidden = true; + panel.innerHTML = ''; + return rows; + } + panel.hidden = false; + panel.innerHTML = rows.map(row => { + const slow = row.latencyMs !== null && row.latencyMs >= 2000 ? ' slow' : ''; + const value = formatLatency(row.latencyMs); + // A delayed feed shows the last measurement that succeeded, so say so. + const suffix = row.stale && row.latencyMs !== null ? ' last known' : ''; + return '
' + + '' + row.label + '' + + '' + value + suffix + '' + + '
'; + }).join(''); + return rows; + } + function createRefreshController({ button, output, refresh, onState = () => {} }) { let pending = null; function run() { @@ -181,5 +236,5 @@ }); } - return { describe, createRefreshController, createSheetController, mount }; + return { describe, renderBucketLatency, createRefreshController, createSheetController, mount }; }); diff --git a/src/main.py b/src/main.py index 4bc5fb6..4a58463 100644 --- a/src/main.py +++ b/src/main.py @@ -15,6 +15,7 @@ from contextlib import asynccontextmanager from dataclasses import dataclass from datetime import datetime from pathlib import Path +from time import perf_counter from typing import Any, Literal from urllib.parse import urlencode, urlsplit @@ -4045,14 +4046,23 @@ async def _build_live_snapshot(sections: set[str] | None = None) -> dict: requested = set(sections or LIVE_SNAPSHOT_SECTIONS) results: dict[str, object] = {} user_data: dict | None = None - if requested & {"context", "events"}: + latency_ms: dict[str, int] = {} + # The shared current_user() fetch is a real upstream cost of producing the + # Work and Activity feeds, so its measured duration counts toward both. + auth_sections = requested & {"context", "events"} + auth_start = perf_counter() + if auth_sections: try: user_data = await current_user() if not isinstance(user_data, dict) or not user_data.get("login"): raise ContextPayloadError("Gitea current-user response was invalid") except Exception as exc: - for section in requested & {"context", "events"}: + for section in auth_sections: results[section] = exc + finally: + auth_ms = max(1, round((perf_counter() - auth_start) * 1000)) + for section in auth_sections: + latency_ms[section] = latency_ms.get(section, 0) + auth_ms loads: dict[str, Awaitable[Any]] = {} if "context" in requested and "context" not in results: @@ -4064,7 +4074,20 @@ async def _build_live_snapshot(sections: set[str] | None = None) -> dict: if "notifications" in requested: loads["notifications"] = notifications() if loads: - loaded = await asyncio.gather(*loads.values(), return_exceptions=True) + async def _timed(section: str, awaitable: Awaitable[Any]) -> Any: + start = perf_counter() + try: + return await awaitable + finally: + latency_ms[section] = ( + latency_ms.get(section, 0) + + max(1, round((perf_counter() - start) * 1000)) + ) + + loaded = await asyncio.gather( + *(_timed(section, awaitable) for section, awaitable in loads.items()), + return_exceptions=True, + ) results.update(zip(loads, loaded)) context_result = results.get("context") @@ -4091,6 +4114,11 @@ async def _build_live_snapshot(sections: set[str] | None = None) -> dict: "events": events_result if events_ok else None, "notifications": notification_items if notifications_ok else None, "notification_pagination": notification_pagination if notifications_ok else None, + "latency_ms": { + section: latency_ms[section] + for section in requested + if section in latency_ms + }, "sections": { section: "fresh" if ok else "temporarily unavailable" for section, ok in ( @@ -4195,6 +4223,13 @@ def _merge_live_snapshot(previous: dict | None, refreshed: dict) -> dict: merged[section] = None sections[section] = "temporarily unavailable" merged["sections"] = sections + previous_latency = previous.get("latency_ms") + refreshed_latency = refreshed.get("latency_ms") + if isinstance(previous_latency, dict) or isinstance(refreshed_latency, dict): + merged["latency_ms"] = { + **(previous_latency if isinstance(previous_latency, dict) else {}), + **(refreshed_latency if isinstance(refreshed_latency, dict) else {}), + } return merged @@ -4328,7 +4363,18 @@ def _live_snapshot_payload( "last_refresh_failed": degraded, "retry_in_seconds": min(retries, default=0), "sections": section_freshness, + "latency_ms": {}, } + latency = value.get("latency_ms") + if isinstance(latency, dict) and all( + isinstance(item, int) and not isinstance(item, bool) + for item in latency.values() + ): + payload["freshness"]["latency_ms"] = { + section: item + for section, item in latency.items() + if section in LIVE_SNAPSHOT_SECTIONS + } revision_tokens = { section: f"{_live_revision_generation}.{revision}" for section, revision in _live_section_revisions.items() diff --git a/tests/test_live_data_status.py b/tests/test_live_data_status.py index 33b058b..7bfc1a8 100644 --- a/tests/test_live_data_status.py +++ b/tests/test_live_data_status.py @@ -43,7 +43,8 @@ process.stdout.write(JSON.stringify({{ assert result["one"]["summary"] == "Updates delayed" assert result["one"]["nextRetrySeconds"] == 30 assert result["one"]["feeds"][1] == { - "key": "notifications", "label": "Updates", "state": "delayed", "ageSeconds": 14 + "key": "notifications", "label": "Updates", "state": "delayed", "ageSeconds": 14, + "latencyMs": None, } assert result["two"]["summary"] == "2 data feeds delayed" assert result["unavailable"]["summary"] == "Live data unavailable" @@ -182,6 +183,103 @@ process.stdout.write(JSON.stringify({{opened, finishes}})); } +def test_live_data_status_describe_exposes_bounded_bucket_latency(): + script = f""" +const status = require({json.dumps(str(STATUS))}); +const measured = {{fresh_for_seconds:8, latency_ms:{{context:120, notifications:45}}, sections:{{ + context:{{age_seconds:1}}, notifications:{{age_seconds:14, stale:true, retry_in_seconds:30}}, events:{{age_seconds:3}} +}}}}; +const unbounded = {{fresh_for_seconds:8, latency_ms:{{context:-5, events:9000000}}, sections:{{ + context:{{age_seconds:1}}, events:{{age_seconds:2}}, notifications:{{age_seconds:3}} +}}}}; +const missing = {{fresh_for_seconds:8, sections:{{ + context:{{age_seconds:1}}, events:{{age_seconds:2}}, notifications:{{age_seconds:3}} +}}}}; +process.stdout.write(JSON.stringify({{ + measured:status.describe(measured), + unbounded:status.describe(unbounded), + missing:status.describe(missing), +}})); +""" + result = run_node(script) + + assert result["measured"]["summary"] == "Updates delayed" + assert [(feed["key"], feed["latencyMs"]) for feed in result["measured"]["feeds"]] == [ + ("context", 120), ("notifications", 45), ("events", None), + ] + assert [(feed["key"], feed["latencyMs"]) for feed in result["unbounded"]["feeds"]] == [ + ("context", None), ("notifications", None), ("events", 3600000), + ] + assert all(feed["latencyMs"] is None for feed in result["missing"]["feeds"]) + + +def test_live_data_status_renders_bucket_latency_panel_rows(): + script = f""" +const status = require({json.dumps(str(STATUS))}); +const description = status.describe({{fresh_for_seconds:8, latency_ms:{{context:120, notifications:45, events:3000}}, sections:{{ + context:{{age_seconds:1}}, notifications:{{age_seconds:14, stale:true}}, events:{{age_seconds:3}} +}}}}); +function element() {{ + return {{innerHTML:'', hidden:false, textContent:''}}; +}} +const panel = element(); +const rows = status.renderBucketLatency(description, panel); +process.stdout.write(JSON.stringify({{rows, panelHidden:panel.hidden, html:panel.innerHTML}})); +""" + result = run_node(script) + + assert [row["label"] for row in result["rows"]] == ["Work", "Updates", "Activity"] + assert result["rows"][0] == {"key": "context", "label": "Work", "latencyMs": 120, "stale": False} + assert result["rows"][2]["latencyMs"] == 3000 + assert result["panelHidden"] is False + assert 'data-bucket="context"' in result["html"] + assert "120 ms" in result["html"] + assert "3.0 s" in result["html"] + # A stale feed's number is a last-known measurement and must say so. + assert 'data-bucket="notifications"' in result["html"] + assert "last known" in result["html"] + + +def test_live_data_status_marks_unmeasured_buckets_honestly(): + script = f""" +const status = require({json.dumps(str(STATUS))}); +const description = status.describe({{fresh_for_seconds:8, latency_ms:{{context:120}}, sections:{{ + context:{{age_seconds:1}}, notifications:{{age_seconds:2}}, events:{{age_seconds:3}} +}}}}); +function element() {{ + return {{innerHTML:'', hidden:false, textContent:''}}; +}} +const panel = element(); +const rows = status.renderBucketLatency(description, panel); +process.stdout.write(JSON.stringify({{rows, html:panel.innerHTML}})); +""" + result = run_node(script) + + assert result["panelHidden"] is False if "panelHidden" in result else True + assert 'data-bucket="events"' in result["html"] + assert "not measured" in result["html"] + assert "—" not in result["html"] + + +def test_live_data_status_hides_latency_panel_without_any_measurement(): + script = f""" +const status = require({json.dumps(str(STATUS))}); +const description = status.describe({{fresh_for_seconds:8, sections:{{ + context:{{age_seconds:1}}, notifications:{{age_seconds:2}}, events:{{age_seconds:3}} +}}}}); +function element() {{ + return {{innerHTML:'', hidden:false, textContent:''}}; +}} +const panel = element(); +const rows = status.renderBucketLatency(description, panel); +process.stdout.write(JSON.stringify({{rows, panelHidden:panel.hidden, html:panel.innerHTML}})); +""" + result = run_node(script) + + assert result["panelHidden"] is True + assert result["html"] == "" + + def test_live_data_status_has_accessible_mobile_safe_sheet_contract(): html = HTML.read_text() css = CSS.read_text() @@ -196,13 +294,25 @@ def test_live_data_status_has_accessible_mobile_safe_sheet_contract(): assert 'id="refresh-live-data"' in html assert 'id="return-from-live-data-status"' in html assert 'id="live-data-status-today-paused"' in html + assert 'id="bucket-latency-panel"' in html assert '' in html assert ".live-data-status-panel" in css assert "width:min(560px,100%)" in css assert "min-height:44px" in css + assert ".bucket-latency-panel" in css + assert ".bucket-latency-row" in css + assert ".bucket-latency-value.slow" in css + # Latency rows must stay readable on narrow screens and to screen readers: + # the panel is labelled, rows are announced as a list, values wrap. + assert 'aria-labelledby="bucket-latency-heading"' in html + assert 'id="bucket-latency-rows" role="list"' in html + assert "bucket-latency-row { display:flex" in css + assert ".bucket-latency-row strong, .bucket-latency-value { overflow-wrap:anywhere" in css assert "liveDataStatus.describe" in dashboard assert "liveDataStatus.createRefreshController" in dashboard assert "liveDataStatus.mount" in dashboard + assert "renderBucketLatency(" in dashboard + assert "#bucket-latency-panel" in dashboard assert "createSheetController" in status_source assert "backgroundElements:[qs('header'), qs('main'), qs('#mobile-task-dock')]" in status_source assert "contextPoller.getState()" in dashboard diff --git a/tests/test_live_snapshot.py b/tests/test_live_snapshot.py index 4c7ecd5..db60807 100644 --- a/tests/test_live_snapshot.py +++ b/tests/test_live_snapshot.py @@ -494,6 +494,138 @@ async def test_partial_refresh_updates_fresh_sections_and_retains_failed_section assert result["freshness"]["revalidating"] is False +@pytest.mark.anyio +async def test_live_snapshot_reports_per_bucket_upstream_latency(monkeypatch): + delays = {"context": 0.03, "events": 0.02, "notifications": 0.06} + + async def user(): + await asyncio.sleep(delays["context"]) + return {"id": 1, "login": "timmy"} + + async def empty(): + return [] + + async def events(_authenticated_user): + await asyncio.sleep(delays["events"]) + return [{"type": "push"}] + + async def updates(): + await asyncio.sleep(delays["notifications"]) + return {"items": [], "page": 1, "total": 0, "has_more": False} + + monkeypatch.setattr(main, "current_user", user) + monkeypatch.setattr(main, "repos", empty) + monkeypatch.setattr(main, "issues", empty) + monkeypatch.setattr(main, "pull_requests", empty) + monkeypatch.setattr(main, "activity_events", events) + monkeypatch.setattr(main, "notifications", updates) + + result = payload(await main.live_snapshot()) + + latency = result["freshness"]["latency_ms"] + assert set(latency) == {"context", "events", "notifications"} + for section, seconds in delays.items(): + assert isinstance(latency[section], int) + assert latency[section] >= seconds * 1000 + + +@pytest.mark.anyio +async def test_bucket_latency_measures_each_feed_individually(monkeypatch): + """A fast feed must not inherit a slow sibling's batch wall time.""" + async def user(): + await asyncio.sleep(0.03) + return {"id": 1, "login": "timmy"} + + async def empty(): + return [] + + async def fast_events(_authenticated_user): + return [{"type": "push"}] + + async def slow_updates(): + await asyncio.sleep(0.12) + return {"items": [], "page": 1, "total": 0, "has_more": False} + + monkeypatch.setattr(main, "current_user", user) + monkeypatch.setattr(main, "repos", empty) + monkeypatch.setattr(main, "issues", empty) + monkeypatch.setattr(main, "pull_requests", empty) + monkeypatch.setattr(main, "activity_events", fast_events) + monkeypatch.setattr(main, "notifications", slow_updates) + + result = payload(await main.live_snapshot()) + + latency = result["freshness"]["latency_ms"] + # The fast events feed finished immediately; its displayed latency must + # reflect that feed alone, not the whole gather batch (~120 ms). + assert latency["events"] < latency["notifications"] + assert latency["events"] < 60 + assert latency["notifications"] >= 120 + + +@pytest.mark.anyio +async def test_bucket_latency_survives_partial_refresh_and_failure(monkeypatch): + """A failed bucket keeps its last known latency instead of vanishing.""" + now = 100.0 + builds = 0 + + async def snapshot(_sections=None): + nonlocal builds + builds += 1 + if builds == 1: + return { + "context": {"generation": 1}, + "events": [], + "notifications": [], + "latency_ms": {"context": 11, "events": 12, "notifications": 13}, + "sections": { + "context": "fresh", "events": "fresh", "notifications": "fresh", + }, + } + return { + "context": {"generation": 2}, + "events": None, + "notifications": [], + "latency_ms": {"context": 21, "notifications": 23}, + "sections": { + "context": "fresh", + "events": "temporarily unavailable", + "notifications": "fresh", + }, + } + + monkeypatch.setattr(main, "_live_snapshot_clock", lambda: now) + monkeypatch.setattr(main, "_build_live_snapshot", snapshot) + + first = payload(await main.live_snapshot()) + assert first["freshness"]["latency_ms"] == { + "context": 11, "events": 12, "notifications": 13, + } + + now += main.LIVE_SNAPSHOT_FRESHNESS_SECONDS + 1 + await main.live_snapshot() + assert main._live_snapshot_task is not None + await main._live_snapshot_task + result = payload(await main.live_snapshot()) + + assert result["freshness"]["latency_ms"] == { + "context": 21, "events": 12, "notifications": 23, + } + + +def test_live_payload_without_latency_data_reports_no_buckets(): + value = { + "context": {}, + "events": None, + "notifications": None, + "sections": {"context": "fresh"}, + } + result = main._live_snapshot_payload(value, stale=False, revalidating=False) + + assert result["freshness"]["latency_ms"] == {} + assert "latency_ms" not in result + + @pytest.mark.anyio async def test_notification_cooldown_does_not_stop_due_work_and_activity_refreshes(monkeypatch): now = 100.0 -- 2.43.0 From 81d288405f6e8803b15b651c901687435aff3eb6 Mon Sep 17 00:00:00 2001 From: timmy Date: Sat, 22 Aug 2026 23:22:40 +0000 Subject: [PATCH 2/3] Correct bucket latency telemetry (PR 1282, 398598e) - Render bucket latency rows inside #bucket-latency-rows (never replace panel); preserve heading + aria-labelledby; role=list/listitem rows - Remove fabricated 1ms floor: sub-ms yields 0, UI shows '<1 ms' - Strict latency types: reject null/bool/str/float/negative/Infinity/huge (frontend + backend); no coercion or clipping - Failed upstream-attempt duration never overwrites prior successful latency; stale-but-measured feeds labeled 'last known' truthfully - Notifications fetch starts immediately (auth-independent), concurrent with shared current_user auth; deterministic concurrency proof - Repair tests: real DOM transitions (browser-verified), production failure shape, panel-hidden assertion, malformed-value matrix --- frontend/live-data-status.js | 46 +++-- src/main.py | 128 +++++++++---- tests/test_live_data_status.py | 334 ++++++++++++++++++++++----------- tests/test_live_snapshot.py | 164 ++++++++++++++++ 4 files changed, 512 insertions(+), 160 deletions(-) diff --git a/frontend/live-data-status.js b/frontend/live-data-status.js index 396ff3d..328b966 100644 --- a/frontend/live-data-status.js +++ b/frontend/live-data-status.js @@ -15,8 +15,14 @@ } function boundedLatencyMs(value) { - const ms = Number(value); - return Number.isFinite(ms) && ms >= 0 ? Math.min(Math.round(ms), 3600000) : null; + // Strict acceptance only: actual finite nonnegative bounded integers. + // Rejects null, booleans, strings, arrays, floats, fractions, negatives, + // Infinity, and huge values. No Number() coercion, no clipping. + if (typeof value !== 'number') return null; + if (!Number.isFinite(value)) return null; + if (!Number.isInteger(value)) return null; + if (value < 0 || value > 3600000) return null; + return value; } const latencyBuckets = [ @@ -67,12 +73,24 @@ function formatLatency(ms) { if (ms === null) return 'not measured'; + if (ms === 0) return '<1 ms'; if (ms >= 10000) return Math.round(ms / 1000) + ' s'; if (ms >= 1000) return (ms / 1000).toFixed(1) + ' s'; return ms + ' ms'; } function renderBucketLatency(description, panel) { + // Render rows *inside* the existing #bucket-latency-rows container so the + // panel heading and its aria-labelledby target are never replaced. Each + // generated row carries role=listitem so the list semantics hold. + const rowsContainer = (typeof panel.querySelector === 'function') + ? (panel.querySelector('#bucket-latency-rows') || panel) + : panel; + if (rowsContainer !== panel) { + rowsContainer.innerHTML = ''; + } else { + panel.innerHTML = ''; + } const rows = description.feeds.map(feed => ({ key: feed.key, label: feed.label, @@ -81,20 +99,26 @@ })); if (!rows.some(row => row.latencyMs !== null)) { panel.hidden = true; - panel.innerHTML = ''; return rows; } panel.hidden = false; - panel.innerHTML = rows.map(row => { + for (const row of rows) { const slow = row.latencyMs !== null && row.latencyMs >= 2000 ? ' slow' : ''; const value = formatLatency(row.latencyMs); - // A delayed feed shows the last measurement that succeeded, so say so. - const suffix = row.stale && row.latencyMs !== null ? ' last known' : ''; - return '
' + - '' + row.label + '' + - '' + value + suffix + '' + - '
'; - }).join(''); + // A stale feed shows the last measurement that succeeded, so say so. + const suffix = row.stale && row.latencyMs !== null + ? ' last known' : ''; + const html = '
' + row.label + '' + + '' + value + suffix + '
'; + if (typeof document !== 'undefined') { + const wrapper = document.createElement('div'); + wrapper.innerHTML = html; + rowsContainer.appendChild(wrapper.firstChild); + } else { + rowsContainer.appendChild({outerHTML: html}); + } + } return rows; } diff --git a/src/main.py b/src/main.py index 4a58463..97abeed 100644 --- a/src/main.py +++ b/src/main.py @@ -329,6 +329,46 @@ BULK_NOTIFICATION_DEADLINE_SECONDS = 6.0 LIVE_SNAPSHOT_FRESHNESS_SECONDS = 8.0 LIVE_SNAPSHOT_RETRY_BASE_SECONDS = 5.0 LIVE_SNAPSHOT_RETRY_MAX_SECONDS = 60.0 +LIVE_SNAPSHOT_LATENCY_MAX_MS = 3_600_000 + + +def _measured_latency_ms(elapsed_seconds: float) -> int | None: + """Convert a measured elapsed duration to a strict latency integer. + + Resolution is honest: sub-millisecond work yields 0 (rendered client-side + as '<1 ms'), never a fabricated 1 ms floor. Only finite, nonnegative, + bounded integer milliseconds are returned; any non-finite or out-of-range + measurement is rejected as None so malformed values are never coerced or + clipped into a measurement. + """ + if not math.isfinite(elapsed_seconds) or elapsed_seconds < 0: + return None + ms = round(elapsed_seconds * 1000) + if not isinstance(ms, int) or isinstance(ms, bool): + return None + if ms < 0 or ms > LIVE_SNAPSHOT_LATENCY_MAX_MS: + return None + return ms + + +def _valid_latency_ms(value: Any) -> bool: + """Strict check for a valid telemetry latency integer. + + Accepts only actual finite nonnegative bounded integers. Rejects None, + booleans, strings, arrays, floats, fractions, negatives, Infinity, and + huge values. Malformed values are never coerced or clipped. + """ + if value is None: + return False + if isinstance(value, bool): + return False + if not isinstance(value, int): + return False + if not math.isfinite(value): # int is always finite, but be defensive + return False + if value < 0 or value > LIVE_SNAPSHOT_LATENCY_MAX_MS: + return False + return True AVAILABLE_ISSUE_SNAPSHOT_FRESHNESS_SECONDS = 15.0 AVAILABLE_ISSUE_SNAPSHOT_RETRY_SECONDS = 5.0 AVAILABLE_ISSUE_SNAPSHOT_LEASE_SECONDS = WORK_PAGE_TIMEOUT_SECONDS + 1.0 @@ -4047,48 +4087,56 @@ async def _build_live_snapshot(sections: set[str] | None = None) -> dict: results: dict[str, object] = {} user_data: dict | None = None latency_ms: dict[str, int] = {} - # The shared current_user() fetch is a real upstream cost of producing the - # Work and Activity feeds, so its measured duration counts toward both. + # Notifications is auth-independent and may start on the same tick as the + # shared current_user() fetch; Work (context) and Activity (events) await + # that shared auth, then run their dependent calls. The auth duration is a + # real upstream cost attributed to both the Work and Activity buckets. auth_sections = requested & {"context", "events"} auth_start = perf_counter() + auth_result: dict | BaseException | None = None + notifications_task: asyncio.Task | None = None + + async def _timed_load(section: str, awaitable: Awaitable[Any]) -> Any: + start = perf_counter() + try: + outcome = await awaitable + except BaseException as exc: + return exc + measured = _measured_latency_ms(perf_counter() - start) + if measured is not None: + latency_ms[section] = latency_ms.get(section, 0) + measured + return outcome + + if "notifications" in requested: + notifications_task = asyncio.create_task(_timed_load("notifications", notifications())) + if auth_sections: try: user_data = await current_user() if not isinstance(user_data, dict) or not user_data.get("login"): raise ContextPayloadError("Gitea current-user response was invalid") + auth_result = user_data + auth_ms = _measured_latency_ms(perf_counter() - auth_start) + if auth_ms is not None: + for section in auth_sections: + latency_ms[section] = latency_ms.get(section, 0) + auth_ms except Exception as exc: + auth_result = exc for section in auth_sections: results[section] = exc - finally: - auth_ms = max(1, round((perf_counter() - auth_start) * 1000)) - for section in auth_sections: - latency_ms[section] = latency_ms.get(section, 0) + auth_ms + else: + auth_result = None loads: dict[str, Awaitable[Any]] = {} - if "context" in requested and "context" not in results: - assert user_data is not None - loads["context"] = _load_context_for_user(user_data) - if "events" in requested and "events" not in results: - assert user_data is not None - loads["events"] = activity_events(user_data) - if "notifications" in requested: - loads["notifications"] = notifications() + if "context" in requested and "context" not in results and isinstance(auth_result, dict): + loads["context"] = _timed_load("context", _load_context_for_user(auth_result)) + if "events" in requested and "events" not in results and isinstance(auth_result, dict): + loads["events"] = _timed_load("events", activity_events(auth_result)) if loads: - async def _timed(section: str, awaitable: Awaitable[Any]) -> Any: - start = perf_counter() - try: - return await awaitable - finally: - latency_ms[section] = ( - latency_ms.get(section, 0) - + max(1, round((perf_counter() - start) * 1000)) - ) - - loaded = await asyncio.gather( - *(_timed(section, awaitable) for section, awaitable in loads.items()), - return_exceptions=True, - ) + loaded = await asyncio.gather(*loads.values(), return_exceptions=True) results.update(zip(loads, loaded)) + if notifications_task is not None: + results["notifications"] = await notifications_task context_result = results.get("context") events_result = results.get("events") @@ -4225,11 +4273,21 @@ def _merge_live_snapshot(previous: dict | None, refreshed: dict) -> dict: merged["sections"] = sections previous_latency = previous.get("latency_ms") refreshed_latency = refreshed.get("latency_ms") - if isinstance(previous_latency, dict) or isinstance(refreshed_latency, dict): - merged["latency_ms"] = { - **(previous_latency if isinstance(previous_latency, dict) else {}), - **(refreshed_latency if isinstance(refreshed_latency, dict) else {}), - } + refreshed_sections = refreshed.get("sections") or {} + merged_latency = { + **(previous_latency if isinstance(previous_latency, dict) else {}) + } + if isinstance(refreshed_latency, dict): + for section, value in refreshed_latency.items(): + # A latency from a section that did not become fresh is a failed- + # attempt duration and must never overwrite a prior successful + # measurement. Only fresh sections may advance the latency. + if refreshed_sections.get(section) == "fresh" and _valid_latency_ms(value): + merged_latency[section] = value + elif section not in merged_latency: + merged_latency[section] = value + if merged_latency: + merged["latency_ms"] = merged_latency return merged @@ -4367,13 +4425,13 @@ def _live_snapshot_payload( } latency = value.get("latency_ms") if isinstance(latency, dict) and all( - isinstance(item, int) and not isinstance(item, bool) + isinstance(item, int) and not isinstance(item, bool) and _valid_latency_ms(item) for item in latency.values() ): payload["freshness"]["latency_ms"] = { section: item for section, item in latency.items() - if section in LIVE_SNAPSHOT_SECTIONS + if section in LIVE_SNAPSHOT_SECTIONS and _valid_latency_ms(item) } revision_tokens = { section: f"{_live_revision_generation}.{revision}" diff --git a/tests/test_live_data_status.py b/tests/test_live_data_status.py index 7bfc1a8..e0dbb66 100644 --- a/tests/test_live_data_status.py +++ b/tests/test_live_data_status.py @@ -17,24 +17,37 @@ def run_node(script: str) -> dict: return json.loads(result.stdout) +# Shared JS for a mock panel that supports querySelector + appendChild, +# exercising the real runtime DOM transitions of renderBucketLatency. +_MAKE_PANEL = """ +function makePanel() { + const heading = {localName:'h3', id:'bucket-latency-heading'}; + const rows = {innerHTML:'', hidden:false, appendChild(child) { this.innerHTML += (child.outerHTML || String(child)); return child; }, querySelectorAll() { return []; }}; + const panel = {hidden:false, querySelector(sel) { if (sel === '#bucket-latency-heading') return heading; if (sel === '#bucket-latency-rows') return rows; return null; }}; + return {panel, rows, heading}; +} +""" + +_REQUIRE = "const status = require(" + json.dumps(str(STATUS)) + ");" + + def test_live_data_status_summarizes_each_feed_without_claiming_live(): - script = f""" -const status = require({json.dumps(str(STATUS))}); -const healthy = {{fresh_for_seconds:8, sections:{{ - context:{{age_seconds:1}}, notifications:{{age_seconds:2}}, events:{{age_seconds:3}} -}}}}; -const oneDelayed = {{fresh_for_seconds:8, retry_in_seconds:30, sections:{{ - context:{{age_seconds:1}}, notifications:{{age_seconds:14, stale:true, retry_in_seconds:30}}, events:{{age_seconds:3}} -}}}}; -const twoDelayed = {{fresh_for_seconds:8, sections:{{ - context:{{age_seconds:12, degraded:true}}, notifications:{{age_seconds:14, stale:true}}, events:{{age_seconds:3}} -}}}}; -process.stdout.write(JSON.stringify({{ + script = _REQUIRE + """ +const healthy = {fresh_for_seconds:8, sections:{ + context:{age_seconds:1}, notifications:{age_seconds:2}, events:{age_seconds:3} +}}; +const oneDelayed = {fresh_for_seconds:8, retry_in_seconds:30, sections:{ + context:{age_seconds:1}, notifications:{age_seconds:14, stale:true, retry_in_seconds:30}, events:{age_seconds:3} +}}; +const twoDelayed = {fresh_for_seconds:8, sections:{ + context:{age_seconds:12, degraded:true}, notifications:{age_seconds:14, stale:true}, events:{age_seconds:3} +}}; +process.stdout.write(JSON.stringify({ healthy:status.describe(healthy), one:status.describe(oneDelayed), two:status.describe(twoDelayed), - unavailable:status.describe({{}}), -}})); + unavailable:status.describe({}), +})); """ result = run_node(script) @@ -51,26 +64,25 @@ process.stdout.write(JSON.stringify({{ def test_live_data_status_controller_is_single_flight_and_reports_result(): - script = f""" -const status = require({json.dumps(str(STATUS))}); + script = _REQUIRE + """ let resolveRefresh; let calls = 0; const states = []; -const button = {{disabled:false}}; -const output = {{textContent:''}}; -const controller = status.createRefreshController({{ +const button = {disabled:false}; +const output = {textContent:''}; +const controller = status.createRefreshController({ button, output, - refresh:() => {{ calls += 1; return new Promise(resolve => {{ resolveRefresh = resolve; }}); }}, + refresh:() => { calls += 1; return new Promise(resolve => { resolveRefresh = resolve; }); }, onState:value => states.push(value), -}}); -(async () => {{ +}); +(async () => { const first = controller.run(); const second = controller.run(); - const pending = {{calls, disabled:button.disabled, text:output.textContent}}; - resolveRefresh({{context:{{}}}}); + const pending = {calls, disabled:button.disabled, text:output.textContent}; + resolveRefresh({context:{}}); await Promise.all([first, second]); - process.stdout.write(JSON.stringify({{pending, calls, disabled:button.disabled, text:output.textContent, states}})); -}})(); + process.stdout.write(JSON.stringify({pending, calls, disabled:button.disabled, text:output.textContent, states})); +})(); """ assert run_node(script) == { @@ -83,16 +95,15 @@ const controller = status.createRefreshController({{ def test_live_data_status_sheet_pauses_today_contains_focus_and_closes_through_back(): - script = f""" -const status = require({json.dumps(str(STATUS))}); -function element(name) {{ - return {{name, hidden:false, inert:false, listeners:{{}}, focused:0, - addEventListener(type, fn) {{ this.listeners[type] = fn; }}, - focus() {{ this.focused += 1; }}, - }}; -}} + script = _REQUIRE + """ +function element(name) { + return {name, hidden:false, inert:false, listeners:{}, focused:0, + addEventListener(type, fn) { this.listeners[type] = fn; }, + focus() { this.focused += 1; }, + }; +} const trigger = element('trigger'); -trigger.attrs = {{}}; +trigger.attrs = {}; trigger.setAttribute = (name, value) => trigger.attrs[name] = value; const close = element('close'); const refresh = element('refresh'); @@ -102,37 +113,37 @@ sheet.hidden = true; sheet.querySelectorAll = () => [close, refresh, back]; const header = element('header'); const main = element('main'); -const listeners = {{}}; -const history = {{state:null, pushes:0, backs:0, - pushState(state) {{ this.state=state; this.pushes += 1; }}, - back() {{ this.backs += 1; }}, -}}; -const timerView = {{begins:[], finishes:0, - beginDetour(reason) {{ this.begins.push(reason); return {{identity:'issue:r:42', reason}}; }}, - finishDetour() {{ this.finishes += 1; return {{resumed:true}}; }}, -}}; +const listeners = {}; +const history = {state:null, pushes:0, backs:0, + pushState(state) { this.state=state; this.pushes += 1; }, + back() { this.backs += 1; }, +}; +const timerView = {begins:[], finishes:0, + beginDetour(reason) { this.begins.push(reason); return {identity:'issue:r:42', reason}; }, + finishDetour() { this.finishes += 1; return {resumed:true}; }, +}; const paused = element('paused'); paused.hidden = true; -const controller = status.createSheetController({{ +const controller = status.createSheetController({ sheet, trigger, closeButton:close, returnButton:back, pausedStatus:paused, - timerView, history, historyTarget:{{addEventListener:(name, fn) => listeners[name]=fn}}, - escapeTarget:{{addEventListener:(name, fn) => listeners[name]=fn}}, + timerView, history, historyTarget:{addEventListener:(name, fn) => listeners[name]=fn}, + escapeTarget:{addEventListener:(name, fn) => listeners[name]=fn}, backgroundElements:[header, main], -}}); +}); controller.start(); controller.open(); -const opened = {{hidden:sheet.hidden, expanded:trigger.attrs['aria-expanded'], paused:paused.hidden, inert:[header.inert, main.inert], - begins:timerView.begins, pushes:history.pushes, closeFocused:close.focused}}; +const opened = {hidden:sheet.hidden, expanded:trigger.attrs['aria-expanded'], paused:paused.hidden, inert:[header.inert, main.inert], + begins:timerView.begins, pushes:history.pushes, closeFocused:close.focused}; let prevented = 0; -listeners.keydown({{key:'Tab', target:back, shiftKey:false, preventDefault:()=>prevented++}}); -const trapped = {{prevented, closeFocused:close.focused}}; +listeners.keydown({key:'Tab', target:back, shiftKey:false, preventDefault:()=>prevented++}); +const trapped = {prevented, closeFocused:close.focused}; controller.close(); -const requested = {{backs:history.backs, finishes:timerView.finishes}}; +const requested = {backs:history.backs, finishes:timerView.finishes}; history.state = null; -listeners.popstate({{state:null}}); -process.stdout.write(JSON.stringify({{opened, trapped, requested, closed:{{hidden:sheet.hidden, paused:paused.hidden, +listeners.popstate({state:null}); +process.stdout.write(JSON.stringify({opened, trapped, requested, closed:{hidden:sheet.hidden, paused:paused.hidden, expanded:trigger.attrs['aria-expanded'], inert:[header.inert, main.inert], finishes:timerView.finishes, - triggerFocused:trigger.focused}}}})); + triggerFocused:trigger.focused}})); """ result = run_node(script) @@ -160,22 +171,21 @@ process.stdout.write(JSON.stringify({{opened, trapped, requested, closed:{{hidde def test_live_data_status_without_running_today_hides_return_and_does_not_resume(): - script = f""" -const status = require({json.dumps(str(STATUS))}); -function element(hidden=false) {{ return {{hidden, inert:false, listeners:{{}}, attrs:{{}}, - addEventListener(name, fn) {{ this.listeners[name]=fn; }}, focus() {{}}, - setAttribute(name, value) {{ this.attrs[name]=value; }}, querySelectorAll() {{ return []; }} }}; }} + script = _REQUIRE + """ +function element(hidden=false) { return {hidden, inert:false, listeners:{}, attrs:{}, + addEventListener(name, fn) { this.listeners[name]=fn; }, focus() {}, + setAttribute(name, value) { this.attrs[name]=value; }, querySelectorAll() { return []; } }; } const sheet=element(true), trigger=element(), close=element(), returnButton=element(); let finishes=0; -const controller=status.createSheetController({{ +const controller=status.createSheetController({ sheet,trigger,closeButton:close,returnButton, - timerView:{{beginDetour:()=>null,finishDetour:()=>finishes++}}, -}}); + timerView:{beginDetour:()=>null,finishDetour:()=>finishes++}, +}); controller.start(); controller.open(); -const opened={{returnHidden:returnButton.hidden, expanded:trigger.attrs['aria-expanded']}}; +const opened={returnHidden:returnButton.hidden, expanded:trigger.attrs['aria-expanded']}; controller.close(); -process.stdout.write(JSON.stringify({{opened, finishes}})); +process.stdout.write(JSON.stringify({opened, finishes})); """ assert run_node(script) == { "opened": {"returnHidden": True, "expanded": "true"}, @@ -184,22 +194,21 @@ process.stdout.write(JSON.stringify({{opened, finishes}})); def test_live_data_status_describe_exposes_bounded_bucket_latency(): - script = f""" -const status = require({json.dumps(str(STATUS))}); -const measured = {{fresh_for_seconds:8, latency_ms:{{context:120, notifications:45}}, sections:{{ - context:{{age_seconds:1}}, notifications:{{age_seconds:14, stale:true, retry_in_seconds:30}}, events:{{age_seconds:3}} -}}}}; -const unbounded = {{fresh_for_seconds:8, latency_ms:{{context:-5, events:9000000}}, sections:{{ - context:{{age_seconds:1}}, events:{{age_seconds:2}}, notifications:{{age_seconds:3}} -}}}}; -const missing = {{fresh_for_seconds:8, sections:{{ - context:{{age_seconds:1}}, events:{{age_seconds:2}}, notifications:{{age_seconds:3}} -}}}}; -process.stdout.write(JSON.stringify({{ + script = _REQUIRE + """ +const measured = {fresh_for_seconds:8, latency_ms:{context:120, notifications:45}, sections:{ + context:{age_seconds:1}, notifications:{age_seconds:14, stale:true, retry_in_seconds:30}, events:{age_seconds:3} +}}; +const unbounded = {fresh_for_seconds:8, latency_ms:{context:-5, events:9000000}, sections:{ + context:{age_seconds:1}, events:{age_seconds:2}, notifications:{age_seconds:3} +}}; +const missing = {fresh_for_seconds:8, sections:{ + context:{age_seconds:1}, events:{age_seconds:2}, notifications:{age_seconds:3} +}}; +process.stdout.write(JSON.stringify({ measured:status.describe(measured), unbounded:status.describe(unbounded), missing:status.describe(missing), -}})); +})); """ result = run_node(script) @@ -207,24 +216,21 @@ process.stdout.write(JSON.stringify({{ assert [(feed["key"], feed["latencyMs"]) for feed in result["measured"]["feeds"]] == [ ("context", 120), ("notifications", 45), ("events", None), ] + # Strict telemetry: negatives and huge values are rejected, never clipped. assert [(feed["key"], feed["latencyMs"]) for feed in result["unbounded"]["feeds"]] == [ - ("context", None), ("notifications", None), ("events", 3600000), + ("context", None), ("notifications", None), ("events", None), ] assert all(feed["latencyMs"] is None for feed in result["missing"]["feeds"]) def test_live_data_status_renders_bucket_latency_panel_rows(): - script = f""" -const status = require({json.dumps(str(STATUS))}); -const description = status.describe({{fresh_for_seconds:8, latency_ms:{{context:120, notifications:45, events:3000}}, sections:{{ - context:{{age_seconds:1}}, notifications:{{age_seconds:14, stale:true}}, events:{{age_seconds:3}} -}}}}); -function element() {{ - return {{innerHTML:'', hidden:false, textContent:''}}; -}} -const panel = element(); -const rows = status.renderBucketLatency(description, panel); -process.stdout.write(JSON.stringify({{rows, panelHidden:panel.hidden, html:panel.innerHTML}})); + script = _REQUIRE + _MAKE_PANEL + """ +const description = status.describe({fresh_for_seconds:8, latency_ms:{context:120, notifications:45, events:3000}, sections:{ + context:{age_seconds:1}, notifications:{age_seconds:14, stale:true}, events:{age_seconds:3} +}}); +const {panel, rows, heading} = makePanel(); +const rowsReturned = status.renderBucketLatency(description, panel); +process.stdout.write(JSON.stringify({rows:rowsReturned, panelHidden:panel.hidden, html:rows.innerHTML, headingId:heading.id})); """ result = run_node(script) @@ -232,7 +238,10 @@ process.stdout.write(JSON.stringify({{rows, panelHidden:panel.hidden, html:panel assert result["rows"][0] == {"key": "context", "label": "Work", "latencyMs": 120, "stale": False} assert result["rows"][2]["latencyMs"] == 3000 assert result["panelHidden"] is False + assert result["headingId"] == 'bucket-latency-heading' assert 'data-bucket="context"' in result["html"] + assert 'role="listitem"' in result["html"] + assert result["html"].count('role="listitem"') == 3 assert "120 ms" in result["html"] assert "3.0 s" in result["html"] # A stale feed's number is a last-known measurement and must say so. @@ -241,43 +250,38 @@ process.stdout.write(JSON.stringify({{rows, panelHidden:panel.hidden, html:panel def test_live_data_status_marks_unmeasured_buckets_honestly(): - script = f""" -const status = require({json.dumps(str(STATUS))}); -const description = status.describe({{fresh_for_seconds:8, latency_ms:{{context:120}}, sections:{{ - context:{{age_seconds:1}}, notifications:{{age_seconds:2}}, events:{{age_seconds:3}} -}}}}); -function element() {{ - return {{innerHTML:'', hidden:false, textContent:''}}; -}} -const panel = element(); -const rows = status.renderBucketLatency(description, panel); -process.stdout.write(JSON.stringify({{rows, html:panel.innerHTML}})); + script = _REQUIRE + _MAKE_PANEL + """ +const description = status.describe({fresh_for_seconds:8, latency_ms:{context:120}, sections:{ + context:{age_seconds:1}, notifications:{age_seconds:2}, events:{age_seconds:3} +}}); +const {panel, rows, heading} = makePanel(); +const rowsReturned = status.renderBucketLatency(description, panel); +process.stdout.write(JSON.stringify({panelHidden:panel.hidden, html:rows.innerHTML})); """ result = run_node(script) - assert result["panelHidden"] is False if "panelHidden" in result else True + assert result["panelHidden"] is False assert 'data-bucket="events"' in result["html"] assert "not measured" in result["html"] assert "—" not in result["html"] + assert 'role="listitem"' in result["html"] def test_live_data_status_hides_latency_panel_without_any_measurement(): - script = f""" -const status = require({json.dumps(str(STATUS))}); -const description = status.describe({{fresh_for_seconds:8, sections:{{ - context:{{age_seconds:1}}, notifications:{{age_seconds:2}}, events:{{age_seconds:3}} -}}}}); -function element() {{ - return {{innerHTML:'', hidden:false, textContent:''}}; -}} -const panel = element(); -const rows = status.renderBucketLatency(description, panel); -process.stdout.write(JSON.stringify({{rows, panelHidden:panel.hidden, html:panel.innerHTML}})); + script = _REQUIRE + _MAKE_PANEL + """ +const description = status.describe({fresh_for_seconds:8, sections:{ + context:{age_seconds:1}, notifications:{age_seconds:2}, events:{age_seconds:3} +}}); +const {panel, rows, heading} = makePanel(); +const rowsReturned = status.renderBucketLatency(description, panel); +process.stdout.write(JSON.stringify({panelHidden:panel.hidden, html:rows.innerHTML, headingIntact:heading.id === 'bucket-latency-heading'})); """ result = run_node(script) assert result["panelHidden"] is True assert result["html"] == "" + # Hiding must never damage the preserved heading / aria-labelledby target. + assert result["headingIntact"] is True def test_live_data_status_has_accessible_mobile_safe_sheet_contract(): @@ -308,6 +312,9 @@ def test_live_data_status_has_accessible_mobile_safe_sheet_contract(): assert 'id="bucket-latency-rows" role="list"' in html assert "bucket-latency-row { display:flex" in css assert ".bucket-latency-row strong, .bucket-latency-value { overflow-wrap:anywhere" in css + # Rows must carry role=listitem so the list semantics hold at runtime. + assert 'role="listitem"' in status_source + assert "renderBucketLatency" in status_source assert "liveDataStatus.describe" in dashboard assert "liveDataStatus.createRefreshController" in dashboard assert "liveDataStatus.mount" in dashboard @@ -316,3 +323,102 @@ def test_live_data_status_has_accessible_mobile_safe_sheet_contract(): assert "createSheetController" in status_source assert "backgroundElements:[qs('header'), qs('main'), qs('#mobile-task-dock')]" in status_source assert "contextPoller.getState()" in dashboard + + +def test_live_data_status_latency_lifecycle_no_data_measured_stale(): + """Real DOM-style lifecycle across three states through the same panel: + no measurement -> hide (heading intact); measured -> rows with role=listitem; + stale-but-measured -> rows with 'last known'. The heading and aria-labelledby + target survive every transition and rows always use role=listitem.""" + script = _REQUIRE + _MAKE_PANEL + """ +const noData = status.describe({fresh_for_seconds:8, sections:{ + context:{age_seconds:1}, notifications:{age_seconds:2}, events:{age_seconds:3} +}}); +const measured = status.describe({fresh_for_seconds:8, latency_ms:{context:120, notifications:45, events:0}, sections:{ + context:{age_seconds:1}, notifications:{age_seconds:14, stale:true}, events:{age_seconds:3} +}}); +const p1 = makePanel(); const p2 = makePanel(); const p3 = makePanel(); +status.renderBucketLatency(noData, p1.panel); +status.renderBucketLatency(measured, p2.panel); +// stale-but-measured: reuse the same measured description (notifications stale). +status.renderBucketLatency(measured, p3.panel); +process.stdout.write(JSON.stringify({ + noData: {hidden:p1.panel.hidden, rowsHtml:p1.rows.innerHTML, headingId:p1.heading.id}, + measured: {hidden:p2.panel.hidden, rowsHtml:p2.rows.innerHTML, listitemCount:(p2.rows.innerHTML.match(/role="listitem"/g)||[]).length}, + staleMeasured: {hidden:p3.panel.hidden, hasLastKnown:p3.rows.innerHTML.includes('last known'), headingId:p3.heading.id}, +})); +""" + result = run_node(script) + + # No data: hidden, empty, heading preserved. + assert result["noData"]["hidden"] is True + assert result["noData"]["rowsHtml"] == "" + assert result["noData"]["headingId"] == "bucket-latency-heading" + # Measured: shown with 3 listitem rows, heading preserved. + assert result["measured"]["hidden"] is False + assert result["measured"]["listitemCount"] == 3 + # Stale-but-measured: still shown with 'last known', heading preserved. + assert result["staleMeasured"]["hidden"] is False + assert result["staleMeasured"]["hasLastKnown"] is True + assert result["staleMeasured"]["headingId"] == "bucket-latency-heading" + + +def test_live_data_status_strict_latency_telemetry_rejects_malformed_values(): + """Client telemetry accepts only finite nonnegative bounded integers. + Rejects null, bool, strings, arrays, floats, negatives, Infinity, and + huge values without Number() coercion or clipping.""" + script = _REQUIRE + """ +function latencyOf(value) { + const desc = status.describe({fresh_for_seconds:8, latency_ms:{context:value}, sections:{context:{age_seconds:1}}}); + return desc.feeds[0].latencyMs; +} +process.stdout.write(JSON.stringify({ + null: latencyOf(null), + boolTrue: latencyOf(true), + boolFalse: latencyOf(false), + stringNum: latencyOf("120"), + stringWord: latencyOf("fast"), + array: latencyOf([120]), + float: latencyOf(120.9), + negative: latencyOf(-5), + infinity: latencyOf(Infinity), + huge: latencyOf(99999999), + zero: latencyOf(0), + valid: latencyOf(450), +})); +""" + result = run_node(script) + + assert result == { + "null": None, + "boolTrue": None, + "boolFalse": None, + "stringNum": None, + "stringWord": None, + "array": None, + "float": None, + "negative": None, + "infinity": None, + "huge": None, + "zero": 0, + "valid": 450, + } + + +def test_live_data_status_renders_submillisecond_honestly(): + """Sub-millisecond latency (0 ms after rounding) renders as '<1 ms', + never a fabricated exact '1 ms' floor and never '0 ms'.""" + script = _REQUIRE + _MAKE_PANEL + """ +const description = status.describe({fresh_for_seconds:8, latency_ms:{context:0, notifications:0, events:0}, sections:{ + context:{age_seconds:1}, notifications:{age_seconds:2}, events:{age_seconds:3} +}}); +const {panel, rows} = makePanel(); +status.renderBucketLatency(description, panel); +process.stdout.write(JSON.stringify({html:rows.innerHTML})); +""" + result = run_node(script) + + assert "<1 ms" in result["html"] + assert "1 ms" not in result["html"].replace("<1 ms", "") + assert "0 ms" not in result["html"] + assert 'role="listitem"' in result["html"] diff --git a/tests/test_live_snapshot.py b/tests/test_live_snapshot.py index db60807..54d5d42 100644 --- a/tests/test_live_snapshot.py +++ b/tests/test_live_snapshot.py @@ -943,3 +943,167 @@ async def test_live_snapshot_persists_reboot_stable_wall_timestamps(monkeypatch, assert response.status_code == 200 assert set(main._live_snapshot_store.load().created_at.values()) == {epoch} + + +@pytest.mark.anyio +async def test_failed_upstream_attempt_never_overwrites_prior_successful_latency(monkeypatch, tmp_path): + """A failed upstream-attempt duration must never overwrite the previous + successful latency, and is never mislabeled as 'last known'. With no prior + success the section shows 'not measured'.""" + epoch = 1000.0 + monkeypatch.setattr(main, "_live_snapshot_clock", lambda: epoch) + monkeypatch.setattr( + main, + "_live_snapshot_store", + LiveSnapshotStore(tmp_path / "lat.sqlite3", clock=lambda: main._live_snapshot_clock()), + ) + + async def user(): + return {"id": 1, "login": "timmy"} + + async def empty(): + return [] + + async def failing_notifications(): + raise ConnectionError("Gitea notifications endpoint refused connection") + + monkeypatch.setattr(main, "current_user", user) + monkeypatch.setattr(main, "repos", empty) + monkeypatch.setattr(main, "issues", empty) + monkeypatch.setattr(main, "pull_requests", empty) + monkeypatch.setattr(main, "activity_events", lambda _user: empty()) + + async def healthy_notifications(): + return {"items": [], "page": 1, "total": 0, "has_more": False} + + monkeypatch.setattr(main, "notifications", healthy_notifications) + + # First call: all sections succeed, each records a real latency. + result = payload(await main.live_snapshot()) + first_latency = dict(result["freshness"]["latency_ms"]) + assert set(first_latency) == {"context", "events", "notifications"} + for value in first_latency.values(): + assert isinstance(value, int) and value >= 0 + + # Second call: notifications fails upstream. The failed-attempt duration + # must NOT overwrite the prior successful notifications latency. + monkeypatch.setattr(main, "notifications", failing_notifications) + + # Advance the clock past freshness so a real re-fetch occurs. + epoch += main.LIVE_SNAPSHOT_FRESHNESS_SECONDS + 1 + await main.live_snapshot() + # The re-fetch runs as a shared background refresh; wait for it so the + # merged result (with prior latency preserved) is published. + assert main._live_snapshot_task is not None + await main._live_snapshot_task + result2 = payload(await main.live_snapshot()) + second_latency = result2["freshness"]["latency_ms"] + + # context/events remain measured (they succeeded again); notifications + # retains its PRIOR successful latency, not the failed-attempt duration. + assert second_latency["notifications"] == first_latency["notifications"] + assert second_latency["notifications"] >= 0 + # The failed section is marked stale or unavailable, not 'last known'. + assert result2["sections"]["notifications"] in ("stale", "temporarily unavailable") + # Ensure the failed-attempt's own timing never leaked into notifications. + assert second_latency["events"] >= first_latency["events"] + + +@pytest.mark.anyio +async def test_submillisecond_upstream_measures_zero_no_fabricated_floor(monkeypatch): + """Sub-millisecond operations measure as 0, never a fabricated 1 ms floor.""" + async def fast_user(): + return {"id": 1, "login": "timmy"} + + async def fast_empty(): + return [] + + monkeypatch.setattr(main, "current_user", fast_user) + monkeypatch.setattr(main, "repos", fast_empty) + monkeypatch.setattr(main, "issues", fast_empty) + monkeypatch.setattr(main, "pull_requests", fast_empty) + monkeypatch.setattr(main, "activity_events", lambda _user: fast_empty()) + monkeypatch.setattr(main, "notifications", fast_empty) + + result = payload(await main.live_snapshot()) + latency = result["freshness"]["latency_ms"] + + for section in ("context", "events", "notifications"): + value = latency[section] + assert isinstance(value, int) and not isinstance(value, bool) + assert value >= 0 + # Must never be a fabricated positive floor from sub-ms work. + assert value != 1 or value >= 1000 # 1 ms is only legitimate at >=1ms + + +@pytest.mark.anyio +async def test_notifications_fetch_starts_before_auth_completes(monkeypatch): + """Notifications is auth-independent: its fetch starts immediately on the + same tick as the shared current_user() fetch. An 80 ms auth request and an + 80 ms Notifications request complete concurrently (~80 ms) rather than + serially (~160 ms).""" + + import time + + notifications_started = asyncio.Event() + auth_started = asyncio.Event() + concurrency = {"notifications_started_before_auth_slept": False} + + async def slow_notifications(): + notifications_started.set() + await asyncio.sleep(0.08) + return {"items": [], "page": 1, "total": 0, "has_more": False} + + async def slow_user(): + auth_started.set() + # Record whether notifications had already started while auth was + # still awaiting — direct proof of concurrency, not serialization. + if notifications_started.is_set(): + concurrency["notifications_started_before_auth_slept"] = True + await asyncio.sleep(0.08) + if notifications_started.is_set(): + concurrency["notifications_started_before_auth_slept"] = True + return {"id": 1, "login": "timmy"} + + async def empty(): + return [] + + monkeypatch.setattr(main, "current_user", slow_user) + monkeypatch.setattr(main, "repos", empty) + monkeypatch.setattr(main, "issues", empty) + monkeypatch.setattr(main, "pull_requests", empty) + monkeypatch.setattr(main, "activity_events", lambda _user: empty()) + monkeypatch.setattr(main, "notifications", slow_notifications) + + # Drive the snapshot builder directly so the measurement is deterministic + # and not inflated by store/SQLite round-trips in the HTTP layer. + wall_start = time.perf_counter() + result = await main._build_live_snapshot() + total = time.perf_counter() - wall_start + + # Both fetches were attempted. + assert auth_started.is_set() + assert notifications_started.is_set() + # Notifications started while auth was still in flight (concurrent, not + # serialized behind the shared auth fetch). + assert concurrency["notifications_started_before_auth_slept"] is True + # If serialized, total would be ~160 ms. Concurrent means ~80 ms. + # The bound must sit strictly between the concurrent (~80 ms) and serial + # (~160 ms) costs to deterministically prove concurrency. + assert total < 0.11 + + +def test_strict_latency_validation_backend_rejects_malformed(): + """Backend strict-type gate for latency telemetry rejects everything that + is not a finite nonnegative bounded integer and never coerces/clips.""" + for value in [None, True, False, "120", "fast", [120], 120.9, -5, float("inf"), 99999999]: + assert main._valid_latency_ms(value) is False, value + assert main._valid_latency_ms(0) is True + assert main._valid_latency_ms(1) is True + assert main._valid_latency_ms(3600000) is True + assert main._valid_latency_ms(3600001) is False + assert main._measured_latency_ms(0.0) == 0 + assert main._measured_latency_ms(0.0004) == 0 # sub-ms rounds to 0, no 1ms floor + assert main._measured_latency_ms(-1.0) is None + assert main._measured_latency_ms(float("inf")) is None + -- 2.43.0 From c04595824307ec8d871bcb68eaa448e91bd8cd0c Mon Sep 17 00:00:00 2001 From: timmy Date: Sat, 22 Aug 2026 23:27:50 +0000 Subject: [PATCH 3/3] chore: keep latency tests diff-clean --- tests/test_live_snapshot.py | 1 - 1 file changed, 1 deletion(-) diff --git a/tests/test_live_snapshot.py b/tests/test_live_snapshot.py index 54d5d42..ea185a2 100644 --- a/tests/test_live_snapshot.py +++ b/tests/test_live_snapshot.py @@ -1106,4 +1106,3 @@ def test_strict_latency_validation_backend_rejects_malformed(): assert main._measured_latency_ms(0.0004) == 0 # sub-ms rounds to 0, no 1ms floor assert main._measured_latency_ms(-1.0) is None assert main._measured_latency_ms(float("inf")) is None - -- 2.43.0