Unknown usb port causes strange behaviour

Getting your soundcard to work, using Debian on non-i386 hardware, etc

Unknown usb port causes strange behaviour

Postby Battleman » 2019-01-13 13:59

Hello,
I've lived happily with my Lenovo for some time now, with various OS. For a few years, Debian has become my favourite pic, and I'm loving it! But since recently, I suffered strange behaviours, that seem to be caused by a USB device, but I can't troubleshoot the problem (neither the actual device!), Here is what I know:

Whenever I try to put my computer to sleep, it hangs for a few seconds before resuming, as if nothing happened (though it's locked now). When trying to shut down, it's basically the same, except the computer totally hangs and can only be force-shutdown or rebooted with Magic-Sysrq keys REISUB combination.

Inspecting the output of dmesg, I see the following:

Code: Select all
>dmesg
...
[19713.176082] PM: suspend entry (deep)
[19713.176085] PM: Syncing filesystems ... done.
[19713.191792] (NULL device *): firmware: direct-loading firmware intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq
[19713.191998] (NULL device *): firmware: direct-loading firmware iwlwifi-7260-17.ucode
[19713.192025] Freezing user space processes ... (elapsed 0.002 seconds) done.
[19713.194077] OOM killer disabled.
[19713.194078] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
[19713.195475] Suspending console(s) (use no_console_suspend to debug)
[19713.195871] wlp3s0: deauthenticating from 1c:24:cd:02:d2:49 by local choice (Reason: 3=DEAUTH_LEAVING)
[19713.326862] dpm_run_callback(): usb_dev_suspend+0x0/0x10 [usbcore] returns -16
[19713.326865] PM: Device usb2 failed to suspend async: error -16
[19713.346351] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[19713.347552] sd 0:0:0:0: [sda] Stopping disk
[19713.350296] sd 5:0:0:0: [sdb] Synchronizing SCSI cache
[19713.353586] sd 5:0:0:0: [sdb] Stopping disk
[19713.568201] PM: Some devices failed to suspend, or early wake event detected
[19713.568481] sd 0:0:0:0: [sda] Starting disk
[19713.568482] sd 5:0:0:0: [sdb] Starting disk
[19714.273473] psmouse serio1: synaptics: queried max coordinates: x [..5674], y [..4684]
[19714.305644] psmouse serio1: synaptics: queried min coordinates: x [1266..], y [1170..]
[19714.415141] acpi LNXPOWER:02: Turning OFF
[19714.415412] OOM killer enabled.
[19714.415415] Restarting tasks ... done.
[19714.441267] PM: suspend exit
[19714.441433] PM: suspend entry (s2idle)
[19714.441437] PM: Syncing filesystems ... done.
[19714.451333] Freezing user space processes ... (elapsed 0.002 seconds) done.
[19714.453675] OOM killer disabled.
[19714.453676] Freezing remaining freezable tasks ...
[19714.554327] usb 2-13: new full-speed USB device number 18 using xhci_hcd
[19719.718378] usb 2-13: device descriptor read/64, error -110
[19719.954380] usb 2-13: device descriptor read/64, error -71
[19720.190363] usb 2-13: new full-speed USB device number 19 using xhci_hcd
[19720.318385] usb 2-13: device descriptor read/64, error -71
[19720.554386] usb 2-13: device descriptor read/64, error -71
[19720.662421] usb usb2-port13: attempt power cycle
[19721.314371] usb 2-13: new full-speed USB device number 20 using xhci_hcd
[19721.314666] usb 2-13: Device not responding to setup address.
[19721.522656] usb 2-13: Device not responding to setup address.
[19721.730369] usb 2-13: device not accepting address 20, error -71
[19721.858375] usb 2-13: new full-speed USB device number 21 using xhci_hcd
[19721.858667] usb 2-13: Device not responding to setup address.
[19722.066666] usb 2-13: Device not responding to setup address.
[19722.274373] usb 2-13: device not accepting address 21, error -71
[19722.274428] usb usb2-port13: unable to enumerate USB device
[19722.280663] (elapsed 7.826 seconds) done.
[19722.280671] Suspending console(s) (use no_console_suspend to debug)
[19722.426410] sd 5:0:0:0: [sdb] Synchronizing SCSI cache
[19722.428973] sd 5:0:0:0: [sdb] Stopping disk
[19722.430409] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[19722.433294] sd 0:0:0:0: [sda] Stopping disk
[19722.518391] dpm_run_callback(): usb_dev_suspend+0x0/0x10 [usbcore] returns -16
[19722.518395] PM: Device usb2 failed to suspend async: error -16
[19722.620663] PM: Some devices failed to suspend, or early wake event detected
[19722.621362] sd 0:0:0:0: [sda] Starting disk
[19722.621392] sd 5:0:0:0: [sdb] Starting disk
[19722.866752] OOM killer enabled.
[19722.866754] Restarting tasks ... done.
[19722.915468] PM: suspend exit
[19722.934877] ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[19722.938411] ata1.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
[19722.938417] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
[19722.938421] ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
[19722.939116] ata1.00: supports DRM functions and may not be fully accessible
[19722.939491] ata1.00: NCQ Send/Recv Log not supported
[19722.941275] ata1.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
[19722.941280] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
[19722.941284] ata1.00: ACPI cmd ef/10:03:00:00:00:a0 (SET FEATURES) filtered out
[19722.941424] ata1.00: supports DRM functions and may not be fully accessible
[19722.941789] ata1.00: NCQ Send/Recv Log not supported
[19722.942264] ata1.00: configured for UDMA/133
[19722.963295] wlp3s0: authenticate with 1c:24:cd:02:d2:40
[19722.965288] wlp3s0: send auth to 1c:24:cd:02:d2:40 (try 1/3)
[19722.967585] wlp3s0: authenticated
[19722.970342] wlp3s0: associate with 1c:24:cd:02:d2:40 (try 1/3)
[19722.974110] wlp3s0: RX AssocResp from 1c:24:cd:02:d2:40 (capab=0x411 status=0 aid=3)
[19722.975613] wlp3s0: associated
[19722.994353] usb 2-13: new full-speed USB device number 22 using xhci_hcd
[19723.122339] usb 2-13: device descriptor read/64, error -71
[19723.137874] e1000e: enp0s25 NIC Link is Down
[19723.171809] wlp3s0: deauthenticating from 1c:24:cd:02:d2:40 by local choice (Reason: 3=DEAUTH_LEAVING)
[19723.203993] IPv6: ADDRCONF(NETDEV_UP): enp0s25: link is not ready
[19723.358330] usb 2-13: device descriptor read/64, error -71
[19723.362010] psmouse serio1: synaptics: queried max coordinates: x [..5674], y [..4684]
[19723.392619] psmouse serio1: synaptics: queried min coordinates: x [1266..], y [1170..]
[19723.422520] IPv6: ADDRCONF(NETDEV_UP): enp0s25: link is not ready
[19723.423753] IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready
[19723.425185] IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready
[19723.427222] IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready
[19723.598344] usb 2-13: new full-speed USB device number 23 using xhci_hcd
[19723.608657] IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready
[19723.726355] usb 2-13: device descriptor read/64, error -71
[19723.970347] usb 2-13: device descriptor read/64, error -71
[19724.082350] usb usb2-port13: attempt power cycle
[19724.734396] usb 2-13: new full-speed USB device number 24 using xhci_hcd
[19724.734693] usb 2-13: Device not responding to setup address.
[19724.942518] usb 2-13: Device not responding to setup address.
[19725.154395] usb 2-13: device not accepting address 24, error -71
[19725.286385] usb 2-13: new full-speed USB device number 25 using xhci_hcd
[19725.286647] usb 2-13: Device not responding to setup address.
[19725.494561] usb 2-13: Device not responding to setup address.
[19725.702327] usb 2-13: device not accepting address 25, error -71
[19725.702383] usb usb2-port13: unable to enumerate USB device
[19726.993775] IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready
[19730.372852] wlp3s0: authenticate with 1c:24:cd:02:d2:49
[19730.375400] wlp3s0: send auth to 1c:24:cd:02:d2:49 (try 1/3)
[19730.378045] wlp3s0: authenticated
[19730.378382] wlp3s0: associate with 1c:24:cd:02:d2:49 (try 1/3)
[19730.379923] wlp3s0: RX AssocResp from 1c:24:cd:02:d2:49 (capab=0x11 status=0 aid=2)
[19730.381717] wlp3s0: associated
[19730.403895] IPv6: ADDRCONF(NETDEV_CHANGE): wlp3s0: link becomes ready
[19730.480892] wlp3s0: Limiting TX power to 24 (24 - 0) dBm as advertised by 1c:24:cd:02:d2:49


Some background: sda is my main disk, Debian is on sda3. sdb is a secondary SSD. There are no other USB devices plugged.

So clearly there is something fishy there
Code: Select all
[19713.326862] dpm_run_callback(): usb_dev_suspend+0x0/0x10 [usbcore] returns -16
[19713.326865] PM: Device usb2 failed to suspend async: error -16
...
[19713.568201] PM: Some devices failed to suspend, or early wake event detected
...
[19719.718378] usb 2-13: device descriptor read/64, error -110
[19719.954380] usb 2-13: device descriptor read/64, error -71
[19720.190363] usb 2-13: new full-speed USB device number 19 using xhci_hcd
[19720.318385] usb 2-13: device descriptor read/64, error -71
[19720.554386] usb 2-13: device descriptor read/64, error -71
[19720.662421] usb usb2-port13: attempt power cycle
[19721.314371] usb 2-13: new full-speed USB device number 20 using xhci_hcd
[19721.314666] usb 2-13: Device not responding to setup address.
[19721.522656] usb 2-13: Device not responding to setup address.
[19721.730369] usb 2-13: device not accepting address 20, error -71
[19721.858375] usb 2-13: new full-speed USB device number 21 using xhci_hcd
[19721.858667] usb 2-13: Device not responding to setup address.
[19722.066666] usb 2-13: Device not responding to setup address.
[19722.274373] usb 2-13: device not accepting address 21, error -71
[19722.274428] usb usb2-port13: unable to enumerate USB device


From what I understand, USB device 2 at port 13 has a problem. Error -110 indicates error with power (not enough power ?) and -71 I'm not sure.

Here is the output from
Code: Select all
>lsusb
Bus 003 Device 002: ID 8087:8000 Intel Corp.
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 002: ID 8087:8008 Intel Corp.
Bus 001 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 002 Device 003: ID 138a:0017 Validity Sensors, Inc. VFS 5011 fingerprint sensor
Bus 002 Device 009: ID 8087:07dc Intel Corp.
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub


and
Code: Select all
>usb-devices | grep Port

T:  Bus=01 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=480 MxCh= 3
T:  Bus=01 Lev=01 Prnt=01 Port=00 Cnt=01 Dev#=  2 Spd=480 MxCh= 6
T:  Bus=02 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=480 MxCh=15
T:  Bus=02 Lev=01 Prnt=01 Port=10 Cnt=01 Dev#=  9 Spd=12  MxCh= 0
T:  Bus=02 Lev=01 Prnt=01 Port=06 Cnt=02 Dev#=  3 Spd=12  MxCh= 0
T:  Bus=03 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=480 MxCh= 3
T:  Bus=03 Lev=01 Prnt=01 Port=00 Cnt=01 Dev#=  2 Spd=480 MxCh= 8
T:  Bus=04 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=5000 MxCh= 6

(very verbose, I only kept the ports). So from what I see, there is no device 2 - port 13.

What happens ? I had no problem before, but suddely I am completely unable to put it to sleep, and mostly (can't pin a rul) unable to shut it down properly...
Any help appreciated ! Thanks.
Battleman
 
Posts: 2
Joined: 2019-01-13 13:32

Re: Unknown usb port causes strange behaviour

Postby Head_on_a_Stick » 2019-01-13 15:50

Disable the fingerprint sensor from the firmware ("BIOS") menu, perhaps?

The systemd journal may have more clues (or maybe not), enable persistent logging with
Code: Select all
# mkdir -p /var/log/journal # remove the folder to return to non-persistent logging

Then use this to examine the logs from the last boot in reverse order:
Code: Select all
# journalctl -b -1 -r
"The trouble with the world is that the stupid are cocksure and the intelligent full of doubt." — Bertrand Russell
User avatar
Head_on_a_Stick
 
Posts: 8838
Joined: 2014-06-01 17:46
Location: /dev/chair

Re: Unknown usb port causes strange behaviour

Postby Battleman » 2019-01-14 08:11

Hi, thank you for your answer!
The fingerprint is already as disabled as possible (I don't see any option to completely disable it).

systemd journal didn't yield much more information. Interesting point: apparently, here it is usb 1-13 that causes troubles... an excerpt:
Code: Select all
...
jan 14 09:23:05 lenovow540 kernel: usb usb1-port13: unable to enumerate USB device
jan 14 09:23:05 lenovow540 kernel: usb 1-13: device not accepting address 8, error -71
...
jan 14 09:23:05 lenovow540 kernel: usb 1-13: Device not responding to setup address.
...
jan 14 09:23:05 lenovow540 kernel: usb 1-13: Device not responding to setup address.
jan 14 09:23:05 lenovow540 kernel: usb 1-13: new full-speed USB device number 8 using xhci_hcd
...
jan 14 09:23:05 lenovow540 kernel: usb 1-13: device not accepting address 7, error -71
...
jan 14 09:23:04 lenovow540 kernel: usb 1-13: Device not responding to setup address.
jan 14 09:23:04 lenovow540 kernel: usb 1-13: Device not responding to setup address.
jan 14 09:23:04 lenovow540 kernel: usb 1-13: new full-speed USB device number 7 using xhci_hcd
jan 14 09:23:04 lenovow540 kernel: usb usb1-port13: attempt power cycle
jan 14 09:23:04 lenovow540 kernel: usb 1-13: device descriptor read/64, error -71
...
jan 14 09:23:03 lenovow540 kernel: usb 1-13: new full-speed USB device number 6 using xhci_hcd
...
jan 14 09:23:03 lenovow540 kernel: usb 1-13: device descriptor read/64, error -71
...
jan 14 09:23:03 lenovow540 kernel: usb 1-13: new full-speed USB device number 5 using xhci_hcd

The rest seems to be usual. Some minor unrelated errors, e.g. with nouveau
Battleman
 
Posts: 2
Joined: 2019-01-13 13:32

Re: Unknown usb port causes strange behaviour

Postby llivv » 2019-01-14 14:24

Battleman wrote:Hello,Inspecting the output of dmesg, I see the following:
Code: Select all
>dmesg [...]
[19713.176082] PM: suspend entry (deep)
[19713.176085] PM: Syncing filesystems ... done.\
[....]
[19713.192025] Freezing user space processes ... (elapsed 0.002 seconds) done.
[19713.194077] OOM killer disabled.
[19713.194078] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
[19713.195475] Suspending console(s) (use no_console_suspend to debug)
[.....]
[19722.280671] Suspending console(s) (use no_console_suspend to debug)
[....]
[19722.518391] dpm_run_callback(): usb_dev_suspend+0x0/0x10 [usbcore] returns -16
[19722.518395] PM: Device usb2 failed to suspend async: error -16
[19722.620663] PM: Some devices failed to suspend, or early wake event detected
[....]
[19722.994353] usb 2-13: new full-speed USB device number 22 using xhci_hcd
[19723.122339] usb 2-13: device descriptor read/64, error -71
[...]
[19723.358330] usb 2-13: device descriptor read/64, error -71
[...]
[19723.598344] usb 2-13: new full-speed USB device number 23 using xhci_hcd
[....] 1 line
[19723.726355] usb 2-13: device descriptor read/64, error -71
[19723.970347] usb 2-13: device descriptor read/64, error -71
[19724.082350] usb usb2-port13: attempt power cycle
[19724.734396] usb 2-13: new full-speed USB device number 24 using xhci_hcd
[19724.734693] usb 2-13: Device not responding to setup address.
[19724.942518] usb 2-13: Device not responding to setup address.
[19725.154395] usb 2-13: device not accepting address 24, error -71
[19725.286385] usb 2-13: new full-speed USB device number 25 using xhci_hcd
[19725.286647] usb 2-13: Device not responding to setup address.
[19725.494561] usb 2-13: Device not responding to setup address.
[19725.702327] usb 2-13: device not accepting address 25, error -71
[19725.702383] usb usb2-port13: unable to enumerate USB device
[....] 9 lines


Code: Select all
[19713.326862] dpm_run_callback(): usb_dev_suspend+0x0/0x10 [usbcore] returns -16
[19713.326865] PM: Device usb2 failed to suspend async: error -16
[...]
[19713.568201] PM: Some devices failed to suspend, or early wake event detected
[...]
[19719.718378] usb 2-13: device descriptor read/64, error -110
[....]
[19720.190363] usb 2-13: new full-speed USB device number 19 using xhci_hcd
[....]
[19720.554386] usb 2-13: device descriptor read/64, error -71
[19720.662421] usb usb2-port13: attempt power cycle
[....]
[19721.730369] usb 2-13: device not accepting address 20, error -71
[19721.858375] usb 2-13: new full-speed USB device number 21 using xhci_hcd
[19721.858667] usb 2-13: Device not responding to setup address.
[19722.066666] usb 2-13: Device not responding to setup address.
[19722.274428] usb usb2-port13: unable to enumerate USB device


The easy stuff first to get it out of the way - be ready for more complicated things later...
from dmesg above
Code: Select all
[19713.195475] Suspending console(s) (use no_console_suspend to debug)

append the kernel boot parameters in grub adding
Code: Select all
no_console_suspend

try
Code: Select all
>usb-devices | grep Product

instead
also try
plugging a usb [anything you have] into each usb port
Code: Select all
usb 2-13: Device not responding to setup address.

identify usb 2-13 event(s) in the kernel log when plugging in a device?.
In memory of Ian Ashley Murdock (1973 - 2015) founder of the Debian project.
User avatar
llivv
 
Posts: 5738
Joined: 2007-02-14 18:10
Location: cold storage


Return to Hardware

Who is online

Users browsing this forum: No registered users and 7 guests

fashionable