Intermittent Xen blkfront I/O stalls: all guest tags busy while tapdisk reports zero outstanding requests

poddingue

Your GDB capture looks to me like it lands where @anthoineb already pointed in post #2, when he guessed at a race condition losing the notification somewhere.
An empty ring on the tapdisk side while the guest still believes 31 tags are in flight seems to fit that, though I might be reading more into it than is there.
He mentioned too that the next update brings a batch of QCOW2 fixes in tapdisk and sm, which he recommended you take.

anthoineb

Hello @kazual82 Sorry for the delay, I was working on a gdb script for you before I was preempt. Yes, I'm curious about GDB backtraces and ring dump. I'm puzzled because even if we miss a notification from the frontend, tapdisk periodically checks blkif ring, so he must see the request with a delay at least. Can you also share your daemon.log and SMlog?

mike.potapov

Hello @anthoineb,

Thank you. I have attached the requested evidence as separate text files because the forum does not accept ZIP archives:

two complete GDB/tap-ctl captures taken during the same incident, before reboot;
the corresponding daemon.log excerpt from the hypervisor;
the corresponding SMlog excerpt from the hypervisor;
a README containing the timeline and identifiers;
SHA-256 checksums.

Both host-log excerpts cover 2026-07-25 04:35:00-05:10:00 MSK (UTC+03:00).
The first GDB capture started at 04:45:44, the independent repeat capture
started at 04:48:03, and the forced VM reboot was requested at 04:58:33.

Both captures show the same state:

the tapdisk main thread was in scheduler_wait_for_events();
n_reqs=32 and n_reqs_free=32;
req_prod=req_cons=rsp_prod=rsp_prod_pvt=0;
tap-ctl reported reqs_outstanding=0;
the guest still reported 31 requests in flight and all 32 blkfront tags busy.

The host logs contain no tapdisk error before the reboot. At 04:58:34-04:58:36
they show the expected sring disconnect, tapdisk close/detach and clean shutdown
after the forced reboot request. The new QCOW2 tapdisk was opened at 04:59:57
and its sring connected at 05:00:27.

Please let me know if you need another structure printed from GDB or a wider
host-log interval. Our recovery controller can preserve the same pre-reboot
diagnostic window during the next occurrence.
SHA256SUMS.txt README.txt osott-193-SMlog-20260725-0435-0510.txt osott-193-daemon-20260725-0435-0510.txt 20260725-044732-gdb-172.30.52.193.txt 20260725-044544-gdb-172.30.52.193.txt

mike.potapov

Hello @anthoineb,

We captured another occurrence on the same VM, os-ott-data-3-2
(172.30.52.193), on the same hypervisor and QCOW2 VDI as the incident
reported on 2026-07-25.

This occurrence is useful because xen_blkfront.max_ring_page_order=3 was
definitely active:

xenstore showed ring-page-order=3 with eight ring references;
the guest queue depth was 256;
255 write requests remained in flight;
all 256 blk-mq scheduler tags were busy;
wbt_lat_usec=0;
I/O PSI full was approximately 98%;
completed xvdb counters did not advance between samples.

The backend state was nevertheless the same as in the previous capture:

tapdisk was sleeping in scheduler_wait_for_events();
tap-ctl reported reqs_outstanding=0;
tap request counters were 0/0;
req_prod=0 and rsp_prod=0;
no tap, image, VBD, map or xenbus errors were reported.

One detail may be relevant: GDB still printed n_reqs=32 and
n_reqs_free=32, although the frontend had negotiated an order-3 ring and the
guest exposed 256 tags. Is this expected because n_reqs represents a separate
fixed tapdisk request pool, or could it indicate that tapdisk is not observing
the complete multi-page ring?

The controller captured GDB and the guest/hypervisor state before reboot. After
the ten-minute diagnostic window, the same signature was confirmed three more
times and the VM was rebooted. It rejoined the cluster successfully.

I have attached:

the complete GDB/tap-ctl capture;
the guest blk-mq, diskstats, PSI, D-state stack and kernel-journal snapshot;
the corresponding tapdisk/xenstore, daemon.log and SMlog excerpt;
a README and SHA-256 checksums.

The important new result appears to be that increasing
max_ring_page_order from 0 to 3 did not prevent the stall; the same mismatch
recurred with 255/256 frontend requests/tags occupied while the backend ring
and tapdisk remained empty.
20260730-005220-gdb-172.30.52.193.txt 20260730-pre-reboot-guest-172.30.52.193.txt 20260730-pre-reboot-hypervisor-172.30.50.191.txt README.txt SHA256SUMS.txt

anthoineb

Hello @mike.potapov , on n_reqs=32 and n_reqs_free=32, I think you're watching td_blktap_t structure. This structure is only used if the pvdriver are not install in the VM, so it's normal this ring is not used. You should watch struct td_xenblkif that is the ring use normally and that must contains 256 requests on max_order=3.

The tapdisk will wakeup periodically, you could put a breakpoint on tapdisk_xenio_ctx_ring_event to confirm that the ring is check periodically. You can investigate td_xenblkif here.

Ultimatly, you can try to send a notification from the tapdisk under gdb to the linux kernel with call (int)xenevtchn_notify(blkif->ctx->xce_handle, blkif->port); to see if it unlock something on the guest side. It it's the case it will confirm a notification was lost. If not you will get a message about spurious interrupt in the dmesg of the guest kernel.

mike.potapov

Hello @anthoineb,

We captured another occurrence and repeated the diagnostics you suggested. This time we inspected the active struct td_xenblkif, not the legacy td_blktap_t.

The incident affected os-ott-data-2-4 (172.30.52.185) on hypervisor 172.30.50.181. The guest had xen_blkfront.max_ring_page_order=3 active.

Guest state:

no completed xvdb I/O progress;
249 requests in flight;
250 of 256 blk-mq tags busy;
I/O PSI full approximately 97%;
11 tasks in D state;
OpenSearch remained locally responsive for part of the incident, but the node had left cluster membership.

Tapdisk remained responsive and reported:

reqs_outstanding=0
xenbus reqs=[8105673748,8105673748]
tap/image/VBD/xenbus errors=0

The active td_xenblkif state was:

domid=20
devid=832
port=325
ring_n_pages=8
ring_size=256
n_reqs_free=256

req_prod=3810706702
req_cons=3810706452
rsp_prod=3810706452
rsp_prod_pvt=3810706452

Therefore, req_prod - req_cons = 250: the 250 pending requests were present in the active Xen PV ring, but tapdisk had not consumed them and still reported zero outstanding requests.

Additional state:

in_polling=false
chkrng_event=57
stoppolling_event=58
poll_duration=8000
poll_idle_threshold=50

We placed a breakpoint on tapdisk_xenio_ctx_ring_event for eight seconds. It did not fire. GDB then detached and tapdisk remained responsive.

After preserving the original ring and guest state, we executed the suggested notification:

call (int)xenevtchn_notify(blkif->ctx->xce_handle, blkif->port)

The call returned 0, but it did not restore I/O. Three subsequent guest samples remained at 249 inflight / 250 busy tags with no disk progress. The td_xenblkif ring indices were unchanged in a second GDB capture, and no new spurious-interrupt message appeared in the guest dmesg.

A forced VM reboot restored I/O and the node rejoined the cluster.

This appears to show that requests are present in the active PV ring but are not being consumed by tapdisk, and a backend-to-guest event-channel notification alone does not unblock the condition.

Could you advise which callback or scheduler state we should inspect next? In particular, should we also place breakpoints on tapdisk_xenblkif_cb_chkrng or related polling callbacks during the next occurrence?

We have the complete before/after td_xenblkif dumps, breakpoint log, notify log, guest snapshots and hypervisor data available for upload.

anthoineb

Hello @mike.potapov , ok that's interesting, it seems that the lack of communication is in the other way, from guest to tapdisk.

To try unlock the ring on tapdisk side you can either:

send a SIGUSR2 to force the polling of tapdisk: kill -s SIGUSR2 <TAPDISK_PID> . Problem is the polling will start only if the cpu load is low enough.
or with gdb, call (void)tapdisk_xenblkif_sched_chkrng(blkif). Same command the polling is doing above but without the cpu load check.

Can you confirm one of the method check the ring and unlock it?

SMlog is doing a pause/unpause at the moment of the lock or just before?

I will investigate on how a event channel could be lost in tapdisk because I trust the kernel to send it and the hypervisor to deliver it.

mike.potapov

@anthoineb,

We checked both SMlog and xensource.log for the two latest incidents on hypervisor 172.30.50.181.

There was no VM or storage pause/unpause operation before either stall. The only matching pause/unpause pairs were part of our later forced VM.hard_reboot:

2026-08-19, VM 172.30.52.185: stall confirmed around 20:24; pause at 20:36:37 and unpause at 20:38:12.
2026-08-20, VM 172.30.52.182: stall confirmed around 20:24; pause at 20:30:07 and unpause at 20:31:26.

The first related VDI operations in SMlog were also the vdi_deactivate actions initiated by those reboots. Therefore, we do not see a pause/unpause immediately before or at the onset of either lock.

mike.potapov

Hello @anthoineb,

We had another occurrence and this time tested the exact GDB method you suggested. It successfully unlocked the ring.

The incident affected os-ott-data-3-2 (172.30.52.193) on hypervisor 172.30.50.191.

Before the test, the guest state was:

254 requests in flight
255/256 blk-mq tags busy
I/O PSI full: approximately 94-97%
3 tasks in D state
no completed xvdb I/O progress

Tapdisk remained responsive and reported:

reqs_outstanding=0
tap/image/VBD/xenbus errors=0

The untouched active td_xenblkif state was:

domid=26
devid=832
port=343
ring_n_pages=8
ring_size=256
n_reqs_free=256
in_polling=false

req_prod=2243281141
req_cons=2243280886
rsp_prod=2243280886
rsp_prod_pvt=2243280886

Therefore, exactly 255 requests were waiting in the active PV ring.

After preserving the baseline, we executed once:

call (void)tapdisk_xenblkif_sched_chkrng(blkif)

The indices were unchanged immediately inside GDB, but within approximately five seconds:

tapdisk reqs_outstanding: 0 -> 256
guest write inflight: 254 -> 0
I/O PSI full: approximately 98% -> 24% and continuing to decrease
xvdb completed-I/O counters started advancing

The post-test GDB capture showed:

in_polling=true
req_prod=2243366603
req_cons=2243366603
rsp_prod=2243366600
rsp_prod_pvt=2243366600
n_reqs_free=253

The previously stuck requests had been consumed and normal new I/O was flowing.

OpenSearch recovered its transport communication and the node rejoined the cluster without restarting the OpenSearch service and without rebooting the VM. The cluster completed shard recovery and became green at 17:05 MSK.

We also checked SMlog, xensource.log, and daemon.log for this incident. There was no VM or storage pause/unpause immediately before or during the stall.

This appears to confirm that tapdisk was not performing the scheduled ring check, and explicitly calling tapdisk_xenblkif_sched_chkrng() restored processing.

Would it be reasonable to use this call as an automated recovery action when the same exact signature is detected, before falling back to a VM reboot? We have the complete before/after GDB captures and guest/hypervisor diagnostics available if useful.

anthoineb

@mike.potapov yes, it is safe but it's a bit a heavy procedure to recover. I will open a ticket on our side to investigate now we have the root-cause.

anthoineb

@mike.potapov Can you upgrade to the latest blktap-3.55.5-9.3.xcpng8.3 to check is the issue is still there?