KDE4 takes a minute to recognize USB3 pendrive

brunomcl · May 15, 2015, 10:00pm

Desktop computer, oS 13.2, KDE 4.14.6, Kernel 3.16.7-21-desktop x86_64

After inserting a cheap EMTEC USB3 16GB pendrive in a (obviously) USB3 port, KDE notifications takes approx. 60-65 seconds to show up with the removable device notice. Particulars:

System load widget shows 1 core fully in I/O wait; iotop shows no process consuming large I/O, and the HDD led does not light up continuously, it just flashes now and then.
The same delay happens when the pendrive is inserted in a USB2 port. Note: driver invoked in this case is xhci_hcd, not ehci.
In W7 in the same computer there’s no delay, in either USB2 ou 3 port.
In parted magic (a live distro with the XFCE desktop IINM), there’s no delay. The driver invoked is ehci-pci. Tested only in a USB2 port, no USB3 available in that machine.
In an HP laptop running oS 13.1, KDE 4.11.5, Kernel 3.11.10-29-desktop x86_64 there is no delay. Driver is the same as the desktop, name-wise: xhci_hcd. Tested in a USB3 port.
After the pendrive is recognized in oS, performance is similar to W7’s (i.e., better than USB2 but not that much, it’s a cheap device after all).

dmesg info when inserting pendrive in USB3 port of the desktop:

[73321.550748] usb 4-2: new SuperSpeed USB device number 2 using xhci_hcd
[73321.658227] usb 4-2: New USB device found, idVendor=6557, idProduct=5500
[73321.658229] usb 4-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[73321.658231] usb 4-2: Product: USB DISK 3.0
[73321.658232] usb 4-2: Manufacturer:         
[73321.658233] usb 4-2: SerialNumber: 07014C96AAB2F989
[73321.658697] usb-storage 4-2:1.0: USB Mass Storage device detected
[73321.659195] scsi19 : usb-storage 4-2:1.0
[73322.715782] scsi 19:0:0:0: Direct-Access              USB DISK 3.0     PMAP PQ: 0 ANSI: 6
[73322.715967] sd 19:0:0:0: Attached scsi generic sg8 type 0
[73323.702226] sd 19:0:0:0: [sdg] 30283008 512-byte logical blocks: (15.5 GB/14.4 GiB)
[73323.702331] sd 19:0:0:0: [sdg] Write Protect is off
[73323.702333] sd 19:0:0:0: [sdg] Mode Sense: 23 00 00 00
[73323.702447] sd 19:0:0:0: [sdg] No Caching mode page found
[73323.702449] sd 19:0:0:0: [sdg] Assuming drive cache: write through
[73323.728195]  sdg: sdg1
[73323.729111] sd 19:0:0:0: [sdg] Attached SCSI removable disk
*----> this is where the delay happens <----*
[73384.701086] usb 4-2: reset SuperSpeed USB device number 2 using xhci_hcd
[73384.877063] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff8803ee282400
[73384.877066] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff8803ee282448

dmesg from HP laptop, also using USB3 port:

[48016.680729] usb 4-1: new SuperSpeed USB device number 2 using xhci_hcd
[48016.788981] usb 4-1: New USB device found, idVendor=6557, idProduct=5500
[48016.788987] usb 4-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[48016.788989] usb 4-1: Product: USB DISK 3.0
[48016.788991] usb 4-1: Manufacturer:         
[48016.788993] usb 4-1: SerialNumber: 07014C96AAB2F989
[48016.801656] usb-storage 4-1:1.0: USB Mass Storage device detected
[48016.801800] scsi6 : usb-storage 4-1:1.0
[48016.802518] usbcore: registered new interface driver usb-storage
[48017.858208] scsi 6:0:0:0: Direct-Access              USB DISK 3.0     PMAP PQ: 0 ANSI: 6
[48017.858837] sd 6:0:0:0: Attached scsi generic sg2 type 0
[48018.802517] sd 6:0:0:0: [sdc] 30283008 512-byte logical blocks: (15.5 GB/14.4 GiB)
[48018.803135] sd 6:0:0:0: [sdc] Write Protect is off
[48018.803146] sd 6:0:0:0: [sdc] Mode Sense: 23 00 00 00
[48018.803751] sd 6:0:0:0: [sdc] No Caching mode page found
[48018.803756] sd 6:0:0:0: [sdc] Assuming drive cache: write through
[48018.807993] sd 6:0:0:0: [sdc] No Caching mode page found
[48018.807999] sd 6:0:0:0: [sdc] Assuming drive cache: write through
[48018.831963]  sdc: sdc1
[48018.834438] sd 6:0:0:0: [sdc] No Caching mode page found
[48018.834442] sd 6:0:0:0: [sdc] Assuming drive cache: write through
[48018.834446] sd 6:0:0:0: [sdc] Attached SCSI removable disk

I was close to lay the blame on the USB3 implementation on the cheap pendrive, but it works nicely on the laptop, so I don’t know how to fix this. Any ideas?

TIA

brunomcl · May 15, 2015, 10:14pm

Also, there’s no delay on the desktop with an external USB3 HDD, also using xhci_hcd.

brunomcl · May 17, 2015, 9:08pm

From this: https://forums.opensuse.org/showthread.php/498118-USB-3-0-malfunction?p=2645315#post2645315

I’m back to thinking it’s the pendrive itself. It works in 13.1 (that apparently blacklists uas) but at slower speed according to hdparm:

oS 13.1 laptop:

# hdparm -t /dev/sdc

/dev/sdc:
 Timing buffered disk reads: 198 MB in  3.01 seconds =  65.77 MB/sec

# uname -r
3.11.10-29-desktop

oS 13.2 desktop (with uas blacklisted):

# hdparm -t /dev/sdg

/dev/sdg:
 Timing buffered disk reads: 262 MB in  3.01 seconds =  86.95 MB/sec

# uname -r
3.16.7-21-desktop

# lsmod | grep uas
#
# lsmod | grep usb
usb_storage            62302  0 
usblp                  18756  0

It didn’t make a difference if uas is blacklisted or not, either in the 60 sec delay or in hdparm test speed. So I’m thinking it’s not related to this old bug: https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/commit/?id=a9c54caa456dccba938005f6479892b589975e6a

Any ideas?

brunomcl · May 17, 2015, 9:14pm

Device ID is very parsimonious, just vendor/product code:

# lsusb
Bus 002 Device 002: ID 8087:8000 Intel Corp. 
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 002: ID 8087:8008 Intel Corp. 
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 004 Device 004: ID **6557:5500**  
Bus 004 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
...

More info (uas blacklisted):

hwinfo --usb
07: SCSI b00.0: 10600 Disk                                      
  [Created at block.245]
  Unique ID: rg_L.Qa79IJVPvmA
  SysFS ID: /class/block/sdg
  SysFS BusID: 11:0:0:0
  SysFS Device Link: /devices/pci0000:00/0000:00:14.0/usb4/4-2/4-2:1.0/host11/target11:0:0/11:0:0:0
  Hardware Class: disk
  Model: "USB DISK 3.0"
  Vendor: usb 0x6557 
  Device: usb 0x5500 "USB DISK 3.0"
  Revision: "PMAP"
  Serial ID: "0F79081940C0"
  Driver: "usb-storage", "sd"
  Driver Modules: "usb_storage"
  Device File: /dev/sdg (/dev/sg8)
  Device Files: /dev/sdg, /dev/disk/by-id/scsi-1***USB_DISK_2.0***, /dev/disk/by-id/scsi-28765432ab567abcd, /dev/disk/by-id/scsi-32000acde48234567, /dev/disk/by-id/wwn-0x2000acde48234567, /dev/disk/by-path/pci-0000:00:14.0-usb-0:2:1.0-scsi-0:0:0:0
  Device Number: block 8:96-8:111 (char 21:8)
  Geometry (Logical): CHS 14786/64/32
  Size: 30283008 sectors a 512 bytes
  Capacity: 14 GB (15504900096 bytes)
  Module Alias: "usb:v6557p5500d0100dc00dsc00dp00ic08isc06ip50in00"
  Driver Info #0:
    Driver Status: uas is not active
    Driver Activation Cmd: "modprobe uas"
  Driver Info #1:
    Driver Status: usb_storage is active
    Driver Activation Cmd: "modprobe usb_storage"
  Config Status: cfg=new, avail=yes, need=no, active=unknown

Not sure if the USB_DISK_2.0 device file name highlighted above is relevant, probably not.

oldcpu · May 18, 2015, 10:05am

I have a Kingson USB stick that is very slow to mount in GNU/Linux. I would guess closer to 20 to 30 seconds to mount each time. It mounts in MS-Windows-7 a bit faster (maybe 10 seconds or so) albeit it is slower than my other USB sticks in Windows-7.

This USB stick is a small device and it has two ports - one USB for PCs and on the other end a USB for Smartphones/Tablets. It also mounts very slow under Android GNU/Linux (also 20 to 30 seconds to mount).

I am happy with this USB device, but I thought I would note it here in this thread in case there is any similarity to the slow mounting “behaviour” you noted in a different device.

Some outputs (using a USB-3.0 port on my ultrabook):


  530.499709] usb 3-1: new high-speed USB device number 4 using xhci_hcd
  530.670198] usb 3-1: New USB device found, idVendor=0951, idProduct=16a1
  530.670208] usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
  530.670214] usb 3-1: Product: DT microDuo
  530.670218] usb 3-1: Manufacturer: Kingston
  530.670222] usb 3-1: SerialNumber: 50E549C34436BEC029097BA2
  530.703441] usb-storage 3-1:1.0: USB Mass Storage device detected
  530.703560] scsi6 : usb-storage 3-1:1.0
  530.703692] usbcore: registered new interface driver usb-storage
  530.704641] usbcore: registered new interface driver uas
  531.729056] scsi 6:0:0:0: Direct-Access     Kingston DT microDuo      PMAP PQ: 0 ANSI: 4
  531.729431] sd 6:0:0:0: Attached scsi generic sg1 type 0
  542.244089] sd 6:0:0:0: [sdb] 61457664 512-byte logical blocks: (31.4 GB/29.3 GiB)
  542.244328] sd 6:0:0:0: [sdb] Write Protect is off
  542.244336] sd 6:0:0:0: [sdb] Mode Sense: 23 00 00 00
  542.244547] sd 6:0:0:0: [sdb] No Caching mode page found
  542.244552] sd 6:0:0:0: [sdb] Assuming drive cache: write through
  542.269908]  sdb: sdb1
  542.271386] sd 6:0:0:0: [sdb] Attached SCSI removable disk

and


linux-0w6l:/home/oldcpu # hdparm -t /dev/sdb

/dev/sdb:
 Timing buffered disk reads:  60 MB in  3.02 seconds =  19.84 MB/sec

and


oldcpu@linux-0w6l:~> lsusb
Bus 002 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 003: ID 04f2:b369 Chicony Electronics Co., Ltd 
Bus 001 Device 004: ID 8087:07da Intel Corp. 
Bus 001 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 004 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub                      
Bus 003 Device 003: ID 046d:c52f Logitech, Inc. Unifying Receiver                             
**Bus 003 Device 004: ID 0951:16a1 Kingston Technology **
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

and


oldcpu@linux-0w6l:~> hwinfo --usb
02: SCSI 600.0: 10600 Disk                                      
  [Created at block.245]
  Unique ID: KRJj.3nhv4cmf7eC
  SysFS ID: /class/block/sdb
  SysFS BusID: 6:0:0:0
  SysFS Device Link: /devices/pci0000:00/0000:00:14.0/usb3/3-1/3-1:1.0/host6/target6:0:0/6:0:0:0
  Hardware Class: disk
  Model: "Kingston DT microDuo"
  Vendor: usb 0x0951 "Kingston"
  Device: usb 0x16a1 "DT microDuo"
  Revision: "PMAP"
  Serial ID: "50E549C34436BEC029097BA2"
  Driver: "usb-storage", "sd"
  Driver Modules: "usb_storage"
  Device File: /dev/sdb (/dev/sg1)
  Device Files: /dev/sdb, /dev/disk/by-id/scsi-1USB_DISK_2.0, /dev/disk/by-id/scsi-28765432ab567abcd, /dev/disk/by-id/scsi-32000acde48234567, /dev/disk/by-id/scsi-SKingston_DT_microDuo_5B0EEC504299, /dev/disk/by-id/wwn-0x2000acde48234567, /dev/disk/by-path/pci-0000:00:14.0-usb-0:1:1.0-scsi-0:0:0:0
  Device Number: block 8:16-8:31 (char 21:1)
  Speed: 480 Mbps
  Module Alias: "usb:v0951p16A1d0100dc00dsc00dp00ic08isc06ip50in00"
  Driver Info #0:
    Driver Status: uas is active
    Driver Activation Cmd: "modprobe uas"
  Driver Info #1:
    Driver Status: usb_storage is active
    Driver Activation Cmd: "modprobe usb_storage"
  Drive status: no medium
  Config Status: cfg=new, avail=yes, need=no, active=unknown

.

embar · September 10, 2015, 10:01am

Try to downgrade **sg3_utils **to 1.36 version by installing RPM from openSUSE 13.1 repository:
https://software.opensuse.org/package/sg3_utils?search_term=sg3_utils
One-Click-install: https://software.opensuse.org/ymp/openSUSE:13.1:Update/standard/sg3_utils.ymp
Downgrade fixes long delay issue!
P.S. see bug #945094](https://bugzilla.opensuse.org/show_bug.cgi?id=945094)