fix(virtio-blk): wait for a request's own completion, by time

On riscv64 a system=v3 boot never reached its prompt: Artemis's writes
"timed out" and Zuse was never confirmed (logs/20261026-134850). vblk_io()
bounded its wait by ~1M polling iterations, which on riscv64 under TCG is
about one heartbeat tick of real time -- shorter than a write that allocates
space in a sparse host image. Instrumented, the request was seen completing
just after the give-up ("used idx=409 last=408"), and every later request
then took its predecessor's completion for its own and returned before its
own I/O was done (a stale used index at each later request), reusing the
descriptor chain while the device still owned it: silent read and write
corruption from that point on. FABRIC-3.md's 2026-09-09 "request that never
gets a used-ring completion" is this same early give-up.

Now: the wait is for this request's own completion (the used index
reaching the avail index it was given), bounded by 5 s of real time on the
CPU's counter (timer_now_ns(), which needs no interrupts); a request that
truly never completes takes the disk out of service instead of letting a
later request reuse the chain.

Red (riscv64 system=v3, with temporary instrumentation): 151003, 151100 --
a timeout then dozens of stale completions each. Green: 151238, 151332 --
none; Zuse confirmed; the keyboard line answered. system=v3 with the fix:
riscv64 151438, amd64 151528, aarch64 151610, no timeouts. Accepted (v4):
151722, 151916, 152247, POST 538/538, dict_hash 0xfec8c47cfc6f437f;
test-32, 39 modules, 0 failures.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
rajames
2026-10-26 15:30:00 -04:00
co-authored by Claude Opus 5.5
parent 83d3692976
commit 0dbc98c049
21 changed files with 63986 additions and 37 deletions
+50 -37
View File
@@ -26,6 +26,7 @@
#include "blkio.h"
#include "log.h"
#include "starkernel/arch.h"
#include "starkernel/timer.h" /* timer_now_ns(): vblk_io()'s bound */
/* -------------------------------------------------------------------------
* Virtio 1.0 PCI capability structures
@@ -172,6 +173,18 @@ typedef struct {
static VirtBlkState g_vblk;
static int g_vblk_ready = 0;
/* How long one request may take before the disk is given up on: real time,
* not loop iterations (fixed 2026-10-26: a bound of ~1M iterations was
* about 10 ms on riscv64 under TCG, shorter than a write that allocates
* space in a sparse host image, and the driver then fell one completion
* behind for good -- see vblk_io()). */
#define VBLK_IO_TIMEOUT_NS 5000000000ULL
/* Set when a request was never completed within VBLK_IO_TIMEOUT_NS: the
* device may still own the descriptor chain, so it is not reused; every
* later request fails at once. */
static int g_vblk_dead = 0;
/* -------------------------------------------------------------------------
* Capability walker
* Returns MMIO pointer to the virtio capability region, or NULL.
@@ -238,6 +251,8 @@ static int vblk_io(int write, uint64_t sector, void *buf, uint32_t nbytes) {
VirtqDesc *d = s->desc;
int result;
if (g_vblk_dead) return BLKIO_EIO;
/* Fill request header */
s->req_buf->type = write ? VIRTIO_BLK_T_OUT : VIRTIO_BLK_T_IN;
s->req_buf->reserved = 0;
@@ -278,43 +293,41 @@ 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.
*
* 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();
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;
/* Wait for this request's own completion: the used index reaching the
* avail index this request was given (one request in flight, so the
* two move together). Fixed 2026-10-26 (the riscv64 v3 boot's Artemis
* write timeouts, logs/20261026-134850): the wait was bounded by ~1M
* polling iterations, which on riscv64 under TCG is about one heartbeat
* tick of real time -- shorter than a write that allocates space in a
* sparse host image. The request then completed just after the driver
* had given up on it, and every later request took its predecessor's
* completion for its own and returned before its own I/O was done
* (seen: "used idx=409 last=408" at the timeout, then a stale used
* index at every later request), reusing the descriptor chain while the
* device still owned it. Now the bound is real time, measured by the
* CPU's own counter (timer_now_ns(), which needs no interrupts: the
* disk is used before the timer runs), and a request that truly never
* completes takes the disk out of service rather than letting a later
* request reuse the chain. The 2026-09-09 notes (FABRIC-3.md) on a
* request "that never gets a used-ring completion" describe this same
* early give-up. arch_relax() stays: a tight MMIO-adjacent poll with no
* yield hint can starve TCG's own host-side timer injection (xhci.c,
* xhci_wait_bit()). */
{
uint64_t t0 = timer_now_ns();
result = BLKIO_OK;
while (s->used->idx != s->avail_idx) {
rmb();
arch_relax();
if (timer_now_ns() - t0 > VBLK_IO_TIMEOUT_NS) {
log_message(LOG_ERROR,
"virtio_blk: request never completed in 5 s (write=%d sector=%llu) -- "
"the disk is taken out of service",
write, (unsigned long long)sector);
g_vblk_dead = 1;
result = BLKIO_EIO;
break;
}
}
}
if (result == BLKIO_OK) {