in openSUSE 13.1 plug and un-plug

#dmesg

[ 1909.199566] usb 4-2: new SuperSpeed USB device number 3 using xhci_hcd
[ 1909.309961] usb 4-2: New USB device found, idVendor=0951, idProduct=1666
[ 1909.309971] usb 4-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1909.309977] usb 4-2: Product: DataTraveler 3.0
[ 1909.309981] usb 4-2: Manufacturer: Kingston
[ 1909.309985] usb 4-2: SerialNumber: 60A44C413B99BF611998453E
[ 1909.311712] usb-storage 4-2:1.0: USB Mass Storage device detected
[ 1909.311844] scsi6 : usb-storage 4-2:1.0
[ 1910.380363] scsi 6:0:0:0: Direct-Access     Kingston DataTraveler 3.0 PMAP PQ: 0 ANSI: 6
[ 1910.380875] sd 6:0:0:0: Attached scsi generic sg3 type 0
[ 1911.323502] sd 6:0:0:0: [sdd] 30728832 512-byte logical blocks: (15.7 GB/14.6 GiB)
[ 1911.324026] sd 6:0:0:0: [sdd] Write Protect is off
[ 1911.324029] sd 6:0:0:0: [sdd] Mode Sense: 23 00 00 00
[ 1911.324518] sd 6:0:0:0: [sdd] No Caching mode page found
[ 1911.324520] sd 6:0:0:0: [sdd] Assuming drive cache: write through
[ 1911.327540] sd 6:0:0:0: [sdd] No Caching mode page found
[ 1911.327542] sd 6:0:0:0: [sdd] Assuming drive cache: write through
[ 1911.350882]  sdd: sdd1
[ 1911.355631] sd 6:0:0:0: [sdd] No Caching mode page found
[ 1911.355634] sd 6:0:0:0: [sdd] Assuming drive cache: write through
[ 1911.355636] sd 6:0:0:0: [sdd] Attached SCSI removable disk
[ 1918.886241] usb 4-2: USB disconnect, device number 3
[ 1918.889872] usb 4-2: Set SEL for device-initiated U1 failed.
[ 1918.889885] usb 4-2: Set SEL for device-initiated U2 failed.

The same device in Tumbleweed:

# lsusb
...
Bus 004 Device 002: ID 0951:1666 Kingston Technology DataTraveler G4

(But this device is not G4, it is G3: DataTraveler 100 G3)


# hwinfo --usb
03: SCSI 200.0: 10600 Disk                                      
  [Created at block.245]
  Unique ID: rg_L.qGiClTgtDkA
  SysFS ID: /class/block/sdc
  SysFS BusID: 2:0:0:0
  SysFS Device Link: /devices/pci0000:00/0000:00:14.0/usb4/4-2/4-2:1.0/host2/target2:0:0/2:0:0:0
  Hardware Class: disk
  Model: "Kingston DataTraveler 3.0"
  Vendor: usb 0x0951 "Kingston"
  Device: usb 0x1666 "DataTraveler 3.0"
  Revision: "PMAP"
  Serial ID: "6B0FA64141C9"
  Driver: "usb-storage", "sd"
  Driver Modules: "usb_storage"
  Device File: /dev/sdc (/dev/sg2)
  Device Files: /dev/sdc, /dev/disk/by-id/scsi-1USB_DISK_2.0, /dev/disk/by-id/scsi-28765432ab567abcd, /dev/disk/by-id/scsi-3, /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:32-8:47 (char 21:2)
  Geometry (Logical): CHS 15004/64/32
  Size: 30728832 sectors a 512 bytes
  Capacity: 14 GB (15733161984 bytes)
  Module Alias: "usb:v0951p1666d0100dc00dsc00dp00ic08isc06ip50in00"
  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"
  Config Status: cfg=new, avail=yes, need=no, active=unknown


# hdparm -I /dev/sdc

/dev/sdc:
SG_IO: bad/missing sense data, sb[]:  70 00 05 00 00 00 00 0a 00 00 00 00 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

ATA device, with non-removable media
        Model Number:       ��H�{���b@y���B@$���2�$����@z�
        Serial Number:      �������4�$���
        Firmware Revision:  �����
        Media Serial Num:   7$���j�$�������������2�����
Standards:
        Used: unknown (minor revision code 0x1024) 
        Supported: 14 10 9 6 
        Likely used: 14
Configuration:
        Logical         max     current
        cylinders       0       59904
        heads           0       65535
        sectors/track   510     60096
        --
        CHS current addressable sectors: 3925872671
        Logical/Physical Sector size:           512 bytes
        device size with M = 1024*1024:     1916930 MBytes
        device size with M = 1000*1000:     2010046 MBytes (2010 GB)
        cache/buffer size  = unknown
Capabilities:
        IORDY(may be)(cannot be disabled)
        Queue depth: 32
        Standby timer values: spec'd by Vendor
        R/W multiple sector transfer: Max = 255 Current = 255
        Recommended acoustic management value: 234, current value: 0
        DMA: not supported
        PIO: pio0 pio1 pio2 
             Cycle time: no flow control=65535ns  IORDY flow control=61312ns
           *    reserved 69[0]
           *    reserved 69[1]
           *    reserved 69[2]
           *    reserved 69[3]
           *    reserved 69[4]
           *    DEVICE CONFIGURATION SET/IDENTIFY DMA commands
           *    Data Set Management TRIM supported (limit 4132 blocks)
Integrity word not set (found 0x0000, expected 0x0da5)


[   86.251268] usb 3-2: new high-speed USB device number 3 using xhci_hcd
[   86.533456] usb 4-2: new SuperSpeed USB device number 2 using xhci_hcd
[   86.643134] usb 4-2: New USB device found, idVendor=0951, idProduct=1666
[   86.643138] usb 4-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[   86.643140] usb 4-2: Product: DataTraveler 3.0
[   86.643142] usb 4-2: Manufacturer: Kingston
[   86.643143] usb 4-2: SerialNumber: 60A44C413B99BF611998453E
[   86.855727] usb-storage 4-2:1.0: USB Mass Storage device detected
[   86.855811] scsi host2: usb-storage 4-2:1.0
[   86.856514] usbcore: registered new interface driver usb-storage
[   86.859110] usbcore: registered new interface driver uas
[   87.925130] scsi 2:0:0:0: Direct-Access     Kingston DataTraveler 3.0 PMAP PQ: 0 ANSI: 6
[   87.925520] sd 2:0:0:0: Attached scsi generic sg2 type 0
[   88.868563] sd 2:0:0:0: [sdc] 30728832 512-byte logical blocks: (15.7 GB/14.6 GiB)
[   88.869024] sd 2:0:0:0: [sdc] Write Protect is off
[   88.869027] sd 2:0:0:0: [sdc] Mode Sense: 23 00 00 00
[   88.869483] sd 2:0:0:0: [sdc] No Caching mode page found
[   88.869486] sd 2:0:0:0: [sdc] Assuming drive cache: write through
[   88.894861]  sdc: sdc1
[   88.896621] sd 2:0:0:0: [sdc] Attached SCSI removable disk
<-- delay of 61 seconds -->
[  149.940709] usb 4-2: reset SuperSpeed USB device number 2 using xhci_hcd

(last block was from dmesg)

Found, that after pluging USB-key, starts new processes: 

systemd-udevd (4 instances!)
scsi_eh_13
scsi_tmf_13
usb-storage
sg_inq

"sg_inq" and "usb-storage" are sleeping in disk for a minute.
When sg_inq automatically terminates, USB device is notified in desktop.
When all 4 instances of "systemd-udevd" terminates also.

sg_inq is running as `/usr/bin/sg_inq --export --page=sn /dev/sdc`

Found, that /usr/bin/sg_inq exist in "sg3_utils" package.

In openSUSE TW:
> rpm -q sg3_utils
sg3_utils-1.41-1.1.x86_64

In openSUSE 13.1:
> rpm -q sg3_utils
sg3_utils-1.36-3.4.1.i586

After downgrading sg3_utils version to 1.36 (RPM openSUSE 13.1 repo) fixed  lond delay issue just after downgrading.

What does 'sg_vpd -p 0x0 /dev/sdX' for that device say?

Do you incur a delay during executing that?

With sg3_utils-1.41-1.1.x86_64

# sg_vpd -p 0x0 /dev/sdc
Supported VPD pages VPD page:
invalid VPD response; probably a STANDARD INQUIRY response
fetching VPD page failed: Malformed response

Yes, there is long delay to show response.

But with sg3_utils-1.36-3.1.2.x86_64 from oS 13.1 no delay:

# sg_vpd -p 0x0 /dev/sdc
Supported VPD pages VPD page:
invalid VPD response; probably a STANDARD INQUIRY response
fetching VPD page failed

Then executing without -p parameters:

# sg_inq  /dev/sdc
standard INQUIRY:
  PQual=0  Device_type=0  RMB=1  LU_CONG=0  version=0x06  [SPC-4]
  [AERC=0]  [TrmTsk=0]  NormACA=0  HiSUP=0  Resp_data_format=2
  SCCS=0  ACC=0  TPGS=0  3PC=0  Protect=0  [BQue=0]
  EncServ=0  MultiP=0  [MChngr=0]  [ACKREQQ=0]  Addr16=0
  [RelAdr=0]  WBus16=0  Sync=0  [Linked=0]  [TranDis=0]  CmdQue=0
    length=36 (0x24)   Peripheral device type: disk
 Vendor identification: Kingston
 Product identification: DataTraveler 3.0
 Product revision level: PMAP
 Unit serial number: 6B0FA64141C9

Can you please try

'strace sg_vpd -p 0x0 -v -v -v /dev/sdX'

with both the 13.2 and 13.1 version?
And attach the output here, of course :-)

Created attachment 652049 [details]
strace sg_vpd -p 0x0 -v -v -v /dev/sdc # with sg3_utils-1.41-1.1.x86_64 from openSUSE TW

Created attachment 652055 [details]
strace sg_vpd -p 0x0 -v -v -v /dev/sdc # with sg3_utils-1.41-1.1.x86_64 from openSUSE TW - just plugged USB flash

In openSUSE TumbleWeed,
After just pluging, and executing, it makes long pause after printing:

open("/dev/sdc", O_RDONLY|O_NONBLOCK

Created attachment 652058 [details]
strace sg_vpd -p 0x0 -v -v -v /dev/sdc # with sg3_utils-1.36-3.1.2.x86_64 from openSUSE 13.1

(In reply to Mindaugas Baranauskas from comment #11)
> 
> In openSUSE TumbleWeed,
> After just pluging, and executing, it makes long pause after printing:
> 
> open("/dev/sdc", O_RDONLY|O_NONBLOCK

So that means the open syscall takes the time.
You tried the different sg3utils variants under different openSUSE versions, which makes me think the change of kernel version is the cause, not sg3utils.

All tests today is with openSUSE TW with 4.2.1-1-desktop kernel.
I changed only version of sg3_utils.

In openSUSE TW with sg3_utils 1.41 'sg_vpd -p 0x0 /dev/sdX' takes no time, if is executed after displaying USB flash in desktop; but may take minute if executed before showing in desktop.

`/usr/bin/sg_inq --export --page=sn /dev/sdc` takes _always_ a minute with sg3_utils 1.41: both before and after showing device in dekstop.

I.e. attachment labeled "with sg3_utils-1.36-3.1.2.x86_64 from openSUSE 13.1" means _package_ is from openSUSE 13.1, but running system always was same openSUSE Tumbleweed (20151012) (x86_64)

Of course, the whole issue becomes even more pointed as we're having the same information provided for in sysfs; so actually there's no need to call sg_inq in the first place ...

Created attachment 652287 [details]
55-scsi-sg3_id.rules

Updated 55-scsi-sg3_id.rules

Can you try to copy the above rules file into /usr/lib/udev/rules.d, re-run mkinitrd and reboot?

OK, changed /usr/lib/udev/rules.d/55-scsi-sg3_id.rules, run mkinitrd, rebooted.
USB flash still takes minute to show-up.

What information do you need more?

Can you post the message log here?

Like the output of

journalctl --output short-monotonic -xm

?

Created attachment 652407 [details]
short log using sg3_utils-1.41

Created attachment 652410 [details]
short log using sg3_utils-1.36

Hmm. Just figured that the updates udev rules file won't help, as the device doesn't support VPD pages.

Oliver, the more I look into it the more I've got the feeling that USB keels over here. Is there a way of enabling USB debugging here so see what's going on?

(In reply to Hannes Reinecke from comment #25)
> Oliver, the more I look into it the more I've got the feeling that USB keels
> over here. Is there a way of enabling USB debugging here so see what's going
> on?

A kernel compiled with CONFIG_USB_STORAGE_DEBUG. Our debug flavor has that.

I installed kernel-debug and booted with this kernel.
Seems it is somehow broken: takes very long time to boot, some endless cyclic messages about failed services to run...

Created attachment 658642 [details]
journalctl output from openSUSE 42.1 booted via kernel-debug

I don't know, if this is that you want (please instruct me).
I installed kernel-debug. It still seems not very usable – I can not even login with root user in console. But after several minutes waiting from begining of booting, I inserted USB key into conputer; I attach log.

Seems this point is deterction of USB key:

Grd 08 07:51:14 linux-ro0f kernel: usb 1-1.2: New USB device found, idVendor=0951, idProduct=1666

Reset of USB key after one minute:

Grd 08 07:52:25 linux-ro0f.suse kernel: usb 1-1.2: reset high-speed USB device number 3 using ehci-pci

(openSUSE Leap 42.1 use sg3_utils-1.41-6.1.x86_64 is affected also)

Does exist other options for testing without running kernel -debug flavour?

Same problem exists on Leap, tested with Sony PMAP 16GB USB 3.0 stick on old Toshiba laptop. Downgrading sg3_utils fixed problem, but this does not seem to be right solution...

(In reply to Jiří Novák from comment #30)
> Same problem exists on Leap, tested with Sony PMAP 16GB USB 3.0 stick on old
> Toshiba laptop. Downgrading sg3_utils fixed problem, but this does not seem
> to be right solution...

Most likely the device gets a request for a VPD page that it does not like and chokes. If you use the debug flavour you can learn which request that is. Alternatively a usbmon trace can be used to find out the command.

That, however, does not help all that much. You just should not ask such commands directly from the devices. The SCSI layer is nice enough enough to cache the answers and provide them in sysfs. Use that.
The real culprit is some udev rule.

Created attachment 674902 [details]
0001-sg_vpd-sg_inq-Safe-VPD-page-access.patch

sg_vpd, sg_inq: Safe VPD page access

I've just checked sg3_utils, and we indeed do not check if the requested VPD pages are present. Should be fixed with the above patch.

Can you try and see if it makes a difference?

An updated rpm can be found at

build.opensuse.org home:hreinecke:branches:Base:System/sg3_utils

Please test and report the results.

(In reply to Hannes Reinecke from comment #34)
> An updated rpm can be found at
> 
> build.opensuse.org home:hreinecke:branches:Base:System/sg3_utils
> 
> Please test and report the results.

I would love to test it, but repo/package is 404 on download.opensuse.org...
JN

I just installed into openSUSE_13.2 RPMs from home:hreinecke:branches:Base:System / sg3_utils
(https://build.opensuse.org/package/binaries/home:hreinecke:branches:Base:System/sg3_utils?repository=openSUSE_13.2 and logging with openSUSE account):
libsgutils2-1_42-2-1.42-72.1.x86_64.rpm 
sg3_utils-1.42-72.1.x86_64.rpm

Previous problematic Kingston DataTraveler 100 G3 recognized without minute delay.
So patch WORKS NICE!

(In reply to Jiří Novák from comment #35)

> I would love to test it, but repo/package is 404 on download.opensuse.org...
> JN

As work around:
1. Go https://build.opensuse.org/package/show?project=home:hreinecke:branches:Base:System&package=sg3_utils
2. Login with openSUSE account
3. Select your openSUSE version, e.g. for Leap https://build.opensuse.org/package/binaries/home:hreinecke:branches:Base:System/sg3_utils?repository=openSUSE_Leap_42.1
4. Press link on libsgutils2, press link in new page (at "Detailed Information About libsgutils2...") 
5. Install package by ignoring signature check
6. Do 4-5 steps with sg3_utils RPM

(In reply to Mindaugas Baranauskas from comment #37)
> (In reply to Jiří Novák from comment #35)
> 
> > I would love to test it, but repo/package is 404 on download.opensuse.org...
> > JN
> 
> As work around:
> 1. Go
> https://build.opensuse.org/package/show?project=home:hreinecke:branches:Base:
> System&package=sg3_utils
> 2. Login with openSUSE account
> 3. Select your openSUSE version, e.g. for Leap
> https://build.opensuse.org/package/binaries/home:hreinecke:branches:Base:
> System/sg3_utils?repository=openSUSE_Leap_42.1
> 4. Press link on libsgutils2, press link in new page (at "Detailed
> Information About libsgutils2...") 
> 5. Install package by ignoring signature check
> 6. Do 4-5 steps with sg3_utils RPM

ah, got it... :)
wth updated packages works like a charm on the Leap machine, no more minute wait...
JN

I've updated sg3_utils to version 1.43 which includes this patch.

I hope updated sg3_utils will arrive via online updates for oS 13.2 and Leap 42.1

Please provide maintenance update for 13.2/42.1!