Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1633767 > unrolled thread

Re: Asmedia USB 1343 crashes

Started byAlan Stern <stern@rowland.harvard.edu>
First post2017-05-01 20:00 +0200
Last post2017-05-04 17:20 +0200
Articles 8 — 3 participants

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  Re: Asmedia USB 1343 crashes Alan Stern <stern@rowland.harvard.edu> - 2017-05-01 20:00 +0200
    Re: Asmedia USB 1343 crashes Thomas Fjellstrom <thomas@fjellstrom.ca> - 2017-05-01 20:10 +0200
      Re: Asmedia USB 1343 crashes Thomas Fjellstrom <thomas@fjellstrom.ca> - 2017-05-03 04:10 +0200
        Re: Asmedia USB 1343 crashes Thomas Fjellstrom <thomas@fjellstrom.ca> - 2017-05-03 04:20 +0200
        Re: Asmedia USB 1343 crashes Alan Stern <stern@rowland.harvard.edu> - 2017-05-03 20:00 +0200
          Re: Asmedia USB 1343 crashes Thomas Fjellstrom <thomas@fjellstrom.ca> - 2017-05-03 21:30 +0200
            Re: Asmedia USB 1343 crashes Mathias Nyman <mathias.nyman@linux.intel.com> - 2017-05-04 17:10 +0200
              Re: Asmedia USB 1343 crashes Thomas Fjellstrom <thomas@fjellstrom.ca> - 2017-05-04 17:20 +0200

#1633767 — Re: Asmedia USB 1343 crashes

FromAlan Stern <stern@rowland.harvard.edu>
Date2017-05-01 20:00 +0200
SubjectRe: Asmedia USB 1343 crashes
Message-ID<tCnM6-3J1-9@gated-at.bofh.it>
On Mon, 1 May 2017, Thomas Fjellstrom wrote:

> On Monday, May 1, 2017 10:54:12 AM MDT Alan Stern wrote:
> > On Mon, 1 May 2017, Thomas Fjellstrom wrote:
> > > I've got a 970 Pro gaming aura motherboard with an Asmedia 1343 Usb 3.1
> > > controller. It's been consistently throwing errors and eventually crashing
> > > and becomming unresponsive.
> > 
> > Maybe if you posted a kernel log showing those errors, people would
> > have a better idea of what's causing your problems.
> 
> I was going to, but it seems I lost my previous log. I've searched through the
> system logs and haven't found a good clean set of logs, but I'll post what I
> have (at end of message), and later re-test with autosuspend on.
> 
> > > Even just plugging in one device to the rear port will eventually cause
> > > the
> > > controller to die. Usually only takes a few hours for it to completely
> > > die.
> > > 
> > > 
> > > One of the errors that shows up consistently is:
> > > 
> > > usbfs: process did not claim interface 0 before use
> > 
> > This warning message is not related to the Asmedia controller.  It
> > refers to some program running on the computer, and the same message
> > would appear no matter what sort of controller was being used.
> 
> Ah. I figured since it was a kernel message, it was directly connected to the
> issues.
> 
> > Alan Stern
> > 
> [snip]
...
> [   81.609260] usb 1-1.4: new high-speed USB device number 3 using xhci_hcd
> [   81.701710] usb 1-1.4: New USB device found, idVendor=2109, idProduct=2812
> [   81.701713] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0
> [   81.701716] usb 1-1.4: Product: USB2.0 Hub             
> [   81.701717] usb 1-1.4: Manufacturer: VIA Labs, Inc.         
> [   81.702643] hub 1-1.4:1.0: USB hub found
> [   81.702943] hub 1-1.4:1.0: 4 ports detected
> [   81.918578] usb 2-1.4: new SuperSpeed USB device number 3 using xhci_hcd
> [   82.166707] usb 2-1.4: New USB device found, idVendor=2109, idProduct=0812
> [   82.166712] usb 2-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0
> [   82.166714] usb 2-1.4: Product: USB3.0 Hub             
> [   82.166717] usb 2-1.4: Manufacturer: VIA Labs, Inc.         
> [   82.168062] hub 2-1.4:1.0: USB hub found
> [   82.168743] hub 2-1.4:1.0: 4 ports detected
> [  103.735979] usb 1-1.4.4: new high-speed USB device number 4 using xhci_hcd
> [  103.826980] usb 1-1.4.4: New USB device found, idVendor=05c6, idProduct=9039
> [  103.826985] usb 1-1.4.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
> [  103.826987] usb 1-1.4.4: Product: Android
> [  103.826989] usb 1-1.4.4: Manufacturer: Android
> [  103.826992] usb 1-1.4.4: SerialNumber: XH023891
> [  103.852744] usb 1-1.4.4: usbfs: process 4360 (ThreadWeaver::T) did not claim interface 0 before use
> [  103.930343] usb 1-1.4.4: reset high-speed USB device number 4 using xhci_hcd
> [  104.021437] usb 1-1.4.4: usbfs: process 4360 (ThreadWeaver::T) did not claim interface 0 before use
> [  104.098365] usb 1-1.4.4: reset high-speed USB device number 4 using xhci_hcd

[lots of resets and warnings cut out]

Well, this answers one question: The program not claiming interface 0 
is ThreadWeaver::T, whatever that is.  This isn't really an error, but 
it is sloppy programming.  You could report it to the maintainers of 
that program.

The log shows a more or less constant series of warnings and resets as 
long as the Android device is plugged in.  This would explain any 
unresponsiveness, although it doesn't explain eventual crashes.

If you know what that ThreadWeaver program is, and if you don't need
it, you could try disabling or removing it to see if the situation
improves.

Alan Stern

[toc] | [next] | [standalone]

#1633771

FromThomas Fjellstrom <thomas@fjellstrom.ca>
Date2017-05-01 20:10 +0200
Message-ID<tCnVL-417-11@gated-at.bofh.it>
In reply to#1633767
On Monday, May 1, 2017 1:57:53 PM MDT Alan Stern wrote:
> On Mon, 1 May 2017, Thomas Fjellstrom wrote:
> 
> > On Monday, May 1, 2017 10:54:12 AM MDT Alan Stern wrote:
> > > On Mon, 1 May 2017, Thomas Fjellstrom wrote:
> > > > I've got a 970 Pro gaming aura motherboard with an Asmedia 1343 Usb 
3.1
> > > > controller. It's been consistently throwing errors and eventually 
crashing
> > > > and becomming unresponsive.
> > > 
> > > Maybe if you posted a kernel log showing those errors, people would
> > > have a better idea of what's causing your problems.
> > 
> > I was going to, but it seems I lost my previous log. I've searched through 
the
> > system logs and haven't found a good clean set of logs, but I'll post what 
I
> > have (at end of message), and later re-test with autosuspend on.
> > 
> > > > Even just plugging in one device to the rear port will eventually 
cause
> > > > the
> > > > controller to die. Usually only takes a few hours for it to completely
> > > > die.
> > > > 
> > > > 
> > > > One of the errors that shows up consistently is:
> > > > 
> > > > usbfs: process did not claim interface 0 before use
> > > 
> > > This warning message is not related to the Asmedia controller.  It
> > > refers to some program running on the computer, and the same message
> > > would appear no matter what sort of controller was being used.
> > 
> > Ah. I figured since it was a kernel message, it was directly connected to 
the
> > issues.
> > 
> > > Alan Stern
> > > 
> > [snip]
> ...
> > [   81.609260] usb 1-1.4: new high-speed USB device number 3 using 
xhci_hcd
> > [   81.701710] usb 1-1.4: New USB device found, idVendor=2109, 
idProduct=2812
> > [   81.701713] usb 1-1.4: New USB device strings: Mfr=1, Product=2, 
SerialNumber=0
> > [   81.701716] usb 1-1.4: Product: USB2.0 Hub             
> > [   81.701717] usb 1-1.4: Manufacturer: VIA Labs, Inc.         
> > [   81.702643] hub 1-1.4:1.0: USB hub found
> > [   81.702943] hub 1-1.4:1.0: 4 ports detected
> > [   81.918578] usb 2-1.4: new SuperSpeed USB device number 3 using 
xhci_hcd
> > [   82.166707] usb 2-1.4: New USB device found, idVendor=2109, 
idProduct=0812
> > [   82.166712] usb 2-1.4: New USB device strings: Mfr=1, Product=2, 
SerialNumber=0
> > [   82.166714] usb 2-1.4: Product: USB3.0 Hub             
> > [   82.166717] usb 2-1.4: Manufacturer: VIA Labs, Inc.         
> > [   82.168062] hub 2-1.4:1.0: USB hub found
> > [   82.168743] hub 2-1.4:1.0: 4 ports detected
> > [  103.735979] usb 1-1.4.4: new high-speed USB device number 4 using 
xhci_hcd
> > [  103.826980] usb 1-1.4.4: New USB device found, idVendor=05c6, 
idProduct=9039
> > [  103.826985] usb 1-1.4.4: New USB device strings: Mfr=1, Product=2, 
SerialNumber=3
> > [  103.826987] usb 1-1.4.4: Product: Android
> > [  103.826989] usb 1-1.4.4: Manufacturer: Android
> > [  103.826992] usb 1-1.4.4: SerialNumber: XH023891
> > [  103.852744] usb 1-1.4.4: usbfs: process 4360 (ThreadWeaver::T) did not 
claim interface 0 before use
> > [  103.930343] usb 1-1.4.4: reset high-speed USB device number 4 using 
xhci_hcd
> > [  104.021437] usb 1-1.4.4: usbfs: process 4360 (ThreadWeaver::T) did not 
claim interface 0 before use
> > [  104.098365] usb 1-1.4.4: reset high-speed USB device number 4 using 
xhci_hcd
> 
> [lots of resets and warnings cut out]
> 
> Well, this answers one question: The program not claiming interface 0 
> is ThreadWeaver::T, whatever that is.  This isn't really an error, but 
> it is sloppy programming.  You could report it to the maintainers of 
> that program.
> 
> The log shows a more or less constant series of warnings and resets as 
> long as the Android device is plugged in.  This would explain any 
> unresponsiveness, although it doesn't explain eventual crashes.
> 
> If you know what that ThreadWeaver program is, and if you don't need
> it, you could try disabling or removing it to see if the situation
> improves.

I'm not sure what program that comes from either, I'll look it up.

Something to note is that things work fine if suspend is disabled or using the 
regular usb 2 ports on my motherboard instead of the usb 3 ports.

I also saw different error messages, much more severe ones that caused the 
xhci host to lock up completely and it didn't seem to need me to plug phones 
in to cause it. I'll follow up after i get it to happen again.

> Alan Stern
> 
> 


-- 
Thomas Fjellstrom
thomas@fjellstrom.ca

[toc] | [prev] | [next] | [standalone]

#1634698

FromThomas Fjellstrom <thomas@fjellstrom.ca>
Date2017-05-03 04:10 +0200
Message-ID<tCRTP-6vM-9@gated-at.bofh.it>
In reply to#1633771
On Monday, May 1, 2017 12:08:55 PM MDT Thomas Fjellstrom wrote:
> On Monday, May 1, 2017 1:57:53 PM MDT Alan Stern wrote:
> > On Mon, 1 May 2017, Thomas Fjellstrom wrote:
> > > On Monday, May 1, 2017 10:54:12 AM MDT Alan Stern wrote:
> > > > On Mon, 1 May 2017, Thomas Fjellstrom wrote:
> > > > > I've got a 970 Pro gaming aura motherboard with an Asmedia 1343 Usb
> 
[snip]
> 
> > [lots of resets and warnings cut out]
> > 
> > Well, this answers one question: The program not claiming interface 0
> > is ThreadWeaver::T, whatever that is.  This isn't really an error, but
> > it is sloppy programming.  You could report it to the maintainers of
> > that program.
> > 
> > The log shows a more or less constant series of warnings and resets as
> > long as the Android device is plugged in.  This would explain any
> > unresponsiveness, although it doesn't explain eventual crashes.
> > 
> > If you know what that ThreadWeaver program is, and if you don't need
> > it, you could try disabling or removing it to see if the situation
> > improves.
> 
> I'm not sure what program that comes from either, I'll look it up.
> 
> Something to note is that things work fine if suspend is disabled or using
> the regular usb 2 ports on my motherboard instead of the usb 3 ports.
> 
> I also saw different error messages, much more severe ones that caused the
> xhci host to lock up completely and it didn't seem to need me to plug phones
> in to cause it. I'll follow up after i get it to happen again.

I just had a brief lockup, desktop stopped responding, other usb devices not 
on the usb3 controller. Two android devices were in the process of restarting.

It doesn't seem to matter what android devices it is.

[294503.849350] ------------[ cut here ]------------
[294503.849362] WARNING: CPU: 0 PID: 0 at net/sched/sch_generic.c:316 dev_watchdog+0x223/0x230
[294503.849365] NETDEV WATCHDOG: enp4s0 (igb): transmit queue 0 timed out
[294503.849367] Modules linked in: sr_mod cdrom ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 xt_addrtype xt_conntrack nf_nat nf_conntrack br_netfilter overlay ebtable_filter ebtables ip6table_filter ip6_tables nfsv3 nfs_acl nfs lockd grace iptable_filter bridge stp llc amdgpu mfd_core fuse vfat fat eeepc_wmi asus_wmi rfkill edac_mce_amd edac_core pcspkr sg amdkfd radeon ttm sunrpc k10temp it87 hwmon_vid fam15h_power efivarfs ip_tables ipv6 autofs4 crc32c_intel i2c_piix4
[294503.849407] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.11.0-rc7 #8
[294503.849410] Hardware name: To be filled by O.E.M. To be filled by O.E.M./970 PRO GAMING/AURA, BIOS 0901 11/07/2016
[294503.849413] Call Trace:
[294503.849417]  <IRQ>
[294503.849422]  dump_stack+0x4d/0x63
[294503.849426]  __warn+0xc6/0xe0
[294503.849430]  warn_slowpath_fmt+0x46/0x50
[294503.849434]  dev_watchdog+0x223/0x230
[294503.849438]  ? qdisc_rcu_free+0x40/0x40
[294503.849442]  call_timer_fn+0x30/0x160
[294503.849445]  ? qdisc_rcu_free+0x40/0x40
[294503.849448]  run_timer_softirq+0x1e1/0x440
[294503.849453]  ? lapic_next_event+0x18/0x20
[294503.849456]  ? sched_clock_cpu+0x11/0xd0
[294503.849459]  __do_softirq+0x101/0x2f0
[294503.849463]  irq_exit+0xb9/0xc0
[294503.849466]  smp_apic_timer_interrupt+0x38/0x50
[294503.849470]  apic_timer_interrupt+0x86/0x90
[294503.849474] RIP: 0010:acpi_idle_do_entry+0x2c/0x40
[294503.849476] RSP: 0018:ffffffffb2a03d90 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
[294503.849480] RAX: 0000000000000000 RBX: ffff884d1a966c00 RCX: 0000000000000034
[294503.849483] RDX: 4ec4ec4ec4ec4ec5 RSI: 0000000000000001 RDI: ffff884d1a966c64
[294503.849485] RBP: ffffffffb2a03dd0 R08: 00000000000003e3 R09: 0000000000000018
[294503.849487] R10: 00000000000003c1 R11: 00000000000003d4 R12: ffff884d1a966c64
[294503.849490] R13: 0000000000000001 R14: 0000000000000001 R15: 0000000000000001
[294503.849492]  </IRQ>
[294503.849497]  ? acpi_idle_enter+0xd7/0x290
[294503.849502]  cpuidle_enter_state+0xed/0x2e0
[294503.849506]  cpuidle_enter+0x12/0x20
[294503.849509]  call_cpuidle+0x1e/0x30
[294503.849512]  do_idle+0x179/0x1d0
[294503.849515]  cpu_startup_entry+0x5d/0x60
[294503.849518]  rest_init+0x7f/0x90
[294503.849522]  start_kernel+0x405/0x412
[294503.849525]  x86_64_start_reservations+0x24/0x26
[294503.849528]  x86_64_start_kernel+0x182/0x193
[294503.849531]  start_cpu+0x14/0x14
[294503.849534]  ? start_cpu+0x14/0x14
[294503.849537] ---[ end trace 12db587e781d6e4f ]---
[294503.849558] igb 0000:04:00.0 enp4s0: Reset adapter
[294504.576629] xhci_hcd 0000:02:00.0: Stop command ring failed, maybe the host is dead
[294504.576656] xhci_hcd 0000:02:00.0: Abort command ring failed
[294504.576799] xhci_hcd 0000:02:00.0: xHCI host not responding to stop endpoint command.
[294504.576805] xhci_hcd 0000:02:00.0: Assuming host is dying, halting host.
[294504.576817] br0: port 1(enp4s0) entered disabled state
[294504.576858] xhci_hcd 0000:02:00.0: HC died; cleaning up
[294504.576909] xhci_hcd 0000:02:00.0: Timeout while waiting for setup device command
[294504.576975] igb 0000:04:00.0 enp4s0: igb: enp4s0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX/TX
[294504.577144] xhci_hcd 0000:02:00.0: HC died; cleaning up
[294504.577158] usb 8-1: USB disconnect, device number 2
[294504.577164] usb 8-1.3: USB disconnect, device number 8
[294504.577225] br0: port 1(enp4s0) entered blocking state
[294504.577230] br0: port 1(enp4s0) entered forwarding state
[294504.580048] usb 9-1: USB disconnect, device number 2
[294504.580058] usb 9-1.4: USB disconnect, device number 3
[294504.580063] usb 9-1.4.3: USB disconnect, device number 4
[294504.588587] usb 8-1.4: USB disconnect, device number 3
[294504.617124] igb 0000:04:00.0 enp4s0: igb: enp4s0 NIC Link is Down
[294504.856569] br0: port 1(enp4s0) entered disabled state
[294504.992429] usb 8-1.4.2: device not accepting address 16, error -108
[294504.992464] usb 8-1.4-port2: couldn't allocate usb_device
[294504.992478] usb 8-1.4.1: USB disconnect, device number 6
[294505.013765] usb 8-1.4.4: USB disconnect, device number 15
[294508.254985] igb 0000:04:00.0 enp4s0: igb: enp4s0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX/TX
[294508.360695] br0: port 1(enp4s0) entered blocking state
[294508.360701] br0: port 1(enp4s0) entered forwarding state
 
> > Alan Stern


-- 
Thomas Fjellstrom
thomas@fjellstrom.ca

[toc] | [prev] | [next] | [standalone]

#1634699

FromThomas Fjellstrom <thomas@fjellstrom.ca>
Date2017-05-03 04:20 +0200
Message-ID<tCS3v-6G2-1@gated-at.bofh.it>
In reply to#1634698
On Tuesday, May 2, 2017 8:04:28 PM MDT Thomas Fjellstrom wrote:
> On Monday, May 1, 2017 12:08:55 PM MDT Thomas Fjellstrom wrote:
> > On Monday, May 1, 2017 1:57:53 PM MDT Alan Stern wrote:
> > > On Mon, 1 May 2017, Thomas Fjellstrom wrote:
> > > > On Monday, May 1, 2017 10:54:12 AM MDT Alan Stern wrote:
> > > > > On Mon, 1 May 2017, Thomas Fjellstrom wrote:
> > > > > > I've got a 970 Pro gaming aura motherboard with an Asmedia 1343 Usb
> > 
> [snip]
> > 
> > > [lots of resets and warnings cut out]
> > > 
> > > Well, this answers one question: The program not claiming interface 0
> > > is ThreadWeaver::T, whatever that is.  This isn't really an error, but
> > > it is sloppy programming.  You could report it to the maintainers of
> > > that program.
> > > 
> > > The log shows a more or less constant series of warnings and resets as
> > > long as the Android device is plugged in.  This would explain any
> > > unresponsiveness, although it doesn't explain eventual crashes.
> > > 
> > > If you know what that ThreadWeaver program is, and if you don't need
> > > it, you could try disabling or removing it to see if the situation
> > > improves.
> > 
> > I'm not sure what program that comes from either, I'll look it up.
> > 
> > Something to note is that things work fine if suspend is disabled or using
> > the regular usb 2 ports on my motherboard instead of the usb 3 ports.
> > 
> > I also saw different error messages, much more severe ones that caused the
> > xhci host to lock up completely and it didn't seem to need me to plug phones
> > in to cause it. I'll follow up after i get it to happen again.
> 
> I just had a brief lockup, desktop stopped responding, other usb devices not 
> on the usb3 controller. Two android devices were in the process of restarting.
> 
> It doesn't seem to matter what android devices it is.
> 
[snip log]

The usb 3.1 controller seems to be inaccessible. 
It'll probably need a reboot to get working again.

>  
> > > Alan Stern
> 
> 
> 


-- 
Thomas Fjellstrom
thomas@fjellstrom.ca

[toc] | [prev] | [next] | [standalone]

#1635181

FromAlan Stern <stern@rowland.harvard.edu>
Date2017-05-03 20:00 +0200
Message-ID<tD6Jc-a7-7@gated-at.bofh.it>
In reply to#1634698
On Tue, 2 May 2017, Thomas Fjellstrom wrote:

> I just had a brief lockup, desktop stopped responding, other usb devices not 
> on the usb3 controller. Two android devices were in the process of restarting.
> 
> It doesn't seem to matter what android devices it is.
> 
> [294503.849350] ------------[ cut here ]------------
> [294503.849362] WARNING: CPU: 0 PID: 0 at net/sched/sch_generic.c:316 dev_watchdog+0x223/0x230
> [294503.849365] NETDEV WATCHDOG: enp4s0 (igb): transmit queue 0 timed out
> [294503.849367] Modules linked in: sr_mod cdrom ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 xt_addrtype xt_conntrack nf_nat nf_conntrack br_netfilter overlay ebtable_filter ebtables ip6table_filter ip6_tables nfsv3 nfs_acl nfs lockd grace iptable_filter bridge stp llc amdgpu mfd_core fuse vfat fat eeepc_wmi asus_wmi rfkill edac_mce_amd edac_core pcspkr sg amdkfd radeon ttm sunrpc k10temp it87 hwmon_vid fam15h_power efivarfs ip_tables ipv6 autofs4 crc32c_intel i2c_piix4
> [294503.849407] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.11.0-rc7 #8
> [294503.849410] Hardware name: To be filled by O.E.M. To be filled by O.E.M./970 PRO GAMING/AURA, BIOS 0901 11/07/2016
> [294503.849413] Call Trace:
> [294503.849417]  <IRQ>
> [294503.849422]  dump_stack+0x4d/0x63
> [294503.849426]  __warn+0xc6/0xe0
> [294503.849430]  warn_slowpath_fmt+0x46/0x50
> [294503.849434]  dev_watchdog+0x223/0x230
> [294503.849438]  ? qdisc_rcu_free+0x40/0x40
> [294503.849442]  call_timer_fn+0x30/0x160
> [294503.849445]  ? qdisc_rcu_free+0x40/0x40
> [294503.849448]  run_timer_softirq+0x1e1/0x440
> [294503.849453]  ? lapic_next_event+0x18/0x20
> [294503.849456]  ? sched_clock_cpu+0x11/0xd0
> [294503.849459]  __do_softirq+0x101/0x2f0
> [294503.849463]  irq_exit+0xb9/0xc0
> [294503.849466]  smp_apic_timer_interrupt+0x38/0x50
> [294503.849470]  apic_timer_interrupt+0x86/0x90
> [294503.849474] RIP: 0010:acpi_idle_do_entry+0x2c/0x40
> [294503.849476] RSP: 0018:ffffffffb2a03d90 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
> [294503.849480] RAX: 0000000000000000 RBX: ffff884d1a966c00 RCX: 0000000000000034
> [294503.849483] RDX: 4ec4ec4ec4ec4ec5 RSI: 0000000000000001 RDI: ffff884d1a966c64
> [294503.849485] RBP: ffffffffb2a03dd0 R08: 00000000000003e3 R09: 0000000000000018
> [294503.849487] R10: 00000000000003c1 R11: 00000000000003d4 R12: ffff884d1a966c64
> [294503.849490] R13: 0000000000000001 R14: 0000000000000001 R15: 0000000000000001
> [294503.849492]  </IRQ>
> [294503.849497]  ? acpi_idle_enter+0xd7/0x290
> [294503.849502]  cpuidle_enter_state+0xed/0x2e0
> [294503.849506]  cpuidle_enter+0x12/0x20
> [294503.849509]  call_cpuidle+0x1e/0x30
> [294503.849512]  do_idle+0x179/0x1d0
> [294503.849515]  cpu_startup_entry+0x5d/0x60
> [294503.849518]  rest_init+0x7f/0x90
> [294503.849522]  start_kernel+0x405/0x412
> [294503.849525]  x86_64_start_reservations+0x24/0x26
> [294503.849528]  x86_64_start_kernel+0x182/0x193
> [294503.849531]  start_cpu+0x14/0x14
> [294503.849534]  ? start_cpu+0x14/0x14
> [294503.849537] ---[ end trace 12db587e781d6e4f ]---
> [294503.849558] igb 0000:04:00.0 enp4s0: Reset adapter
> [294504.576629] xhci_hcd 0000:02:00.0: Stop command ring failed, maybe the host is dead
> [294504.576656] xhci_hcd 0000:02:00.0: Abort command ring failed
> [294504.576799] xhci_hcd 0000:02:00.0: xHCI host not responding to stop endpoint command.
> [294504.576805] xhci_hcd 0000:02:00.0: Assuming host is dying, halting host.

At this point you have reached the limit of my knowledge.  The best 
person to help is Mathias Nyman, the xHCI maintainer (CC'ed).

Is that WARNING at the start of the log connected with the later 
events?

Alan Stern

[toc] | [prev] | [next] | [standalone]

#1635229

FromThomas Fjellstrom <thomas@fjellstrom.ca>
Date2017-05-03 21:30 +0200
Message-ID<tD88h-1cl-19@gated-at.bofh.it>
In reply to#1635181
On Wednesday, May 3, 2017 1:54:39 PM MDT Alan Stern wrote:
> On Tue, 2 May 2017, Thomas Fjellstrom wrote:
> 
> > I just had a brief lockup, desktop stopped responding, other usb devices not 
> > on the usb3 controller. Two android devices were in the process of restarting.
> > 
> > It doesn't seem to matter what android devices it is.
> > 
> > [294503.849350] ------------[ cut here ]------------
> > [294503.849362] WARNING: CPU: 0 PID: 0 at net/sched/sch_generic.c:316 dev_watchdog+0x223/0x230
> > [294503.849365] NETDEV WATCHDOG: enp4s0 (igb): transmit queue 0 timed out
> > [294503.849367] Modules linked in: sr_mod cdrom ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 xt_addrtype xt_conntrack nf_nat nf_conntrack br_netfilter overlay ebtable_filter ebtables ip6table_filter ip6_tables nfsv3 nfs_acl nfs lockd grace iptable_filter bridge stp llc amdgpu mfd_core fuse vfat fat eeepc_wmi asus_wmi rfkill edac_mce_amd edac_core pcspkr sg amdkfd radeon ttm sunrpc k10temp it87 hwmon_vid fam15h_power efivarfs ip_tables ipv6 autofs4 crc32c_intel i2c_piix4
> > [294503.849407] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.11.0-rc7 #8
> > [294503.849410] Hardware name: To be filled by O.E.M. To be filled by O.E.M./970 PRO GAMING/AURA, BIOS 0901 11/07/2016
> > [294503.849413] Call Trace:
> > [294503.849417]  <IRQ>
> > [294503.849422]  dump_stack+0x4d/0x63
> > [294503.849426]  __warn+0xc6/0xe0
> > [294503.849430]  warn_slowpath_fmt+0x46/0x50
> > [294503.849434]  dev_watchdog+0x223/0x230
> > [294503.849438]  ? qdisc_rcu_free+0x40/0x40
> > [294503.849442]  call_timer_fn+0x30/0x160
> > [294503.849445]  ? qdisc_rcu_free+0x40/0x40
> > [294503.849448]  run_timer_softirq+0x1e1/0x440
> > [294503.849453]  ? lapic_next_event+0x18/0x20
> > [294503.849456]  ? sched_clock_cpu+0x11/0xd0
> > [294503.849459]  __do_softirq+0x101/0x2f0
> > [294503.849463]  irq_exit+0xb9/0xc0
> > [294503.849466]  smp_apic_timer_interrupt+0x38/0x50
> > [294503.849470]  apic_timer_interrupt+0x86/0x90
> > [294503.849474] RIP: 0010:acpi_idle_do_entry+0x2c/0x40
> > [294503.849476] RSP: 0018:ffffffffb2a03d90 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
> > [294503.849480] RAX: 0000000000000000 RBX: ffff884d1a966c00 RCX: 0000000000000034
> > [294503.849483] RDX: 4ec4ec4ec4ec4ec5 RSI: 0000000000000001 RDI: ffff884d1a966c64
> > [294503.849485] RBP: ffffffffb2a03dd0 R08: 00000000000003e3 R09: 0000000000000018
> > [294503.849487] R10: 00000000000003c1 R11: 00000000000003d4 R12: ffff884d1a966c64
> > [294503.849490] R13: 0000000000000001 R14: 0000000000000001 R15: 0000000000000001
> > [294503.849492]  </IRQ>
> > [294503.849497]  ? acpi_idle_enter+0xd7/0x290
> > [294503.849502]  cpuidle_enter_state+0xed/0x2e0
> > [294503.849506]  cpuidle_enter+0x12/0x20
> > [294503.849509]  call_cpuidle+0x1e/0x30
> > [294503.849512]  do_idle+0x179/0x1d0
> > [294503.849515]  cpu_startup_entry+0x5d/0x60
> > [294503.849518]  rest_init+0x7f/0x90
> > [294503.849522]  start_kernel+0x405/0x412
> > [294503.849525]  x86_64_start_reservations+0x24/0x26
> > [294503.849528]  x86_64_start_kernel+0x182/0x193
> > [294503.849531]  start_cpu+0x14/0x14
> > [294503.849534]  ? start_cpu+0x14/0x14
> > [294503.849537] ---[ end trace 12db587e781d6e4f ]---
> > [294503.849558] igb 0000:04:00.0 enp4s0: Reset adapter
> > [294504.576629] xhci_hcd 0000:02:00.0: Stop command ring failed, maybe the host is dead
> > [294504.576656] xhci_hcd 0000:02:00.0: Abort command ring failed
> > [294504.576799] xhci_hcd 0000:02:00.0: xHCI host not responding to stop endpoint command.
> > [294504.576805] xhci_hcd 0000:02:00.0: Assuming host is dying, halting host.
> 
> At this point you have reached the limit of my knowledge.  The best 
> person to help is Mathias Nyman, the xHCI maintainer (CC'ed).
> 
> Is that WARNING at the start of the log connected with the later 
> events?

I belive so yes. Except for some usb adds/removals for the devices restarting.

> Alan Stern
> 
> --
> To unsubscribe from this list: send the line "unsubscribe linux-usb" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> 


-- 
Thomas Fjellstrom
thomas@fjellstrom.ca

[toc] | [prev] | [next] | [standalone]

#1635825

FromMathias Nyman <mathias.nyman@linux.intel.com>
Date2017-05-04 17:10 +0200
Message-ID<tDqye-595-27@gated-at.bofh.it>
In reply to#1635229
On 03.05.2017 22:20, Thomas Fjellstrom wrote:
> On Wednesday, May 3, 2017 1:54:39 PM MDT Alan Stern wrote:
>> On Tue, 2 May 2017, Thomas Fjellstrom wrote:
>>
>>> I just had a brief lockup, desktop stopped responding, other usb devices not
>>> on the usb3 controller. Two android devices were in the process of restarting
>>>
>>> It doesn't seem to matter what android devices it is.
>>>
>>> [294503.849350] ------------[ cut here ]------------
>>> [294503.849362] WARNING: CPU: 0 PID: 0 at net/sched/sch_generic.c:316 dev_watchdog+0x223/0x230
>>> [294503.849365] NETDEV WATCHDOG: enp4s0 (igb): transmit queue 0 timed out
>>> [294503.849367] Modules linked in: sr_mod cdrom ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 xt_addrtype xt_conntrack nf_nat nf_conntrack br_netfilter overlay ebtable_filter ebtables ip6table_filter ip6_tables nfsv3 nfs_acl nfs lockd grace iptable_filter bridge stp llc amdgpu mfd_core fuse vfat fat eeepc_wmi asus_wmi rfkill edac_mce_amd edac_core pcspkr sg amdkfd radeon ttm sunrpc k10temp it87 hwmon_vid fam15h_power efivarfs ip_tables ipv6 autofs4 crc32c_intel i2c_piix4
>>> [294503.849407] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.11.0-rc7 #8
>>> [294503.849410] Hardware name: To be filled by O.E.M. To be filled by O.E.M./970 PRO GAMING/AURA, BIOS 0901 11/07/2016
>>> [294503.849413] Call Trace:
>>> [294503.849417]  <IRQ>
>>> [294503.849422]  dump_stack+0x4d/0x63
>>> [294503.849426]  __warn+0xc6/0xe0
>>> [294503.849430]  warn_slowpath_fmt+0x46/0x50
>>> [294503.849434]  dev_watchdog+0x223/0x230
>>> [294503.849438]  ? qdisc_rcu_free+0x40/0x40
>>> [294503.849442]  call_timer_fn+0x30/0x160
>>> [294503.849445]  ? qdisc_rcu_free+0x40/0x40
>>> [294503.849448]  run_timer_softirq+0x1e1/0x440
>>> [294503.849453]  ? lapic_next_event+0x18/0x20
>>> [294503.849456]  ? sched_clock_cpu+0x11/0xd0
>>> [294503.849459]  __do_softirq+0x101/0x2f0
>>> [294503.849463]  irq_exit+0xb9/0xc0
>>> [294503.849466]  smp_apic_timer_interrupt+0x38/0x50
>>> [294503.849470]  apic_timer_interrupt+0x86/0x90
>>> [294503.849474] RIP: 0010:acpi_idle_do_entry+0x2c/0x40
>>> [294503.849476] RSP: 0018:ffffffffb2a03d90 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
>>> [294503.849480] RAX: 0000000000000000 RBX: ffff884d1a966c00 RCX: 0000000000000034
>>> [294503.849483] RDX: 4ec4ec4ec4ec4ec5 RSI: 0000000000000001 RDI: ffff884d1a966c64
>>> [294503.849485] RBP: ffffffffb2a03dd0 R08: 00000000000003e3 R09: 0000000000000018
>>> [294503.849487] R10: 00000000000003c1 R11: 00000000000003d4 R12: ffff884d1a966c64
>>> [294503.849490] R13: 0000000000000001 R14: 0000000000000001 R15: 0000000000000001
>>> [294503.849492]  </IRQ>
>>> [294503.849497]  ? acpi_idle_enter+0xd7/0x290
>>> [294503.849502]  cpuidle_enter_state+0xed/0x2e0
>>> [294503.849506]  cpuidle_enter+0x12/0x20
>>> [294503.849509]  call_cpuidle+0x1e/0x30
>>> [294503.849512]  do_idle+0x179/0x1d0
>>> [294503.849515]  cpu_startup_entry+0x5d/0x60
>>> [294503.849518]  rest_init+0x7f/0x90
>>> [294503.849522]  start_kernel+0x405/0x412
>>> [294503.849525]  x86_64_start_reservations+0x24/0x26
>>> [294503.849528]  x86_64_start_kernel+0x182/0x193
>>> [294503.849531]  start_cpu+0x14/0x14
>>> [294503.849534]  ? start_cpu+0x14/0x14
>>> [294503.849537] ---[ end trace 12db587e781d6e4f ]---
>>> [294503.849558] igb 0000:04:00.0 enp4s0: Reset adapter
>>> [294504.576629] xhci_hcd 0000:02:00.0: Stop command ring failed, maybe the host is dead
>>> [294504.576656] xhci_hcd 0000:02:00.0: Abort command ring failed
>>> [294504.576799] xhci_hcd 0000:02:00.0: xHCI host not responding to stop endpoint command.
>>> [294504.576805] xhci_hcd 0000:02:00.0: Assuming host is dying, halting host.
>>
>> At this point you have reached the limit of my knowledge.  The best
>> person to help is Mathias Nyman, the xHCI maintainer (CC'ed).
>>

For some reason stopping the command ring fails, ring is stopped by writing a
bit in a register, hardware is supposed to clear another bit in the same register
when ring is stopped.  We poll for the second bit immediately after writing the first.
If second bit is not cleare after 5 seconds we bail out.

It could be that hardware never clears the bit.

You said you had two android phones connected, and both were restarting.
It could be a race in the command ring stopping code.

Can you reproduce this xhci with only one android device connected?

-Mathias

[toc] | [prev] | [next] | [standalone]

#1635834

FromThomas Fjellstrom <thomas@fjellstrom.ca>
Date2017-05-04 17:20 +0200
Message-ID<tDqHU-5dq-23@gated-at.bofh.it>
In reply to#1635825
On Thursday, May 4, 2017 6:02:53 PM MDT Mathias Nyman wrote:
> On 03.05.2017 22:20, Thomas Fjellstrom wrote:
> > On Wednesday, May 3, 2017 1:54:39 PM MDT Alan Stern wrote:
> >> On Tue, 2 May 2017, Thomas Fjellstrom wrote:
> >>
> >>> I just had a brief lockup, desktop stopped responding, other usb devices 
not
> >>> on the usb3 controller. Two android devices were in the process of 
restarting
> >>>
> >>> It doesn't seem to matter what android devices it is.
> >>>
> >>> [294503.849350] ------------[ cut here ]------------
> >>> [294503.849362] WARNING: CPU: 0 PID: 0 at net/sched/sch_generic.c:316 
dev_watchdog+0x223/0x230
> >>> [294503.849365] NETDEV WATCHDOG: enp4s0 (igb): transmit queue 0 timed 
out
> >>> [294503.849367] Modules linked in: sr_mod cdrom ipt_MASQUERADE 
nf_nat_masquerade_ipv4 iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 
nf_nat_ipv4 xt_addrtype xt_conntrack nf_nat nf_conntrack br_netfilter overlay 
ebtable_filter ebtables ip6table_filter ip6_tables nfsv3 nfs_acl nfs lockd grace 
iptable_filter bridge stp llc amdgpu mfd_core fuse vfat fat eeepc_wmi asus_wmi 
rfkill edac_mce_amd edac_core pcspkr sg amdkfd radeon ttm sunrpc k10temp it87 
hwmon_vid fam15h_power efivarfs ip_tables ipv6 autofs4 crc32c_intel i2c_piix4
> >>> [294503.849407] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.11.0-rc7 #8
> >>> [294503.849410] Hardware name: To be filled by O.E.M. To be filled by 
O.E.M./970 PRO GAMING/AURA, BIOS 0901 11/07/2016
> >>> [294503.849413] Call Trace:
> >>> [294503.849417]  <IRQ>
> >>> [294503.849422]  dump_stack+0x4d/0x63
> >>> [294503.849426]  __warn+0xc6/0xe0
> >>> [294503.849430]  warn_slowpath_fmt+0x46/0x50
> >>> [294503.849434]  dev_watchdog+0x223/0x230
> >>> [294503.849438]  ? qdisc_rcu_free+0x40/0x40
> >>> [294503.849442]  call_timer_fn+0x30/0x160
> >>> [294503.849445]  ? qdisc_rcu_free+0x40/0x40
> >>> [294503.849448]  run_timer_softirq+0x1e1/0x440
> >>> [294503.849453]  ? lapic_next_event+0x18/0x20
> >>> [294503.849456]  ? sched_clock_cpu+0x11/0xd0
> >>> [294503.849459]  __do_softirq+0x101/0x2f0
> >>> [294503.849463]  irq_exit+0xb9/0xc0
> >>> [294503.849466]  smp_apic_timer_interrupt+0x38/0x50
> >>> [294503.849470]  apic_timer_interrupt+0x86/0x90
> >>> [294503.849474] RIP: 0010:acpi_idle_do_entry+0x2c/0x40
> >>> [294503.849476] RSP: 0018:ffffffffb2a03d90 EFLAGS: 00000246 ORIG_RAX: 
ffffffffffffff10
> >>> [294503.849480] RAX: 0000000000000000 RBX: ffff884d1a966c00 RCX: 
0000000000000034
> >>> [294503.849483] RDX: 4ec4ec4ec4ec4ec5 RSI: 0000000000000001 RDI: 
ffff884d1a966c64
> >>> [294503.849485] RBP: ffffffffb2a03dd0 R08: 00000000000003e3 R09: 
0000000000000018
> >>> [294503.849487] R10: 00000000000003c1 R11: 00000000000003d4 R12: 
ffff884d1a966c64
> >>> [294503.849490] R13: 0000000000000001 R14: 0000000000000001 R15: 
0000000000000001
> >>> [294503.849492]  </IRQ>
> >>> [294503.849497]  ? acpi_idle_enter+0xd7/0x290
> >>> [294503.849502]  cpuidle_enter_state+0xed/0x2e0
> >>> [294503.849506]  cpuidle_enter+0x12/0x20
> >>> [294503.849509]  call_cpuidle+0x1e/0x30
> >>> [294503.849512]  do_idle+0x179/0x1d0
> >>> [294503.849515]  cpu_startup_entry+0x5d/0x60
> >>> [294503.849518]  rest_init+0x7f/0x90
> >>> [294503.849522]  start_kernel+0x405/0x412
> >>> [294503.849525]  x86_64_start_reservations+0x24/0x26
> >>> [294503.849528]  x86_64_start_kernel+0x182/0x193
> >>> [294503.849531]  start_cpu+0x14/0x14
> >>> [294503.849534]  ? start_cpu+0x14/0x14
> >>> [294503.849537] ---[ end trace 12db587e781d6e4f ]---
> >>> [294503.849558] igb 0000:04:00.0 enp4s0: Reset adapter
> >>> [294504.576629] xhci_hcd 0000:02:00.0: Stop command ring failed, maybe 
the host is dead
> >>> [294504.576656] xhci_hcd 0000:02:00.0: Abort command ring failed
> >>> [294504.576799] xhci_hcd 0000:02:00.0: xHCI host not responding to stop 
endpoint command.
> >>> [294504.576805] xhci_hcd 0000:02:00.0: Assuming host is dying, halting 
host.
> >>
> >> At this point you have reached the limit of my knowledge.  The best
> >> person to help is Mathias Nyman, the xHCI maintainer (CC'ed).
> >>
> 
> For some reason stopping the command ring fails, ring is stopped by writing 
a
> bit in a register, hardware is supposed to clear another bit in the same 
register
> when ring is stopped.  We poll for the second bit immediately after writing 
the first.
> If second bit is not cleare after 5 seconds we bail out.
> 
> It could be that hardware never clears the bit.
> 
> You said you had two android phones connected, and both were restarting.
> It could be a race in the command ring stopping code.
> 
> Can you reproduce this xhci with only one android device connected?

I'll try my best. I have had issues with this controller with just devices 
connected and no restarting, so I can't guarantee if I can reproduce the same 
exact issue right away.

> -Mathias
> 
> 


-- 
Thomas Fjellstrom
thomas@fjellstrom.ca

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web