blkparse: identifying which request does not complete

"Nikolaus Rath" <[email protected]> Mon, 09 Jun 2025 10:27:32 +0100
Newsgroups org.kernel.vger.linux-btrace
Message-ID <[email protected]>
Hello,

I am debugging an issue with a command that seems to be stuck hanging in kernel when doing a particular bit of I/O.

I've run blktrace on the devices that are being accessed, and noticed that for one of the devices the submitted and completed read requests don't agree:

# blkparse sdX.blktrace.0
[...]
Total (sdX):
 Reads Queued:       25872,   110096KiB  Writes Queued:          24,      108KiB
 Read Dispatches:    25872,   110096KiB  Write Dispatches:       24,      108KiB
 Reads Requeued:         0               Writes Requeued:         0
 Reads Completed:    25871,   110092KiB  Writes Completed:       24,      108KiB
 Read Merges:            0,        0KiB  Write Merges:            0,        0KiB
 IO unplugs:         25860               Timer unplugs:           0

This led me to suspect that the one outstanding request is the one that causes the command to hang. I then wanted to identify that request, so I ran:

# blkparse sdX.blktrace.0 -f "%a\t%s\t%p\t%C\t"
QRS	r	18579	zpool
GRS	r	18579	zpool
IRS	r	18579	zpool
DRS	r	426	kworker/29:1H
ARS	r	18571	zpool
QRS	r	18571	zpool
GRS	r	18571	zpool
IRS	r	18571	zpool
DRS	r	422	kworker/35:1H
[...]
And looked for a sequence number that was issued, but not completed. However, I found a large number of such sequence numbers, for example both 5530 and 8076:

PN 5530 18463 zpool
QR 5530 18463 zpool
PN 5530 19153 z_rd_int_5
QR 5530 19148 z_rd_int_0
IR 5530 18463 zpool
QR 5530 20637 z_rd_int_5
DR 8076 18463 zpool
GR 5530 18463 zpool
GR 5530 18463 zpool
PN 8076 18463 zpool
PN 8076 20595 z_rd_int_5
DR 8076 18463 zpool
DR 5530 20605 z_rd_int_1
GR 5530 18463 zpool
PN 8076 20165 z_rd_int_4
IR 8076 18463 zpool
GR 5530 18463 zpool
PN 5530 20632 z_rd_int_3

I would have expected there to be exactly one request without a "C" action (corresponding to the off-by-one difference in the total count), not many.

Did I misunderstand what I'm looking at? Or is the sequence id not the right number to identify a request?

Best,
-Nikolaus