New issue
Advanced search Search tips

Issue 692260 link

Starred by 2 users

Issue metadata

Status: Assigned
Owner:
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 3
Type: Bug



Sign in to add a comment

repeated bind/unbind of USB hub borks the driver

Project Member Reported by semenzato@chromium.org, Feb 14 2017

Issue description

I ran this test:

# while true; do sleep 10; echo unbind; echo "1-0:1.0" > /sys/bus/usb/drivers/hub/unbind; sleep 5; echo bind;  echo "1-0:1.0" > /sys/bus/usb/drivers/hub/bind; done

After between 13 and 25 iterations, the bind fails:

# echo bind;  echo "1-0:1.0" > /sys/bus/usb/drivers/hub/bind
-bash: echo: write error: No such device

One time there was a kernel panic shortly afterwards.  However, the panic is not repeatable

[  435.276681] usb 1-1: USB disconnect, device number 56
[  435.278400] asix 1-1:1.0 eth0: unregister 'asix' usb-0000:00:14.0-1, ASIX AX88772 USB 2.0 Ethernet
[  435.305957] usb 1-4: USB disconnect, device number 57
[  435.307104] usb 1-5: USB disconnect, device number 58
[  440.355119] hub 1-0:1.0: USB hub found
[  440.355192] hub 1-0:1.0: 7 ports detected
[  440.356904] platform vpd: Driver vpd requests probe deferral
[  440.456676] xhci_hcd 0000:00:14.0: Command completion event does not match command
[  514.514049] init: dptf main process (5996) killed by ABRT signal
[  514.514100] init: dptf main process ended, respawning
[  600.086901] INFO: task bash:3537 blocked for more than 120 seconds.
[  600.086946]       Tainted: G        W      3.18.0-13690-g5008f19 #1
[  600.086968] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  600.086992] bash            D 0000000000000001     0  3537   3334 0x00000000
[  600.087035]  ffff880059193d98 0000000000000086 ffff880059193da8 ffff88007979f6a0
[  600.087081]  ffff880059193fd8 ffff880078db36c0 0000000000013500 ffff880078db36c0
[  600.087121]  0000000000007f7f ffff880078c798f0 ffff880078c798f8 ffff880078db36c0
[  600.087163] Call Trace:
[  600.087207]  [<ffffffffb129ed8b>] schedule+0x69/0x6b
[  600.087241]  [<ffffffffb129f042>] schedule_preempt_disabled+0x16/0x20
[  600.087274]  [<ffffffffb12a040f>] __mutex_lock_slowpath+0xba/0x13f
[  600.087305]  [<ffffffffb12a04c2>] mutex_lock+0x2e/0x3f
[  600.087411]  [<ffffffffb0ffb767>] unbind_store+0x5d/0x98
[  600.087445]  [<ffffffffb0ffa938>] drv_attr_store+0x2c/0x2e
[  600.087478]  [<ffffffffb0dad655>] sysfs_kf_write+0x39/0x3b
[  600.087511]  [<ffffffffb0dac8f9>] kernfs_fop_write+0xf0/0x127
[  600.087548]  [<ffffffffb0d52043>] vfs_write+0xb0/0xf5
[  600.087580]  [<ffffffffb0d526a1>] SyS_write+0x5d/0x9f
[  600.087630]  [<ffffffffb12a20dc>] system_call_fastpath+0x1c/0x21
[  600.087672]   task                        PC stack   pid father
[  600.087789] bash            D 0000000000000001     0  3537   3334 0x00000000
[  600.087848]  ffff880059193d98 0000000000000086 ffff880059193da8 ffff88007979f6a0
[  600.087894]  ffff880059193fd8 ffff880078db36c0 0000000000013500 ffff880078db36c0
[  600.087939]  0000000000007f7f ffff880078c798f0 ffff880078c798f8 ffff880078db36c0
[  600.087983] Call Trace:
[  600.088012]  [<ffffffffb129ed8b>] schedule+0x69/0x6b
[  600.088042]  [<ffffffffb129f042>] schedule_preempt_disabled+0x16/0x20
[  600.088076]  [<ffffffffb12a040f>] __mutex_lock_slowpath+0xba/0x13f
[  600.088110]  [<ffffffffb12a04c2>] mutex_lock+0x2e/0x3f
[  600.088142]  [<ffffffffb0ffb767>] unbind_store+0x5d/0x98
[  600.088187]  [<ffffffffb0ffa938>] drv_attr_store+0x2c/0x2e
[  600.088219]  [<ffffffffb0dad655>] sysfs_kf_write+0x39/0x3b
[  600.088249]  [<ffffffffb0dac8f9>] kernfs_fop_write+0xf0/0x127
[  600.088283]  [<ffffffffb0d52043>] vfs_write+0xb0/0xf5
[  600.088355]  [<ffffffffb0d526a1>] SyS_write+0x5d/0x9f
[  600.088391]  [<ffffffffb12a20dc>] system_call_fastpath+0x1c/0x21
[  600.088430] kworker/1:0     D 0000000000000000     0  9083      2 0x00000000
[  600.088483] Workqueue: usb_hub_wq hub_event
[  600.088543]  ffff88005832fb08 0000000000000046 0000000000000000 ffff880079d16460
[  600.088586]  ffff88005832ffd8 ffff8800796e9b60 0000000000013500 ffff8800796e9b60
[  600.088629]  ffff88005832fb68 7fffffffffffffff 7fffffffffffffff 0000000000000002
[  600.088673] Call Trace:
[  600.088705]  [<ffffffffb12a100d>] ? console_conditional_schedule+0x2c/0x2c
[  600.088736]  [<ffffffffb129ed8b>] schedule+0x69/0x6b
[  600.088773]  [<ffffffffb12a1041>] schedule_timeout+0x34/0x11d
[  600.088807]  [<ffffffffb0d484bc>] ? kfree+0x3c/0x10e
[  600.088839]  [<ffffffffb129f815>] do_wait_for_common+0x12f/0x16c
[  600.088876]  [<ffffffffb0c86673>] ? wake_up_process+0x39/0x39
[  600.088909]  [<ffffffffb129f8fe>] wait_for_common+0x52/0x6d
[  600.088940]  [<ffffffffb129f936>] wait_for_completion+0x1d/0x1f
[  600.088983]  [<ffffffffb108cdb8>] xhci_alloc_dev+0xbb/0x26a
[  600.089017]  [<ffffffffb106225f>] usb_alloc_dev+0x70/0x2a0
[  600.089048]  [<ffffffffb1067339>] hub_event+0x864/0xf7a
[  600.089087]  [<ffffffffb0c78913>] process_one_work+0x176/0x2d4
[  600.089122]  [<ffffffffb0c79298>] worker_thread+0x1ec/0x2bf
[  600.089158]  [<ffffffffb0c790ac>] ? rescuer_thread+0x2db/0x2db
[  600.089192]  [<ffffffffb0c7d362>] kthread+0x10e/0x116
[  600.089224]  [<ffffffffb0c7d254>] ? __kthread_parkme+0x67/0x67
[  600.089256]  [<ffffffffb12a202c>] ret_from_fork+0x7c/0xb0
[  600.089286]  [<ffffffffb0c7d254>] ? __kthread_parkme+0x67/0x67
[  600.089366] sending NMI to all CPUs:
[  600.089663] NMI backtrace for cpu 0
[  600.089687] CPU: 0 PID: 1687 Comm: memory_kills_mo Tainted: G        W      3.18.0-13690-g5008f19 #1
[  600.089713] Hardware name: GOOGLE Cyan, BIOS Google_Cyan.7287.57.25 10/13/2015
[  600.089737] task: ffff880073a82da0 ti: ffff880064884000 task.ti: ffff880064884000
[  600.089760] RIP: 0033:[<0000615ac25c24fe>]  [<0000615ac25c24fe>] 0x615ac25c24fe
[  600.089783] RSP: 002b:000073dd8f0cc3b8  EFLAGS: 00000202
[  600.089803] RAX: 0000615ac45bfc90 RBX: 000073dd8f0cc490 RCX: 0000119afc04ca10
[  600.089826] RDX: 0000119afc04ca18 RSI: 0000119afe058420 RDI: 0000615acb8821c0
[  600.089850] RBP: 000073dd8f0cc400 R08: 000000000000010e R09: 0000000119afe10e
[  600.089873] R10: 0000000000000000 R11: 0000000000009a4f R12: 0000119afe058900
[  600.089896] R13: 0000000000000000 R14: 0000119afe058420 R15: 0000119afd3b43c0
[  600.089921] FS:  000073dd8f0cd700(0000) GS:ffff88007c800000(0000) knlGS:0000000000000000
[  600.089945] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  600.089966] CR2: 00007396b8dbfff8 CR3: 0000000073926000 CR4: 00000000001007f0
[  600.089987] 
[  600.090000] NMI backtrace for cpu 1
[  600.090019] CPU: 1 PID: 21 Comm: khungtaskd Tainted: G        W      3.18.0-13690-g5008f19 #1
[  600.090044] Hardware name: GOOGLE Cyan, BIOS Google_Cyan.7287.57.25 10/13/2015
[  600.090067] task: ffff880079d73fe0 ti: ffff880079f70000 task.ti: ffff880079f70000
[  600.090091] RIP: 0010:[<ffffffffb0c30233>]  [<ffffffffb0c30233>] flat_send_IPI_mask+0x12/0x13
[  600.090116] RSP: 0018:ffff880079f73de0  EFLAGS: 00000246
[  600.090136] RAX: 0000000000000000 RBX: 0000000000000001 RCX: 000000000000fcfb
[  600.090159] RDX: 0000000000000000 RSI: 0000000000000c00 RDI: 0000000000000300
[  600.090182] RBP: ffff880079f73e28 R08: 000000000001ffe8 R09: 0000000000000000
[  600.090205] R10: 0000000000000000 R11: ffffffffb1a96800 R12: 000000000000c100
[  600.090235] R13: 000000000000032d R14: ffff880078db36c0 R15: ffff880078db3a10
[  600.090258] FS:  0000000000000000(0000) GS:ffff88007c900000(0000) knlGS:0000000000000000
[  600.090282] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[  600.090342] CR2: 00007396b8d9bf58 CR3: 000000003181a000 CR4: 00000000001007e0
[  600.090366] Stack:
[  600.090381]  ffffffffb0c2d4f5 ffff880079f73e28 ffffffffb0c88a61 ffffffffb181f850
[  600.090405]  ffff880078db36c0 0000000000000078 000000000000032d ffff880078db36c0
[  600.090428]  ffff880078db3a10 ffff880079f73e98 ffffffffb0cdef69 ffff880079f73fd8
[  600.090450] Call Trace:
[  600.090466]  [<ffffffffb0c2d4f5>] ? arch_trigger_all_cpu_backtrace+0x107/0x213
[  600.090488]  [<ffffffffb0c88a61>] ? show_state_filter+0xcc/0xeb
[  600.090509]  [<ffffffffb0cdef69>] watchdog+0x274/0x300
[  600.090529]  [<ffffffffb0cdecf5>] ? reset_hung_task_detector+0x15/0x15
[  600.090550]  [<ffffffffb0c7d362>] kthread+0x10e/0x116
[  600.090571]  [<ffffffffb0c7d254>] ? __kthread_parkme+0x67/0x67
[  600.090592]  [<ffffffffb12a202c>] ret_from_fork+0x7c/0xb0
[  600.090612]  [<ffffffffb0c7d254>] ? __kthread_parkme+0x67/0x67
[  600.090637] Code: ff ff ff 48 8b 45 f8 65 48 33 04 25 28 00 00 00 74 05 e8 ff 37 03 00 c9 c3 0f 1f 44 00 00 55 48 8b 3f 48 89 e5 e8 27 ff ff ff 5d <c3> 55 48 8b 0f b8 ea ff ff ff 48 23 0e 48 8b 35 a1 83 7d 00 48 
[  600.090687] Kernel panic - not syncing: hung_task: blocked tasks
[  600.090717] CPU: 1 PID: 21 Comm: khungtaskd Tainted: G        W      3.18.0-13690-g5008f19 #1
[  600.090742] Hardware name: GOOGLE Cyan, BIOS Google_Cyan.7287.57.25 10/13/2015
[  600.090766]  0000000000000000 0000000009d6b204 ffff880079f73da8 ffffffffb129ce87
[  600.090810]  0000000000000000 ffffffffb15a4dba ffff880079f73e28 ffffffffb129bb36
[  600.090857]  ffff880000000008 ffff880079f73e38 ffff880079f73dd8 0000000009d6b204
[  600.090900] Call Trace:
[  600.090930]  [<ffffffffb129ce87>] dump_stack+0x4e/0x71
[  600.090962]  [<ffffffffb129bb36>] panic+0xcd/0x1e3
[  600.090994]  [<ffffffffb0cdef77>] watchdog+0x282/0x300
[  600.091025]  [<ffffffffb0cdecf5>] ? reset_hung_task_detector+0x15/0x15
[  600.091057]  [<ffffffffb0c7d362>] kthread+0x10e/0x116
[  600.091089]  [<ffffffffb0c7d254>] ? __kthread_parkme+0x67/0x67
[  600.091121]  [<ffffffffb12a202c>] ret_from_fork+0x7c/0xb0
[  600.091151]  [<ffffffffb0c7d254>] ? __kthread_parkme+0x67/0x67
[  600.091192] Kernel Offset: 0x2fc00000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
[  600.094954] gsmi: Log Shutdown Reason 0x02
[  600.139685] ACPI MEMORY or I/O RESET_REG.



 
Cc: cylee@chromium.org
This is a snippet of "grep usb /var/log/messages", for the last part of the last run of the "while true" command above.

2017-02-14T15:03:02.569820-08:00 INFO kernel: [  309.647575] usb 1-5: New USB device strings: Mfr=0, Product=0, SerialNumber=0
2017-02-14T15:03:11.045657-08:00 INFO kernel: [  318.123352] usb 1-1: USB disconnect, device number 41
2017-02-14T15:03:11.048086-08:00 INFO kernel: [  318.125354] asix 1-1:1.0 eth0: unregister 'asix' usb-0000:00:14.0-1, ASIX AX88772 USB 2.0 Ethernet
2017-02-14T15:03:11.071538-08:00 INFO kernel: [  318.149713] usb 1-4: USB disconnect, device number 42
2017-02-14T15:03:11.074698-08:00 INFO kernel: [  318.151911] usb 1-5: USB disconnect, device number 43
2017-02-14T15:03:16.376665-08:00 INFO kernel: [  323.454169] usb 1-1: new high-speed USB device number 44 using xhci_hcd
2017-02-14T15:03:16.560677-08:00 INFO kernel: [  323.638204] usb 1-1: New USB device found, idVendor=0b95, idProduct=772a
2017-02-14T15:03:16.560720-08:00 INFO kernel: [  323.638239] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
2017-02-14T15:03:16.560730-08:00 INFO kernel: [  323.638255] usb 1-1: Product: AX88x72A
2017-02-14T15:03:16.560735-08:00 INFO kernel: [  323.638268] usb 1-1: Manufacturer: ASIX Elec. Corp.
2017-02-14T15:03:16.560739-08:00 INFO kernel: [  323.638281] usb 1-1: SerialNumber: 6383BF
2017-02-14T15:03:16.971521-08:00 INFO kernel: [  324.049120] asix 1-1:1.0 eth0: register 'asix' at usb-0000:00:14.0-1, ASIX AX88772 USB 2.0 Ethernet, 00:50:b6:63:83:bf
2017-02-14T15:03:17.125569-08:00 INFO kernel: [  324.202725] usb 1-4: new high-speed USB device number 45 using xhci_hcd
2017-02-14T15:03:17.301773-08:00 INFO kernel: [  324.379051] usb 1-4: New USB device found, idVendor=04f2, idProduct=b490
2017-02-14T15:03:17.301810-08:00 INFO kernel: [  324.379074] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=0
2017-02-14T15:03:17.301816-08:00 INFO kernel: [  324.379089] usb 1-4: Product: HD WebCam
2017-02-14T15:03:17.301820-08:00 INFO kernel: [  324.379099] usb 1-4: Manufacturer: Chicony Electronics Co.,Ltd.
2017-02-14T15:03:17.473516-08:00 INFO kernel: [  324.551058] usb 1-5: new full-speed USB device number 46 using xhci_hcd
2017-02-14T15:03:17.643841-08:00 INFO kernel: [  324.720893] usb 1-5: New USB device found, idVendor=8087, idProduct=0a2a
2017-02-14T15:03:17.643880-08:00 INFO kernel: [  324.720918] usb 1-5: New USB device strings: Mfr=0, Product=0, SerialNumber=0
2017-02-14T15:03:26.131544-08:00 INFO kernel: [  333.208278] usb 1-1: USB disconnect, device number 44
2017-02-14T15:03:26.131590-08:00 INFO kernel: [  333.208931] asix 1-1:1.0 eth0: unregister 'asix' usb-0000:00:14.0-1, ASIX AX88772 USB 2.0 Ethernet
2017-02-14T15:03:26.152611-08:00 INFO kernel: [  333.230069] usb 1-4: USB disconnect, device number 45
2017-02-14T15:03:26.153622-08:00 INFO kernel: [  333.230955] usb 1-5: USB disconnect, device number 46
2017-02-14T15:03:31.461840-08:00 INFO kernel: [  338.538675] usb 1-1: new high-speed USB device number 47 using xhci_hcd
2017-02-14T15:03:31.644930-08:00 INFO kernel: [  338.722075] usb 1-1: New USB device found, idVendor=0b95, idProduct=772a
2017-02-14T15:03:31.645005-08:00 INFO kernel: [  338.722126] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
2017-02-14T15:03:31.645044-08:00 INFO kernel: [  338.722156] usb 1-1: Product: AX88x72A
2017-02-14T15:03:31.645058-08:00 INFO kernel: [  338.722227] usb 1-1: Manufacturer: ASIX Elec. Corp.
2017-02-14T15:03:31.645068-08:00 INFO kernel: [  338.722237] usb 1-1: SerialNumber: 6383BF
2017-02-14T15:03:32.056644-08:00 INFO kernel: [  339.134005] asix 1-1:1.0 eth0: register 'asix' at usb-0000:00:14.0-1, ASIX AX88772 USB 2.0 Ethernet, 00:50:b6:63:83:bf
2017-02-14T15:03:32.212901-08:00 INFO kernel: [  339.289224] usb 1-4: new high-speed USB device number 48 using xhci_hcd
2017-02-14T15:03:32.389761-08:00 INFO kernel: [  339.466242] usb 1-4: New USB device found, idVendor=04f2, idProduct=b490
2017-02-14T15:03:32.389798-08:00 INFO kernel: [  339.466273] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=0
2017-02-14T15:03:32.389804-08:00 INFO kernel: [  339.466290] usb 1-4: Product: HD WebCam
2017-02-14T15:03:32.389808-08:00 INFO kernel: [  339.466300] usb 1-4: Manufacturer: Chicony Electronics Co.,Ltd.
2017-02-14T15:03:32.559513-08:00 INFO kernel: [  339.636207] usb 1-5: new full-speed USB device number 49 using xhci_hcd
2017-02-14T15:03:32.730058-08:00 INFO kernel: [  339.806572] usb 1-5: New USB device found, idVendor=8087, idProduct=0a2a
2017-02-14T15:03:32.730098-08:00 INFO kernel: [  339.806598] usb 1-5: New USB device strings: Mfr=0, Product=0, SerialNumber=0
2017-02-14T15:03:41.214984-08:00 INFO kernel: [  348.291673] usb 1-1: USB disconnect, device number 47
2017-02-14T15:03:41.222666-08:00 INFO kernel: [  348.295604] asix 1-1:1.0 eth0: unregister 'asix' usb-0000:00:14.0-1, ASIX AX88772 USB 2.0 Ethernet
2017-02-14T15:03:41.242661-08:00 INFO kernel: [  348.318912] usb 1-4: USB disconnect, device number 48
2017-02-14T15:03:41.244925-08:00 INFO kernel: [  348.321354] usb 1-5: USB disconnect, device number 49
2017-02-14T15:03:46.545925-08:00 INFO kernel: [  353.622186] usb 1-1: new high-speed USB device number 50 using xhci_hcd
2017-02-14T15:03:46.728565-08:00 INFO kernel: [  353.805227] usb 1-1: New USB device found, idVendor=0b95, idProduct=772a
2017-02-14T15:03:46.728617-08:00 INFO kernel: [  353.805255] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
2017-02-14T15:03:46.728625-08:00 INFO kernel: [  353.805272] usb 1-1: Product: AX88x72A
2017-02-14T15:03:46.728633-08:00 INFO kernel: [  353.805285] usb 1-1: Manufacturer: ASIX Elec. Corp.
2017-02-14T15:03:46.728637-08:00 INFO kernel: [  353.805298] usb 1-1: SerialNumber: 6383BF
2017-02-14T15:03:47.150071-08:00 INFO kernel: [  354.224107] asix 1-1:1.0 eth0: register 'asix' at usb-0000:00:14.0-1, ASIX AX88772 USB 2.0 Ethernet, 00:50:b6:63:83:bf
2017-02-14T15:03:47.304517-08:00 INFO kernel: [  354.380749] usb 1-4: new high-speed USB device number 51 using xhci_hcd
2017-02-14T15:03:47.481782-08:00 INFO kernel: [  354.557754] usb 1-4: New USB device found, idVendor=04f2, idProduct=b490
2017-02-14T15:03:47.481832-08:00 INFO kernel: [  354.557776] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=0
2017-02-14T15:03:47.481839-08:00 INFO kernel: [  354.557790] usb 1-4: Product: HD WebCam
2017-02-14T15:03:47.481843-08:00 INFO kernel: [  354.557800] usb 1-4: Manufacturer: Chicony Electronics Co.,Ltd.
2017-02-14T15:03:47.654512-08:00 INFO kernel: [  354.731074] usb 1-5: new full-speed USB device number 52 using xhci_hcd
2017-02-14T15:03:47.823638-08:00 INFO kernel: [  354.899935] usb 1-5: New USB device found, idVendor=8087, idProduct=0a2a
2017-02-14T15:03:47.823678-08:00 INFO kernel: [  354.899957] usb 1-5: New USB device strings: Mfr=0, Product=0, SerialNumber=0
2017-02-14T15:03:56.299305-08:00 INFO kernel: [  363.373426] usb 1-1: USB disconnect, device number 50
2017-02-14T15:03:56.299366-08:00 INFO kernel: [  363.374445] asix 1-1:1.0 eth0: unregister 'asix' usb-0000:00:14.0-1, ASIX AX88772 USB 2.0 Ethernet
2017-02-14T15:03:56.321546-08:00 INFO kernel: [  363.397489] usb 1-4: USB disconnect, device number 51
2017-02-14T15:03:56.322631-08:00 INFO kernel: [  363.398837] usb 1-5: USB disconnect, device number 52


Issue 705059 has been merged into this issue.
Status: Assigned (was: Untriaged)

Sign in to add a comment