Hello Alan, > The kernel freezes before the > new log statements, or any others in hub.c, are executed.
Wrong filename there, it's usb.c of course. I've collected debug output from the boot sequence of the bad kernel, with extra entry/exit statements, and of the last good kernel, without the extra statements. Below are excerpts which hopefully catch all relevant lines. Because of its size, I've attached the full output to the bug report that I initially opened against my distribution. The "good" kernel apparently has delays of 4 seconds related to the "Cannot enable" problem. The "bad" kernel has no such problem at all. Any idea how that difference in behavior can be caused by changing the implementation of the workqueue? There are two exit traces without a matching entry trace: [ 2.990519] hub 2-0:1.0: exit [ 17.092630] hub 1-0:1.0: exit I guess the x-0 device init starts at a different function. cheers and thanks, Roland # bad kernel, full output at https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1485057/+attachment/4456918/+files/dmesg.bad.full.txt > grep -i -e 'usb\|hub' # bad kernel [ 2.672184] usb usb2-port4: status 0101, change 0000, 12 Mb/s [ 2.690605] systemd-udevd[105]: seq 1289 queued, 'add' 'usb' [ 2.690662] systemd-udevd[105]: seq 1290 queued, 'add' 'usb' [ 2.771257] usb 2-2-port1: status 0101 change 0001 [ 2.786767] usb 2-4: new high-speed USB device number 3 using xhci_hcd [ 2.842780] usb usb2-port4: not reset yet, waiting 50ms [ 2.878808] hub 2-2:1.0: entry [ 2.878811] hub 2-2:1.0: state 7 ports 4 chg 0002 evt 0000 [ 2.881573] usb 2-2-port1: status 0101, change 0000, 12 Mb/s [ 2.885371] usb 2-2-port1: indicator auto status 0 [ 2.985325] usb 2-4: udev 3, busnum 2, minor = 130 [ 2.985328] usb 2-4: New USB device found, idVendor=04f2, idProduct=b469 [ 2.985330] usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [ 2.985332] usb 2-4: Product: HD WebCam [ 2.985334] usb 2-4: Manufacturer: Chicony Electronics Co.,Ltd. [ 2.985868] systemd-udevd[105]: seq 1294 queued, 'add' 'usb' [ 2.990519] hub 2-0:1.0: exit [ 2.990787] systemd-udevd[119]: handling device node '/dev/bus/usb/002/001', devnum=c189:128, mode=0664, uid=0, gid=0 [ 2.990797] systemd-udevd[119]: set permissions /dev/bus/usb/002/001, 020664, uid=0, gid=0 [ 2.990821] systemd-udevd[119]: creating symlink '/dev/char/189:128' to '../bus/usb/002/001' [ 2.990920] systemd-udevd[119]: created db file '/run/udev/data/c189:128' for '/devices/pci0000:00/0000:00:14.0/usb2' [ 2.991034] systemd-udevd[105]: seq 1296 queued, 'add' 'usb' [ 2.991150] systemd-udevd[119]: no db file to read /run/udev/data/+usb:2-0:1.0: No such file or directory [ 2.991199] systemd-udevd[119]: Execute 'load' 'usb:v1D6Bp0002d0317dc09dsc00dp01ic09isc00ip00in00' [ 2.991244] systemd-udevd[119]: No module matches 'usb:v1D6Bp0002d0317dc09dsc00dp01ic09isc00ip00in00' [ 2.991429] systemd-udevd[123]: IMPORT builtin 'usb_id' /lib/udev/rules.d/50-udev-default.rules:9 [ 2.991618] systemd-udevd[125]: IMPORT builtin 'usb_id' /lib/udev/rules.d/50-udev-default.rules:9 [ 2.991820] systemd-udevd[125]: handling device node '/dev/bus/usb/002/003', devnum=c189:130, mode=0664, uid=0, gid=0 [ 2.991830] systemd-udevd[125]: set permissions /dev/bus/usb/002/003, 020664, uid=0, gid=0 [ 2.991851] systemd-udevd[125]: creating symlink '/dev/char/189:130' to '../bus/usb/002/003' [ 2.991922] systemd-udevd[125]: created db file '/run/udev/data/c189:130' for '/devices/pci0000:00/0000:00:14.0/usb2/2-4' [ 2.992049] systemd-udevd[105]: seq 1297 queued, 'add' 'usb' [ 2.992170] systemd-udevd[119]: no db file to read /run/udev/data/+usb:2-4:1.0: No such file or directory [ 2.992220] systemd-udevd[119]: Execute 'load' 'usb:v04F2pB469d2857dcEFdsc02dp01ic0Eisc01ip00in00' [ 2.992262] systemd-udevd[119]: No module matches 'usb:v04F2pB469d2857dcEFdsc02dp01ic0Eisc01ip00in00' [ 2.992421] systemd-udevd[125]: no db file to read /run/udev/data/+usb:2-4:1.1: No such file or directory [ 2.992468] systemd-udevd[125]: Execute 'load' 'usb:v04F2pB469d2857dcEFdsc02dp01ic0Eisc02ip00in01' [ 2.992508] systemd-udevd[125]: No module matches 'usb:v04F2pB469d2857dcEFdsc02dp01ic0Eisc02ip00in01' [ 3.043577] usb 2-2.1: new full-speed USB device number 4 using xhci_hcd [ 3.133028] usb 2-2.1: udev 4, busnum 2, minor = 131 [ 3.133031] usb 2-2.1: New USB device found, idVendor=04ca, idProduct=300b [ 3.133033] usb 2-2.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 [ 3.133245] systemd-udevd[105]: seq 1309 queued, 'add' 'usb' [ 3.135058] hub 2-2:1.0: exit [ 3.135062] hub 2-2:1.0: entry [ 3.135064] hub 2-2:1.0: state 7 ports 4 chg 0000 evt 0002 [ 3.135685] hub 2-2:1.0: exit [ 3.135872] systemd-udevd[123]: handling device node '/dev/bus/usb/002/002', devnum=c189:129, mode=0664, uid=0, gid=0 [ 3.135882] systemd-udevd[123]: set permissions /dev/bus/usb/002/002, 020664, uid=0, gid=0 [ 3.135904] systemd-udevd[123]: creating symlink '/dev/char/189:129' to '../bus/usb/002/002' [ 3.135986] systemd-udevd[123]: created db file '/run/udev/data/c189:129' for '/devices/pci0000:00/0000:00:14.0/usb2/2-2' [ 3.136565] systemd-udevd[105]: seq 1310 queued, 'add' 'usb' [ 3.136711] systemd-udevd[123]: no db file to read /run/udev/data/+usb:2-2:1.0: No such file or directory [ 3.136763] systemd-udevd[123]: Execute 'load' 'usb:v05E3p0608d8537dc09dsc00dp01ic09isc00ip00in00' [ 3.136809] systemd-udevd[123]: No module matches 'usb:v05E3p0608d8537dc09dsc00dp01ic09isc00ip00in00' [ 3.137418] systemd-udevd[105]: seq 1311 queued, 'add' 'usb' [ 3.137565] systemd-udevd[123]: IMPORT builtin 'usb_id' /lib/udev/rules.d/50-udev-default.rules:9 [ 3.137727] systemd-udevd[123]: handling device node '/dev/bus/usb/002/004', devnum=c189:131, mode=0664, uid=0, gid=0 [ 3.137737] systemd-udevd[123]: set permissions /dev/bus/usb/002/004, 020664, uid=0, gid=0 [ 3.137759] systemd-udevd[123]: creating symlink '/dev/char/189:131' to '../bus/usb/002/004' [ 3.137828] systemd-udevd[123]: created db file '/run/udev/data/c189:131' for '/devices/pci0000:00/0000:00:14.0/usb2/2-2/2-2.1' [ 3.138035] systemd-udevd[123]: no db file to read /run/udev/data/+usb:2-2.1:1.0: No such file or directory [ 3.138083] systemd-udevd[123]: Execute 'load' 'usb:v04CAp300Bd0001dcE0dsc01dp01icE0isc01ip01in00' [ 3.138126] systemd-udevd[123]: No module matches 'usb:v04CAp300Bd0001dcE0dsc01dp01icE0isc01ip01in00' [ 3.138315] systemd-udevd[123]: no db file to read /run/udev/data/+usb:2-2.1:1.1: No such file or directory [ 3.138362] systemd-udevd[123]: Execute 'load' 'usb:v04CAp300Bd0001dcE0dsc01dp01icE0isc01ip01in01' [ 3.138399] systemd-udevd[123]: No module matches 'usb:v04CAp300Bd0001dcE0dsc01dp01icE0isc01ip01in01' [ 16.905066] usb 1-1: new high-speed USB device number 2 using ehci-pci [ 17.090825] usb 1-1: udev 2, busnum 1, minor = 1 [ 17.090828] usb 1-1: New USB device found, idVendor=8087, idProduct=07e6 [ 17.090830] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 [ 17.091240] hub 1-1:1.0: USB hub found [ 17.091442] hub 1-1:1.0: 4 ports detected [ 17.091444] hub 1-1:1.0: standalone hub [ 17.091446] hub 1-1:1.0: individual port power switching [ 17.091448] hub 1-1:1.0: individual port over-current protection [ 17.091449] hub 1-1:1.0: Single TT [ 17.091451] hub 1-1:1.0: TT requires at most 8 FS bit times (666 ns) [ 17.091453] hub 1-1:1.0: power on to power good time: 0ms [ 17.091720] hub 1-1:1.0: local power source is good [ 17.091952] hub 1-1:1.0: enabling power on all ports [ 17.092630] hub 1-0:1.0: exit [ 17.094463] systemd-udevd[124]: handling device node '/dev/bus/usb/001/001', devnum=c189:0, mode=0664, uid=0, gid=0 [ 17.094472] systemd-udevd[124]: set permissions /dev/bus/usb/001/001, 020664, uid=0, gid=0 [ 17.094497] systemd-udevd[124]: creating symlink '/dev/char/189:0' to '../bus/usb/001/001' [ 17.094594] systemd-udevd[124]: created db file '/run/udev/data/c189:0' for '/devices/pci0000:00/0000:00:1d.0/usb1' [ 17.191198] hub 1-1:1.0: entry [ 17.191201] hub 1-1:1.0: state 7 ports 4 chg 0000 evt 0000 [ 17.191204] hub 1-1:1.0: exit [ 17.191211] hub 1-1:1.0: hub_suspend [ 17.193689] usb 1-1: usb auto-suspend, wakeup 1 [ 17.206444] hub 1-0:1.0: hub_suspend [ 32.818801] systemd-journald[206]: no db file to read /run/udev/data/+usb:2-2:1.0: No such file or directory [ 32.818922] systemd-journald[206]: no db file to read /run/udev/data/+usb:2-2:1.0: No such file or directory [ 32.820625] systemd-journald[206]: no db file to read /run/udev/data/+usb:2-0:1.0: No such file or directory [ 32.825511] systemd-journald[206]: no db file to read /run/udev/data/+usb:2-2:1.0: No such file or directory [ 32.825630] systemd-journald[206]: no db file to read /run/udev/data/+usb:2-2:1.0: No such file or directory [ 32.825748] systemd-journald[206]: no db file to read /run/udev/data/+usb:2-2:1.0: No such file or directory [ 32.826205] systemd-journald[206]: no db file to read /run/udev/data/+usb:2-2:1.0: No such file or directory [ 32.835419] systemd-journald[206]: no db file to read /run/udev/data/+usb:1-1:1.0: No such file or directory [ 32.835540] systemd-journald[206]: no db file to read /run/udev/data/+usb:1-1:1.0: No such file or directory [ 32.835660] systemd-journald[206]: no db file to read /run/udev/data/+usb:1-1:1.0: No such file or directory [ 32.835782] systemd-journald[206]: no db file to read /run/udev/data/+usb:1-1:1.0: No such file or directory [ 32.835900] systemd-journald[206]: no db file to read /run/udev/data/+usb:1-1:1.0: No such file or directory [ 32.836018] systemd-journald[206]: no db file to read /run/udev/data/+usb:1-1:1.0: No such file or directory [ 32.836138] systemd-journald[206]: no db file to read /run/udev/data/+usb:1-1:1.0: No such file or directory [ 32.836256] systemd-journald[206]: no db file to read /run/udev/data/+usb:1-1:1.0: No such file or directory [ 32.836379] systemd-journald[206]: no db file to read /run/udev/data/+usb:1-1:1.0: No such file or directory [ 32.836498] systemd-journald[206]: no db file to read /run/udev/data/+usb:1-1:1.0: No such file or directory [ 32.836621] systemd-journald[206]: no db file to read /run/udev/data/+usb:1-0:1.0: No such file or directory [ 32.837077] systemd-journald[206]: no db file to read /run/udev/data/+usb:1-1:1.0: No such file or directory [ 32.837196] systemd-journald[206]: no db file to read /run/udev/data/+usb:1-1:1.0: No such file or directory [ 32.837315] systemd-journald[206]: no db file to read /run/udev/data/+usb:1-1:1.0: No such file or directory [ 32.837433] systemd-journald[206]: no db file to read /run/udev/data/+usb:1-1:1.0: No such file or directory [ 32.837675] systemd-journald[206]: no db file to read /run/udev/data/+usb:1-0:1.0: No such file or directory [ 33.876109] input: HD WebCam as /devices/pci0000:00/0000:00:14.0/usb2/2-4/2-4:1.0/input/input14 [ 33.878566] usbcore: registered new interface driver uvcvideo [ 33.878571] USB Video Class driver (1.1.1) [ 36.840053] usb 2-4: usb auto-suspend, wakeup 0 # good kernel, full output at https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1485057/+attachment/4456919/+files/dmesg.good.full.txt > grep -i -e 'usb\|hub' # good kernel [ 6.072699] usb usb1-port1: Cannot enable. Maybe the USB cable is bad? [ 10.064079] usb usb1-port1: Cannot enable. Maybe the USB cable is bad? [ 14.055325] usb usb1-port1: Cannot enable. Maybe the USB cable is bad? [ 18.046573] usb usb1-port1: Cannot enable. Maybe the USB cable is bad? [ 18.046587] usb usb1-port1: unable to enumerate USB device [ 18.082846] systemd-udevd[124]: handling device node '/dev/bus/usb/001/001', devnum=c189:0, mode=0664, uid=0, gid=0 [ 18.082857] systemd-udevd[124]: set permissions /dev/bus/usb/001/001, 020664, uid=0, gid=0 [ 18.082880] systemd-udevd[124]: creating symlink '/dev/char/189:0' to '../bus/usb/001/001' [ 18.082966] systemd-udevd[124]: created db file '/run/udev/data/c189:0' for '/devices/pci0000:00/0000:00:1d.0/usb1' [ 18.083234] systemd-udevd[117]: no db file to read /run/udev/data/+usb:1-0:1.0: No such file or directory [ 18.083285] systemd-udevd[117]: Execute 'load' 'usb:v1D6Bp0002d0317dc09dsc00dp00ic09isc00ip00in00' [ 18.083332] systemd-udevd[117]: No module matches 'usb:v1D6Bp0002d0317dc09dsc00dp00ic09isc00ip00in00' [ 18.202705] usb 2-2: new high-speed USB device number 2 using xhci_hcd [ 18.386068] usb 2-2: New USB device found, idVendor=05e3, idProduct=0608 [ 18.386070] usb 2-2: New USB device strings: Mfr=0, Product=1, SerialNumber=0 [ 18.386072] usb 2-2: Product: USB2.0 Hub [ 18.386241] systemd-udevd[104]: seq 1307 queued, 'add' 'usb' [ 18.386465] systemd-udevd[117]: IMPORT builtin 'usb_id' /lib/udev/rules.d/50-udev-default.rules:9 [ 18.386640] systemd-udevd[117]: handling device node '/dev/bus/usb/002/002', devnum=c189:129, mode=0664, uid=0, gid=0 [ 18.386649] systemd-udevd[117]: set permissions /dev/bus/usb/002/002, 020664, uid=0, gid=0 [ 18.386705] systemd-udevd[117]: creating symlink '/dev/char/189:129' to '../bus/usb/002/002' [ 18.386776] systemd-udevd[117]: created db file '/run/udev/data/c189:129' for '/devices/pci0000:00/0000:00:14.0/usb2/2-2' [ 18.403740] systemd-udevd[104]: seq 1308 queued, 'add' 'usb' [ 18.403914] systemd-udevd[117]: no db file to read /run/udev/data/+usb:2-2:1.0: No such file or directory [ 18.403965] systemd-udevd[117]: Execute 'load' 'usb:v05E3p0608d8537dc09dsc00dp01ic09isc00ip00in00' [ 18.404009] systemd-udevd[117]: No module matches 'usb:v05E3p0608d8537dc09dsc00dp01ic09isc00ip00in00' [ 18.404110] hub 2-2:1.0: USB hub found [ 18.412472] hub 2-2:1.0: 4 ports detected [ 18.425703] usb: failed to peer 2-2-port1 and usb3-port1 by location (2-2-port1:none) (usb3-port1:usb2-port1) [ 18.425705] usb 2-2-port1: failed to peer to usb3-port1 (-16) [ 18.425706] usb: port power management may be unreliable [ 18.425790] usb: failed to peer 2-2-port2 and usb3-port1 by location (2-2-port2:none) (usb3-port1:usb2-port1) [ 18.425792] usb 2-2-port2: failed to peer to usb3-port1 (-16) [ 18.425875] usb: failed to peer 2-2-port3 and usb3-port1 by location (2-2-port3:none) (usb3-port1:usb2-port1) [ 18.425877] usb 2-2-port3: failed to peer to usb3-port1 (-16) [ 18.425958] usb: failed to peer 2-2-port4 and usb3-port1 by location (2-2-port4:none) (usb3-port1:usb2-port1) [ 18.425960] usb 2-2-port4: failed to peer to usb3-port1 (-16) [ 18.631047] usb 2-4: new high-speed USB device number 3 using xhci_hcd [ 18.884271] usb 2-4: New USB device found, idVendor=04f2, idProduct=b469 [ 18.884273] usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [ 18.884275] usb 2-4: Product: HD WebCam [ 18.884277] usb 2-4: Manufacturer: Chicony Electronics Co.,Ltd. [ 18.884446] systemd-udevd[104]: seq 1309 queued, 'add' 'usb' [ 18.884680] systemd-udevd[117]: IMPORT builtin 'usb_id' /lib/udev/rules.d/50-udev-default.rules:9 [ 18.884883] systemd-udevd[117]: handling device node '/dev/bus/usb/002/003', devnum=c189:130, mode=0664, uid=0, gid=0 [ 18.884892] systemd-udevd[117]: set permissions /dev/bus/usb/002/003, 020664, uid=0, gid=0 [ 18.884913] systemd-udevd[117]: creating symlink '/dev/char/189:130' to '../bus/usb/002/003' [ 18.884992] systemd-udevd[117]: created db file '/run/udev/data/c189:130' for '/devices/pci0000:00/0000:00:14.0/usb2/2-4' [ 18.912171] systemd-udevd[104]: seq 1310 queued, 'add' 'usb' [ 18.912349] systemd-udevd[117]: no db file to read /run/udev/data/+usb:2-4:1.0: No such file or directory [ 18.912401] systemd-udevd[117]: Execute 'load' 'usb:v04F2pB469d2857dcEFdsc02dp01ic0Eisc01ip00in00' [ 18.912447] systemd-udevd[117]: No module matches 'usb:v04F2pB469d2857dcEFdsc02dp01ic0Eisc01ip00in00' [ 18.912648] systemd-udevd[104]: seq 1311 queued, 'add' 'usb' [ 18.912809] systemd-udevd[117]: no db file to read /run/udev/data/+usb:2-4:1.1: No such file or directory [ 18.912857] systemd-udevd[117]: Execute 'load' 'usb:v04F2pB469d2857dcEFdsc02dp01ic0Eisc02ip00in01' [ 18.912894] systemd-udevd[117]: No module matches 'usb:v04F2pB469d2857dcEFdsc02dp01ic0Eisc02ip00in01' [ 19.026822] usb 2-2.1: new full-speed USB device number 4 using xhci_hcd [ 19.182849] usb 2-2.1: New USB device found, idVendor=04ca, idProduct=300b [ 19.182852] usb 2-2.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0 [ 19.183061] systemd-udevd[104]: seq 1312 queued, 'add' 'usb' [ 19.183279] systemd-udevd[117]: IMPORT builtin 'usb_id' /lib/udev/rules.d/50-udev-default.rules:9 [ 19.183482] systemd-udevd[117]: handling device node '/dev/bus/usb/002/004', devnum=c189:131, mode=0664, uid=0, gid=0 [ 19.183491] systemd-udevd[117]: set permissions /dev/bus/usb/002/004, 020664, uid=0, gid=0 [ 19.183513] systemd-udevd[117]: creating symlink '/dev/char/189:131' to '../bus/usb/002/004' [ 19.183584] systemd-udevd[117]: created db file '/run/udev/data/c189:131' for '/devices/pci0000:00/0000:00:14.0/usb2/2-2/2-2.1' [ 19.201946] systemd-udevd[104]: seq 1313 queued, 'add' 'usb' [ 19.202045] systemd-udevd[104]: seq 1314 queued, 'add' 'usb' [ 19.202231] systemd-udevd[118]: no db file to read /run/udev/data/+usb:2-2.1:1.1: No such file or directory [ 19.202284] systemd-udevd[118]: Execute 'load' 'usb:v04CAp300Bd0001dcE0dsc01dp01icE0isc01ip01in01' [ 19.202332] systemd-udevd[118]: No module matches 'usb:v04CAp300Bd0001dcE0dsc01dp01icE0isc01ip01in01' [ 19.202518] systemd-udevd[117]: no db file to read /run/udev/data/+usb:2-2.1:1.0: No such file or directory [ 19.202566] systemd-udevd[117]: Execute 'load' 'usb:v04CAp300Bd0001dcE0dsc01dp01icE0isc01ip01in00' [ 19.202607] systemd-udevd[117]: No module matches 'usb:v04CAp300Bd0001dcE0dsc01dp01icE0isc01ip01in00' [ 38.415510] systemd-journald[237]: no db file to read /run/udev/data/+usb:2-2:1.0: No such file or directory [ 38.415677] systemd-journald[237]: no db file to read /run/udev/data/+usb:2-2:1.0: No such file or directory [ 39.132541] input: HD WebCam as /devices/pci0000:00/0000:00:14.0/usb2/2-4/2-4:1.0/input/input13 [ 39.132654] usbcore: registered new interface driver uvcvideo [ 39.132657] USB Video Class driver (1.1.1) -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
