Bug 93681

Summary: Ongoing USB enumeration with xhci_hcd
Product: Drivers Reporter: Malte Vesper (m_v_)
Component: USBAssignee: Greg Kroah-Hartman (greg)
Status: NEW ---    
Severity: normal CC: m_v_
Priority: P1    
Hardware: x86-64   
OS: Linux   
Kernel Version: 3.19.0 Subsystem:
Regression: No Bisected commit-id:
Attachments: full dmesg output
full lsusb -v output

Description Malte Vesper 2015-02-23 12:35:08 UTC
After the 3.13 Kernel series I experience that it can take an arbitrary amount of time/retries to identify the USB devices in my system. The issue became apparent when I could not start my new kernel most of the times because the usb Keyboard did not work.

Attaching the USB Keyboard to a non USB 3.0 port works arround the problem, however devices on USB 3.0 ports only become available after the initialization completes.

Here are some exceprts from dmesg:

After Booting I keep getting lots of messages like this:

[   41.555160] usb 1-1: new high-speed USB device number 100 using xhci_hcd
[   41.963154] usb 1-1: new high-speed USB device number 101 using xhci_hcd
[   42.371151] usb 1-1: new high-speed USB device number 102 using xhci_hcd
[   42.779141] usb 1-1: new high-speed USB device number 103 using xhci_hcd
[   43.187135] usb 1-1: new high-speed USB device number 104 using xhci_hcd
[   43.595129] usb 1-1: new high-speed USB device number 105 using xhci_hcd
[   44.003159] usb 1-1: new high-speed USB device number 106 using xhci_hcd
[   44.411153] usb 1-1: new high-speed USB device number 107 using xhci_hcd
[   44.767817] usbcore: registered new interface driver ftdi_sio
[   44.767831] usbserial: USB Serial support registered for FTDI USB Serial Device
[   44.767886] ftdi_sio 5-1:1.0: FTDI USB Serial Device converter detected
[   44.767911] usb 5-1: Detected FT2232H
[   44.768038] usb 5-1: FTDI USB Serial Device converter now attached to ttyUSB1
[   44.768052] ftdi_sio 5-1:1.1: FTDI USB Serial Device converter detected
[   44.768074] usb 5-1: Detected FT2232H
[   44.768182] usb 5-1: FTDI USB Serial Device converter now attached to ttyUSB2
[   44.819116] usb 1-1: new high-speed USB device number 108 using xhci_hcd
[   45.227157] usb 1-1: new high-speed USB device number 109 using xhci_hcd
[   45.635144] usb 1-1: new high-speed USB device number 110 using xhci_hcd
[   46.043128] usb 1-1: new high-speed USB device number 111 using xhci_hcd
[   46.451087] usb 1-1: new high-speed USB device number 112 using xhci_hcd
[   46.859074] usb 1-1: new high-speed USB device number 113 using xhci_hcd
[   47.267075] usb 1-1: new high-speed USB device number 114 using xhci_hcd
[   47.675069] usb 1-1: new high-speed USB device number 115 using xhci_hcd
[   48.083111] usb 1-1: new high-speed USB device number 116 using xhci_hcd
[   48.491090] usb 1-1: new high-speed USB device number 117 using xhci_hcd
[   48.899097] usb 1-1: new high-speed USB device number 118 using xhci_hcd
[   49.307080] usb 1-1: new high-speed USB device number 119 using xhci_hcd
[   49.715035] usb 1-1: new high-speed USB device number 120 using xhci_hcd
[   50.123067] usb 1-1: new high-speed USB device number 121 using xhci_hcd
[   50.531058] usb 1-1: new high-speed USB device number 122 using xhci_hcd
[   50.939053] usb 1-1: new high-speed USB device number 123 using xhci_hcd
[   51.347046] usb 1-1: new high-speed USB device number 124 using xhci_hcd
[   51.755041] usb 1-1: new high-speed USB device number 125 using xhci_hcd
[   52.162998] usb 1-1: new high-speed USB device number 126 using xhci_hcd
[   52.571026] usb 1-1: new high-speed USB device number 127 using xhci_hcd
[   52.979031] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[   53.387013] usb 1-1: new high-speed USB device number 3 using xhci_hcd



this can go on for a very long time (notice that it keeps wrapping arround at 127)

After a while the driver manages to identify the device, this is noted by the following dmesg output:

[ 1568.711670] usb 1-1: new high-speed USB device number 63 using xhci_hcd
[ 1569.119632] usb 1-1: new high-speed USB device number 64 using xhci_hcd
[ 1569.527617] usb 1-1: new high-speed USB device number 65 using xhci_hcd
[ 1569.713176] usb 1-1: New USB device found, idVendor=174c, idProduct=2074
[ 1569.713179] usb 1-1: New USB device strings: Mfr=2, Product=3, SerialNumber=0
[ 1569.713180] usb 1-1: Product: ASM107x
[ 1569.713181] usb 1-1: Manufacturer: ASUS Tek.
[ 1569.714489] hub 1-1:1.0: USB hub found
[ 1569.714634] hub 1-1:1.0: 4 ports detected
[ 1570.003698] usb 1-1.3: new full-speed USB device number 66 using xhci_hcd
[ 1570.135094] usb 1-1.3: New USB device found, idVendor=1395, idProduct=1000
[ 1570.135096] usb 1-1.3: New USB device strings: Mfr=3, Product=1, SerialNumber=0
[ 1570.135098] usb 1-1.3: Product: Sennheiser 3D G4ME1
[ 1570.135099] usb 1-1.3: Manufacturer: Sennheiser
[ 1570.136884] input: Sennheiser Sennheiser 3D G4ME1 as /devices/pci0000:00/0000:00:1c.1/0000:07:00.0/usb1/1-1/1-1.3/1-1.3:1.3/0003:1395:1000.0004/input/input16
[ 1570.191662] hid-generic 0003:1395:1000.0004: input,hidraw3: USB HID v1.00 Device [Sennheiser Sennheiser 3D G4ME1] on usb-0000:07:00.0-1.3/input3
[ 1570.248947] usbcore: registered new interface driver snd-usb-audio


lsusb after completing init:

Bus 008 Device 004: ID 045e:00db Microsoft Corp. Natural Ergonomic Keyboard 4000 V1.0
Bus 008 Device 003: ID 0461:4d22 Primax Electronics, Ltd 
Bus 008 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
Bus 008 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 006 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 005 Device 003: ID 10c4:ea60 Cygnal Integrated Products, Inc. CP210x UART Bridge / myAVR mySmartUSB light
Bus 005 Device 002: ID 0403:6010 Future Technology Devices International, Ltd FT2232C Dual USB-UART/FIFO IC
Bus 005 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 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 002: ID 174c:3074 ASMedia Technology Inc. 
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 066: ID 1395:1000 Sennheiser Communications 
Bus 001 Device 065: ID 174c:2074 ASMedia Technology Inc. 
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 007 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
Bus 007 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

lsmod:

Module                  Size  Used by
snd_usb_audio         168623  3 
snd_usbmidi_lib        29904  1 snd_usb_audio
ftdi_sio               48695  0 
nfsv3                  34919  1 
rpcsec_gss_krb5        31250  0 
nfsv4                 262989  0 
vmw_vsock_vmci_transport    26279  0 
vsock                  33698  1 vmw_vsock_vmci_transport
vmw_vmci               61345  1 vmw_vsock_vmci_transport
autofs4                38800  3 
snd_hda_codec_realtek    75040  1 
snd_hda_codec_generic    67623  1 snd_hda_codec_realtek
snd_hda_codec_hdmi     47820  1 
snd_hda_intel          30148  5 
snd_hda_controller     29344  1 snd_hda_intel
snd_hda_codec         115577  5 snd_hda_codec_realtek,snd_hda_codec_hdmi,snd_hda_codec_generic,snd_hda_intel,snd_hda_controller
x86_pkg_temp_thermal    14205  0 
intel_powerclamp       18823  0 
snd_pcm               101238  6 snd_usb_audio,snd_hda_codec_hdmi,snd_hda_codec,snd_hda_intel,snd_hda_controller
coretemp               13441  0 
kvm_intel             144302  0 
kvm                   325173  1 kvm_intel
snd_hwdep              13554  2 snd_usb_audio,snd_hda_codec
snd_seq_midi           13564  0 
snd_seq_midi_event     14436  1 snd_seq_midi
mxm_wmi                12865  0 
snd_rawmidi            29563  2 snd_usbmidi_lib,snd_seq_midi
sb_edac                26894  0 
snd_seq                62266  2 snd_seq_midi_event,snd_seq_midi
serio_raw              13483  0 
edac_core              51983  1 sb_edac
joydev                 17393  0 
snd_timer              28827  2 snd_pcm,snd_seq
mei_me                 19659  0 
snd_seq_device         14461  3 snd_seq,snd_rawmidi,snd_seq_midi
snd                    70264  28 snd_hda_codec_realtek,snd_usb_audio,snd_hwdep,snd_timer,snd_hda_codec_hdmi,snd_pcm,snd_seq,snd_rawmidi,snd_hda_codec_generic,snd_usbmidi_lib,snd_hda_codec,snd_hda_intel,snd_seq_device
mei                    82807  1 mei_me
lpc_ich                21093  0 
shpchp                 37047  0 
soundcore              12634  2 snd,snd_hda_codec
nfsd                  276736  2 
tpm_infineon           17131  0 
auth_rpcgss            58468  2 nfsd,rpcsec_gss_krb5
bnep                   19484  2 
rfcomm                 69371  4 
nfs_acl                12741  2 nfsd,nfsv3
bluetooth             465648  10 bnep,rfcomm
nfs                   167318  3 nfsv3,nfsv4
wmi                    18820  1 mxm_wmi
lockd                  88645  3 nfs,nfsd,nfsv3
grace                  13036  2 nfsd,lockd
sunrpc                253461  22 nfs,nfsd,rpcsec_gss_krb5,auth_rpcgss,lockd,nfsv3,nfsv4,nfs_acl
cp210x                 23485  0 
usbserial              43649  2 cp210x,ftdi_sio
fscache                53027  2 nfs,nfsv4
binfmt_misc            18035  1 
nls_iso8859_1          12713  1 
dm_crypt               23073  1 
hid_microsoft          12817  0 
hid_generic            12559  0 
usbhid                 52511  0 
hid                   108158  3 hid_generic,hid_microsoft,usbhid
radeon               1640544  3 
i2c_algo_bit           13257  1 radeon
drm_kms_helper        106928  1 radeon
ttm                    84664  1 radeon
drm                   295044  6 ttm,drm_kms_helper,radeon
crct10dif_pclmul       14307  0 
crc32_pclmul           13133  0 
e1000e                221900  0 
ghash_clmulni_intel    13230  0 
aesni_intel           169551  1943 
aes_x86_64             17017  1 aesni_intel
glue_helper            13584  1 aesni_intel
lrw                    13115  1 aesni_intel
psmouse               111607  0 
gf128mul               14332  1 lrw
ablk_helper            13268  1 aesni_intel
cryptd                 19792  974 ghash_clmulni_intel,aesni_intel,ablk_helper
aacraid                95469  0 
ptp                    19140  1 e1000e
ahci                   29923  3 
pps_core               19149  1 ptp
libahci                30915  1 ahci

Should the kernelconfiguration help, or should you have a specific kernelconfig/version you would like me to try let me know
Comment 1 Malte Vesper 2015-02-23 12:38:04 UTC
Created attachment 168001 [details]
full dmesg output
Comment 2 Malte Vesper 2015-02-23 12:47:42 UTC
Created attachment 168011 [details]
full lsusb -v output
Comment 3 Greg Kroah-Hartman 2015-02-23 15:26:05 UTC
On Mon, Feb 23, 2015 at 12:35:08PM +0000, bugzilla-daemon@bugzilla.kernel.org wrote:
> https://bugzilla.kernel.org/show_bug.cgi?id=93681
> 
>             Bug ID: 93681
>            Summary: Ongoing USB enumeration with xhci_hcd

Please send to the linux-usb@vger.kernel.org mailing list.