/health/ready flaps to 503 pool_metadata_check_timeout on healthy nodes — a 100 ms mutex inspection timeout is reported as unready

Describe the bug

On 1.0.0, /health/ready on healthy nodes intermittently answers 503 with degradedReasons: ["pool_metadata_check_timeout"] for about 300 ms at a time, roughly once a minute, with no pool-metadata activity on the node. The reason string says what happened: the readiness handler waited 100 ms for the pool-metadata save-gate mutex, the wait expired, and readiness reported the node unready. Nothing is wrong with the node — writes are flowing, the write gate reads writable in the cluster snapshot immediately before and after, and the next sample 200 ms later is 200 again.

We caught it because our load balancer health-checks /health/ready on every node (HAProxy httpchk, 4 proxies × ~2 s interval) and logged groups of HEAD /health/ready → 503 at irregular intervals after the rolling upgrade from 1.0.0-rc.5. A 5 Hz sampler on two follower nodes shows the shape directly (only non-200 samples and the first recovery sample are written):

# object04 (follower, no scanner work, ~17 of 80 cores busy) — /tmp/ready_sampler.log
20:56:25.630 503 ["pool_metadata_check_timeout"]
20:56:25.937 200
20:56:30.479 503 ["pool_metadata_check_timeout"]
20:56:30.785 200
20:56:45.439 503 ["pool_metadata_check_timeout"]
20:56:45.746 200
20:56:59.390 503 ["pool_metadata_check_timeout"]
20:56:59.733 200

Over the full 40-minute run (2026-09-16 20:56:13–21:36:13 CST) object03 produced 16 such outages and object04 27, every one 0.31–0.34 s long (the 100 ms budget plus one 200 ms sampling interval), every one carrying only pool_metadata_check_timeout, and every one recovered by the next sample. It is steady-state, not an upgrade transient: a fresh 3-minute sample four hours later (2026-09-17 00:51–00:54 CST, 900 samples at 5 Hz over HTTPS) produced 4 more on object04, same reason, same shape. The rate is not tied to admin traffic: a burst of 40 authenticated admin requests (10× cluster/snapshot, 10× scanner/status, 5× storageinfo, 3× info) against the same node produced zero timeouts during or after the burst.

To Reproduce

1. Four-node cluster, EC 12+4, single pool, 1.0.0 on all nodes, ordinary foreground traffic (a JuiceFS backend, ~20 k objects/min of mixed PUT/GET/DELETE cluster-wide), scanner leader on another node — the sampled nodes report current_disk_bucket_scans_active: 0 and current_set_scans_active: 0.
2. Sample GET /health/ready at 5 Hz on any follower node and log the non-200 responses with their degradedReasons.
3. Observe ~0.4–1.2 isolated 503 pool_metadata_check_timeout per minute, each recovering by the next sample.

What we could rule out on the sampled node during the outages: no pool_metadata_blocked, no recovery-worker activity, no decommission/rebalance/format heal, no admin pool-status calls (the log contains only the ordinary internode walk_dir/transport churn that is also present between outages), and pool_meta_write_gate in the cluster snapshot reads writable immediately before and after.

Expected behavior

A readiness probe that could not inspect a gate within 100 ms should not report the node as unable to serve. The distinction is already modeled — check_timed_out is separate from write_blocked in pool_meta_write_status and the snapshot handler labels it check_timeout — but pool_metadata_write_readiness maps StorageError::Timeout to ready: false, and a test pins that as intended (inspection timeout must remain fail-closed). The two states have opposite operational meanings — a block means writes are refused, a timeout means the probe learned nothing — and the node path is uncached, so every timeout goes straight to the load balancer.

Concretely, any of these would fix it for us:

1. On inspection timeout, keep the last observed gate state (unready only if the last observation was blocked), or retry the inspection once before declaring the timeout.
2. Make the 100 ms budget configurable — there is no knob today, and the node storage-inventory inspection has a second hard-coded 100 ms budget of the same shape (NODE_STORAGE_READINESS_TIMEOUT, applied at readiness.rs:824).
3. Count these timeouts (rustfs_pool_metadata_blocks_total and ..._recoveries_total exist; a ..._check_timeouts_total does not), so the flapping is visible somewhere other than the load balancer's logs.

Environment

• 1.0.0 (d47f54bfb2f39f48bd1adda334bd27e151fe85b8), four nodes × 12 drives, EC 12+4, single pool, TLS internode, HAProxy in front of every node checking /health/ready.
• First seen within minutes of the rolling upgrade from 1.0.0-rc.5 on 2026-09-16 and still present 4 h later; rc.5 has no bounded gate inspection on the readiness path and never flapped this way on the same workload.

Additional context

Where this comes from. We asked for this inspection: #7361 (ours) reported a node whose pool-metadata write latch refused every write while /health/ready stayed 200, and #7365 ("surface blocked pool metadata writes", 2026-09-07) made readiness consult the gate, with #7417 later distinguishing an inspection timeout from a latched block in the diagnostics while keeping both unready. The block half of that is exactly right. This report is about the timeout half: it turns a probe that could not look into a verdict that the node cannot serve.

What holds the gate for 100 ms on an idle single-pool node — we could not find anything. We inventoried every pool_meta_save_gate acquisition in 1.0.0. The object write path never takes it on a single pool: PUT and multipart request decommission-capacity admission only if !self.single_pool() (multipart). What remains is decommission/rebalance (inactive), format heal (inactive), startup, the recovery worker's non-blocking try_lock, the admin pool-status refresh (refresh_pool_status_meta, admin-only), local bucket heal — which drops the gate after snapshotting fenced pools, before any disk work — and the peer bucket-heal RPC handler, which does hold it across the on-disk bucket heal but is driven by bucket creation and metadata-load retries, neither of which was happening once a minute. None of these fits a steady ~1/min cadence on a node doing only foreground I/O.

That leaves the budget itself. pool_meta_write_status wraps only Mutex::lock() in a 100 ms tokio::time::timeout; an uncontended lock completes on its first poll, so the timeout can only elapse if the readiness task is not polled for 100 ms — that is, if the runtime is busy enough that a fresh task waits that long for a worker. On these nodes ~17 of 80 cores are busy with foreground traffic plus the 1.0.0 heal executor, and the heal admission counters record a maxStartDurationMicros of 3.5 s on the same nodes, so 100 ms scheduling gaps are entirely plausible. If that is the mechanism, the check is measuring executor latency and reporting it as storage state — and fail-closed is the wrong mapping for a different reason than contention. The function's own doc comment ("A health probe must not wait behind a metadata transaction's disk I/O") describes what the budget is for: protecting the probe, not judging the node.

Why it matters even though HAProxy masks it for us. Our fall 3 absorbs an isolated failed check and the chkfail counters just climb. But readiness is a signal other things act on: a Kubernetes readiness probe with failureThreshold: 1, an operator script, our own automation — each sees a healthy node go unready once a minute, and a balancer with a shorter fall would drain it.