USB kernel issue with 4.19.57-2 and above

[erion]

Hi all,

I am running Arch Linux ARM v7H on a Raspberry Pi 3. It has two USB hard drives attached, both of them are wall-powered.

Since the release of linux-raspberrypi-4.19.57-2, I am getting a lot of USB resets and sector errors on the attached drives. This is a snippet of the latest log entries via 4.19.60-1. These log entries keep repeating.

$this->bbcode_second_pass_code('', 'Jul 28 10:40:38 idris kernel: usb 1-1.4: reset high-speed USB device number 5 using dwc_otg
Jul 28 10:40:38 idris kernel: sd 1:0:0:0: [sdb] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x07 driverbyte=0x00
Jul 28 10:40:38 idris kernel: sd 1:0:0:0: [sdb] tag#0 CDB: opcode=0x28 28 00 15 1d b3 a9 00 00 01 00
Jul 28 10:40:38 idris kernel: print_req_error: I/O error, dev sdb, sector 2834144584')

I am currently running 4.19.57-1, which works fine. Smart tests are performed daily, and they are also okay.
Any ideas what this could be?

Erion

[davep]

This is the most active of many threads across the RPi forums:

https://github.com/raspberrypi/linux/issues/3087

[erion]

Thanks for the link. In my case, I am able to boot properly, the log snippet I posted is from a live system installed to a microsd card. The issue does not seem like it's related, at least at a first glance, but I will definitely look into it and keep an eye on the thread.
Thanks again.

Erion

[mnemonic]

I am using 4.19.60-1-ARCH #1 SMP PREEMPT Sat Jul 27 22:59:08 UTC 2019 armv7l GNU/Linux

When i try rsync something in my USB pendrive i get alot of errors in dmesg before fail. Was working fine in older kernels.

Seems like have some new bug in USB drivers, i don´t know.

[mnemonic]

Just tried copy somes files to the pendrive, i get this erros on dmesg:

$this->bbcode_second_pass_code('', '
[ 81.513133] EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null)
[ 167.826816] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 168.597010] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 169.367223] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 170.137439] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 170.907683] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 171.677884] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 171.810572] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x07 driverbyte=0x00
[ 171.818308] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x2a 2a 00 00 47 28 00 00 00 a0 00
[ 171.826487] print_req_error: I/O error, dev sda, sector 4663296
[ 171.830747] EXT4-fs warning (device sda2): ext4_end_bio:323: I/O error 10 writing to inode 131077 (offset 0 size 4096 starting block 582913)
[ 171.839300] Buffer I/O error on device sda2, logical block 557056
[ 171.843642] EXT4-fs warning (device sda2): ext4_end_bio:323: I/O error 10 writing to inode 131078 (offset 0 size 4096 starting block 582914)
[ 171.851904] Buffer I/O error on device sda2, logical block 557057
[ 171.856064] EXT4-fs warning (device sda2): ext4_end_bio:323: I/O error 10 writing to inode 131079 (offset 0 size 8192 starting block 582916)
[ 171.864304] Buffer I/O error on device sda2, logical block 557058
[ 171.868515] Buffer I/O error on device sda2, logical block 557059
[ 171.872563] EXT4-fs warning (device sda2): ext4_end_bio:323: I/O error 10 writing to inode 131080 (offset 0 size 4096 starting block 582917)
[ 171.880444] Buffer I/O error on device sda2, logical block 557060
[ 171.884325] EXT4-fs warning (device sda2): ext4_end_bio:323: I/O error 10 writing to inode 131082 (offset 0 size 4096 starting block 582918)
[ 171.891757] Buffer I/O error on device sda2, logical block 557061
[ 171.895541] EXT4-fs warning (device sda2): ext4_end_bio:323: I/O error 10 writing to inode 131081 (offset 0 size 8192 starting block 582920)
[ 171.903424] Buffer I/O error on device sda2, logical block 557062
[ 171.907607] Buffer I/O error on device sda2, logical block 557063
[ 171.911798] EXT4-fs warning (device sda2): ext4_end_bio:323: I/O error 10 writing to inode 131088 (offset 0 size 4096 starting block 582921)
[ 171.919881] Buffer I/O error on device sda2, logical block 557064
[ 171.923837] EXT4-fs warning (device sda2): ext4_end_bio:323: I/O error 10 writing to inode 131089 (offset 0 size 4096 starting block 582922)
[ 171.931367] Buffer I/O error on device sda2, logical block 557065
[ 171.935186] EXT4-fs warning (device sda2): ext4_end_bio:323: I/O error 10 writing to inode 131090 (offset 0 size 4096 starting block 582923)
[ 171.942716] EXT4-fs warning (device sda2): ext4_end_bio:323: I/O error 10 writing to inode 131091 (offset 0 size 4096 starting block 582924)
[ 172.598143] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 173.368319] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 174.138547] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 174.908710] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 175.678910] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 176.449084] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 176.581642] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x07 driverbyte=0x00
[ 176.588437] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x2a 2a 00 00 47 28 a0 00 00 f0 00
[ 176.595721] print_req_error: I/O error, dev sda, sector 4663456
[ 177.239283] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 178.009505] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 178.779638] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 179.549830] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 180.319958] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 181.090137] usb 1-1.3: reset high-speed USB device number 4 using dwc_otg
[ 181.222809] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x07 driverbyte=0x00
[ 181.229538] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x2a 2a 00 00 47 29 90 00 00 f0 00
[ 181.236664] print_req_error: I/O error, dev sda, sector 4663696
[ 181.242058] EXT4-fs warning: 7 callbacks suppressed
[ 181.242067] EXT4-fs warning (device sda2): ext4_end_bio:323: I/O error 10 writing to inode 131103 (offset 0 size 2101248 starting block 583188)
[ 181.250374] buffer_io_error: 10 callbacks suppressed
[ 181.250379] Buffer I/O error on device sda2, logical block 557076
[ 181.255747] Buffer I/O error on device sda2, logical block 557077
[ 181.258469] Buffer I/O error on device sda2, logical block 557078
[ 181.261229] Buffer I/O error on device sda2, logical block 557079
[ 181.263987] Buffer I/O error on device sda2, logical block 557080
[ 181.266748] Buffer I/O error on device sda2, logical block 557081
[ 181.269383] Buffer I/O error on device sda2, logical block 557082
[ 181.271815] Buffer I/O error on device sda2, logical block 557083
[ 181.274053] Buffer I/O error on device sda2, logical block 557084
[ 181.276165] Buffer I/O error on device sda2, logical block 557085
[ 181.279158] EXT4-fs warning (device sda2): ext4_end_bio:323: I/O error 10 writing to inode 131103 (offset 0 size 2363392 starting block 583444)
[ 181.284825] EXT4-fs warning (device sda2): ext4_end_bio:323: I/O error 10 writing to inode 131103 (offset 0 size 2363392 starting block 583509)
[ 181.289526] EXT4-fs error (device sda2): ext4_wait_block_bitmap:511: comm kworker/u8:0: Cannot read block bitmap - block_group = 0, block_bitmap = 1029
[ 181.289528] JBD2: Detected IO errors while flushing file data on sda2-8
[ 181.289558] Aborting journal on device sda2-8.
[ 181.294764] EXT4-fs (sda2): I/O error while writing superblock
[ 181.294891] EXT4-fs error (device sda2) in __ext4_new_inode:933: Readonly filesystem
[ 181.294914] EXT4-fs (sda2): previous I/O error to superblock detected
[ 181.294953] EXT4-fs (sda2): I/O error while writing superblock
[ 181.295168] EXT4-fs error (device sda2) in __ext4_new_inode:933: Readonly filesystem
[ 181.295197] EXT4-fs (sda2): I/O error while writing superblock
[ 181.295319] EXT4-fs error (device sda2) in __ext4_new_inode:933: Readonly filesystem
[ 181.295358] EXT4-fs (sda2): I/O error while writing superblock
[ 181.295453] EXT4-fs error (device sda2) in __ext4_new_inode:933: Readonly filesystem
[ 181.295492] EXT4-fs (sda2): I/O error while writing superblock
[ 181.295603] EXT4-fs error (device sda2) in __ext4_new_inode:933: Readonly filesystem
[ 181.295630] EXT4-fs (sda2): I/O error while writing superblock
[ 181.295748] EXT4-fs error (device sda2) in __ext4_new_inode:933: Readonly filesystem
[ 181.295774] EXT4-fs (sda2): I/O error while writing superblock
[ 181.295886] EXT4-fs error (device sda2) in __ext4_new_inode:933: Readonly filesystem
[ 181.295913] EXT4-fs (sda2): I/O error while writing superblock
[ 181.296018] EXT4-fs error (device sda2) in __ext4_new_inode:933: Readonly filesystem
[ 181.296045] EXT4-fs (sda2): I/O error while writing superblock
[ 181.296160] EXT4-fs error (device sda2) in __ext4_new_inode:933: Readonly filesystem
[ 181.297355] JBD2: Error -5 detected when updating journal superblock for sda2-8.
[ 181.307266] EXT4-fs error (device sda2): ext4_journal_check_start:61: Detected aborted journal
')

[mnemonic]

yeah, it is broke: http://ix.io/1PUz

[erion]

Thanks for confirming this. Your log entries are exactly the same as mine in the first post, so it's good to know that I am not alone

[graysky]

You should really open a ticket against the RPi kernel so the developers are aware of this: https://github.com/raspberrypi/linux/issues/new/choose

[erion]

Thanks for the link. There is a ticket already at https://github.com/raspberrypi/linux/issues/3087

As it turns out, this is not an ALARM issue, this happens with Raspbian as well. The next steps would be to notify the upstream, I'm not sure if this has happened yet.

[NotEinstein]

Same/similar issue seems to be back again with linux-raspberrypi-headers-4.19.68-1