From efba1e7eed0c33da00afc18b7f42656be375c577 Mon Sep 17 00:00:00 2001 From: Anatolie Date: Tue, 11 Aug 2026 12:31:01 -0400 Subject: [PATCH 01/10] fix(prism): submit found blocks before accounting --- .env.example | 6 + compose.yaml | 3 + docs/prism-ledger-ops.md | 31 +- lab/prism/prism_coordinator.py | 1029 +++++++++++++++++++---- lab/prism/share_ledger.py | 288 ++++++- tests/test_prism_coordinator_vardiff.py | 337 +++++++- tests/test_prism_share_ledger.py | 100 +++ 7 files changed, 1564 insertions(+), 230 deletions(-) diff --git a/.env.example b/.env.example index 580f0aa1..cb616b5f 100644 --- a/.env.example +++ b/.env.example @@ -174,6 +174,12 @@ PRISM_MAX_BLOCKS=2147483647 PRISM_BLOCKPOLL_SECONDS=2 PRISM_BLOCKWAIT_ENABLED=1 PRISM_BLOCKWAIT_TIMEOUT_SECONDS=5 +# Found-block fast lane: submitblock runs before writer admission/accounting. +PRISM_BLOCK_SUBMIT_RPC_TIMEOUT_SECONDS=1 +# Fresh deadline for each submitter Postgres statement and local DB gate. +PRISM_BLOCK_SUBMIT_DB_TIMEOUT_SECONDS=1 +# Emit the contended lock and current submitter phase at this cadence. +PRISM_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS=5 PRISM_REORG_RECONCILER_ENABLED=1 PRISM_VERSION_ROLLING_MASK=1fffe000 PRISM_COINBASE_TAG=/PRISM/ diff --git a/compose.yaml b/compose.yaml index 37ee95d8..2120589c 100644 --- a/compose.yaml +++ b/compose.yaml @@ -509,6 +509,9 @@ services: PRISM_BLOCKPOLL_SECONDS: ${PRISM_BLOCKPOLL_SECONDS:-2} PRISM_BLOCKWAIT_ENABLED: ${PRISM_BLOCKWAIT_ENABLED:-1} PRISM_BLOCKWAIT_TIMEOUT_SECONDS: ${PRISM_BLOCKWAIT_TIMEOUT_SECONDS:-5} + PRISM_BLOCK_SUBMIT_RPC_TIMEOUT_SECONDS: ${PRISM_BLOCK_SUBMIT_RPC_TIMEOUT_SECONDS:-1} + PRISM_BLOCK_SUBMIT_DB_TIMEOUT_SECONDS: ${PRISM_BLOCK_SUBMIT_DB_TIMEOUT_SECONDS:-1} + PRISM_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS: ${PRISM_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS:-5} PRISM_OBSERVED_TIP_ACCEPT_WINDOW_SECONDS: ${PRISM_OBSERVED_TIP_ACCEPT_WINDOW_SECONDS:-300} PRISM_TIP_REFRESH_FAILURE_HOLDOFF_SECONDS: ${PRISM_TIP_REFRESH_FAILURE_HOLDOFF_SECONDS:-1} PRISM_TIP_REFRESH_EPOCH_FANOUT: ${PRISM_TIP_REFRESH_EPOCH_FANOUT:-0} diff --git a/docs/prism-ledger-ops.md b/docs/prism-ledger-ops.md index 3454794f..971262d5 100644 --- a/docs/prism-ledger-ops.md +++ b/docs/prism-ledger-ops.md @@ -97,16 +97,43 @@ success. The in-memory candidate queue is only a bounded wakeup path. Queue saturation coalesces wakeups; it cannot delete an outbox row. Before opening Stratum listeners and whenever the queue drains, the coordinator replays pending rows. +Once a durable candidate is dequeued, its qbit `submitblock` RPC is the fast +lane: it runs before the attempt-marker write, accepted-block writer admission, +audit construction, or payout publication. An in-memory wakeup is also drained +before querying the recovery outbox. This priority isolation means a newly +found block cannot queue behind a payout-artifact writer already waiting for +admission; accounting remains serialized only after the node has seen the +candidate. + +`PRISM_BLOCK_SUBMIT_RPC_TIMEOUT_SECONDS` bounds the fast-lane RPC (default 1 +second). `PRISM_BLOCK_SUBMIT_DB_TIMEOUT_SECONDS` gives each later Postgres +statement and local ledger gate a fresh deadline (default 1 second); direct +outbox reads and mutations additionally use a single-flight wrapper so a +driver that ignores its deadline cannot accumulate retry threads. Timeouts +leave the row pending and enter the ordinary candidate backoff. Contended +submit-path locks are acquired in heartbeat slices and identify the lock in a +periodic diagnostic controlled by `PRISM_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS` +(default 5 seconds). + Successful submissions become `submitted`; candidates that definitively lose their tip race or fail validation become `abandoned`. If the process exits -after `submitblock` but before finalizing the row, restart recognizes the -candidate as the active tip and completes the idempotent confirmation path. +after `submitblock` but before the attempt marker or terminal outbox update, +restart resubmits the same bytes. qbit's accepted-duplicate response is a +successful landing signal; block-hash-keyed ledger persistence and the +finalize-only registry keep accounting and terminal side effects exactly once. +Restart can also recognize the candidate as the active tip and complete the +same idempotent confirmation path. Transient RPC, audit, and ledger outcomes remain pending and retry with an exponential delay starting at 250 milliseconds and capped at 30 seconds. They do not increment terminal abandonment counters. Replay carries the database row's block hash separately from candidate JSON, so malformed payloads can be quarantined by their authoritative outbox key instead of replaying forever. +The block submitter heartbeat carries its current phase, including replay +query, node RPC, lock admission, audit, persistence, and finalization. A stale +watchdog diagnostic therefore reports a label such as +`block_submitter:replay-outbox-query` instead of only the thread name. + When a network-valid hash is below a listener's advertised share target, the coordinator first stores a candidate-only intent, submits it synchronously, and links share credit only if the block lands. This closes the submit-to-credit diff --git a/lab/prism/prism_coordinator.py b/lab/prism/prism_coordinator.py index d25068dc..77e51b3b 100644 --- a/lab/prism/prism_coordinator.py +++ b/lab/prism/prism_coordinator.py @@ -465,6 +465,16 @@ def validate_payout_artifact_age_bounds( ) DEFAULT_BLOCK_CANDIDATE_RETRY_INITIAL_SECONDS = 0.25 DEFAULT_BLOCK_CANDIDATE_RETRY_MAX_SECONDS = 30.0 +# The node fast lane is intentionally shorter than the normal ten-second RPC +# budget: an ambiguous timeout leaves the durable outbox pending and replay +# safely submits the same hash again. +DEFAULT_BLOCK_SUBMIT_RPC_TIMEOUT_SECONDS = 1.0 +# Every PostgreSQL operation reached by the submitter inherits this deadline. +# Direct outbox calls also run behind a coordinator-side single-flight guard, +# so a driver that ignores the deadline cannot freeze the submitter thread. +DEFAULT_BLOCK_SUBMIT_DB_TIMEOUT_SECONDS = 1.0 +BLOCK_SUBMITTER_WAIT_HEARTBEAT_SLICE_SECONDS = 0.25 +DEFAULT_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS = 5.0 # How long an own-hash tip observation keeps protecting a block candidate # from terminal abandonment while instantaneous chain probes disagree # (transient sibling/fork views during quick-succession blocks, RPC blips). @@ -525,12 +535,17 @@ class _ObservedRLock: metrics are meant to diagnose. """ - def __init__(self) -> None: + def __init__( + self, + *, + wait_observer: Callable[[float], None] | None = None, + ) -> None: self._lock = threading.RLock() self._metrics_lock = threading.Lock() self._contention_count = 0 self._wait_seconds_sum = 0.0 self._wait_seconds_max = 0.0 + self._wait_observer = wait_observer def acquire(self, blocking: bool = True, timeout: float = -1) -> bool: if not blocking: @@ -538,7 +553,25 @@ def acquire(self, blocking: bool = True, timeout: float = -1) -> bool: if self._lock.acquire(blocking=False): return True started = time.monotonic() - acquired = self._lock.acquire(blocking=True, timeout=timeout) + observer = self._wait_observer + if observer is None: + acquired = self._lock.acquire(blocking=True, timeout=timeout) + else: + deadline = None if timeout < 0 else started + max(0.0, timeout) + acquired = False + while not acquired: + wait_slice = BLOCK_SUBMITTER_WAIT_HEARTBEAT_SLICE_SECONDS + if deadline is not None: + remaining = deadline - time.monotonic() + if remaining <= 0: + break + wait_slice = min(wait_slice, remaining) + acquired = self._lock.acquire( + blocking=True, + timeout=wait_slice, + ) + if not acquired: + observer(max(0.0, time.monotonic() - started)) waited = max(0.0, time.monotonic() - started) with self._metrics_lock: self._contention_count += 1 @@ -1251,8 +1284,14 @@ def call( attempt_count = ( 1 if method in _QBIT_RPC_NO_TRANSPORT_RETRY_METHODS else 2 ) + deadline = time.monotonic() + max(0.001, float(timeout)) for attempt in range(attempt_count): - conn = self._acquire_connection(timeout) + remaining = deadline - time.monotonic() + if remaining <= 0: + if last_exc is not None: + raise last_exc + raise TimeoutError(f"qbit RPC {method} timed out") + conn = self._acquire_connection(remaining) try: conn.request("POST", path, body=body, headers=headers) response = conn.getresponse() @@ -1391,6 +1430,28 @@ class _BlockCandidateDispositionFlight: users: int = 0 +@dataclass(frozen=True) +class _BlockCandidateNodeSubmission: + """Result of the latency-critical qbitd fast-lane call.""" + + attempted: bool + result: object = None + error: BaseException | None = None + + +@dataclass +class _BlockSubmitterLedgerCall: + """One still-running direct outbox call, reused across paced retries.""" + + done: threading.Event = field(default_factory=threading.Event) + result: object = None + error: BaseException | None = None + + +class BlockSubmitterDatabaseTimeout(TimeoutError): + """A submitter ledger phase exceeded its coordinator-side deadline.""" + + @dataclass(frozen=True) class CachedTemplateArtifacts: """Template plus everything derivable from it alone, shared by all clients. @@ -2614,10 +2675,25 @@ def _admit_writer_locked(self, component: str, *, inherited: bool) -> _WriterOpe self.active_writers[component] = self.active_writers.get(component, 0) + 1 return _WriterOperationToken(self, component) - def enter_writer(self, component: str) -> _WriterOperationToken: + def enter_writer( + self, + component: str, + *, + wait_callback: Callable[[], None] | None = None, + ) -> _WriterOperationToken: depth = self._thread_writer_depth() - with self.condition: - token = self._admit_writer_locked(component, inherited=depth > 0) + if wait_callback is None: + with self.condition: + token = self._admit_writer_locked(component, inherited=depth > 0) + else: + while not self.condition.acquire( + timeout=BLOCK_SUBMITTER_WAIT_HEARTBEAT_SLICE_SECONDS + ): + wait_callback() + try: + token = self._admit_writer_locked(component, inherited=depth > 0) + finally: + self.condition.release() self.local.writer_depth = depth + 1 return token @@ -2962,6 +3038,18 @@ def __init__(self) -> None: "PRISM_BLOCKWAIT_TIMEOUT_SECONDS", DEFAULT_PRISM_BLOCKWAIT_TIMEOUT_SECONDS, ) + self.block_submit_rpc_timeout_seconds = env_positive_float( + "PRISM_BLOCK_SUBMIT_RPC_TIMEOUT_SECONDS", + DEFAULT_BLOCK_SUBMIT_RPC_TIMEOUT_SECONDS, + ) + self.block_submit_db_timeout_seconds = env_positive_float( + "PRISM_BLOCK_SUBMIT_DB_TIMEOUT_SECONDS", + DEFAULT_BLOCK_SUBMIT_DB_TIMEOUT_SECONDS, + ) + self.block_submit_lock_wait_log_seconds = env_positive_float( + "PRISM_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS", + DEFAULT_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS, + ) # An own-hash tip observation is acceptance evidence even when the # direct submitblock ack was lost; this window bounds how long that # evidence blocks a terminal abandonment while fresh chain probes @@ -3314,7 +3402,9 @@ def __init__(self) -> None: self.ctv_broadcaster_processed_rows_total = 0 self._ctv_fanout_market_fee_rate_cache: dict[tuple[int | None, str | None], int] = {} self.ctv_fanout_broadcast_daemon: CtvFanoutBroadcastDaemon | None = None - self.lock = _ObservedRLock() + self.lock = _ObservedRLock( + wait_observer=self._observe_coordinator_lock_wait, + ) self.clients: set[ClientState] = set() self.connection_limit_rejection_counts = {"global": 0, "username": 0} self.peak_active_connection_count = 0 @@ -3440,6 +3530,11 @@ def __init__(self) -> None: self._block_submitter_backoff_started_monotonic: float | None = None self._block_submitter_backoff_deadline_monotonic: float | None = None self._block_submitter_backoff_delay_seconds = 0.0 + self._block_submitter_ledger_calls_lock = threading.Lock() + self._block_submitter_ledger_calls: dict[ + tuple[object, ...], _BlockSubmitterLedgerCall + ] = {} + self._block_submitter_last_lock_wait_log_monotonic = 0.0 # Terminal candidates whose durable outbox update failed; replays for # these run finalize-only (see _finalize_block_candidate). self._block_candidate_finalize_retries: dict[str, tuple[bool, str]] = {} @@ -3534,6 +3629,7 @@ def __init__(self) -> None: # container/systemd restart policy recovers a *hung* coordinator (a # healthcheck alone does not restart it under plain compose). self._heartbeats: dict[str, float] = {} + self._heartbeat_phases: dict[str, str] = {} self._watchdog_pauses: dict[str, int] = {} self._heartbeats_lock = threading.Lock() self.watchdog_enabled = env_bool("PRISM_WATCHDOG_ENABLED", "1") @@ -10390,6 +10486,8 @@ def _ensure_watchdog_state(self) -> None: self._heartbeats_lock = threading.Lock() if not hasattr(self, "_heartbeats"): self._heartbeats = {} + if not hasattr(self, "_heartbeat_phases"): + self._heartbeat_phases = {} if not hasattr(self, "_watchdog_pauses"): self._watchdog_pauses = {} @@ -12136,20 +12234,118 @@ def initial_job_timeout_loop(self) -> None: while not self.stop_event.wait(1.0): self.sweep_initial_job_timeouts() - def _record_heartbeat(self, name: str) -> None: + def _record_heartbeat(self, name: str, *, phase: str | None = None) -> None: self._ensure_watchdog_state() with self._heartbeats_lock: self._heartbeats[name] = time.monotonic() + if phase is not None: + self._heartbeat_phases[name] = phase + + def _record_block_submitter_heartbeat(self, phase: str) -> None: + """Record a phase while preserving one-argument heartbeat embedders.""" + heartbeat = self._record_heartbeat + try: + heartbeat("block_submitter", phase=phase) + except TypeError as exc: + # Preserve the historical one-argument heartbeat seam used by + # focused embedders. Do not hide TypeErrors raised by a heartbeat + # implementation that did accept the keyword. + if "unexpected keyword argument 'phase'" not in str(exc): + raise + heartbeat("block_submitter") + + def _record_block_submitter_phase(self, phase: str) -> None: + """Stamp a named phase only from the dedicated submitter owner.""" + owner = getattr(self, "_block_submitter_thread_ident", None) + if owner is None or threading.get_ident() != owner: + return + self._block_submitter_phase = phase + self._record_block_submitter_heartbeat(phase) + + def _record_block_submitter_wait(self, phase: str) -> None: + """Heartbeat owner waits while preserving lightweight test behavior.""" + owner = getattr(self, "_block_submitter_thread_ident", None) + if owner is None: + self._record_heartbeat("block_submitter") + return + self._record_block_submitter_phase(phase) + + def _observe_coordinator_lock_wait(self, elapsed_seconds: float) -> None: + """Keep a sliced coordinator-lock wait visible and watchdog-safe.""" + owner = getattr(self, "_block_submitter_thread_ident", None) + if owner is None or threading.get_ident() != owner: + return + current_phase = getattr(self, "_block_submitter_phase", "unknown") + wait_phase = f"wait-lock:coordinator-state:{current_phase}" + self._record_block_submitter_heartbeat(wait_phase) + now = time.monotonic() + log_interval = float( + getattr( + self, + "block_submit_lock_wait_log_seconds", + DEFAULT_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS, + ) + ) + last_log = float( + getattr(self, "_block_submitter_last_lock_wait_log_monotonic", 0.0) + ) + if last_log <= 0 or now - last_log >= log_interval: + self._block_submitter_last_lock_wait_log_monotonic = now + print( + "prism coordinator: block submitter waiting on lock " + f"lock=coordinator-state phase={current_phase} " + f"elapsed={elapsed_seconds:.3f}s", + flush=True, + ) + + def _acquire_block_submitter_lock(self, lock: Any, name: str) -> None: + """Acquire a submit-path lock in heartbeat/logging slices.""" + owner = getattr(self, "_block_submitter_thread_ident", None) + if owner is not None and threading.get_ident() != owner: + lock.acquire() + return + started = time.monotonic() + last_log = started + log_interval = float( + getattr( + self, + "block_submit_lock_wait_log_seconds", + DEFAULT_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS, + ) + ) + while not lock.acquire( + timeout=BLOCK_SUBMITTER_WAIT_HEARTBEAT_SLICE_SECONDS + ): + phase = f"wait-lock:{name}" + self._record_block_submitter_wait(phase) + now = time.monotonic() + if now - last_log >= log_interval: + print( + "prism coordinator: block submitter waiting on lock " + f"lock={name} elapsed={now - started:.3f}s", + flush=True, + ) + last_log = now + + @contextmanager + def _block_submitter_lock(self, lock: Any, name: str) -> Iterator[None]: + self._acquire_block_submitter_lock(lock, name) + try: + yield + finally: + lock.release() def _overdue_heartbeats(self, now: float) -> list[str]: self._ensure_watchdog_state() with self._heartbeats_lock: paused = set(self._watchdog_pauses) - return sorted( - name - for name, last in self._heartbeats.items() - if name not in paused and now - last > self.watchdog_timeout_seconds - ) + overdue: list[str] = [] + for name, last in self._heartbeats.items(): + if name in paused or now - last <= self.watchdog_timeout_seconds: + continue + phase = self._heartbeat_phases.get(name) + overdue.append(f"{name}:{phase}" if phase else name) + return sorted(overdue) def _pause_watchdog_heartbeat(self, name: str) -> None: self._ensure_watchdog_state() @@ -12171,6 +12367,7 @@ def _remove_watchdog_heartbeat(self, name: str) -> None: self._ensure_watchdog_state() with self._heartbeats_lock: self._heartbeats.pop(name, None) + self._heartbeat_phases.pop(name, None) self._watchdog_pauses.pop(name, None) def _registered_watchdog_heartbeat_names(self, *names: str) -> tuple[str, ...]: @@ -12820,7 +13017,21 @@ def _ensure_shutdown_controller(self) -> CoordinatorShutdownController: @contextmanager def _writer_operation(self, component: str) -> Iterator[None]: controller = self._ensure_shutdown_controller() - token = controller.enter_writer(component) + owner = getattr(self, "_block_submitter_thread_ident", None) + submitter_owner = owner is not None and threading.get_ident() == owner + phase = f"writer-admission:{component}" + if submitter_owner: + self._record_block_submitter_phase(phase) + if submitter_owner: + token = controller.enter_writer( + component, + wait_callback=lambda: self._record_block_submitter_phase(phase), + ) + else: + # Keep the historical one-argument seam for focused embedders and + # test controllers; only the dedicated submitter needs sliced + # admission heartbeats. + token = controller.enter_writer(component) try: yield finally: @@ -20339,6 +20550,16 @@ def build_audit_bundle( assert process.stdin is not None input_byte_count = 0 worker_deadline = build_deadline + killed_process_wait_seconds = max( + 0.001, + float( + getattr( + self, + "job_build_cancel_grace_seconds", + DEFAULT_PRISM_JOB_BUILD_CANCEL_GRACE_SECONDS, + ) + ), + ) coordinator = self class _CancelableInput: @@ -20506,7 +20727,10 @@ def write_precomposed_tail() -> None: process.kill() except ProcessLookupError: pass - process.wait() + try: + process.wait(timeout=killed_process_wait_seconds) + except subprocess.TimeoutExpired: + pass if isinstance( exc, (JobBuildCancelled, _JobBundleBuildSuperseded), @@ -20537,7 +20761,9 @@ def write_precomposed_tail() -> None: terminated = False returncode: int | None = None if cancellation is None and not hasattr(process, "poll"): - returncode = process.wait() + returncode = process.wait( + timeout=max(0.001, worker_deadline - time.monotonic()) + ) else: while returncode is None: returncode = process.poll() @@ -20568,14 +20794,24 @@ def write_precomposed_tail() -> None: ) except subprocess.TimeoutExpired: process.kill() - returncode = process.wait() + try: + returncode = process.wait( + timeout=killed_process_wait_seconds + ) + except subprocess.TimeoutExpired: + returncode = process.poll() with self._job_build_scheduler_lock: self.job_build_worker_counts["terminations"] += 1 self._job_build_worker_restart_pending = True break if time.monotonic() >= worker_deadline: process.kill() - returncode = process.wait() + try: + returncode = process.wait( + timeout=killed_process_wait_seconds + ) + except subprocess.TimeoutExpired: + returncode = process.poll() with self._tip_refresh_metrics_lock: self.tip_refresh_worker_failures += 1 raise RuntimeError( @@ -20939,7 +21175,14 @@ def handle_submit(self, client: ClientState, params: list[object]) -> bool: try: candidate_intent = self.block_candidate_intent(candidate) if callable(persist_intent): - persist_intent(candidate_intent) + self._run_block_submitter_ledger_call( + ( + "persist-candidate-intent", + str(candidate.submission.block_hash_hex).lower(), + ), + "persist-candidate-intent", + lambda: persist_intent(candidate_intent), + ) except BaseException: # No retry slot is safe until the pre-submit outbox boundary is # durable. Let the miner retry this submission instead. Without @@ -20949,10 +21192,15 @@ def handle_submit(self, client: ClientState, params: list[object]) -> bool: self._forget_recent_share_key(share_key) raise try: + node_submission = self._node_submission_for_candidate(candidate) self._mark_block_candidate_attempted( str(candidate.submission.block_hash_hex).lower() ) - block_landed = self.submit_block_candidate(candidate) + with self._block_submitter_ledger_statement_timeout_scope(): + block_landed = self._account_block_candidate_after_node_submit( + candidate, + node_submission, + ) except BaseException: self._retain_block_candidate_for_retry(candidate) self._forget_recent_share_key(share_key) @@ -20973,30 +21221,19 @@ def handle_submit(self, client: ClientState, params: list[object]) -> bool: if reason not in retryable_reasons: # This process will never credit the candidate share now: # release its snapshot anchor floor entry before the - # terminal outbox update. If that update fails, durable - # replay may run in this process with a reconstructed - # PendingShare; append-side cache invalidation protects its - # original stamps without retaining an old anchor floor. - self._finish_pending_share_commit(candidate.pending_share) - finish = getattr(self.ledger, "mark_block_candidate_abandoned", None) - if callable(finish): - abandon_error = ( - getattr(outcome, "error", None) - if outcome is not None - else None - ) - finish( - block_hash=submission.block_hash_hex, - error=abandon_error or reason, - ) - # Once the durable outbox cannot replay this candidate, - # its landed-transition tombstone no longer protects a - # crash seam and would otherwise accumulate forever. - self._clear_accepted_block_payout_preview( - submission.block_hash_hex + # terminal outbox update, whose failure would still leave + # only restart replay (a fresh PendingShare) to credit it. + abandon_error = ( + getattr(outcome, "error", None) + if outcome is not None + else None ) - self._discard_outstanding_block_candidate( - str(submission.block_hash_hex) + self._finalize_block_candidate( + candidate, + block_hash=str(submission.block_hash_hex).lower(), + accepted=False, + error=str(abandon_error or reason), + outcome=outcome, ) self._forget_recent_share_key(share_key) self.reject_stratum( @@ -21006,11 +21243,16 @@ def handle_submit(self, client: ClientState, params: list[object]) -> bool: worker=worker_name, ) else: - finish = getattr(self.ledger, "mark_block_candidate_submitted", None) - if callable(finish): - finish(block_hash=submission.block_hash_hex) - self._discard_outstanding_block_candidate( - str(submission.block_hash_hex) + outcome = getattr(self, "_block_candidate_outcome", None) + if outcome is None: + outcome = threading.local() + self._block_candidate_outcome = outcome + self._finalize_block_candidate( + candidate, + block_hash=str(submission.block_hash_hex).lower(), + accepted=True, + error="", + outcome=outcome, ) if evicted_entry is not None: self.note_evicted_job_submit( @@ -23001,16 +23243,32 @@ def enqueue_block_candidate(self, candidate: PrismBlockCandidate) -> bool: @ledger_writer_operation("accepted_block_handling") def replay_pending_block_candidates(self) -> int: """Queue durable candidate intents not completed by an earlier process.""" + self._record_block_submitter_phase("replay-check-memory") with self.lock: if getattr(self, "_retry_block_candidate", None) is not None: return 0 + # A live wakeup is already the lowest-latency route to qbitd. Never + # park it behind the outbox query that exists only to recover missing + # wakeups after queue pressure or restart. + queue_obj = getattr(self, "block_candidate_queue", None) + if queue_obj is not None and not queue_obj.empty(): + return 0 pending_rows = getattr(self.ledger, "pending_block_candidate_rows", None) if callable(pending_rows): - durable_rows = pending_rows(limit=MAX_PENDING_BLOCK_CANDIDATES) + durable_rows = self._run_block_submitter_ledger_call( + ("replay-outbox-query",), + "replay-outbox-query", + lambda: pending_rows(limit=MAX_PENDING_BLOCK_CANDIDATES), + ) else: pending = getattr(self.ledger, "pending_block_candidates", None) if not callable(pending): return 0 + pending_intents = self._run_block_submitter_ledger_call( + ("replay-outbox-query",), + "replay-outbox-query", + lambda: pending(limit=MAX_PENDING_BLOCK_CANDIDATES), + ) durable_rows = [ { "block_hash": ( @@ -23020,11 +23278,9 @@ def replay_pending_block_candidates(self) -> int: ), "candidate": intent, } - for intent in pending(limit=MAX_PENDING_BLOCK_CANDIDATES) + for intent in pending_intents ] - queue_obj = getattr(self, "block_candidate_queue", None) - if queue_obj is not None and not queue_obj.empty(): - return 0 + self._record_block_submitter_phase("replay-restore") queued = 0 for durable_row in durable_rows: durable_block_hash = "" @@ -23057,7 +23313,13 @@ def replay_pending_block_candidates(self) -> int: try: state_reader = getattr(self.ledger, "pool_block_state", None) if callable(state_reader): - block_state = state_reader(block_hash=durable_block_hash) + block_state = self._run_block_submitter_ledger_call( + ("replay-pool-block-state", durable_block_hash), + "replay-pool-block-state", + lambda block_hash=durable_block_hash, reader=state_reader: reader( + block_hash=block_hash + ), + ) except Exception: traceback.print_exc() block_state = None @@ -23106,9 +23368,13 @@ def replay_pending_block_candidates(self) -> int: quarantine = getattr(self.ledger, "mark_block_candidate_abandoned", None) if durable_block_hash and callable(quarantine): try: - quarantined = quarantine( - block_hash=durable_block_hash, - error="invalid durable candidate intent", + quarantined = self._run_block_submitter_ledger_call( + ("replay-quarantine", durable_block_hash), + "replay-quarantine", + lambda block_hash=durable_block_hash, finish=quarantine: finish( + block_hash=block_hash, + error="invalid durable candidate intent", + ), ) self._clear_accepted_block_payout_preview( durable_block_hash @@ -23141,15 +23407,117 @@ def _ensure_block_submitter_retry_state(self) -> None: if not hasattr(self, "_block_submitter_backoff_delay_seconds"): self._block_submitter_backoff_delay_seconds = 0.0 + def _ensure_block_submitter_ledger_call_state(self) -> None: + if not hasattr(self, "_block_submitter_ledger_calls_lock"): + self._block_submitter_ledger_calls_lock = threading.Lock() + if not hasattr(self, "_block_submitter_ledger_calls"): + self._block_submitter_ledger_calls = {} + + def _block_submitter_db_timeout(self) -> float: + return max( + 0.001, + float( + getattr( + self, + "block_submit_db_timeout_seconds", + DEFAULT_BLOCK_SUBMIT_DB_TIMEOUT_SECONDS, + ) + ), + ) + + @contextmanager + def _block_submitter_ledger_timeout_scope(self) -> Iterator[None]: + """Apply the submitter's PostgreSQL deadline when the ledger supports it.""" + operation_timeout = getattr(self.ledger, "operation_timeout", None) + if not callable(operation_timeout): + yield + return + with operation_timeout(self._block_submitter_db_timeout()): + yield + + @contextmanager + def _block_submitter_ledger_statement_timeout_scope(self) -> Iterator[None]: + """Give each post-submit ledger step a fresh short deadline.""" + statement_timeout = getattr(self.ledger, "statement_timeout", None) + if callable(statement_timeout): + with statement_timeout(self._block_submitter_db_timeout()): + yield + return + # Duck-typed ledgers predating per-statement scopes still receive a + # bounded operation, even though their budget spans the whole tail. + with self._block_submitter_ledger_timeout_scope(): + yield + + def _run_block_submitter_ledger_call( + self, + key: tuple[object, ...], + phase: str, + operation: Callable[[], Any], + ) -> Any: + """Run one direct outbox call without letting its driver wedge us. + + A timed-out call remains registered and is reused by the next paced + retry. This bounds the coordinator-side wait without spawning an + unbounded pile of threads when a fake/misbehaving driver ignores the + real PostgreSQL statement deadline. Candidate outbox mutations are + idempotent, so a late completion converges with replay. + """ + self._ensure_block_submitter_ledger_call_state() + with self._block_submitter_ledger_calls_lock: + call = self._block_submitter_ledger_calls.get(key) + if call is None: + call = _BlockSubmitterLedgerCall() + self._block_submitter_ledger_calls[key] = call + + def run() -> None: + try: + with self._block_submitter_ledger_timeout_scope(): + call.result = operation() + except BaseException as exc: + call.error = exc + finally: + call.done.set() + + threading.Thread( + target=run, + name=f"prism-block-ledger-{phase}", + daemon=True, + ).start() + + timeout_seconds = self._block_submitter_db_timeout() + deadline = time.monotonic() + timeout_seconds + while not call.done.is_set(): + self._record_block_submitter_wait(phase) + remaining = deadline - time.monotonic() + if remaining <= 0: + print( + "prism coordinator: block submitter ledger phase timed out " + f"phase={phase} timeout={timeout_seconds:g}s", + flush=True, + ) + raise BlockSubmitterDatabaseTimeout( + f"{phase} exceeded {timeout_seconds:g}s" + ) + call.done.wait( + min( + remaining, + BLOCK_SUBMITTER_WAIT_HEARTBEAT_SLICE_SECONDS, + ) + ) + self._record_block_submitter_wait(f"{phase}:complete") + with self._block_submitter_ledger_calls_lock: + if self._block_submitter_ledger_calls.get(key) is call: + self._block_submitter_ledger_calls.pop(key, None) + if call.error is not None: + raise call.error + return call.result + def _wait_for_block_candidate_retry(self, delay_seconds: float) -> bool: """Wait for intentional backoff without impersonating stuck work. - Only this bounded retry wait and the owner-thread boundary stamps in - ``_record_block_candidate_progress`` refresh the submitter - heartbeat, and every boundary stamp follows completed work. SQL, - RPC, audit/finalization, and socket phases call no helper while they - run, so a genuinely blocked candidate phase remains - watchdog-eligible. + Retry waits heartbeat in bounded slices. Direct outbox calls and lock + admission use the same phase-aware pattern; work that is not covered + by an explicit deadline remains watchdog-eligible. """ delay_seconds = max(0.0, float(delay_seconds)) if delay_seconds <= 0: @@ -23163,7 +23531,7 @@ def _wait_for_block_candidate_retry(self, delay_seconds: float) -> bool: remaining = delay_seconds try: while remaining > 0: - self._record_heartbeat("block_submitter") + self._record_block_submitter_wait("retry-backoff") wait_slice = min( remaining, BLOCK_CANDIDATE_RETRY_HEARTBEAT_SLICE_SECONDS, @@ -23171,7 +23539,7 @@ def _wait_for_block_candidate_retry(self, delay_seconds: float) -> bool: if self.stop_event.wait(wait_slice): return True remaining = max(0.0, remaining - wait_slice) - self._record_heartbeat("block_submitter") + self._record_block_submitter_wait("retry-backoff:complete") return False finally: with self._block_submitter_retry_state_lock: @@ -23182,7 +23550,146 @@ def _wait_for_block_candidate_retry(self, delay_seconds: float) -> bool: def _mark_block_candidate_attempted(self, block_hash: str) -> None: mark_attempted = getattr(self.ledger, "mark_block_candidate_attempted", None) if callable(mark_attempted): - mark_attempted(block_hash=block_hash) + self._run_block_submitter_ledger_call( + ("mark-attempted", block_hash), + "mark-attempted", + lambda: mark_attempted(block_hash=block_hash), + ) + + def _rpc_call_with_timeout( + self, + method: str, + params: list[object], + *, + timeout_seconds: float, + ) -> Any: + """Pass an explicit timeout to production RPCs and capable test doubles.""" + call = self.rpc.call + supports_timeout = isinstance(self.rpc, JsonRpc) + if not supports_timeout: + try: + parameters = inspect.signature(call).parameters.values() + supports_timeout = any( + parameter.name == "timeout" + or parameter.kind is inspect.Parameter.VAR_KEYWORD + for parameter in parameters + ) + except (TypeError, ValueError): + supports_timeout = False + if supports_timeout: + return call(method, params, timeout=timeout_seconds) + return call(method, params) + + def _submit_block_candidate_to_node( + self, + candidate: PrismBlockCandidate, + ) -> _BlockCandidateNodeSubmission: + """Offer the durable candidate to qbitd before any accounting work.""" + block_hash = str(candidate.submission.block_hash_hex).lower() + self._register_outstanding_block_candidate(block_hash) + self._record_block_submitter_phase("submitblock-rpc") + timeout_seconds = max( + 0.001, + float( + getattr( + self, + "block_submit_rpc_timeout_seconds", + DEFAULT_BLOCK_SUBMIT_RPC_TIMEOUT_SECONDS, + ) + ), + ) + try: + result = self._rpc_call_with_timeout( + "submitblock", + [candidate.submission.block_hex], + timeout_seconds=timeout_seconds, + ) + except BaseException as exc: + self._record_block_submitter_phase("submitblock-rpc:error") + return _BlockCandidateNodeSubmission( + attempted=True, + error=exc, + ) + self._record_block_submitter_phase("submitblock-rpc:complete") + landed_monotonic = getattr(candidate, "landed_monotonic", None) + if landed_monotonic is not None: + self._observe_block_submit_seconds( + time.monotonic() - float(landed_monotonic) + ) + return _BlockCandidateNodeSubmission( + attempted=True, + result=result, + ) + + def _node_submission_for_candidate( + self, + candidate: PrismBlockCandidate, + ) -> _BlockCandidateNodeSubmission: + """Choose the node fast lane unless the pool was already closed.""" + block_hash = str(candidate.submission.block_hash_hex).lower() + self._record_block_submitter_phase("fast-lane-admission") + with self.lock: + accounted_hashes = getattr( + self, + "_accounted_accepted_block_hashes", + set(), + ) + pool_closed = ( + self.accepted_block_count >= self.max_blocks + and block_hash not in accounted_hashes + ) + if pool_closed: + return _BlockCandidateNodeSubmission(attempted=False) + return self._submit_block_candidate_to_node(candidate) + + def _node_submission_for_direct_candidate( + self, + candidate: PrismBlockCandidate, + ) -> _BlockCandidateNodeSubmission: + """Preserve active-replay semantics for non-queue embedders. + + The dedicated submitter always uses the unconditional fast lane. A + direct caller can instead be resuming a durable active ancestor, for + which another submit is unnecessary and some integrations do not + retain block bytes. This compatibility probe is not on the incident + queue-to-node path. + """ + block_hash = str(candidate.submission.block_hash_hex).lower() + expected_height = int(candidate.context.template["height"]) + try: + if str(self.rpc.call("getbestblockhash")).lower() == block_hash: + return _BlockCandidateNodeSubmission(attempted=False) + except Exception: + pass + try: + if self.active_block_candidate_height(block_hash) == expected_height: + return _BlockCandidateNodeSubmission(attempted=False) + except Exception: + pass + if not hasattr(candidate.submission, "block_hex"): + return _BlockCandidateNodeSubmission(attempted=False) + return self._node_submission_for_candidate(candidate) + + def _account_block_candidate_after_node_submit( + self, + candidate: PrismBlockCandidate, + node_submission: _BlockCandidateNodeSubmission, + ) -> bool: + """Pass fast-lane evidence while tolerating legacy test embedders.""" + submit = self.submit_block_candidate + supports_node_submission = True + try: + parameters = inspect.signature(submit).parameters.values() + supports_node_submission = any( + parameter.name == "node_submission" + or parameter.kind is inspect.Parameter.VAR_KEYWORD + for parameter in parameters + ) + except (TypeError, ValueError): + pass + if supports_node_submission: + return bool(submit(candidate, node_submission=node_submission)) + return bool(submit(candidate)) def _ensure_block_candidate_disposition_state(self) -> None: """Backfill same-hash submission guards for lightweight embedders.""" @@ -23212,7 +23719,10 @@ def _block_candidate_disposition(self, block_hash: str) -> Iterator[None]: """ key = block_hash.lower() self._ensure_block_candidate_disposition_state() - with self._block_candidate_disposition_registry_lock: + with self._block_submitter_lock( + self._block_candidate_disposition_registry_lock, + "candidate-disposition-registry", + ): flight = self._block_candidate_disposition_flights.get(key) if flight is None: flight = _BlockCandidateDispositionFlight() @@ -23221,10 +23731,21 @@ def _block_candidate_disposition(self, block_hash: str) -> Iterator[None]: try: # Never hold the registry lock while waiting on the hash-specific # guard: unrelated candidates must remain independent. - with flight.lock: + guard = ( + self._block_submitter_lock( + flight.lock, + f"candidate-disposition:{key}", + ) + if hasattr(flight.lock, "acquire") + else flight.lock + ) + with guard: yield finally: - with self._block_candidate_disposition_registry_lock: + with self._block_submitter_lock( + self._block_candidate_disposition_registry_lock, + "candidate-disposition-registry", + ): flight.users -= 1 if ( flight.users == 0 @@ -23239,14 +23760,44 @@ def block_submit_loop(self) -> None: # submitter's liveness budget on its behalf. self._block_submitter_thread_ident = threading.get_ident() while not self.stop_event.is_set(): - self._record_heartbeat("block_submitter") + self._record_block_submitter_phase("loop") try: + # The in-memory wakeup is already backed by the durable + # outbox. Drain it before any recovery query so a saturated + # database cannot delay the first node submission. + with self.lock: + retry_ready = ( + getattr(self, "_retry_block_candidate", None) is not None + ) + queue_obj = getattr(self, "block_candidate_queue", None) + wakeup_ready = ( + queue_obj is not None and not queue_obj.empty() + ) + if (retry_ready or wakeup_ready) and self.submit_next_block_candidate(): + continue self.replay_pending_block_candidates() self.submit_next_block_candidate(timeout=1.0) except ShutdownInProgress: # Admission can close after the loop condition. Durable block # candidates remain in the outbox for the replacement writer. return + except Exception: + phase = getattr(self, "_block_submitter_phase", "unknown") + print( + "prism coordinator: block submitter iteration failed " + f"phase={phase}; durable candidates remain pending", + flush=True, + ) + traceback.print_exc() + retry_delay = float( + getattr( + self, + "block_candidate_retry_initial_seconds", + DEFAULT_BLOCK_CANDIDATE_RETRY_INITIAL_SECONDS, + ) + ) + if self._wait_for_block_candidate_retry(retry_delay): + return def submit_next_block_candidate(self, timeout: float | None = None) -> bool: """Dequeue and land one block candidate; returns True when one ran. @@ -23254,6 +23805,7 @@ def submit_next_block_candidate(self, timeout: float | None = None) -> bool: The block-submitter loop calls this continuously; tests call it directly to drain the queue deterministically. """ + self._record_block_submitter_phase("dequeue-retry") with self.lock: candidate = getattr(self, "_retry_block_candidate", None) if candidate is not None: @@ -23263,6 +23815,7 @@ def submit_next_block_candidate(self, timeout: float | None = None) -> bool: if queue_obj is None: return False try: + self._record_block_submitter_phase("dequeue-queue") if timeout is None: candidate = queue_obj.get_nowait() else: @@ -23275,9 +23828,24 @@ def submit_next_block_candidate(self, timeout: float | None = None) -> bool: outcome = threading.local() self._block_candidate_outcome = outcome outcome.refresh_client = None + block_hash = str(candidate.submission.block_hash_hex).lower() + self._record_block_submitter_phase("finalize-registry") + with self.lock: + registry = getattr(self, "_block_candidate_finalize_retries", None) + pending_finalize = ( + registry.get(block_hash) if registry is not None else None + ) + node_submission = ( + None + if pending_finalize is not None + else self._node_submission_for_candidate(candidate) + ) try: with self._writer_operation("accepted_block_handling"): - ran = self._submit_next_block_candidate_writer(candidate) + ran = self._submit_next_block_candidate_writer( + candidate, + node_submission=node_submission, + ) refresh_client = getattr(outcome, "refresh_client", None) outcome.refresh_client = None except ShutdownInProgress: @@ -23298,6 +23866,8 @@ def submit_next_block_candidate(self, timeout: float | None = None) -> bool: def _submit_next_block_candidate_writer( self, candidate: PrismBlockCandidate, + *, + node_submission: _BlockCandidateNodeSubmission | None = None, ) -> bool: """Land one dequeued block candidate inside writer admission.""" outcome = getattr(self, "_block_candidate_outcome", None) @@ -23307,32 +23877,16 @@ def _submit_next_block_candidate_writer( outcome.reason = None outcome.error = None block_hash = str(candidate.submission.block_hash_hex).lower() - try: - self._mark_block_candidate_attempted(block_hash) - except Exception: - print( - "prism coordinator: could not record block candidate attempt " - f"hash={block_hash}", - flush=True, - ) - traceback.print_exc() - self._retain_block_candidate_for_retry(candidate) - self._wait_for_block_candidate_retry( - self._next_block_candidate_retry_delay(block_hash) - ) - return True + self._record_block_submitter_phase("finalize-registry") with self.lock: registry = getattr(self, "_block_candidate_finalize_retries", None) pending_finalize = ( registry.get(block_hash) if registry is not None else None ) if pending_finalize is not None: - # Finalize-only replay: submission, terminal accounting, and + # Finalize-only replay: node submission, terminal accounting, and # payout persistence already completed on the pass that armed - # this entry; only the durable outbox update remains. Re-running - # submit_block_candidate here would recount terminal - # abandonments and redo the accepted-path audit/persist work - # once per paced retry. + # this entry. It bypasses both submitblock and attempt marking. accepted, error = pending_finalize return self._finalize_block_candidate( candidate, @@ -23341,10 +23895,31 @@ def _submit_next_block_candidate_writer( error=error, outcome=outcome, ) + if node_submission is None: + node_submission = self._node_submission_for_candidate(candidate) + try: + self._mark_block_candidate_attempted(block_hash) + except Exception: + print( + "prism coordinator: could not record block candidate attempt " + f"hash={block_hash}", + flush=True, + ) + traceback.print_exc() + self._retain_block_candidate_for_retry(candidate) + self._wait_for_block_candidate_retry( + self._next_block_candidate_retry_delay(block_hash) + ) + return True accepted = False error = "candidate became stale or submission failed" try: - accepted = self.submit_block_candidate(candidate) + self._record_block_submitter_phase("accounting") + with self._block_submitter_ledger_statement_timeout_scope(): + accepted = self._account_block_candidate_after_node_submit( + candidate, + node_submission, + ) except Exception: error = "candidate submission raised an exception" print( @@ -23423,6 +23998,7 @@ def _finalize_block_candidate( so terminal abandonment accounting stays once-per-candidate and an accepted candidate's audit/persist work is not redone per retry. """ + self._record_block_submitter_phase("finalize-preview") self._clear_accepted_block_payout_preview( block_hash, invalidate_published=not accepted, @@ -23436,9 +24012,17 @@ def _finalize_block_candidate( if callable(finish): try: if accepted: - finish(block_hash=block_hash) + self._run_block_submitter_ledger_call( + ("finalize", block_hash, "submitted"), + "finalize-outbox-submitted", + lambda: finish(block_hash=block_hash), + ) else: - finish(block_hash=block_hash, error=error) + self._run_block_submitter_ledger_call( + ("finalize", block_hash, "abandoned"), + "finalize-outbox-abandoned", + lambda: finish(block_hash=block_hash, error=error), + ) # The invalidation tombstone is needed until the durable # outbox becomes terminal. A normal return (including an # already-terminal/missing row) means there is no pending @@ -24066,7 +24650,10 @@ def _payout_balance_serializer_released(self) -> Iterator[None]: try: yield finally: - self._payout_balance_mutation_lock.acquire() + self._acquire_block_submitter_lock( + self._payout_balance_mutation_lock, + "payout-balance-mutation", + ) def _replayed_payout_window_reproducible( self, @@ -24130,6 +24717,7 @@ def _land_and_confirm_block_candidate( current_tip: str, already_active: bool, worker: str | None, + node_submission: _BlockCandidateNodeSubmission, revalidated_append_epoch: int | None = None, ) -> tuple[ dict[str, Any], @@ -24142,10 +24730,10 @@ def _land_and_confirm_block_candidate( The balance serializer spans the last prior-state check through durable confirmation. Reconciliation therefore cannot change the base beneath the accepted coinbase, while ordinary job delivery remains unblocked. - submitblock always runs first; the audit bundle build and verification - then execute with the serializer temporarily released (the landed - fence stays armed), so neither block announcement nor job delivery - waits on audit construction. + The caller has already run submitblock on the lock/DB-free fast lane. + The audit bundle build and verification execute with the serializer + temporarily released (the landed fence stays armed), so neither block + announcement nor job delivery waits on audit construction. """ context = candidate.context submission = candidate.submission @@ -24156,7 +24744,10 @@ def _land_and_confirm_block_candidate( durable_payout_state = bool( getattr(self.ledger, "durable_payout_state", False) ) - with self._payout_balance_mutation_lock: + with self._block_submitter_lock( + self._payout_balance_mutation_lock, + "payout-balance-mutation", + ): if self._defer_for_pending_parent_payout_transition( block_hash=block_hash, parent_hash=parent_hash, @@ -24316,7 +24907,7 @@ def _land_and_confirm_block_candidate( stale_job_class="balance_stale", ) return None - if not already_active: + if not already_active and not node_submission.attempted: before_height = int(self.rpc.call("getblockcount")) if before_height + 1 != expected_height: self._abandon_block_candidate( @@ -24327,7 +24918,8 @@ def _land_and_confirm_block_candidate( expected_height=expected_height, ) return None - # Register before submitblock can expose this hash as the new + if not already_active: + # Register before a fallback submitblock can expose this hash as the new # tip. Child builders will wait for the verified preview rather # than reading balances that omit their new parent. self._begin_accepted_block_payout_preview( @@ -24341,61 +24933,54 @@ def _land_and_confirm_block_candidate( block_hash, block_height=expected_height, ) - self._record_heartbeat("block_submitter") - self._require_fresh_ledger_lease_for_external_side_effect( - "submitblock" - ) - # The epoch fence above is advisory: it releases the lock - # after one read, so an append-side bump could still commit - # between that read and the RPC below. This one is - # authoritative -- the bump acquires the same fence lock, so - # holding it across submitblock means no late-visible append - # can advance the epoch between this comparison and the - # block entering qbitd. The lock spans exactly one RPC and - # only on this boundary; ordinary share commits never touch - # it (the append side takes it only for rows that predate a - # live anchor, and this landing's own declared anchor stays - # exposed for the landing's duration). - result: object = None - append_epoch_raced = False - if ( - effective_append_epoch is None - or getattr(context, "collection_only", False) - ): - result = self.rpc.call( - "submitblock", [submission.block_hex] - ) - else: - with self._payout_append_landing_fence_lock: - with self._job_cache_lock: - live_append_epoch = int( - self._payout_ledger_append_invalidation_epoch - ) - if live_append_epoch != effective_append_epoch: - append_epoch_raced = True - else: - result = self.rpc.call( - "submitblock", [submission.block_hex] - ) - if append_epoch_raced: - self._abandon_block_candidate( - PRISM_REJECTION_STALE_JOB, - "payout window was invalidated by a late-visible share append", - block_hash=block_hash, - worker=worker, - expected_height=expected_height, - stale_job_class="append_epoch_stale", - ) - return None - self._record_heartbeat("block_submitter") - landed_monotonic = getattr(candidate, "landed_monotonic", None) - if landed_monotonic is not None: - # Observed for every attempt whose RPC returned, accepted - # or rejected: a rejected race is exactly the tail this - # histogram exists to expose. - self._observe_block_submit_seconds( - time.monotonic() - float(landed_monotonic) + if not node_submission.attempted: + self._require_fresh_ledger_lease_for_external_side_effect( + "submitblock" ) + # The epoch fence above is advisory: it releases the lock + # after one read, so an append-side bump could still commit + # between that read and the RPC below. This one is + # authoritative -- the bump acquires the same fence lock, so + # holding it across submitblock means no late-visible append + # can advance the epoch between this comparison and the + # block entering qbitd. The lock spans exactly one RPC and + # only on this boundary; ordinary share commits never touch + # it (the append side takes it only for rows that predate a + # live anchor, and this landing's own declared anchor stays + # exposed for the landing's duration). + append_epoch_raced = False + if ( + effective_append_epoch is None + or getattr(context, "collection_only", False) + ): + node_submission = self._submit_block_candidate_to_node( + candidate + ) + else: + with self._payout_append_landing_fence_lock: + with self._job_cache_lock: + live_append_epoch = int( + self._payout_ledger_append_invalidation_epoch + ) + if live_append_epoch != effective_append_epoch: + append_epoch_raced = True + else: + node_submission = ( + self._submit_block_candidate_to_node(candidate) + ) + if append_epoch_raced: + self._abandon_block_candidate( + PRISM_REJECTION_STALE_JOB, + "payout window was invalidated by a late-visible share append", + block_hash=block_hash, + worker=worker, + expected_height=expected_height, + stale_job_class="append_epoch_stale", + ) + return None + if node_submission.error is not None: + raise node_submission.error + result = node_submission.result if result not in (None, "duplicate"): self._abandon_block_candidate( PRISM_REJECTION_SUBMITBLOCK_REJECTED, @@ -24445,7 +25030,7 @@ def _land_and_confirm_block_candidate( return None self._publish_accepted_block_payout_preview(block_hash, preview) - self._record_heartbeat("block_submitter") + self._record_block_submitter_phase("audit-build") # The bundle derives only from inputs frozen on the candidate # (share window, prior balances, extranonces, template fields), # so the serializer is released around the builder/verifier @@ -24519,6 +25104,7 @@ def _land_and_confirm_block_candidate( payout_commit_source: int | None = None try: with self._payout_balance_serializer_released(): + self._record_block_submitter_phase("audit-verify") report = self.verify_bundle( candidate_bundle_path, submission.coinbase_tx_hex, @@ -24539,7 +25125,7 @@ def _land_and_confirm_block_candidate( prior_balances=context.prior_balances, ) ) - self._record_heartbeat("block_submitter") + self._record_block_submitter_phase("audit-verify:complete") if not already_confirmed: if preview is None and durable_payout_state: live_prior_balances = self.settlement_balances_by_program( @@ -24587,6 +25173,7 @@ def _land_and_confirm_block_candidate( # and bulk SQL without owning the delivery gate. payout_commit_started = time.monotonic() payout_commit_source = self._capture_payout_state_source()[1] + self._record_block_submitter_phase("persist-accepted-block") persistence = self.ledger.persist_accepted_block( block_hash=submission.block_hash_hex, block_height=expected_height, @@ -24595,7 +25182,7 @@ def _land_and_confirm_block_candidate( audit_report=report, canonical_bundle_path=persistence_canonical_bundle_path, ) - self._record_heartbeat("block_submitter") + self._record_block_submitter_phase("persist-accepted-block:complete") active_hash = str( self.rpc.call("getblockhash", [expected_height]) ).lower() @@ -24788,7 +25375,12 @@ def _land_and_confirm_block_candidate( pass @ledger_writer_operation("accepted_block_handling") - def submit_block_candidate(self, candidate: PrismBlockCandidate) -> bool: + def submit_block_candidate( + self, + candidate: PrismBlockCandidate, + *, + node_submission: _BlockCandidateNodeSubmission | None = None, + ) -> bool: """Land one block candidate, then finalize its audit and payout state. Runs on the block-submitter thread (tests call it synchronously). It @@ -24801,10 +25393,18 @@ def submit_block_candidate(self, candidate: PrismBlockCandidate) -> bool: after that finalization completes. """ block_hash = str(candidate.submission.block_hash_hex).lower() + if node_submission is None: + node_submission = self._node_submission_for_direct_candidate(candidate) with self._block_candidate_disposition(block_hash): - return self._submit_block_candidate_serialized(candidate) + return self._submit_block_candidate_serialized( + candidate, + node_submission=node_submission, + ) - def _record_block_candidate_progress(self) -> None: + def _record_block_candidate_progress( + self, + phase: str = "accounting-progress", + ) -> None: """Stamp the submitter heartbeat at a candidate-disposition boundary. Stamps come only from the dedicated submitter thread: dispositions @@ -24822,11 +25422,13 @@ def _record_block_candidate_progress(self) -> None: owner = getattr(self, "_block_submitter_thread_ident", None) if owner is None or threading.get_ident() != owner: return - self._record_heartbeat("block_submitter") + self._record_block_submitter_phase(phase) def _submit_block_candidate_serialized( self, candidate: PrismBlockCandidate, + *, + node_submission: _BlockCandidateNodeSubmission, ) -> bool: """Process a candidate while its same-hash disposition guard is held.""" outcome = getattr(self, "_block_candidate_outcome", None) @@ -24846,7 +25448,16 @@ def _submit_block_candidate_serialized( # outbox replay, retained retry) marks its hash outstanding so tip # observations arriving on other threads can register acceptance. self._register_outstanding_block_candidate(block_hash) - self._record_block_candidate_progress() + self._record_block_candidate_progress("disposition-start") + if ( + self._block_candidate_acceptance_recorded(block_hash) + and node_submission.error is not None + ): + # A concurrent same-hash pass completed the success tail while + # this duplicate-safe node offer waited for disposition. Do not + # recreate its payout transition or accounting work. + self._clear_accepted_block_payout_preview(block_hash) + return True with self.lock: pool_closed = ( self.accepted_block_count >= self.max_blocks @@ -24873,8 +25484,24 @@ def _submit_block_candidate_serialized( expected_height=expected_height, ) return False - current_tip = str(self.rpc.call("getbestblockhash")) - self._record_block_candidate_progress() + self._record_block_candidate_progress("current-tip-rpc") + observed_tip = str(self.rpc.call("getbestblockhash")) + self._record_block_candidate_progress("current-tip-rpc:complete") + # A successful or transport-ambiguous fast-lane call can change the + # tip before this post-submit probe. It is still a *fresh* attempt, + # not an active replay: run the normal validation/persistence tail + # against the candidate's stamped parent. A later getblockhash check + # proves a successful acknowledgement, while an ambiguous transport + # outcome stays pending for duplicate-safe replay. Duplicate replies + # are replay evidence and retain the live-tip classification. + fresh_or_uncertain_submit = bool( + node_submission.attempted + and ( + node_submission.error is not None + or node_submission.result is None + ) + ) + current_tip = parent_hash if fresh_or_uncertain_submit else observed_tip landed_height: int | None = None if current_tip.lower() == block_hash: landed_height = expected_height @@ -24928,6 +25555,20 @@ def _submit_block_candidate_serialized( stale_job_class="tip_moved", ) return accepted_race_won + if ( + node_submission.attempted + and node_submission.error is None + and node_submission.result not in (None, "duplicate") + and not already_active + ): + self._abandon_block_candidate( + PRISM_REJECTION_SUBMITBLOCK_REJECTED, + f"submitblock rejected candidate: {node_submission.result}", + block_hash=block_hash, + worker=worker, + expected_height=expected_height, + ) + return False # A reconstructed candidate revalidates BEFORE the balance # serializer: the audit share-window replay is the slow oracle walk # and takes the ledger writer lock, so running it inside @@ -25012,6 +25653,7 @@ def _submit_block_candidate_serialized( current_tip=current_tip, already_active=already_active, worker=worker, + node_submission=node_submission, revalidated_append_epoch=revalidated_append_epoch, ) finally: @@ -25019,7 +25661,7 @@ def _submit_block_candidate_serialized( if landed is None: return False final_bundle, report, persistence, confirmation = landed - self._record_block_candidate_progress() + self._record_block_candidate_progress("durable-accounting:complete") with self.lock: already_accounted = block_hash in self._accounted_accepted_block_hashes if already_accounted: @@ -25036,7 +25678,7 @@ def _submit_block_candidate_serialized( manifest_set=ctv_manifest_set, manifest_set_sha256=sha256_json_hex(ctv_manifest_set), ) - self._record_block_candidate_progress() + self._record_block_candidate_progress("ctv-manifest-persist:complete") final_bundle_path = ( self.audit_dir / f"prism-live-audit-bundle-{expected_height}-{block_hash}.json" @@ -25049,7 +25691,7 @@ def _submit_block_candidate_serialized( persistence=persistence, ) self.prune_audit_artifacts(keep_live_path=final_bundle_path) - self._record_block_candidate_progress() + self._record_block_candidate_progress("audit-envelope-write:complete") bundle_path = final_bundle_path if candidate.credit_share_on_accept: self.append_accepted_share( @@ -25072,7 +25714,7 @@ def _submit_block_candidate_serialized( template_artifacts.network_difficulty, bypass_build_interval=True, ) - self._record_block_candidate_progress() + self._record_block_candidate_progress("accepted-share-credit:complete") # Aggregate counts only: materializing the whole share history # (all_shares) here would scan the full ledger twice per block, # and would grow without bound as the ledger grows. The counters are @@ -25098,7 +25740,7 @@ def _submit_block_candidate_serialized( "job_share_count": len(context.shares_json), } self.evidence_path.write_text(json.dumps(evidence, indent=2), encoding="utf-8") - self._record_block_candidate_progress() + self._record_block_candidate_progress("evidence-write:complete") with self.lock: newly_accounted = block_hash not in self._accounted_accepted_block_hashes if newly_accounted: @@ -25268,22 +25910,39 @@ def verify_bundle( *, expected_coinbase_value_sats: int, ) -> dict[str, Any]: - completed = subprocess.run( - prism_tool_command("qbit-prism-audit-verify") - + [ - str(bundle_path), - "--coinbase-tx-hex", - coinbase_tx_hex, - "--ledger-writer-public-key-hex", - ledger_writer_public_key_hex, - "--expected-coinbase-value-sats", - str(expected_coinbase_value_sats), - ], - text=True, - stdout=subprocess.PIPE, - stderr=subprocess.PIPE, - check=False, + timeout_seconds = max( + 0.001, + float( + getattr( + self, + "bundle_build_timeout_seconds", + DEFAULT_PRISM_BUNDLE_BUILD_TIMEOUT_SECONDS, + ) + ), ) + try: + completed = subprocess.run( + prism_tool_command("qbit-prism-audit-verify") + + [ + str(bundle_path), + "--coinbase-tx-hex", + coinbase_tx_hex, + "--ledger-writer-public-key-hex", + ledger_writer_public_key_hex, + "--expected-coinbase-value-sats", + str(expected_coinbase_value_sats), + ], + text=True, + stdout=subprocess.PIPE, + stderr=subprocess.PIPE, + check=False, + timeout=timeout_seconds, + ) + except subprocess.TimeoutExpired as exc: + raise RuntimeError( + "qbit-prism-audit-verify timed out after " + f"{timeout_seconds:g}s" + ) from exc if completed.returncode != 0: raise RuntimeError(f"qbit-prism-audit-verify failed: {completed.stderr}") return json.loads(completed.stdout) diff --git a/lab/prism/share_ledger.py b/lab/prism/share_ledger.py index 7582a060..86c3be40 100644 --- a/lab/prism/share_ledger.py +++ b/lab/prism/share_ledger.py @@ -20,7 +20,7 @@ from datetime import datetime, timedelta, timezone from decimal import Decimal from pathlib import Path -from threading import BoundedSemaphore, Lock, Thread +from threading import BoundedSemaphore, Lock, Thread, local from typing import Any, Callable, Iterator from lab.prism.prism_tools import prism_tool_command @@ -42,6 +42,10 @@ VALID_CREDIT_POLICIES = frozenset({"stale-grace"}) +class LedgerOperationTimeout(TimeoutError): + """A caller-scoped PostgreSQL deadline expired before work completed.""" + + class _AuditShareSegmentConflict(RuntimeError): """A share sequence is bound to more than one audit payload.""" @@ -1565,13 +1569,25 @@ def __init__(self, conninfo: str, *, pool_size: int): def pool_size(self) -> int: return self._pool_size - def _connect(self) -> Any: - return self._psycopg.connect(self._conninfo, autocommit=True) + def _connect(self, timeout_seconds: float | None = None) -> Any: + kwargs: dict[str, Any] = {"autocommit": True} + if timeout_seconds is not None: + # libpq accepts integral connect_timeout seconds. Rounding up keeps + # sub-second statement budgets valid without silently disabling + # the connection deadline. + kwargs["connect_timeout"] = max(1, math.ceil(timeout_seconds)) + return self._psycopg.connect(self._conninfo, **kwargs) @contextmanager - def connection(self) -> Iterator[Any]: + def connection(self, *, timeout_seconds: float | None = None) -> Iterator[Any]: """Borrow a pooled connection; discard it if the caller raises.""" - self._slots.acquire() + started = time.monotonic() + if timeout_seconds is None: + acquired = self._slots.acquire() + else: + acquired = self._slots.acquire(timeout=max(0.0, timeout_seconds)) + if not acquired: + raise LedgerOperationTimeout("timed out waiting for a postgres pool slot") conn = None try: with self._idle_lock: @@ -1580,7 +1596,13 @@ def connection(self) -> Iterator[Any]: if self._idle: conn = self._idle.pop() if conn is None or conn.closed: - conn = self._connect() + connect_timeout = timeout_seconds + if connect_timeout is not None: + connect_timeout = max( + 0.001, + connect_timeout - (time.monotonic() - started), + ) + conn = self._connect(connect_timeout) yield conn except BaseException: if conn is not None: @@ -1604,7 +1626,13 @@ def connection(self) -> Iterator[Any]: finally: self._slots.release() - def run_json(self, sql: str, *, retry_safe: bool = False) -> Any: + def run_json( + self, + sql: str, + *, + retry_safe: bool = False, + timeout_seconds: float | None = None, + ) -> Any: """Run one JSON-returning statement. An ``OperationalError`` does not reveal whether PostgreSQL committed @@ -1613,10 +1641,46 @@ def run_json(self, sql: str, *, retry_safe: bool = False) -> Any: mutation fails after the first ambiguous execution. """ attempts = 2 if retry_safe else 1 + deadline = ( + None + if timeout_seconds is None + else time.monotonic() + max(0.0, timeout_seconds) + ) for attempt in range(attempts): try: - with self.connection() as conn: - row = conn.execute(sql).fetchone() + remaining = ( + None + if deadline is None + else max(0.0, deadline - time.monotonic()) + ) + if remaining is not None and remaining <= 0: + raise LedgerOperationTimeout("postgres statement deadline expired") + connection = ( + self.connection() + if remaining is None + else self.connection(timeout_seconds=remaining) + ) + with connection as conn: + if deadline is None: + row = conn.execute(sql).fetchone() + else: + remaining = deadline - time.monotonic() + if remaining <= 0: + raise LedgerOperationTimeout( + "postgres statement deadline expired" + ) + timeout_ms = max(1, int(remaining * 1000)) + # SET LOCAL confines both guards to this explicit + # transaction, so pooled connections cannot leak a + # submitter-specific deadline into unrelated work. + with conn.transaction(): + conn.execute( + f"SET LOCAL statement_timeout = '{timeout_ms}ms'" + ) + conn.execute( + f"SET LOCAL lock_timeout = '{timeout_ms}ms'" + ) + row = conn.execute(sql).fetchone() return parse_single_json_value(row[0] if row else None) except self._psycopg.OperationalError as exc: if attempt + 1 >= attempts: @@ -1790,6 +1854,8 @@ def __init__( self._lease_retry_max_sleep_seconds = lease_retry_max_sleep_seconds self._lease_retry_min_sleep_seconds = min(0.25, self._lease_retry_max_sleep_seconds) self._lease_adoption_silence_seconds = lease_adoption_silence_seconds + self._operation_timeout_local = local() + self._statement_timeout_local = local() self._lock = Lock() self._read_semaphore = BoundedSemaphore(read_concurrency) self._audit_body_dir = Path(audit_body_dir) if audit_body_dir else None @@ -1971,6 +2037,116 @@ def writer_lease_last_refresh_monotonic(self) -> float | None: def backend_name(self) -> str: return "postgres-psql" + @contextmanager + def operation_timeout(self, timeout_seconds: float) -> Iterator[None]: + """Bound PostgreSQL and local admission for the current thread. + + The block submitter uses this scope for direct outbox operations. + Nested scopes keep the earliest deadline, so helper calls cannot + accidentally widen the caller's liveness budget. + """ + timeout_seconds = float(timeout_seconds) + if not math.isfinite(timeout_seconds) or timeout_seconds <= 0: + raise ValueError("operation timeout must be finite and positive") + timeout_local = getattr(self, "_operation_timeout_local", None) + if timeout_local is None: + timeout_local = local() + self._operation_timeout_local = timeout_local + previous = getattr(timeout_local, "deadline", None) + deadline = time.monotonic() + timeout_seconds + timeout_local.deadline = ( + deadline if previous is None else min(float(previous), deadline) + ) + try: + yield + finally: + if previous is None: + try: + del timeout_local.deadline + except AttributeError: + pass + else: + timeout_local.deadline = previous + + @contextmanager + def statement_timeout(self, timeout_seconds: float) -> Iterator[None]: + """Apply a fresh bound to each lock admission and SQL statement. + + Unlike ``operation_timeout``, this budget does not start counting down + across non-database work between calls. The block accounting tail can + therefore build and verify an audit bundle before giving each later + Postgres step its own short deadline. + """ + timeout_seconds = float(timeout_seconds) + if not math.isfinite(timeout_seconds) or timeout_seconds <= 0: + raise ValueError("statement timeout must be finite and positive") + timeout_local = getattr(self, "_statement_timeout_local", None) + if timeout_local is None: + timeout_local = local() + self._statement_timeout_local = timeout_local + previous = getattr(timeout_local, "timeout_seconds", None) + timeout_local.timeout_seconds = ( + timeout_seconds + if previous is None + else min(float(previous), timeout_seconds) + ) + try: + yield + finally: + if previous is None: + try: + del timeout_local.timeout_seconds + except AttributeError: + pass + else: + timeout_local.timeout_seconds = previous + + def _remaining_operation_timeout(self) -> float | None: + timeout_local = getattr(self, "_operation_timeout_local", None) + deadline = ( + getattr(timeout_local, "deadline", None) + if timeout_local is not None + else None + ) + statement_timeout_local = getattr( + self, + "_statement_timeout_local", + None, + ) + statement_timeout_seconds = ( + getattr(statement_timeout_local, "timeout_seconds", None) + if statement_timeout_local is not None + else None + ) + if deadline is None: + return ( + None + if statement_timeout_seconds is None + else float(statement_timeout_seconds) + ) + remaining = float(deadline) - time.monotonic() + if remaining <= 0: + raise LedgerOperationTimeout("postgres operation deadline expired") + if statement_timeout_seconds is not None: + remaining = min(remaining, float(statement_timeout_seconds)) + return remaining + + @contextmanager + def _operation_gate(self, gate: Any, name: str) -> Iterator[None]: + """Acquire a ledger lock/semaphore within the caller's deadline.""" + remaining = self._remaining_operation_timeout() + acquired = ( + gate.acquire() + if remaining is None + else gate.acquire(timeout=max(0.0, remaining)) + ) + if not acquired: + raise LedgerOperationTimeout(f"timed out waiting for postgres {name}") + try: + yield + finally: + gate.release() + def append(self, pending: PendingShare) -> AcceptedShareRecord: if pending.share_difficulty <= 0: raise ValueError("share_difficulty must be positive") @@ -2076,7 +2252,7 @@ def append(self, pending: PendingShare) -> AcceptedShareRecord: # Serialize the single writer through its durable commit and cache note. # Stats reconciliation uses a separate read connection plus a share-seq # watermark, so it never acquires this writer lock. - with self._lock: + with self._operation_gate(self._lock, "writer lock"): result = self._run_json(sql) if "error" in result: raise RuntimeError(str(result["error"])) @@ -2307,7 +2483,7 @@ def append_batch( ) END; """ - with self._lock: + with self._operation_gate(self._lock, "writer lock"): result = self._run_json(sql) if "error" in result: raise RuntimeError(str(result["error"])) @@ -2409,7 +2585,7 @@ def pending_block_candidate_rows(self, *, limit: int = 32) -> list[dict[str, Any LIMIT {int(limit)} ) pending; """ - with self._lock: + with self._operation_gate(self._lock, "writer lock"): return list(self._run_retry_safe_read_json(sql)) def block_candidate_pending_metrics(self) -> dict[str, int | float]: @@ -2432,7 +2608,7 @@ def block_candidate_pending_metrics(self) -> dict[str, int | float]: FROM qbit_block_candidate_outbox WHERE state = 'pending'; """ - with self._lock: + with self._operation_gate(self._lock, "writer lock"): metrics = self._run_retry_safe_read_json(sql) return { "pending_count": int(metrics.get("pending_count", 0)), @@ -2720,7 +2896,7 @@ def all_shares(self) -> list[AcceptedShareRecord]: FROM qbit_share_ledger WHERE accepted; """ - with self._lock: + with self._operation_gate(self._lock, "writer lock"): return [ self._record_from_json(item) for item in self._run_retry_safe_read_json(sql) @@ -2925,7 +3101,7 @@ def current_owed_balances(self) -> list[dict[str, object]]: FROM qbit_current_owed_balances() WHERE owed_balance_sats > 0; """ - with self._lock: + with self._operation_gate(self._lock, "writer lock"): balances = self._run_retry_safe_read_json(sql) for balance in balances: balance["balance_sats"] = int(balance["balance_sats"]) @@ -2986,7 +3162,7 @@ def current_prior_balances(self) -> list[dict[str, object]]: ) ORDER BY payout_order_key, miner_id, encode(p2mr_program, 'hex')), '[]'::json) FROM qbit_current_carry_forward_balances(); """ - with self._lock: + with self._operation_gate(self._lock, "writer lock"): balances = self._run_retry_safe_read_json(sql) for balance in balances: balance["balance_sats"] = int(balance["balance_sats"]) @@ -2994,7 +3170,7 @@ def current_prior_balances(self) -> list[dict[str, object]]: def carry_forward_integrity_report(self) -> dict[str, object]: sql = "SELECT qbit_carry_forward_integrity_report();" - with self._lock: + with self._operation_gate(self._lock, "writer lock"): report = self._run_retry_safe_read_json(sql) audit_head = self._carry_forward_audit_head_locked() report["backend"] = "postgres-psql" @@ -3079,7 +3255,7 @@ def audit_share_window( {int(network_difficulty)}::numeric ); """ - with self._lock: + with self._operation_gate(self._lock, "writer lock"): rows = self._run_retry_safe_read_json(sql) for row in rows: for key in ( @@ -3109,7 +3285,7 @@ def audit_block_payouts(self, *, block_hash: str) -> list[dict[str, object]]: ) ORDER BY payout_order_key, miner_id, encode(p2mr_program, 'hex')), '[]'::json) FROM qbit_audit_block_payouts({self._text_literal(block_hash)}); """ - with self._lock: + with self._operation_gate(self._lock, "writer lock"): rows = self._run_retry_safe_read_json(sql) for row in rows: row["carry_forward_balance_sats"] = int(row["carry_forward_balance_sats"]) @@ -3144,7 +3320,7 @@ def recipient_payout_history(self, *, recipient_id: str, limit: int = 50) -> lis JOIN qbit_pool_blocks block ON block.block_hash = payout.block_hash; """ - with self._lock: + with self._operation_gate(self._lock, "writer lock"): rows = self._run_retry_safe_read_json(sql) for row in rows: row["carry_forward_balance_sats"] = int(row["carry_forward_balance_sats"]) @@ -3653,7 +3829,7 @@ def audit_bundle(self, *, block_hash: str) -> dict[str, object] | None: 'null'::json ); """ - with self._lock: + with self._operation_gate(self._lock, "writer lock"): row = self._run_retry_safe_read_json(sql) return self._resolve_audit_bundle_row(row) @@ -3684,7 +3860,7 @@ def audit_bundle_by_commitment(self, *, commitment_leaf_hex: str) -> dict[str, o 'null'::json ); """ - with self._lock: + with self._operation_gate(self._lock, "writer lock"): row = self._run_retry_safe_read_json(sql) return self._resolve_audit_bundle_row(row) @@ -4481,7 +4657,7 @@ def metrics(self) -> dict[str, int]: 'ctv_fanouts_failed', (SELECT count(*) FROM qbit_ctv_fanout_artifacts WHERE settlement_status = 'failed') ); """ - with self._lock: + with self._operation_gate(self._lock, "writer lock"): metrics = self._run_retry_safe_read_json(sql) report = {str(key): int(value) for key, value in metrics.items()} report["shares"] = accepted_share_count @@ -6747,7 +6923,7 @@ def pool_block_state(self, *, block_hash: str) -> dict[str, object] | None: ) ); """ - with self._lock: + with self._operation_gate(self._lock, "writer lock"): result = self._run_retry_safe_read_json(sql) if not isinstance(result, dict): raise RuntimeError("pool block state query returned non-object JSON") @@ -6773,7 +6949,7 @@ def reorg_watch_blocks(self, *, active_tip_height: int) -> list[dict[str, object AND maturity_state = 'immature' ; """ - with self._lock: + with self._operation_gate(self._lock, "writer lock"): rows = self._run_retry_safe_read_json(sql) for row in rows: row["block_height"] = int(row["block_height"]) @@ -6855,21 +7031,28 @@ def mark_mature_pool_payouts(self, *, active_tip_height: int) -> dict[str, int | def __len__(self) -> int: sql = "SELECT json_build_object('count', count(*)) FROM qbit_share_ledger WHERE accepted;" - with self._lock: + with self._operation_gate(self._lock, "writer lock"): return int(self._run_retry_safe_read_json(sql)["count"]) def _run_fenced_json(self, sql: str) -> Any: - with self._lock: + with self._operation_gate(self._lock, "writer lock"): return self._run_json(sql) def _run_read_json(self, sql: str) -> Any: - with self._read_semaphore: + with self._operation_gate(self._read_semaphore, "read slot"): return self._run_retry_safe_read_json(sql) def _run_retry_safe_read_json(self, sql: str) -> Any: native = getattr(self, "_native", None) if native is not None: - return native.run_json(sql, retry_safe=True) + timeout_seconds = self._remaining_operation_timeout() + if timeout_seconds is None: + return native.run_json(sql, retry_safe=True) + return native.run_json( + sql, + retry_safe=True, + timeout_seconds=timeout_seconds, + ) return self._run_json(sql) def _ensure_writer_lease(self) -> None: @@ -7390,7 +7573,10 @@ def _run_fresh_connection_json(self, sql: str) -> Any: def _run_json(self, sql: str) -> Any: native = getattr(self, "_native", None) if native is not None: - return native.run_json(sql) + timeout_seconds = self._remaining_operation_timeout() + if timeout_seconds is None: + return native.run_json(sql) + return native.run_json(sql, timeout_seconds=timeout_seconds) output = self._run_sql(sql).strip() if not output: raise RuntimeError("psql query returned no JSON") @@ -7413,14 +7599,40 @@ def _run_sql(self, sql: str) -> str: "--no-align", "--quiet", ] - completed = subprocess.run( - cmd, - input=sql, - text=True, - stdout=subprocess.PIPE, - stderr=subprocess.PIPE, - check=False, - ) + timeout_seconds = self._remaining_operation_timeout() + run_kwargs: dict[str, Any] = {} + if timeout_seconds is not None: + timeout_ms = max(1, int(timeout_seconds * 1000)) + subprocess_env = dict(os.environ) + existing_options = subprocess_env.get("PGOPTIONS", "").strip() + timeout_options = ( + f"-c statement_timeout={timeout_ms}ms " + f"-c lock_timeout={timeout_ms}ms" + ) + subprocess_env["PGOPTIONS"] = " ".join( + option for option in (existing_options, timeout_options) if option + ) + subprocess_env["PGCONNECT_TIMEOUT"] = str( + max(1, math.ceil(timeout_seconds)) + ) + run_kwargs = { + "env": subprocess_env, + "timeout": timeout_seconds, + } + try: + completed = subprocess.run( + cmd, + input=sql, + text=True, + stdout=subprocess.PIPE, + stderr=subprocess.PIPE, + check=False, + **run_kwargs, + ) + except subprocess.TimeoutExpired as exc: + raise LedgerOperationTimeout( + f"psql operation exceeded {timeout_seconds:g}s" + ) from exc if completed.returncode != 0: raise RuntimeError( "psql command failed " diff --git a/tests/test_prism_coordinator_vardiff.py b/tests/test_prism_coordinator_vardiff.py index fab1afd8..21714279 100644 --- a/tests/test_prism_coordinator_vardiff.py +++ b/tests/test_prism_coordinator_vardiff.py @@ -8,6 +8,7 @@ import os import queue import socket +import subprocess import tempfile import threading import time @@ -295,6 +296,13 @@ def call(self, method: str, params: list[object] | None = None) -> object: return super().call(method, params) +class RejectingSubmitTipRpc(TipRpc): + def call(self, method: str, params: list[object] | None = None) -> object: + if method == "submitblock": + return "bad-prevblk" + return super().call(method, params) + + class ParentTipRpc(TipRpc): def __init__(self, *, tip: str, parent: str) -> None: super().__init__(tip) @@ -8051,7 +8059,10 @@ def active_ancestor_call( ) self.assertFalse(accepted) - self.assertEqual(submit_calls, []) + # Node propagation is the fast lane: the durable descendant is offered + # to qbitd before payout/accounting notices the ancestor transition. + # Its accounting still defers until that ancestor is durable. + self.assertEqual(submit_calls, ["submitblock"]) self.assertEqual(ledger.persisted, []) self.assertEqual( server._block_candidate_outcome.reason, @@ -8842,6 +8853,63 @@ def ordered_build(**_kwargs: object) -> dict[str, object]: self.assertEqual(len(ledger.persisted), 1) self.assertEqual(len(ledger.confirmed), 1) + def test_submitter_offers_block_before_writer_admission_with_rpc_deadline(self) -> None: + server, state, _ledger = submit_coordinator() + server.block_submit_rpc_timeout_seconds = 0.75 + order: list[object] = [] + + class TimeoutRecordingRpc(TipRpc): + def call( + self, + method: str, + params: list[object] | None = None, + *, + timeout: float | None = None, + ) -> object: + if method == "submitblock": + order.append(("submitblock", timeout)) + return None + return super().call(method, params) + + class WriterAdmission: + def __enter__(self) -> None: + order.append("writer-admission") + + def __exit__(self, *_args: object) -> None: + return None + + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="00", + block_hash_hex="ce" * 32, + block_hex="00", + share_pass=True, + block_pass=True, + ), + ) + server.rpc = TimeoutRecordingRpc("00" * 32) + server._writer_operation = lambda _component: WriterAdmission() # type: ignore[method-assign] + + def account( + _candidate: PrismBlockCandidate, + *, + node_submission: object, + ) -> bool: + order.append("accounting") + self.assertIsNone(getattr(node_submission, "result")) + return True + + server._submit_next_block_candidate_writer = account # type: ignore[method-assign] + server.enqueue_block_candidate(candidate) + + self.assertTrue(server.submit_next_block_candidate()) + self.assertEqual( + order, + [("submitblock", 0.75), "writer-admission", "accounting"], + ) + def test_block_submit_histogram_measures_landed_to_rpc_interval(self) -> None: # The race-critical span (candidate landed -> submitblock returned) # must be observed exactly once per attempted submit, independent of @@ -8922,6 +8990,7 @@ def test_orphaned_block_candidate_keeps_share_credit(self) -> None: submission = SimpleNamespace( header_hex="aa" * 80, block_hash_hex="cc" * 32, + block_hex="00", share_pass=True, block_pass=True, ) @@ -8937,7 +9006,7 @@ def test_orphaned_block_candidate_keeps_share_credit(self) -> None: self.assertEqual(len(ledger.all_shares()), 1) # The tip moves before the submitter drains the candidate. - server.rpc = TipRpc(new_tip) + server.rpc = RejectingSubmitTipRpc(new_tip) self.assertTrue(server.submit_next_block_candidate()) @@ -9456,7 +9525,7 @@ def clear_while_accepting( block_hash, block_height=10, ) - server.rpc = TipRpc(new_tip) + server.rpc = RejectingSubmitTipRpc(new_tip) server.enqueue_block_candidate(candidate) self.assertTrue(server.submit_next_block_candidate()) @@ -9575,7 +9644,14 @@ def accepting_submit(_candidate: PrismBlockCandidate) -> bool: server.submit_block_candidate = accepting_submit # type: ignore[method-assign] original_finish = ledger.mark_block_candidate_submitted + original_mark_attempted = ledger.mark_block_candidate_attempted finish_attempts = 0 + attempt_marks = 0 + + def mark_attempted(*, block_hash: str) -> bool: + nonlocal attempt_marks + attempt_marks += 1 + return original_mark_attempted(block_hash=block_hash) def flaky_finish(*, block_hash: str) -> bool: nonlocal finish_attempts @@ -9584,6 +9660,7 @@ def flaky_finish(*, block_hash: str) -> bool: raise RuntimeError("ledger unavailable") return original_finish(block_hash=block_hash) + ledger.mark_block_candidate_attempted = mark_attempted # type: ignore[method-assign] ledger.mark_block_candidate_submitted = flaky_finish # type: ignore[method-assign] waits: list[float] = [] with patch.object( @@ -9609,6 +9686,7 @@ def flaky_finish(*, block_hash: str) -> bool: ): self.assertAlmostEqual(observed, expected) self.assertEqual(finish_attempts, 5) + self.assertEqual(attempt_marks, 1) self.assertEqual(submit_calls, 1) self.assertNotIn(candidate.submission.block_hash_hex, server.block_candidate_retry_delays) self.assertEqual(server.block_candidate_abandoned_counts, {}) @@ -9619,6 +9697,121 @@ def flaky_finish(*, block_hash: str) -> bool: server.metrics_payload(), ) + def test_crash_after_submit_before_attempt_mark_replays_duplicate_once(self) -> None: + parent_hash = "00" * 32 + block_hash = "cf" * 32 + ledger = SingleWriterShareLedger() + first, state, _recording = submit_coordinator(tip=parent_hash) + first.ledger = ledger + first.stop_after_block = False + first.max_blocks = 10 + pending = self._pending_append("submit-before-mark-crash").pending_share + candidate = block_candidate( + first, + state, + SimpleNamespace( + coinbase_tx_hex="c0ffee", + block_hash_hex=block_hash, + block_hex="00", + share_pass=True, + block_pass=True, + ), + pending_share=pending, + ) + intent = first.block_candidate_intent(candidate) + ledger.append_batch([(pending, intent)]) + + class RestartAwareRpc(FakeRpc): + def __init__(self) -> None: + self.submit_results: list[object] = [] + + def call( + self, + method: str, + params: list[object] | None = None, + *, + timeout: float | None = None, + ) -> object: + if method == "submitblock": + result = None if not self.submit_results else "duplicate" + self.submit_results.append(result) + return result + if method == "getbestblockhash": + return parent_hash + if method == "getblockhash": + return block_hash + if method == "getblockcount": + return 9 + return super().call(method, params) + + rpc = RestartAwareRpc() + first.rpc = rpc + original_mark = ledger.mark_block_candidate_attempted + + def crash_before_mark(*, block_hash: str) -> bool: + raise SystemExit(f"simulated crash before marking {block_hash}") + + ledger.mark_block_candidate_attempted = crash_before_mark # type: ignore[method-assign] + first.enqueue_block_candidate(candidate) + with self.assertRaisesRegex(SystemExit, "simulated crash"): + first.submit_next_block_candidate() + + self.assertEqual(rpc.submit_results, [None]) + self.assertEqual(ledger.pending_block_candidates(), [intent]) + self.assertEqual( + ledger._block_candidate_outbox[block_hash]["attempt_count"], + 0, + ) + + ledger.mark_block_candidate_attempted = original_mark # type: ignore[method-assign] + persisted_calls = 0 + confirmed_calls = 0 + original_persist = ledger.persist_accepted_block + original_confirm = ledger.confirm_accepted_block + + def persist_once(**kwargs: object) -> dict[str, object]: + nonlocal persisted_calls + persisted_calls += 1 + return original_persist(**kwargs) + + def confirm_once(**kwargs: object) -> dict[str, object]: + nonlocal confirmed_calls + confirmed_calls += 1 + return original_confirm(**kwargs) + + ledger.persist_accepted_block = persist_once # type: ignore[method-assign] + ledger.confirm_accepted_block = confirm_once # type: ignore[method-assign] + + restarted, _restart_state, _recording = submit_coordinator(tip=parent_hash) + restarted.ledger = ledger + restarted.rpc = rpc + restarted.stop_after_block = False + restarted.max_blocks = 10 + with tempfile.TemporaryDirectory() as tempdir: + restarted.audit_dir = Path(tempdir) + restarted.evidence_path = Path(tempdir) / "evidence.json" + restarted.ledger_writer_public_key_hex = "aa" * 32 + restarted.build_audit_bundle = ( # type: ignore[method-assign] + lambda **_kwargs: verified_block_bundle() + ) + restarted.verify_bundle = ( # type: ignore[method-assign] + lambda *_args, **_kwargs: verified_audit_report() + ) + + self.assertEqual(restarted.replay_pending_block_candidates(), 1) + self.assertTrue(restarted.submit_next_block_candidate()) + self.assertEqual(restarted.replay_pending_block_candidates(), 0) + + self.assertEqual(rpc.submit_results, [None, "duplicate"]) + self.assertEqual(persisted_calls, 1) + self.assertEqual(confirmed_calls, 1) + self.assertEqual(restarted.accepted_block_count, 1) + self.assertEqual(ledger.pending_block_candidates(), []) + self.assertEqual( + ledger._block_candidate_outbox[block_hash]["state"], + "submitted", + ) + def test_abandon_finalize_failure_counts_one_abandonment(self) -> None: server, state, _recording = submit_coordinator() ledger = SingleWriterShareLedger() @@ -11616,6 +11809,23 @@ def test_positive_float_env_rejects_non_finite_values(self) -> None: with self.assertRaisesRegex(SystemExit, "PRISM_WATCHDOG_TIMEOUT_SECONDS must be finite"): env_positive_float("PRISM_WATCHDOG_TIMEOUT_SECONDS", 120.0) + def test_audit_verifier_subprocess_has_explicit_timeout(self) -> None: + server = self._bare_coordinator() + server.bundle_build_timeout_seconds = 0.25 + with patch( + "lab.prism.prism_coordinator.subprocess.run", + side_effect=subprocess.TimeoutExpired("audit-verify", 0.25), + ) as run: + with self.assertRaisesRegex(RuntimeError, "timed out after 0.25s"): + server.verify_bundle( + Path("candidate.json"), + "00", + "11" * 32, + expected_coinbase_value_sats=1, + ) + + self.assertEqual(run.call_args.kwargs["timeout"], 0.25) + def test_overdue_heartbeats_flags_only_stale_subsystems(self) -> None: server = self._bare_coordinator() server._record_heartbeat("stratum_accept") @@ -11629,6 +11839,116 @@ def test_overdue_heartbeats_flags_only_stale_subsystems(self) -> None: self.assertEqual(server._overdue_heartbeats(now), ["qbit_blockpoll"]) + def test_overdue_submitter_heartbeat_names_the_stuck_phase(self) -> None: + server = self._bare_coordinator() + clock = {"now": 1_000.0} + server._block_submitter_thread_ident = threading.get_ident() + with patch( + "lab.prism.prism_coordinator.time.monotonic", + side_effect=lambda: clock["now"], + ): + server._record_block_submitter_phase("replay-outbox-query") + clock["now"] += server.watchdog_timeout_seconds + 1.0 + self.assertEqual( + server._overdue_heartbeats(clock["now"]), + ["block_submitter:replay-outbox-query"], + ) + + def test_sixty_second_attempt_mark_stall_does_not_delay_rpc_or_heartbeat(self) -> None: + server, state, recording = submit_coordinator() + entered_mark = threading.Event() + release_mark = threading.Event() + submitted = threading.Event() + + class StallingLedger(RecordingLedger): + def __init__(self) -> None: + super().__init__() + self.mark_calls = 0 + + def mark_block_candidate_attempted(self, *, block_hash: str) -> bool: + self.mark_calls += 1 + entered_mark.set() + release_mark.wait(60.0) + return True + + class DeadlineRpc(SubmitRpc): + def __init__(self, ledger: RecordingLedger) -> None: + super().__init__( + tip="00" * 32, + block_hash="d2" * 32, + ledger=ledger, + ) + self.timeouts: list[float | None] = [] + + def call( + self, + method: str, + params: list[object] | None = None, + *, + timeout: float | None = None, + ) -> object: + if method == "submitblock": + self.timeouts.append(timeout) + submitted.set() + if len(self.timeouts) > 1: + return "duplicate" + return super().call(method, params) + + ledger = StallingLedger() + server.ledger = ledger + rpc = DeadlineRpc(ledger) + server.rpc = rpc + server.block_submit_rpc_timeout_seconds = 0.4 + server.block_submit_db_timeout_seconds = 0.05 + server.block_candidate_retry_initial_seconds = 0.01 + server.block_candidate_retry_max_seconds = 0.01 + server.watchdog_timeout_seconds = 0.2 + server._heartbeats = {} + server._heartbeat_phases = {} + server._watchdog_pauses = {} + server._heartbeats_lock = threading.Lock() + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="00", + block_hash_hex="d2" * 32, + block_hex="00", + share_pass=True, + block_pass=True, + ), + ) + server.enqueue_block_candidate(candidate) + started = time.monotonic() + submitter = threading.Thread(target=server.block_submit_loop) + with patch("builtins.print"): + submitter.start() + try: + self.assertTrue(submitted.wait(2.0)) + self.assertLess(time.monotonic() - started, 2.0) + self.assertTrue(entered_mark.wait(1.0)) + with server._heartbeats_lock: + first_heartbeat = server._heartbeats["block_submitter"] + heartbeat_deadline = time.monotonic() + 1.0 + while time.monotonic() < heartbeat_deadline: + with server._heartbeats_lock: + latest_heartbeat = server._heartbeats["block_submitter"] + if latest_heartbeat > first_heartbeat: + break + time.sleep(0.01) + self.assertGreater(latest_heartbeat, first_heartbeat) + self.assertEqual( + server._overdue_heartbeats(time.monotonic()), + [], + ) + self.assertEqual(ledger.mark_calls, 1) + self.assertEqual(rpc.timeouts[0], 0.4) + finally: + server.stop_event.set() + submitter.join(2.0) + release_mark.set() + self.assertFalse(submitter.is_alive()) + def test_block_submitter_retry_wait_heartbeats_in_bounded_slices(self) -> None: server = self._bare_coordinator() server.watchdog_timeout_seconds = 0.3 @@ -13052,7 +13372,10 @@ def replay_pending_candidate() -> None: synchronous_thread = threading.Thread(target=submit_synchronously) synchronous_thread.start() try: - self.assertTrue(accepted_tail_paused.wait(5)) + self.assertTrue( + accepted_tail_paused.wait(5), + msg=f"synchronous submit exited early: {errors!r}", + ) self.assertTrue(durable_confirmation.is_set()) self.assertEqual(len(ledger), 1) self.assertEqual(len(ledger.pending_block_candidates()), 1) @@ -13438,6 +13761,10 @@ def call(self, method: str, params: list[object] | None = None) -> object: if method == "submitblock": self.submitblock_calls += 1 block_hash = self.hash_by_hex[str((params or [""])[0])] + if block_hash in self.active: + return "duplicate" + if self.racing_tip is not None: + return "bad-prevblk" self.height += 1 self.active[block_hash] = self.height self.tip = block_hash @@ -13645,7 +13972,7 @@ def test_blockwait_observed_acceptance_survives_stale_chain_probe(self) -> None: self.assertEqual(submitted, [block_hash]) self.assertEqual(abandoned, []) - self.assertEqual(rpc.submitblock_calls, 1) + self.assertEqual(rpc.submitblock_calls, 3) self.assertIn(block_hash, server._accounted_accepted_block_hashes) self.assertEqual(server.accepted_block_count, 1) self.assertEqual(len(ledger.persisted), 1) diff --git a/tests/test_prism_share_ledger.py b/tests/test_prism_share_ledger.py index 6cae4391..20eb646c 100644 --- a/tests/test_prism_share_ledger.py +++ b/tests/test_prism_share_ledger.py @@ -30,6 +30,7 @@ AUDIT_BUNDLE_V2_SCHEMA, PendingShare, PsqlShareLedger, + LedgerOperationTimeout, AUDIT_WINDOW_COMPLETENESS_PROOF_SCHEMA, DEFAULT_WRITER_LEASE_ADOPTION_SILENCE_SECONDS, SingleWriterShareLedger, @@ -3814,6 +3815,105 @@ def stats_payload( class NativeClientSelectionTests(unittest.TestCase): + def test_operation_timeout_bounds_local_writer_lock_admission(self) -> None: + ledger = PsqlShareLedger.__new__(PsqlShareLedger) + ledger._operation_timeout_local = threading.local() + gate = threading.Lock() + gate.acquire() + started = time.monotonic() + try: + with ledger.operation_timeout(0.02): + with self.assertRaisesRegex( + LedgerOperationTimeout, + "writer lock", + ): + with ledger._operation_gate(gate, "writer lock"): + self.fail("contended writer lock unexpectedly acquired") + finally: + gate.release() + self.assertLess(time.monotonic() - started, 0.5) + + def test_statement_timeout_refreshes_for_each_database_step(self) -> None: + ledger = PsqlShareLedger.__new__(PsqlShareLedger) + ledger._operation_timeout_local = threading.local() + ledger._statement_timeout_local = threading.local() + clock = {"now": 10.0} + + with unittest.mock.patch( + "lab.prism.share_ledger.time.monotonic", + side_effect=lambda: clock["now"], + ): + with ledger.statement_timeout(0.5): + self.assertEqual(ledger._remaining_operation_timeout(), 0.5) + clock["now"] += 60.0 + self.assertEqual(ledger._remaining_operation_timeout(), 0.5) + + def test_subprocess_operation_timeout_sets_client_and_server_deadlines(self) -> None: + ledger = PsqlShareLedger.__new__(PsqlShareLedger) + ledger._command = ["psql"] + ledger._native = None + ledger._operation_timeout_local = threading.local() + completed = unittest.mock.Mock(returncode=0, stdout="{}\n", stderr="") + + with unittest.mock.patch( + "lab.prism.share_ledger.subprocess.run", + return_value=completed, + ) as run: + with ledger.operation_timeout(0.5): + self.assertEqual(ledger._run_sql("SELECT '{}'::json;"), "{}\n") + + kwargs = run.call_args.kwargs + self.assertGreater(float(kwargs["timeout"]), 0.0) + self.assertLessEqual(float(kwargs["timeout"]), 0.5) + self.assertEqual(kwargs["env"]["PGCONNECT_TIMEOUT"], "1") + self.assertIn("statement_timeout=", kwargs["env"]["PGOPTIONS"]) + self.assertIn("lock_timeout=", kwargs["env"]["PGOPTIONS"]) + + def test_native_operation_timeout_is_transaction_local(self) -> None: + class OperationalError(Exception): + pass + + class FakePsycopg: + pass + + FakePsycopg.OperationalError = OperationalError # type: ignore[attr-defined] + executions: list[str] = [] + borrowed_with: list[float | None] = [] + + class FakeConnection: + @contextlib.contextmanager + def transaction(self) -> Any: + yield + + def execute(self, sql: str) -> FakeConnection: + executions.append(sql) + return self + + def fetchone(self) -> tuple[object]: + return ({"ok": True},) + + client = _NativePostgresClient.__new__(_NativePostgresClient) + client._psycopg = FakePsycopg + + @contextlib.contextmanager + def connection(*, timeout_seconds: float | None = None) -> Any: + borrowed_with.append(timeout_seconds) + yield FakeConnection() + + client.connection = connection # type: ignore[method-assign] + + self.assertEqual( + client.run_json("SELECT json_build_object('ok', true)", timeout_seconds=0.5), + {"ok": True}, + ) + self.assertEqual(len(borrowed_with), 1) + self.assertIsNotNone(borrowed_with[0]) + self.assertGreater(float(borrowed_with[0]), 0.0) + self.assertLessEqual(float(borrowed_with[0]), 0.5) + self.assertRegex(executions[0], r"^SET LOCAL statement_timeout = '\d+ms'$") + self.assertRegex(executions[1], r"^SET LOCAL lock_timeout = '\d+ms'$") + self.assertEqual(executions[2], "SELECT json_build_object('ok', true)") + def test_database_url_extraction_variants(self) -> None: self.assertEqual( database_url_from_psql_command(["psql", "postgres://u:p@h:5432/db"]), From 9a2b553c2054d37e53cf5500326e109cfb457822 Mon Sep 17 00:00:00 2001 From: Anatolie Date: Tue, 11 Aug 2026 13:36:20 -0400 Subject: [PATCH 02/10] fix(prism): isolate node offers from block accounting --- .env.example | 2 + compose.yaml | 1 + docs/prism-ledger-ops.md | 47 +- lab/prism/prism_coordinator.py | 1800 ++++++++++++++++++----- lab/prism/share_ledger.py | 102 +- tests/test_prism_coordinator_vardiff.py | 1178 ++++++++++++++- tests/test_prism_share_ledger.py | 42 +- 7 files changed, 2694 insertions(+), 478 deletions(-) diff --git a/.env.example b/.env.example index cb616b5f..7959da40 100644 --- a/.env.example +++ b/.env.example @@ -180,6 +180,8 @@ PRISM_BLOCK_SUBMIT_RPC_TIMEOUT_SECONDS=1 PRISM_BLOCK_SUBMIT_DB_TIMEOUT_SECONDS=1 # Emit the contended lock and current submitter phase at this cadence. PRISM_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS=5 +# Exit nonzero when a timeout-ignoring RPC/DB worker pool stays exhausted this long. +PRISM_BLOCK_SUBMIT_STUCK_CALL_EXIT_SECONDS=30 PRISM_REORG_RECONCILER_ENABLED=1 PRISM_VERSION_ROLLING_MASK=1fffe000 PRISM_COINBASE_TAG=/PRISM/ diff --git a/compose.yaml b/compose.yaml index 2120589c..d82bc6e8 100644 --- a/compose.yaml +++ b/compose.yaml @@ -512,6 +512,7 @@ services: PRISM_BLOCK_SUBMIT_RPC_TIMEOUT_SECONDS: ${PRISM_BLOCK_SUBMIT_RPC_TIMEOUT_SECONDS:-1} PRISM_BLOCK_SUBMIT_DB_TIMEOUT_SECONDS: ${PRISM_BLOCK_SUBMIT_DB_TIMEOUT_SECONDS:-1} PRISM_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS: ${PRISM_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS:-5} + PRISM_BLOCK_SUBMIT_STUCK_CALL_EXIT_SECONDS: ${PRISM_BLOCK_SUBMIT_STUCK_CALL_EXIT_SECONDS:-30} PRISM_OBSERVED_TIP_ACCEPT_WINDOW_SECONDS: ${PRISM_OBSERVED_TIP_ACCEPT_WINDOW_SECONDS:-300} PRISM_TIP_REFRESH_FAILURE_HOLDOFF_SECONDS: ${PRISM_TIP_REFRESH_FAILURE_HOLDOFF_SECONDS:-1} PRISM_TIP_REFRESH_EPOCH_FANOUT: ${PRISM_TIP_REFRESH_EPOCH_FANOUT:-0} diff --git a/docs/prism-ledger-ops.md b/docs/prism-ledger-ops.md index 971262d5..d551e864 100644 --- a/docs/prism-ledger-ops.md +++ b/docs/prism-ledger-ops.md @@ -94,16 +94,24 @@ context, reward inputs, and extranonce fields required to finish audit and submission. The share and intent become visible atomically before Stratum success. -The in-memory candidate queue is only a bounded wakeup path. Queue saturation -coalesces wakeups; it cannot delete an outbox row. Before opening Stratum -listeners and whenever the queue drains, the coordinator replays pending rows. +The bounded live-candidate queue is only a wakeup path. Queue saturation +coalesces wakeups; it cannot delete an outbox row. Recovery restores pending +rows in batches into a separate, lower-priority replay queue, without doing +per-row database accounting. Live discoveries therefore always outrank restart +work, while an older replay stalled in accounting cannot hide later durable +rows. Before qbitd can observe a candidate, the coordinator installs a short +in-memory prospective-payout barrier; this prevents startup prewarm from +issuing child work from the old balance base without falsely claiming that the +block landed. + Once a durable candidate is dequeued, its qbit `submitblock` RPC is the fast lane: it runs before the attempt-marker write, accepted-block writer admission, -audit construction, or payout publication. An in-memory wakeup is also drained -before querying the recovery outbox. This priority isolation means a newly -found block cannot queue behind a payout-artifact writer already waiting for -admission; accounting remains serialized only after the node has seen the -candidate. +audit construction, or payout publication. The node result and same-hash lease +then transfer to an independent, height-prioritized accounting lane. A full +primary handoff spills to a result-preserving overflow queue; it never turns an +already-offered block back into a raw-submit retry. `block_submitter` and +`block_accounting` expose independent phase heartbeats, so slow accounting does +not delay later node offers or disguise the phase that stopped progressing. `PRISM_BLOCK_SUBMIT_RPC_TIMEOUT_SECONDS` bounds the fast-lane RPC (default 1 second). `PRISM_BLOCK_SUBMIT_DB_TIMEOUT_SECONDS` gives each later Postgres @@ -113,7 +121,13 @@ driver that ignores its deadline cannot accumulate retry threads. Timeouts leave the row pending and enter the ordinary candidate backoff. Contended submit-path locks are acquired in heartbeat slices and identify the lock in a periodic diagnostic controlled by `PRISM_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS` -(default 5 seconds). +(default 5 seconds). At most two timeout-ignoring RPC workers and two +timeout-ignoring ledger workers may remain detached. If either bounded worker +pool remains exhausted for `PRISM_BLOCK_SUBMIT_STUCK_CALL_EXIT_SECONDS` +(default 30 seconds), the coordinator requests shutdown and exits nonzero so +the supervisor replaces the poisoned process; durable outbox rows remain +pending for replay. One detached call does not interrupt the healthy raw lane +while the other bounded slot can still make progress. Successful submissions become `submitted`; candidates that definitively lose their tip race or fail validation become `abandoned`. If the process exits @@ -122,12 +136,19 @@ restart resubmits the same bytes. qbit's accepted-duplicate response is a successful landing signal; block-hash-keyed ledger persistence and the finalize-only registry keep accounting and terminal side effects exactly once. Restart can also recognize the candidate as the active tip and complete the -same idempotent confirmation path. +same idempotent confirmation path. Exact miner resubmissions observe an +existing terminal outbox state in the same durable pre-submit transaction: +`submitted` coalesces to success and `abandoned` stays rejected before any new +node offer. Exact share replays return the original row as not newly inserted, +so process-local worker and vardiff counters are not credited twice. Transient RPC, audit, and ledger outcomes remain pending and retry with an exponential delay starting at 250 milliseconds and capped at 30 seconds. They -do not increment terminal abandonment counters. Replay carries the database -row's block hash separately from candidate JSON, so malformed payloads can be -quarantined by their authoritative outbox key instead of replaying forever. +do not increment terminal abandonment counters. An abandonment is counted only +after any prepared payout state is rejected and the false disposition is fixed; +if cleanup fails, the candidate remains pending and can still converge to +submitted on later chain evidence. Replay carries the database row's block hash +separately from candidate JSON, so malformed payloads can be quarantined using +the authoritative outbox key instead of replaying forever. The block submitter heartbeat carries its current phase, including replay query, node RPC, lock admission, audit, persistence, and finalization. A stale diff --git a/lab/prism/prism_coordinator.py b/lab/prism/prism_coordinator.py index 77e51b3b..17c52404 100644 --- a/lab/prism/prism_coordinator.py +++ b/lab/prism/prism_coordinator.py @@ -475,6 +475,8 @@ def validate_payout_artifact_age_bounds( DEFAULT_BLOCK_SUBMIT_DB_TIMEOUT_SECONDS = 1.0 BLOCK_SUBMITTER_WAIT_HEARTBEAT_SLICE_SECONDS = 0.25 DEFAULT_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS = 5.0 +DEFAULT_BLOCK_SUBMIT_STUCK_CALL_EXIT_SECONDS = 30.0 +MAX_BLOCK_SUBMITTER_STUCK_CALL_WORKERS = 2 # How long an own-hash tip observation keeps protecting a block candidate # from terminal abandonment while instantaneous chain probes disagree # (transient sibling/fork views during quick-succession blocks, RPC blips). @@ -1415,6 +1417,7 @@ class PrismBlockCandidate: pending_share: PendingShare client: ClientState credit_share_on_accept: bool = False + durable_replay: bool = False # When this in-process attempt became runnable: live candidates stamp # share-accept time, durable outbox replays stamp row-restore time. The # block-submit histogram measures from here to submitblock's return -- @@ -1426,10 +1429,21 @@ class PrismBlockCandidate: class _BlockCandidateDispositionFlight: """One same-hash submission guard shared by its holder and waiters.""" - lock: threading.RLock = field(default_factory=threading.RLock) + # The node-offer thread acquires this guard and the accounting thread + # releases it after durable finalization. A plain Lock permits that + # deliberate ownership transfer; RLock does not. + lock: threading.Lock = field(default_factory=threading.Lock) users: int = 0 +@dataclass(frozen=True) +class _BlockCandidateDispositionLease: + """A same-hash guard held across node offer and durable finalization.""" + + block_hash: str + flight: _BlockCandidateDispositionFlight + + @dataclass(frozen=True) class _BlockCandidateNodeSubmission: """Result of the latency-critical qbitd fast-lane call.""" @@ -1443,11 +1457,31 @@ class _BlockCandidateNodeSubmission: class _BlockSubmitterLedgerCall: """One still-running direct outbox call, reused across paced retries.""" + started_monotonic: float = field(default_factory=time.monotonic) + done: threading.Event = field(default_factory=threading.Event) + result: object = None + error: BaseException | None = None + + +@dataclass +class _BlockSubmitterRpcCall: + """One hard-deadline, single-flight submitblock transport call.""" + + started_monotonic: float = field(default_factory=time.monotonic) done: threading.Event = field(default_factory=threading.Event) result: object = None error: BaseException | None = None +@dataclass(frozen=True) +class _BlockCandidateAccountingTask: + """A node-offered candidate awaiting serialized durable accounting.""" + + candidate: PrismBlockCandidate + node_submission: _BlockCandidateNodeSubmission + disposition_lease: _BlockCandidateDispositionLease + + class BlockSubmitterDatabaseTimeout(TimeoutError): """A submitter ledger phase exceeded its coordinator-side deadline.""" @@ -3050,6 +3084,10 @@ def __init__(self) -> None: "PRISM_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS", DEFAULT_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS, ) + self.block_submit_stuck_call_exit_seconds = env_positive_float( + "PRISM_BLOCK_SUBMIT_STUCK_CALL_EXIT_SECONDS", + DEFAULT_BLOCK_SUBMIT_STUCK_CALL_EXIT_SECONDS, + ) # An own-hash tip observation is acceptance evidence even when the # direct submitblock ack was lost; this window bounds how long that # evidence blocks a terminal abandonment while fresh chain probes @@ -3500,10 +3538,34 @@ def __init__(self) -> None: self.block_candidate_queue: queue.Queue[PrismBlockCandidate] = queue.Queue( maxsize=MAX_PENDING_BLOCK_CANDIDATES ) + # Durable recovery work is separate and lower priority: a newly found + # live block must never sit behind a restart batch. The in-flight set + # lets batch replay expose later rows while an older row is still in + # accounting without repeatedly queueing the older hash. + self._block_replay_candidate_queue: queue.Queue[ + PrismBlockCandidate + ] = queue.Queue() + self._block_replay_inflight_hashes: set[str] = set() + self._block_quarantine_queue: queue.Queue[tuple[str, str]] = queue.Queue() + self._block_quarantine_hashes: set[str] = set() self._block_candidate_disposition_registry_lock = threading.Lock() self._block_candidate_disposition_flights: dict[ str, _BlockCandidateDispositionFlight ] = {} + self._block_candidate_terminal_outcomes: dict[str, bool] = {} + self._block_fast_lane_reservations: set[str] = set() + self._block_disposition_waiting_retries: dict[ + str, PrismBlockCandidate + ] = {} + self._block_accounting_queue: queue.PriorityQueue[ + tuple[int, int, _BlockCandidateAccountingTask] + ] = queue.PriorityQueue() + self._block_accounting_overflow_queue: queue.PriorityQueue[ + tuple[int, int, _BlockCandidateAccountingTask] + ] = queue.PriorityQueue() + self._block_accounting_sequence = 0 + self._block_accounting_state_lock = threading.Lock() + self._block_accounting_thread: threading.Thread | None = None self.block_candidates_dropped = 0 self.block_candidate_wakeups_coalesced = 0 self.block_candidate_retry_count = 0 @@ -3534,6 +3596,15 @@ def __init__(self) -> None: self._block_submitter_ledger_calls: dict[ tuple[object, ...], _BlockSubmitterLedgerCall ] = {} + self._block_submitter_ledger_worker_slots = threading.BoundedSemaphore( + MAX_BLOCK_SUBMITTER_STUCK_CALL_WORKERS + ) + self._block_submitter_rpc_calls_lock = threading.Lock() + self._block_submitter_rpc_calls: dict[str, _BlockSubmitterRpcCall] = {} + self._block_submitter_rpc_worker_slots = threading.BoundedSemaphore( + MAX_BLOCK_SUBMITTER_STUCK_CALL_WORKERS + ) + self._fatal_exit_requested = False self._block_submitter_last_lock_wait_log_monotonic = 0.0 # Terminal candidates whose durable outbox update failed; replays for # these run finalize-only (see _finalize_block_candidate). @@ -3544,6 +3615,10 @@ def __init__(self) -> None: # share-reject counters (that would inflate stale_share_percent with # block-race losses). Tracked here by reason instead. self.block_candidate_abandoned_counts: dict[str, int] = {} + # Durable cleanup can fail after a terminal decision and force the + # same hash through that decision again; abandonment metrics count + # candidates, not cleanup attempts. + self._counted_block_candidate_abandonments: set[str] = set() self.stale_job_abandon_counts = { abandon_class: 0 for abandon_class in PRISM_STALE_JOB_ABANDON_CLASSES @@ -4415,6 +4490,8 @@ def _ensure_job_cache_state(self) -> None: ] = {} if not hasattr(self, "_accounted_accepted_block_hashes"): self._accounted_accepted_block_hashes: set[str] = set() + if not hasattr(self, "_counted_block_candidate_abandonments"): + self._counted_block_candidate_abandonments: set[str] = set() if not hasattr(self, "_outstanding_block_candidate_hashes"): self._outstanding_block_candidate_hashes: set[str] = set() if not hasattr(self, "_tip_observed_accepted_block_hashes"): @@ -7300,7 +7377,10 @@ def _job_bundle_payout_state_current(self, bundle: CachedJobBundle) -> bool: def _payout_balance_mutation(self) -> Iterator[None]: """Serialize durable balance changes without excluding delivery.""" self._ensure_job_cache_state() - with self._payout_balance_mutation_lock: + with self._block_submitter_lock( + self._payout_balance_mutation_lock, + "payout-balance-mutation", + ): with self._accepted_block_payout_preview_condition: landed_transition = any( transition.landed @@ -7377,7 +7457,10 @@ def _publish_accepted_block_payout_preview( normalized = self.normalized_prior_balances(balances) serialized = self._serialize_prior_balance_preview(normalized) key = block_hash.lower() - with self._payout_balance_mutation_lock: + with self._block_submitter_lock( + self._payout_balance_mutation_lock, + "payout-balance-mutation", + ): with self._accepted_block_payout_preview_condition: existing = self._accepted_block_payout_previews.get(key) existing_preview = existing.preview if existing is not None else None @@ -7582,7 +7665,10 @@ def _clear_accepted_block_payout_preview( ) -> None: self._ensure_job_cache_state() key = block_hash.lower() - with self._payout_balance_mutation_lock: + with self._block_submitter_lock( + self._payout_balance_mutation_lock, + "payout-balance-mutation", + ): with self._accepted_block_payout_preview_condition: existing = self._accepted_block_payout_previews.get(key) if existing is None: @@ -12241,43 +12327,65 @@ def _record_heartbeat(self, name: str, *, phase: str | None = None) -> None: if phase is not None: self._heartbeat_phases[name] = phase - def _record_block_submitter_heartbeat(self, phase: str) -> None: + def _block_work_heartbeat_owner(self) -> tuple[str, str] | None: + """Return the independent heartbeat/phase slots owned by this thread.""" + current = threading.get_ident() + if current == getattr(self, "_block_submitter_thread_ident", None): + return "block_submitter", "_block_submitter_phase" + if current == getattr(self, "_block_accounting_thread_ident", None): + return "block_accounting", "_block_accounting_phase" + return None + + def _record_block_work_heartbeat(self, name: str, phase: str) -> None: """Record a phase while preserving one-argument heartbeat embedders.""" heartbeat = self._record_heartbeat try: - heartbeat("block_submitter", phase=phase) + heartbeat(name, phase=phase) except TypeError as exc: # Preserve the historical one-argument heartbeat seam used by # focused embedders. Do not hide TypeErrors raised by a heartbeat # implementation that did accept the keyword. if "unexpected keyword argument 'phase'" not in str(exc): raise - heartbeat("block_submitter") + heartbeat(name) def _record_block_submitter_phase(self, phase: str) -> None: - """Stamp a named phase only from the dedicated submitter owner.""" - owner = getattr(self, "_block_submitter_thread_ident", None) - if owner is None or threading.get_ident() != owner: + """Stamp a named phase only from a dedicated block-work owner.""" + owner = self._block_work_heartbeat_owner() + if owner is None: return - self._block_submitter_phase = phase - self._record_block_submitter_heartbeat(phase) + heartbeat_name, phase_attribute = owner + setattr(self, phase_attribute, phase) + self._record_block_work_heartbeat(heartbeat_name, phase) def _record_block_submitter_wait(self, phase: str) -> None: """Heartbeat owner waits while preserving lightweight test behavior.""" - owner = getattr(self, "_block_submitter_thread_ident", None) - if owner is None: + owner = self._block_work_heartbeat_owner() + if owner is None and not hasattr(self, "_block_submitter_thread_ident"): self._record_heartbeat("block_submitter") return self._record_block_submitter_phase(phase) + def _block_work_wait_slice(self) -> float: + """Choose a polling slice that stays inside the configured watchdog.""" + watchdog_budget = max( + 0.001, + float(getattr(self, "watchdog_timeout_seconds", 120.0)), + ) + return min( + BLOCK_SUBMITTER_WAIT_HEARTBEAT_SLICE_SECONDS, + max(0.001, watchdog_budget * 0.9), + ) + def _observe_coordinator_lock_wait(self, elapsed_seconds: float) -> None: """Keep a sliced coordinator-lock wait visible and watchdog-safe.""" - owner = getattr(self, "_block_submitter_thread_ident", None) - if owner is None or threading.get_ident() != owner: + owner = self._block_work_heartbeat_owner() + if owner is None: return - current_phase = getattr(self, "_block_submitter_phase", "unknown") + heartbeat_name, phase_attribute = owner + current_phase = getattr(self, phase_attribute, "unknown") wait_phase = f"wait-lock:coordinator-state:{current_phase}" - self._record_block_submitter_heartbeat(wait_phase) + self._record_block_work_heartbeat(heartbeat_name, wait_phase) now = time.monotonic() log_interval = float( getattr( @@ -12300,8 +12408,11 @@ def _observe_coordinator_lock_wait(self, elapsed_seconds: float) -> None: def _acquire_block_submitter_lock(self, lock: Any, name: str) -> None: """Acquire a submit-path lock in heartbeat/logging slices.""" - owner = getattr(self, "_block_submitter_thread_ident", None) - if owner is not None and threading.get_ident() != owner: + owner = self._block_work_heartbeat_owner() + if owner is None and ( + hasattr(self, "_block_submitter_thread_ident") + or hasattr(self, "_block_accounting_thread_ident") + ): lock.acquire() return started = time.monotonic() @@ -12313,9 +12424,7 @@ def _acquire_block_submitter_lock(self, lock: Any, name: str) -> None: DEFAULT_BLOCK_SUBMIT_LOCK_WAIT_LOG_SECONDS, ) ) - while not lock.acquire( - timeout=BLOCK_SUBMITTER_WAIT_HEARTBEAT_SLICE_SECONDS - ): + while not lock.acquire(timeout=self._block_work_wait_slice()): phase = f"wait-lock:{name}" self._record_block_submitter_wait(phase) now = time.monotonic() @@ -12864,7 +12973,16 @@ def _watchdog_paused(self, *names: str) -> Iterator[None]: self._resume_watchdog_heartbeat(name) def watchdog_loop(self) -> None: - while not self.stop_event.wait(self.watchdog_interval_seconds): + while True: + if self.stop_event.wait(self.watchdog_interval_seconds): + if getattr(self, "_fatal_exit_requested", False): + print( + "prism coordinator: fatal block-work restart requested; " + "exiting non-zero even if the main thread is blocked", + flush=True, + ) + os._exit(1) + return now = time.monotonic() ( publication_failure, @@ -13017,19 +13135,18 @@ def _ensure_shutdown_controller(self) -> CoordinatorShutdownController: @contextmanager def _writer_operation(self, component: str) -> Iterator[None]: controller = self._ensure_shutdown_controller() - owner = getattr(self, "_block_submitter_thread_ident", None) - submitter_owner = owner is not None and threading.get_ident() == owner + block_work_owner = self._block_work_heartbeat_owner() is not None phase = f"writer-admission:{component}" - if submitter_owner: + if block_work_owner: self._record_block_submitter_phase(phase) - if submitter_owner: + if block_work_owner: token = controller.enter_writer( component, wait_callback=lambda: self._record_block_submitter_phase(phase), ) else: # Keep the historical one-argument seam for focused embedders and - # test controllers; only the dedicated submitter needs sliced + # test controllers; only dedicated block-work owners need sliced # admission heartbeats. token = controller.enter_writer(component) try: @@ -13325,15 +13442,31 @@ def _serve_with_listener_stack(self, listener_stack: ExitStack) -> None: ) if self.audit_bind and self.audit_port: self.start_audit_server() - # Recover block work before accepting Stratum connections. New miners - # can only add wakeups after every previously committed candidate has - # had a chance to re-enter the submit queue. The listener sockets are - # already bound above, so reconnecting miners wait in the accept - # backlog through this recovery instead of being refused. + # Recover one block candidate before accepting Stratum connections. + # Start its qbitd fast lane immediately afterward: startup job prewarm + # may depend on a slow ledger/backend, but it must never postpone an + # already-durable block offer to the node. if not self._run_startup_writer_replay(self.replay_pending_block_candidates): return if self.stop_event.is_set(): return + self._record_block_work_heartbeat("block_submitter", "starting") + block_accounting_thread = self._start_block_accounting_thread() + block_submitter_thread = threading.Thread( + target=self.block_submit_loop, + name="prism-block-submitter", + daemon=True, + ) + block_submitter_thread.start() + drain_threads: list[tuple[threading.Thread, float]] = [ + (block_submitter_thread, 1.0), + (block_accounting_thread, 1.0), + ] + # Publication progress is mandatory even when the operator disables + # ordinary heartbeat checks. Start the watchdog before any synchronous + # startup prewarm/recovery work: a timeout-ignoring block call can ask + # for fail-stop while the main thread is itself wedged in that work. + threading.Thread(target=self.watchdog_loop, daemon=True).start() prepared = self.prewarm_startup_jobs() print( "prism coordinator: startup job preparation " @@ -13370,16 +13503,7 @@ def _serve_with_listener_stack(self, listener_stack: ExitStack) -> None: daemon=True, ) initial_job_timeout_thread.start() - self._record_heartbeat("block_submitter") - block_submitter_thread = threading.Thread( - target=self.block_submit_loop, - daemon=True, - ) - block_submitter_thread.start() - drain_threads: list[tuple[threading.Thread, float]] = [ - (blockpoll_thread, 1.0), - (block_submitter_thread, 1.0), - ] + drain_threads.append((blockpoll_thread, 1.0)) if lease_heartbeat_thread is not None: drain_threads.append((lease_heartbeat_thread, 1.0)) lease_heartbeat_monitor_thread = getattr( @@ -13429,10 +13553,6 @@ def _serve_with_listener_stack(self, listener_stack: ExitStack) -> None: f"chunk_size={self.ctv_broadcaster_chunk_size}", flush=True, ) - # Publication progress is mandatory even when the operator disables - # the ordinary heartbeat watchdog: advancing retry heartbeats do not - # prove that current work has ever reached publication. - threading.Thread(target=self.watchdog_loop, daemon=True).start() if self.watchdog_enabled: print( "prism coordinator: liveness and publication-progress watchdog enabled " @@ -17985,7 +18105,10 @@ def retry_superseded_candidate() -> bool: # _note_reorg_reconcile_outcome. proof_epoch = int(getattr(self, "tip_detection_epoch", 0)) try: - with self._payout_state_prepare_lock: + with self._block_submitter_lock( + self._payout_state_prepare_lock, + "payout-state-prepare", + ): prepared_started = time.monotonic() captured_source = self._capture_payout_state_source() payout_changed = False @@ -21167,15 +21290,16 @@ def handle_submit(self, client: ClientState, params: list[object]) -> bool: # common-path latency. On failure the submitter already recorded # the specific block-failure reason; reject the miner as # low-difficulty (the share was, after all, below its target). The - # submitter already recorded the specific block-failure reason in - # block_candidate_abandoned_counts; reject_stratum additionally counts - # the miner-facing rejection (globally and per worker) so this rare + # submitter already recorded the specific block-failure reason in + # block_candidate_abandoned_counts; reject_stratum additionally counts + # the miner-facing rejection (globally and per worker) so this rare # synchronous path is not missing from the rejection metrics. persist_intent = getattr(self.ledger, "persist_block_candidate_intent", None) + durable_candidate_state: str | None = None try: candidate_intent = self.block_candidate_intent(candidate) if callable(persist_intent): - self._run_block_submitter_ledger_call( + persist_result = self._run_block_submitter_ledger_call( ( "persist-candidate-intent", str(candidate.submission.block_hash_hex).lower(), @@ -21183,6 +21307,9 @@ def handle_submit(self, client: ClientState, params: list[object]) -> bool: "persist-candidate-intent", lambda: persist_intent(candidate_intent), ) + result_state = getattr(persist_result, "state", None) + if result_state is not None: + durable_candidate_state = str(result_state) except BaseException: # No retry slot is safe until the pre-submit outbox boundary is # durable. Let the miner retry this submission instead. Without @@ -21191,50 +21318,23 @@ def handle_submit(self, client: ClientState, params: list[object]) -> bool: self._finish_pending_share_commit(pending_share) self._forget_recent_share_key(share_key) raise - try: - node_submission = self._node_submission_for_candidate(candidate) - self._mark_block_candidate_attempted( - str(candidate.submission.block_hash_hex).lower() + if durable_candidate_state in {"submitted", "abandoned"}: + # A process restart clears the in-memory disposition cache, + # but the existing outbox row remains authoritative. Join its + # terminal result before any new raw node offer. + block_landed = durable_candidate_state == "submitted" + self._record_block_candidate_terminal_outcome( + submission.block_hash_hex, + accepted=block_landed, ) - with self._block_submitter_ledger_statement_timeout_scope(): - block_landed = self._account_block_candidate_after_node_submit( - candidate, - node_submission, - ) - except BaseException: - self._retain_block_candidate_for_retry(candidate) - self._forget_recent_share_key(share_key) - raise - if not block_landed: - outcome = getattr(self, "_block_candidate_outcome", None) - reason = getattr(outcome, "reason", None) if outcome is not None else None - retryable_reasons = {None, *PRISM_RETRYABLE_BLOCK_CANDIDATE_REASONS} - if reason in retryable_reasons: - # The durable outbox may still land and credit this block. - # Close without a Stratum result instead of issuing a false - # definitive rejection for an uncertain outcome. - self._retain_block_candidate_for_retry(candidate) + self._finish_pending_share_commit(pending_share) + else: + try: + block_landed = self._submit_synchronous_block_candidate(candidate) + except BaseException: self._forget_recent_share_key(share_key) - raise RuntimeError( - "block candidate outcome is pending durable retry" - ) - if reason not in retryable_reasons: - # This process will never credit the candidate share now: - # release its snapshot anchor floor entry before the - # terminal outbox update, whose failure would still leave - # only restart replay (a fresh PendingShare) to credit it. - abandon_error = ( - getattr(outcome, "error", None) - if outcome is not None - else None - ) - self._finalize_block_candidate( - candidate, - block_hash=str(submission.block_hash_hex).lower(), - accepted=False, - error=str(abandon_error or reason), - outcome=outcome, - ) + raise + if not block_landed: self._forget_recent_share_key(share_key) self.reject_stratum( 23, @@ -21242,26 +21342,13 @@ def handle_submit(self, client: ClientState, params: list[object]) -> bool: "low difficulty share", worker=worker_name, ) - else: - outcome = getattr(self, "_block_candidate_outcome", None) - if outcome is None: - outcome = threading.local() - self._block_candidate_outcome = outcome - self._finalize_block_candidate( - candidate, - block_hash=str(submission.block_hash_hex).lower(), - accepted=True, - error="", - outcome=outcome, + elif evicted_entry is not None: + self.note_evicted_job_submit( + credit_policy, + cross_connection=( + evicted_entry.connection_id != client.connection_id + ), ) - if evicted_entry is not None: - self.note_evicted_job_submit( - credit_policy, - cross_connection=( - evicted_entry.connection_id - != client.connection_id - ), - ) return False # A block-worthy submission that met the share target is a valid share # regardless of the block's fate: credit it now, acknowledge the miner @@ -21270,7 +21357,7 @@ def handle_submit(self, client: ClientState, params: list[object]) -> bool: # share credit. try: candidate_intent = self.block_candidate_intent(candidate) - self.append_accepted_share( + durable_candidate_state = self.append_accepted_share( client, context, submission, @@ -21291,6 +21378,12 @@ def handle_submit(self, client: ClientState, params: list[object]) -> bool: self._finish_pending_share_commit(pending_share) self._forget_recent_share_key(share_key) raise + if durable_candidate_state in {"submitted", "abandoned"}: + self._record_block_candidate_terminal_outcome( + submission.block_hash_hex, + accepted=durable_candidate_state == "submitted", + ) + return False self.enqueue_block_candidate(candidate) return False @@ -21859,7 +21952,7 @@ def append_accepted_share( *, credit_policy: str | None = None, candidate_intent: dict[str, Any] | None = None, - ) -> None: + ) -> str | None: entry = PendingShareAppend( pending_share=pending_share, username=context.worker.username, @@ -21880,10 +21973,16 @@ def append_accepted_share( # share. Either way the stamped share no longer holds the snapshot # anchor floor. Idempotent with the group-commit writer's release. self._finish_pending_share_commit(pending_share) - # Only committed shares affect public accounting, vardiff, and the - # response that handle_request sends immediately after this returns. - self.note_worker_accepted_share(context.worker.username, credit_policy) - self.note_vardiff_accepted_share(client, context.job) + record = entry.record + # Exact ledger replays return the original record. Their durable share + # must not increment process-local worker/vardiff counters again. + if record is None or bool(getattr(record, "newly_inserted", True)): + self.note_worker_accepted_share(context.worker.username, credit_policy) + self.note_vardiff_accepted_share(client, context.job) + if candidate_intent is None or record is None: + return None + candidate_state = getattr(record, "candidate_outbox_state", None) + return str(candidate_state) if candidate_state is not None else None def enqueue_share_append(self, entry: PendingShareAppend, *, wait: bool = False) -> None: queue_obj = getattr(self, "share_append_queue", None) @@ -23240,6 +23339,65 @@ def enqueue_block_candidate(self, candidate: PrismBlockCandidate) -> bool: ) return False + def _ensure_block_replay_state(self) -> None: + """Backfill replay/maintenance queues for lightweight coordinators.""" + with _HOT_PATH_LOCK_INITIALIZATION_LOCK: + if not hasattr(self, "_block_replay_candidate_queue"): + self._block_replay_candidate_queue = queue.Queue() + if not hasattr(self, "_block_replay_inflight_hashes"): + self._block_replay_inflight_hashes: set[str] = set() + if not hasattr(self, "_block_quarantine_queue"): + self._block_quarantine_queue = queue.Queue() + if not hasattr(self, "_block_quarantine_hashes"): + self._block_quarantine_hashes: set[str] = set() + + def _enqueue_replayed_block_candidate( + self, + candidate: PrismBlockCandidate, + ) -> bool: + """Queue one durable replay behind live solves, once per process.""" + self._ensure_block_replay_state() + block_hash = str(candidate.submission.block_hash_hex).lower() + with self.lock: + if ( + block_hash in self._block_replay_inflight_hashes + or block_hash + in getattr(self, "_block_candidate_terminal_outcomes", {}) + ): + return False + self._block_replay_inflight_hashes.add(block_hash) + try: + # This is an in-memory condition update, not accounting. Install + # it before making the candidate visible to the raw lane so + # startup prewarm cannot build a child from the old payout base + # after qbitd accepts but before the RPC response returns. + self._begin_accepted_block_payout_preview( + block_hash, + block_height=int(candidate.context.template["height"]), + ) + self._block_replay_candidate_queue.put_nowait(candidate) + except BaseException: + with self.lock: + self._block_replay_inflight_hashes.discard(block_hash) + raise + return True + + def _queue_invalid_block_candidate_for_quarantine( + self, + block_hash: str, + error: str, + ) -> None: + """Move malformed-row cleanup off the node-offer lane.""" + if not block_hash: + return + self._ensure_block_replay_state() + key = block_hash.lower() + with self.lock: + if key in self._block_quarantine_hashes: + return + self._block_quarantine_hashes.add(key) + self._block_quarantine_queue.put_nowait((key, error)) + @ledger_writer_operation("accepted_block_handling") def replay_pending_block_candidates(self) -> int: """Queue durable candidate intents not completed by an earlier process.""" @@ -23253,11 +23411,17 @@ def replay_pending_block_candidates(self) -> int: queue_obj = getattr(self, "block_candidate_queue", None) if queue_obj is not None and not queue_obj.empty(): return 0 + self._ensure_block_replay_state() + if not self._block_replay_candidate_queue.empty(): + return 0 pending_rows = getattr(self.ledger, "pending_block_candidate_rows", None) if callable(pending_rows): durable_rows = self._run_block_submitter_ledger_call( ("replay-outbox-query",), "replay-outbox-query", + # Restore a batch with no per-row database work. In-flight + # dedupe lets later rows reach qbitd even while the oldest + # candidate is still accounting. lambda: pending_rows(limit=MAX_PENDING_BLOCK_CANDIDATES), ) else: @@ -23294,102 +23458,22 @@ def replay_pending_block_candidates(self) -> int: intent_block_hash = str(intent.get("block_hash_hex", "")).lower() if not durable_block_hash or intent_block_hash != durable_block_hash: raise ValueError("durable block candidate row key does not match intent") - candidate = self.block_candidate_from_intent(intent) - # Startup replay runs before listeners start. Registering every - # durable hash here also closes the crash seam where submitblock - # landed but preview publication had not yet happened. - self._begin_accepted_block_payout_preview( - durable_block_hash, - block_height=int(intent["expected_height"]), - ) - # A durable prepared/confirmed pool-block row proves a prior - # process's submitblock succeeded. Restore the acceptance - # evidence that died with that process's memory (the - # observation window restarts at replay time), so a replay - # probe racing a transient fork view cannot terminally - # abandon the accepted block before blockwait re-observes it. - block_state = None - state_read_failed = False - try: - state_reader = getattr(self.ledger, "pool_block_state", None) - if callable(state_reader): - block_state = self._run_block_submitter_ledger_call( - ("replay-pool-block-state", durable_block_hash), - "replay-pool-block-state", - lambda block_hash=durable_block_hash, reader=state_reader: reader( - block_hash=block_hash - ), - ) - except Exception: - traceback.print_exc() - block_state = None - # Fail safe: an unreadable durable state must protect the - # candidate like proven acceptance, not strip it. A - # genuinely stale replay then defers only until the - # bounded observation window expires, while an accepted - # block survives a flaky read racing a transient fork. - state_read_failed = True - durable_chain_state = ( - str(block_state.get("chain_state", "")) - if block_state is not None - else "" - ) - if state_read_failed or durable_chain_state in { - "prepared", - "confirmed", - }: - self._register_outstanding_block_candidate( - durable_block_hash - ) - with self.lock: - self._tip_observed_accepted_block_hashes[ - durable_block_hash - ] = time.monotonic() - print( - "prism coordinator: restored acceptance evidence for " - f"replayed block candidate hash={durable_block_hash} " - + ( - "after a failed durable-state read" - if state_read_failed - else f"chain_state={durable_chain_state}" - ), - flush=True, - ) - if self.enqueue_block_candidate(candidate): + candidate = dataclass_replace( + self.block_candidate_from_intent(intent), + durable_replay=True, + ) + # Durable acceptance-state reads stay in accounting. The + # separate replay queue keeps these recovered rows behind any + # live solve while still exposing the whole batch to qbitd. + if self._enqueue_replayed_block_candidate(candidate): queued += 1 except Exception: - if durable_block_hash: - self._clear_accepted_block_payout_preview( - durable_block_hash, - invalidate_published=True, - ) print("prism coordinator: invalid durable block candidate intent", flush=True) traceback.print_exc() - quarantine = getattr(self.ledger, "mark_block_candidate_abandoned", None) - if durable_block_hash and callable(quarantine): - try: - quarantined = self._run_block_submitter_ledger_call( - ("replay-quarantine", durable_block_hash), - "replay-quarantine", - lambda block_hash=durable_block_hash, finish=quarantine: finish( - block_hash=block_hash, - error="invalid durable candidate intent", - ), - ) - self._clear_accepted_block_payout_preview( - durable_block_hash - ) - if quarantined: - self._clear_block_candidate_retry_state(durable_block_hash) - self._discard_outstanding_block_candidate( - durable_block_hash - ) - with self.lock: - self.block_candidate_poisoned_count = int( - getattr(self, "block_candidate_poisoned_count", 0) - ) + 1 - except Exception: - traceback.print_exc() + self._queue_invalid_block_candidate_for_quarantine( + durable_block_hash, + "invalid durable candidate intent", + ) if queued: print( f"prism coordinator: replayed {queued} pending block candidate(s)", @@ -23412,6 +23496,10 @@ def _ensure_block_submitter_ledger_call_state(self) -> None: self._block_submitter_ledger_calls_lock = threading.Lock() if not hasattr(self, "_block_submitter_ledger_calls"): self._block_submitter_ledger_calls = {} + if not hasattr(self, "_block_submitter_ledger_worker_slots"): + self._block_submitter_ledger_worker_slots = threading.BoundedSemaphore( + MAX_BLOCK_SUBMITTER_STUCK_CALL_WORKERS + ) def _block_submitter_db_timeout(self) -> float: return max( @@ -23425,6 +23513,62 @@ def _block_submitter_db_timeout(self) -> float: ), ) + def _block_submitter_stuck_call_exit_timeout(self) -> float: + return max( + 0.001, + float( + getattr( + self, + "block_submit_stuck_call_exit_seconds", + DEFAULT_BLOCK_SUBMIT_STUCK_CALL_EXIT_SECONDS, + ) + ), + ) + + def _maybe_restart_for_stuck_block_call( + self, + *, + kind: str, + started_monotonic: float, + ) -> None: + """Fail stop when a poisoned worker pool stays exhausted.""" + age_seconds = max(0.0, time.monotonic() - started_monotonic) + exit_seconds = self._block_submitter_stuck_call_exit_timeout() + if age_seconds < exit_seconds: + return + stop_event = getattr(self, "stop_event", None) + if stop_event is not None and stop_event.is_set(): + return + print( + "prism coordinator: block work call remained stuck; requesting " + f"restart kind={kind} age={age_seconds:.3f}s " + f"budget={exit_seconds:g}s", + flush=True, + ) + self._fatal_exit_requested = True + self.request_shutdown() + + def _maybe_restart_for_exhausted_block_call_pool( + self, + *, + kind: str, + calls_lock: threading.Lock, + calls: dict[Any, Any], + ) -> None: + """Age an exhausted pool even when retries reuse existing calls.""" + with calls_lock: + active_starts = [ + pending.started_monotonic + for pending in calls.values() + if not pending.done.is_set() + ] + if len(active_starts) < MAX_BLOCK_SUBMITTER_STUCK_CALL_WORKERS: + return + self._maybe_restart_for_stuck_block_call( + kind=kind, + started_monotonic=min(active_starts), + ) + @contextmanager def _block_submitter_ledger_timeout_scope(self) -> Iterator[None]: """Apply the submitter's PostgreSQL deadline when the ledger supports it.""" @@ -23466,6 +23610,24 @@ def _run_block_submitter_ledger_call( with self._block_submitter_ledger_calls_lock: call = self._block_submitter_ledger_calls.get(key) if call is None: + if not self._block_submitter_ledger_worker_slots.acquire( + blocking=False + ): + oldest_started = min( + ( + pending.started_monotonic + for pending in self._block_submitter_ledger_calls.values() + if not pending.done.is_set() + ), + default=time.monotonic(), + ) + self._maybe_restart_for_stuck_block_call( + kind="ledger-worker-pool", + started_monotonic=oldest_started, + ) + raise BlockSubmitterDatabaseTimeout( + f"{phase} could not acquire a bounded ledger worker" + ) call = _BlockSubmitterLedgerCall() self._block_submitter_ledger_calls[key] = call @@ -23477,6 +23639,7 @@ def run() -> None: call.error = exc finally: call.done.set() + self._block_submitter_ledger_worker_slots.release() threading.Thread( target=run, @@ -23490,6 +23653,11 @@ def run() -> None: self._record_block_submitter_wait(phase) remaining = deadline - time.monotonic() if remaining <= 0: + self._maybe_restart_for_exhausted_block_call_pool( + kind="ledger-worker-pool", + calls_lock=self._block_submitter_ledger_calls_lock, + calls=self._block_submitter_ledger_calls, + ) print( "prism coordinator: block submitter ledger phase timed out " f"phase={phase} timeout={timeout_seconds:g}s", @@ -23501,7 +23669,7 @@ def run() -> None: call.done.wait( min( remaining, - BLOCK_SUBMITTER_WAIT_HEARTBEAT_SLICE_SECONDS, + self._block_work_wait_slice(), ) ) self._record_block_submitter_wait(f"{phase}:complete") @@ -23532,10 +23700,7 @@ def _wait_for_block_candidate_retry(self, delay_seconds: float) -> bool: try: while remaining > 0: self._record_block_submitter_wait("retry-backoff") - wait_slice = min( - remaining, - BLOCK_CANDIDATE_RETRY_HEARTBEAT_SLICE_SECONDS, - ) + wait_slice = min(remaining, self._block_work_wait_slice()) if self.stop_event.wait(wait_slice): return True remaining = max(0.0, remaining - wait_slice) @@ -23580,55 +23745,170 @@ def _rpc_call_with_timeout( return call(method, params, timeout=timeout_seconds) return call(method, params) - def _submit_block_candidate_to_node( - self, - candidate: PrismBlockCandidate, - ) -> _BlockCandidateNodeSubmission: - """Offer the durable candidate to qbitd before any accounting work.""" - block_hash = str(candidate.submission.block_hash_hex).lower() - self._register_outstanding_block_candidate(block_hash) - self._record_block_submitter_phase("submitblock-rpc") - timeout_seconds = max( - 0.001, - float( - getattr( - self, - "block_submit_rpc_timeout_seconds", - DEFAULT_BLOCK_SUBMIT_RPC_TIMEOUT_SECONDS, - ) - ), - ) - try: - result = self._rpc_call_with_timeout( - "submitblock", - [candidate.submission.block_hex], - timeout_seconds=timeout_seconds, - ) - except BaseException as exc: - self._record_block_submitter_phase("submitblock-rpc:error") - return _BlockCandidateNodeSubmission( - attempted=True, - error=exc, + def _ensure_block_submitter_rpc_call_state(self) -> None: + if not hasattr(self, "_block_submitter_rpc_calls_lock"): + self._block_submitter_rpc_calls_lock = threading.Lock() + if not hasattr(self, "_block_submitter_rpc_calls"): + self._block_submitter_rpc_calls = {} + if not hasattr(self, "_block_submitter_rpc_worker_slots"): + self._block_submitter_rpc_worker_slots = threading.BoundedSemaphore( + MAX_BLOCK_SUBMITTER_STUCK_CALL_WORKERS ) - self._record_block_submitter_phase("submitblock-rpc:complete") - landed_monotonic = getattr(candidate, "landed_monotonic", None) - if landed_monotonic is not None: - self._observe_block_submit_seconds( - time.monotonic() - float(landed_monotonic) - ) - return _BlockCandidateNodeSubmission( - attempted=True, - result=result, - ) - def _node_submission_for_candidate( + def _run_submitblock_rpc_with_hard_deadline( self, - candidate: PrismBlockCandidate, - ) -> _BlockCandidateNodeSubmission: - """Choose the node fast lane unless the pool was already closed.""" - block_hash = str(candidate.submission.block_hash_hex).lower() - self._record_block_submitter_phase("fast-lane-admission") - with self.lock: + *, + block_hash: str, + block_hex: str, + timeout_seconds: float, + ) -> Any: + """Bound wall time even when an RPC adapter ignores its timeout.""" + self._ensure_block_submitter_rpc_call_state() + with self._block_submitter_rpc_calls_lock: + call = self._block_submitter_rpc_calls.get(block_hash) + if call is None: + if not self._block_submitter_rpc_worker_slots.acquire( + blocking=False + ): + oldest_started = min( + ( + pending.started_monotonic + for pending in self._block_submitter_rpc_calls.values() + if not pending.done.is_set() + ), + default=time.monotonic(), + ) + self._maybe_restart_for_stuck_block_call( + kind="rpc-worker-pool", + started_monotonic=oldest_started, + ) + raise TimeoutError( + "submitblock could not acquire a bounded RPC worker" + ) + call = _BlockSubmitterRpcCall() + self._block_submitter_rpc_calls[block_hash] = call + + def run() -> None: + try: + call.result = self._rpc_call_with_timeout( + "submitblock", + [block_hex], + timeout_seconds=timeout_seconds, + ) + except BaseException as exc: + call.error = exc + finally: + call.done.set() + self._block_submitter_rpc_worker_slots.release() + + threading.Thread( + target=run, + name=f"prism-block-rpc-{block_hash[:12]}", + daemon=True, + ).start() + + deadline = time.monotonic() + timeout_seconds + while not call.done.is_set(): + self._record_block_submitter_wait("submitblock-rpc") + remaining = deadline - time.monotonic() + if remaining <= 0: + self._maybe_restart_for_exhausted_block_call_pool( + kind="rpc-worker-pool", + calls_lock=self._block_submitter_rpc_calls_lock, + calls=self._block_submitter_rpc_calls, + ) + raise TimeoutError( + f"submitblock exceeded {timeout_seconds:g}s" + ) + call.done.wait( + min(remaining, self._block_work_wait_slice()) + ) + with self._block_submitter_rpc_calls_lock: + if self._block_submitter_rpc_calls.get(block_hash) is call: + self._block_submitter_rpc_calls.pop(block_hash, None) + if call.error is not None: + raise call.error + return call.result + + def _arm_block_candidate_after_node_offer( + self, + candidate: PrismBlockCandidate, + node_submission: _BlockCandidateNodeSubmission, + ) -> None: + """Fence child payout work as soon as node acceptance is possible.""" + ambiguous_or_landed = ( + node_submission.error is not None + or node_submission.result in (None, "duplicate") + ) + if not ambiguous_or_landed: + self._release_block_fast_lane_slot( + str(candidate.submission.block_hash_hex) + ) + return + block_hash = str(candidate.submission.block_hash_hex).lower() + expected_height = int(candidate.context.template["height"]) + self._begin_accepted_block_payout_preview( + block_hash, + block_height=expected_height, + ) + + def _submit_block_candidate_to_node( + self, + candidate: PrismBlockCandidate, + ) -> _BlockCandidateNodeSubmission: + """Offer the durable candidate to qbitd before any accounting work.""" + block_hash = str(candidate.submission.block_hash_hex).lower() + self._begin_accepted_block_payout_preview( + block_hash, + block_height=int(candidate.context.template["height"]), + ) + self._register_outstanding_block_candidate(block_hash) + self._record_block_submitter_phase("submitblock-rpc") + timeout_seconds = max( + 0.001, + float( + getattr( + self, + "block_submit_rpc_timeout_seconds", + DEFAULT_BLOCK_SUBMIT_RPC_TIMEOUT_SECONDS, + ) + ), + ) + try: + result = self._run_submitblock_rpc_with_hard_deadline( + block_hash=block_hash, + block_hex=str(candidate.submission.block_hex), + timeout_seconds=timeout_seconds, + ) + except BaseException as exc: + self._record_block_submitter_phase("submitblock-rpc:error") + node_submission = _BlockCandidateNodeSubmission( + attempted=True, + error=exc, + ) + self._arm_block_candidate_after_node_offer(candidate, node_submission) + return node_submission + self._record_block_submitter_phase("submitblock-rpc:complete") + landed_monotonic = getattr(candidate, "landed_monotonic", None) + if landed_monotonic is not None: + self._observe_block_submit_seconds( + time.monotonic() - float(landed_monotonic) + ) + node_submission = _BlockCandidateNodeSubmission( + attempted=True, + result=result, + ) + self._arm_block_candidate_after_node_offer(candidate, node_submission) + return node_submission + + def _node_submission_for_candidate( + self, + candidate: PrismBlockCandidate, + ) -> _BlockCandidateNodeSubmission: + """Choose the node fast lane unless the pool was already closed.""" + block_hash = str(candidate.submission.block_hash_hex).lower() + self._record_block_submitter_phase("fast-lane-admission") + with self.lock: accounted_hashes = getattr( self, "_accounted_accepted_block_hashes", @@ -23691,11 +23971,120 @@ def _account_block_candidate_after_node_submit( return bool(submit(candidate, node_submission=node_submission)) return bool(submit(candidate)) + def _submit_synchronous_block_candidate( + self, + candidate: PrismBlockCandidate, + ) -> bool: + """Run the rare miner-facing path under one same-hash disposition.""" + block_hash = str(candidate.submission.block_hash_hex).lower() + with self._block_candidate_disposition(block_hash): + terminal_outcome = self._block_candidate_terminal_outcome(block_hash) + if terminal_outcome is not None: + self._finish_pending_share_commit(candidate.pending_share) + return terminal_outcome + outcome = getattr(self, "_block_candidate_outcome", None) + if outcome is None: + outcome = threading.local() + self._block_candidate_outcome = outcome + # The accepted/rejected accounting tail may already be complete + # while only its durable outbox terminal update is retrying. A + # synchronous same-hash waiter must join that finalize-only state; + # another node offer/accounting pass could invert the outcome. + with self.lock: + registry = getattr(self, "_block_candidate_finalize_retries", None) + pending_finalize = ( + registry.get(block_hash) if registry is not None else None + ) + if pending_finalize is not None: + accepted, error = pending_finalize + self._finalize_block_candidate( + candidate, + block_hash=block_hash, + accepted=accepted, + error=error, + outcome=outcome, + ) + return accepted + try: + node_submission = self._node_submission_for_candidate(candidate) + self._mark_block_candidate_attempted(block_hash) + with self._block_submitter_ledger_statement_timeout_scope(): + production_submit = ( + getattr(self.submit_block_candidate, "__func__", None) + is PrismCoordinator.submit_block_candidate + ) + if production_submit: + block_landed = self._submit_block_candidate_serialized( + candidate, + node_submission=node_submission, + ) + else: + block_landed = self._account_block_candidate_after_node_submit( + candidate, + node_submission, + ) + except BaseException: + self._retain_block_candidate_for_retry(candidate) + raise + + if not block_landed: + reason = getattr(outcome, "reason", None) + if reason in {None, *PRISM_RETRYABLE_BLOCK_CANDIDATE_REASONS}: + self._retain_block_candidate_for_retry(candidate) + raise RuntimeError( + "block candidate outcome is pending durable retry" + ) + abandon_error = getattr(outcome, "error", None) + try: + self._record_block_submitter_phase( + "reject-prepared-block" + ) + with self._block_submitter_ledger_statement_timeout_scope(): + self._reject_terminal_prepared_block_candidate(candidate) + self._record_block_submitter_phase( + "reject-prepared-block:complete" + ) + except Exception as exc: + # A prior attempt may have persisted prepared payout rows + # before this synchronous resubmit reached a false terminal + # verdict. Keep the outbox pending until those rows can be + # rejected; otherwise restart replay is removed while its + # balance transition remains live. + self._defer_block_candidate( + PRISM_REJECTION_BACKEND_RPC_UNAVAILABLE, + "could not reject prepared state for terminal candidate", + worker=candidate.client.username or None, + ) + self._retain_block_candidate_for_retry(candidate) + raise RuntimeError( + "could not reject prepared state for terminal candidate" + ) from exc + self._finalize_block_candidate( + candidate, + block_hash=block_hash, + accepted=False, + error=str(abandon_error or reason), + outcome=outcome, + ) + return False + + self._finalize_block_candidate( + candidate, + block_hash=block_hash, + accepted=True, + error="", + outcome=outcome, + ) + return True + def _ensure_block_candidate_disposition_state(self) -> None: """Backfill same-hash submission guards for lightweight embedders.""" if ( hasattr(self, "_block_candidate_disposition_registry_lock") and hasattr(self, "_block_candidate_disposition_flights") + and hasattr(self, "_block_candidate_terminal_outcomes") + and hasattr(self, "_block_fast_lane_reservations") + and hasattr(self, "_block_disposition_waiting_retries") ): return with _HOT_PATH_LOCK_INITIALIZATION_LOCK: @@ -23705,18 +24094,22 @@ def _ensure_block_candidate_disposition_state(self) -> None: self._block_candidate_disposition_flights: dict[ str, _BlockCandidateDispositionFlight ] = {} + if not hasattr(self, "_block_candidate_terminal_outcomes"): + self._block_candidate_terminal_outcomes: dict[str, bool] = {} + if not hasattr(self, "_block_fast_lane_reservations"): + self._block_fast_lane_reservations: set[str] = set() + if not hasattr(self, "_block_disposition_waiting_retries"): + self._block_disposition_waiting_retries: dict[ + str, PrismBlockCandidate + ] = {} - @contextmanager - def _block_candidate_disposition(self, block_hash: str) -> Iterator[None]: - """Serialize the full accepted/abandoned decision for one hash. - - A below-share-target solve submits synchronously while the durable - outbox can concurrently replay that same candidate. Keep both attempts - ordered until the accepted success tail records its process-local - completion; otherwise the replay can terminally abandon the outbox - during the gap after durable confirmation but before audit/share - evidence is complete. - """ + def _claim_block_candidate_disposition( + self, + block_hash: str, + *, + blocking: bool, + ) -> _BlockCandidateDispositionLease | None: + """Claim one hash without making unrelated node offers wait.""" key = block_hash.lower() self._ensure_block_candidate_disposition_state() with self._block_submitter_lock( @@ -23728,37 +24121,436 @@ def _block_candidate_disposition(self, block_hash: str) -> Iterator[None]: flight = _BlockCandidateDispositionFlight() self._block_candidate_disposition_flights[key] = flight flight.users += 1 + if blocking: + self._acquire_block_submitter_lock( + flight.lock, + f"candidate-disposition:{key}", + ) + acquired = True + else: + acquired = flight.lock.acquire(blocking=False) + if acquired: + return _BlockCandidateDispositionLease(key, flight) + self._drop_block_candidate_disposition_user(key, flight) + return None + + def _drop_block_candidate_disposition_user( + self, + key: str, + flight: _BlockCandidateDispositionFlight, + ) -> None: + with self._block_submitter_lock( + self._block_candidate_disposition_registry_lock, + "candidate-disposition-registry", + ): + flight.users -= 1 + if ( + flight.users == 0 + and self._block_candidate_disposition_flights.get(key) is flight + ): + self._block_candidate_disposition_flights.pop(key, None) + + def _release_block_candidate_disposition( + self, + lease: _BlockCandidateDispositionLease, + ) -> None: + lease.flight.lock.release() + self._drop_block_candidate_disposition_user( + lease.block_hash, + lease.flight, + ) + + def _block_candidate_terminal_outcome(self, block_hash: str) -> bool | None: + self._ensure_block_candidate_disposition_state() + with self.lock: + return self._block_candidate_terminal_outcomes.get(block_hash.lower()) + + def _record_block_candidate_terminal_outcome( + self, + block_hash: str, + *, + accepted: bool, + ) -> None: + self._ensure_block_candidate_disposition_state() + with self.lock: + key = block_hash.lower() + self._block_candidate_terminal_outcomes[key] = accepted + self._block_fast_lane_reservations.discard(key) + replay_hashes = getattr(self, "_block_replay_inflight_hashes", None) + if replay_hashes is not None: + replay_hashes.discard(key) + waiting = getattr(self, "_block_disposition_waiting_retries", None) + if waiting is not None: + waiting.pop(key, None) + + def _record_committed_block_candidate_abandonment( + self, + block_hash: str, + outcome: threading.local, + ) -> None: + """Count an abandonment only after its terminal cleanup is fixed. + + ``_abandon_block_candidate`` seals a proposed rejection before any + prepared payout rows are removed. That cleanup can fail, in which + case the candidate is deliberately re-registered and can still prove + accepted on a later pass. Counting at the seal would then expose the + same hash as both abandoned and accepted. The writer calls this only + after cleanup succeeds or after a false finalize-only disposition is + installed; direct accounting callers invoke it only after the full + serialized rejection path returns. + """ + reason = getattr(outcome, "reason", None) + if not isinstance(reason, str) or not reason: + return + if reason in PRISM_RETRYABLE_BLOCK_CANDIDATE_REASONS: + return + stale_job_class = getattr(outcome, "stale_job_class", None) + key = block_hash.lower() + with self.lock: + counted_abandonments = getattr( + self, + "_counted_block_candidate_abandonments", + None, + ) + if counted_abandonments is None: + counted_abandonments = set() + self._counted_block_candidate_abandonments = counted_abandonments + if key in counted_abandonments: + return + counted_abandonments.add(key) + counts = getattr(self, "block_candidate_abandoned_counts", None) + if counts is None: + counts = {} + self.block_candidate_abandoned_counts = counts + counts[reason] = int(counts.get(reason, 0)) + 1 + if stale_job_class is not None: + stale_counts = getattr(self, "stale_job_abandon_counts", None) + if stale_counts is None: + stale_counts = { + abandon_class: 0 + for abandon_class in PRISM_STALE_JOB_ABANDON_CLASSES + } + self.stale_job_abandon_counts = stale_counts + stale_counts[stale_job_class] = ( + int(stale_counts.get(stale_job_class, 0)) + 1 + ) + + def _reserve_block_fast_lane_slot(self, block_hash: str) -> bool: + """Reserve configured pool capacity before asynchronous accounting.""" + key = block_hash.lower() + with self.lock: + reservations = getattr(self, "_block_fast_lane_reservations", None) + if reservations is None: + reservations = set() + self._block_fast_lane_reservations = reservations + if key in reservations: + return True + accepted_count = int(getattr(self, "accepted_block_count", 0)) + capacity = int(getattr(self, "max_blocks", 2**31 - 1)) + stop_after_one = bool(getattr(self, "stop_after_block", False)) + reserved_count = len(reservations) + if accepted_count + reserved_count >= capacity: + return False + if stop_after_one and accepted_count + reserved_count >= 1: + return False + reservations.add(key) + return True + + def _release_block_fast_lane_slot(self, block_hash: str) -> None: + with self.lock: + reservations = getattr(self, "_block_fast_lane_reservations", None) + if reservations is not None: + reservations.discard(block_hash.lower()) + + @contextmanager + def _block_candidate_disposition( + self, + block_hash: str, + ) -> Iterator[_BlockCandidateDispositionLease]: + """Serialize the full accepted/abandoned decision for one hash. + + A below-share-target solve submits synchronously while the durable + outbox can concurrently replay that same candidate. Keep both attempts + ordered until the accepted success tail records its process-local + completion; otherwise the replay can terminally abandon the outbox + during the gap after durable confirmation but before audit/share + evidence is complete. + """ + lease = self._claim_block_candidate_disposition( + block_hash, + blocking=True, + ) + assert lease is not None try: - # Never hold the registry lock while waiting on the hash-specific - # guard: unrelated candidates must remain independent. - guard = ( - self._block_submitter_lock( - flight.lock, - f"candidate-disposition:{key}", + yield lease + finally: + self._release_block_candidate_disposition(lease) + + def _ensure_block_accounting_state(self) -> None: + if not hasattr(self, "_block_accounting_state_lock"): + self._block_accounting_state_lock = threading.Lock() + if not hasattr(self, "_block_accounting_queue"): + self._block_accounting_queue = queue.PriorityQueue() + if not hasattr(self, "_block_accounting_overflow_queue"): + self._block_accounting_overflow_queue = queue.PriorityQueue() + if not hasattr(self, "_block_accounting_sequence"): + self._block_accounting_sequence = 0 + if not hasattr(self, "_block_accounting_thread"): + self._block_accounting_thread = None + + def _start_block_accounting_thread(self) -> threading.Thread: + self._ensure_block_accounting_state() + with self._block_accounting_state_lock: + thread = self._block_accounting_thread + if thread is not None and thread.is_alive(): + return thread + self._record_block_work_heartbeat("block_accounting", "starting") + thread = threading.Thread( + target=self.block_accounting_loop, + name="prism-block-accounting", + daemon=True, + ) + self._block_accounting_thread = thread + thread.start() + return thread + + def _enqueue_block_accounting_task( + self, + task: _BlockCandidateAccountingTask, + ) -> bool: + self._ensure_block_accounting_state() + with self._block_accounting_state_lock: + sequence = self._block_accounting_sequence + self._block_accounting_sequence += 1 + priority = int(task.candidate.context.template["height"]) + item = (priority, sequence, task) + if not self._block_accounting_overflow_queue.empty(): + # Once spillover begins, keep later handoffs behind it instead of + # repeatedly refilling the primary queue and starving older spill + # entries. + self._block_accounting_overflow_queue.put_nowait(item) + return True + try: + self._block_accounting_queue.put_nowait(item) + return True + except queue.Full: + # A node offer has already happened and must never be converted + # back into a raw-submit retry. Preserve its result and lease in + # an unbounded, process-local overflow queue; max-block admission + # bounds the number of unresolved real offers. + self._block_accounting_overflow_queue.put_nowait(item) + print( + "prism coordinator: block accounting handoff spilled " + f"hash={task.candidate.submission.block_hash_hex}", + flush=True, + ) + return True + + def _run_one_invalid_block_candidate_quarantine(self) -> bool: + self._ensure_block_replay_state() + try: + block_hash, error = self._block_quarantine_queue.get_nowait() + except queue.Empty: + return False + completed = False + try: + self._record_block_submitter_phase("replay-quarantine") + quarantine = getattr( + self.ledger, + "mark_block_candidate_abandoned", + None, + ) + if callable(quarantine): + quarantined = self._run_block_submitter_ledger_call( + ("replay-quarantine", block_hash), + "replay-quarantine", + lambda: quarantine(block_hash=block_hash, error=error), ) - if hasattr(flight.lock, "acquire") - else flight.lock + self._clear_accepted_block_payout_preview(block_hash) + if quarantined: + self._clear_block_candidate_retry_state(block_hash) + self._discard_outstanding_block_candidate(block_hash) + with self.lock: + self.block_candidate_poisoned_count = int( + getattr(self, "block_candidate_poisoned_count", 0) + ) + 1 + completed = True + return True + except Exception: + print( + "prism coordinator: invalid candidate quarantine failed " + f"hash={block_hash}", + flush=True, ) - with guard: - yield + traceback.print_exc() + return True finally: - with self._block_submitter_lock( - self._block_candidate_disposition_registry_lock, - "candidate-disposition-registry", - ): - flight.users -= 1 - if ( - flight.users == 0 - and self._block_candidate_disposition_flights.get(key) - is flight - ): - self._block_candidate_disposition_flights.pop(key, None) + self._block_quarantine_queue.task_done() + if completed: + with self.lock: + self._block_quarantine_hashes.discard(block_hash) + elif not self.stop_event.is_set(): + self._block_quarantine_queue.put_nowait((block_hash, error)) + + def _call_block_candidate_writer( + self, + candidate: PrismBlockCandidate, + *, + node_submission: _BlockCandidateNodeSubmission, + disposition_held: bool, + ) -> bool: + """Invoke the writer while preserving duck-typed test integrations.""" + writer = self._submit_next_block_candidate_writer + supports_disposition_held = True + try: + parameters = inspect.signature(writer).parameters.values() + supports_disposition_held = any( + parameter.name == "disposition_held" + or parameter.kind is inspect.Parameter.VAR_KEYWORD + for parameter in parameters + ) + except (TypeError, ValueError): + pass + if supports_disposition_held: + return bool( + writer( + candidate, + node_submission=node_submission, + disposition_held=disposition_held, + ) + ) + return bool(writer(candidate, node_submission=node_submission)) + + def _restore_replayed_candidate_acceptance_evidence( + self, + candidate: PrismBlockCandidate, + ) -> None: + if not candidate.durable_replay: + return + block_hash = str(candidate.submission.block_hash_hex).lower() + block_state = None + state_read_failed = False + state_reader = getattr(self.ledger, "pool_block_state", None) + if callable(state_reader): + try: + block_state = self._run_block_submitter_ledger_call( + ("replay-pool-block-state", block_hash), + "replay-pool-block-state", + lambda: state_reader(block_hash=block_hash), + ) + except Exception: + traceback.print_exc() + state_read_failed = True + durable_chain_state = ( + str(block_state.get("chain_state", "")) + if block_state is not None + else "" + ) + if state_read_failed or durable_chain_state in {"prepared", "confirmed"}: + self._register_outstanding_block_candidate(block_hash) + with self.lock: + self._tip_observed_accepted_block_hashes[block_hash] = ( + time.monotonic() + ) + print( + "prism coordinator: restored acceptance evidence for " + f"replayed block candidate hash={block_hash} " + + ( + "after a failed durable-state read" + if state_read_failed + else f"chain_state={durable_chain_state}" + ), + flush=True, + ) + + def _run_block_accounting_task( + self, + task: _BlockCandidateAccountingTask, + ) -> None: + candidate = task.candidate + with self.lock: + self._block_accounting_holds_disposition = True + self._block_accounting_deferred_retry_candidate = None + outcome = getattr(self, "_block_candidate_outcome", None) + if outcome is None: + outcome = threading.local() + self._block_candidate_outcome = outcome + outcome.refresh_client = None + try: + self._restore_replayed_candidate_acceptance_evidence(candidate) + with self._writer_operation("accepted_block_handling"): + self._call_block_candidate_writer( + candidate, + node_submission=task.node_submission, + disposition_held=True, + ) + refresh_client = getattr(outcome, "refresh_client", None) + outcome.refresh_client = None + except ShutdownInProgress: + return + finally: + self._release_block_candidate_disposition(task.disposition_lease) + with self.lock: + self._block_accounting_holds_disposition = False + deferred_retry = getattr( + self, + "_block_accounting_deferred_retry_candidate", + None, + ) + self._block_accounting_deferred_retry_candidate = None + if deferred_retry is not None: + self._merge_block_candidate_retry_locked( + "_retry_block_candidate", + deferred_retry, + ) + if refresh_client is not None and not self.stop_event.is_set(): + self._record_block_submitter_phase("refresh-jobs") + self.refresh_jobs_after_pending_accepted_block( + refresh_client, + heartbeat_name="block_accounting", + ) + self._record_block_submitter_phase("refresh-jobs:complete") + + def block_accounting_loop(self) -> None: + self._block_accounting_thread_ident = threading.get_ident() + self._ensure_block_accounting_state() + while not self.stop_event.is_set(): + self._record_block_submitter_phase("accounting-queue") + source_queue = None + try: + _priority, _sequence, task = self._block_accounting_queue.get_nowait() + source_queue = self._block_accounting_queue + except queue.Empty: + try: + _priority, _sequence, task = ( + self._block_accounting_overflow_queue.get_nowait() + ) + source_queue = self._block_accounting_overflow_queue + except queue.Empty: + if self._run_one_invalid_block_candidate_quarantine(): + continue + self.stop_event.wait(self._block_work_wait_slice()) + continue + try: + self._run_block_accounting_task(task) + except Exception: + print( + "prism coordinator: block accounting iteration failed; " + "durable candidate remains pending", + flush=True, + ) + traceback.print_exc() + self._retain_block_candidate_for_retry(task.candidate) + finally: + assert source_queue is not None + source_queue.task_done() def block_submit_loop(self) -> None: # Boundary stamps in _record_block_candidate_progress are gated to # this thread so client-thread dispositions cannot refresh the # submitter's liveness budget on its behalf. self._block_submitter_thread_ident = threading.get_ident() + self._start_block_accounting_thread() while not self.stop_event.is_set(): self._record_block_submitter_phase("loop") try: @@ -23770,13 +24562,24 @@ def block_submit_loop(self) -> None: getattr(self, "_retry_block_candidate", None) is not None ) queue_obj = getattr(self, "block_candidate_queue", None) - wakeup_ready = ( - queue_obj is not None and not queue_obj.empty() + replay_queue = getattr( + self, + "_block_replay_candidate_queue", + None, + ) + wakeup_ready = bool( + (queue_obj is not None and not queue_obj.empty()) + or (replay_queue is not None and not replay_queue.empty()) ) - if (retry_ready or wakeup_ready) and self.submit_next_block_candidate(): + if (retry_ready or wakeup_ready) and self.submit_next_block_candidate( + defer_accounting=True + ): continue self.replay_pending_block_candidates() - self.submit_next_block_candidate(timeout=1.0) + self.submit_next_block_candidate( + timeout=1.0, + defer_accounting=True, + ) except ShutdownInProgress: # Admission can close after the loop condition. Durable block # candidates remain in the outbox for the replacement writer. @@ -23799,7 +24602,12 @@ def block_submit_loop(self) -> None: if self._wait_for_block_candidate_retry(retry_delay): return - def submit_next_block_candidate(self, timeout: float | None = None) -> bool: + def submit_next_block_candidate( + self, + timeout: float | None = None, + *, + defer_accounting: bool = False, + ) -> bool: """Dequeue and land one block candidate; returns True when one ran. The block-submitter loop calls this continuously; tests call it @@ -23812,39 +24620,179 @@ def submit_next_block_candidate(self, timeout: float | None = None) -> bool: self._retry_block_candidate = None if candidate is None: queue_obj = getattr(self, "block_candidate_queue", None) - if queue_obj is None: + self._ensure_block_replay_state() + replay_queue = self._block_replay_candidate_queue + if queue_obj is None and replay_queue is None: return False - try: + deadline = ( + None + if timeout is None + else time.monotonic() + max(0.0, timeout) + ) + while candidate is None: self._record_block_submitter_phase("dequeue-queue") - if timeout is None: - candidate = queue_obj.get_nowait() - else: - candidate = queue_obj.get(timeout=timeout) - except queue.Empty: - return False + # Live discoveries always outrank durable restart replay. + for candidate_queue in (queue_obj, replay_queue): + if candidate_queue is None: + continue + try: + candidate = candidate_queue.get_nowait() + break + except queue.Empty: + pass + if candidate is None: + self._ensure_block_candidate_disposition_state() + with self.lock: + waiting = self._block_disposition_waiting_retries + if waiting: + waiting_hash = min( + waiting, + key=lambda key: int( + waiting[key].context.template["height"] + ), + ) + candidate = waiting.pop(waiting_hash) + if candidate is not None: + break + if deadline is None: + return False + remaining = deadline - time.monotonic() + if remaining <= 0: + return False + if self.stop_event.wait( + min(remaining, self._block_work_wait_slice()) + ): + return False + + block_hash = str(candidate.submission.block_hash_hex).lower() + lease = self._claim_block_candidate_disposition( + block_hash, + blocking=not defer_accounting, + ) + if lease is None: + # Another same-hash pass already spans node offer through durable + # finalization. Keep this wakeup outside the global parent retry + # slot until that lease transfers/releases: consuming it can lose + # an accounting retry, while repeatedly prioritizing it can starve + # unrelated live blocks. + with self.lock: + self._block_disposition_waiting_retries[block_hash] = candidate + self._wait_for_block_candidate_retry( + float( + getattr( + self, + "block_candidate_retry_initial_seconds", + DEFAULT_BLOCK_CANDIDATE_RETRY_INITIAL_SECONDS, + ) + ) + ) + return True + transferred = False + if self._block_candidate_terminal_outcome(block_hash) is not None: + self._release_block_candidate_disposition(lease) + return True outcome = getattr(self, "_block_candidate_outcome", None) if outcome is None: outcome = threading.local() self._block_candidate_outcome = outcome outcome.refresh_client = None - block_hash = str(candidate.submission.block_hash_hex).lower() self._record_block_submitter_phase("finalize-registry") with self.lock: registry = getattr(self, "_block_candidate_finalize_retries", None) pending_finalize = ( registry.get(block_hash) if registry is not None else None ) - node_submission = ( - None - if pending_finalize is not None - else self._node_submission_for_candidate(candidate) - ) + if pending_finalize is None: + permanently_closed = False + already_accounted = False + if defer_accounting: + with self.lock: + accounted_hashes = getattr( + self, + "_accounted_accepted_block_hashes", + set(), + ) + already_accounted = block_hash in accounted_hashes + accepted_count = int(getattr(self, "accepted_block_count", 0)) + permanently_closed = not already_accounted and ( + accepted_count >= int(getattr(self, "max_blocks", 2**31 - 1)) + or ( + bool(getattr(self, "stop_after_block", False)) + and accepted_count >= 1 + ) + ) + if permanently_closed or already_accounted: + # Accounting must terminalize a durable outbox row even + # after pool capacity closes. An already-accounted hash + # likewise needs only its exact-idempotent/finalize tail. + node_submission = _BlockCandidateNodeSubmission( + attempted=False + ) + elif not self._reserve_block_fast_lane_slot(block_hash): + # Capacity is provisionally occupied by another unresolved + # node offer. Preserve strict max-block semantics until + # that offer either accounts or terminates. + self._release_block_candidate_disposition(lease) + self._retain_block_candidate_for_retry(candidate) + self._wait_for_block_candidate_retry( + float( + getattr( + self, + "block_candidate_retry_initial_seconds", + DEFAULT_BLOCK_CANDIDATE_RETRY_INITIAL_SECONDS, + ) + ) + ) + return True + else: + try: + node_submission = self._node_submission_for_candidate(candidate) + except BaseException: + self._release_block_candidate_disposition(lease) + raise + else: + try: + node_submission = self._node_submission_for_candidate(candidate) + except BaseException: + self._release_block_candidate_disposition(lease) + raise + else: + node_submission = _BlockCandidateNodeSubmission(attempted=False) + + if defer_accounting: + task = _BlockCandidateAccountingTask( + candidate=candidate, + node_submission=node_submission, + disposition_lease=lease, + ) + try: + enqueued = self._enqueue_block_accounting_task(task) + except BaseException: + self._release_block_candidate_disposition(lease) + raise + if enqueued: + transferred = True + return True + self._release_block_candidate_disposition(lease) + self._retain_block_candidate_for_retry(candidate) + self._wait_for_block_candidate_retry( + float( + getattr( + self, + "block_candidate_retry_initial_seconds", + DEFAULT_BLOCK_CANDIDATE_RETRY_INITIAL_SECONDS, + ) + ) + ) + return True + try: with self._writer_operation("accepted_block_handling"): - ran = self._submit_next_block_candidate_writer( + ran = self._call_block_candidate_writer( candidate, node_submission=node_submission, + disposition_held=True, ) refresh_client = getattr(outcome, "refresh_client", None) outcome.refresh_client = None @@ -23853,14 +24801,19 @@ def submit_next_block_candidate(self, timeout: float | None = None) -> bool: # will replay it. Dequeuing the in-memory wakeup during the # admission-close race cannot lose candidate work. return False + finally: + if not transferred: + self._release_block_candidate_disposition(lease) # Fresh-job fanout is deliberately outside the writer admission. Once # the candidate outbox is finalized it cannot mutate the ledger, so a # blocked client send must not hold the writer lease during shutdown. if refresh_client is not None and not self.stop_event.is_set(): + self._record_block_submitter_phase("refresh-jobs") self.refresh_jobs_after_pending_accepted_block( refresh_client, heartbeat_name="block_submitter", ) + self._record_block_submitter_phase("refresh-jobs:complete") return ran def _submit_next_block_candidate_writer( @@ -23868,15 +24821,37 @@ def _submit_next_block_candidate_writer( candidate: PrismBlockCandidate, *, node_submission: _BlockCandidateNodeSubmission | None = None, + disposition_held: bool = False, ) -> bool: """Land one dequeued block candidate inside writer admission.""" + block_hash = str(candidate.submission.block_hash_hex).lower() + if not disposition_held: + # Preserve the historical direct-writer seam while keeping its + # node offer and terminal outbox decision inside the same-hash + # guard. Production queue/accounting calls transfer an existing + # lease and skip this wrapper. + with self._block_candidate_disposition(block_hash): + terminal_outcome = self._block_candidate_terminal_outcome( + block_hash + ) + if terminal_outcome is not None: + return terminal_outcome + if node_submission is None: + node_submission = self._node_submission_for_candidate( + candidate + ) + return self._submit_next_block_candidate_writer( + candidate, + node_submission=node_submission, + disposition_held=True, + ) outcome = getattr(self, "_block_candidate_outcome", None) if outcome is None: outcome = threading.local() self._block_candidate_outcome = outcome outcome.reason = None outcome.error = None - block_hash = str(candidate.submission.block_hash_hex).lower() + outcome.stale_job_class = None self._record_block_submitter_phase("finalize-registry") with self.lock: registry = getattr(self, "_block_candidate_finalize_retries", None) @@ -23916,10 +24891,23 @@ def _submit_next_block_candidate_writer( try: self._record_block_submitter_phase("accounting") with self._block_submitter_ledger_statement_timeout_scope(): - accepted = self._account_block_candidate_after_node_submit( - candidate, - node_submission, + production_submit = ( + getattr(self.submit_block_candidate, "__func__", None) + is PrismCoordinator.submit_block_candidate ) + if disposition_held and production_submit: + assert node_submission is not None + accepted = self._submit_block_candidate_serialized( + candidate, + node_submission=node_submission, + ) + elif node_submission is None: + accepted = bool(self.submit_block_candidate(candidate)) + else: + accepted = self._account_block_candidate_after_node_submit( + candidate, + node_submission, + ) except Exception: error = "candidate submission raised an exception" print( @@ -23953,7 +24941,12 @@ def _submit_next_block_candidate_writer( return True if not accepted: try: - self._reject_terminal_prepared_block_candidate(candidate) + self._record_block_submitter_phase("reject-prepared-block") + with self._block_submitter_ledger_statement_timeout_scope(): + self._reject_terminal_prepared_block_candidate(candidate) + self._record_block_submitter_phase( + "reject-prepared-block:complete" + ) except Exception: # Persistence may have committed before a later RPC/transport # failure. Do not terminally discard the outbox row until its @@ -24023,6 +25016,10 @@ def _finalize_block_candidate( "finalize-outbox-abandoned", lambda: finish(block_hash=block_hash, error=error), ) + self._record_committed_block_candidate_abandonment( + block_hash, + outcome, + ) # The invalidation tombstone is needed until the durable # outbox becomes terminal. A normal return (including an # already-terminal/missing row) means there is no pending @@ -24047,6 +25044,15 @@ def _finalize_block_candidate( self._block_candidate_finalize_retries = registry first_failure = block_hash not in registry registry[block_hash] = (accepted, error) + if not accepted: + # The durable update is ambiguous, but this process has + # now frozen a false finalize-only disposition. It cannot + # return to chain-state evaluation until restart, where + # these process-local counters start fresh. + self._record_committed_block_candidate_abandonment( + block_hash, + outcome, + ) # The share row already reached its terminal outcome in this # process; only the outbox mark is pending. Release the # snapshot anchor floor now (idempotent) -- holding it across @@ -24070,12 +25076,20 @@ def _finalize_block_candidate( # Compatibility ledgers without a durable candidate outbox have # no restart replay source that could require the tombstone. self._clear_accepted_block_payout_preview(block_hash) + self._record_committed_block_candidate_abandonment( + block_hash, + outcome, + ) with self.lock: registry = getattr(self, "_block_candidate_finalize_retries", None) if registry is not None: registry.pop(block_hash, None) self._clear_block_candidate_retry_state(block_hash) self._discard_outstanding_block_candidate(block_hash) + self._record_block_candidate_terminal_outcome( + block_hash, + accepted=accepted, + ) # Terminal for this process either way: an accepted candidate credited # its share during the success tail (a no-op release here), and an # abandoned one can only be credited by restart replay, which stamps a @@ -24085,9 +25099,42 @@ def _finalize_block_candidate( outcome.refresh_client = candidate.client return True + def _merge_block_candidate_retry_locked( + self, + attribute: str, + candidate: PrismBlockCandidate, + ) -> None: + """Merge one retry by parent-first order. Caller holds self.lock.""" + candidate_height = int(candidate.context.template["height"]) + candidate_hash = str(candidate.submission.block_hash_hex).lower() + existing = getattr(self, attribute, None) + if existing is None: + setattr(self, attribute, candidate) + return + existing_height = int(existing.context.template["height"]) + existing_hash = str(existing.submission.block_hash_hex).lower() + if candidate_hash == existing_hash: + setattr(self, attribute, candidate) + return + if attribute != "_retry_block_candidate": + if candidate_height < existing_height: + setattr(self, attribute, candidate) + return + + # The raw lane has one parent-first head slot, but every displaced + # hash still needs an in-memory wakeup. Durable replay dedupe keeps a + # replayed descendant marked in-flight, so relying on a later outbox + # scan here could otherwise suppress it forever. + self._ensure_block_candidate_disposition_state() + waiting = self._block_disposition_waiting_retries + if candidate_height < existing_height: + waiting[existing_hash] = existing + setattr(self, attribute, candidate) + else: + waiting[candidate_hash] = candidate + def _retain_block_candidate_for_retry(self, candidate: PrismBlockCandidate) -> None: """Keep the oldest unresolved candidate ahead of queued descendants.""" - candidate_height = int(candidate.context.template["height"]) candidate_hash = str(candidate.submission.block_hash_hex).lower() # A retained candidate will be re-disposed, so the disposition seal # (which stopped tip-observation matching at a terminal commit) no @@ -24099,17 +25146,26 @@ def _retain_block_candidate_for_retry(self, candidate: PrismBlockCandidate) -> N self.block_candidate_retry_count = int( getattr(self, "block_candidate_retry_count", 0) ) + 1 - existing = getattr(self, "_retry_block_candidate", None) - if existing is None: - self._retry_block_candidate = candidate - return - existing_height = int(existing.context.template["height"]) - existing_hash = str(existing.submission.block_hash_hex).lower() - if candidate_hash == existing_hash or candidate_height < existing_height: - # Replacing a descendant is safe because its durable outbox row - # will replay after this lower-height parent reaches a terminal - # state. Equal-height competitors preserve first-in ordering. - self._retry_block_candidate = candidate + accounting_owner = ( + threading.get_ident() + == getattr(self, "_block_accounting_thread_ident", None) + and bool( + getattr( + self, + "_block_accounting_holds_disposition", + False, + ) + ) + ) + retry_attribute = ( + "_block_accounting_deferred_retry_candidate" + if accounting_owner + else "_retry_block_candidate" + ) + self._merge_block_candidate_retry_locked( + retry_attribute, + candidate, + ) def _reject_terminal_prepared_block_candidate( self, @@ -24180,6 +25236,7 @@ def _defer_block_candidate(self, reason: str, message: str, *, worker: str | Non self._block_candidate_outcome = outcome outcome.reason = reason outcome.error = None + outcome.stale_job_class = None print( f"prism coordinator: block candidate deferred reason={reason}: {message}", flush=True, @@ -24365,9 +25422,10 @@ def _abandon_block_candidate( publication for work qbitd already accepted -- so such candidates defer for retry instead; only hashes provably absent from the active chain (past the observation window) abandon terminally. The terminal - commit re-reads the observation evidence atomically with the counts, - so callers holding follow-up durable work (rejecting prepared payout - rows) can order it strictly after a sealed terminal outcome. + seal re-reads observation evidence atomically, so callers can order + follow-up durable work (rejecting prepared payout rows) strictly + afterward. Abandonment metrics commit only once that cleanup succeeds + or a false finalize-only disposition is frozen. """ if reason in PRISM_RETRYABLE_BLOCK_CANDIDATE_REASONS: self._defer_block_candidate(reason, message, worker=worker) @@ -24445,9 +25503,11 @@ def _abandon_block_candidate( and block_hash.lower() in self._accounted_accepted_block_hashes ) # A blockwait observation can also register during the blocking - # invalidation. Terminal commitment must consult the evidence - # atomically with the counts, or the same blind spot reopens - # inside this window; the probe still wins both directions. + # invalidation. The disposition seal must consult that evidence + # atomically or the same blind spot reopens inside this window; + # the probe still wins both directions. Metrics are committed + # later, after prepared-state cleanup can no longer reverse this + # decision. late_acceptance_observed = bool( not accepted_race_won and ( @@ -24463,26 +25523,7 @@ def _abandon_block_candidate( if not accepted_race_won and not late_acceptance_observed: outcome.reason = reason outcome.error = message - counts = getattr(self, "block_candidate_abandoned_counts", None) - if counts is None: - counts = {} - self.block_candidate_abandoned_counts = counts - counts[reason] = int(counts.get(reason, 0)) + 1 - if stale_job_class is not None: - stale_counts = getattr( - self, - "stale_job_abandon_counts", - None, - ) - if stale_counts is None: - stale_counts = { - abandon_class: 0 - for abandon_class in PRISM_STALE_JOB_ABANDON_CLASSES - } - self.stale_job_abandon_counts = stale_counts - stale_counts[stale_job_class] = ( - int(stale_counts.get(stale_job_class, 0)) + 1 - ) + outcome.stale_job_class = stale_job_class # Seal the disposition in the same critical section that # commits it: stop matching tip observations for this hash so # no acceptance evidence can register between this terminal @@ -24791,7 +25832,9 @@ def _land_and_confirm_block_candidate( ) return None if already_active and callable(block_state_reader): + self._record_block_submitter_phase("pool-block-state") block_state = block_state_reader(block_hash=block_hash) + self._record_block_submitter_phase("pool-block-state:complete") already_confirmed = bool( block_state is not None and str(block_state.get("chain_state", "")) == "confirmed" @@ -25228,6 +26271,7 @@ def _land_and_confirm_block_candidate( active_tip_height=active_tip_height, ) return None + self._record_block_submitter_phase("confirm-accepted-block") confirmation = self.ledger.confirm_accepted_block( block_hash=block_hash, # The ledger confirmation function matches this value @@ -25235,6 +26279,9 @@ def _land_and_confirm_block_candidate( # ancestor can be finalized after newer blocks arrive. active_tip_height=expected_height, ) + self._record_block_submitter_phase( + "confirm-accepted-block:complete" + ) confirmed_count = int(confirmation.get("confirmed_count", 0)) if confirmed_count not in {0, 1}: self.request_shutdown() @@ -25393,13 +26440,27 @@ def submit_block_candidate( after that finalization completes. """ block_hash = str(candidate.submission.block_hash_hex).lower() - if node_submission is None: - node_submission = self._node_submission_for_direct_candidate(candidate) with self._block_candidate_disposition(block_hash): - return self._submit_block_candidate_serialized( + terminal_outcome = self._block_candidate_terminal_outcome(block_hash) + if terminal_outcome is not None: + return terminal_outcome + if node_submission is None: + node_submission = self._node_submission_for_direct_candidate(candidate) + accepted = self._submit_block_candidate_serialized( candidate, node_submission=node_submission, ) + if not accepted: + outcome = getattr(self, "_block_candidate_outcome", None) + if outcome is not None: + # Direct embedders do not use the outbox-finalization + # wrapper. A normal return means the serialized path also + # completed any prepared-state rejection it initiated. + self._record_committed_block_candidate_abandonment( + block_hash, + outcome, + ) + return accepted def _record_block_candidate_progress( self, @@ -25419,9 +26480,6 @@ def _record_block_candidate_progress( same shape as the CTV broadcaster's per-row stamping, whose name likewise maps to a single thread. """ - owner = getattr(self, "_block_submitter_thread_ident", None) - if owner is None or threading.get_ident() != owner: - return self._record_block_submitter_phase(phase) def _submit_block_candidate_serialized( @@ -25437,6 +26495,7 @@ def _submit_block_candidate_serialized( self._block_candidate_outcome = outcome outcome.reason = None outcome.error = None + outcome.stale_job_class = None context = candidate.context submission = candidate.submission worker = candidate.client.username or None @@ -25673,6 +26732,7 @@ def _submit_block_candidate_serialized( ctv_persistence = None ctv_manifest_set = final_bundle.get("ctv_fanout_manifest_set") if isinstance(ctv_manifest_set, dict): + self._record_block_candidate_progress("ctv-manifest-persist") ctv_persistence = self.ledger.persist_ctv_fanout_manifest_set( block_hash=block_hash, manifest_set=ctv_manifest_set, @@ -25683,6 +26743,7 @@ def _submit_block_candidate_serialized( self.audit_dir / f"prism-live-audit-bundle-{expected_height}-{block_hash}.json" ) + self._record_block_candidate_progress("audit-envelope-write") self.write_audit_bundle_envelope( final_bundle_path, block_hash=block_hash, @@ -25694,6 +26755,7 @@ def _submit_block_candidate_serialized( self._record_block_candidate_progress("audit-envelope-write:complete") bundle_path = final_bundle_path if candidate.credit_share_on_accept: + self._record_block_candidate_progress("accepted-share-credit") self.append_accepted_share( candidate.client, context, @@ -25723,7 +26785,9 @@ def _submit_block_candidate_serialized( # and stays watchdog-eligible on purpose, so a wedged read keeps the # exit-and-replay recovery path instead of hanging the disposition # invisibly. + self._record_block_candidate_progress("accepted-share-stats") evidence_share_count, evidence_distinct_miners = self.accepted_share_stats() + self._record_block_candidate_progress("accepted-share-stats:complete") evidence = { "schema": "qbit.prism.live-stratum-evidence.v1", "block_hash": block_hash, @@ -25739,6 +26803,7 @@ def _submit_block_candidate_serialized( "distinct_miner_count": evidence_distinct_miners, "job_share_count": len(context.shares_json), } + self._record_block_candidate_progress("evidence-write") self.evidence_path.write_text(json.dumps(evidence, indent=2), encoding="utf-8") self._record_block_candidate_progress("evidence-write:complete") with self.lock: @@ -25746,6 +26811,11 @@ def _submit_block_candidate_serialized( if newly_accounted: self._accounted_accepted_block_hashes.add(block_hash) self.accepted_block_count += 1 + # Replace this hash's provisional capacity reservation with + # its durable accounted slot atomically. Keeping both until + # the outbox terminal write would double-count the block and + # unnecessarily reject an unrelated next solve. + self._block_fast_lane_reservations.discard(block_hash) self.latest_coinbase_size_bytes = len( str( final_bundle["signed_coinbase_manifest"]["manifest"][ @@ -28591,7 +29661,7 @@ def _request_shutdown(signum: int, _frame: Any) -> None: finally: coordinator.shutdown(reason="main_finally") coordinator.drain_non_writer_components() - return 0 + return 1 if getattr(coordinator, "_fatal_exit_requested", False) else 0 if __name__ == "__main__": diff --git a/lab/prism/share_ledger.py b/lab/prism/share_ledger.py index 86c3be40..94a33033 100644 --- a/lab/prism/share_ledger.py +++ b/lab/prism/share_ledger.py @@ -16,7 +16,7 @@ import uuid from collections.abc import Sequence from contextlib import contextmanager -from dataclasses import dataclass, replace +from dataclasses import dataclass, field, replace from datetime import datetime, timedelta, timezone from decimal import Decimal from pathlib import Path @@ -73,6 +73,16 @@ class AcceptedShareRecord: accepted_at_ms: int ntime: int credit_policy: str | None = None + # Append-result metadata is deliberately excluded from the durable/public + # share identity. It lets the coordinator make process-local accounting + # idempotent and observe the candidate state from the same transaction + # that established the pre-submit outbox boundary. + newly_inserted: bool = field(default=True, compare=False, repr=False) + candidate_outbox_state: str | None = field( + default=None, + compare=False, + repr=False, + ) def to_prism_json(self) -> dict[str, object]: payload: dict[str, object] = { @@ -424,6 +434,15 @@ def advance( ) +@dataclass(frozen=True) +class BlockCandidateIntentPersistResult: + inserted: bool + state: str + + def __bool__(self) -> bool: + return self.inserted + + class SingleWriterShareLedger: """Assigns canonical share_seq values and returns immutable snapshots. @@ -469,7 +488,7 @@ def append(self, pending: PendingShare) -> AcceptedShareRecord: if pending.share_id in self._share_ids: existing = self._shares_by_id[pending.share_id] if self._pending_matches_record(pending, existing, credit_policy=credit_policy): - return replace(existing) + return replace(existing, newly_inserted=False) raise ValueError("duplicate share_id payload mismatch") record = AcceptedShareRecord( share_seq=self._next_share_seq, @@ -509,7 +528,9 @@ def _pending_matches_record( and int(pending.template_height) == int(record.template_height) and pending.job_id == record.job_id and int(pending.job_issued_at_ms) == int(record.job_issued_at_ms) - and int(pending.accepted_at_ms) == int(record.accepted_at_ms) + # accepted_at_ms is assigned when the coordinator receives an + # attempt. An exact header replay after restart gets a fresh stamp; + # the original durable row remains authoritative. and int(pending.ntime) == int(record.ntime) and credit_policy == record.credit_policy ) @@ -562,6 +583,7 @@ def append_batch( for pending, candidate in entries: existing = self._shares_by_id.get(pending.share_id) + newly_inserted = existing is None if existing is None: credit_policy = validate_credit_policy(pending.credit_policy) existing = AcceptedShareRecord( @@ -583,7 +605,7 @@ def append_batch( self._share_ids.add(pending.share_id) self._shares_by_id[pending.share_id] = existing self._next_share_seq += 1 - records.append(replace(existing)) + candidate_state: str | None = None if candidate is not None: block_hash = str(candidate["block_hash_hex"]).lower() self._block_candidate_outbox.setdefault( @@ -600,9 +622,22 @@ def append_batch( }, ) self._block_candidate_outbox[block_hash]["share_id"] = pending.share_id + candidate_state = str( + self._block_candidate_outbox[block_hash]["state"] + ) + records.append( + replace( + existing, + newly_inserted=newly_inserted, + candidate_outbox_state=candidate_state, + ) + ) return records - def persist_block_candidate_intent(self, candidate: dict[str, Any]) -> bool: + def persist_block_candidate_intent( + self, + candidate: dict[str, Any], + ) -> BlockCandidateIntentPersistResult: """Persist candidate work before a below-share-target synchronous submit.""" block_hash = str(candidate.get("block_hash_hex", "")).lower() if not block_hash: @@ -613,7 +648,10 @@ def persist_block_candidate_intent(self, candidate: dict[str, Any]) -> bool: if existing is not None: if existing["candidate_sha256"] != candidate_sha256: raise ValueError("block candidate payload mismatch") - return False + return BlockCandidateIntentPersistResult( + inserted=False, + state=str(existing["state"]), + ) self._block_candidate_outbox[block_hash] = { "block_hash": block_hash, "share_id": None, @@ -624,7 +662,10 @@ def persist_block_candidate_intent(self, candidate: dict[str, Any]) -> bool: "last_error": None, "created_monotonic": time.monotonic(), } - return True + return BlockCandidateIntentPersistResult( + inserted=True, + state="pending", + ) def pending_block_candidates(self, *, limit: int = 32) -> list[dict[str, Any]]: return [ @@ -694,7 +735,7 @@ def mark_block_candidate_abandoned(self, *, block_hash: str, error: str) -> bool def _finish_block_candidate(self, *, block_hash: str, state: str, error: str | None) -> bool: with self._lock: row = self._block_candidate_outbox.get(block_hash.lower()) - if row is None: + if row is None or row["state"] != "pending": return False row["state"] = state row["last_error"] = error @@ -2354,7 +2395,6 @@ def append_batch( OR ledger.template_height IS DISTINCT FROM (data->>'template_height')::bigint OR ledger.job_id IS DISTINCT FROM data->>'job_id' OR ledger.job_issued_at IS DISTINCT FROM to_timestamp((data->>'job_issued_at_ms')::double precision / 1000.0) - OR ledger.accepted_at IS DISTINCT FROM to_timestamp((data->>'accepted_at_ms')::double precision / 1000.0) OR ledger.ntime IS DISTINCT FROM (data->>'ntime')::bigint OR ledger.credit_policy IS DISTINCT FROM data->>'credit_policy' ), @@ -2370,6 +2410,17 @@ def append_batch( AND (outbox.candidate #- '{{pending_share,accepted_at_ms}}') IS DISTINCT FROM (payload.candidate #- '{{pending_share,accepted_at_ms}}'))) ), +candidate_states AS ( + SELECT + payload.ordinality, + CASE + WHEN payload.candidate IS NULL THEN NULL + ELSE COALESCE(outbox.state, 'pending') + END AS candidate_outbox_state + FROM payload + LEFT JOIN qbit_block_candidate_outbox outbox + ON outbox.block_hash = payload.candidate->>'block_hash_hex' +), batch_ok AS ( SELECT 1 AS ok WHERE EXISTS (SELECT 1 FROM lease) @@ -2422,9 +2473,10 @@ def append_batch( records AS ( SELECT ledger.*, payload.ordinality, false AS newly_inserted, - false AS new_miner + false AS new_miner, candidate_states.candidate_outbox_state FROM payload JOIN qbit_share_ledger ledger ON ledger.share_id = payload.data->>'share_id' + JOIN candidate_states ON candidate_states.ordinality = payload.ordinality UNION ALL SELECT inserted_shares.*, payload.ordinality, true AS newly_inserted, @@ -2442,9 +2494,11 @@ def append_batch( FROM inserted_shares earlier_insert WHERE earlier_insert.miner_id = inserted_shares.miner_id AND earlier_insert.share_seq < inserted_shares.share_seq - ) AS new_miner + ) AS new_miner, + candidate_states.candidate_outbox_state FROM inserted_shares JOIN payload ON payload.data->>'share_id' = inserted_shares.share_id + JOIN candidate_states ON candidate_states.ordinality = payload.ordinality ) SELECT CASE WHEN NOT EXISTS (SELECT 1 FROM lease) THEN @@ -2476,7 +2530,8 @@ def append_batch( 'ntime', records.ntime, 'credit_policy', records.credit_policy, 'newly_inserted', records.newly_inserted, - 'new_miner', records.new_miner + 'new_miner', records.new_miner, + 'candidate_outbox_state', records.candidate_outbox_state ) ORDER BY records.ordinality) FROM records ) @@ -2503,7 +2558,10 @@ def append_batch( ) return parsed - def persist_block_candidate_intent(self, candidate: dict[str, Any]) -> bool: + def persist_block_candidate_intent( + self, + candidate: dict[str, Any], + ) -> BlockCandidateIntentPersistResult: """Persist candidate work that is not yet eligible for share credit.""" block_hash = str(candidate.get("block_hash_hex", "")).lower() if not block_hash: @@ -2526,7 +2584,7 @@ def persist_block_candidate_intent(self, candidate: dict[str, Any]) -> bool: RETURNING writer_id ), existing AS ( - SELECT candidate_sha256 + SELECT candidate_sha256, state FROM qbit_block_candidate_outbox WHERE block_hash = {self._text_literal(block_hash)} ), @@ -2551,13 +2609,19 @@ def persist_block_candidate_intent(self, candidate: dict[str, Any]) -> bool: ) THEN json_build_object('error', 'block candidate payload mismatch') ELSE - json_build_object('inserted', (SELECT count(*) FROM inserted)) + json_build_object( + 'inserted', (SELECT count(*) FROM inserted), + 'state', COALESCE((SELECT state FROM existing), 'pending') + ) END; """ result = self._run_fenced_json(sql) if "error" in result: raise RuntimeError(str(result["error"])) - return int(result.get("inserted", 0)) > 0 + return BlockCandidateIntentPersistResult( + inserted=int(result.get("inserted", 0)) > 0, + state=str(result.get("state", "pending")), + ) def pending_block_candidates(self, *, limit: int = 32) -> list[dict[str, Any]]: return [ @@ -7660,6 +7724,12 @@ def _record_from_json(payload: dict[str, Any]) -> AcceptedShareRecord: if payload.get("credit_policy") is not None else None ), + newly_inserted=bool(payload.get("newly_inserted", True)), + candidate_outbox_state=( + str(payload["candidate_outbox_state"]) + if payload.get("candidate_outbox_state") is not None + else None + ), ) @staticmethod diff --git a/tests/test_prism_coordinator_vardiff.py b/tests/test_prism_coordinator_vardiff.py index 21714279..8249f319 100644 --- a/tests/test_prism_coordinator_vardiff.py +++ b/tests/test_prism_coordinator_vardiff.py @@ -4,6 +4,7 @@ import errno import hashlib +import inspect import json import os import queue @@ -9173,20 +9174,22 @@ def test_durable_block_candidates_replay_after_queue_drains(self) -> None: ) ledger.append_batch([(pending, server.block_candidate_intent(candidate))]) - self.assertEqual(server.replay_pending_block_candidates(), 2) - first = server.block_candidate_queue.get_nowait() - second = server.block_candidate_queue.get_nowait() + self.assertEqual(server.replay_pending_block_candidates(), 3) + self.assertTrue(server.block_candidate_queue.empty()) + first = server._block_replay_candidate_queue.get_nowait() + second = server._block_replay_candidate_queue.get_nowait() + third = server._block_replay_candidate_queue.get_nowait() self.assertEqual( - [first.submission.block_hash_hex, second.submission.block_hash_hex], - ["aa" * 32, "bb" * 32], + [ + first.submission.block_hash_hex, + second.submission.block_hash_hex, + third.submission.block_hash_hex, + ], + ["aa" * 32, "bb" * 32, "cc" * 32], ) ledger.mark_block_candidate_submitted(block_hash="aa" * 32) ledger.mark_block_candidate_abandoned(block_hash="bb" * 32, error="stale") - - self.assertEqual(server.replay_pending_block_candidates(), 1) - replayed = server.block_candidate_queue.get_nowait() - self.assertEqual(replayed.submission.block_hash_hex, "cc" * 32) - self.assertEqual(replayed.pending_share.share_id, "miner-a:" + "cc" * 32) + self.assertEqual(third.pending_share.share_id, "miner-a:" + "cc" * 32) def test_candidate_intent_avoids_duplicate_template_transaction_bodies(self) -> None: server, state, _ledger = submit_coordinator() @@ -9968,6 +9971,12 @@ def test_invalid_durable_candidate_is_quarantined_by_outbox_row_key(self) -> Non server.block_candidate_retry_delays = {durable_hash: 1.0} self.assertEqual(server.replay_pending_block_candidates(), 0) + # Malformed-row cleanup is lower-priority maintenance, so it + # cannot form an N x database-timeout convoy ahead of valid + # recovered blocks on the node-offer lane. + self.assertTrue( + server._run_one_invalid_block_candidate_quarantine() + ) self.assertEqual(ledger.pending_block_candidates(), []) self.assertNotIn(durable_hash, server.block_candidate_retry_delays) @@ -11865,21 +11874,824 @@ def __init__(self) -> None: super().__init__() self.mark_calls = 0 - def mark_block_candidate_attempted(self, *, block_hash: str) -> bool: - self.mark_calls += 1 - entered_mark.set() - release_mark.wait(60.0) - return True + def mark_block_candidate_attempted(self, *, block_hash: str) -> bool: + self.mark_calls += 1 + entered_mark.set() + release_mark.wait(60.0) + return True + + class DeadlineRpc(SubmitRpc): + def __init__(self, ledger: RecordingLedger) -> None: + super().__init__( + tip="00" * 32, + block_hash="d2" * 32, + ledger=ledger, + ) + self.timeouts: list[float | None] = [] + + def call( + self, + method: str, + params: list[object] | None = None, + *, + timeout: float | None = None, + ) -> object: + if method == "submitblock": + self.timeouts.append(timeout) + submitted.set() + if len(self.timeouts) > 1: + return "duplicate" + return super().call(method, params) + + ledger = StallingLedger() + server.ledger = ledger + rpc = DeadlineRpc(ledger) + server.rpc = rpc + server.block_submit_rpc_timeout_seconds = 0.4 + server.block_submit_db_timeout_seconds = 0.05 + server.block_candidate_retry_initial_seconds = 0.01 + server.block_candidate_retry_max_seconds = 0.01 + server.watchdog_timeout_seconds = 0.2 + server._heartbeats = {} + server._heartbeat_phases = {} + server._watchdog_pauses = {} + server._heartbeats_lock = threading.Lock() + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="00", + block_hash_hex="d2" * 32, + block_hex="00", + share_pass=True, + block_pass=True, + ), + ) + server.enqueue_block_candidate(candidate) + started = time.monotonic() + submitter = threading.Thread(target=server.block_submit_loop) + with patch("builtins.print"): + submitter.start() + try: + self.assertTrue(submitted.wait(2.0)) + self.assertLess(time.monotonic() - started, 2.0) + self.assertTrue(entered_mark.wait(1.0)) + with server._heartbeats_lock: + first_heartbeat = server._heartbeats["block_submitter"] + heartbeat_deadline = time.monotonic() + 1.0 + while time.monotonic() < heartbeat_deadline: + with server._heartbeats_lock: + latest_heartbeat = server._heartbeats["block_submitter"] + if latest_heartbeat > first_heartbeat: + break + time.sleep(0.01) + self.assertGreater(latest_heartbeat, first_heartbeat) + self.assertEqual( + server._overdue_heartbeats(time.monotonic()), + [], + ) + self.assertEqual(ledger.mark_calls, 1) + self.assertEqual(rpc.timeouts[0], 0.4) + finally: + server.stop_event.set() + submitter.join(2.0) + release_mark.set() + self.assertFalse(submitter.is_alive()) + + def test_accounting_saturation_does_not_convoy_node_offers(self) -> None: + server, state, _recording = submit_coordinator() + server.max_blocks = 10 + server.stop_after_block = False + server.block_candidate_retry_initial_seconds = 0.01 + server._block_accounting_queue = queue.PriorityQueue(maxsize=1) + entered_accounting = threading.Event() + release_accounting = threading.Event() + submitted: list[str] = [] + + class RecordingRpc(TipRpc): + def call( + self, + method: str, + params: list[object] | None = None, + *, + timeout: float | None = None, + ) -> object: + if method == "submitblock": + submitted.append(str((params or [""])[0])) + return None + return super().call(method, params) + + server.rpc = RecordingRpc("00" * 32) + + def blocked_accounting( + _candidate: PrismBlockCandidate, + **_kwargs: object, + ) -> bool: + entered_accounting.set() + release_accounting.wait(5) + return True + + server._call_block_candidate_writer = blocked_accounting # type: ignore[method-assign] + for tag in ("a1", "b2", "c3", "d4"): + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="00", + block_hash_hex=tag * 32, + block_hex=tag, + share_pass=True, + block_pass=True, + ), + ) + server.enqueue_block_candidate(candidate) + + submitter = threading.Thread(target=server.block_submit_loop) + with patch("builtins.print"): + submitter.start() + try: + self.assertTrue(entered_accounting.wait(1)) + deadline = time.monotonic() + 2 + while len(submitted) < 4 and time.monotonic() < deadline: + time.sleep(0.01) + self.assertEqual(submitted, ["a1", "b2", "c3", "d4"]) + finally: + server.stop_event.set() + release_accounting.set() + submitter.join(2) + accounting = getattr(server, "_block_accounting_thread", None) + if accounting is not None: + accounting.join(2) + self.assertFalse(submitter.is_alive()) + + def test_replay_batch_reaches_node_while_oldest_accounting_stalls(self) -> None: + server, state, _recording = submit_coordinator() + ledger = SingleWriterShareLedger() + server.ledger = ledger + server.max_blocks = 10 + server.stop_after_block = False + submitted: list[str] = [] + release_accounting = threading.Event() + entered_accounting = threading.Event() + + for index, tag in enumerate(("a5", "b6"), start=1): + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="00", + block_hash_hex=tag * 32, + block_hex=tag, + share_pass=True, + block_pass=True, + ), + ) + pending = PendingShare( + share_id=f"miner-a:{tag * 32}", + miner_id="miner-a", + order_key="miner-a", + p2mr_program_hex="11" * 32, + share_difficulty=1, + network_difficulty=1, + template_height=9, + job_id="job-1", + job_issued_at_ms=1, + accepted_at_ms=index, + ntime=1, + ) + candidate = dataclass_replace(candidate, pending_share=pending) + ledger.append_batch( + [(pending, server.block_candidate_intent(candidate))] + ) + + self.assertEqual(server.replay_pending_block_candidates(), 2) + + class RecordingRpc(TipRpc): + def call( + self, + method: str, + params: list[object] | None = None, + *, + timeout: float | None = None, + ) -> object: + if method == "submitblock": + submitted.append(str((params or [""])[0])) + return None + return super().call(method, params) + + server.rpc = RecordingRpc("00" * 32) + + def blocked_accounting( + _candidate: PrismBlockCandidate, + **_kwargs: object, + ) -> bool: + entered_accounting.set() + release_accounting.wait(5) + return True + + server._call_block_candidate_writer = blocked_accounting # type: ignore[method-assign] + submitter = threading.Thread(target=server.block_submit_loop) + with patch("builtins.print"): + submitter.start() + try: + self.assertTrue(entered_accounting.wait(1)) + deadline = time.monotonic() + 2 + while len(submitted) < 2 and time.monotonic() < deadline: + time.sleep(0.01) + self.assertEqual(submitted, ["a5", "b6"]) + finally: + server.stop_event.set() + release_accounting.set() + submitter.join(2) + accounting = getattr(server, "_block_accounting_thread", None) + if accounting is not None: + accounting.join(2) + + def test_stuck_rpc_worker_pool_requests_nonzero_restart(self) -> None: + server, _state, _recording = submit_coordinator() + server.block_submit_stuck_call_exit_seconds = 0.04 + release = threading.Event() + entered: list[str] = [] + + class IgnoringRpc: + def call( + self, + method: str, + params: list[object] | None = None, + *, + timeout: float | None = None, + ) -> object: + entered.append(str((params or [""])[0])) + release.wait(5) + return None + + server.rpc = IgnoringRpc() + try: + for tag in ("11", "22"): + with self.assertRaises(TimeoutError): + server._run_submitblock_rpc_with_hard_deadline( + block_hash=tag * 32, + block_hex=tag, + timeout_seconds=0.01, + ) + time.sleep(0.05) + with self.assertRaises(TimeoutError): + server._run_submitblock_rpc_with_hard_deadline( + block_hash="33" * 32, + block_hex="33", + timeout_seconds=0.01, + ) + self.assertEqual(entered, ["11", "22"]) + self.assertTrue(server.stop_event.is_set()) + self.assertTrue(server._fatal_exit_requested) + finally: + release.set() + + def test_stuck_ledger_worker_pool_requests_nonzero_restart(self) -> None: + server, _state, _recording = submit_coordinator() + server.block_submit_db_timeout_seconds = 0.01 + server.block_submit_stuck_call_exit_seconds = 0.04 + release = threading.Event() + entered: list[str] = [] + + def blocking_operation(tag: str) -> str: + entered.append(tag) + release.wait(5) + return tag + + try: + for tag in ("one", "two"): + with self.assertRaises(TimeoutError): + server._run_block_submitter_ledger_call( + (tag,), + f"test-{tag}", + lambda tag=tag: blocking_operation(tag), + ) + time.sleep(0.05) + with self.assertRaises(TimeoutError): + server._run_block_submitter_ledger_call( + ("three",), + "test-three", + lambda: blocking_operation("three"), + ) + self.assertEqual(entered, ["one", "two"]) + self.assertTrue(server.stop_event.is_set()) + self.assertTrue(server._fatal_exit_requested) + finally: + release.set() + + def test_one_stuck_ledger_call_does_not_restart_with_spare_capacity(self) -> None: + server, _state, _recording = submit_coordinator() + server.block_submit_db_timeout_seconds = 0.01 + server.block_submit_stuck_call_exit_seconds = 0.04 + release = threading.Event() + entered = threading.Event() + + def blocking_operation() -> None: + entered.set() + release.wait(5) + + try: + with self.assertRaises(TimeoutError): + server._run_block_submitter_ledger_call( + ("same-key",), + "same-key", + blocking_operation, + ) + self.assertTrue(entered.wait(1)) + time.sleep(0.05) + with self.assertRaises(TimeoutError): + server._run_block_submitter_ledger_call( + ("same-key",), + "same-key", + blocking_operation, + ) + self.assertFalse(server.stop_event.is_set()) + self.assertFalse(getattr(server, "_fatal_exit_requested", False)) + finally: + release.set() + + def test_two_stuck_ledger_calls_restart_on_existing_key_retry(self) -> None: + server, _state, _recording = submit_coordinator() + server.block_submit_db_timeout_seconds = 0.01 + server.block_submit_stuck_call_exit_seconds = 0.04 + release = threading.Event() + entered: list[str] = [] + + def blocking_operation(tag: str) -> None: + entered.append(tag) + release.wait(5) + + try: + for tag in ("one", "two"): + with self.assertRaises(TimeoutError): + server._run_block_submitter_ledger_call( + (tag,), + tag, + lambda tag=tag: blocking_operation(tag), + ) + time.sleep(0.05) + # No third key is required: a retry reusing either poisoned call + # still observes that every bounded worker slot is exhausted. + with self.assertRaises(TimeoutError): + server._run_block_submitter_ledger_call( + ("one",), + "one", + lambda: blocking_operation("one"), + ) + self.assertEqual(entered, ["one", "two"]) + self.assertTrue(server.stop_event.is_set()) + self.assertTrue(server._fatal_exit_requested) + finally: + release.set() + + def test_watchdog_starts_before_synchronous_startup_work(self) -> None: + source = inspect.getsource(PrismCoordinator._serve_with_listener_stack) + watchdog_start = source.index("target=self.watchdog_loop") + + self.assertEqual(source.count("target=self.watchdog_loop"), 1) + self.assertLess(watchdog_start, source.index("self.prewarm_startup_jobs")) + self.assertLess(watchdog_start, source.index("self.replay_recovered_shares")) + + def test_watchdog_hard_exits_when_fatal_stop_wins_during_startup(self) -> None: + server = self._bare_coordinator() + server._fatal_exit_requested = True + server.stop_event.set() + + with patch("lab.prism.prism_coordinator.os._exit") as hard_exit: + server.watchdog_loop() + + hard_exit.assert_called_once_with(1) + + def test_parent_retry_displacement_preserves_durable_descendant(self) -> None: + server, state, _recording = submit_coordinator() + + def candidate_at(tag: str, height: int) -> PrismBlockCandidate: + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="00", + block_hash_hex=tag * 32, + block_hex=tag, + share_pass=True, + block_pass=True, + ), + ) + context = SimpleNamespace(**vars(candidate.context)) + context.template = {**candidate.context.template, "height": height} + return dataclass_replace( + candidate, + context=context, + durable_replay=True, + ) + + descendant = candidate_at("b8", 11) + parent = candidate_at("a8", 10) + descendant_hash = descendant.submission.block_hash_hex + server._ensure_block_candidate_disposition_state() + server._ensure_block_replay_state() + server._block_replay_inflight_hashes.add(descendant_hash) + with server.lock: + server._retry_block_candidate = descendant + server._merge_block_candidate_retry_locked( + "_retry_block_candidate", + parent, + ) + + self.assertIs(server._retry_block_candidate, parent) + self.assertIs( + server._block_disposition_waiting_retries[descendant_hash], + descendant, + ) + + # Once the parent reaches a terminal state, the descendant's preserved + # wakeup is selected even though durable replay still deduplicates it. + with server.lock: + server._retry_block_candidate = None + captured: list[object] = [] + server.max_blocks = 10 + server.stop_after_block = False + server._node_submission_for_candidate = ( # type: ignore[method-assign] + lambda _candidate: SimpleNamespace( + attempted=True, + result="duplicate", + error=None, + ) + ) + server._enqueue_block_accounting_task = ( # type: ignore[method-assign] + lambda task: (captured.append(task), True)[1] + ) + + self.assertTrue(server.submit_next_block_candidate(defer_accounting=True)) + self.assertEqual(len(captured), 1) + task = captured[0] + self.assertIs(task.candidate, descendant) + server._release_block_candidate_disposition(task.disposition_lease) + + def test_synchronous_waiter_joins_finalize_only_registry(self) -> None: + server, state, _recording = submit_coordinator() + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="00", + block_hash_hex="c8" * 32, + block_hex="c8", + share_pass=False, + block_pass=True, + ), + credit_share_on_accept=True, + ) + block_hash = candidate.submission.block_hash_hex + server._block_candidate_finalize_retries = {} + server._block_candidate_finalize_retries[block_hash] = (True, "") + server._node_submission_for_candidate = ( # type: ignore[method-assign] + lambda _candidate: (_ for _ in ()).throw( + AssertionError("finalize-only retry must not call qbitd") + ) + ) + finalized: list[dict[str, object]] = [] + + def finalize( + _candidate: PrismBlockCandidate, + **kwargs: object, + ) -> bool: + finalized.append(kwargs) + return True + + server._finalize_block_candidate = finalize # type: ignore[method-assign] + + self.assertTrue(server._submit_synchronous_block_candidate(candidate)) + self.assertEqual(len(finalized), 1) + self.assertTrue(finalized[0]["accepted"]) + self.assertEqual(finalized[0]["block_hash"], block_hash) + + def test_synchronous_waiter_preserves_finalize_only_abandonment(self) -> None: + server, state, _recording = submit_coordinator() + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="00", + block_hash_hex="c9" * 32, + block_hex="c9", + share_pass=False, + block_pass=True, + ), + credit_share_on_accept=True, + ) + block_hash = candidate.submission.block_hash_hex + server._block_candidate_finalize_retries = { + block_hash: (False, "terminal rejection") + } + server._node_submission_for_candidate = ( # type: ignore[method-assign] + lambda _candidate: (_ for _ in ()).throw( + AssertionError("finalize-only retry must not call qbitd") + ) + ) + finalized: list[dict[str, object]] = [] + server._finalize_block_candidate = ( # type: ignore[method-assign] + lambda _candidate, **kwargs: (finalized.append(kwargs), True)[1] + ) + + self.assertFalse(server._submit_synchronous_block_candidate(candidate)) + self.assertEqual(len(finalized), 1) + self.assertFalse(finalized[0]["accepted"]) + self.assertEqual(finalized[0]["error"], "terminal rejection") + + def test_synchronous_abandon_rejects_prepared_state_before_outbox(self) -> None: + server, state, ledger = submit_coordinator() + block_hash = "ca" * 32 + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="00", + block_hash_hex=block_hash, + block_hex="ca", + share_pass=False, + block_pass=True, + ), + credit_share_on_accept=True, + ) + events: list[str] = [] + prepared = {"value": True} + + def pool_block_state(*, block_hash: str) -> dict[str, str]: + self.assertEqual(block_hash, candidate.submission.block_hash_hex) + events.append("state") + return { + "chain_state": "prepared" if prepared["value"] else "rejected", + "maturity_state": "immature", + } + + def reject_prepared_block(**_kwargs: object) -> dict[str, object]: + events.append("reject") + prepared["value"] = False + return {"backend": "fake", "rejected_count": 1} + + def mark_abandoned(**_kwargs: object) -> bool: + events.append("abandon") + return True + + ledger.pool_block_state = pool_block_state # type: ignore[attr-defined] + ledger.reject_prepared_block = reject_prepared_block # type: ignore[method-assign] + ledger.mark_block_candidate_abandoned = mark_abandoned # type: ignore[attr-defined] + + class CleanupRpc(TipRpc): + def call( + self, + method: str, + params: list[object] | None = None, + ) -> object: + if method == "getblockcount": + return 9 + return super().call(method, params) + + server.rpc = CleanupRpc("00" * 32) + server._node_submission_for_candidate = ( # type: ignore[method-assign] + lambda _candidate: SimpleNamespace( + attempted=False, + result=None, + error=None, + ) + ) + server._mark_block_candidate_attempted = ( # type: ignore[method-assign] + lambda _block_hash: True + ) + + def stage_terminal_rejection( + _candidate: PrismBlockCandidate, + *, + node_submission: object, + ) -> bool: + self.assertIsNotNone(node_submission) + outcome = server._block_candidate_outcome + outcome.reason = PRISM_REJECTION_POOL_CLOSED + outcome.error = "pool is no longer accepting blocks" + outcome.stale_job_class = None + return False + + server._submit_block_candidate_serialized = ( # type: ignore[method-assign] + stage_terminal_rejection + ) + + self.assertFalse(server._submit_synchronous_block_candidate(candidate)) + self.assertEqual(events, ["state", "reject", "abandon"]) + self.assertEqual( + server.block_candidate_abandoned_counts, + {PRISM_REJECTION_POOL_CLOSED: 1}, + ) + self.assertFalse(server._block_candidate_terminal_outcome(block_hash)) + + def test_synchronous_cleanup_failure_keeps_candidate_pending(self) -> None: + server, state, ledger = submit_coordinator() + block_hash = "cb" * 32 + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="00", + block_hash_hex=block_hash, + block_hex="cb", + share_pass=False, + block_pass=True, + ), + credit_share_on_accept=True, + ) + events: list[str] = [] + ledger.pool_block_state = ( # type: ignore[attr-defined] + lambda *, block_hash: { + "chain_state": "prepared", + "maturity_state": "immature", + } + ) + + def fail_reject(**_kwargs: object) -> dict[str, object]: + events.append("reject") + raise RuntimeError("postgres unavailable") + + def unexpected_abandon(**_kwargs: object) -> bool: + events.append("abandon") + return True + + ledger.reject_prepared_block = fail_reject # type: ignore[method-assign] + ledger.mark_block_candidate_abandoned = unexpected_abandon # type: ignore[attr-defined] + + class CleanupRpc(TipRpc): + def call( + self, + method: str, + params: list[object] | None = None, + ) -> object: + if method == "getblockcount": + return 9 + return super().call(method, params) + + server.rpc = CleanupRpc("00" * 32) + server._node_submission_for_candidate = ( # type: ignore[method-assign] + lambda _candidate: SimpleNamespace( + attempted=False, + result=None, + error=None, + ) + ) + server._mark_block_candidate_attempted = ( # type: ignore[method-assign] + lambda _block_hash: True + ) + + def stage_terminal_rejection( + _candidate: PrismBlockCandidate, + *, + node_submission: object, + ) -> bool: + self.assertIsNotNone(node_submission) + outcome = server._block_candidate_outcome + outcome.reason = PRISM_REJECTION_POOL_CLOSED + outcome.error = "pool is no longer accepting blocks" + outcome.stale_job_class = None + return False + + server._submit_block_candidate_serialized = ( # type: ignore[method-assign] + stage_terminal_rejection + ) + + with self.assertRaisesRegex( + RuntimeError, + "could not reject prepared state for terminal candidate", + ): + server._submit_synchronous_block_candidate(candidate) + + self.assertEqual(events, ["reject"]) + self.assertIs(server._retry_block_candidate, candidate) + self.assertEqual(server.block_candidate_abandoned_counts, {}) + self.assertIsNone(server._block_candidate_terminal_outcome(block_hash)) + self.assertEqual( + server._block_candidate_outcome.reason, + PRISM_REJECTION_BACKEND_RPC_UNAVAILABLE, + ) + + def test_restart_resubmit_honors_terminal_abandoned_outbox(self) -> None: + server, state, _recording = submit_coordinator() + ledger = SingleWriterShareLedger() + server.ledger = ledger + block_hash = "e8" * 32 + submission = SimpleNamespace( + header_hex="aa" * 80, + coinbase_tx_hex="00", + block_hash_hex=block_hash, + block_hex="e8", + share_pass=False, + block_pass=True, + ) + first_pending = server.pending_share_from_submission( + context=server.jobs["job-1"], + submission=submission, + ntime_hex="00000001", + ) + first_candidate = block_candidate( + server, + state, + submission, + pending_share=first_pending, + credit_share_on_accept=True, + ) + self.assertTrue( + ledger.persist_block_candidate_intent( + server.block_candidate_intent(first_candidate) + ) + ) + self.assertTrue( + ledger.mark_block_candidate_abandoned( + block_hash=block_hash, + error="terminal before restart", + ) + ) + server._finish_pending_share_commit(first_pending) + submitblock_calls: list[str] = [] + + class NoResubmitRpc(TipRpc): + def call( + self, + method: str, + params: list[object] | None = None, + *, + timeout: float | None = None, + ) -> object: + if method == "submitblock": + submitblock_calls.append(str((params or [""])[0])) + return None + return super().call(method, params) + + server.rpc = NoResubmitRpc("00" * 32) + with patch( + "lab.prism.prism_coordinator.direct_stratum.assemble_submission", + return_value=submission, + ): + with self.assertRaises(StratumError) as raised: + server.handle_submit( + state, + ["miner-a", "job-1", "00" * 8, "00000001", "00000002"], + ) + + self.assertEqual(raised.exception.code, 23) + self.assertEqual(submitblock_calls, []) + self.assertEqual(ledger._block_candidate_outbox[block_hash]["state"], "abandoned") + self.assertEqual(len(ledger), 0) - class DeadlineRpc(SubmitRpc): - def __init__(self, ledger: RecordingLedger) -> None: - super().__init__( - tip="00" * 32, - block_hash="d2" * 32, - ledger=ledger, + def test_restart_resubmit_coalesces_terminal_submitted_outbox(self) -> None: + first_server, first_state, _recording = submit_coordinator() + ledger = SingleWriterShareLedger() + first_server.ledger = ledger + block_hash = "f8" * 32 + submission = SimpleNamespace( + header_hex="ab" * 80, + coinbase_tx_hex="00", + block_hash_hex=block_hash, + block_hex="f8", + share_pass=True, + block_pass=True, + ) + first_pending = PendingShare( + share_id=f"miner-a:{block_hash}", + miner_id="miner-a", + order_key="miner-a", + p2mr_program_hex="11" * 32, + share_difficulty=7, + network_difficulty=1, + template_height=9, + job_id="job-1", + job_issued_at_ms=12345, + accepted_at_ms=1, + ntime=1, + ) + first_candidate = block_candidate( + first_server, + first_state, + submission, + pending_share=first_pending, + ) + first_record = ledger.append_batch( + [ + ( + first_pending, + first_server.block_candidate_intent(first_candidate), ) - self.timeouts: list[float | None] = [] + ] + )[0] + self.assertTrue(first_record.newly_inserted) + self.assertTrue( + ledger.mark_block_candidate_submitted(block_hash=block_hash) + ) + + # Model a clean restart: volatile duplicate/disposition state is gone, + # while the ledger and terminal candidate outbox remain authoritative. + server, state, _recording = submit_coordinator() + server.ledger = ledger + submitblock_calls: list[str] = [] + class NoResubmitRpc(TipRpc): def call( self, method: str, @@ -11888,66 +12700,228 @@ def call( timeout: float | None = None, ) -> object: if method == "submitblock": - self.timeouts.append(timeout) - submitted.set() - if len(self.timeouts) > 1: - return "duplicate" + submitblock_calls.append(str((params or [""])[0])) + return None return super().call(method, params) - ledger = StallingLedger() + server.rpc = NoResubmitRpc("00" * 32) + with patch( + "lab.prism.prism_coordinator.direct_stratum.assemble_submission", + return_value=submission, + ): + self.assertFalse( + server.handle_submit( + state, + ["miner-a", "job-1", "00" * 8, "00000001", "00000002"], + ) + ) + + self.assertEqual(submitblock_calls, []) + self.assertEqual( + ledger._block_candidate_outbox[block_hash]["state"], "submitted" + ) + self.assertEqual(len(ledger), 1) + self.assertEqual(ledger._shares[0].accepted_at_ms, 1) + self.assertTrue(server.block_candidate_queue.empty()) + self.assertEqual( + server.worker_share_counts["miner-a"], + {"submitted": 1, "accepted": 0, "grace": 0}, + ) + + def test_exact_share_replay_does_not_repeat_process_credit(self) -> None: + server, state, _recording = submit_coordinator() + ledger = SingleWriterShareLedger() server.ledger = ledger - rpc = DeadlineRpc(ledger) - server.rpc = rpc - server.block_submit_rpc_timeout_seconds = 0.4 - server.block_submit_db_timeout_seconds = 0.05 - server.block_candidate_retry_initial_seconds = 0.01 - server.block_candidate_retry_max_seconds = 0.01 - server.watchdog_timeout_seconds = 0.2 - server._heartbeats = {} - server._heartbeat_phases = {} - server._watchdog_pauses = {} - server._heartbeats_lock = threading.Lock() + block_hash = "d8" * 32 + submission = SimpleNamespace( + coinbase_tx_hex="00", + block_hash_hex=block_hash, + block_hex="d8", + share_pass=True, + block_pass=True, + ) + pending = PendingShare( + share_id=f"miner-a:{block_hash}", + miner_id="miner-a", + order_key="miner-a", + p2mr_program_hex="11" * 32, + share_difficulty=1, + network_difficulty=1, + template_height=9, + job_id="job-1", + job_issued_at_ms=12345, + accepted_at_ms=12346, + ntime=1, + ) + candidate = block_candidate( + server, + state, + submission, + pending_share=pending, + ) + intent = server.block_candidate_intent(candidate) + worker_credits: list[str] = [] + vardiff_credits: list[str] = [] + server.note_worker_accepted_share = ( # type: ignore[method-assign] + lambda worker, _policy: worker_credits.append(worker) + ) + server.note_vardiff_accepted_share = ( # type: ignore[method-assign] + lambda _client, job: vardiff_credits.append(job.job_id) + ) + + self.assertEqual( + server.append_accepted_share( + state, + candidate.context, + submission, + pending, + candidate_intent=intent, + ), + "pending", + ) + self.assertEqual( + server.append_accepted_share( + state, + candidate.context, + submission, + pending, + candidate_intent=intent, + ), + "pending", + ) + + self.assertEqual(len(ledger), 1) + self.assertEqual(worker_credits, ["miner-a"]) + self.assertEqual(vardiff_credits, ["job-1"]) + + def test_same_hash_busy_lease_preserves_retry_behind_live_work(self) -> None: + server, state, _recording = submit_coordinator() + server.block_candidate_retry_initial_seconds = 0.0 candidate = block_candidate( server, state, SimpleNamespace( coinbase_tx_hex="00", - block_hash_hex="d2" * 32, - block_hex="00", + block_hash_hex="a7" * 32, + block_hex="a7", + share_pass=True, + block_pass=True, + ), + ) + block_hash = candidate.submission.block_hash_hex + lease = server._claim_block_candidate_disposition( + block_hash, + blocking=True, + ) + assert lease is not None + server._retry_block_candidate = candidate + server._ensure_block_replay_state() + server._block_replay_inflight_hashes.add(block_hash) + try: + self.assertTrue( + server.submit_next_block_candidate(defer_accounting=True) + ) + self.assertIsNone(server._retry_block_candidate) + self.assertIs( + server._block_disposition_waiting_retries[block_hash], + candidate, + ) + finally: + server._release_block_candidate_disposition(lease) + + captured: list[object] = [] + server._node_submission_for_candidate = ( # type: ignore[method-assign] + lambda _candidate: SimpleNamespace( + attempted=True, + result="duplicate", + error=None, + ) + ) + server._enqueue_block_accounting_task = ( # type: ignore[method-assign] + lambda task: (captured.append(task), True)[1] + ) + self.assertTrue(server.submit_next_block_candidate(defer_accounting=True)) + self.assertEqual(len(captured), 1) + task = captured[0] + server._release_block_candidate_disposition(task.disposition_lease) + + def test_permanently_closed_pool_hands_outbox_to_accounting(self) -> None: + server, state, _recording = submit_coordinator() + server.max_blocks = 1 + server.accepted_block_count = 1 + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="00", + block_hash_hex="f2" * 32, + block_hex="f2", share_pass=True, block_pass=True, ), ) + captured: list[object] = [] + server._enqueue_block_accounting_task = ( # type: ignore[method-assign] + lambda task: (captured.append(task), True)[1] + ) + server.rpc = SimpleNamespace( + call=lambda *_args, **_kwargs: (_ for _ in ()).throw( + AssertionError("closed pool must not call submitblock") + ) + ) server.enqueue_block_candidate(candidate) - started = time.monotonic() - submitter = threading.Thread(target=server.block_submit_loop) - with patch("builtins.print"): - submitter.start() - try: - self.assertTrue(submitted.wait(2.0)) - self.assertLess(time.monotonic() - started, 2.0) - self.assertTrue(entered_mark.wait(1.0)) - with server._heartbeats_lock: - first_heartbeat = server._heartbeats["block_submitter"] - heartbeat_deadline = time.monotonic() + 1.0 - while time.monotonic() < heartbeat_deadline: - with server._heartbeats_lock: - latest_heartbeat = server._heartbeats["block_submitter"] - if latest_heartbeat > first_heartbeat: - break - time.sleep(0.01) - self.assertGreater(latest_heartbeat, first_heartbeat) - self.assertEqual( - server._overdue_heartbeats(time.monotonic()), - [], + + self.assertTrue(server.submit_next_block_candidate(defer_accounting=True)) + self.assertEqual(len(captured), 1) + task = captured[0] + self.assertFalse(task.node_submission.attempted) + self.assertIsNone(getattr(server, "_retry_block_candidate", None)) + server._release_block_candidate_disposition(task.disposition_lease) + + def test_accounted_block_replaces_its_capacity_reservation(self) -> None: + server, state, _recording = submit_coordinator() + server.max_blocks = 2 + server.stop_after_block = False + block_hash = "e2" * 32 + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="c0ffee", + block_hash_hex=block_hash, + block_hex="e2", + share_pass=True, + block_pass=True, + ), + ) + server._ensure_block_candidate_disposition_state() + server._block_fast_lane_reservations.add(block_hash) + server._land_and_confirm_block_candidate = ( # type: ignore[method-assign] + lambda *_args, **_kwargs: ( + verified_block_bundle(), + verified_audit_report(), + {"persisted": True}, + {"confirmed_count": 1}, + ) + ) + server.accepted_share_stats = lambda: (0, 0) # type: ignore[method-assign] + with tempfile.TemporaryDirectory() as tempdir: + server.audit_dir = Path(tempdir) + server.evidence_path = Path(tempdir) / "evidence.json" + self.assertTrue( + server._submit_block_candidate_serialized( + candidate, + node_submission=SimpleNamespace( + attempted=True, + result=None, + error=None, + ), ) - self.assertEqual(ledger.mark_calls, 1) - self.assertEqual(rpc.timeouts[0], 0.4) - finally: - server.stop_event.set() - submitter.join(2.0) - release_mark.set() - self.assertFalse(submitter.is_alive()) + ) + + self.assertEqual(server.accepted_block_count, 1) + self.assertNotIn(block_hash, server._block_fast_lane_reservations) + self.assertTrue(server._reserve_block_fast_lane_slot("e3" * 32)) def test_block_submitter_retry_wait_heartbeats_in_bounded_slices(self) -> None: server = self._bare_coordinator() @@ -13287,19 +14261,26 @@ def test_below_target_accepted_tail_serializes_moved_tip_replay(self) -> None: class ObservedDispositionLock: def __init__(self) -> None: - self.lock = threading.RLock() + self.lock = threading.Lock() - def __enter__(self) -> ObservedDispositionLock: + def acquire( + self, + blocking: bool = True, + timeout: float = -1, + ) -> bool: if threading.current_thread() is replay_thread: if self.lock.acquire(blocking=False): - return self + return True # A failed non-blocking acquisition proves the accepted # attempt still owns this exact same-hash guard. replay_guard_blocked.set() - self.lock.acquire() - return self + if not blocking: + return self.lock.acquire(blocking=False) + if timeout < 0: + return self.lock.acquire() + return self.lock.acquire(timeout=timeout) - def __exit__(self, *_args: object) -> None: + def release(self) -> None: self.lock.release() server._ensure_block_candidate_disposition_state() @@ -14484,6 +15465,12 @@ def durable_block_state(*, block_hash: str) -> dict[str, object] | None: ledger.pool_block_state = durable_block_state # type: ignore[attr-defined] self.assertEqual(server.replay_pending_block_candidates(), 3) + replayed = [ + server._block_replay_candidate_queue.get_nowait() + for _ in range(3) + ] + for candidate in replayed: + server._restore_replayed_candidate_acceptance_evidence(candidate) self.assertIn(accepted_hash, server._tip_observed_accepted_block_hashes) self.assertIn(accepted_hash, server._outstanding_block_candidate_hashes) @@ -14679,9 +15666,9 @@ def observing_clear( self.assertFalse(accepted_race_won) outcome = getattr(server, "_block_candidate_outcome", None) self.assertEqual(getattr(outcome, "reason", None), "block-stale") - self.assertEqual( - server.block_candidate_abandoned_counts["block-stale"], - 1, + self.assertNotIn( + "block-stale", + server.block_candidate_abandoned_counts, ) self.assertEqual( getattr(server, "block_candidate_accept_pending_defer_count", 0), @@ -14711,9 +15698,9 @@ def test_terminal_seal_excludes_observations_after_the_commit(self) -> None: ) self.assertFalse(accepted_race_won) - self.assertEqual( - server.block_candidate_abandoned_counts[PRISM_REJECTION_STALE_JOB], - 1, + self.assertNotIn( + PRISM_REJECTION_STALE_JOB, + server.block_candidate_abandoned_counts, ) self.assertNotIn(block_hash, server._outstanding_block_candidate_hashes) @@ -14721,6 +15708,13 @@ def test_terminal_seal_excludes_observations_after_the_commit(self) -> None: # must not register acceptance evidence for the sealed hash. self.assertTrue(server.observe_tip_for_refresh(block_hash)) self.assertNotIn(block_hash, server._tip_observed_accepted_block_hashes) + outcome = getattr(server, "_block_candidate_outcome", None) + self.assertIsNotNone(outcome) + server._record_committed_block_candidate_abandonment(block_hash, outcome) + self.assertEqual( + server.block_candidate_abandoned_counts[PRISM_REJECTION_STALE_JOB], + 1, + ) def test_observation_during_prepared_row_rejection_cannot_split_state(self) -> None: # The exact round-3 interleaving at the post-persist site: a @@ -14863,6 +15857,10 @@ def failing_reject(**kwargs: object) -> dict[str, object]: self.assertIn( block_hash, server._outstanding_block_candidate_hashes ) + self.assertNotIn( + "block-stale", + server.block_candidate_abandoned_counts, + ) # Blockwait reports the pool's own hash during the backoff gap: # the evidence registers instead of vanishing behind the seal. @@ -14872,6 +15870,26 @@ def failing_reject(**kwargs: object) -> dict[str, object]: ) self.assertEqual(abandoned, []) + # The retry can subsequently prove the candidate active and + # complete as submitted. The earlier reversible seals must never + # leave a contradictory abandonment count behind. + ledger.persist_accepted_block = real_persist # type: ignore[method-assign] + rpc.tip = block_hash + rpc.height = 10 + rpc.active[block_hash] = 10 + rpc.getblockhash_override = None + recovered_candidate = self._retained_candidate(server) + self.assertTrue( + server._submit_next_block_candidate_writer(recovered_candidate) + ) + self.assertEqual(submitted, [block_hash]) + self.assertEqual(abandoned, []) + self.assertEqual(server.accepted_block_count, 1) + self.assertNotIn( + "block-stale", + server.block_candidate_abandoned_counts, + ) + def test_pool_closed_gate_requires_probe_proven_acceptance(self) -> None: # Bugbot: observation evidence alone must not open the pool-closed # gate -- an off-chain candidate would fall through toward diff --git a/tests/test_prism_share_ledger.py b/tests/test_prism_share_ledger.py index 20eb646c..92dccd64 100644 --- a/tests/test_prism_share_ledger.py +++ b/tests/test_prism_share_ledger.py @@ -423,9 +423,15 @@ def test_exact_duplicate_share_is_idempotent_but_mutation_is_rejected(self) -> N ledger = SingleWriterShareLedger() first = pending_share(1) duplicate = pending_share(2).__class__(**{**pending_share(2).__dict__, "share_id": first.share_id}) + later_stamp = first.__class__( + **{**first.__dict__, "accepted_at_ms": first.accepted_at_ms + 42} + ) self.assertEqual(ledger.append(first).share_seq, 1) - self.assertEqual(ledger.append(first).share_seq, 1) + replay = ledger.append(later_stamp) + self.assertEqual(replay.share_seq, 1) + self.assertFalse(replay.newly_inserted) + self.assertEqual(replay.accepted_at_ms, first.accepted_at_ms) with self.assertRaisesRegex(ValueError, "payload mismatch"): ledger.append(duplicate) @@ -443,6 +449,8 @@ def test_share_and_block_candidate_intent_commit_atomically(self) -> None: records = ledger.append_batch([(share, intent)]) self.assertEqual(records[0].share_seq, 1) + self.assertTrue(records[0].newly_inserted) + self.assertEqual(records[0].candidate_outbox_state, "pending") self.assertEqual(ledger.pending_block_candidates(), [intent]) self.assertEqual( ledger.pending_block_candidate_rows(), @@ -450,12 +458,27 @@ def test_share_and_block_candidate_intent_commit_atomically(self) -> None: ) # Exact replay returns the original row and does not duplicate outbox # work. A changed intent with the same hash is rejected as corruption. - self.assertEqual(ledger.append_batch([(share, intent)])[0].share_seq, 1) + replay = ledger.append_batch([(share, intent)])[0] + self.assertEqual(replay.share_seq, 1) + self.assertFalse(replay.newly_inserted) + self.assertEqual(replay.candidate_outbox_state, "pending") with self.assertRaisesRegex(ValueError, "candidate payload mismatch"): ledger.append_batch([(share, {**intent, "block_hex": "01"})]) self.assertEqual(len(ledger), 1) self.assertTrue(ledger.mark_block_candidate_submitted(block_hash="ab" * 32)) self.assertEqual(ledger.pending_block_candidates(), []) + later_share = share.__class__( + **{**share.__dict__, "accepted_at_ms": share.accepted_at_ms + 42} + ) + terminal_replay = ledger.append_batch([(later_share, intent)])[0] + self.assertFalse(terminal_replay.newly_inserted) + self.assertEqual(terminal_replay.candidate_outbox_state, "submitted") + self.assertFalse( + ledger.mark_block_candidate_abandoned( + block_hash="ab" * 32, + error="must not invert terminal state", + ) + ) def test_pending_candidate_age_distinguishes_first_attempt(self) -> None: ledger = SingleWriterShareLedger() @@ -527,8 +550,12 @@ def test_candidate_retry_with_new_acknowledgment_stamp_is_idempotent(self) -> No retry_share = pending_share(1, accepted_at_ms=2_042) retry_intent = {**intent, "pending_share": dict(retry_share.__dict__)} - self.assertTrue(ledger.persist_block_candidate_intent(intent)) - self.assertFalse(ledger.persist_block_candidate_intent(retry_intent)) + first_persist = ledger.persist_block_candidate_intent(intent) + retry_persist = ledger.persist_block_candidate_intent(retry_intent) + self.assertTrue(first_persist) + self.assertEqual(first_persist.state, "pending") + self.assertFalse(retry_persist) + self.assertEqual(retry_persist.state, "pending") self.assertEqual(ledger.pending_block_candidates(), [intent]) with self.assertRaisesRegex(ValueError, "candidate payload mismatch"): ledger.persist_block_candidate_intent({**retry_intent, "block_hex": "01"}) @@ -541,6 +568,10 @@ def test_candidate_retry_with_new_acknowledgment_stamp_is_idempotent(self) -> No ledger.pending_block_candidate_rows(), [{"block_hash": "ef" * 32, "candidate": intent}], ) + self.assertTrue(ledger.mark_block_candidate_submitted(block_hash="ef" * 32)) + terminal_persist = ledger.persist_block_candidate_intent(retry_intent) + self.assertFalse(terminal_persist) + self.assertEqual(terminal_persist.state, "submitted") def test_concurrent_append_still_has_one_canonical_sequence(self) -> None: ledger = SingleWriterShareLedger() @@ -998,6 +1029,8 @@ def test_postgres_batch_sql_fences_share_and_candidate_in_one_statement(self) -> self.assertIn("inserted_candidates AS", query) self.assertIn("qbit_block_candidate_outbox", query) self.assertIn("duplicate share_id payload mismatch", query) + self.assertIn("'candidate_outbox_state'", query) + self.assertNotIn("ledger.accepted_at IS DISTINCT", query) self.assertEqual(query.count("SELECT CASE"), 1) def test_postgres_candidate_only_intent_forces_durable_fenced_commit(self) -> None: @@ -1016,6 +1049,7 @@ def test_postgres_candidate_only_intent_forces_durable_fenced_commit(self) -> No self.assertIn("set_config('synchronous_commit', 'on', true)", query) self.assertIn("qbit_ledger_writer_lease", query) self.assertIn("qbit_block_candidate_outbox", query) + self.assertIn("SELECT candidate_sha256, state", query) def test_postgres_pending_candidate_rows_keep_authoritative_outbox_key(self) -> None: intent = { From 8cfe6263fe0193ba8882b4a8993160d3a69e1300 Mon Sep 17 00:00:00 2001 From: Anatolie Date: Tue, 11 Aug 2026 15:58:29 -0400 Subject: [PATCH 03/10] fix(prism): tolerate startup replay timeouts --- docs/prism-ledger-ops.md | 10 +- lab/prism/prism_coordinator.py | 26 ++- lab/prism/share_ledger.py | 40 +++- tests/test_prism_coordinator_vardiff.py | 254 ++++++++++++++++++++++++ tests/test_prism_share_ledger.py | 87 ++++++++ 5 files changed, 407 insertions(+), 10 deletions(-) diff --git a/docs/prism-ledger-ops.md b/docs/prism-ledger-ops.md index d551e864..e4724449 100644 --- a/docs/prism-ledger-ops.md +++ b/docs/prism-ledger-ops.md @@ -99,10 +99,12 @@ coalesces wakeups; it cannot delete an outbox row. Recovery restores pending rows in batches into a separate, lower-priority replay queue, without doing per-row database accounting. Live discoveries therefore always outrank restart work, while an older replay stalled in accounting cannot hide later durable -rows. Before qbitd can observe a candidate, the coordinator installs a short -in-memory prospective-payout barrier; this prevents startup prewarm from -issuing child work from the old balance base without falsely claiming that the -block landed. +rows. The pre-accept startup recovery pass is best-effort under a slow ledger: +if its database budget expires, the coordinator finishes starting and the +block-submitter loop retries every durable pending row with ordinary backoff. +Before qbitd can observe a candidate, the coordinator installs a short in-memory +prospective-payout barrier; this prevents startup prewarm from issuing child +work from the old balance base without falsely claiming that the block landed. Once a durable candidate is dequeued, its qbit `submitblock` RPC is the fast lane: it runs before the attempt-marker write, accepted-block writer admission, diff --git a/lab/prism/prism_coordinator.py b/lab/prism/prism_coordinator.py index 17c52404..4819a977 100644 --- a/lab/prism/prism_coordinator.py +++ b/lab/prism/prism_coordinator.py @@ -13442,11 +13442,11 @@ def _serve_with_listener_stack(self, listener_stack: ExitStack) -> None: ) if self.audit_bind and self.audit_port: self.start_audit_server() - # Recover one block candidate before accepting Stratum connections. - # Start its qbitd fast lane immediately afterward: startup job prewarm - # may depend on a slow ledger/backend, but it must never postpone an - # already-durable block offer to the node. - if not self._run_startup_writer_replay(self.replay_pending_block_candidates): + # Make a best-effort attempt to recover one block candidate before + # accepting Stratum connections. If a slow ledger exhausts the short + # database budget, finish startup and let the dedicated submitter loop + # retry every durable outbox row with its ordinary paced backoff. + if not self._run_startup_block_candidate_replay(): return if self.stop_event.is_set(): return @@ -13608,6 +13608,22 @@ def _run_startup_writer_replay( return False return True + def _run_startup_block_candidate_replay(self) -> bool: + """Run best-effort pre-accept replay without dying on a slow ledger.""" + try: + return self._run_startup_writer_replay( + self.replay_pending_block_candidates + ) + except TimeoutError: + print( + "prism coordinator: startup block candidate replay timed out " + "phase=replay-outbox-query " + f"timeout={self._block_submitter_db_timeout():g}s; " + "continuing startup; block submitter loop will retry", + flush=True, + ) + return True + def accept_loop(self, server: socket.socket, profile: StratumListenerProfile) -> None: while not self.stop_event.is_set(): self._record_heartbeat(profile.heartbeat_name) diff --git a/lab/prism/share_ledger.py b/lab/prism/share_ledger.py index 94a33033..92483ad4 100644 --- a/lab/prism/share_ledger.py +++ b/lab/prism/share_ledger.py @@ -46,6 +46,33 @@ class LedgerOperationTimeout(TimeoutError): """A caller-scoped PostgreSQL deadline expired before work completed.""" +def _is_postgres_deadline_error(error: BaseException | str) -> bool: + """Recognize backend cancellations caused by an armed caller deadline.""" + message = str(error).casefold() + sqlstate = getattr(error, "sqlstate", None) + if sqlstate is None: + sqlstate = getattr(getattr(error, "diag", None), "sqlstate", None) + normalized_sqlstate = str(sqlstate or "").upper() + if normalized_sqlstate in {"57014", "55P03"}: + return True + # psql's verbose mode exposes SQLSTATE even when lc_messages localizes the + # text. This helper is called only while our statement/lock deadlines are + # armed, and ledger SQL does not use NOWAIT, so scoped 55P03 is a timeout. + if "57014:" in message or "55p03:" in message: + return True + return any( + marker in message + for marker in ( + "canceling statement due to statement timeout", + "canceling statement due to lock timeout", + "connection timeout expired", + "timeout expired", + "connection timed out", + "operation timed out", + ) + ) + + class _AuditShareSegmentConflict(RuntimeError): """A share sequence is bound to more than one audit payload.""" @@ -1724,6 +1751,10 @@ def run_json( row = conn.execute(sql).fetchone() return parse_single_json_value(row[0] if row else None) except self._psycopg.OperationalError as exc: + if timeout_seconds is not None and _is_postgres_deadline_error(exc): + raise LedgerOperationTimeout( + f"postgres operation exceeded {timeout_seconds:g}s" + ) from exc if attempt + 1 >= attempts: raise RuntimeError(f"postgres query failed: {exc}") from exc raise AssertionError("unreachable") @@ -7659,6 +7690,8 @@ def _run_sql(self, sql: str) -> str: "--no-psqlrc", "--set", "ON_ERROR_STOP=1", + "--set", + "VERBOSITY=verbose", "--tuples-only", "--no-align", "--quiet", @@ -7698,9 +7731,14 @@ def _run_sql(self, sql: str) -> str: f"psql operation exceeded {timeout_seconds:g}s" ) from exc if completed.returncode != 0: + stderr = completed.stderr.strip() + if timeout_seconds is not None and _is_postgres_deadline_error(stderr): + raise LedgerOperationTimeout( + f"psql operation exceeded {timeout_seconds:g}s" + ) raise RuntimeError( "psql command failed " - f"(exit {completed.returncode}): {completed.stderr.strip()}" + f"(exit {completed.returncode}): {stderr}" ) return completed.stdout diff --git a/tests/test_prism_coordinator_vardiff.py b/tests/test_prism_coordinator_vardiff.py index 8249f319..e81e433d 100644 --- a/tests/test_prism_coordinator_vardiff.py +++ b/tests/test_prism_coordinator_vardiff.py @@ -25,6 +25,7 @@ from lab.prism import direct_stratum from lab.prism.share_ledger import ( PendingShare, + PsqlShareLedger, SingleWriterShareLedger, WRITER_LEASE_HEARTBEAT_SESSION_PREFIX, ) @@ -61,6 +62,7 @@ TemplateRefreshBlocked, TemplateRefreshSuperseded, PrismCoordinator, + ShutdownInProgress, WorkerIdentity, _FanoutCancellation, _ObservedRLock, @@ -12107,6 +12109,258 @@ def blocked_accounting( if accounting is not None: accounting.join(2) + def test_startup_block_replay_timeout_starts_submitter_and_converges(self) -> None: + server, state, _recording = submit_coordinator() + server.max_blocks = 10 + server.stop_after_block = False + server.block_submit_db_timeout_seconds = 0.01 + server.block_candidate_retry_initial_seconds = 0.01 + ledger = SingleWriterShareLedger() + server.ledger = ledger + block_hash = "e5" * 32 + pending = PendingShare( + share_id=f"miner-a:{block_hash}", + miner_id="miner-a", + order_key="miner-a", + p2mr_program_hex="11" * 32, + share_difficulty=1, + network_difficulty=1, + template_height=9, + job_id="job-1", + job_issued_at_ms=1, + accepted_at_ms=1, + ntime=1, + ) + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="00", + block_hash_hex=block_hash, + block_hex="e5", + share_pass=True, + block_pass=True, + ), + pending_share=pending, + ) + ledger.append_batch( + [(pending, server.block_candidate_intent(candidate))] + ) + + query_started = threading.Event() + release_query = threading.Event() + query_calls = 0 + startup_call: list[object] = [] + original_pending_rows = ledger.pending_block_candidate_rows + + def slow_pending_rows(*, limit: int = 32) -> list[dict[str, object]]: + nonlocal query_calls + query_calls += 1 + if query_calls == 1: + with server._block_submitter_ledger_calls_lock: + startup_call.append( + server._block_submitter_ledger_calls[ + ("replay-outbox-query",) + ] + ) + query_started.set() + if not release_query.wait(5): + raise AssertionError("timed out waiting to release outbox query") + return original_pending_rows(limit=limit) + + ledger.pending_block_candidate_rows = slow_pending_rows # type: ignore[method-assign] + original_record_wait = server._record_block_submitter_wait + loop_reuse_waiting = threading.Event() + + def observed_record_wait(phase: str) -> None: + original_record_wait(phase) + if ( + phase == "replay-outbox-query" + and getattr(server, "_block_submitter_thread_ident", None) + == threading.get_ident() + ): + loop_reuse_waiting.set() + + server._record_block_submitter_wait = observed_record_wait # type: ignore[method-assign] + + submitted: list[str] = [] + + class RecordingRpc(TipRpc): + def call( + self, + method: str, + params: list[object] | None = None, + *, + timeout: float | None = None, + ) -> object: + if method == "getblockcount": + return 9 + if method == "submitblock": + submitted.append(str((params or [""])[0])) + return None + return super().call(method, params) + + server.rpc = RecordingRpc("00" * 32) + accounted: list[str] = [] + + def account_candidate( + replayed: PrismBlockCandidate, + **_kwargs: object, + ) -> bool: + replayed_hash = replayed.submission.block_hash_hex + accounted.append(replayed_hash) + ledger.mark_block_candidate_submitted(block_hash=replayed_hash) + server.stop_event.set() + return True + + server._call_block_candidate_writer = account_candidate # type: ignore[method-assign] + + profile = SimpleNamespace(heartbeat_name="stratum_accept_default") + listener_closed = threading.Event() + listener = SimpleNamespace(close=listener_closed.set) + server.listener_profiles = [profile] + server.bind = "127.0.0.1" + server.port = 0 + server.min_ready_miners = 1 + server.audit_bind = None + server.audit_port = 0 + server.hot_path_log_enabled = False + server.blockwait_enabled = False + server.vardiff_idle_sweep_seconds = 0.0 + server.stratum_initial_job_timeout_seconds = 0.0 + server.watchdog_enabled = False + server.watchdog_interval_seconds = 0.1 + server.template_refresh_failure_exit_seconds = 120.0 + server.coordination_blocked_exit_seconds = 120.0 + server.open_stratum_listeners = ( # type: ignore[method-assign] + lambda _stack: [(listener, profile)] + ) + server.validate_live_chain_identity = lambda: None # type: ignore[method-assign] + server.validate_live_template_and_fee_policy = lambda: None # type: ignore[method-assign] + server.prism_payout_policy = lambda: {} # type: ignore[method-assign] + server.prewarm_startup_jobs = lambda: None # type: ignore[method-assign] + server.watchdog_loop = lambda: None # type: ignore[method-assign] + server.blockpoll_loop = lambda: None # type: ignore[method-assign] + server.replay_recovered_shares = lambda: 0 # type: ignore[method-assign] + server.share_append_loop = lambda: None # type: ignore[method-assign] + server.shutdown = lambda *, reason="graceful": True # type: ignore[method-assign] + + def drain_threads(threads: list[tuple[threading.Thread, float]]) -> None: + for thread, timeout in threads: + thread.join(timeout) + + server.drain_non_writer_components = drain_threads # type: ignore[method-assign] + + def accept_after_startup(_listener: object, _profile: object) -> None: + self.assertTrue(loop_reuse_waiting.wait(2)) + self.assertIsNotNone( + getattr(server, "_block_submitter_thread_ident", None) + ) + self.assertTrue(query_started.wait(1)) + # The loop is waiting on the exact startup call while that worker + # remains blocked; no replacement query was spawned. + with server._block_submitter_ledger_calls_lock: + self.assertIs( + server._block_submitter_ledger_calls.get( + ("replay-outbox-query",) + ), + startup_call[0], + ) + self.assertEqual(query_calls, 1) + release_query.set() + deadline = time.monotonic() + 2 + while not accounted and time.monotonic() < deadline: + time.sleep(0.01) + self.assertTrue(accounted) + + server.accept_loop = accept_after_startup # type: ignore[method-assign] + + try: + with patch("builtins.print") as printed: + server._serve_with_listener_stack(SimpleNamespace()) # type: ignore[arg-type] + finally: + server.stop_event.set() + release_query.set() + + ledger.pending_block_candidate_rows = original_pending_rows # type: ignore[method-assign] + startup_logs = [ + " ".join(str(value) for value in call.args) + for call in printed.call_args_list + ] + self.assertTrue( + any( + "prism coordinator: startup block candidate replay timed out " + "phase=replay-outbox-query timeout=0.01s" in message + for message in startup_logs + ) + ) + self.assertTrue(query_started.is_set()) + self.assertTrue(listener_closed.is_set()) + self.assertEqual(submitted, ["e5"]) + self.assertEqual(accounted, [block_hash]) + self.assertEqual(ledger.pending_block_candidates(), []) + + def test_startup_block_replay_catches_psql_server_timeout(self) -> None: + server, _state, _recording = submit_coordinator() + ledger = PsqlShareLedger.__new__(PsqlShareLedger) + ledger._command = ["psql"] + ledger._native = None + ledger._operation_timeout_local = threading.local() + + def timed_out_rows(*, limit: int = 32) -> list[dict[str, object]]: + ledger._run_sql(f"SELECT {limit};") + return [] + + ledger.pending_block_candidate_rows = timed_out_rows # type: ignore[method-assign] + server.ledger = ledger + completed = subprocess.CompletedProcess( + args=["psql"], + returncode=3, + stdout="", + stderr=( + "ERROR: 57014: canceling statement due to statement timeout" + ), + ) + with patch( + "lab.prism.share_ledger.subprocess.run", + return_value=completed, + ), patch("builtins.print") as printed: + self.assertTrue(server._run_startup_block_candidate_replay()) + + startup_logs = [ + " ".join(str(value) for value in call.args) + for call in printed.call_args_list + ] + self.assertTrue( + any( + "startup block candidate replay timed out " + "phase=replay-outbox-query" in message + for message in startup_logs + ) + ) + + def test_startup_block_replay_keeps_hard_database_errors_fatal(self) -> None: + server, _state, _recording = submit_coordinator() + + def failed_rows(*, limit: int = 32) -> list[dict[str, object]]: + raise RuntimeError(f"postgres failed limit={limit}") + + server.ledger = SimpleNamespace( + pending_block_candidate_rows=failed_rows, + ) + with self.assertRaisesRegex(RuntimeError, "postgres failed"): + server._run_startup_block_candidate_replay() + + def test_startup_block_replay_preserves_shutdown_stop(self) -> None: + server = self._bare_coordinator() + + def shutdown_replay() -> int: + raise ShutdownInProgress("shutdown won") + + server.replay_pending_block_candidates = shutdown_replay # type: ignore[method-assign] + + self.assertFalse(server._run_startup_block_candidate_replay()) + def test_stuck_rpc_worker_pool_requests_nonzero_restart(self) -> None: server, _state, _recording = submit_coordinator() server.block_submit_stuck_call_exit_seconds = 0.04 diff --git a/tests/test_prism_share_ledger.py b/tests/test_prism_share_ledger.py index 92dccd64..6bc2b050 100644 --- a/tests/test_prism_share_ledger.py +++ b/tests/test_prism_share_ledger.py @@ -3902,6 +3902,51 @@ def test_subprocess_operation_timeout_sets_client_and_server_deadlines(self) -> self.assertEqual(kwargs["env"]["PGCONNECT_TIMEOUT"], "1") self.assertIn("statement_timeout=", kwargs["env"]["PGOPTIONS"]) self.assertIn("lock_timeout=", kwargs["env"]["PGOPTIONS"]) + self.assertIn("VERBOSITY=verbose", run.call_args.args[0]) + + def test_subprocess_server_deadlines_raise_operation_timeout(self) -> None: + ledger = PsqlShareLedger.__new__(PsqlShareLedger) + ledger._command = ["psql"] + ledger._native = None + ledger._operation_timeout_local = threading.local() + deadline_errors = ( + "ERROR: 57014: canceling statement due to statement timeout", + "FEHLER: 57014: Anweisung wegen Zeitüberschreitung abgebrochen", + "ERROR: 55P03: canceling statement due to lock timeout", + "FEHLER: 55P03: Anweisung wegen Zeitüberschreitung abgebrochen", + "psql: error: connection to server failed: timeout expired", + ) + + for stderr in deadline_errors: + with self.subTest(stderr=stderr), unittest.mock.patch( + "lab.prism.share_ledger.subprocess.run", + return_value=unittest.mock.Mock( + returncode=3, + stdout="", + stderr=stderr, + ), + ): + with ledger.operation_timeout(0.5): + with self.assertRaises(LedgerOperationTimeout): + ledger._run_sql("SELECT '{}'::json;") + + def test_subprocess_hard_error_remains_runtime_error(self) -> None: + ledger = PsqlShareLedger.__new__(PsqlShareLedger) + ledger._command = ["psql"] + ledger._native = None + ledger._operation_timeout_local = threading.local() + completed = unittest.mock.Mock( + returncode=3, + stdout="", + stderr="ERROR: permission denied for table qbit_block_candidate_outbox", + ) + + with unittest.mock.patch( + "lab.prism.share_ledger.subprocess.run", + return_value=completed, + ), ledger.operation_timeout(0.5): + with self.assertRaisesRegex(RuntimeError, "permission denied"): + ledger._run_sql("SELECT '{}'::json;") def test_native_operation_timeout_is_transaction_local(self) -> None: class OperationalError(Exception): @@ -3948,6 +3993,48 @@ def connection(*, timeout_seconds: float | None = None) -> Any: self.assertRegex(executions[1], r"^SET LOCAL lock_timeout = '\d+ms'$") self.assertEqual(executions[2], "SELECT json_build_object('ok', true)") + def test_native_server_deadline_raises_operation_timeout(self) -> None: + class OperationalError(Exception): + pass + + class FakePsycopg: + pass + + FakePsycopg.OperationalError = OperationalError # type: ignore[attr-defined] + + class FakeConnection: + def __init__(self, error: OperationalError): + self.error = error + + @contextlib.contextmanager + def transaction(self) -> Any: + yield + + def execute(self, sql: str) -> FakeConnection: + if sql.startswith("SET LOCAL"): + return self + raise self.error + + client = _NativePostgresClient.__new__(_NativePostgresClient) + client._psycopg = FakePsycopg + + deadline_errors = ( + ("57014", "canceling statement due to statement timeout"), + ("55P03", "Anweisung wegen Zeitüberschreitung abgebrochen"), + ) + for sqlstate, message in deadline_errors: + with self.subTest(sqlstate=sqlstate): + error = OperationalError(message) + error.sqlstate = sqlstate # type: ignore[attr-defined] + + @contextlib.contextmanager + def connection(*, timeout_seconds: float | None = None) -> Any: + yield FakeConnection(error) + + client.connection = connection # type: ignore[method-assign] + with self.assertRaises(LedgerOperationTimeout): + client.run_json("SELECT '{}'::json", timeout_seconds=0.5) + def test_database_url_extraction_variants(self) -> None: self.assertEqual( database_url_from_psql_command(["psql", "postgres://u:p@h:5432/db"]), From c05d5b4670b574153b78505e10f8a408df59a20e Mon Sep 17 00:00:00 2001 From: Anatolie Date: Tue, 11 Aug 2026 17:02:23 -0400 Subject: [PATCH 04/10] fix(prism): enforce fast-lane block capacity --- lab/prism/prism_coordinator.py | 21 +++++++--- tests/test_prism_coordinator_vardiff.py | 55 +++++++++++++++++++++++++ 2 files changed, 70 insertions(+), 6 deletions(-) diff --git a/lab/prism/prism_coordinator.py b/lab/prism/prism_coordinator.py index 4819a977..bc7e6717 100644 --- a/lab/prism/prism_coordinator.py +++ b/lab/prism/prism_coordinator.py @@ -23930,9 +23930,10 @@ def _node_submission_for_candidate( "_accounted_accepted_block_hashes", set(), ) - pool_closed = ( - self.accepted_block_count >= self.max_blocks - and block_hash not in accounted_hashes + accepted_count = int(self.accepted_block_count) + pool_closed = block_hash not in accounted_hashes and ( + accepted_count >= int(self.max_blocks) + or (bool(self.stop_after_block) and accepted_count >= 1) ) if pool_closed: return _BlockCandidateNodeSubmission(attempted=False) @@ -24022,6 +24023,10 @@ def _submit_synchronous_block_candidate( ) return accepted try: + if not self._reserve_block_fast_lane_slot(block_hash): + raise RuntimeError( + "block candidate is waiting for fast-lane capacity" + ) node_submission = self._node_submission_for_candidate(candidate) self._mark_block_candidate_attempted(block_hash) with self._block_submitter_ledger_statement_timeout_scope(): @@ -24252,7 +24257,7 @@ def _record_committed_block_candidate_abandonment( ) def _reserve_block_fast_lane_slot(self, block_hash: str) -> bool: - """Reserve configured pool capacity before asynchronous accounting.""" + """Reserve pool capacity while a node offer awaits terminal accounting.""" key = block_hash.lower() with self.lock: reservations = getattr(self, "_block_fast_lane_reservations", None) @@ -26534,9 +26539,13 @@ def _submit_block_candidate_serialized( self._clear_accepted_block_payout_preview(block_hash) return True with self.lock: + accepted_count = int(self.accepted_block_count) pool_closed = ( - self.accepted_block_count >= self.max_blocks - and block_hash not in self._accounted_accepted_block_hashes + block_hash not in self._accounted_accepted_block_hashes + and ( + accepted_count >= int(self.max_blocks) + or (bool(self.stop_after_block) and accepted_count >= 1) + ) ) if pool_closed and self._block_candidate_chain_probe( block_hash, diff --git a/tests/test_prism_coordinator_vardiff.py b/tests/test_prism_coordinator_vardiff.py index e81e433d..8f8be8c2 100644 --- a/tests/test_prism_coordinator_vardiff.py +++ b/tests/test_prism_coordinator_vardiff.py @@ -10004,6 +10004,30 @@ def test_block_submitter_drops_candidate_when_pool_closed(self) -> None: self.assertEqual(server.rejection_counts_by_reason[PRISM_REJECTION_POOL_CLOSED], 0) self.assertEqual(ledger.persisted, []) + def test_block_submitter_honors_stop_after_block_above_one_block_capacity( + self, + ) -> None: + server, state, ledger = submit_coordinator() + server.accepted_block_count = 1 + server.max_blocks = 2 + server.stop_after_block = True + submission = SimpleNamespace( + coinbase_tx_hex="c0ffee", + block_hash_hex="de" * 32, + block_hex="00", + ) + + accepted = server.submit_block_candidate( + block_candidate(server, state, submission) + ) + + self.assertFalse(accepted) + self.assertEqual( + server.block_candidate_abandoned_counts[PRISM_REJECTION_POOL_CLOSED], + 1, + ) + self.assertEqual(ledger.persisted, []) + def test_block_worthy_share_is_credited_and_enqueued_before_block_submission(self) -> None: # The share ack must never wait on the block path: a block-worthy # share that met its target is credited immediately and the candidate @@ -13177,6 +13201,37 @@ def test_accounted_block_replaces_its_capacity_reservation(self) -> None: self.assertNotIn(block_hash, server._block_fast_lane_reservations) self.assertTrue(server._reserve_block_fast_lane_slot("e3" * 32)) + def test_synchronous_candidate_waits_for_fast_lane_capacity(self) -> None: + server, state, _recording = submit_coordinator() + server.max_blocks = 1 + server.stop_after_block = True + reserved_hash = "e4" * 32 + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="c0ffee", + block_hash_hex="e5" * 32, + block_hex="e5", + share_pass=False, + block_pass=True, + ), + credit_share_on_accept=True, + ) + server._ensure_block_candidate_disposition_state() + self.assertTrue(server._reserve_block_fast_lane_slot(reserved_hash)) + server._node_submission_for_candidate = ( # type: ignore[method-assign] + lambda _candidate: (_ for _ in ()).throw( + AssertionError("capacity-blocked candidate must not reach qbitd") + ) + ) + + with self.assertRaisesRegex(RuntimeError, "fast-lane capacity"): + server._submit_synchronous_block_candidate(candidate) + + self.assertIs(server._retry_block_candidate, candidate) + self.assertEqual(server._block_fast_lane_reservations, {reserved_hash}) + def test_block_submitter_retry_wait_heartbeats_in_bounded_slices(self) -> None: server = self._bare_coordinator() server.watchdog_timeout_seconds = 0.3 From 84e3d52ee5126d4b1bd4aaa1cd641f3716e29686 Mon Sep 17 00:00:00 2001 From: Anatolie Date: Tue, 11 Aug 2026 17:03:00 -0400 Subject: [PATCH 05/10] fix(prism): retain failed fast-lane handoffs --- lab/prism/prism_coordinator.py | 15 ++++- tests/test_prism_coordinator_vardiff.py | 81 +++++++++++++++++++++++++ 2 files changed, 93 insertions(+), 3 deletions(-) diff --git a/lab/prism/prism_coordinator.py b/lab/prism/prism_coordinator.py index bc7e6717..e80ad71e 100644 --- a/lab/prism/prism_coordinator.py +++ b/lab/prism/prism_coordinator.py @@ -24770,13 +24770,19 @@ def submit_next_block_candidate( try: node_submission = self._node_submission_for_candidate(candidate) except BaseException: - self._release_block_candidate_disposition(lease) + try: + self._retain_block_candidate_for_retry(candidate) + finally: + self._release_block_candidate_disposition(lease) raise else: try: node_submission = self._node_submission_for_candidate(candidate) except BaseException: - self._release_block_candidate_disposition(lease) + try: + self._retain_block_candidate_for_retry(candidate) + finally: + self._release_block_candidate_disposition(lease) raise else: node_submission = _BlockCandidateNodeSubmission(attempted=False) @@ -24790,7 +24796,10 @@ def submit_next_block_candidate( try: enqueued = self._enqueue_block_accounting_task(task) except BaseException: - self._release_block_candidate_disposition(lease) + try: + self._retain_block_candidate_for_retry(candidate) + finally: + self._release_block_candidate_disposition(lease) raise if enqueued: transferred = True diff --git a/tests/test_prism_coordinator_vardiff.py b/tests/test_prism_coordinator_vardiff.py index 8f8be8c2..51665cff 100644 --- a/tests/test_prism_coordinator_vardiff.py +++ b/tests/test_prism_coordinator_vardiff.py @@ -13232,6 +13232,87 @@ def test_synchronous_candidate_waits_for_fast_lane_capacity(self) -> None: self.assertIs(server._retry_block_candidate, candidate) self.assertEqual(server._block_fast_lane_reservations, {reserved_hash}) + def test_node_offer_exception_retains_reserved_candidate(self) -> None: + server, state, _recording = submit_coordinator() + server.max_blocks = 1 + server.stop_after_block = True + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="c0ffee", + block_hash_hex="e6" * 32, + block_hex="e6", + share_pass=True, + block_pass=True, + ), + ) + block_hash = candidate.submission.block_hash_hex + server._node_submission_for_candidate = ( # type: ignore[method-assign] + lambda _candidate: (_ for _ in ()).throw( + RuntimeError("node offer bookkeeping failed") + ) + ) + server.enqueue_block_candidate(candidate) + + with self.assertRaisesRegex(RuntimeError, "node offer bookkeeping failed"): + server.submit_next_block_candidate(defer_accounting=True) + + self.assertIs(server._retry_block_candidate, candidate) + self.assertIn(block_hash, server._block_fast_lane_reservations) + self.assertFalse(server._reserve_block_fast_lane_slot("e7" * 32)) + lease = server._claim_block_candidate_disposition( + block_hash, + blocking=False, + ) + self.assertIsNotNone(lease) + assert lease is not None + server._release_block_candidate_disposition(lease) + + def test_accounting_enqueue_exception_retains_reserved_candidate(self) -> None: + server, state, _recording = submit_coordinator() + server.max_blocks = 1 + server.stop_after_block = True + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="c0ffee", + block_hash_hex="e8" * 32, + block_hex="e8", + share_pass=True, + block_pass=True, + ), + ) + block_hash = candidate.submission.block_hash_hex + server._node_submission_for_candidate = ( # type: ignore[method-assign] + lambda _candidate: SimpleNamespace( + attempted=True, + result=None, + error=None, + ) + ) + server._enqueue_block_accounting_task = ( # type: ignore[method-assign] + lambda _task: (_ for _ in ()).throw( + RuntimeError("accounting enqueue failed") + ) + ) + server.enqueue_block_candidate(candidate) + + with self.assertRaisesRegex(RuntimeError, "accounting enqueue failed"): + server.submit_next_block_candidate(defer_accounting=True) + + self.assertIs(server._retry_block_candidate, candidate) + self.assertIn(block_hash, server._block_fast_lane_reservations) + self.assertFalse(server._reserve_block_fast_lane_slot("e9" * 32)) + lease = server._claim_block_candidate_disposition( + block_hash, + blocking=False, + ) + self.assertIsNotNone(lease) + assert lease is not None + server._release_block_candidate_disposition(lease) + def test_block_submitter_retry_wait_heartbeats_in_bounded_slices(self) -> None: server = self._bare_coordinator() server.watchdog_timeout_seconds = 0.3 From 81c601d57aa6173fd0ff533d00d9c5dbbf7fd817 Mon Sep 17 00:00:00 2001 From: Anatolie Date: Tue, 11 Aug 2026 17:03:37 -0400 Subject: [PATCH 06/10] fix(prism): reconcile the observed post-submit tip --- lab/prism/prism_coordinator.py | 4 +- tests/test_prism_coordinator_vardiff.py | 59 +++++++++++++++++++++++++ 2 files changed, 62 insertions(+), 1 deletion(-) diff --git a/lab/prism/prism_coordinator.py b/lab/prism/prism_coordinator.py index e80ad71e..70dc9371 100644 --- a/lab/prism/prism_coordinator.py +++ b/lab/prism/prism_coordinator.py @@ -26743,7 +26743,9 @@ def _submit_block_candidate_serialized( revalidated_append_epoch = revalidation_base_epoch landed = self._land_and_confirm_block_candidate( candidate, - current_tip=current_tip, + # Fresh-attempt classification may use the stamped parent, but + # payout reconciliation must follow the observed post-submit tip. + current_tip=observed_tip, already_active=already_active, worker=worker, node_submission=node_submission, diff --git a/tests/test_prism_coordinator_vardiff.py b/tests/test_prism_coordinator_vardiff.py index 51665cff..e849fff8 100644 --- a/tests/test_prism_coordinator_vardiff.py +++ b/tests/test_prism_coordinator_vardiff.py @@ -8856,6 +8856,65 @@ def ordered_build(**_kwargs: object) -> dict[str, object]: self.assertEqual(len(ledger.persisted), 1) self.assertEqual(len(ledger.confirmed), 1) + def test_successful_fast_lane_reconciles_observed_post_submit_tip(self) -> None: + parent_hash = "00" * 32 + block_hash = "cd" * 32 + server, state, ledger = submit_coordinator(tip=parent_hash) + server.stop_after_block = False + server.max_blocks = 10 + server.rpc = SubmitAcceptingTemplateRpc( + old_tip=parent_hash, + block_hash=block_hash, + ledger=ledger, + ) + reconciled: list[tuple[str, bool]] = [] + landing_inputs: list[tuple[str, bool]] = [] + + def reconcile( + tip_hash: str, + *, + _coalesce_same_tip: bool = True, + ) -> bool: + reconciled.append((tip_hash, _coalesce_same_tip)) + return True + + original_land = server._land_and_confirm_block_candidate + + def observe_landing( + candidate: PrismBlockCandidate, + **kwargs: object, + ) -> object: + landing_inputs.append( + (str(kwargs["current_tip"]), bool(kwargs["already_active"])) + ) + return original_land(candidate, **kwargs) # type: ignore[arg-type] + + server.ensure_reorg_reconciled_for_tip = reconcile # type: ignore[method-assign] + server._land_and_confirm_block_candidate = observe_landing # type: ignore[method-assign] + server.build_audit_bundle = ( # type: ignore[method-assign] + lambda **_kwargs: verified_block_bundle() + ) + server.verify_bundle = ( # type: ignore[method-assign] + lambda *_args, **_kwargs: verified_audit_report() + ) + submission = SimpleNamespace( + coinbase_tx_hex="c0ffee", + block_hash_hex=block_hash, + block_hex="00", + ) + + with tempfile.TemporaryDirectory() as tempdir: + server.audit_dir = Path(tempdir) + server.evidence_path = Path(tempdir) / "evidence.json" + server.ledger_writer_public_key_hex = "aa" * 32 + accepted = server.submit_block_candidate( + block_candidate(server, state, submission) + ) + + self.assertTrue(accepted) + self.assertEqual(landing_inputs, [(block_hash, False)]) + self.assertEqual(reconciled, [(block_hash, False)]) + def test_submitter_offers_block_before_writer_admission_with_rpc_deadline(self) -> None: server, state, _ledger = submit_coordinator() server.block_submit_rpc_timeout_seconds = 0.75 From c74fd006b5a88cb58d3723022e46bfabc790c2b8 Mon Sep 17 00:00:00 2001 From: Anatolie Diordita Date: Wed, 12 Aug 2026 07:14:50 +0000 Subject: [PATCH 07/10] fix(prism): gate accounting on the landing fence after fast-lane offers Rebasing the submit-first fast lane onto the 1.x.x landing fences left the accounting decision unsynchronized with fenced predating appends: the fast lane no longer holds the fence across submitblock, so a landing could verify a pre-bump epoch while a predating row's durable commit was still in flight and persist a payout window omitting that row. Re-check the live append-invalidation epoch under the landing fence lock after a completed fast-lane offer, immediately before accounting: the fence can no longer gate the node offer, but it still gates accounting. The fallback (not-yet-offered) path keeps the base behavior of holding the fence across submitblock itself. Adapt the 1.x.x fence tests to submit-first semantics: the node offer now always goes out, so their assertions move from "submitblock must not run" to "accounting must abandon with append_epoch_stale", matching the pattern the durable-descendant fast-lane test already uses. Co-Authored-By: Claude Fable 5 --- lab/prism/prism_coordinator.py | 29 +++++ tests/test_prism_coordinator_vardiff.py | 157 ++++++++++++++---------- 2 files changed, 118 insertions(+), 68 deletions(-) diff --git a/lab/prism/prism_coordinator.py b/lab/prism/prism_coordinator.py index 70dc9371..81d46899 100644 --- a/lab/prism/prism_coordinator.py +++ b/lab/prism/prism_coordinator.py @@ -26006,6 +26006,7 @@ def _land_and_confirm_block_candidate( block_hash, block_height=expected_height, ) + fallback_submit_under_fence = not node_submission.attempted if not node_submission.attempted: self._require_fresh_ledger_lease_for_external_side_effect( "submitblock" @@ -26063,6 +26064,34 @@ def _land_and_confirm_block_candidate( expected_height=expected_height, ) return None + if ( + not fallback_submit_under_fence + and effective_append_epoch is not None + and not getattr(context, "collection_only", False) + ): + # The fast lane offered this block to qbitd without any + # ledger synchronization, so the landing fence can no + # longer gate submitblock itself. It still gates the + # accounting decision: wait out any fenced predating + # append whose durable commit is in flight (the commit + # holds this lock across its epoch bump) and fail closed + # if the live epoch moved past the window this + # candidate's coinbase paid. + with self._payout_append_landing_fence_lock: + with self._job_cache_lock: + live_append_epoch = int( + self._payout_ledger_append_invalidation_epoch + ) + if live_append_epoch != effective_append_epoch: + self._abandon_block_candidate( + PRISM_REJECTION_STALE_JOB, + "payout window was invalidated by a late-visible share append", + block_hash=block_hash, + worker=worker, + expected_height=expected_height, + stale_job_class="append_epoch_stale", + ) + return None active_hash = str( self.rpc.call("getblockhash", [expected_height]) ).lower() diff --git a/tests/test_prism_coordinator_vardiff.py b/tests/test_prism_coordinator_vardiff.py index e849fff8..80d7a4c6 100644 --- a/tests/test_prism_coordinator_vardiff.py +++ b/tests/test_prism_coordinator_vardiff.py @@ -7399,13 +7399,15 @@ def test_replayed_block_candidate_lands_when_durable_window_replays_intact( def test_block_submit_aborts_when_append_invalidation_races_the_landing( self, ) -> None: - # An append-side invalidation landing between the advisory epoch - # fence and submitblock must still abort the landing: the - # authoritative fence holds the same lock the bump takes, so the - # bump cannot slip past both. The bump here is driven through the - # REAL invalidation path from the getblockcount hook -- with no - # armed artifact or in-flight walk in the harness, it fires only - # because the landing exposed its own declared anchor. + # Node propagation is the fast lane: the block is offered to qbitd + # before payout accounting notices anything, so an append-side + # invalidation racing the landing can no longer block submitblock. + # It must still abort the ACCOUNTING: the landing's epoch fences + # fail closed before the audit bundle or any payout persistence. + # The bump here is driven through the REAL invalidation path from + # the drain hook -- with no armed artifact or in-flight walk in the + # harness, it fires only because the landing exposed its own + # declared anchor. server, state, _recording = submit_coordinator() ledger = SingleWriterShareLedger() server.ledger = ledger @@ -7422,31 +7424,35 @@ def test_block_submit_aborts_when_append_invalidation_races_the_landing( ) late_append = self._pending_append("late-during-landing").pending_share - class RaceRpc(TipRpc): - def __init__(rpc_self, tip: str) -> None: - super().__init__(tip) - rpc_self.race_fired = False + race_fired: list[bool] = [] + original_drain = server._await_unfenced_appends_predating_anchor + + def racing_drain(anchor_ms: int) -> None: + original_drain(anchor_ms) + if not race_fired: + race_fired.append(True) + server._invalidate_incremental_payout_window_for_append( + late_append + ) + server._await_unfenced_appends_predating_anchor = racing_drain # type: ignore[method-assign] + + submitblock_calls: list[object] = [] + + class RecordingSubmitRpc(TipRpc): def call( rpc_self, method: str, params: list[object] | None = None, ) -> object: if method == "getblockcount": - if not rpc_self.race_fired: - rpc_self.race_fired = True - server._invalidate_incremental_payout_window_for_append( - late_append - ) return 9 if method == "submitblock": - raise AssertionError( - "submitblock must not run after a racing append " - "invalidation" - ) + submitblock_calls.append(params) + return None return super().call(method, params) - server.rpc = RaceRpc("00" * 32) + server.rpc = RecordingSubmitRpc("00" * 32) submission = SimpleNamespace( coinbase_tx_hex="c0ffee", block_hash_hex="da" * 32, @@ -7465,7 +7471,9 @@ def call( server.enqueue_block_candidate(candidate) self.assertTrue(server.submit_next_block_candidate()) - self.assertTrue(server.rpc.race_fired) + self.assertEqual(race_fired, [True]) + # The fast lane offered the block before the race could be observed. + self.assertEqual(submitblock_calls, [["00"]]) with server._job_cache_lock: self.assertEqual(server._payout_ledger_append_invalidation_epoch, 1) self.assertEqual(server.stale_share_count, 0) @@ -7489,16 +7497,28 @@ def test_replayed_candidate_aborts_when_append_races_after_revalidation( ) -> None: # The durable replay rebases a reconstructed candidate onto the live # epoch sequence as of the revalidation read; an epoch advanced - # after that read must still abort the landing at the authoritative - # fence even though the replayed window itself matched. + # after that read must still abort the landing's ACCOUNTING at the + # epoch fence even though the replayed window itself matched. The + # node offer itself is the fast lane and is not gated: the block + # reaches qbitd, but no audit bundle or payout persistence follows. server, state, _recording = submit_coordinator() ledger = SingleWriterShareLedger() ledger.durable_payout_state = True # type: ignore[attr-defined] - ledger.audit_share_window = ( # type: ignore[method-assign] - lambda *, anchor_job_issued_at_ms, network_difficulty: [ - {"share_id": "recorded-window-share"} - ] - ) + + race_fired: list[bool] = [] + + def racing_audit_share_window( + *, anchor_job_issued_at_ms: int, network_difficulty: int + ) -> list[dict[str, object]]: + # The epoch advances only after the revalidation base read, + # i.e. while the replayed-window walk itself is in flight. + if not race_fired: + race_fired.append(True) + with server._job_cache_lock: + server._payout_ledger_append_invalidation_epoch += 1 + return [{"share_id": "recorded-window-share"}] + + ledger.audit_share_window = racing_audit_share_window # type: ignore[method-assign] server.ledger = ledger context = server.jobs["job-1"] context.shares_json = [{"share_id": "recorded-window-share"}] @@ -7513,30 +7533,22 @@ def test_replayed_candidate_aborts_when_append_races_after_revalidation( ) ) - class RaceRpc(TipRpc): - def __init__(rpc_self, tip: str) -> None: - super().__init__(tip) - rpc_self.race_fired = False + submitblock_calls: list[object] = [] + class RecordingSubmitRpc(TipRpc): def call( rpc_self, method: str, params: list[object] | None = None, ) -> object: if method == "getblockcount": - if not rpc_self.race_fired: - rpc_self.race_fired = True - with server._job_cache_lock: - server._payout_ledger_append_invalidation_epoch += 1 return 9 if method == "submitblock": - raise AssertionError( - "submitblock must not run after a racing append " - "invalidation" - ) + submitblock_calls.append(params) + return None return super().call(method, params) - server.rpc = RaceRpc("00" * 32) + server.rpc = RecordingSubmitRpc("00" * 32) submission = SimpleNamespace( coinbase_tx_hex="c0ffee", block_hash_hex="db" * 32, @@ -7556,7 +7568,9 @@ def call( server.enqueue_block_candidate(candidate) self.assertTrue(server.submit_next_block_candidate()) - self.assertTrue(server.rpc.race_fired) + self.assertEqual(race_fired, [True]) + # The fast lane offered the replayed block before revalidation ran. + self.assertEqual(submitblock_calls, [["00"]]) self.assertEqual(server.block_candidate_abandoned_counts[PRISM_REJECTION_STALE_JOB], 1) self.assertEqual( server.stale_job_abandon_counts, @@ -7573,10 +7587,11 @@ def test_landing_blocked_by_fenced_append_aborts_on_bumped_epoch( self, ) -> None: # A replay-shaped append holds the landing fence across the durable - # commit itself, not only across its epoch bump. A landing that - # arrives while that commit is in flight must wait at the fence and + # commit itself, not only across its epoch bump. The node offer is + # the fast lane and does not wait, but a landing whose offer is + # already in must still wait at the fence before ACCOUNTING and # abort on the bumped epoch -- never verify the pre-bump epoch and - # submit a coinbase whose window omits the row that just became + # account a coinbase whose window omits the row that just became # durable. server, state, _recording = submit_coordinator() ledger = SingleWriterShareLedger() @@ -7659,10 +7674,12 @@ def gated_append_batch(entries: list[object]) -> list[object]: daemon=True, ) landing.start() - # Give the landing time to run up against the fence; with the commit - # still gated it must not have entered submitblock. + # Give the landing time to run up against the fence: the fast-lane + # node offer already went out, but with the commit still gated the + # landing must not have reached a terminal accounting decision. time.sleep(0.05) - self.assertEqual(submitblock_calls, []) + self.assertEqual(submitblock_calls, [["00"]]) + self.assertEqual(server.block_candidate_abandoned_counts, {}) release_commit.set() writer.join(timeout=10.0) @@ -7671,8 +7688,9 @@ def gated_append_batch(entries: list[object]) -> list[object]: self.assertFalse(landing.is_alive()) # The bump landed together with the durable append; the landing - # observed it and abandoned instead of submitting. - self.assertEqual(submitblock_calls, []) + # observed it and abandoned its accounting instead of persisting a + # payout window that omits the durable predating share. + self.assertEqual(submitblock_calls, [["00"]]) self.assertIn(late_entry.pending_share.share_id, ledger._share_ids) with server._job_cache_lock: self.assertEqual(server._payout_ledger_append_invalidation_epoch, 1) @@ -7691,16 +7709,17 @@ def gated_append_batch(entries: list[object]) -> list[object]: "payout window was invalidated by a late-visible share append", ) - def test_predating_append_stays_undurable_while_landing_holds_submit_fence( + def test_predating_append_commits_while_fast_lane_offer_is_in_flight( self, ) -> None: - # The other side of the fence boundary: while a landing holds the - # fence across submitblock, a predating append's durable commit -- - # not only its epoch bump -- must wait for the RPC to return. The - # old ordering let the row become durable mid-RPC while its bump - # queued behind the fence, so the authoritative epoch check could - # not observe the invalidation and the coinbase entered qbitd - # underpaying a durable share no refresh wave can unsubmit. + # The other side of the fence boundary flipped with the node fast + # lane: submitblock no longer holds the landing fence, so a + # predating append's durable commit does NOT wait for the RPC to + # return. The row may become durable mid-offer with its epoch bump + # landing under the fence; the landing's post-offer accounting + # fences (not the offer itself) are what observe the invalidation. + # Here the node rejects the block outright, so the rejection -- not + # the epoch race -- terminally abandons the candidate. server, state, _recording = submit_coordinator() ledger = SingleWriterShareLedger() server.ledger = ledger @@ -7765,9 +7784,9 @@ def call( self.assertTrue(server.submit_next_block_candidate()) - # The append could not make the row durable while the fence-guarded - # RPC was in flight; it committed and bumped only afterwards. - self.assertEqual(durable_mid_rpc, [False]) + # The fast-lane RPC holds no fence, so the predating row became + # durable while the offer was still in flight. + self.assertEqual(durable_mid_rpc, [True]) self.assertTrue(append_threads) append_threads[0].join(timeout=10.0) self.assertFalse(append_threads[0].is_alive()) @@ -7882,9 +7901,10 @@ def call( server._payout_unfenced_append_inflight_stamps, {} ) # The drained append's bump landed before the landing's epoch - # fences, so the candidate was abandoned instead of entering - # submitblock with a coinbase omitting the durable predating share. - self.assertEqual(submitblock_calls, []) + # fences, so the accounting was abandoned instead of persisting a + # payout window omitting the durable predating share. The node + # offer itself is the fast lane and had already gone out. + self.assertEqual(submitblock_calls, [["00"]]) self.assertEqual( server.block_candidate_abandoned_counts[PRISM_REJECTION_STALE_JOB], 1, @@ -7990,9 +8010,10 @@ def call( self.assertTrue(server.submit_next_block_candidate()) # The bump already happened at commit time, so the landing's epoch - # fence rejects the pre-append window instead of submitting a - # coinbase that omits the durable predating share. - self.assertEqual(submitblock_calls, []) + # fence rejects the pre-append window instead of accounting a + # coinbase that omits the durable predating share. The node offer + # itself is the fast lane and had already gone out. + self.assertEqual(submitblock_calls, [["00"]]) self.assertEqual( server.block_candidate_abandoned_counts[PRISM_REJECTION_STALE_JOB], 1, From 9892e6ceb3748872d4ebe496f41c2e5708855b42 Mon Sep 17 00:00:00 2001 From: Dan Hepworth Date: Wed, 12 Aug 2026 13:45:47 -0400 Subject: [PATCH 08/10] Defer accounting-lane retry backoff instead of sleeping under admission MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A retryable candidate failure inside the block_accounting task (for example an attempt-marker statement timeout) slept out the exponential backoff while still holding accepted_block_handling writer admission and the disposition lease. That stalled every queued accounting task and kept an armed payout barrier blocking balance mutation for up to the 30s backoff cap — the exact convoy this branch exists to prevent, in its target saturation conditions. Record a per-hash not-before deadline instead (same escalation state) and honor it at both dequeue sites. The submitter-thread path keeps its existing heartbeating backoff wait, and replay_pending_block_candidates already short-circuits while the retained candidate occupies the retry slot, so a parked candidate adds no outbox churn during its backoff. Co-Authored-By: Claude Fable 5 --- lab/prism/prism_coordinator.py | 93 ++++++++++++++++++++++--- tests/test_prism_coordinator_vardiff.py | 70 +++++++++++++++++++ 2 files changed, 155 insertions(+), 8 deletions(-) diff --git a/lab/prism/prism_coordinator.py b/lab/prism/prism_coordinator.py index 81d46899..51692248 100644 --- a/lab/prism/prism_coordinator.py +++ b/lab/prism/prism_coordinator.py @@ -24637,6 +24637,13 @@ def submit_next_block_candidate( self._record_block_submitter_phase("dequeue-retry") with self.lock: candidate = getattr(self, "_retry_block_candidate", None) + if candidate is not None and not self._block_candidate_retry_ready_locked( + candidate + ): + # Parked by _pace_block_candidate_retry: honor the backoff + # deadline without sleeping on the submitter or accounting + # lane. + candidate = None if candidate is not None: self._retry_block_candidate = None if candidate is None: @@ -24665,9 +24672,16 @@ def submit_next_block_candidate( self._ensure_block_candidate_disposition_state() with self.lock: waiting = self._block_disposition_waiting_retries - if waiting: + ready_hashes = [ + key + for key in waiting + if self._block_candidate_retry_ready_locked( + waiting[key] + ) + ] + if ready_hashes: waiting_hash = min( - waiting, + ready_hashes, key=lambda key: int( waiting[key].context.template["height"] ), @@ -24912,9 +24926,7 @@ def _submit_next_block_candidate_writer( ) traceback.print_exc() self._retain_block_candidate_for_retry(candidate) - self._wait_for_block_candidate_retry( - self._next_block_candidate_retry_delay(block_hash) - ) + self._pace_block_candidate_retry(block_hash) return True accepted = False error = "candidate became stale or submission failed" @@ -24965,9 +24977,7 @@ def _submit_next_block_candidate_writer( flush=True, ) self._retain_block_candidate_for_retry(candidate) - self._wait_for_block_candidate_retry( - self._next_block_candidate_retry_delay(block_hash) - ) + self._pace_block_candidate_retry(block_hash) return True if not accepted: try: @@ -25252,11 +25262,78 @@ def _next_block_candidate_retry_delay(self, block_hash: str) -> float: delays[block_hash] = min(maximum, max(initial, delay * 2)) return min(delay, maximum) + def _pace_block_candidate_retry(self, block_hash: str) -> None: + """Apply per-candidate retry backoff without convoying accounting. + + On the block_accounting thread the disposition lease and writer + admission stay held until the accounting task's finally clause, so + sleeping here would stall every queued accounting task and keep an + armed payout barrier blocking balance mutation for the whole backoff + window. Record a not-before deadline instead; the dequeue path honors + it, and replay_pending_block_candidates already short-circuits while + the retained candidate occupies the retry slot. + """ + delay_seconds = self._next_block_candidate_retry_delay(block_hash) + accounting_owner = ( + threading.get_ident() + == getattr(self, "_block_accounting_thread_ident", None) + and bool( + getattr( + self, + "_block_accounting_holds_disposition", + False, + ) + ) + ) + if not accounting_owner: + self._wait_for_block_candidate_retry(delay_seconds) + return + with self.lock: + not_before = getattr( + self, + "_block_candidate_retry_not_before", + None, + ) + if not_before is None: + not_before = {} + self._block_candidate_retry_not_before = not_before + not_before[str(block_hash).lower()] = ( + time.monotonic() + delay_seconds + ) + + def _block_candidate_retry_ready_locked( + self, + candidate: PrismBlockCandidate, + ) -> bool: + """Return whether a parked retry's backoff deadline has passed. + + Caller holds self.lock. A ready entry is dropped so a candidate that + later lands terminally leaves no stale pacing behind. + """ + not_before = getattr(self, "_block_candidate_retry_not_before", None) + if not not_before: + return True + block_hash = str(candidate.submission.block_hash_hex).lower() + deadline = not_before.get(block_hash) + if deadline is None: + return True + if time.monotonic() < deadline: + return False + not_before.pop(block_hash, None) + return True + def _clear_block_candidate_retry_state(self, block_hash: str) -> None: with self.lock: delays = getattr(self, "block_candidate_retry_delays", None) if delays is not None: delays.pop(block_hash, None) + not_before = getattr( + self, + "_block_candidate_retry_not_before", + None, + ) + if not_before is not None: + not_before.pop(block_hash, None) def _defer_block_candidate(self, reason: str, message: str, *, worker: str | None) -> None: """Record a retryable outcome without counting a terminal abandonment.""" diff --git a/tests/test_prism_coordinator_vardiff.py b/tests/test_prism_coordinator_vardiff.py index 80d7a4c6..c6e7f98b 100644 --- a/tests/test_prism_coordinator_vardiff.py +++ b/tests/test_prism_coordinator_vardiff.py @@ -12064,6 +12064,76 @@ def call( release_mark.set() self.assertFalse(submitter.is_alive()) + def test_accounting_retry_backoff_defers_instead_of_sleeping_under_admission(self) -> None: + server, state, _recording = submit_coordinator() + server.block_candidate_retry_initial_seconds = 30.0 + server.block_candidate_retry_max_seconds = 30.0 + + class FailingMarkLedger(RecordingLedger): + def mark_block_candidate_attempted(self, *, block_hash: str) -> bool: + raise RuntimeError("attempt marker unavailable") + + server.ledger = FailingMarkLedger() + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="00", + block_hash_hex="ab" * 32, + block_hex="ab", + share_pass=True, + block_pass=True, + ), + ) + block_hash = "ab" * 32 + server._block_accounting_thread_ident = threading.get_ident() + server._block_accounting_holds_disposition = True + started = time.monotonic() + with patch("builtins.print"): + handled = server._submit_next_block_candidate_writer( + candidate, + node_submission=SimpleNamespace(), + disposition_held=True, + ) + elapsed = time.monotonic() - started + self.assertTrue(handled) + # The 30s backoff must be recorded as a deadline, never slept while + # the accounting thread holds admission and the disposition lease. + self.assertLess(elapsed, 10.0) + self.assertIs( + getattr(server, "_block_accounting_deferred_retry_candidate", None), + candidate, + ) + with server.lock: + deadline = server._block_candidate_retry_not_before.get(block_hash) + self.assertIsNotNone(deadline) + self.assertGreater(deadline, time.monotonic()) + + # After the lease releases, the deferred candidate parks in the retry + # slot and the dequeue honors the backoff deadline. + server._block_accounting_holds_disposition = False + with server.lock: + server._block_accounting_deferred_retry_candidate = None + server._merge_block_candidate_retry_locked( + "_retry_block_candidate", + candidate, + ) + with patch("builtins.print"): + self.assertFalse( + server.submit_next_block_candidate(defer_accounting=True) + ) + self.assertIs(getattr(server, "_retry_block_candidate", None), candidate) + + # Once the deadline passes the same candidate dequeues again. + with server.lock: + server._block_candidate_retry_not_before[block_hash] = ( + time.monotonic() - 1.0 + ) + with patch("builtins.print"): + self.assertTrue( + server.submit_next_block_candidate(defer_accounting=True) + ) + def test_accounting_saturation_does_not_convoy_node_offers(self) -> None: server, state, _recording = submit_coordinator() server.max_blocks = 10 From 5a563ca4c0faf38d324ff78175bbed075bb75491 Mon Sep 17 00:00:00 2001 From: Dan Hepworth Date: Wed, 12 Aug 2026 14:18:39 -0400 Subject: [PATCH 09/10] Carry definitive node acceptances across in-process retries and bound the accounting queue MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A successful submitblock followed by a retryable failure (for example an attempt-marker statement timeout) dropped the fresh node result, so the in-process retry re-offered and read "duplicate" — classifying against the moved live tip and leaning on chain probes that may be unavailable under the same saturation, which could terminally abandon a block the node had already accepted. Retention now stashes a definitive acceptance and every offer site reuses it instead of re-asking the node, rerunning the landing tail exactly as if the first pass had continued past the failure. Ambiguous or rejected offers are never reused, and a process crash still converges through the durable replay path. Separately, the primary accounting handoff queue was constructed unbounded, so the documented result-preserving spillover ordering could never engage in production. It is now bounded (default depth 8, attribute-overridable); the overflow queue stays unbounded by design. Co-Authored-By: Claude Fable 5 --- lab/prism/prism_coordinator.py | 125 +++++++++++++++++++-- tests/test_prism_coordinator_vardiff.py | 141 +++++++++++++++++++++++- 2 files changed, 257 insertions(+), 9 deletions(-) diff --git a/lab/prism/prism_coordinator.py b/lab/prism/prism_coordinator.py index 51692248..9b5eddb2 100644 --- a/lab/prism/prism_coordinator.py +++ b/lab/prism/prism_coordinator.py @@ -465,6 +465,11 @@ def validate_payout_artifact_age_bounds( ) DEFAULT_BLOCK_CANDIDATE_RETRY_INITIAL_SECONDS = 0.25 DEFAULT_BLOCK_CANDIDATE_RETRY_MAX_SECONDS = 30.0 +# The primary accounting handoff queue must be bounded or the documented +# result-preserving spillover ordering can never engage; the overflow queue +# stays unbounded by design so an already-offered block is never converted +# back into a raw-submit retry. +DEFAULT_BLOCK_ACCOUNTING_QUEUE_DEPTH = 8 # The node fast lane is intentionally shorter than the normal ten-second RPC # budget: an ambiguous timeout leaves the durable outbox pending and replay # safely submits the same hash again. @@ -23939,6 +23944,26 @@ def _node_submission_for_candidate( return _BlockCandidateNodeSubmission(attempted=False) return self._submit_block_candidate_to_node(candidate) + def _node_submission_for_candidate_or_retained( + self, + candidate: PrismBlockCandidate, + ) -> _BlockCandidateNodeSubmission: + """Reuse a retained definitive acceptance instead of re-offering. + + An in-process retry of a candidate whose earlier offer already + returned success must not ask the node again: the re-offer answers + "duplicate", which downgrades the classification to the moved live + tip and leans on chain probes that may be unavailable under the + same saturation that caused the retry. The stashed result reruns + the landing tail as if the first pass had continued. + """ + retained = self._pop_retained_block_candidate_node_submission( + str(candidate.submission.block_hash_hex) + ) + if retained is not None: + return retained + return self._node_submission_for_candidate(candidate) + def _node_submission_for_direct_candidate( self, candidate: PrismBlockCandidate, @@ -24027,7 +24052,7 @@ def _submit_synchronous_block_candidate( raise RuntimeError( "block candidate is waiting for fast-lane capacity" ) - node_submission = self._node_submission_for_candidate(candidate) + node_submission = self._node_submission_for_candidate_or_retained(candidate) self._mark_block_candidate_attempted(block_hash) with self._block_submitter_ledger_statement_timeout_scope(): production_submit = ( @@ -24311,7 +24336,17 @@ def _ensure_block_accounting_state(self) -> None: if not hasattr(self, "_block_accounting_state_lock"): self._block_accounting_state_lock = threading.Lock() if not hasattr(self, "_block_accounting_queue"): - self._block_accounting_queue = queue.PriorityQueue() + depth = max( + 1, + int( + getattr( + self, + "block_accounting_queue_depth", + DEFAULT_BLOCK_ACCOUNTING_QUEUE_DEPTH, + ) + ), + ) + self._block_accounting_queue = queue.PriorityQueue(maxsize=depth) if not hasattr(self, "_block_accounting_overflow_queue"): self._block_accounting_overflow_queue = queue.PriorityQueue() if not hasattr(self, "_block_accounting_sequence"): @@ -24561,6 +24596,10 @@ def block_accounting_loop(self) -> None: flush=True, ) traceback.print_exc() + self._stash_retained_block_candidate_node_submission( + str(task.candidate.submission.block_hash_hex), + task.node_submission, + ) self._retain_block_candidate_for_retry(task.candidate) finally: assert source_queue is not None @@ -24782,7 +24821,7 @@ def submit_next_block_candidate( return True else: try: - node_submission = self._node_submission_for_candidate(candidate) + node_submission = self._node_submission_for_candidate_or_retained(candidate) except BaseException: try: self._retain_block_candidate_for_retry(candidate) @@ -24791,7 +24830,7 @@ def submit_next_block_candidate( raise else: try: - node_submission = self._node_submission_for_candidate(candidate) + node_submission = self._node_submission_for_candidate_or_retained(candidate) except BaseException: try: self._retain_block_candidate_for_retry(candidate) @@ -24881,8 +24920,10 @@ def _submit_next_block_candidate_writer( if terminal_outcome is not None: return terminal_outcome if node_submission is None: - node_submission = self._node_submission_for_candidate( - candidate + node_submission = ( + self._node_submission_for_candidate_or_retained( + candidate + ) ) return self._submit_next_block_candidate_writer( candidate, @@ -24915,7 +24956,7 @@ def _submit_next_block_candidate_writer( outcome=outcome, ) if node_submission is None: - node_submission = self._node_submission_for_candidate(candidate) + node_submission = self._node_submission_for_candidate_or_retained(candidate) try: self._mark_block_candidate_attempted(block_hash) except Exception: @@ -24925,6 +24966,10 @@ def _submit_next_block_candidate_writer( flush=True, ) traceback.print_exc() + self._stash_retained_block_candidate_node_submission( + block_hash, + node_submission, + ) self._retain_block_candidate_for_retry(candidate) self._pace_block_candidate_retry(block_hash) return True @@ -24976,6 +25021,10 @@ def _submit_next_block_candidate_writer( f"hash={block_hash} reason={abandon_reason or 'exception'}", flush=True, ) + self._stash_retained_block_candidate_node_submission( + block_hash, + node_submission, + ) self._retain_block_candidate_for_retry(candidate) self._pace_block_candidate_retry(block_hash) return True @@ -25322,6 +25371,56 @@ def _block_candidate_retry_ready_locked( not_before.pop(block_hash, None) return True + def _stash_retained_block_candidate_node_submission( + self, + block_hash: str, + node_submission: _BlockCandidateNodeSubmission | None, + ) -> None: + """Carry a definitive node acceptance across an in-process retry. + + A fast-lane offer that returned success can be followed by a + retryable failure (for example an attempt-marker statement timeout). + Re-offering on the retry would come back "duplicate", which + classifies against the moved live tip and can only rescue the block + through chain probes that may be unavailable under the same + saturation. The acceptance is already known, so retain it with the + candidate; the retry reruns the landing tail exactly as if the + first pass had continued. + """ + if node_submission is None or not node_submission.attempted: + return + if ( + node_submission.error is not None + or node_submission.result is not None + ): + # Only a definitive success is safe to reuse: an ambiguous or + # rejected offer must be re-offered so the node can resolve it. + return + with self.lock: + retained = getattr( + self, + "_block_candidate_retained_node_submissions", + None, + ) + if retained is None: + retained = {} + self._block_candidate_retained_node_submissions = retained + retained[str(block_hash).lower()] = node_submission + + def _pop_retained_block_candidate_node_submission( + self, + block_hash: str, + ) -> _BlockCandidateNodeSubmission | None: + with self.lock: + retained = getattr( + self, + "_block_candidate_retained_node_submissions", + None, + ) + if not retained: + return None + return retained.pop(str(block_hash).lower(), None) + def _clear_block_candidate_retry_state(self, block_hash: str) -> None: with self.lock: delays = getattr(self, "block_candidate_retry_delays", None) @@ -25334,6 +25433,13 @@ def _clear_block_candidate_retry_state(self, block_hash: str) -> None: ) if not_before is not None: not_before.pop(block_hash, None) + retained = getattr( + self, + "_block_candidate_retained_node_submissions", + None, + ) + if retained is not None: + retained.pop(str(block_hash).lower(), None) def _defer_block_candidate(self, reason: str, message: str, *, worker: str | None) -> None: """Record a retryable outcome without counting a terminal abandonment.""" @@ -26692,7 +26798,10 @@ def _submit_block_candidate_serialized( # against the candidate's stamped parent. A later getblockhash check # proves a successful acknowledgement, while an ambiguous transport # outcome stays pending for duplicate-safe replay. Duplicate replies - # are replay evidence and retain the live-tip classification. + # are replay evidence and retain the live-tip classification; the + # abandonment tie-breaker separately consults this process's own + # recorded offer evidence so an unprovable chain view cannot + # terminally discard a block the node already told us it has. fresh_or_uncertain_submit = bool( node_submission.attempted and ( diff --git a/tests/test_prism_coordinator_vardiff.py b/tests/test_prism_coordinator_vardiff.py index c6e7f98b..02446e4e 100644 --- a/tests/test_prism_coordinator_vardiff.py +++ b/tests/test_prism_coordinator_vardiff.py @@ -12092,7 +12092,11 @@ def mark_block_candidate_attempted(self, *, block_hash: str) -> bool: with patch("builtins.print"): handled = server._submit_next_block_candidate_writer( candidate, - node_submission=SimpleNamespace(), + node_submission=SimpleNamespace( + attempted=False, + result=None, + error=None, + ), disposition_held=True, ) elapsed = time.monotonic() - started @@ -12134,6 +12138,141 @@ def mark_block_candidate_attempted(self, *, block_hash: str) -> bool: server.submit_next_block_candidate(defer_accounting=True) ) + def test_live_retry_reuses_definitive_node_acceptance_without_reoffer(self) -> None: + parent_hash = "00" * 32 + block_hash = "ce" * 32 + moved_tip = "11" * 32 + ledger = SingleWriterShareLedger() + server, state, _recording = submit_coordinator(tip=parent_hash) + server.ledger = ledger + server.stop_after_block = False + server.max_blocks = 10 + server.block_candidate_retry_initial_seconds = 0.0 + server.block_candidate_retry_max_seconds = 0.0 + from lab.prism.share_ledger import PendingShare + + pending = PendingShare( + share_id="miner-a:live-retry-duplicate", + miner_id="miner-a", + order_key="miner-a", + p2mr_program_hex="11" * 32, + share_difficulty=1, + network_difficulty=1, + template_height=10, + job_id="job-1", + job_issued_at_ms=1, + accepted_at_ms=2, + ntime=1_700_000_000, + ) + candidate = block_candidate( + server, + state, + SimpleNamespace( + coinbase_tx_hex="c0ffee", + block_hash_hex=block_hash, + block_hex="00", + share_pass=True, + block_pass=True, + ), + pending_share=pending, + ) + intent = server.block_candidate_intent(candidate) + ledger.append_batch([(pending, intent)]) + + expected_height = int(candidate.context.template["height"]) + header_state = {"confirmations": -1} + + class MovedTipRpc(FakeRpc): + def __init__(self) -> None: + self.submit_results: list[object] = [] + + def call( + self, + method: str, + params: list[object] | None = None, + *, + timeout: float | None = None, + ) -> object: + if method == "submitblock": + result = None if not self.submit_results else "duplicate" + self.submit_results.append(result) + return result + if method == "getbestblockhash": + # The chain advances as soon as the first offer lands, so + # the in-process retry observes a moved tip. + return parent_hash if not self.submit_results else moved_tip + if method == "getblockhash": + return block_hash + if method == "getblockcount": + return 9 + if method == "getblockheader": + # Unprovable during the tip race (found, not yet active), + # then settled and active for the final pass. + return { + "height": expected_height, + "confirmations": header_state["confirmations"], + } + return super().call(method, params) + + rpc = MovedTipRpc() + server.rpc = rpc + original_mark = ledger.mark_block_candidate_attempted + mark_state = {"failed_once": False} + + def flaky_mark(*, block_hash: str) -> bool: + # Fail exactly once, on the first attempt marker after the fresh + # node offer, mirroring a statement timeout under saturation. + if len(rpc.submit_results) == 1 and not mark_state["failed_once"]: + mark_state["failed_once"] = True + raise RuntimeError("attempt marker timed out") + return original_mark(block_hash=block_hash) + + ledger.mark_block_candidate_attempted = flaky_mark # type: ignore[method-assign] + server.enqueue_block_candidate(candidate) + with tempfile.TemporaryDirectory() as tempdir: + server.audit_dir = Path(tempdir) + server.evidence_path = Path(tempdir) / "evidence.json" + server.ledger_writer_public_key_hex = "aa" * 32 + server.build_audit_bundle = ( # type: ignore[method-assign] + lambda **_kwargs: verified_block_bundle() + ) + server.verify_bundle = ( # type: ignore[method-assign] + lambda *_args, **_kwargs: verified_audit_report() + ) + with patch("builtins.print"): + # First pass: fresh accept from the node, then the attempt + # marker fails and the candidate is retained for an + # in-process retry carrying the definitive node result. + self.assertTrue(server.submit_next_block_candidate()) + self.assertEqual(rpc.submit_results, [None]) + self.assertEqual( + ledger._block_candidate_outbox[block_hash]["state"], + "pending", + ) + # Retry: the stashed acceptance is reused, so the node is + # never asked again (no "duplicate" classification, no chain + # probe reliance) and the landing tail finalizes exactly as + # if the first pass had continued past the marker failure. + self.assertTrue(server.submit_next_block_candidate()) + self.assertEqual(rpc.submit_results, [None]) + self.assertEqual( + ledger._block_candidate_outbox[block_hash]["state"], + "submitted", + ) + self.assertNotIn( + PRISM_REJECTION_STALE_JOB, + getattr(server, "block_candidate_abandoned_counts", {}), + ) + self.assertEqual(server.accepted_block_count, 1) + + def test_block_accounting_primary_queue_is_bounded_by_default(self) -> None: + server, _state, _recording = submit_coordinator() + server._ensure_block_accounting_state() + # A bounded primary is what makes the documented result-preserving + # spillover ordering reachable; the overflow queue stays unbounded. + self.assertEqual(server._block_accounting_queue.maxsize, 8) + self.assertEqual(server._block_accounting_overflow_queue.maxsize, 0) + def test_accounting_saturation_does_not_convoy_node_offers(self) -> None: server, state, _recording = submit_coordinator() server.max_blocks = 10 From 431c708f571f29b936876ffe4f003dcf3e997aa0 Mon Sep 17 00:00:00 2001 From: Dan Hepworth Date: Wed, 12 Aug 2026 14:26:30 -0400 Subject: [PATCH 10/10] Record retained node acceptances at the offer itself MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The stash for definitive submitblock successes was written only at three retention sites, so retention paths that did not stash (the defer-accounting handoff failures among them) dropped a popped result on the floor, and even covered paths consumed the stash on a retry that then failed again — both re-opening the duplicate-reclassification hazard the stash exists to prevent. Record the entry once, in the universal post-offer hook, read it without consuming, and clear it only when the candidate reaches a terminal outcome. Every present and future retention path is covered without having to remember, and repeated retryable failures keep reusing the same known acceptance. The regression test now fails the attempt marker twice to pin survival across a consumed-and-failed retry. Co-Authored-By: Claude Fable 5 --- lab/prism/prism_coordinator.py | 44 +++++++++++-------------- tests/test_prism_coordinator_vardiff.py | 29 +++++++++++----- 2 files changed, 39 insertions(+), 34 deletions(-) diff --git a/lab/prism/prism_coordinator.py b/lab/prism/prism_coordinator.py index 9b5eddb2..9d4b09b6 100644 --- a/lab/prism/prism_coordinator.py +++ b/lab/prism/prism_coordinator.py @@ -23857,6 +23857,10 @@ def _arm_block_candidate_after_node_offer( node_submission: _BlockCandidateNodeSubmission, ) -> None: """Fence child payout work as soon as node acceptance is possible.""" + self._stash_retained_block_candidate_node_submission( + str(candidate.submission.block_hash_hex), + node_submission, + ) ambiguous_or_landed = ( node_submission.error is not None or node_submission.result in (None, "duplicate") @@ -23957,7 +23961,7 @@ def _node_submission_for_candidate_or_retained( same saturation that caused the retry. The stashed result reruns the landing tail as if the first pass had continued. """ - retained = self._pop_retained_block_candidate_node_submission( + retained = self._retained_block_candidate_node_submission( str(candidate.submission.block_hash_hex) ) if retained is not None: @@ -24596,10 +24600,6 @@ def block_accounting_loop(self) -> None: flush=True, ) traceback.print_exc() - self._stash_retained_block_candidate_node_submission( - str(task.candidate.submission.block_hash_hex), - task.node_submission, - ) self._retain_block_candidate_for_retry(task.candidate) finally: assert source_queue is not None @@ -24966,10 +24966,6 @@ def _submit_next_block_candidate_writer( flush=True, ) traceback.print_exc() - self._stash_retained_block_candidate_node_submission( - block_hash, - node_submission, - ) self._retain_block_candidate_for_retry(candidate) self._pace_block_candidate_retry(block_hash) return True @@ -25021,10 +25017,6 @@ def _submit_next_block_candidate_writer( f"hash={block_hash} reason={abandon_reason or 'exception'}", flush=True, ) - self._stash_retained_block_candidate_node_submission( - block_hash, - node_submission, - ) self._retain_block_candidate_for_retry(candidate) self._pace_block_candidate_retry(block_hash) return True @@ -25376,16 +25368,18 @@ def _stash_retained_block_candidate_node_submission( block_hash: str, node_submission: _BlockCandidateNodeSubmission | None, ) -> None: - """Carry a definitive node acceptance across an in-process retry. - - A fast-lane offer that returned success can be followed by a - retryable failure (for example an attempt-marker statement timeout). - Re-offering on the retry would come back "duplicate", which - classifies against the moved live tip and can only rescue the block - through chain probes that may be unavailable under the same - saturation. The acceptance is already known, so retain it with the - candidate; the retry reruns the landing tail exactly as if the - first pass had continued. + """Record a definitive node acceptance for in-process retries. + + Recorded at the offer itself (the universal post-offer hook) so + every retention path — writer failures, defer-accounting handoff + failures, the accounting loop — is covered without each site having + to remember. A retryable failure after a successful offer would + otherwise re-offer on retry and read "duplicate", which classifies + against the moved live tip and can only rescue the block through + chain probes that may be unavailable under the same saturation. + The entry is read without consuming and lives until the candidate + reaches a terminal outcome, so repeated retryable failures keep + reusing the same known acceptance. """ if node_submission is None or not node_submission.attempted: return @@ -25407,7 +25401,7 @@ def _stash_retained_block_candidate_node_submission( self._block_candidate_retained_node_submissions = retained retained[str(block_hash).lower()] = node_submission - def _pop_retained_block_candidate_node_submission( + def _retained_block_candidate_node_submission( self, block_hash: str, ) -> _BlockCandidateNodeSubmission | None: @@ -25419,7 +25413,7 @@ def _pop_retained_block_candidate_node_submission( ) if not retained: return None - return retained.pop(str(block_hash).lower(), None) + return retained.get(str(block_hash).lower()) def _clear_block_candidate_retry_state(self, block_hash: str) -> None: with self.lock: diff --git a/tests/test_prism_coordinator_vardiff.py b/tests/test_prism_coordinator_vardiff.py index 02446e4e..ff49cbbe 100644 --- a/tests/test_prism_coordinator_vardiff.py +++ b/tests/test_prism_coordinator_vardiff.py @@ -12217,13 +12217,15 @@ def call( rpc = MovedTipRpc() server.rpc = rpc original_mark = ledger.mark_block_candidate_attempted - mark_state = {"failed_once": False} + mark_state = {"failures": 0} def flaky_mark(*, block_hash: str) -> bool: - # Fail exactly once, on the first attempt marker after the fresh - # node offer, mirroring a statement timeout under saturation. - if len(rpc.submit_results) == 1 and not mark_state["failed_once"]: - mark_state["failed_once"] = True + # Fail twice, starting at the first attempt marker after the + # fresh node offer, mirroring statement timeouts under sustained + # saturation. The retained acceptance must survive the failed + # retry too, not just the first failure. + if len(rpc.submit_results) == 1 and mark_state["failures"] < 2: + mark_state["failures"] += 1 raise RuntimeError("attempt marker timed out") return original_mark(block_hash=block_hash) @@ -12249,10 +12251,19 @@ def flaky_mark(*, block_hash: str) -> bool: ledger._block_candidate_outbox[block_hash]["state"], "pending", ) - # Retry: the stashed acceptance is reused, so the node is - # never asked again (no "duplicate" classification, no chain - # probe reliance) and the landing tail finalizes exactly as - # if the first pass had continued past the marker failure. + # Retry 1 fails the marker again: the retained acceptance + # must survive a consumed-and-failed retry, not just the + # first failure. + self.assertTrue(server.submit_next_block_candidate()) + self.assertEqual(rpc.submit_results, [None]) + self.assertEqual( + ledger._block_candidate_outbox[block_hash]["state"], + "pending", + ) + # Retry 2: the stashed acceptance is still reused, so the + # node is never asked again (no "duplicate" classification, + # no chain probe reliance) and the landing tail finalizes + # exactly as if the first pass had continued. self.assertTrue(server.submit_next_block_candidate()) self.assertEqual(rpc.submit_results, [None]) self.assertEqual(