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