Make a stalled draw wait observable (B-36)

_wait_for_next_block had no timeout, no log, and no audit entry: a
connection that stopped advancing the tip left a round silently frozen
in "drawing" with nothing in /admin to explain why. Log progress
periodically, write a draw_stalled audit entry past a threshold (a few
block-time multiples), and surface the wait via a new Round.drawing_started_at
column, exposed as draw_waiting_since in GET /rounds/current.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
This commit is contained in:
2026-07-27 14:12:27 +02:00
co-authored by Claude Sonnet 5
parent bb8b71278a
commit 7fa26df104
8 changed files with 189 additions and 26 deletions
+9 -19
View File
@@ -1,16 +1,17 @@
# Known bugs
A second full-codebase audit on 2026-07-27 found **25 further issues** (4 critical, 6 high,
7 medium, 8 low), listed below as B-33 … B-49. B-25 through B-35 are fixed (see "Previously
fixed" below) — no Critical-severity finding remains open; the other 14 are High/Medium/Low.
7 medium, 8 low), listed below as B-33 … B-49. B-25 through B-36 are fixed (see "Previously
fixed" below) — no Critical-severity finding remains open; the other 13 are High/Medium/Low.
The 139-test suite was green at the time of the audit, so none of these were caught by existing
coverage — every fix lands with a regression test (the eleven fixes so far brought the suite
from 139 to 198).
coverage — every fix lands with a regression test (the twelve fixes so far brought the suite
from 139 to 200).
The recurring pattern across the open findings is worth stating once: the code is rigorous
about the failure modes that have actually been hit, and silent about the ones that have not.
The payout phase is now fully recoverable; the "drawing" phase (waiting on a block) still has
no equivalent resume-after-restart or stall visibility (B-36).
The payout phase is now fully recoverable; the "drawing" phase (waiting on a block) is now
observable (B-36) but still has no equivalent resume-after-restart — see "Known gaps / TODO"
in [CLAUDE.md](CLAUDE.md).
For limitations that are accepted by design rather than bugs (single-shared-token admin auth,
single-process assumptions, no user-facing history, etc.), see "Known gaps / TODO" in
@@ -20,18 +21,6 @@ single-process assumptions, no user-facing history, etc.), see "Known gaps / TOD
## Medium
### B-36 — `_wait_for_next_block` waits forever, with no timeout and no visibility
`rounds/scheduler.py:158-161` loops until a higher block arrives. No timeout, no log, no audit
entry. If the connection dies in a way that stops the tip advancing, the round sits in
`drawing` indefinitely and **the admin panel shows nothing at all** — just a frozen state with
no explanation.
**Proposed fix.** Log progress periodically while waiting, and past a threshold (a few
multiples of the 120s block time) write a `draw_stalled` audit entry so it surfaces in
`/admin`. Surface the wait in `GET /rounds/current` too (it already returns
`chain_tip_height`; `draw_waiting_since` would make the stall self-evident to users).
### B-37 — Displayed balance and spendable balance diverge, and the error does not explain it
After a bet the change is unconfirmed, so `cached_balance_sats` ≈ 0 while the UI shows
@@ -184,9 +173,10 @@ already does.
- **B-33** — `POST /auth/login` had no rate limiting, so a password could be brute-forced against an enumerable username list
- **B-34** — password change/reset didn't invalidate already-issued JWTs, so a stolen token survived a change meant to lock it out
- **B-35** — API timestamps round-tripped as naive datetimes, so the frontend parsed them as local time instead of UTC
- **B-36** — a stalled draw wait had no timeout, no log, and no audit trail, so a frozen round showed nothing in `/admin`
See git history for the fix-by-fix breakdown (commits `f13f685`, `50a43ae`, `933760e`, and the
B-28/B-29/B-30/B-31/B-32/B-33/B-34/B-35 fixes). Suite grew from 139 to 198 tests over the eleven.
B-28/B-29/B-30/B-31/B-32/B-33/B-34/B-35/B-36 fixes). Suite grew from 139 to 200 tests over the twelve.
A full-codebase audit on 2026-07-26 (commit `d4e0974`) found 24 bugs across every Python
module under `app/`, both static frontends, and the Docker/Caddy deployment — 5 critical,
+2 -2
View File
@@ -12,7 +12,7 @@ All 10 stages of the original build order are code-complete and unit-tested —
Verified on mainnet with real money: registration + address derivation, deposit crediting (1-conf), a real 10 PLM bet (broadcast → confirmed → change credited back), and one full round cycle (close → draw on a real block hash → 70/30 payout with sat math checked against the broadcast tx → confirmation → close → next round auto-opened). **Withdrawal and the RBF bump path have never been exercised against a live broadcast** — unit-tested only.
**Read [BUGS.md](BUGS.md) before trusting any behaviour here.** Two audits: 2026-07-26 found 24 bugs (5 critical), all fixed; 2026-07-27 found 25 more (B-25 … B-49), of which **14 are still open** — no Critical or High remains, only Medium/Low: `_wait_for_next_block` has no timeout or visibility if a round gets stuck in `drawing` (B-36), no WAL/`busy_timeout` under five concurrent SQLite writer tasks (B-39), among others. BUGS.md is the live open list with a proposed fix per finding; "Known gaps" at the end of this file is for limitations accepted **by design** instead. Don't fix a BUGS.md item silently as a side effect of other work — each fix lands with its own regression test.
**Read [BUGS.md](BUGS.md) before trusting any behaviour here.** Two audits: 2026-07-26 found 24 bugs (5 critical), all fixed; 2026-07-27 found 25 more (B-25 … B-49), of which **13 are still open** — no Critical or High remains, only Medium/Low: no WAL/`busy_timeout` under five concurrent SQLite writer tasks (B-39), a 500-subscriber SSE cap that doubles as a cheap DoS of the realtime feature (B-38), among others. BUGS.md is the live open list with a proposed fix per finding; "Known gaps" at the end of this file is for limitations accepted **by design** instead. Don't fix a BUGS.md item silently as a side effect of other work — each fix lands with its own regression test.
Before writing code, read the "Architecture" section below in full plus the diagrams in [flowchart/](flowchart/): [platform-overview.mmd](flowchart/platform-overview.mmd) (the 5-phase flow) and [round-lifecycle.mmd](flowchart/round-lifecycle.mmd) (the round/draw lifecycle). Every node **and edge label** (conditions, retries, loops) is a behaviour that must be implemented as described. Regenerate the companion PDFs with `flowchart/render-pdf.sh <file>.mmd` after editing either.
@@ -235,7 +235,7 @@ Explicit design choices, not derivable from any single file — respect them:
Accepted **by design**. For actual bugs see [BUGS.md](BUGS.md) (18 open) — not duplicated here.
- **`drawing` doesn't resume after a restart.** `_tick()` handles `open`, `closing` and `paying_out` (the last via `_retry_payout_if_due`); nothing re-enters `_wait_for_next_block`. That wait is also unbounded and invisible in `/admin` (B-36) — the last prerequisite for running unattended.
- **`drawing` doesn't resume after a restart.** `_tick()` handles `open`, `closing` and `paying_out` (the last via `_retry_payout_if_due`); nothing re-enters `_wait_for_next_block` after a crash. That wait is unbounded by design (the draw's entropy genuinely depends on a future block) but no longer silent — past `_DRAW_STALL_THRESHOLD_SECONDS` it logs progress and writes a `draw_stalled` audit entry, and `GET /rounds/current`'s `draw_waiting_since` surfaces it live (B-36). Restart-resumption itself remains the last prerequisite for running unattended.
- **RBF handles one shape only**: a single change output, back to the tx's own sender, big enough to absorb the increase. No extra-input fallback — an exact-amount tx or too-small change raises `RbfError`. Not permanent, though: an unbumpable tx that never confirms is eventually abandoned and its UTXOs released.
- **Withdrawal and RBF bump are unit-tested but never live-broadcast** (failure and rollback branches included — still not a real network).
- **No user-facing history.** `GET /users/me/last-round-result` covers exactly one case (the reveal backstop above). Admin has `/admin/rounds`, `/admin/pending-transactions`, `/admin/audit-log`; a user has no equivalent — a failed withdrawal leaves a `failed` row they can never see, which argues for closing this.
+6
View File
@@ -8,6 +8,7 @@ from pydantic import BaseModel
from sqlalchemy import func, select
from sqlalchemy.ext.asyncio import AsyncSession
from app.api.timeutil import isoformat_utc
from app.auth.dependencies import get_optional_user
from app.db.models import RoundParticipant, User
from app.db.session import get_session
@@ -90,6 +91,10 @@ class CurrentRoundResponse(BaseModel):
winner_amount_sats: int | None = None
draw_block_height: int | None = None
draw_block_hash: str | None = None
# B-36: set only while status == "drawing", so the frontend can show "still
# waiting for a block" rather than a countdown implying a bounded wait — this
# phase has no timeout, only draw_animation_seconds' cosmetic minimum.
draw_waiting_since: str | None = None
chain_tip_height: int | None = None
lottery_paused: bool = False
user_played: bool = False
@@ -168,6 +173,7 @@ async def current_round(
winner_amount_sats=round_.winner_amount_sats,
draw_block_height=round_.draw_block_height,
draw_block_hash=round_.draw_block_hash,
draw_waiting_since=isoformat_utc(round_.drawing_started_at) if round_.status == "drawing" else None,
chain_tip_height=chain_tip_height,
lottery_paused=config.paused,
user_played=user_played,
+5
View File
@@ -72,6 +72,11 @@ class Round(Base):
status: Mapped[str] = mapped_column(String(16), default="open")
opened_at: Mapped[datetime] = mapped_column(default=utcnow)
closed_at: Mapped[datetime | None] = mapped_column(default=None)
# Set once, when status flips to "drawing" (rounds/scheduler.py:_close_and_draw).
# Lets both the audit log (B-36's draw_stalled entries) and GET /rounds/current
# (draw_waiting_since) measure how long a round has been waiting on a block,
# since that wait has no timeout of its own — see _wait_for_next_block.
drawing_started_at: Mapped[datetime | None] = mapped_column(default=None)
draw_block_height: Mapped[int | None] = mapped_column(default=None)
draw_block_hash: Mapped[str | None] = mapped_column(String(64), default=None)
seed_int: Mapped[str | None] = mapped_column(String(128), default=None)
+49 -3
View File
@@ -30,6 +30,13 @@ _TICK_INTERVAL_SECONDS = 5
# (a dropped Electrum connection, a momentarily-empty pool) self-heals quickly.
_PAYOUT_RETRY_INTERVAL_SECONDS = 60
# B-36: _wait_for_next_block has no timeout of its own — a round can legitimately
# wait several PLM blocks (120s each) for its draw entropy, and re-waits on a
# corroboration failure. These only make an already-long wait *observable*, they
# never cut it short.
_DRAW_PROGRESS_LOG_INTERVAL_SECONDS = 60
_DRAW_STALL_THRESHOLD_SECONDS = 360 # a few multiples of PLM's 120s block time
class RoundScheduler:
"""Background task implementing flowchart.mmd's DRAW subgraph: closes the
@@ -138,11 +145,13 @@ class RoundScheduler:
user_by_address[user.address] = user.id
round_.status = "drawing"
drawing_started_at = datetime.now(timezone.utc)
round_.drawing_started_at = drawing_started_at
await session.commit()
broadcaster.publish()
tip_at_close = self._listener.tip_height
block_height, block_hash = await self._wait_for_next_block(round_id, tip_at_close)
block_height, block_hash = await self._wait_for_next_block(round_id, tip_at_close, drawing_started_at)
winner_address = draw_winner(addresses, block_hash)
async with self._session_factory() as session:
@@ -172,7 +181,9 @@ class RoundScheduler:
logger.info("round %s: winner=%s pool=%s", round_id, winner_address, pool_amount)
await self._trigger_payout(round_id)
async def _wait_for_next_block(self, round_id: int, tip_at_close: int) -> tuple[int, str]:
async def _wait_for_next_block(
self, round_id: int, tip_at_close: int, waiting_since: datetime
) -> tuple[int, str]:
"""Waits for a block after tip_at_close and, before handing it back as the
draw's entropy source, requires it to be corroborated by the other
configured Electrum servers (B-28) our own active connection is exactly
@@ -180,9 +191,44 @@ class RoundScheduler:
not enough to seed a payout. A candidate that fails corroboration is never
used: this keeps waiting for a further block and tries corroborating that
one instead, logging why every time so a stuck draw is visible in
/admin's audit log rather than a silent, unexplained wait."""
/admin's audit log rather than a silent, unexplained wait.
This wait has no timeout it can't, since the draw's entropy genuinely
depends on a future block. B-36: what it lacked was *visibility*, so a
connection that stopped advancing the tip left the round silently frozen
in "drawing" with nothing in the logs or /admin to explain why. Progress
is now logged periodically, and past _DRAW_STALL_THRESHOLD_SECONDS a
draw_stalled audit entry is written (and re-written every threshold
interval for as long as the stall continues) so the wait shows up next
to the draw_header_corroboration_failed entries above.
"""
next_progress_log_at = waiting_since + timedelta(seconds=_DRAW_PROGRESS_LOG_INTERVAL_SECONDS)
next_stall_audit_at = waiting_since + timedelta(seconds=_DRAW_STALL_THRESHOLD_SECONDS)
while True:
while self._listener.tip_height <= tip_at_close or not self._listener.tip_header_hex:
now = datetime.now(timezone.utc)
if now >= next_progress_log_at:
logger.info(
"round %s: still waiting for a block past height %s (%.0fs since drawing started)",
round_id,
tip_at_close,
(now - waiting_since).total_seconds(),
)
next_progress_log_at = now + timedelta(seconds=_DRAW_PROGRESS_LOG_INTERVAL_SECONDS)
if now >= next_stall_audit_at:
async with self._session_factory() as session:
await write_audit_log(
session,
"draw_stalled",
{
"tip_at_close": tip_at_close,
"current_tip_height": self._listener.tip_height,
"elapsed_seconds": int((now - waiting_since).total_seconds()),
},
round_id=round_id,
)
await session.commit()
next_stall_audit_at = now + timedelta(seconds=_DRAW_STALL_THRESHOLD_SECONDS)
await asyncio.sleep(_TICK_INTERVAL_SECONDS)
height = self._listener.tip_height
block_hash = header_hex_to_block_hash(self._listener.tip_header_hex)
@@ -0,0 +1,32 @@
"""add drawing_started_at to rounds
Revision ID: 9ef6a51509f7
Revises: 943dbd74d983
Create Date: 2026-07-27 12:31:09.907682
"""
from typing import Sequence, Union
from alembic import op
import sqlalchemy as sa
# revision identifiers, used by Alembic.
revision: str = '9ef6a51509f7'
down_revision: Union[str, Sequence[str], None] = '943dbd74d983'
branch_labels: Union[str, Sequence[str], None] = None
depends_on: Union[str, Sequence[str], None] = None
def upgrade() -> None:
"""Upgrade schema."""
# ### commands auto generated by Alembic - please adjust! ###
op.add_column('rounds', sa.Column('drawing_started_at', sa.DateTime(), nullable=True))
# ### end Alembic commands ###
def downgrade() -> None:
"""Downgrade schema."""
# ### commands auto generated by Alembic - please adjust! ###
op.drop_column('rounds', 'drawing_started_at')
# ### end Alembic commands ###
+30
View File
@@ -134,6 +134,36 @@ async def test_jackpot_comes_from_the_participants_actual_bets(client):
assert body["jackpot_sats"] == (999_800_000 * 2) * 70 // 100
async def test_draw_waiting_since_is_exposed_only_while_drawing(client):
"""B-36: the "drawing" wait on a future block has no timeout, so the frontend
needs draw_waiting_since to show "still waiting" instead of implying a bounded
countdown. It must not leak for any other status, where it's meaningless."""
from datetime import datetime, timezone
from app.db.models import Round, RoundConfig
ac, session_factory = client
started_at = datetime(2026, 7, 27, 10, 0, 0)
async with session_factory() as session:
session.add(RoundConfig(fee_address=""))
session.add(Round(id=60, status="drawing", drawing_started_at=started_at))
await session.commit()
body = (await ac.get("/rounds/current")).json()
assert body["draw_waiting_since"] == "2026-07-27T10:00:00+00:00"
async with session_factory() as session:
from sqlalchemy import select
round_ = (await session.scalars(select(Round).where(Round.id == 60))).one()
round_.status = "paying_out"
await session.commit()
body = (await ac.get("/rounds/current")).json()
assert body["draw_waiting_since"] is None
async def test_unhandled_errors_use_the_structured_detail_shape(client):
"""B-24: the catch-all handler answered with a bare-string `detail`, while
app/api/errors.py documents detail as {"code", "message", "params"}. Clients then
+56 -2
View File
@@ -381,7 +381,9 @@ async def test_wait_for_next_block_accepts_an_immediately_corroborated_block(ses
listener = CorroboratingListener(responses={101: True})
scheduler = RoundScheduler(session_factory, listener)
height, block_hash = await scheduler._wait_for_next_block(round_id=1, tip_at_close=100)
height, block_hash = await scheduler._wait_for_next_block(
round_id=1, tip_at_close=100, waiting_since=datetime.now(timezone.utc)
)
assert height == 101
assert listener.corroboration_calls == [101]
@@ -395,7 +397,9 @@ async def test_wait_for_next_block_retries_after_a_failed_corroboration(session_
)
scheduler = RoundScheduler(session_factory, listener)
height, block_hash = await scheduler._wait_for_next_block(round_id=1, tip_at_close=100)
height, block_hash = await scheduler._wait_for_next_block(
round_id=1, tip_at_close=100, waiting_since=datetime.now(timezone.utc)
)
assert height == 102
assert listener.corroboration_calls == [101, 102]
@@ -403,3 +407,53 @@ async def test_wait_for_next_block_retries_after_a_failed_corroboration(session_
async with session_factory() as session:
events = [e.event_type for e in (await session.scalars(select(AuditLog))).all()]
assert events == ["draw_header_corroboration_failed"]
# --- B-36: a stalled draw must be visible, not a silent frozen wait --------------
class StallingListener:
"""A tip that never advances until the test decides it should — used to drive
_wait_for_next_block's stall-detection past _DRAW_STALL_THRESHOLD_SECONDS
without a real 6-minute wait."""
def __init__(self):
self.tip_height = 100
self.tip_header_hex = None
async def corroborate_header(self, height: int, expected_hash: str) -> bool:
return True
async def test_wait_for_next_block_logs_a_stall_audit_entry_past_the_threshold(session_factory, monkeypatch):
import app.rounds.scheduler as scheduler_module
listener = StallingListener()
scheduler = RoundScheduler(session_factory, listener)
start = datetime.now(timezone.utc)
class _FakeClock:
now = start
def fake_now(tz=None):
return _FakeClock.now
async def fake_sleep(seconds: float) -> None:
_FakeClock.now += timedelta(seconds=seconds)
# Past the stall threshold, but before it would repeat: unblock the wait
# by making a (corroborated) block appear, so the test terminates.
if _FakeClock.now >= start + timedelta(seconds=scheduler_module._DRAW_STALL_THRESHOLD_SECONDS + 30):
listener.tip_height = 101
listener.tip_header_hex = "aa"
monkeypatch.setattr(scheduler_module, "datetime", type("_D", (), {"now": staticmethod(fake_now)}))
monkeypatch.setattr(scheduler_module.asyncio, "sleep", fake_sleep)
height, block_hash = await scheduler._wait_for_next_block(round_id=1, tip_at_close=100, waiting_since=start)
assert height == 101
async with session_factory() as session:
entries = (await session.scalars(select(AuditLog).where(AuditLog.event_type == "draw_stalled"))).all()
assert len(entries) == 1
assert entries[0].round_id == 1