Fix pathological migration scan that stalled WIREBIND identity attach
Root cause (found by a fresh subagent after an extended live-debugging investigation into "identity 00 attaches slowly/stalls when Zuse never attached first this boot"): blk_migration_idle_check() was generalized earlier today to walk every attached device slot uniformly instead of hardcoding first_disk_slot() (Artemis's own disk). But its per-slot scan can only early-exit once it finds a devblock that is BOTH "hot" (claimed and worn) AND "free" -- and a just-attached, never-claimed USB identity drive can never satisfy the "hot" half by design (claiming only ever happens via blk_firsttouch_claim(), which only ever targets first_disk_slot()). So the scan ran to completion -- the drive's entire ~16,000 devblocks, mostly cache misses over slow emulated USB/BOT -- every single idle tick, forever, blocking sk_repl_idle() (and therefore the console and the storage-attach message round-trip) each time. Fix, in src/block_subsystem.c: a new has_ever_claimed flag on blk_dev_slot_t (set in blk_set_meta(), the single choke point every BLK_FLAG_CLAIMED transition passes through) skips the scan entirely, O(1), for any slot nothing has ever claimed -- the common case for a freshly-attached drive. A new migration_scan_lbn resume cursor bounds *any* slot's per-tick cost to MIGRATION_SCAN_BUDGET (256) devblocks examined, picking up where the previous tick left off instead of restarting from start_lbn every time -- restores this function's own documented "coarse cadence, cheap early-exit" design intent for every device, not just the one it used to hardcode. Also along the way (kept, all real improvements, verified live): - src/starkernel/usb/xhci.c: xhci_wait_bit()/xhci_bot_wait_for_idle() had zero yield hints in their MMIO-polling loops; added arch_relax() to both (matches virtio_blk.c below) -- a tight loop of nothing but MMIO reads can starve TCG's own host-side timer injection under QEMU. - src/starkernel/virtio/virtio_blk.c: vblk_io()'s spin bound was 33M iterations with zero logging on timeout; a single real (still not fully root-caused) timeout cost 31+ minutes of CPU before this was caught. Reduced to 1M and added a log line naming the failing sector, turning a silent, effectively-unbounded stall into a fast, loud failure -- callers already tolerate BLKIO_EIO. - src/starkernel/repl.c: blk_migration_idle_check() deferred for any idle tick where a storage-attach message round-trip is still pending, to keep the two block-subsystem-touching paths from interleaving; the existing MSG-TICK pump now checks the target VM's own dictionary for MSG-TICK (vm_find_word + acl_allow) before VM-EXECing into it, instead of spamming "VM-EXEC: ERROR" every tick for a VM that doesn't have -- or isn't allowed -- the word (e.g. a FORTH-79/83-locked-down identity); fixed a real -Wunused-variable build break in the EMERGENCY_CONSOLE_ ENABLED=1 path (unused today, but needed live to reproduce this bug with no identity attached at all). - src/starkernel/capsule/capsule_mint.c: dropped the dead S" common:messaging.4th" EXEC / MSG-CD-INIT lines from MINT_RESTRICTED_PERSONALITY -- a FORTH-79/83-locked-down identity has no legitimate use for a messaging vocabulary it can never call. Status: the pathological CPU-climbing scan is confirmed fixed (verified live: CPU stays flat across an extended run instead of climbing without bound). The WIREBIND storage-attach message round-trip still does not complete promptly in the "Zuse never attached, other identity attaches first" scenario -- a separate, still-open issue in the message-delivery path itself, not the scan. Tracked as follow-on work. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_014Ec88YKxxhZGG1RNnune78
This commit is contained in:
Robert Allan James
co-authored by
Claude Sonnet 5
Claude Sonnet 5
parent
63b8b3bc29
commit
1a263555e2
@@ -67,8 +67,6 @@ static const char MINT_DEFAULT_PERSONALITY[] =
|
||||
* use of EXEC this VM will ever get. */
|
||||
static const char MINT_RESTRICTED_PERSONALITY[] =
|
||||
"Block 4998\n"
|
||||
"S\" common:messaging.4th\" EXEC\n"
|
||||
"MSG-CD-INIT\n"
|
||||
"S\" acl-std79.4th\" EXEC\n"
|
||||
"ACL-LOCKDOWN-STD79\n"
|
||||
": WELCOME ( -- ) .\" Minted identity -- FORTH-79/83 standard words only\" CR ;\n"
|
||||
|
||||
+46
-2
@@ -522,8 +522,28 @@ static void sk_repl_idle(VM *active_vm)
|
||||
* rather than only on a failed write). See block_subsystem.c's own
|
||||
* doc comment on blk_migration_idle_check() for what's built (heat-
|
||||
* based relocation) vs. deliberately left open (overflow-triggered
|
||||
* migration, needs a call site threaded from WIREBIND). */
|
||||
blk_migration_idle_check();
|
||||
* migration, needs a call site threaded from WIREBIND).
|
||||
*
|
||||
* FABRIC-3.md, 2026-09-09: skipped while any g_blk_attach_pending
|
||||
* entry is still pending -- this scan and the storage-attach message
|
||||
* round-trip (HERA-BLK-ATTACH-REQ/BLK-ATTACH-ACK) both touch the
|
||||
* block subsystem/Artemis's own virtio-backed storage, and live-
|
||||
* caught the two interleaving is where a real vblk_io() request stops
|
||||
* getting a used-ring completion (root cause not fully isolated, see
|
||||
* virtio_blk.c's own doc comment on vblk_io()'s reduced spin bound --
|
||||
* that's the safety net; this is the actual avoidance). One deferred
|
||||
* scan is harmless -- next idle tick retries, same as any other tick
|
||||
* with nothing to do. */
|
||||
{
|
||||
int attach_in_flight = 0;
|
||||
if (g_blk_attach_pending) {
|
||||
uint32_t pi;
|
||||
for (pi = 0; pi < g_usb_blk_dev_slot_count; pi++) {
|
||||
if (g_blk_attach_pending[pi].pending) { attach_in_flight = 1; break; }
|
||||
}
|
||||
}
|
||||
if (!attach_in_flight) blk_migration_idle_check();
|
||||
}
|
||||
|
||||
/* FABRIC-2.md §I.2's own overflow trigger, closed 2026-09-05: the
|
||||
* call site named above, now built. Same cadence, same idle-tick
|
||||
@@ -569,6 +589,22 @@ static void sk_repl_idle(VM *active_vm)
|
||||
if (capsule_vm_registry_get_by_index(i, &ent) != 0) continue;
|
||||
if (ent.state != VM_STATE_LIVE) continue;
|
||||
if (ent.vm_ptr == (void *)mama) continue;
|
||||
/* FABRIC-3.md, 2026-09-09: a per-VM flag (e.g. "this one is
|
||||
* std79-locked") doesn't generalize -- any VM whose own
|
||||
* dictionary lacks MSG-TICK, for whatever reason (never
|
||||
* loaded common:messaging.4th, a future personality that
|
||||
* drops it, ACL denial), hits the identical failure. So
|
||||
* check the actual target VM's own dictionary fresh every
|
||||
* tick, the same source of truth the interpreter's own ACL
|
||||
* enforcement uses (vm_core.c), rather than pre-flag specific
|
||||
* personalities. Skip silently rather than spam "VM-EXEC:
|
||||
* ERROR in <name>" every idle tick forever for a VM that
|
||||
* plain doesn't have -- or isn't allowed -- MSG-TICK
|
||||
* (live-caught 2026-09-07/09). */
|
||||
{
|
||||
DictEntry *msgtick = vm_find_word((VM *)ent.vm_ptr, "MSG-TICK", 8);
|
||||
if (!msgtick || !msgtick->acl_allow) continue;
|
||||
}
|
||||
|
||||
static const char PFX[] = "S\" MSG-TICK\" S\" ";
|
||||
static const char SFX[] = "\" VM-EXEC";
|
||||
@@ -1176,6 +1212,14 @@ void sk_repl_run(VM *vm)
|
||||
sk_print_prompt();
|
||||
|
||||
int n = sk_console_readline(input, sizeof(input), active, 1);
|
||||
#if EMERGENCY_CONSOLE_ENABLED
|
||||
/* n only consumed below under !EMERGENCY_CONSOLE_ENABLED (the
|
||||
* logged-out-mid-read bailout doesn't apply when the emergency
|
||||
* console bypasses login entirely) -- silence -Wunused-variable
|
||||
* rather than drop the assignment (sk_console_readline()'s return
|
||||
* value is still meaningful, just not acted on in this build). */
|
||||
(void)n;
|
||||
#endif
|
||||
|
||||
#if !EMERGENCY_CONSOLE_ENABLED
|
||||
/* n < 0: sk_console_readline() bailed out because the identity
|
||||
|
||||
@@ -24,6 +24,7 @@
|
||||
#include "starkernel/xhci_driver.h"
|
||||
#include "starkernel/kmalloc.h"
|
||||
#include "starkernel/timer.h"
|
||||
#include "starkernel/arch.h"
|
||||
#include "log.h"
|
||||
|
||||
/* Conservative fixed BAR0 mapping size. xHCI has no self-describing
|
||||
@@ -92,6 +93,16 @@ static int xhci_wait_bit(volatile uint32_t *reg, uint32_t mask, int want_set,
|
||||
if (heartbeat_ticks() - start >= max_ticks || spins >= 100000000ULL) {
|
||||
return -1;
|
||||
}
|
||||
/* FABRIC-3.md, 2026-09-09: a tight loop of nothing but MMIO reads
|
||||
* (no PAUSE/yield hint) can starve TCG's own host-side timer
|
||||
* injection under QEMU -- live-caught heartbeat_ticks() itself
|
||||
* (this loop's own timeout clock!) freezing for 30+ seconds
|
||||
* straight during a real reproduction, confirmed via a clean,
|
||||
* uninterfered-with measurement. That leaves only the 100M hard
|
||||
* spin cap as a backstop, which is far too permissive on its own.
|
||||
* arch_relax() (PAUSE on amd64) costs nothing on real hardware but
|
||||
* gives TCG a natural yield point between MMIO polls. */
|
||||
arch_relax();
|
||||
}
|
||||
}
|
||||
|
||||
@@ -986,6 +997,12 @@ int xhci_bot_wait_for_idle(xhci_dev_t *dev, uint32_t max_iters)
|
||||
for (uint32_t i = 0; i < max_iters; i++) {
|
||||
if (dev->bot_cmd_kind == BOT_CMD_NONE) return (int)dev->bot_last_status;
|
||||
xhci_poll_events();
|
||||
/* FABRIC-3.md, 2026-09-09: same TCG timer-starvation reasoning as
|
||||
* xhci_wait_bit()'s own doc comment above -- xhci_poll_events()
|
||||
* itself is a real MMIO-reading call, and max_iters (100000 from
|
||||
* blkio_usb_open_msc()) is large enough that a starved host timer
|
||||
* during a slow completion could stall for a very long time. */
|
||||
arch_relax();
|
||||
}
|
||||
return BOT_STATUS_TIMEOUT;
|
||||
}
|
||||
|
||||
@@ -24,6 +24,8 @@
|
||||
#include "starkernel/kmalloc.h"
|
||||
#include "console.h"
|
||||
#include "blkio.h"
|
||||
#include "log.h"
|
||||
#include "starkernel/arch.h"
|
||||
|
||||
/* -------------------------------------------------------------------------
|
||||
* Virtio 1.0 PCI capability structures
|
||||
@@ -234,6 +236,7 @@ static inline void rmb(void) {
|
||||
static int vblk_io(int write, uint64_t sector, void *buf, uint32_t nbytes) {
|
||||
VirtBlkState *s = &g_vblk;
|
||||
VirtqDesc *d = s->desc;
|
||||
int result;
|
||||
|
||||
/* Fill request header */
|
||||
s->req_buf->type = write ? VIRTIO_BLK_T_OUT : VIRTIO_BLK_T_IN;
|
||||
@@ -275,18 +278,52 @@ static int vblk_io(int write, uint64_t sector, void *buf, uint32_t nbytes) {
|
||||
*doorbell = 0; /* queue index 0 */
|
||||
wmb();
|
||||
|
||||
/* Poll until device posts a used entry */
|
||||
uint32_t spin = 0x2000000u; /* ~seconds at ~1 GHz; QEMU is fast */
|
||||
/* Poll until device posts a used entry.
|
||||
*
|
||||
* FABRIC-3.md, 2026-09-09: live-caught a real request that never gets
|
||||
* a used-ring completion -- root cause not yet isolated (every
|
||||
* existing bounds check, vblk_read()'s own fblock vs total_forth_
|
||||
* blocks and read_devblock_4k()'s own lba vs total_blkio_blocks_1k,
|
||||
* already passed before reaching here, so it isn't a simple out-of-
|
||||
* range request; disabling interrupts around this call was tried and
|
||||
* made it strictly worse -- suggests QEMU's own device-model
|
||||
* completion here depends on guest-visible time/interrupt progress in
|
||||
* this TCG configuration, not a driver-side reentrancy bug -- so that
|
||||
* approach was reverted). spin was 0x2000000 (~33M); at that bound a
|
||||
* single such failure cost tens of real minutes (confirmed: 31+ CPU-
|
||||
* minutes on one boot) because blk_migration_idle_check()'s own scan
|
||||
* calls this per un-cached devblock, up to ~23,000 times a boot, and
|
||||
* apparently more than one of those hits this failure mode. Cut by
|
||||
* ~30x: still enormously generous for a real completion (confirmed
|
||||
* live those return in a handful of iterations, not millions), but
|
||||
* turns what was an effectively-unbounded stall into a fast, loud,
|
||||
* logged failure instead -- callers already tolerate BLKIO_EIO
|
||||
* (zero-fill and move on), they just couldn't afford the old wait to
|
||||
* find that out. */
|
||||
uint32_t spin = 0x100000u; /* ~1M iterations */
|
||||
result = BLKIO_OK;
|
||||
while (s->used->idx == s->last_used_idx) {
|
||||
rmb();
|
||||
if (!--spin) return BLKIO_EIO;
|
||||
arch_relax(); /* FABRIC-3.md, 2026-09-09: xhci_wait_bit()'s own doc
|
||||
* comment (xhci.c) has the full reasoning -- a tight
|
||||
* MMIO-adjacent poll with no yield hint can starve
|
||||
* TCG's own host-side timer injection. */
|
||||
if (!--spin) {
|
||||
log_message(LOG_ERROR,
|
||||
"virtio_blk: vblk_io timed out (write=%d sector=%llu) -- "
|
||||
"queue never posted a used entry",
|
||||
write, (unsigned long long)sector);
|
||||
result = BLKIO_EIO;
|
||||
break;
|
||||
}
|
||||
}
|
||||
if (result == BLKIO_OK) {
|
||||
s->last_used_idx = s->used->idx;
|
||||
uint8_t status = *s->status_buf;
|
||||
if (status != (uint8_t)VIRTIO_BLK_S_OK) result = BLKIO_EIO;
|
||||
}
|
||||
s->last_used_idx = s->used->idx;
|
||||
|
||||
uint8_t status = *s->status_buf;
|
||||
if (status != (uint8_t)VIRTIO_BLK_S_OK) return BLKIO_EIO;
|
||||
|
||||
return BLKIO_OK;
|
||||
return result;
|
||||
}
|
||||
|
||||
/* -------------------------------------------------------------------------
|
||||
|
||||
Reference in New Issue
Block a user