So, I’ve been trying to move an NTFS partition to the left so I can consolidate free space I got by deleting no longer used partitions and then extend the drive to take up that new space.
Routine GParted task, right? Shouldn’t take more than an hour with a decent SSD, right?
It’s been >12 hours and it was stuck looking like this… (the time remaining is frozen)
Uhh… Okay.
So I looked at the drive and the indicator lights show nothing, not a good sign. I checked system journal logs and didn’t see anything unusual, no USB errors (it is an SSD connected with a USB SATA enclosure), no UASP errors, nothing.
I ran sync and thought it’ll take a few minutes at best but it’s been two hours and it’s still stuck. Now I’m really confused, so I dig around and find this post that’ll routinely update me about how much unflushed data is pending (source).
Dirty: 1844300 kB
Writeback: 668 kB
WritebackTmp: 0 kB
dm-0: 0
sda: 0
sdb: 4
Well, shit. Aren’t there tunables that prevent such situations from happening? What do I do now?
I think your drive is having a hard time.
When the dirty ratio is exceeded, I/O stops until the dirty data is flushed.
Down there at the bottom you can see its copied 78.64 GiB of data so I think you’ll have to wait until all of is done before the operation will complete.
If there is a hardware issue in the middle of a flush then I/O will stop entirely and the kernel will just continue to stack dirty writes. Bad sectors are supposed to be remapped automatically by the firmware but it could just be having a bad day under the hood.
Do you see any I/O related errors presented in sudo dmesg -T | tail -n 50?
Weird that journalctl didn’t show me this but dmesg did…
[Thu Aug 10 23:20:32 2023] sd 5:0:0:0: [sdb] tag#5 CDB: Write(10) 2a 00 19 a7 36 28 00 03 50 00
[Thu Aug 10 23:20:32 2023] sd 5:0:0:0: [sdb] tag#4 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD
[Thu Aug 10 23:20:32 2023] sd 5:0:0:0: [sdb] tag#4 CDB: Write(10) 2a 00 19 a7 33 58 00 02 d0 00
[Thu Aug 10 23:20:32 2023] scsi host5: uas_eh_device_reset_handler start
[Thu Aug 10 23:20:32 2023] usb 1-5: reset high-speed USB device number 32 using xhci_hcd
[Thu Aug 10 23:20:32 2023] scsi host5: uas_eh_device_reset_handler success
[Thu Aug 10 23:21:02 2023] sd 5:0:0:0: [sdb] tag#12 uas_eh_abort_handler 0 uas-tag 2 inflight: CMD
[Thu Aug 10 23:21:02 2023] sd 5:0:0:0: [sdb] tag#12 CDB: Write(10) 2a 00 19 a7 3c e8 00 03 48 00
[Thu Aug 10 23:21:02 2023] sd 5:0:0:0: [sdb] tag#10 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD
[Thu Aug 10 23:21:02 2023] sd 5:0:0:0: [sdb] tag#10 CDB: Read(10) 28 00 22 dd d0 00 00 04 00 00
[Thu Aug 10 23:21:02 2023] sd 5:0:0:0: [sdb] tag#9 uas_eh_abort_handler 0 uas-tag 4 inflight: CMD
[Thu Aug 10 23:21:02 2023] sd 5:0:0:0: [sdb] tag#9 CDB: Read(10) 28 00 22 dd d4 00 00 04 00 00
[Thu Aug 10 23:21:02 2023] sd 5:0:0:0: [sdb] tag#8 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD
[Thu Aug 10 23:21:02 2023] sd 5:0:0:0: [sdb] tag#8 CDB: Write(10) 2a 00 19 a7 39 78 00 03 70 00
[Thu Aug 10 23:21:02 2023] scsi host5: uas_eh_device_reset_handler start
[Thu Aug 10 23:21:02 2023] usb 1-5: reset high-speed USB device number 32 using xhci_hcd
[Thu Aug 10 23:21:02 2023] scsi host5: uas_eh_device_reset_handler success
[Thu Aug 10 23:21:33 2023] sd 5:0:0:0: [sdb] tag#14 uas_eh_abort_handler 0 uas-tag 2 inflight: CMD
[Thu Aug 10 23:21:33 2023] sd 5:0:0:0: [sdb] tag#14 CDB: Read(10) 28 00 22 dd dc 00 00 04 00 00
[Thu Aug 10 23:21:33 2023] sd 5:0:0:0: [sdb] tag#13 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD
[Thu Aug 10 23:21:33 2023] sd 5:0:0:0: [sdb] tag#13 CDB: Read(10) 28 00 22 dd d8 00 00 04 00 00
[Thu Aug 10 23:21:33 2023] sd 5:0:0:0: [sdb] tag#11 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD
[Thu Aug 10 23:21:33 2023] sd 5:0:0:0: [sdb] tag#11 CDB: Write(10) 2a 00 19 a7 40 30 00 03 18 00
[Thu Aug 10 23:21:33 2023] sd 5:0:0:0: [sdb] tag#8 uas_eh_abort_handler 0 uas-tag 4 inflight: CMD
[Thu Aug 10 23:21:33 2023] sd 5:0:0:0: [sdb] tag#8 CDB: Write(10) 2a 00 19 a7 43 48 00 03 90 00
[Thu Aug 10 23:21:33 2023] scsi host5: uas_eh_device_reset_handler start
[Thu Aug 10 23:21:33 2023] usb 1-5: reset high-speed USB device number 32 using xhci_hcd
[Thu Aug 10 23:21:33 2023] scsi host5: uas_eh_device_reset_handler success
[Thu Aug 10 23:22:04 2023] sd 5:0:0:0: [sdb] tag#15 uas_eh_abort_handler 0 uas-tag 2 inflight: CMD
[Thu Aug 10 23:22:04 2023] sd 5:0:0:0: [sdb] tag#15 CDB: Write(10) 2a 00 19 a7 48 f8 00 02 c8 00
[Thu Aug 10 23:22:04 2023] sd 5:0:0:0: [sdb] tag#14 uas_eh_abort_handler 0 uas-tag 4 inflight: CMD
[Thu Aug 10 23:22:04 2023] sd 5:0:0:0: [sdb] tag#14 CDB: Read(10) 28 00 22 dd e4 00 00 04 00 00
[Thu Aug 10 23:22:04 2023] sd 5:0:0:0: [sdb] tag#13 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD
[Thu Aug 10 23:22:04 2023] sd 5:0:0:0: [sdb] tag#13 CDB: Read(10) 28 00 22 dd e0 00 00 04 00 00
[Thu Aug 10 23:22:04 2023] sd 5:0:0:0: [sdb] tag#12 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD
[Thu Aug 10 23:22:04 2023] sd 5:0:0:0: [sdb] tag#12 CDB: Write(10) 2a 00 19 a7 46 d8 00 02 20 00
[Thu Aug 10 23:22:04 2023] scsi host5: uas_eh_device_reset_handler start
[Thu Aug 10 23:22:04 2023] usb 1-5: reset high-speed USB device number 32 using xhci_hcd
[Thu Aug 10 23:22:04 2023] scsi host5: uas_eh_device_reset_handler success
[Thu Aug 10 23:22:34 2023] sd 5:0:0:0: [sdb] tag#15 uas_eh_abort_handler 0 uas-tag 4 inflight: CMD
[Thu Aug 10 23:22:34 2023] sd 5:0:0:0: [sdb] tag#15 CDB: Write(10) 2a 00 19 a7 4e 68 00 02 70 00
[Thu Aug 10 23:22:34 2023] sd 5:0:0:0: [sdb] tag#14 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD
[Thu Aug 10 23:22:34 2023] sd 5:0:0:0: [sdb] tag#14 CDB: Write(10) 2a 00 19 a7 4b c0 00 02 a8 00
[Thu Aug 10 23:22:34 2023] sd 5:0:0:0: [sdb] tag#13 uas_eh_abort_handler 0 uas-tag 2 inflight: CMD
[Thu Aug 10 23:22:34 2023] sd 5:0:0:0: [sdb] tag#13 CDB: Read(10) 28 00 22 dd ec 00 00 04 00 00
[Thu Aug 10 23:22:34 2023] sd 5:0:0:0: [sdb] tag#12 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD
[Thu Aug 10 23:22:34 2023] sd 5:0:0:0: [sdb] tag#12 CDB: Read(10) 28 00 22 dd e8 00 00 04 00 00
[Thu Aug 10 23:22:34 2023] scsi host5: uas_eh_device_reset_handler start
[Thu Aug 10 23:22:35 2023] usb 1-5: reset high-speed USB device number 32 using xhci_hcd
[Thu Aug 10 23:22:35 2023] scsi host5: uas_eh_device_reset_handler success
It’s… not having a good time
Is this going through a hard drive enclosure?
Or with a RPi?
Edit: read this below. I think you might be suffering from a bug where the controller on your drive enclosure is not working well with UAS driver. Lots of good information there.
you can keep nmon running in a windows for immediate visibility of activity (or lack thereof…)
Yes, it is! I have less reason to suspect the enclosure and more reasons to suspect the motherboard since I remember having a higher frequency of errors when using a particular USB port and then changing ports till it worked, so it could be flaky USB from what I can tell…
Thankfully, the controller on my card isn’t from ASMedia but from VIA
$ lsusb
[...]
Bus 001 Device 035: ID 2109:0715 VIA Labs, Inc. VL817 SATA Adaptor
[...]
Btw, I did eventually just unplug the drive. 12 hours is a lot.
I accepted that the partition it was moving is just a goner but when reconnecting, it went from sdb to sdc so I symlinked sdc and its children (sdc1, sdc2, etc.) to sdb, allowed GParted to wind down (since for some reason it uses /dev/sdx to access drives instead of /dev/disk/by-id/scsi-XATA-XXXXXXXXXXXXXXXX_XXXXXXXXX), then deleted the symlinks and the partition affected.
I had a bad time with nmon, tried using it, too much information, I just needed a few key stats and grepping them and then using watch for refresh, while not a one-liner, was much more concise. Might use it as my htop replacement though if I get around to learning it.
If one presses d to monitor “drive” activity, then period/fullstop/. It’ll only show drives that update.
Does mean it unlists and relists drives that drop in usage
But is handy to see activity…
1 Like
