Software Information:
kernelversion=6.6.0
blktraceversion=1.3.0
Detailed Reproduction Steps:
1.Set the max_sectors_kb of the sda disk to 64.
[root@oe2403 ~]# find /sys/devices -name "max_sectors_kb"
/sys/devices/pci0000:00/0000:00:16.0/0000:0b:00.0/nvme/nvme0/nvme0n1/queue/max_sectors_kb
/sys/devices/pci0000:00/0000:00:11.0/0000:02:03.0/host2/target2:0:0/2:0:0:0/block/sda/queue/max_sectors_kb
/sys/devices/virtual/block/dm-1/queue/max_sectors_kb
/sys/devices/virtual/block/dm-0/queue/max_sectors_kb
[root@oe2403 ~]# cat
/sys/devices/pci0000:00/0000:00:11.0/0000:02:03.0/host2/target2:0:0/2:0:0:0/block/sda/queue/max_sectors_kb
1280
[root@oe2403 ~]# echo 64 >
/sys/devices/pci0000:00/0000:00:11.0/0000:02:03.0/host2/target2:0:0/2:0:0:0/block/sda/queue/max_sectors_kb
[root@oe2403 ~]# cat
/sys/devices/pci0000:00/0000:00:11.0/0000:02:03.0/host2/target2:0:0/2:0:0:0/block/sda/queue/max_sectors_kb
64
2.Use blktrace to collect IO data from the sda disk while writing
128KB of data to it via dd.
[root@oe2403 0212]# blktrace -d /dev/sda
^C=== sda ===
CPU 0: 6 events, 1 KiB data
CPU 1: 3 events, 1 KiB data
CPU 2: 389 events, 19 KiB data
CPU 3: 2 events, 1 KiB data
Total: 400 events (dropped 0), 19 KiB data
[root@oe2403 0212]# dd if=/dev/zero of=/dev/sda bs=128K count=1 seek=0
oflag=direct
1+0 records in
1+0 records out
131072 bytes (131 kB, 128 KiB) copied, 0.00165445 s, 79.2 MB/s
3.Merge the collected data into sda.blktrace.bin.
[root@oe2403 0212]# blkparse -i sda -d sda.blktrace.bin
4.Parse the blktrace data using btt.
[root@oe2403 0212]# blkparse -i sda.blktrace.bin > blkparse.log
[root@oe2403 0212]# btt -i sda.blktrace.bin > btt.log -p bttp.log -q bttq.log
Issue Observations:
1.In the btt.log, there are 49 entries for Q, Q2G, G2I, and Q2C, but
only 45 entries for I2D and D2C.
==================== All Devices ====================
ALL MIN AVG MAX N
--------------- ------------- ------------- ------------- -----------
Q2Q 0.000042614 0.000391863 0.012673966 48
Q2G 0.000000594 0.000001281 0.000007439 49
G2I 0.000000442 0.000001279 0.000010852 49
I2D 0.000001189 0.000002046 0.000010545 45
D2C 0.000031109 0.000047115 0.000100012 45
Q2C 0.000033475 0.000061946 0.000294852 49
Analysis via bttp.log and blkparse.log confirms that 4 split Q
requests failed to match D actions. Consequently, these 4 Q entries
lack corresponding D entries, resulting in 4 fewer I2D and D2C entries
compared to Q2G/G2I/Q2C.
-----------------------------------------
8,0 : 0.000000000 Q 0+256
0.000007439 G 0+256
0.000018291 I 0+256
0.000191487 C 0+256
8,0 3 1 0.000000000 3786 Q WS 0 + 256 [dd]
8,0 3 2 0.000003093 3786 X WS 0 / 128 [dd]
8,0 3 3 0.000007439 3786 G WS 0 + 128 [dd]
8,0 3 4 0.000018291 3786 I WS 0 + 128 [dd]
8,0 3 5 0.000025103 3786 G WS 128 + 128 [dd]
8,0 3 6 0.000025294 3786 I WS 128 + 128 [dd]
8,0 3 7 0.000036664 64 D WS 0 + 128 [kworker/3:1H]
8,0 3 8 0.000125797 64 D WS 128 + 128 [kworker/3:1H]
8,0 2 1 0.000184364 0 C WS 0 + 128 [0]
8,0 2 2 0.000191487 0 C WS 0 + 256 [0]
2.When Q requests are split, the timestamps for Q2G and G2I are
calculated using the first block of the split Q request's G and I
timestamps, instead of the last block's timestamps. This is verified
in bttp.log and blkparse.log.
Attachment:
btt.log
Description: Binary data
Attachment:
bttp.log
Description: Binary data
Attachment:
sda.blktrace.0
Description: Binary data
Attachment:
bttq.log_8,0_q2c.dat
Description: Binary data
Attachment:
blkparse.log
Description: Binary data
Attachment:
sda.blktrace.1
Description: Binary data
Attachment:
sda.blktrace.2
Description: Binary data
Attachment:
sda.blktrace.bin
Description: Binary data
Attachment:
sda.blktrace.3
Description: Binary data
