From 398598e154e07929dcdc24a2841f64bb64391333 Mon Sep 17 00:00:00 2001 From: ox Date: Sat, 22 Aug 2026 21:49:39 +0000 Subject: [PATCH] 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