blk_update_request I/O errors

[morbidrsa]

David reported:

there are tons of errors in syslog blk_update_request: I/O error, dev nullb1, sector 1281112 op 0x1:(WRITE) flags 0x0 phys_seg 2 prio class 0 BTRFS error (device nullb0): bdev /dev/nullb1 errs: wr 21350, rd 0, flush 0, corrupt 0, gen 0 the fs is on 2 devices and the warnings are only for the 2nd one I think I enabled free-space-tree, no-holes, compress=zstd:15 and blake2 the workload is to copy util-linux.git and randomly checkout commits a full zone monitor has not reported any for nullb0 and the numbers for unusable were fluctuating, so the reclaim was doing fine I guess

[naota]

I could reproduce it with this setup + dbench (4 procs).

$ mount|grep btrfs /dev/mapper/scratch on /mnt/test type btrfs (rw,relatime,compress=zstd:15,space_cache=v2,subvolid=5,subvol=/) $ ls /sys/fs/btrfs/3f3bf0cd-c35f-4e5e-a71e-2eb0f5768e07/features/ big_metadata compress_zstd extended_iref mixed_backref no_holes skinny_metadata zoned

May 10 16:41:06 naota-devel kernel: ata3.00: exception Emask 0x0 SAct 0xc000 SErr 0x0 action 0x0 May 10 16:41:06 naota-devel kernel: ata3.00: irq_stat 0x40000008 May 10 16:41:06 naota-devel kernel: ata3.00: failed command: WRITE FPDMA QUEUED May 10 16:41:06 naota-devel kernel: ata3.00: cmd 61/02:70:f1:11:10/00:00:02:00:00/40 tag 14 ncq dma 8192 out res 43/04:02:f1:11:10/00:00:02:00:00/00 Emask 0x400 (NCQ error) May 10 16:41:06 naota-devel kernel: ata3.00: status: { DRDY SENSE ERR } May 10 16:41:06 naota-devel kernel: ata3.00: error: { ABRT } May 10 16:41:06 naota-devel kernel: ata3.00: configured for UDMA/133 May 10 16:41:06 naota-devel kernel: sd 2:0:0:0: [sda] tag#14 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE cmd_age=0s May 10 16:41:06 naota-devel kernel: sd 2:0:0:0: [sda] tag#14 Sense Key : Illegal Request [current] May 10 16:41:06 naota-devel kernel: sd 2:0:0:0: [sda] tag#14 Add. Sense: Unaligned write command May 10 16:41:06 naota-devel kernel: sd 2:0:0:0: [sda] tag#14 CDB: Write(16) 8a 00 00 00 00 00 02 10 11 f1 00 00 00 02 00 00 May 10 16:41:06 naota-devel kernel: blk_update_request: I/O error, dev sda, sector 276860808 op 0x1:(WRITE) flags 0x100000 phys_seg 2 prio class 0

[morbidrsa]

I got the following:

rapido2:/home/johannes/src/xfstests-dev# ./ltp/fsstress -d /mnt/test/ -n 10000000 seed = 1620099057 [ 4652.900175] blk_update_request: I/O error, dev nullb0, sector 2114680 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4652.902127] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 1, rd 0, flush 0, corrupt 0, gen 0 [ 4652.903948] blk_update_request: I/O error, dev nullb0, sector 2114688 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4652.905344] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 2, rd 0, flush 0, corrupt 0, gen 0 [ 4652.906598] blk_update_request: I/O error, dev nullb0, sector 2114696 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4652.907978] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 3, rd 0, flush 0, corrupt 0, gen 0 [ 4652.909231] blk_update_request: I/O error, dev nullb0, sector 2114704 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4652.910588] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 4, rd 0, flush 0, corrupt 0, gen 0 [ 4652.944112] blk_update_request: I/O error, dev nullb0, sector 2115136 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4652.946018] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 5, rd 0, flush 0, corrupt 0, gen 0 [ 4652.977215] blk_update_request: I/O error, dev nullb0, sector 2115336 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4652.979214] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 6, rd 0, flush 0, corrupt 0, gen 0 [ 4652.982574] blk_update_request: I/O error, dev nullb0, sector 2115344 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 0 [ 4652.984554] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 7, rd 0, flush 0, corrupt 0, gen 0 [ 4652.991753] blk_update_request: I/O error, dev nullb0, sector 2115496 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4652.993151] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 8, rd 0, flush 0, corrupt 0, gen 0 [ 4652.994537] blk_update_request: I/O error, dev nullb0, sector 2115504 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4652.995908] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 9, rd 0, flush 0, corrupt 0, gen 0 [ 4652.998037] blk_update_request: I/O error, dev nullb0, sector 2115520 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4652.999994] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 10, rd 0, flush 0, corrupt 0, gen 0 [ 4657.921874] print_req_error: 923 callbacks suppressed [ 4657.921880] blk_update_request: I/O error, dev nullb0, sector 2169208 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4657.923512] btrfs_dev_stat_print_on_error: 923 callbacks suppressed [ 4657.923514] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 934, rd 0, flush 0, corrupt 0, gen 0 [ 4657.925091] blk_update_request: I/O error, dev nullb0, sector 2169232 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4657.926209] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 935, rd 0, flush 0, corrupt 0, gen 0 [ 4657.931142] blk_update_request: I/O error, dev nullb0, sector 2169248 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4657.932223] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 936, rd 0, flush 0, corrupt 0, gen 0 [ 4657.933931] blk_update_request: I/O error, dev nullb0, sector 2169256 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4657.935137] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 937, rd 0, flush 0, corrupt 0, gen 0 [ 4657.936165] blk_update_request: I/O error, dev nullb0, sector 2169264 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4657.937216] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 938, rd 0, flush 0, corrupt 0, gen 0 [ 4657.938526] blk_update_request: I/O error, dev nullb0, sector 2169280 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4657.939604] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 939, rd 0, flush 0, corrupt 0, gen 0 [ 4657.945525] blk_update_request: I/O error, dev nullb0, sector 2169288 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4657.946698] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 940, rd 0, flush 0, corrupt 0, gen 0 [ 4657.947826] blk_update_request: I/O error, dev nullb0, sector 2169296 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4657.948977] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 941, rd 0, flush 0, corrupt 0, gen 0 [ 4657.950139] blk_update_request: I/O error, dev nullb0, sector 2169312 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4657.951296] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 942, rd 0, flush 0, corrupt 0, gen 0 [ 4657.956766] blk_update_request: I/O error, dev nullb0, sector 2169320 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4657.957848] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 943, rd 0, flush 0, corrupt 0, gen 0 [ 4662.970441] print_req_error: 983 callbacks suppressed [ 4662.970444] blk_update_request: I/O error, dev nullb0, sector 2219264 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4662.972145] btrfs_dev_stat_print_on_error: 983 callbacks suppressed [ 4662.972147] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 1927, rd 0, flush 0, corrupt 0, gen 0 [ 4662.975668] blk_update_request: I/O error, dev nullb0, sector 2219272 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4662.976752] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 1928, rd 0, flush 0, corrupt 0, gen 0 [ 4662.977779] blk_update_request: I/O error, dev nullb0, sector 2219280 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4662.978897] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 1929, rd 0, flush 0, corrupt 0, gen 0 [ 4662.979920] blk_update_request: I/O error, dev nullb0, sector 2219288 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4662.981090] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 1930, rd 0, flush 0, corrupt 0, gen 0 [ 4662.982704] blk_update_request: I/O error, dev nullb0, sector 2219312 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4662.983900] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 1931, rd 0, flush 0, corrupt 0, gen 0 [ 4662.984925] blk_update_request: I/O error, dev nullb0, sector 2219328 op 0x1:(WRITE) flags 0x0 phys_seg 2 prio class 0 [ 4662.986009] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 1932, rd 0, flush 0, corrupt 0, gen 0 [ 4662.986959] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 1933, rd 0, flush 0, corrupt 0, gen 0 [ 4662.995509] blk_update_request: I/O error, dev nullb0, sector 2219344 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4662.996680] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 1934, rd 0, flush 0, corrupt 0, gen 0 [ 4663.038548] blk_update_request: I/O error, dev nullb0, sector 2219656 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4663.039779] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 1935, rd 0, flush 0, corrupt 0, gen 0 [ 4663.046882] blk_update_request: I/O error, dev nullb0, sector 2219664 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 4663.047980] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 1936, rd 0, flush 0, corrupt 0, gen 0 [ 4663.054451] blk_update_request: I/O error, dev nullb0, sector 2219680 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0

[morbidrsa]

Same fsstress command succeeds without -o compress=ztd:15 option.

[morbidrsa]

Minimal reproducer:

rapido2:/home/johannes/src/xfstests-dev# mount -t btrfs -o compress=lzo /dev/nullb0 /mnt/test/ rapido2:/home/johannes/src/xfstests-dev# ./ltp/fsstress -d /mnt/test/ -n 100 seed = 1620279034 [ 7416.852984] blk_update_request: I/O error, dev nullb0, sector 2098280 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0 [ 7416.855913] BTRFS error (device nullb0): bdev /dev/nullb0 errs: wr 1, rd 0, flush 0, corrupt 0, gen 0 rapido2:/home/johannes/src/xfstests-dev#

[morbidrsa]

See also: https://github.com/btrfs/linux/issues/244

[morbidrsa]

https://lore.kernel.org/linux-btrfs/cover.1621351444.git.johannes.thumshirn@wdc.com/