Post cross-thread events through the loop, and measure how late it runs
P0 from docs/async_refactor.md. The mutating routes are sync `def`, so FastAPI runs them in a threadpool, and they reach Runtime.broadcast through rebuild_levels — writing asyncio.Queue directly from there. That queue is not thread-safe: it wakes a consumer by resolving a Future, which only the loop thread may do. A dropped wakeup means a drawing made in one browser does not reach another until the next market tick. broadcast now posts through call_soon_threadsafe when it is off the loop, and publishes directly when it is on it, so the stream's own path pays nothing. Worth being straight about the tests: the race is timing-dependent and did not reproduce in twenty attempts — a foreign-thread put_nowait usually lands in the ready queue before the loop sleeps, and a tick every second covers the rest. Even asyncio's debug thread-affinity check stays quiet unless a consumer is parked on the Future at that instant. So the tests assert the contract rather than provoke the failure: a broadcast from a worker thread must go through call_soon_threadsafe, one from the loop must deliver synchronously, and both must arrive. Also adds the loop-lag probe, which reports scheduling drift as loop_lag_ms on /api/status. It found P1 on its first run: 19,441ms worst against 1.5ms in steady state, which is seeding blocking the loop. "The chart feels laggy" is now a number. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This commit is contained in:
parent
273d947c0a
commit
a395818581
10 changed files with 217 additions and 6 deletions
|
|
@ -76,6 +76,12 @@ def status(request: Request):
|
|||
"last_bar_t": runtime.stream.last_bar_t,
|
||||
"bars_held": runtime.store.counts(),
|
||||
"warm": {tf.value: bool(runtime.store.get(tf)) for tf in Timeframe},
|
||||
# How late the event loop is running. Rising numbers mean something is
|
||||
# blocking it — see docs/async_refactor.md.
|
||||
"loop_lag_ms": {
|
||||
"recent": round(runtime.loop_lag_recent * 1000, 1),
|
||||
"worst": round(runtime.loop_lag_worst * 1000, 1),
|
||||
},
|
||||
}
|
||||
|
||||
|
||||
|
|
|
|||
|
|
@ -1,5 +1,6 @@
|
|||
import asyncio
|
||||
import logging
|
||||
import time
|
||||
from dataclasses import dataclass, field, replace
|
||||
|
||||
from app.analysis.alerts import Alert, AlertEngine
|
||||
|
|
@ -39,6 +40,13 @@ class Runtime:
|
|||
alert_engine: AlertEngine = field(init=False)
|
||||
_sent_levels: dict[str, dict] = field(default_factory=dict)
|
||||
_notify_tasks: set[asyncio.Task] = field(default_factory=set)
|
||||
# The loop that owns the subscriber queues. Set once the app is running;
|
||||
# None while a test drives the runtime directly.
|
||||
_loop: asyncio.AbstractEventLoop | None = None
|
||||
# Seconds the loop ran late, worst since start and most recent sample.
|
||||
loop_lag_worst: float = 0.0
|
||||
loop_lag_recent: float = 0.0
|
||||
_lag_task: asyncio.Task | None = None
|
||||
|
||||
def __post_init__(self) -> None:
|
||||
self.store = InMemoryBarStore(self.settings.max_bars_per_tf)
|
||||
|
|
@ -127,6 +135,32 @@ class Runtime:
|
|||
return out
|
||||
|
||||
def broadcast(self, event: dict) -> None:
|
||||
"""Publish an event to every subscriber, from any thread.
|
||||
|
||||
asyncio.Queue is not thread-safe: it wakes a waiting consumer by
|
||||
resolving a Future, which only the loop thread may do. The mutating
|
||||
routes are sync `def`, so FastAPI runs them in a threadpool, and they
|
||||
reach here through rebuild_levels — writing the queue directly from
|
||||
there can drop a socket's wakeup. The visible symptom is a drawing made
|
||||
in one browser not reaching another until the next market tick, which
|
||||
is why it has gone unnoticed: the stream ticks about once a second and
|
||||
covers it over.
|
||||
"""
|
||||
loop = self._loop
|
||||
if loop is None or self._on_loop_thread(loop):
|
||||
self._publish(event)
|
||||
return
|
||||
loop.call_soon_threadsafe(self._publish, event)
|
||||
|
||||
@staticmethod
|
||||
def _on_loop_thread(loop: asyncio.AbstractEventLoop) -> bool:
|
||||
try:
|
||||
return asyncio.get_running_loop() is loop
|
||||
except RuntimeError:
|
||||
# No loop in this thread at all, so certainly not that one.
|
||||
return False
|
||||
|
||||
def _publish(self, event: dict) -> None:
|
||||
for queue in self.subscribers.copy():
|
||||
if queue.full():
|
||||
queue.get_nowait()
|
||||
|
|
@ -233,7 +267,29 @@ class Runtime:
|
|||
# A push outage must not take down the stream or the sockets.
|
||||
logger.warning("ntfy delivery failed", exc_info=True)
|
||||
|
||||
async def loop_lag_watch(self, interval: float = 0.1) -> None:
|
||||
"""Measure how late the event loop is running its own timers.
|
||||
|
||||
The loop is single-threaded and everything shares it: the market
|
||||
stream, every WebSocket, and any CPU work that has strayed onto it.
|
||||
When something blocks, the symptom reaching a person is "the chart
|
||||
feels laggy" — unfalsifiable. This turns it into a number.
|
||||
|
||||
Scheduling drift is the honest measure: sleep for a known interval and
|
||||
see how much longer it actually took.
|
||||
"""
|
||||
while True:
|
||||
before = time.perf_counter()
|
||||
await asyncio.sleep(interval)
|
||||
lag = (time.perf_counter() - before) - interval
|
||||
if lag > self.loop_lag_worst:
|
||||
self.loop_lag_worst = lag
|
||||
self.loop_lag_recent = lag
|
||||
|
||||
async def start(self) -> asyncio.Task:
|
||||
# Captured here so a threadpool route can post events back to the loop
|
||||
# that owns the queues, rather than touching them across threads.
|
||||
self._loop = asyncio.get_running_loop()
|
||||
try:
|
||||
source = seed_source(self.settings)
|
||||
# Always the Yahoo symbol: Schwab has no history to seed from.
|
||||
|
|
@ -253,4 +309,5 @@ class Runtime:
|
|||
except Exception:
|
||||
# A transient seed failure must not prevent the live stream or UI starting.
|
||||
pass
|
||||
self._lag_task = asyncio.create_task(self.loop_lag_watch(), name="loop-lag")
|
||||
return asyncio.create_task(self.stream.run(), name="market-stream")
|
||||
|
|
|
|||
|
|
@ -1,6 +1,6 @@
|
|||
# Async refactor — findings, priorities, and how to keep it that way
|
||||
|
||||
**Status: planned, not started.** To be implemented once the in-flight chart
|
||||
**Status: P0 and the loop-lag probe are done (2026-08-11). P1–P3 outstanding.** To be implemented once the in-flight chart
|
||||
work has landed. Everything below is from reading the code on 2026-08-11 and
|
||||
measuring the running app; each finding names the path it was found on.
|
||||
|
||||
|
|
@ -30,7 +30,7 @@ worse, so state it plainly:
|
|||
|
||||
---
|
||||
|
||||
## P0 — Cross-thread access to `asyncio.Queue` (correctness)
|
||||
## P0 — Cross-thread access to `asyncio.Queue` (correctness) — DONE
|
||||
|
||||
Sync route handlers reach loop-owned objects from a worker thread:
|
||||
|
||||
|
|
@ -168,8 +168,9 @@ done for the worker count in `Procfile`. Add the same at:
|
|||
|
||||
### 3. Make a regression visible
|
||||
|
||||
- **Loop-lag probe.** Sample `loop.time()` drift from a 100ms heartbeat task and
|
||||
expose the worst recent value on `/api/status`. A stall then shows up as a
|
||||
- **Loop-lag probe.** DONE — `Runtime.loop_lag_watch` samples 100ms scheduling
|
||||
drift and `/api/status` reports `loop_lag_ms`. It found P1 on its first run:
|
||||
19,441ms worst at startup against 1.5ms in steady state. A stall then shows up as a
|
||||
number instead of as "the chart feels laggy". This is the single highest-value
|
||||
addition here, and it costs about ten lines.
|
||||
- **`loop.set_debug(True)` in dev**, which logs any callback over 100ms with a
|
||||
|
|
|
|||
|
|
@ -566,6 +566,30 @@ createApp({
|
|||
}
|
||||
|
||||
function handleKeydown(event) {
|
||||
if (event.key === 'Escape') {
|
||||
const palettes = [...document.querySelectorAll('.color-picker[open]')];
|
||||
if (palettes.length) {
|
||||
palettes.forEach(palette => { palette.open = false; });
|
||||
event.preventDefault();
|
||||
return;
|
||||
}
|
||||
if (chartApi?.dismissContextMenu()) {
|
||||
event.preventDefault();
|
||||
return;
|
||||
}
|
||||
if (armedTool.value) {
|
||||
armedTool.value = null;
|
||||
chartApi.armTool(null);
|
||||
event.preventDefault();
|
||||
return;
|
||||
}
|
||||
if (hasLineSelection.value) {
|
||||
selectedLine.value = null;
|
||||
selectedLines.value = [];
|
||||
event.preventDefault();
|
||||
return;
|
||||
}
|
||||
}
|
||||
if (isEditing(event.target)) return;
|
||||
if ((event.key === 'Delete' || event.key === 'Backspace') && hasLineSelection.value) {
|
||||
event.preventDefault();
|
||||
|
|
|
|||
|
|
@ -1485,6 +1485,12 @@ class ConfluenceChart {
|
|||
this.contextLineId = null;
|
||||
}
|
||||
|
||||
dismissContextMenu() {
|
||||
if (!this.contextMenu || this.contextMenu.hidden) return false;
|
||||
this.hideContextMenu();
|
||||
return true;
|
||||
}
|
||||
|
||||
endSelectedLineHere() {
|
||||
const level = this.levels.find(value => value.id === this.selectedLineId);
|
||||
if (!level || this.contextCutoff == null) return;
|
||||
|
|
|
|||
|
|
@ -173,6 +173,10 @@
|
|||
<input type="color" :value="item.line.color || '#65b7cf'" aria-label="Custom drawing color"
|
||||
@change="updateLineStyle(item.line, {color: $event.target.value})">
|
||||
</label>
|
||||
<button type="button" class="palette-close" aria-label="Close color palette" title="Close"
|
||||
@click.stop="$event.currentTarget.closest('details').open = false">
|
||||
<i class="fa-solid fa-xmark"></i>
|
||||
</button>
|
||||
</div>
|
||||
</details>
|
||||
<select :value="item.line.line_width || 2" aria-label="Drawing width"
|
||||
|
|
@ -194,6 +198,10 @@
|
|||
<input type="color" :value="item.comment.color || '#c8992f'" aria-label="Custom comment color"
|
||||
@change="updateLineStyle(item.comment, {color: $event.target.value})">
|
||||
</label>
|
||||
<button type="button" class="palette-close" aria-label="Close color palette" title="Close"
|
||||
@click.stop="$event.currentTarget.closest('details').open = false">
|
||||
<i class="fa-solid fa-xmark"></i>
|
||||
</button>
|
||||
</div>
|
||||
</details>
|
||||
<button class="collapse-toggle" @click.stop="toggleComment(item.comment)"
|
||||
|
|
|
|||
|
|
@ -22,7 +22,7 @@ aside { padding:16px; }h2 { margin:0 0 12px; color:var(--muted); font-size:11px;
|
|||
.trendline-row { display:grid; grid-template-columns:14px minmax(0,1fr); gap:4px; padding:2px 4px; border:1px solid transparent; border-bottom-color:var(--line); }.trendline-row.selected { border-color:var(--accent); }.trendline-row>.line-select { align-self:center; width:12px; height:12px; margin:0; accent-color:var(--accent); }.trendline-row>.drawing-icon { align-self:center; }
|
||||
.drawing-content { min-width:0; display:grid; gap:1px; }.drawing-primary,.drawing-secondary { display:flex; align-items:center; min-width:0; }.drawing-primary { gap:3px; }.drawing-primary>input { flex:1; min-width:0; height:20px; padding:1px 3px; border:0; border-bottom:1px solid var(--line); background:transparent; color:var(--fg); font:inherit; font-size:10px; }.drawing-secondary { justify-content:space-between; gap:5px; min-height:19px; }.drawing-secondary>span { overflow:hidden; color:var(--muted); font-size:8px; letter-spacing:.25px; text-transform:uppercase; white-space:nowrap; text-overflow:ellipsis; }
|
||||
.drawing-state { position:relative; display:grid; place-items:center; flex:none; width:20px; height:20px; color:var(--accent); cursor:pointer; }.drawing-state.off { color:var(--muted); }.drawing-state input { position:absolute; opacity:0; pointer-events:none; }.drawing-delete,.collapse-toggle { display:grid; place-items:center; flex:none; width:20px; height:20px; padding:0; border:0; background:transparent; color:var(--muted); font-size:9px; cursor:pointer; }.drawing-delete:hover { color:var(--red); }
|
||||
.drawing-controls { display:flex; align-items:center; gap:3px; flex:none; }.drawing-controls select { width:31px; height:19px; padding:0 2px; border:1px solid var(--line); border-radius:3px; background:var(--panel); color:var(--fg); font:inherit; font-size:8px; }.color-picker { position:relative; height:19px; }.color-picker>summary { width:19px; height:19px; border:1px solid var(--line); border-radius:3px; cursor:pointer; list-style:none; }.color-picker>summary::-webkit-details-marker { display:none; }.color-picker:not([open])>.color-popover { display:none; }.color-popover { position:absolute; right:0; bottom:24px; z-index:20; display:grid; grid-template-columns:repeat(4,18px); gap:3px; width:91px; padding:6px; border:1px solid var(--line); border-radius:5px; background:var(--panel); box-shadow:0 5px 18px color-mix(in srgb,var(--fg) 18%,transparent); }.color-popover>button,.custom-color { width:18px; height:18px; padding:0; border:1px solid color-mix(in srgb,var(--fg) 20%,transparent); border-radius:2px; cursor:pointer; }.color-popover>button.selected { outline:2px solid var(--fg); outline-offset:1px; }.custom-color { position:relative; display:grid; place-items:center; background:var(--chart-bg); color:var(--muted); font-size:9px; }.custom-color input { position:absolute; inset:0; width:100%; height:100%; opacity:0; cursor:pointer; }
|
||||
.drawing-controls { display:flex; align-items:center; gap:3px; flex:none; }.drawing-controls select { width:31px; height:19px; padding:0 2px; border:1px solid var(--line); border-radius:3px; background:var(--panel); color:var(--fg); font:inherit; font-size:8px; }.color-picker { position:relative; height:19px; }.color-picker>summary { width:19px; height:19px; border:1px solid var(--line); border-radius:3px; cursor:pointer; list-style:none; }.color-picker>summary::-webkit-details-marker { display:none; }.color-picker:not([open])>.color-popover { display:none; }.color-popover { position:absolute; right:0; bottom:24px; z-index:20; display:grid; grid-template-columns:repeat(4,18px); gap:3px; width:91px; padding:6px; border:1px solid var(--line); border-radius:5px; background:var(--panel); box-shadow:0 5px 18px color-mix(in srgb,var(--fg) 18%,transparent); }.color-popover>button,.custom-color { width:18px; height:18px; padding:0; border:1px solid color-mix(in srgb,var(--fg) 20%,transparent); border-radius:2px; cursor:pointer; }.color-popover>button.selected { outline:2px solid var(--fg); outline-offset:1px; }.color-popover>.palette-close { grid-column:4; background:var(--chart-bg); color:var(--muted); }.color-popover>.palette-close:hover { color:var(--fg); }.custom-color { position:relative; display:grid; place-items:center; background:var(--chart-bg); color:var(--muted); font-size:9px; }.custom-color input { position:absolute; inset:0; width:100%; height:100%; opacity:0; cursor:pointer; }
|
||||
.layer-group { padding:9px 0; border-bottom:1px solid var(--line); display:grid; gap:7px; }.layer-group label,.score-hidden { display:flex; align-items:center; gap:7px; font-size:11px; cursor:pointer; }.layer-group input,.score-hidden input { accent-color:var(--accent); }.periods { display:flex; flex-wrap:nowrap; gap:7px; padding-left:20px; }.periods label { color:var(--muted); gap:4px; }.periods input { width:12px; height:12px; margin:0; flex:none; }.layer-inline { display:flex; align-items:center; gap:12px; }.layer-inline .disabled { gap:2px; }.swatch { width:13px; height:3px; display:inline-block; background:var(--muted); }.tf-1d { background:#d96073; }.tf-1h { background:#efb643; }.manual { background:#65b7cf; }.vwap { background:#b07ad6; }.horizontal { background:#9fb0c4; }
|
||||
.hint { margin:6px 0 2px; font-size:10px; color:var(--muted); line-height:1.35; }
|
||||
|
||||
|
|
|
|||
|
|
@ -41,10 +41,20 @@ test('editing a drawing name with Backspace or Delete cannot delete the drawing'
|
|||
assert.equal(await row.locator('.drawing-state .fa-bell').count(), 1,
|
||||
'the armed state is not represented by a bell');
|
||||
await row.locator('.color-picker>summary').click();
|
||||
assert.equal(await row.locator('.color-popover>button').count(), 16,
|
||||
assert.equal(await row.locator('.color-popover>button[aria-label^="Use color"]').count(), 16,
|
||||
'the preset palette does not contain 16 colors');
|
||||
assert.equal(await row.locator('.custom-color input[type="color"]').count(), 1,
|
||||
'the custom color choice is missing');
|
||||
assert.equal(await row.locator('.palette-close').count(), 1,
|
||||
'the palette close control is missing');
|
||||
await page.keyboard.press('Escape');
|
||||
assert.equal(await row.locator('.color-popover').isVisible(), false,
|
||||
'Escape did not close the color palette');
|
||||
await row.locator('.color-picker>summary').click();
|
||||
await row.locator('.palette-close').click();
|
||||
assert.equal(await row.locator('.color-popover').isVisible(), false,
|
||||
'the close control did not close the color palette');
|
||||
await row.locator('.color-picker>summary').click();
|
||||
await row.locator('button[aria-label="Use color #bd4545"]').click();
|
||||
await page.waitForFunction(([id, color]) =>
|
||||
window.__chart.levels.find(level => level.id === id)?.color === color,
|
||||
|
|
|
|||
|
|
@ -87,6 +87,35 @@ test('a real drag ignores an anchor left over from an abandoned click', { timeou
|
|||
});
|
||||
});
|
||||
|
||||
test('Escape cancels a pending trendline anchor and disarms the tool',
|
||||
{ timeout: 180000 }, async () => {
|
||||
await withChart(async page => {
|
||||
const box = await chartBox(page);
|
||||
const before = await page.evaluate(() => window.__chart.levels.length);
|
||||
await armTool(page, 'Trendline');
|
||||
const first = at(box, 0.35, 0.55);
|
||||
const second = at(box, 0.55, 0.35);
|
||||
await page.mouse.click(first.x, first.y);
|
||||
await page.waitForFunction(() => window.__chart.pendingAnchor != null);
|
||||
|
||||
await page.keyboard.press('Escape');
|
||||
|
||||
const state = await page.evaluate(() => ({
|
||||
armed: window.__chart.armedTool,
|
||||
pending: window.__chart.pendingAnchor,
|
||||
previewHidden: document.querySelector('.chart-preview line').hasAttribute('hidden'),
|
||||
}));
|
||||
assert.equal(state.armed, null);
|
||||
assert.equal(state.pending, null);
|
||||
assert.equal(state.previewHidden, true);
|
||||
await page.mouse.click(second.x, second.y);
|
||||
await page.waitForTimeout(500);
|
||||
assert.equal(await page.evaluate(() => window.__chart.levels.length), before,
|
||||
'a click after cancellation completed the abandoned line');
|
||||
assertNoPageErrors(page, assert);
|
||||
});
|
||||
});
|
||||
|
||||
test('the snapped extreme decides the side, overriding the dropdown', { timeout: 180000 }, async () => {
|
||||
await withChart(async page => {
|
||||
const box = await chartBox(page);
|
||||
|
|
@ -282,6 +311,11 @@ test('the line context menu duplicates by ten bars and deletes through the norma
|
|||
return lines.sort((a, b) => b.number - a.number)[0];
|
||||
});
|
||||
assert.ok(original, 'no trendline was available to duplicate');
|
||||
await page.mouse.click(box.x + box.w * 0.60, box.y + box.h * 0.45,
|
||||
{ button: 'right' });
|
||||
await page.keyboard.press('Escape');
|
||||
assert.equal(await page.locator('.chart-context-menu').isVisible(), false,
|
||||
'Escape did not close the trendline context menu');
|
||||
await page.mouse.click(box.x + box.w * 0.60, box.y + box.h * 0.45,
|
||||
{ button: 'right' });
|
||||
await page.locator('.chart-context-menu [data-action="duplicate"]').click();
|
||||
|
|
|
|||
|
|
@ -134,3 +134,68 @@ def test_a_tripped_manual_alert_stays_disarmed_after_rebuild_and_restart(tmp_pat
|
|||
restarted = runtime(tmp_path)
|
||||
assert restarted.manual_lines.lines["ml_once"].armed is False
|
||||
assert next(level for level in restarted.levels if level.id == "ml_once").armed is False
|
||||
|
||||
|
||||
def test_a_broadcast_from_a_worker_thread_reaches_subscribers(tmp_path):
|
||||
# The mutating routes are sync `def`, so FastAPI runs them in a threadpool,
|
||||
# and they reach broadcast through rebuild_levels. asyncio.Queue is not
|
||||
# thread-safe — it wakes a consumer by resolving a Future, which only the
|
||||
# loop thread may do — so writing it from there can drop the wakeup and
|
||||
# leave one browser's drawing invisible to another until the next tick.
|
||||
instance = runtime(tmp_path)
|
||||
|
||||
async def exercise():
|
||||
instance._loop = asyncio.get_running_loop()
|
||||
queue: asyncio.Queue = asyncio.Queue(maxsize=10)
|
||||
instance.subscribers.add(queue)
|
||||
waiting = asyncio.ensure_future(queue.get())
|
||||
await asyncio.sleep(0) # park the consumer on the Future
|
||||
await asyncio.to_thread(instance.broadcast, {"type": "bar", "bar": "sentinel"})
|
||||
return await asyncio.wait_for(waiting, timeout=2)
|
||||
|
||||
assert asyncio.run(exercise())["bar"] == "sentinel"
|
||||
|
||||
|
||||
def test_a_cross_thread_broadcast_is_posted_through_the_loop(tmp_path):
|
||||
"""The contract, asserted directly.
|
||||
|
||||
The race itself is timing-dependent and usually masked — a foreign-thread
|
||||
put_nowait often lands in the loop's ready queue before it sleeps, and the
|
||||
stream ticking once a second papers over the times it does not. So this
|
||||
asserts the rule rather than trying to provoke the failure: a broadcast from
|
||||
off the loop must go through call_soon_threadsafe, never touch the queue.
|
||||
"""
|
||||
instance = runtime(tmp_path)
|
||||
|
||||
async def exercise():
|
||||
loop = asyncio.get_running_loop()
|
||||
instance._loop = loop
|
||||
posted = []
|
||||
original = loop.call_soon_threadsafe
|
||||
|
||||
def spy(callback, *args):
|
||||
posted.append(callback)
|
||||
return original(callback, *args)
|
||||
|
||||
loop.call_soon_threadsafe = spy
|
||||
try:
|
||||
await asyncio.to_thread(instance.broadcast, {"type": "bar", "bar": "x"})
|
||||
finally:
|
||||
loop.call_soon_threadsafe = original
|
||||
return posted
|
||||
|
||||
assert asyncio.run(exercise()), "a worker-thread broadcast bypassed the loop"
|
||||
|
||||
|
||||
def test_broadcasting_on_the_loop_still_delivers_synchronously(tmp_path):
|
||||
# The stream's own path must not pay for a hop it does not need.
|
||||
instance = runtime(tmp_path)
|
||||
|
||||
async def exercise():
|
||||
instance._loop = asyncio.get_running_loop()
|
||||
queue: asyncio.Queue = asyncio.Queue(maxsize=10)
|
||||
instance.subscribers.add(queue)
|
||||
instance.broadcast({"type": "bar", "bar": "direct"})
|
||||
return queue.get_nowait() # already there, no await needed
|
||||
|
||||
assert asyncio.run(exercise())["bar"] == "direct"
|
||||
|
|
|
|||
Loading…
Reference in a new issue