Correct bucket latency telemetry (PR 1282, 398598e)
Some checks failed
CI / lint (pull_request) Successful in 6m20s
CI / build-release (pull_request) Successful in 12s
CI / browser-journey (pull_request) Failing after 10m12s
CI / release-candidate (pull_request) Has been skipped

- 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
This commit is contained in:
timmy 2026-08-22 23:22:40 +00:00
parent 398598e154
commit 81d288405f
4 changed files with 512 additions and 160 deletions

View File

@ -15,8 +15,14 @@
} }
function boundedLatencyMs(value) { function boundedLatencyMs(value) {
const ms = Number(value); // Strict acceptance only: actual finite nonnegative bounded integers.
return Number.isFinite(ms) && ms >= 0 ? Math.min(Math.round(ms), 3600000) : null; // 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 = [ const latencyBuckets = [
@ -67,12 +73,24 @@
function formatLatency(ms) { function formatLatency(ms) {
if (ms === null) return 'not measured'; if (ms === null) return 'not measured';
if (ms === 0) return '<1 ms';
if (ms >= 10000) return Math.round(ms / 1000) + ' s'; if (ms >= 10000) return Math.round(ms / 1000) + ' s';
if (ms >= 1000) return (ms / 1000).toFixed(1) + ' s'; if (ms >= 1000) return (ms / 1000).toFixed(1) + ' s';
return ms + ' ms'; return ms + ' ms';
} }
function renderBucketLatency(description, panel) { 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 => ({ const rows = description.feeds.map(feed => ({
key: feed.key, key: feed.key,
label: feed.label, label: feed.label,
@ -81,20 +99,26 @@
})); }));
if (!rows.some(row => row.latencyMs !== null)) { if (!rows.some(row => row.latencyMs !== null)) {
panel.hidden = true; panel.hidden = true;
panel.innerHTML = '';
return rows; return rows;
} }
panel.hidden = false; panel.hidden = false;
panel.innerHTML = rows.map(row => { for (const row of rows) {
const slow = row.latencyMs !== null && row.latencyMs >= 2000 ? ' slow' : ''; const slow = row.latencyMs !== null && row.latencyMs >= 2000 ? ' slow' : '';
const value = formatLatency(row.latencyMs); const value = formatLatency(row.latencyMs);
// A delayed feed shows the last measurement that succeeded, so say so. // A stale feed shows the last measurement that succeeded, so say so.
const suffix = row.stale && row.latencyMs !== null ? ' <span class="small muted">last known</span>' : ''; const suffix = row.stale && row.latencyMs !== null
return '<div class="bucket-latency-row" data-bucket="' + row.key + '">' + ? ' <span class="small muted">last known</span>' : '';
'<strong>' + row.label + '</strong>' + const html = '<div class="bucket-latency-row' + slow + '" role="listitem" data-bucket="' +
'<span class="bucket-latency-value' + slow + '">' + value + suffix + '</span>' + row.key + '"><strong>' + row.label + '</strong>' +
'</div>'; '<span class="bucket-latency-value' + slow + '">' + value + suffix + '</span></div>';
}).join(''); if (typeof document !== 'undefined') {
const wrapper = document.createElement('div');
wrapper.innerHTML = html;
rowsContainer.appendChild(wrapper.firstChild);
} else {
rowsContainer.appendChild({outerHTML: html});
}
}
return rows; return rows;
} }

View File

@ -329,6 +329,46 @@ BULK_NOTIFICATION_DEADLINE_SECONDS = 6.0
LIVE_SNAPSHOT_FRESHNESS_SECONDS = 8.0 LIVE_SNAPSHOT_FRESHNESS_SECONDS = 8.0
LIVE_SNAPSHOT_RETRY_BASE_SECONDS = 5.0 LIVE_SNAPSHOT_RETRY_BASE_SECONDS = 5.0
LIVE_SNAPSHOT_RETRY_MAX_SECONDS = 60.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_FRESHNESS_SECONDS = 15.0
AVAILABLE_ISSUE_SNAPSHOT_RETRY_SECONDS = 5.0 AVAILABLE_ISSUE_SNAPSHOT_RETRY_SECONDS = 5.0
AVAILABLE_ISSUE_SNAPSHOT_LEASE_SECONDS = WORK_PAGE_TIMEOUT_SECONDS + 1.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] = {} results: dict[str, object] = {}
user_data: dict | None = None user_data: dict | None = None
latency_ms: dict[str, int] = {} latency_ms: dict[str, int] = {}
# The shared current_user() fetch is a real upstream cost of producing the # Notifications is auth-independent and may start on the same tick as the
# Work and Activity feeds, so its measured duration counts toward both. # 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_sections = requested & {"context", "events"}
auth_start = perf_counter() 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: if auth_sections:
try: try:
user_data = await current_user() user_data = await current_user()
if not isinstance(user_data, dict) or not user_data.get("login"): if not isinstance(user_data, dict) or not user_data.get("login"):
raise ContextPayloadError("Gitea current-user response was invalid") 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: except Exception as exc:
auth_result = exc
for section in auth_sections: for section in auth_sections:
results[section] = exc results[section] = exc
finally: else:
auth_ms = max(1, round((perf_counter() - auth_start) * 1000)) auth_result = None
for section in auth_sections:
latency_ms[section] = latency_ms.get(section, 0) + auth_ms
loads: dict[str, Awaitable[Any]] = {} loads: dict[str, Awaitable[Any]] = {}
if "context" in requested and "context" not in results: if "context" in requested and "context" not in results and isinstance(auth_result, dict):
assert user_data is not None loads["context"] = _timed_load("context", _load_context_for_user(auth_result))
loads["context"] = _load_context_for_user(user_data) if "events" in requested and "events" not in results and isinstance(auth_result, dict):
if "events" in requested and "events" not in results: loads["events"] = _timed_load("events", activity_events(auth_result))
assert user_data is not None
loads["events"] = activity_events(user_data)
if "notifications" in requested:
loads["notifications"] = notifications()
if loads: if loads:
async def _timed(section: str, awaitable: Awaitable[Any]) -> Any: loaded = await asyncio.gather(*loads.values(), return_exceptions=True)
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)) results.update(zip(loads, loaded))
if notifications_task is not None:
results["notifications"] = await notifications_task
context_result = results.get("context") context_result = results.get("context")
events_result = results.get("events") events_result = results.get("events")
@ -4225,11 +4273,21 @@ def _merge_live_snapshot(previous: dict | None, refreshed: dict) -> dict:
merged["sections"] = sections merged["sections"] = sections
previous_latency = previous.get("latency_ms") previous_latency = previous.get("latency_ms")
refreshed_latency = refreshed.get("latency_ms") refreshed_latency = refreshed.get("latency_ms")
if isinstance(previous_latency, dict) or isinstance(refreshed_latency, dict): refreshed_sections = refreshed.get("sections") or {}
merged["latency_ms"] = { merged_latency = {
**(previous_latency if isinstance(previous_latency, dict) else {}), **(previous_latency if isinstance(previous_latency, dict) else {})
**(refreshed_latency if isinstance(refreshed_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 return merged
@ -4367,13 +4425,13 @@ def _live_snapshot_payload(
} }
latency = value.get("latency_ms") latency = value.get("latency_ms")
if isinstance(latency, dict) and all( 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() for item in latency.values()
): ):
payload["freshness"]["latency_ms"] = { payload["freshness"]["latency_ms"] = {
section: item section: item
for section, item in latency.items() 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 = { revision_tokens = {
section: f"{_live_revision_generation}.{revision}" section: f"{_live_revision_generation}.{revision}"

View File

@ -17,24 +17,37 @@ def run_node(script: str) -> dict:
return json.loads(result.stdout) 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(): def test_live_data_status_summarizes_each_feed_without_claiming_live():
script = f""" script = _REQUIRE + """
const status = require({json.dumps(str(STATUS))}); const healthy = {fresh_for_seconds:8, sections:{
const healthy = {{fresh_for_seconds:8, sections:{{ context:{age_seconds:1}, notifications:{age_seconds:2}, events:{age_seconds:3}
context:{{age_seconds:1}}, notifications:{{age_seconds:2}}, events:{{age_seconds:3}} }};
}}}}; const oneDelayed = {fresh_for_seconds:8, retry_in_seconds:30, sections:{
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}
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:{
const twoDelayed = {{fresh_for_seconds:8, sections:{{ context:{age_seconds:12, degraded:true}, notifications:{age_seconds:14, stale:true}, events:{age_seconds:3}
context:{{age_seconds:12, degraded:true}}, notifications:{{age_seconds:14, stale:true}}, events:{{age_seconds:3}} }};
}}}}; process.stdout.write(JSON.stringify({
process.stdout.write(JSON.stringify({{
healthy:status.describe(healthy), healthy:status.describe(healthy),
one:status.describe(oneDelayed), one:status.describe(oneDelayed),
two:status.describe(twoDelayed), two:status.describe(twoDelayed),
unavailable:status.describe({{}}), unavailable:status.describe({}),
}})); }));
""" """
result = run_node(script) 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(): def test_live_data_status_controller_is_single_flight_and_reports_result():
script = f""" script = _REQUIRE + """
const status = require({json.dumps(str(STATUS))});
let resolveRefresh; let resolveRefresh;
let calls = 0; let calls = 0;
const states = []; const states = [];
const button = {{disabled:false}}; const button = {disabled:false};
const output = {{textContent:''}}; const output = {textContent:''};
const controller = status.createRefreshController({{ const controller = status.createRefreshController({
button, output, 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), onState:value => states.push(value),
}}); });
(async () => {{ (async () => {
const first = controller.run(); const first = controller.run();
const second = controller.run(); const second = controller.run();
const pending = {{calls, disabled:button.disabled, text:output.textContent}}; const pending = {calls, disabled:button.disabled, text:output.textContent};
resolveRefresh({{context:{{}}}}); resolveRefresh({context:{}});
await Promise.all([first, second]); 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) == { 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(): def test_live_data_status_sheet_pauses_today_contains_focus_and_closes_through_back():
script = f""" script = _REQUIRE + """
const status = require({json.dumps(str(STATUS))}); function element(name) {
function element(name) {{ return {name, hidden:false, inert:false, listeners:{}, focused:0,
return {{name, hidden:false, inert:false, listeners:{{}}, focused:0, addEventListener(type, fn) { this.listeners[type] = fn; },
addEventListener(type, fn) {{ this.listeners[type] = fn; }}, focus() { this.focused += 1; },
focus() {{ this.focused += 1; }}, };
}}; }
}}
const trigger = element('trigger'); const trigger = element('trigger');
trigger.attrs = {{}}; trigger.attrs = {};
trigger.setAttribute = (name, value) => trigger.attrs[name] = value; trigger.setAttribute = (name, value) => trigger.attrs[name] = value;
const close = element('close'); const close = element('close');
const refresh = element('refresh'); const refresh = element('refresh');
@ -102,37 +113,37 @@ sheet.hidden = true;
sheet.querySelectorAll = () => [close, refresh, back]; sheet.querySelectorAll = () => [close, refresh, back];
const header = element('header'); const header = element('header');
const main = element('main'); const main = element('main');
const listeners = {{}}; const listeners = {};
const history = {{state:null, pushes:0, backs:0, const history = {state:null, pushes:0, backs:0,
pushState(state) {{ this.state=state; this.pushes += 1; }}, pushState(state) { this.state=state; this.pushes += 1; },
back() {{ this.backs += 1; }}, back() { this.backs += 1; },
}}; };
const timerView = {{begins:[], finishes:0, const timerView = {begins:[], finishes:0,
beginDetour(reason) {{ this.begins.push(reason); return {{identity:'issue:r:42', reason}}; }}, beginDetour(reason) { this.begins.push(reason); return {identity:'issue:r:42', reason}; },
finishDetour() {{ this.finishes += 1; return {{resumed:true}}; }}, finishDetour() { this.finishes += 1; return {resumed:true}; },
}}; };
const paused = element('paused'); const paused = element('paused');
paused.hidden = true; paused.hidden = true;
const controller = status.createSheetController({{ const controller = status.createSheetController({
sheet, trigger, closeButton:close, returnButton:back, pausedStatus:paused, sheet, trigger, closeButton:close, returnButton:back, pausedStatus:paused,
timerView, history, historyTarget:{{addEventListener:(name, fn) => listeners[name]=fn}}, timerView, history, historyTarget:{addEventListener:(name, fn) => listeners[name]=fn},
escapeTarget:{{addEventListener:(name, fn) => listeners[name]=fn}}, escapeTarget:{addEventListener:(name, fn) => listeners[name]=fn},
backgroundElements:[header, main], backgroundElements:[header, main],
}}); });
controller.start(); controller.start();
controller.open(); controller.open();
const opened = {{hidden:sheet.hidden, expanded:trigger.attrs['aria-expanded'], paused:paused.hidden, inert:[header.inert, main.inert], 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}}; begins:timerView.begins, pushes:history.pushes, closeFocused:close.focused};
let prevented = 0; let prevented = 0;
listeners.keydown({{key:'Tab', target:back, shiftKey:false, preventDefault:()=>prevented++}}); listeners.keydown({key:'Tab', target:back, shiftKey:false, preventDefault:()=>prevented++});
const trapped = {{prevented, closeFocused:close.focused}}; const trapped = {prevented, closeFocused:close.focused};
controller.close(); controller.close();
const requested = {{backs:history.backs, finishes:timerView.finishes}}; const requested = {backs:history.backs, finishes:timerView.finishes};
history.state = null; history.state = null;
listeners.popstate({{state:null}}); listeners.popstate({state:null});
process.stdout.write(JSON.stringify({{opened, trapped, requested, closed:{{hidden:sheet.hidden, paused:paused.hidden, 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, expanded:trigger.attrs['aria-expanded'], inert:[header.inert, main.inert], finishes:timerView.finishes,
triggerFocused:trigger.focused}}}})); triggerFocused:trigger.focused}}));
""" """
result = run_node(script) 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(): def test_live_data_status_without_running_today_hides_return_and_does_not_resume():
script = f""" script = _REQUIRE + """
const status = require({json.dumps(str(STATUS))}); function element(hidden=false) { return {hidden, inert:false, listeners:{}, attrs:{},
function element(hidden=false) {{ return {{hidden, inert:false, listeners:{{}}, attrs:{{}}, addEventListener(name, fn) { this.listeners[name]=fn; }, focus() {},
addEventListener(name, fn) {{ this.listeners[name]=fn; }}, focus() {{}}, setAttribute(name, value) { this.attrs[name]=value; }, querySelectorAll() { return []; } }; }
setAttribute(name, value) {{ this.attrs[name]=value; }}, querySelectorAll() {{ return []; }} }}; }}
const sheet=element(true), trigger=element(), close=element(), returnButton=element(); const sheet=element(true), trigger=element(), close=element(), returnButton=element();
let finishes=0; let finishes=0;
const controller=status.createSheetController({{ const controller=status.createSheetController({
sheet,trigger,closeButton:close,returnButton, sheet,trigger,closeButton:close,returnButton,
timerView:{{beginDetour:()=>null,finishDetour:()=>finishes++}}, timerView:{beginDetour:()=>null,finishDetour:()=>finishes++},
}}); });
controller.start(); controller.start();
controller.open(); controller.open();
const opened={{returnHidden:returnButton.hidden, expanded:trigger.attrs['aria-expanded']}}; const opened={returnHidden:returnButton.hidden, expanded:trigger.attrs['aria-expanded']};
controller.close(); controller.close();
process.stdout.write(JSON.stringify({{opened, finishes}})); process.stdout.write(JSON.stringify({opened, finishes}));
""" """
assert run_node(script) == { assert run_node(script) == {
"opened": {"returnHidden": True, "expanded": "true"}, "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(): def test_live_data_status_describe_exposes_bounded_bucket_latency():
script = f""" script = _REQUIRE + """
const status = require({json.dumps(str(STATUS))}); const measured = {fresh_for_seconds:8, latency_ms:{context:120, notifications:45}, sections:{
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}
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:{
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}
context:{{age_seconds:1}}, events:{{age_seconds:2}}, notifications:{{age_seconds:3}} }};
}}}}; const missing = {fresh_for_seconds:8, sections:{
const missing = {{fresh_for_seconds:8, sections:{{ context:{age_seconds:1}, events:{age_seconds:2}, notifications:{age_seconds:3}
context:{{age_seconds:1}}, events:{{age_seconds:2}}, notifications:{{age_seconds:3}} }};
}}}}; process.stdout.write(JSON.stringify({
process.stdout.write(JSON.stringify({{
measured:status.describe(measured), measured:status.describe(measured),
unbounded:status.describe(unbounded), unbounded:status.describe(unbounded),
missing:status.describe(missing), missing:status.describe(missing),
}})); }));
""" """
result = run_node(script) result = run_node(script)
@ -207,24 +216,21 @@ process.stdout.write(JSON.stringify({{
assert [(feed["key"], feed["latencyMs"]) for feed in result["measured"]["feeds"]] == [ assert [(feed["key"], feed["latencyMs"]) for feed in result["measured"]["feeds"]] == [
("context", 120), ("notifications", 45), ("events", None), ("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"]] == [ 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"]) assert all(feed["latencyMs"] is None for feed in result["missing"]["feeds"])
def test_live_data_status_renders_bucket_latency_panel_rows(): def test_live_data_status_renders_bucket_latency_panel_rows():
script = f""" script = _REQUIRE + _MAKE_PANEL + """
const status = require({json.dumps(str(STATUS))}); const description = status.describe({fresh_for_seconds:8, latency_ms:{context:120, notifications:45, events:3000}, sections:{
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}
context:{{age_seconds:1}}, notifications:{{age_seconds:14, stale:true}}, events:{{age_seconds:3}} }});
}}}}); const {panel, rows, heading} = makePanel();
function element() {{ const rowsReturned = status.renderBucketLatency(description, panel);
return {{innerHTML:'', hidden:false, textContent:''}}; process.stdout.write(JSON.stringify({rows:rowsReturned, panelHidden:panel.hidden, html:rows.innerHTML, headingId:heading.id}));
}}
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) 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"][0] == {"key": "context", "label": "Work", "latencyMs": 120, "stale": False}
assert result["rows"][2]["latencyMs"] == 3000 assert result["rows"][2]["latencyMs"] == 3000
assert result["panelHidden"] is False assert result["panelHidden"] is False
assert result["headingId"] == 'bucket-latency-heading'
assert 'data-bucket="context"' in result["html"] 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 "120 ms" in result["html"]
assert "3.0 s" in result["html"] assert "3.0 s" in result["html"]
# A stale feed's number is a last-known measurement and must say so. # 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(): def test_live_data_status_marks_unmeasured_buckets_honestly():
script = f""" script = _REQUIRE + _MAKE_PANEL + """
const status = require({json.dumps(str(STATUS))}); const description = status.describe({fresh_for_seconds:8, latency_ms:{context:120}, sections:{
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}
context:{{age_seconds:1}}, notifications:{{age_seconds:2}}, events:{{age_seconds:3}} }});
}}}}); const {panel, rows, heading} = makePanel();
function element() {{ const rowsReturned = status.renderBucketLatency(description, panel);
return {{innerHTML:'', hidden:false, textContent:''}}; process.stdout.write(JSON.stringify({panelHidden:panel.hidden, html:rows.innerHTML}));
}}
const panel = element();
const rows = status.renderBucketLatency(description, panel);
process.stdout.write(JSON.stringify({{rows, html:panel.innerHTML}}));
""" """
result = run_node(script) 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 'data-bucket="events"' in result["html"]
assert "not measured" in result["html"] assert "not measured" in result["html"]
assert "" not 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(): def test_live_data_status_hides_latency_panel_without_any_measurement():
script = f""" script = _REQUIRE + _MAKE_PANEL + """
const status = require({json.dumps(str(STATUS))}); const description = status.describe({fresh_for_seconds:8, sections:{
const description = status.describe({{fresh_for_seconds:8, sections:{{ context:{age_seconds:1}, notifications:{age_seconds:2}, events:{age_seconds:3}
context:{{age_seconds:1}}, notifications:{{age_seconds:2}}, events:{{age_seconds:3}} }});
}}}}); const {panel, rows, heading} = makePanel();
function element() {{ const rowsReturned = status.renderBucketLatency(description, panel);
return {{innerHTML:'', hidden:false, textContent:''}}; process.stdout.write(JSON.stringify({panelHidden:panel.hidden, html:rows.innerHTML, headingIntact:heading.id === 'bucket-latency-heading'}));
}}
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) result = run_node(script)
assert result["panelHidden"] is True assert result["panelHidden"] is True
assert result["html"] == "" 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(): 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 'id="bucket-latency-rows" role="list"' in html
assert "bucket-latency-row { display:flex" in css assert "bucket-latency-row { display:flex" in css
assert ".bucket-latency-row strong, .bucket-latency-value { overflow-wrap:anywhere" 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.describe" in dashboard
assert "liveDataStatus.createRefreshController" in dashboard assert "liveDataStatus.createRefreshController" in dashboard
assert "liveDataStatus.mount" 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 "createSheetController" in status_source
assert "backgroundElements:[qs('header'), qs('main'), qs('#mobile-task-dock')]" in status_source assert "backgroundElements:[qs('header'), qs('main'), qs('#mobile-task-dock')]" in status_source
assert "contextPoller.getState()" in dashboard 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"]

View File

@ -943,3 +943,167 @@ async def test_live_snapshot_persists_reboot_stable_wall_timestamps(monkeypatch,
assert response.status_code == 200 assert response.status_code == 200
assert set(main._live_snapshot_store.load().created_at.values()) == {epoch} 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