USB ExpressCard makes kworker process utilise 72-75% CPU infinitely

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi.

This is basically from:
https://bugzilla.kernel.org/show_bug.cgi?id=108341
and
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=805903
respectively
https://www.spinics.net/lists/linux-usb/msg151899.html
the later in which Grek KH recommended me to ping linux-acpi as
well.


I bought a USB3.0 ExpressCard from StarTech[0] which is apparently[1]
based on the NEC uPD720200.

Using a kernel 4.2.6 (see further below for the same on a more recent
kernel version) on amd64, the System is Debian sid, the following
happens when I plug the card:

kernel logs show:
Nov 21 17:15:22 heisenberg kernel: [  102.387452] pci 0000:01:00.0: [1033:0194] type 00 class 0x0c0330
Nov 21 17:15:22 heisenberg kernel: [  102.387545] pci 0000:01:00.0: reg 0x10: [mem0x00000000-0x00001fff 64bit]
Nov 21 17:15:22 heisenberg kernel: [  102.387723] pci 0000:01:00.0: PME# supported from D0 D3hot
Nov 21 17:15:22 heisenberg kernel: [  102.394689] pci 0000:01:00.0: BAR 0: assigned [mem0xf0d00000-0xf0d01fff 64bit]
Nov 21 17:15:22 heisenberg kernel: [  102.394750] pci 0000:01:00.0: enabling device (0000 -> 0002)
Nov 21 17:15:22 heisenberg kernel: [  102.395178] xhci_hcd 0000:01:00.0: xHCI Host Controller
Nov 21 17:15:22 heisenberg kernel: [  102.395192] xhci_hcd 0000:01:00.0: new USB bus registered,assigned bus number 5
Nov 21 17:15:22 heisenberg kernel: [  102.395418] xhci_hcd 0000:01:00.0: hcc params 0x014042cb hciversion 0x96 quirks 0x00000004
Nov 21 17:15:22 heisenberg kernel: [  102.395892] usb usb5: New USB device found, idVendor=1d6b, idProduct=0002
Nov 21 17:15:22 heisenberg kernel: [  102.395896] usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Nov 21 17:15:22 heisenberg kernel: [  102.395899] usb usb5: Product: xHCI Host Controller
Nov 21 17:15:22 heisenberg kernel: [  102.395902] usb usb5: Manufacturer: Linux 4.2.0-1-amd64 xhci-hcd
Nov 21 17:15:22 heisenberg kernel: [  102.395905] usb usb5: SerialNumber: 0000:01:00.0
Nov 21 17:15:22 heisenberg kernel: [  102.396308] hub 5-0:1.0: USB hub found
Nov 21 17:15:22 heisenberg kernel: [  102.396331] hub 5-0:1.0: 2 ports detected
Nov 21 17:15:22 heisenberg kernel: [  102.396591] xhci_hcd 0000:01:00.0: xHCI Host Controller
Nov 21 17:15:22 heisenberg kernel: [  102.396599] xhci_hcd 0000:01:00.0: new USB bus registered,assigned bus number 6
Nov 21 17:15:22 heisenberg kernel: [  102.398835] usb usb6: We don't know the algorithms for LPM forthis host, disabling LPM.
Nov 21 17:15:22 heisenberg kernel: [  102.398883] usb usb6: New USB device found, idVendor=1d6b, idProduct=0003
Nov 21 17:15:22 heisenberg kernel: [  102.398887] usb usb6: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Nov 21 17:15:22 heisenberg kernel: [  102.398890] usb usb6: Product: xHCI Host Controller
Nov 21 17:15:22 heisenberg kernel: [  102.398892] usb usb6: Manufacturer: Linux 4.2.0-1-amd64 xhci-hcd
Nov 21 17:15:22 heisenberg kernel: [  102.398895] usb usb6: SerialNumber: 0000:01:00.0
Nov 21 17:15:22 heisenberg kernel: [  102.399272] hub 6-0:1.0: USB hub found
Nov 21 17:15:22 heisenberg kernel: [  102.399294] hub 6-0:1.0: 2 ports detected

and when removing:
Nov 21 17:15:40 heisenberg kernel: [  120.541515] xhci_hcd 0000:01:00.0: remove, state 4
Nov 21 17:15:40 heisenberg kernel: [  120.544671] usb usb6: USB disconnect, device number 1
Nov 21 17:15:40 heisenberg kernel: [  120.546683] xhci_hcd 0000:01:00.0: Host not halted after 16000 microseconds.
Nov 21 17:15:40 heisenberg kernel: [  120.547611] xhci_hcd 0000:01:00.0: USB bus 6 deregistered
Nov 21 17:15:40 heisenberg kernel: [  120.547618] xhci_hcd 0000:01:00.0: remove, state 4
Nov 21 17:15:40 heisenberg kernel: [  120.547622] usb usb5: USB disconnect, device number 1
Nov 21 17:15:40 heisenberg kernel: [  120.547735] xhci_hcd 0000:01:00.0: USB bus 5 deregistered

Now the problem is that immediately when I attach the card, a kworker
process starts to utilise the CPU to always around 72%.
And it never stops again until I shutdown; removing the card doesn't
help.



On a more recent:
$ uname -a
Linux heisenberg 4.8.0-2-amd64 #1 SMP Debian 4.8.15-2 (2017-01-04) x86_64 GNU/Linux


kernel log for the inserted USB3.0 ExpressCard from StarTech:
Jan 12 14:15:13 heisenberg kernel: pci 0000:01:00.0: [1033:0194] type 00 class 0x0c0330
Jan 12 14:15:13 heisenberg kernel: pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00001fff 64bit]
Jan 12 14:15:13 heisenberg kernel: pci 0000:01:00.0: PME# supported from D0 D3hot
Jan 12 14:15:13 heisenberg kernel: pci 0000:01:00.0: BAR 0: assigned [mem 0xf0d00000-0xf0d01fff 64bit]
Jan 12 14:15:13 heisenberg kernel: pci 0000:01:00.0: enabling device (0000 -> 0002)
Jan 12 14:15:13 heisenberg kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller
Jan 12 14:15:13 heisenberg kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 5
Jan 12 14:15:13 heisenberg kernel: xhci_hcd 0000:01:00.0: hcc params 0x014042cb hci version 0x96 quirks 0x00000004
Jan 12 14:15:13 heisenberg kernel: usb usb5: New USB device found, idVendor=1d6b, idProduct=0002
Jan 12 14:15:13 heisenberg kernel: usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Jan 12 14:15:13 heisenberg kernel: usb usb5: Product: xHCI Host Controller
Jan 12 14:15:13 heisenberg kernel: usb usb5: Manufacturer: Linux 4.8.0-2-amd64 xhci-hcd
Jan 12 14:15:13 heisenberg kernel: usb usb5: SerialNumber: 0000:01:00.0
Jan 12 14:15:13 heisenberg kernel: hub 5-0:1.0: USB hub found
Jan 12 14:15:13 heisenberg kernel: hub 5-0:1.0: 2 ports detected
Jan 12 14:15:13 heisenberg kernel: xhci_hcd 0000:01:00.0: xHCI Host Controller
Jan 12 14:15:13 heisenberg kernel: xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 6
Jan 12 14:15:13 heisenberg kernel: usb usb6: We don't know the algorithms for LPM for this host, disabling LPM.
Jan 12 14:15:13 heisenberg kernel: usb usb6: New USB device found, idVendor=1d6b, idProduct=0003
Jan 12 14:15:13 heisenberg kernel: usb usb6: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Jan 12 14:15:13 heisenberg kernel: usb usb6: Product: xHCI Host Controller
Jan 12 14:15:13 heisenberg kernel: usb usb6: Manufacturer: Linux 4.8.0-2-amd64 xhci-hcd
Jan 12 14:15:13 heisenberg kernel: usb usb6: SerialNumber: 0000:01:00.0
Jan 12 14:15:13 heisenberg kernel: hub 6-0:1.0: USB hub found
Jan 12 14:15:13 heisenberg kernel: hub 6-0:1.0: 2 ports detected
Jan 12 14:15:15 heisenberg kernel: hub 6-0:1.0: USB hub found
Jan 12 14:15:15 heisenberg kernel: hub 6-0:1.0: 2 ports detected
Jan 12 14:15:15 heisenberg kernel: usb usb6: authorized to connect
Jan 12 14:15:16 heisenberg kernel: hub 5-0:1.0: USB hub found
Jan 12 14:15:16 heisenberg kernel: hub 5-0:1.0: 2 ports detected
Jan 12 14:15:16 heisenberg kernel: usb usb5: authorized to connect


then top shows this kworker, which remains at ~75% CPU until reboot:
 2359 root      20   0       0      0      0 R  74,8  0,0   0:46.82 kworker/0:3                                                                                                               

# perf top -p 2359 gives something like that:
Samples: 64K of event 'cycles:ppp', Event count (approx.): 19127246624
Overhead  Shared Object     Symbol
  19,91%  [kernel]          [k] acpi_ns_search_one_scope
  11,18%  [kernel]          [k] acpi_os_write_port
   8,51%  [kernel]          [k] pci_conf1_read
   7,59%  [kernel]          [k] acpi_ex_system_memory_space_handler
   3,57%  [kernel]          [k] acpi_os_read_port
   2,84%  [kernel]          [k] kmem_cache_alloc
   2,27%  [kernel]          [k] acpi_ut_get_next_predefined_method
   1,96%  [kernel]          [k] nmi
   1,95%  [kernel]          [k] kmem_cache_free
   1,73%  [kernel]          [k] ___cache_free
   1,33%  [kernel]          [k] acpi_ut_match_predefined_method
   1,10%  [kernel]          [k] perf_pmu_sched_task
   1,09%  [kernel]          [k] acpi_ns_lookup
   0,99%  [kernel]          [k] _raw_spin_lock_irqsave
   0,97%  [kernel]          [k] acpi_ns_build_normalized_path
   0,92%  [kernel]          [k] acpi_ps_parse_loop
   0,87%  [kernel]          [k] native_write_msr
   0,83%  [kernel]          [k] memset_erms
   0,82%  [kernel]          [k] acpi_ns_search_and_enter
   0,79%  [kernel]          [k] acpi_ut_update_object_reference
   0,71%  [kernel]          [k] acpi_ps_get_opcode_info
   0,70%  [kernel]          [k] kfree
   0,69%  [kernel]          [k] acpi_ps_create_op
   0,64%  [kernel]          [k] _raw_spin_unlock_irqrestore
   0,63%  [kernel]          [k] process_one_work
   0,59%  [kernel]          [k] __kmalloc
   0,56%  [kernel]          [k] acpi_ds_exec_end_op
   0,53%  [kernel]          [k] kmem_cache_alloc_trace
   0,50%  [kernel]          [k] acpi_ut_update_ref_count
   0,48%  [kernel]          [k] acpi_ut_repair_name
   0,47%  [kernel]          [k] acpi_hw_validate_io_request
   0,40%  [kernel]          [k] acpi_ds_create_operand
   0,39%  [kernel]          [k] acpi_ex_resolve_operands
   0,38%  [kernel]          [k] acpi_ut_valid_name_char
   0,36%  [kernel]          [k] acpi_ut_acquire_mutex
   0,35%  [kernel]          [k] _cond_resched
   0,35%  [kernel]          [k] acpi_ut_create_internal_object_dbg
   0,35%  [kernel]          [k] __schedule
   0,34%  [kernel]          [k] acpi_ex_resolve_to_value
   0,33%  [kernel]          [k] acpi_ex_name_segment
   0,31%  [kernel]          [k] _raw_spin_lock
   0,31%  [kernel]          [k] acpi_os_wait_semaphore
   0,31%  [kernel]          [k] memcg_kmem_put_cache
   0,31%  [kernel]          [k] strcat
   0,30%  [kernel]          [k] acpi_ps_alloc_op
   0,29%  [kernel]          [k] acpi_ex_access_region
   0,29%  [kernel]          [k] acpi_ex_read_data_from_field
   0,29%  [kernel]          [k] acpi_ex_extract_from_field
   0,28%  [kernel]          [k] acpi_ut_create_generic_state
   0,27%  [kernel]          [k] finish_task_switch


during the perf, the max sample rate is lowered (which is however normal I'd guess):
Jan 12 14:17:01 heisenberg kernel: perf: interrupt took too long (2502 > 2500), lowering kernel.perf_event_max_sample_rate to 79750
Jan 12 14:17:01 heisenberg kernel: perf: interrupt took too long (3130 > 3127), lowering kernel.perf_event_max_sample_rate to 63750
Jan 12 14:17:01 heisenberg kernel: perf: interrupt took too long (3913 > 3912), lowering kernel.perf_event_max_sample_rate to 51000
Jan 12 14:17:01 heisenberg kernel: perf: interrupt took too long (4909 > 4891), lowering kernel.perf_event_max_sample_rate to 40500


and this is what I get when removing the express card again:
Jan 12 14:17:55 heisenberg kernel: xhci_hcd 0000:01:00.0: remove, state 4
Jan 12 14:17:55 heisenberg kernel: usb usb6: USB disconnect, device number 1
Jan 12 14:17:55 heisenberg kernel: xhci_hcd 0000:01:00.0: Host not halted after 16000 microseconds.
Jan 12 14:17:55 heisenberg kernel: xhci_hcd 0000:01:00.0: USB bus 6 deregistered
Jan 12 14:17:55 heisenberg kernel: xhci_hcd 0000:01:00.0: remove, state 4
Jan 12 14:17:55 heisenberg kernel: usb usb5: USB disconnect, device number 1
Jan 12 14:17:55 heisenberg kernel: xhci_hcd 0000:01:00.0: USB bus 5 deregistered


Just in case it helps:
# lspci
00:00.0 Host bridge: Intel Corporation 3rd Gen Core processor DRAM
Controller (rev 09)
00:02.0 VGA compatible controller: Intel Corporation 3rd Gen Core
processor Graphics Controller (rev 09)
00:14.0 USB controller: Intel Corporation 7 Series/C210 Series Chipset
Family USB xHCI Host Controller (rev 04)
00:16.0 Communication controller: Intel Corporation 7 Series/C216
Chipset Family MEI Controller #1 (rev 04)
00:16.3 Serial controller: Intel Corporation 7 Series/C210 Series
Chipset Family KT Controller (rev 04)
00:19.0 Ethernet controller: Intel Corporation 82579LM Gigabit Network
Connection (rev 04)
00:1a.0 USB controller: Intel Corporation 7 Series/C216 Chipset Family
USB Enhanced Host Controller #2 (rev 04)
00:1b.0 Audio device: Intel Corporation 7 Series/C216 Chipset Family
High Definition Audio Controller (rev 04)
00:1c.0 PCI bridge: Intel Corporation 7 Series/C216 Chipset Family PCI
Express Root Port 1 (rev c4)
00:1c.2 PCI bridge: Intel Corporation 7 Series/C210 Series Chipset
Family PCI Express Root Port 3 (rev c4)
00:1c.7 PCI bridge: Intel Corporation 7 Series/C210 Series Chipset
Family PCI Express Root Port 8 (rev c4)
00:1d.0 USB controller: Intel Corporation 7 Series/C216 Chipset Family
USB Enhanced Host Controller #1 (rev 04)
00:1f.0 ISA bridge: Intel Corporation QM77 Express Chipset LPC
Controller (rev 04)
00:1f.2 SATA controller: Intel Corporation 7 Series Chipset Family 6-
port SATA Controller [AHCI mode] (rev 04)
00:1f.3 SMBus: Intel Corporation 7 Series/C216 Chipset Family SMBus
Controller (rev 04)
01:00.0 USB controller: NEC Corporation uPD720200 USB 3.0 Host
Controller (rev 04)
0a:00.0 Network controller: Intel Corporation Centrino Advanced-N 6205
[Taylor Peak] (rev 34)
0b:00.0 Unassigned class [ff00]: Realtek Semiconductor Co., Ltd.
RTS5229 PCI Express Card Reader (rev 01)


# lsusb
Bus 002 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching
Hub
Bus 002 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 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 010: ID 04f2:b2fc Chicony Electronics Co., Ltd 
Bus 001 Device 004: ID 0489:e052 Foxconn / Hon Hai 
Bus 001 Device 006: ID 0b97:7772 O2 Micro, Inc. OZ776 CCID Smartcard
Reader
Bus 001 Device 003: ID 0b97:7761 O2 Micro, Inc. Oz776 1.1 Hub
Bus 001 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching
Hub
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 003 Device 003: ID 0409:005a NEC Corp. HighSpeed Hub
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub


Any ideas?
Don't hesitate to ask if you'd need more information.

Thanks,
Chris.

[0] http://www.startech.com/Cards-Adapters/USB-3.0/Cards/2-Port-Flush-Mount-USB-3-ExpressCard-Adapter~ECUSB3S254F
[1] http://sgcdn.startech.com/005329/media/sets/ECUSB3S254F_Manual/ECUSB3S254F.pdf

Attachment: smime.p7s
Description: S/MIME cryptographic signature


[Index of Archives]     [Linux IBM ACPI]     [Linux Power Management]     [Linux Kernel]     [Linux Laptop]     [Kernel Newbies]     [Share Photos]     [Security]     [Netfilter]     [Bugtraq]     [Yosemite News]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Linux RAID]     [Samba]     [Video 4 Linux]     [Device Mapper]     [Linux Resources]

  Powered by Linux