Created attachment 12118 [details] Strange sequence in ejecting USB drive device using Device Notifier Applet SUMMARY Since Plasma 5.20.4, we remark a strange behavior when ejecting a USB disk-based device. Kernel seems complain about missing device while udisks has been ejected it. See attached log. STEPS TO REPRODUCE 1. Plug a USB-based disk (USB key, USB Harddrive,...) 2. Mount partition while proposed by Disks and Device Notification applet. 3. Open Dolphin. 4. Close Dolphin window. 5. In Disks and Devices Notification applet, click on Remove securely. 6. See system logs. OBSERVED RESULT kernel: scsi_io_completion_action: 6 callbacks suppressed kernel: sd 4:0:0:0: [sdb] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE cmd_age=0s kernel: sd 4:0:0:0: [sdb] tag#0 Sense Key : Not Ready [current] kernel: sd 4:0:0:0: [sdb] tag#0 Add. Sense: Medium not present kernel: sd 4:0:0:0: [sdb] tag#0 CDB: Read(10) 28 00 00 00 00 00 00 00 01 00 kernel: print_req_error: 6 callbacks suppressed kernel: blk_update_request: I/O error, dev sdb, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0 kernel: buffer_io_error: 54 callbacks suppressed Reproduced by several users on IRC and forums. Reported upstream.
CC: (none) => geiger.david68210
These errors does not appear in 5.9.12 kernel (Beta 2) but since 5.10.1 Kernel. Adding Kernel and Drivers Maintainers here for advice. Something missing? Reported meanwhile to KDE devs.
CC: (none) => kernel
KDE.org devs dismissed this bug. Seems rather a 5.10 kernel one. Need more testing.
Assignee: kde => bugsquadURL: https://bugs.kde.org/show_bug.cgi?id=430584 => (none)
CC: (none) => jan-bugs
Created attachment 12126 [details] Sequence in ejecting USB drive device using Device Notifier Applet with Kernel 5.9.12 Attached system journal output when unmounting a USB key with 5.9.12 kernel running. No spurious errors! Assigning to Kernel and Drivers maintainers. Also, it seems to be a middleware problem.
Assignee: bugsquad => kernelKeywords: UPSTREAM => (none)Source RPM: plasma-workspace-5.20.4-1.mga8.src.rpm => udisks2-2.9.1-1.mga8.src.rpm
Do mount/unmount commands as root: nothing wrong in system journal. I do think there is something in trouble using Kernel 5.10.1 with udisks tools. Drives and Devices Notification Applet in Plasma relies on udisks tools. So, this is reported here: https://github.com/storaged-project/udisks/issues/827
In facts, after many tests, it appears that the command /usr/bin/eject is culprit here. Assuming your USB device is /dev/sdb Doing as root: # mount /dev/sdb1 /media # eject /media See errors in system journal kernel: scsi_io_completion_action: 6 callbacks suppressed kernel: sd 4:0:0:0: [sdb] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE cmd_age=0s kernel: sd 4:0:0:0: [sdb] tag#0 Sense Key : Not Ready [current] kernel: sd 4:0:0:0: [sdb] tag#0 Add. Sense: Medium not present kernel: sd 4:0:0:0: [sdb] tag#0 CDB: Read(10) 28 00 00 00 00 00 00 00 01 00 kernel: print_req_error: 6 callbacks suppressed kernel: blk_update_request: I/O error, dev sdb, sector 0 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0 kernel: buffer_io_error: 54 callbacks suppressed This is present from Kernel 5.10.0 to latest 5.10.4-2.mga8 BUT 5.9.12-1.mga8 is unaffected! udisks2 has not been updated, not the real culprit, eject command is part of util-linux (util-linux-2.36), not updated upstream. I do think there is issue with the kernel: the wolume seems well unmounted but the strange errors printed by Kernel with lots of warnings and errors-level ones are really spurious.
Status comment: (none) => util-linux-2.36.1-4.mga8.src.rpm ? Kernel itself?
Priority: Normal => HighSeverity: normal => major
It seems the kernel is trying to read the partition table of the device after it got removed, not sure how to find out if it does that by itself or that is requested by something (udev?).
CC: (none) => pterjan
Note that it can be even reproduced without a graphical session, even with udisks2 stopped. The errors are displayed right after pressing the Enter key. And again no error with 5.9.12-1. Really strange.
strace tells me that after ejecting, the eject command asks the kernel to reread the partition table: openat(AT_FDCWD, "/dev/sda", O_RDWR|O_EXCL|O_NONBLOCK) = 3 ioctl(3, CDROM_LOCKDOOR, 0) = -1 EINVAL (Invalid argument) ioctl(3, SG_GET_VERSION_NUM, [30527]) = 0 ioctl(3, SG_IO, {interface_id='S', dxfer_direction=SG_DXFER_NONE, cmd_len=6, cmdp="\x1e\x00\x00\x00\x00\x00", mx_sb_len=32, iovec_count=0, dxfer_len=0, timeout=10000, flags=0, status=0, masked_status=0, msg_status=0, sb_len_wr=0, sbp="", host_status=0, driver_status=0, resid=0, duration=0, info=0}) = 0 ioctl(3, SG_IO, {interface_id='S', dxfer_direction=SG_DXFER_NONE, cmd_len=6, cmdp="\x1b\x00\x00\x00\x01\x00", mx_sb_len=32, iovec_count=0, dxfer_len=0, timeout=10000, flags=0, status=0, masked_status=0, msg_status=0, sb_len_wr=0, sbp="", host_status=0, driver_status=0, resid=0, duration=0, info=0}) = 0 ioctl(3, SG_IO, {interface_id='S', dxfer_direction=SG_DXFER_NONE, cmd_len=6, cmdp="\x1b\x00\x00\x00\x02\x00", mx_sb_len=32, iovec_count=0, dxfer_len=0, timeout=10000, flags=0, status=0, masked_status=0, msg_status=0, sb_len_wr=0, sbp="", host_status=0, driver_status=0, resid=0, duration=1, info=0}) = 0 ioctl(3, BLKRRPART) = -1 EIO (Input/output error) However running it again, it does so again but and causes no errors to be logged by the kernel: openat(AT_FDCWD, "/dev/sda", O_RDWR|O_EXCL|O_NONBLOCK) = 3 ioctl(3, CDROM_LOCKDOOR, 0) = -1 EINVAL (Invalid argument) ioctl(3, SG_GET_VERSION_NUM, [30527]) = 0 ioctl(3, SG_IO, {interface_id='S', dxfer_direction=SG_DXFER_NONE, cmd_len=6, cmdp="\x1e\x00\x00\x00\x00\x00", mx_sb_len=32, iovec_count=0, dxfer_len=0, timeout=10000, flags=0, status=0, masked_status=0, msg_status=0, sb_len_wr=0, sbp="", host_status=0, driver_status=0, resid=0, duration=0, info=0}) = 0 ioctl(3, SG_IO, {interface_id='S', dxfer_direction=SG_DXFER_NONE, cmd_len=6, cmdp="\x1b\x00\x00\x00\x01\x00", mx_sb_len=32, iovec_count=0, dxfer_len=0, timeout=10000, flags=0, status=0, masked_status=0, msg_status=0, sb_len_wr=0, sbp="", host_status=0, driver_status=0, resid=0, duration=0, info=0}) = 0 ioctl(3, SG_IO, {interface_id='S', dxfer_direction=SG_DXFER_NONE, cmd_len=6, cmdp="\x1b\x00\x00\x00\x02\x00", mx_sb_len=32, iovec_count=0, dxfer_len=0, timeout=10000, flags=0, status=0, masked_status=0, msg_status=0, sb_len_wr=0, sbp="", host_status=0, driver_status=0, resid=0, duration=0, info=0}) = 0 ioctl(3, BLKRRPART) = 0 I could confirm that removing the "ioctl(ctl->fd, BLKRRPART);" line from eject.c made the problem go away but even if I don't see the point of that call, this seems to be a problem in the kernel accepting the command while it is removing the device.
Also for the record, this can be reproduced with kernel-linus.
does it change anything with util-linux-2.36.1-5.mga8 ? It's basically only a rebuild for glibc 2.32 and kernel 5.10 series headers... Technically it should not matter, but sometimes there have been some subtle changes in glibc and/or kernel that could cause issues...
(In reply to Thomas Backlund from comment #10) > does it change anything with util-linux-2.36.1-5.mga8 ? > > It's basically only a rebuild for glibc 2.32 and kernel 5.10 series > headers... > > > Technically it should not matter, but sometimes there have been some subtle > changes in glibc and/or kernel that could cause issues... $ uname -r 5.10.4-desktop-3.mga8 $ rpm -qa | grep util-linux util-linux-2.36.1-5.mga8 This is the same. Kernel logs errors like @Pascal can confirm. I really think there is something in Kernel. I report upstream to bugzilla.kernel.org: https://bugzilla.kernel.org/show_bug.cgi?id=211023
Don't know if this helps but here is the dmesg output after ejecting a USB drive. First with kernel 5.7.19-desktop-3.mga7 and second with kernel 5.10.3-desktop-1.mga7. ============================ $ uname -a Linux marte 5.7.19-desktop-3.mga7 #1 SMP Sun Oct 18 15:46:00 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux $ rpm -q util-linux util-linux-2.33.2-1.mga7 $ eject /dev/sda $ dmesg <SNIP> [22391.943859] sd 5:0:0:0: [sdg] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE cmd_age=0s [22391.943864] sd 5:0:0:0: [sdg] tag#0 Sense Key : Not Ready [current] [22391.943867] sd 5:0:0:0: [sdg] tag#0 Add. Sense: Medium not present [22391.943871] sd 5:0:0:0: [sdg] tag#0 CDB: Read(10) 28 00 00 00 08 08 00 00 08 00 [22391.943874] blk_update_request: I/O error, dev sdg, sector 2056 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 0 [22391.944490] sd 5:0:0:0: [sdg] tag#0 access beyond end of device [22391.944493] blk_update_request: I/O error, dev sdg, sector 2056 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0 [22391.944496] Buffer I/O error on dev sdg1, logical block 1, async page read [22391.947358] sdg: detected capacity change from 32019316736 to 0 ============================ $ uname -a Linux marte-vm-mageia-7 5.10.3-desktop-1.mga7 #1 SMP Sat Dec 26 18:15:40 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux $ rpm -q util-linux util-linux-2.33.2-1.mga7 $ lsusb | grep lexar Bus 001 Device 003: ID 05dc:a81d Lexar Media, Inc. LJDTT16G [JumpDrive 16GB] $ eject /dev/sda $ dmesg <SNIP> [ 58.992896] sd 8:0:0:0: [sda] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE cmd_age=0s [ 58.992904] sd 8:0:0:0: [sda] tag#0 Sense Key : Not Ready [current] [ 58.992908] sd 8:0:0:0: [sda] tag#0 Add. Sense: Medium not present [ 58.992912] sd 8:0:0:0: [sda] tag#0 CDB: Read(10) 28 00 03 40 10 b0 00 00 08 00 [ 58.992917] blk_update_request: I/O error, dev sda, sector 54530224 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 0 [ 59.001952] sd 8:0:0:0: [sda] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE cmd_age=0s [ 59.001958] sd 8:0:0:0: [sda] tag#0 Sense Key : Not Ready [current] [ 59.001961] sd 8:0:0:0: [sda] tag#0 Add. Sense: Medium not present [ 59.001965] sd 8:0:0:0: [sda] tag#0 CDB: Read(10) 28 00 03 40 10 b0 00 00 08 00 [ 59.001969] blk_update_request: I/O error, dev sda, sector 54530224 op 0x0:(READ) flags 0x0 phys_seg 8 prio class 0 [ 59.001973] Buffer I/O error on dev sda2, logical block 2224, async page read [ 59.001977] Buffer I/O error on dev sda2, logical block 2225, async page read [ 59.001979] Buffer I/O error on dev sda2, logical block 2226, async page read [ 59.001981] Buffer I/O error on dev sda2, logical block 2227, async page read [ 59.001982] Buffer I/O error on dev sda2, logical block 2228, async page read [ 59.001984] Buffer I/O error on dev sda2, logical block 2229, async page read [ 59.001986] Buffer I/O error on dev sda2, logical block 2230, async page read [ 59.001988] Buffer I/O error on dev sda2, logical block 2231, async page read [ 59.020965] sd 8:0:0:0: [sda] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE cmd_age=0s [ 59.021000] sd 8:0:0:0: [sda] tag#0 Sense Key : Not Ready [current] [ 59.021011] sd 8:0:0:0: [sda] tag#0 Add. Sense: Medium not present [ 59.021032] sd 8:0:0:0: [sda] tag#0 CDB: Read(10) 28 00 03 40 10 b0 00 00 08 00 [ 59.021045] blk_update_request: I/O error, dev sda, sector 54530224 op 0x0:(READ) flags 0x0 phys_seg 8 prio class 0 [ 59.021056] Buffer I/O error on dev sda2, logical block 2224, async page read [ 59.021069] Buffer I/O error on dev sda2, logical block 2225, async page read
CC: (none) => mageia
I managed to bisect the changes to https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=471bd0af544bcd80450d61659a1ffabdd1820d7d
thanks for tracking it down. I will revert it for now in Mageia until upstream have time to sort it out
revert is in kernel-5.10.5-1.mga8 currently mirroring out
Yeah. This is fixed. Thanks Thomas.
Closing.
Resolution: (none) => FIXEDStatus: NEW => RESOLVED