raspberrypi / linux

Kernel source tree for Raspberry Pi-provided kernel builds. Issues unrelated to the linux kernel should be posted on the community forum at https://forums.raspberrypi.com/
Other
11.08k stars 4.96k forks source link

USB device requires unplugging and re-plugging to make it work after reboot. #5046

Closed ReneElizondo closed 1 year ago

ReneElizondo commented 2 years ago

Describe the bug

I am trying to get a device called ThingMagic USB Pro UHF Reader (a USB device) to work properly with a Raspberry Pi 4. For the most part, everything works perfectly fine until I reboot or turn the Raspberry Pi off and on, if I do that, the Raspberry Pi no longer recognizes the ThingMagic USB Pro UHF Reader, I must unplug and re-plug the ThingMagic USB cable in order to get things to work again.

Some observations:

Below is a snapshot of what I think are the important bits from dmesg (full dmesg below):

dmesg1

Steps to reproduce the behaviour

Unfortunately, to reproduce this issue you will need a device called ThingMagic USB Pro UHF Reader. But if you have one :), then all you need to do is plug it in, boot the Raspberry Pi and you will experience the pain.

Device (s)

Raspberry Pi 4 Mod. B

System

$ cat /etc/rpi-issue Raspberry Pi reference 2022-04-04 Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 226b479f8d32919c9fe36dd5b4c20c02682f8180, stage4

$ vcgencmd version Mar 24 2022 13:19:26 Copyright (c) 2012 Broadcom version e5a963efa66a1974127860b42e913d2374139ff5 (clean) (release) (start)

$ uname -a Linux raspberrypi 5.15.32-v7l+ #1538 SMP Thu Mar 31 19:39:41 BST 2022 armv7l GNU/Linux

Logs

[ 0.000000] Booting Linux on physical CPU 0x0 [ 0.000000] Linux version 5.15.32-v7l+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1538 SMP Thu Mar 31 19:39:41 BST 2022 [ 0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d [ 0.000000] CPU: div instructions available: patching division code [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache [ 0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.4 [ 0.000000] random: fast init done [ 0.000000] Memory policy: Data cache writealloc [ 0.000000] Reserved memory: created CMA memory pool at 0x000000001ac00000, size 320 MiB [ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool [ 0.000000] Zone ranges: [ 0.000000] DMA [mem 0x0000000000000000-0x000000002fffffff] [ 0.000000] Normal empty [ 0.000000] HighMem [mem 0x0000000030000000-0x00000000fbffffff] [ 0.000000] Movable zone start for each node [ 0.000000] Early memory node ranges [ 0.000000] node 0: [mem 0x0000000000000000-0x000000003b3fffff] [ 0.000000] node 0: [mem 0x0000000040000000-0x00000000fbffffff] [ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff] [ 0.000000] percpu: Embedded 16 pages/cpu s35788 r8192 d21556 u65536 [ 0.000000] pcpu-alloc: s35788 r8192 d21556 u65536 alloc=16*4096 [ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1011008 [ 0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 video=HDMI-A-1:1920x1080M@60 smsc95xx.macaddr=E4:5F:01:79:62:B7 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 console=ttyS0,115200 console=tty1 root=PARTUUID=e6fc1d7b-02 rootfstype=ext4 fsck.repair=yes rootwait quiet splash plymouth.ignore-serial-consoles [ 0.000000] Unknown kernel command line parameters "splash", will be passed to user space. [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear) [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear) [ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off [ 0.000000] software IO TLB: mapped [mem 0x0000000014890000-0x0000000018890000] (64MB) [ 0.000000] Memory: 3601320K/4050944K available (10240K kernel code, 1390K rwdata, 3292K rodata, 2048K init, 590K bss, 121944K reserved, 327680K cma-reserved, 3264512K highmem) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] ftrace: allocating 35355 entries in 104 pages [ 0.000000] ftrace: allocated 104 pages with 3 groups [ 0.000000] trace event string verifier disabled [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] Rude variant of Tasks RCU enabled. [ 0.000000] Tracing variant of Tasks RCU enabled. [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies. [ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 [ 0.000000] GIC: Using split EOI/Deactivate mode [ 0.000000] irq_brcmstb_l2: registered L2 intc (/soc/interrupt-controller@7ef00100, parent irq: 25) [ 0.000000] random: get_random_bytes called from start_kernel+0x574/0x758 with crng_init=1 [ 0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys). [ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns [ 0.000000] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns [ 0.000019] Switching to timer-based delay loop, resolution 18ns [ 0.000334] Console: colour dummy device 80x30 [ 0.000401] printk: console [tty1] enabled [ 0.000469] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000) [ 0.000500] pid_max: default: 32768 minimum: 301 [ 0.000643] LSM: Security Framework initializing [ 0.000806] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) [ 0.000837] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear) [ 0.002450] cgroup: Disabling memory control group subsystem [ 0.002700] CPU: Testing write buffer coherency: ok [ 0.002759] CPU0: Spectre BHB: using loop workaround [ 0.003227] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 [ 0.004492] Setting up static identity map for 0x200000 - 0x20003c [ 0.004710] rcu: Hierarchical SRCU implementation. [ 0.005676] smp: Bringing up secondary CPUs ... [ 0.006880] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 [ 0.006897] CPU1: Spectre BHB: using loop workaround [ 0.008252] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002 [ 0.008270] CPU2: Spectre BHB: using loop workaround [ 0.009587] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003 [ 0.009605] CPU3: Spectre BHB: using loop workaround [ 0.009763] smp: Brought up 1 node, 4 CPUs [ 0.009784] SMP: Total of 4 processors activated (432.00 BogoMIPS). [ 0.009804] CPU: All CPU(s) started in HYP mode. [ 0.009817] CPU: Virtualization extensions available. [ 0.010731] devtmpfs: initialized [ 0.026539] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0 [ 0.026781] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns [ 0.026817] futex hash table entries: 1024 (order: 4, 65536 bytes, linear) [ 0.037297] pinctrl core: initialized pinctrl subsystem [ 0.038613] NET: Registered PF_NETLINK/PF_ROUTE protocol family [ 0.043184] DMA: preallocated 1024 KiB pool for atomic coherent allocations [ 0.043983] audit: initializing netlink subsys (disabled) [ 0.044241] audit: type=2000 audit(0.040:1): state=initialized audit_enabled=0 res=1 [ 0.044871] thermal_sys: Registered thermal governor 'step_wise' [ 0.045701] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. [ 0.045722] hw-breakpoint: maximum watchpoint size is 8 bytes. [ 0.046158] Serial: AMBA PL011 UART driver [ 0.061262] bcm2835-mbox fe00b880.mailbox: mailbox enabled [ 0.100073] raspberrypi-firmware soc:firmware: Attached to firmware from 2022-03-24T13:19:26, variant start [ 0.110087] raspberrypi-firmware soc:firmware: Firmware hash is e5a963efa66a1974127860b42e913d2374139ff5 [ 0.169443] Kprobes globally optimized [ 0.175187] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1 [ 0.179924] vgaarb: loaded [ 0.180738] SCSI subsystem initialized [ 0.180989] usbcore: registered new interface driver usbfs [ 0.181049] usbcore: registered new interface driver hub [ 0.181125] usbcore: registered new device driver usb [ 0.181563] usb_phy_generic phy: supply vcc not found, using dummy regulator [ 0.182065] pps_core: LinuxPPS API ver. 1 registered [ 0.182081] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti giometti@linux.it [ 0.182110] PTP clock support registered [ 0.183867] clocksource: Switched to clocksource arch_sys_counter [ 0.264680] VFS: Disk quotas dquot_6.6.0 [ 0.264789] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) [ 0.264976] FS-Cache: Loaded [ 0.265199] CacheFiles: Loaded [ 0.266387] simple-framebuffer 3e402000.framebuffer: framebuffer at 0x3e402000, 0x7f8000 bytes [ 0.266412] simple-framebuffer 3e402000.framebuffer: format=a8r8g8b8, mode=1920x1080x32, linelength=7680 [ 0.266953] Console: switching to colour frame buffer device 240x67 [ 0.277572] simple-framebuffer 3e402000.framebuffer: fb0: simplefb registered! [ 0.287816] NET: Registered PF_INET protocol family [ 0.288081] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear) [ 0.289740] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear) [ 0.289774] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear) [ 0.289840] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear) [ 0.289917] TCP: Hash tables configured (established 8192 bind 8192) [ 0.290079] UDP hash table entries: 512 (order: 2, 16384 bytes, linear) [ 0.290119] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear) [ 0.290373] NET: Registered PF_UNIX/PF_LOCAL protocol family [ 0.294852] RPC: Registered named UNIX socket transport module. [ 0.294872] RPC: Registered udp transport module. [ 0.294885] RPC: Registered tcp transport module. [ 0.294899] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.294920] PCI: CLS 0 bytes, default 64 [ 1.136943] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available [ 1.139703] Initialise system trusted keyrings [ 1.139966] workingset: timestamp_bits=14 max_order=20 bucket_order=6 [ 1.149047] zbud: loaded [ 1.151105] FS-Cache: Netfs 'nfs' registered for caching [ 1.151972] NFS: Registering the id_resolver key type [ 1.152028] Key type id_resolver registered [ 1.152043] Key type id_legacy registered [ 1.152176] nfs4filelayout_init: NFSv4 File Layout Driver Registering... [ 1.152192] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering... [ 1.153318] Key type asymmetric registered [ 1.153336] Asymmetric key parser 'x509' registered [ 1.153568] bounce: pool size: 64 pages [ 1.153646] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) [ 1.153928] io scheduler mq-deadline registered [ 1.153948] io scheduler kyber registered [ 1.163608] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges: [ 1.163652] brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff] [ 1.163746] brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000 [ 1.163889] brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x00ffffffff -> 0x0400000000 [ 1.225969] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC) [ 1.226342] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00 [ 1.226364] pci_bus 0000:00: root bus resource [bus 00-ff] [ 1.226385] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff]) [ 1.226479] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400 [ 1.226733] pci 0000:00:00.0: PME# supported from D0 D3hot [ 1.230562] PCI: bus0: Fast back to back transfers disabled [ 1.230914] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330 [ 1.231044] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit] [ 1.231478] pci 0000:01:00.0: PME# supported from D0 D3hot [ 1.235294] PCI: bus1: Fast back to back transfers disabled [ 1.235357] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff] [ 1.235385] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit] [ 1.235471] pci 0000:00:00.0: PCI bridge to [bus 01] [ 1.235497] pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff] [ 1.235923] pcieport 0000:00:00.0: enabling device (0140 -> 0142) [ 1.236159] pcieport 0000:00:00.0: PME: Signaling with IRQ 79 [ 1.247653] iproc-rng200 fe104000.rng: hwrng registered [ 1.248060] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) [ 1.249749] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000 [ 1.263113] brd: module loaded [ 1.273772] loop: module loaded [ 1.274710] Loading iSCSI transport class v2.0-870. [ 1.280133] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000 [ 1.374026] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus [ 1.375308] usbcore: registered new interface driver r8152 [ 1.375399] usbcore: registered new interface driver lan78xx [ 1.375463] usbcore: registered new interface driver smsc95xx [ 1.427456] xhci_hcd 0000:01:00.0: xHCI Host Controller [ 1.427495] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1 [ 1.433195] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x00003c0000000890 [ 1.434641] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15 [ 1.434665] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 1.434686] usb usb1: Product: xHCI Host Controller [ 1.434704] usb usb1: Manufacturer: Linux 5.15.32-v7l+ xhci-hcd [ 1.434720] usb usb1: SerialNumber: 0000:01:00.0 [ 1.435537] hub 1-0:1.0: USB hub found [ 1.435637] hub 1-0:1.0: 1 port detected [ 1.436320] xhci_hcd 0000:01:00.0: xHCI Host Controller [ 1.436348] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2 [ 1.436373] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed [ 1.436838] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.15 [ 1.436861] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 1.436879] usb usb2: Product: xHCI Host Controller [ 1.436896] usb usb2: Manufacturer: Linux 5.15.32-v7l+ xhci-hcd [ 1.436913] usb usb2: SerialNumber: 0000:01:00.0 [ 1.437632] hub 2-0:1.0: USB hub found [ 1.437706] hub 2-0:1.0: 4 ports detected [ 1.439601] dwc_otg: version 3.00a 10-AUG-2012 (platform bus) [ 1.439999] dwc_otg: FIQ enabled [ 1.440013] dwc_otg: NAK holdoff enabled [ 1.440027] dwc_otg: FIQ split-transaction FSM enabled [ 1.440044] Module dwc_common_port init [ 1.440532] usbcore: registered new interface driver uas [ 1.440649] usbcore: registered new interface driver usb-storage [ 1.440882] mousedev: PS/2 mouse device common for all mice [ 1.446722] sdhci: Secure Digital Host Controller Interface driver [ 1.446741] sdhci: Copyright(c) Pierre Ossman [ 1.447545] sdhci-pltfm: SDHCI platform and OF driver helper [ 1.451530] ledtrig-cpu: registered to indicate activity on CPUs [ 1.451872] hid: raw HID events driver (C) Jiri Kosina [ 1.452090] usbcore: registered new interface driver usbhid [ 1.452108] usbhid: USB HID core driver [ 1.458862] Initializing XFRM netlink socket [ 1.458912] NET: Registered PF_PACKET protocol family [ 1.459033] Key type dns_resolver registered [ 1.459509] Registering SWP/SWPB emulation handler [ 1.460351] registered taskstats version 1 [ 1.460384] Loading compiled-in X.509 certificates [ 1.461282] Key type ._fscrypt registered [ 1.461299] Key type .fscrypt registered [ 1.461314] Key type fscrypt-provisioning registered [ 1.474218] uart-pl011 fe201000.serial: there is not valid maps for state default [ 1.474550] uart-pl011 fe201000.serial: cts_event_workaround enabled [ 1.474712] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 34, base_baud = 0) is a PL011 rev2 [ 1.484245] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer [ 1.484734] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver [ 1.486037] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0 [ 1.486059] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated [ 1.516688] of_cfs_init [ 1.516963] of_cfs_init: OK [ 1.551187] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA [ 1.551532] Waiting for root device PARTUUID=e6fc1d7b-02... [ 1.654472] mmc0: new ultra high speed DDR50 SDHC card at address aaaa [ 1.655754] mmc1: new high speed SDIO card at address 0001 [ 1.656783] mmcblk0: mmc0:aaaa SC32G 29.7 GiB [ 1.663019] mmcblk0: p1 p2 [ 1.663603] mmcblk0: mmc0:aaaa SC32G 29.7 GiB [ 1.686914] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none. [ 1.687004] VFS: Mounted root (ext4 filesystem) readonly on device 179:2. [ 1.687748] devtmpfs: mounted [ 1.699331] Freeing unused kernel image (initmem) memory: 2048K [ 1.714204] Run /sbin/init as init process [ 1.714220] with arguments: [ 1.714233] /sbin/init [ 1.714246] splash [ 1.714259] with environment: [ 1.714272] HOME=/ [ 1.714285] TERM=linux [ 1.723913] usb 1-1: new high-speed USB device number 2 using xhci_hcd [ 1.906510] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21 [ 1.906542] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 [ 1.906562] usb 1-1: Product: USB2.0 Hub [ 1.908912] hub 1-1:1.0: USB hub found [ 1.909277] hub 1-1:1.0: 4 ports detected [ 2.043202] systemd[1]: System time before build time, advancing clock. [ 2.149406] NET: Registered PF_INET6 protocol family [ 2.151197] Segment Routing with IPv6 [ 2.151242] In-situ OAM (IOAM) with IPv6 [ 2.211725] systemd[1]: systemd 247.3-7+rpi1 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +ZSTD +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=unified) [ 2.212621] systemd[1]: Detected architecture arm. [ 2.214544] systemd[1]: Set hostname to . [ 2.234014] usb 1-1.1: new low-speed USB device number 3 using xhci_hcd [ 2.376250] usb 1-1.1: New USB device found, idVendor=413c, idProduct=3012, bcdDevice=43.01 [ 2.376297] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [ 2.376326] usb 1-1.1: Product: Dell USB Optical Mouse [ 2.376355] usb 1-1.1: Manufacturer: Dell [ 2.388748] input: Dell Dell USB Optical Mouse as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.1/1-1.1:1.0/0003:413C:3012.0001/input/input0 [ 2.389352] hid-generic 0003:413C:3012.0001: input,hidraw0: USB HID v1.11 Mouse [Dell Dell USB Optical Mouse] on usb-0000:01:00.0-1.1/input0 [ 2.483936] usb 1-1.2: new low-speed USB device number 4 using xhci_hcd [ 2.632638] usb 1-1.2: New USB device found, idVendor=413c, idProduct=2003, bcdDevice= 3.01 [ 2.632671] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [ 2.632691] usb 1-1.2: Product: Dell USB Keyboard [ 2.632708] usb 1-1.2: Manufacturer: Dell [ 2.645552] input: Dell Dell USB Keyboard as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2/1-1.2:1.0/0003:413C:2003.0002/input/input1 [ 2.714691] hid-generic 0003:413C:2003.0002: input,hidraw1: USB HID v1.10 Keyboard [Dell Dell USB Keyboard] on usb-0000:01:00.0-1.2/input0 [ 2.813920] usb 1-1.3: new full-speed USB device number 5 using xhci_hcd [ 2.988200] systemd[1]: /lib/systemd/system/plymouth-start.service:16: Unit configured to use KillMode=none. This is unsafe, as it disables systemd's process lifecycle management for the service. Please update your service to use a safer KillMode=, such as 'mixed' or 'control-group'. Support for KillMode=none is deprecated and will eventually be removed. [ 3.189799] systemd[1]: Queued start job for default target Graphical Interface. [ 3.191440] random: systemd: uninitialized urandom read (16 bytes read) [ 3.197277] systemd[1]: Created slice system-getty.slice. [ 3.197704] random: systemd: uninitialized urandom read (16 bytes read) [ 3.198812] systemd[1]: Created slice system-modprobe.slice. [ 3.198938] random: systemd: uninitialized urandom read (16 bytes read) [ 3.199927] systemd[1]: Created slice system-systemd\x2dfsck.slice. [ 3.200823] systemd[1]: Created slice User and Session Slice. [ 3.201373] systemd[1]: Started Forward Password Requests to Wall Directory Watch. [ 3.202548] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point. [ 3.203357] systemd[1]: Reached target Slices. [ 3.203611] systemd[1]: Reached target Swap. [ 3.205137] systemd[1]: Listening on Syslog Socket. [ 3.205962] systemd[1]: Listening on fsck to fsckd communication Socket. [ 3.206401] systemd[1]: Listening on initctl Compatibility Named Pipe. [ 3.207615] systemd[1]: Listening on Journal Audit Socket. [ 3.208439] systemd[1]: Listening on Journal Socket (/dev/log). [ 3.209482] systemd[1]: Listening on Journal Socket. [ 3.213324] systemd[1]: Listening on udev Control Socket. [ 3.214366] systemd[1]: Listening on udev Kernel Socket. [ 3.215334] systemd[1]: Condition check resulted in Huge Pages File System being skipped. [ 3.220828] systemd[1]: Mounting POSIX Message Queue File System... [ 3.227652] systemd[1]: Mounting RPC Pipe File System... [ 3.235617] systemd[1]: Mounting Kernel Debug File System... [ 3.243542] systemd[1]: Mounting Kernel Trace File System... [ 3.245028] systemd[1]: Condition check resulted in Kernel Module supporting RPCSEC_GSS being skipped. [ 3.254609] systemd[1]: Starting Restore / save the current clock... [ 3.263401] systemd[1]: Starting Set the console keyboard layout... [ 3.271091] systemd[1]: Starting Create list of static device nodes for the current kernel... [ 3.280017] systemd[1]: Starting Load Kernel Module configfs... [ 3.287650] systemd[1]: Starting Load Kernel Module drm... [ 3.296472] systemd[1]: Starting Load Kernel Module fuse... [ 3.300437] systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped. [ 3.316712] systemd[1]: Starting File System Check on Root Device... [ 3.334900] systemd[1]: Starting Journal Service... [ 3.353444] systemd[1]: Starting Load Kernel Modules... [ 3.359045] fuse: init (API version 7.34) [ 3.368185] systemd[1]: Starting Coldplug All udev Devices... [ 3.387638] systemd[1]: Mounted POSIX Message Queue File System. [ 3.388687] systemd[1]: Mounted RPC Pipe File System. [ 3.389586] systemd[1]: Mounted Kernel Debug File System. [ 3.390319] systemd[1]: Mounted Kernel Trace File System. [ 3.392322] systemd[1]: Finished Restore / save the current clock. [ 3.410937] systemd[1]: Finished Create list of static device nodes for the current kernel. [ 3.414436] systemd[1]: modprobe@configfs.service: Succeeded. [ 3.416223] systemd[1]: Finished Load Kernel Module configfs. [ 3.418756] systemd[1]: modprobe@fuse.service: Succeeded. [ 3.420397] systemd[1]: Finished Load Kernel Module fuse. [ 3.432756] systemd[1]: Mounting FUSE Control File System... [ 3.444070] systemd[1]: Mounting Kernel Configuration File System... [ 3.453997] systemd[1]: Started File System Check Daemon to report status. [ 3.457063] i2c_dev: i2c /dev entries driver [ 3.479989] systemd[1]: modprobe@drm.service: Succeeded. [ 3.485810] systemd[1]: Finished Load Kernel Module drm. [ 3.488372] systemd[1]: Finished Load Kernel Modules. [ 3.489474] systemd[1]: Mounted FUSE Control File System. [ 3.494205] systemd[1]: Mounted Kernel Configuration File System. [ 3.509038] systemd[1]: Starting Apply Kernel Variables... [ 3.587505] systemd[1]: Finished Apply Kernel Variables. [ 3.620710] systemd[1]: Finished File System Check on Root Device. [ 3.627096] systemd[1]: Starting Remount Root and Kernel File Systems... [ 3.734500] systemd[1]: Started Journal Service. [ 3.826417] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null). Quota mode: none. [ 3.902915] systemd-journald[133]: Received client request to flush runtime journal. [ 3.915434] systemd-journald[133]: File /var/log/journal/68716f4ecfa5426ea966c195a9cf7def/system.journal corrupted or uncleanly shut down, renaming and replacing. [ 5.249667] mc: Linux media interface: v0.10 [ 5.283007] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000 [ 5.283977] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000 [ 5.284821] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000 [ 5.285569] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000 [ 5.299563] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. [ 5.318604] bcm2835_vc_sm_cma_probe: Videocore shared memory driver

[ 5.360678] [vc_sm_connected_init]: installed successfully [ 5.470412] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. [ 5.473155] videodev: Linux video capture interface: v2.00 [ 5.676416] bcm2835_audio bcm2835_audio: card created with 8 channels [ 5.780304] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. [ 5.799103] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned. [ 5.834703] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. [ 5.875479] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13 [ 5.896115] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. [ 5.907208] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14 [ 5.915638] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15 [ 5.924590] bcm2835-codec bcm2835-codec: Device registered as /dev/video10 [ 5.924730] bcm2835-codec bcm2835-codec: Loaded V4L2 decode [ 5.946188] bcm2835-codec bcm2835-codec: Device registered as /dev/video11 [ 5.946244] bcm2835-codec bcm2835-codec: Loaded V4L2 encode [ 5.947401] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16 [ 5.947452] bcm2835-isp bcm2835-isp: Register output node 0 with media controller [ 5.947481] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller [ 5.947505] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller [ 5.947529] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller [ 5.966067] bcm2835-codec bcm2835-codec: Device registered as /dev/video12 [ 5.966127] bcm2835-codec bcm2835-codec: Loaded V4L2 isp [ 5.969271] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20 [ 6.012501] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21 [ 6.064160] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22 [ 6.064773] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23 [ 6.064811] bcm2835-isp bcm2835-isp: Register output node 0 with media controller [ 6.064844] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller [ 6.064884] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller [ 6.064907] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller [ 6.065278] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp [ 6.142245] bcm2835-codec bcm2835-codec: Device registered as /dev/video18 [ 6.142312] bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx [ 6.168544] bcm2835-codec bcm2835-codec: Device registered as /dev/video31 [ 6.168600] bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image [ 6.191271] checking generic (3e402000 7f8000) vs hw (0 ffffffffffffffff) [ 6.191303] fb0: switching to vc4 from simple [ 6.211858] brcmstb-i2c fef04500.i2c: @97500hz registered in polling mode [ 6.217365] Console: switching to colour dummy device 80x30 [ 6.233938] brcmstb-i2c fef09500.i2c: @97500hz registered in polling mode [ 6.237126] i2c i2c-22: Added multiplexed i2c bus 0 [ 6.281614] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops [vc4]) [ 6.287226] Registered IR keymap rc-cec [ 6.296339] i2c 10-0010: Fixing up cyclic dependency with fe801000.csi [ 6.297225] i2c i2c-22: Added multiplexed i2c bus 10 [ 6.305036] rc rc0: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0 [ 6.344992] input: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0/input2 [ 6.371269] [drm] Initialized v3d 1.0.0 20180419 for fec00000.v3d on minor 1 [ 6.545001] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops [vc4]) [ 6.599433] Registered IR keymap rc-cec [ 6.599638] rc rc0: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0 [ 6.599924] input: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0/input3 [ 6.687676] cfg80211: Loading compiled-in X.509 certificates for regulatory database [ 6.741804] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' [ 6.756709] cfg80211: loaded regulatory.db is malformed or signature is missing/invalid [ 6.802950] brcmfmac: F1 signature read @0x18000000=0x15264345 [ 6.808178] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops [vc4]) [ 6.811561] Registered IR keymap rc-cec [ 6.811754] rc rc0: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0 [ 6.811990] input: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0/input4 [ 6.822605] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 [ 6.823724] usbcore: registered new interface driver brcmfmac [ 6.825568] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,4-model-b.bin failed with error -2 [ 6.901999] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops [vc4]) [ 6.921654] Registered IR keymap rc-cec [ 6.921894] rc rc0: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0 [ 6.922156] input: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0/input5 [ 7.098418] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 [ 7.098570] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 [ 7.103819] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60 [ 7.242839] random: crng init done [ 7.242857] random: 7 urandom warning(s) missed due to ratelimiting [ 7.821020] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops [vc4]) [ 7.836966] Registered IR keymap rc-cec [ 7.837188] rc rc0: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0 [ 7.837461] input: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0/input6 [ 7.849100] vc4-drm gpu: bound fef00700.hdmi (ops vc4_hdmi_ops [vc4]) [ 7.857027] Registered IR keymap rc-cec [ 7.857248] rc rc1: vc4 as /devices/platform/soc/fef05700.hdmi/rc/rc1 [ 7.857507] input: vc4 as /devices/platform/soc/fef05700.hdmi/rc/rc1/input7 [ 7.861331] vc4-drm gpu: bound fef05700.hdmi (ops vc4_hdmi_ops [vc4]) [ 7.861841] vc4-drm gpu: bound fe004000.txp (ops vc4_txp_ops [vc4]) [ 7.862322] vc4-drm gpu: bound fe206000.pixelvalve (ops vc4_crtc_ops [vc4]) [ 7.862725] vc4-drm gpu: bound fe207000.pixelvalve (ops vc4_crtc_ops [vc4]) [ 7.863152] vc4-drm gpu: bound fe20a000.pixelvalve (ops vc4_crtc_ops [vc4]) [ 7.863492] vc4-drm gpu: bound fe216000.pixelvalve (ops vc4_crtc_ops [vc4]) [ 7.879372] vc4-drm gpu: bound fec12000.pixelvalve (ops vc4_crtc_ops [vc4]) [ 7.906230] [drm] Initialized vc4 0.0.0 20140616 for gpu on minor 0 [ 7.974300] Console: switching to colour frame buffer device 240x67 [ 7.974369] vc4-drm gpu: [drm] fb0: vc4drmfb frame buffer device [ 8.622313] 8021q: 802.1Q VLAN Support v1.8 [ 8.752111] uart-pl011 fe201000.serial: no DMA platform data [ 8.756941] imx219 10-0010: Consider updating driver imx219 to match on endpoints [ 8.886633] Adding 102396k swap on /var/swap. Priority:-2 extents:2 across:176124k SSFS [ 9.133218] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled [ 9.581961] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay) [ 9.583480] bcmgenet fd580000.ethernet eth0: Link is Down [ 13.754040] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx [ 13.754071] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 14.184326] hdmi-audio-codec hdmi-audio-codec.4.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19 [ 14.184365] MAI: soc_pcm_open() failed (-19) [ 14.185503] hdmi-audio-codec hdmi-audio-codec.4.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19 [ 14.185544] MAI: soc_pcm_open() failed (-19) [ 14.186791] hdmi-audio-codec hdmi-audio-codec.4.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19 [ 14.186836] MAI: soc_pcm_open() failed (-19) [ 14.202303] hdmi-audio-codec hdmi-audio-codec.4.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19 [ 14.202345] MAI: soc_pcm_open() failed (-19) [ 14.202929] hdmi-audio-codec hdmi-audio-codec.4.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19 [ 14.202962] MAI: soc_pcm_open() failed (-19) [ 14.203475] hdmi-audio-codec hdmi-audio-codec.4.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19 [ 14.203506] MAI: soc_pcm_open() failed (-19) [ 15.045698] ICMPv6: process `dhcpcd' is using deprecated sysctl (syscall) net.ipv6.neigh.eth0.retrans_time - use net.ipv6.neigh.eth0.retrans_time_ms instead [ 15.683157] Bluetooth: Core ver 2.22 [ 15.683407] NET: Registered PF_BLUETOOTH protocol family [ 15.683414] Bluetooth: HCI device and connection manager initialized [ 15.683427] Bluetooth: HCI socket layer initialized [ 15.683435] Bluetooth: L2CAP socket layer initialized [ 15.683454] Bluetooth: SCO socket layer initialized [ 15.692917] Bluetooth: HCI UART driver ver 2.3 [ 15.692932] Bluetooth: HCI UART protocol H4 registered [ 15.693119] Bluetooth: HCI UART protocol Three-wire (H5) registered [ 15.693332] Bluetooth: HCI UART protocol Broadcom registered [ 16.031483] Bluetooth: BNEP (Ethernet Emulation) ver 1.3 [ 16.031495] Bluetooth: BNEP filters: protocol multicast [ 16.031507] Bluetooth: BNEP socket layer initialized [ 16.061973] NET: Registered PF_ALG protocol family [ 16.125259] cryptd: max_cpu_qlen set to 1000 [ 16.285021] Bluetooth: RFCOMM TTY layer initialized [ 16.285041] Bluetooth: RFCOMM socket layer initialized [ 16.285115] Bluetooth: RFCOMM ver 1.11 [ 18.014135] usb 1-1.3: device descriptor read/64, error -110 [ 31.837036] cam-dummy-reg: disabling [ 33.378065] usb 1-1.3: device descriptor read/64, error -110 [ 33.597902] usb 1-1.3: new full-speed USB device number 6 using xhci_hcd [ 48.822642] usb 1-1.3: device descriptor read/64, error -110 [ 64.184345] usb 1-1.3: device descriptor read/64, error -110 [ 64.304891] usb 1-1-port3: attempt power cycle [ 64.964096] usb 1-1.3: new full-speed USB device number 7 using xhci_hcd [ 65.587170] xhci_hcd 0000:01:00.0: ERROR: unexpected setup address command completion code 0x24. [ 66.427163] xhci_hcd 0000:01:00.0: ERROR: unexpected setup address command completion code 0x24. [ 66.644210] usb 1-1.3: device not accepting address 7, error -22 [ 66.744233] usb 1-1.3: new full-speed USB device number 8 using xhci_hcd [ 67.367316] xhci_hcd 0000:01:00.0: ERROR: unexpected setup address command completion code 0x24. [ 68.207179] xhci_hcd 0000:01:00.0: ERROR: unexpected setup address command completion code 0x24. [ 68.424293] usb 1-1.3: device not accepting address 8, error -22 [ 68.425031] usb 1-1-port3: unable to enumerate USB device

Additional context

Possible related issue: https://github.com/raspberrypi/linux/issues/5005

solmoller commented 2 years ago

looks familiar to #5005 , as adding an USB hub fixes the problem sometimes

JamesH65 commented 2 years ago

@jdb Any thoughts?

popcornmix commented 2 years ago

@JamesH65 did you mean @P33M ?

JamesH65 commented 2 years ago

I did indeed, mixing up my usernames....this has also come up on the forums.

P33M commented 2 years ago

It goes without saying that we don't have one of those devices.

This is a full-speed device so is accessed behind a transaction translator. The very first transaction to the device times out which suggests it's not in a state where it responds to the Setup packet - which should not happen. My guess is whatever reset strategy is implemented inside the device doesn't account for whatever intermediate state the bus is in while the Pi is rebooting - note that we power cycle ports over reset.

One workaround to try would be to configure USB mass-storage boot and set the bootconf.txt parameter USB_MSD_PWR_OFF_TIME to some large number, e.g. 2000. The Pi will power cycle the USB ports for a longer time when attempting mass-storage boot, but fail and boot from SD.

https://www.raspberrypi.com/documentation/computers/raspberry-pi.html#raspberry-pi-4-boot-flow https://www.raspberrypi.com/documentation/computers/raspberry-pi.html#USB_MSD_PWR_OFF_TIME

ReneElizondo commented 2 years ago

@P33M

Thank you very much for your help, unfortunately, the suggested workaround did not work, I changed the value to 2000, 5000 and some other values in between but the same error kept occurring.

image

There are some things that I wanted to point out... but just keep in mind that I have no idea what I am talking about here so most of my comments are probably going to be gibberish.

Could it be that the Pi OS is sending some bad messages to the ThingMagic device during startup that messes up the device? Or could it be a bug on the USB drivers that have a hard time talking to the new USB hardware? This may explain why things work on the Pi 3 but not on the Pi 4?

Do you have any other suggestions to try? Is there anything you want me to do to help troubleshoot this? Do you need SSH access to the Pi with the ThingMagic device connected to it? Let me know what I can do, we are really eager to see this being fixed assuming this issue is fixable.

Thanks.

ReneElizondo commented 2 years ago

Continuing with my potential gibberish comments... just wanted to reiterate that when the ThingMagic USB device is connected, the problem is not just with the ThingMagic device, the problem spawns to the other USB devices. In my case I have a mouse and a keyboard connected to the other USB ports and both the mouse and keyboard become locked (unusable) while the OS is trying to figure out how to sort the USB issue.

I assume that if this issue was strictly related to the ThingMagic USB device, the keyboard and mouse would continue to work without a problem, the fact that they do not, tells me that something bigger is getting messed up.

P33M commented 2 years ago

The disconnected mouse/keyboard are a side-effect of Linux trying to recover the device as evidenced by "attempt power cycle" messages in dmesg.

What is the boot order of the system? For the power cycle workaround to have an effect, USB mass-storage must come before SD.

https://www.raspberrypi.com/documentation/computers/raspberry-pi.html#BOOT_ORDER

ReneElizondo commented 2 years ago

Originally the boot order was the default order (there was no BOOT_ORDER entry outputted by rpi-eeprom-config command). So I went in and change things to the following:

image

Unfortunately, that still did not work. I can tell right away that is not going to work because I can see that the ThingMagic device is powered on before the boot process start, when that happens the ThingMagic device is never recognized.

One way that I have have been able to make the ThingMagic device work during the bootup process is to wait a couple of seconds after the boot process starts and then plug in the ThingMagic USB device. Usually, plug it in some time before the Welcome to Raspbian GNU/Linus 11 (bullseye)! message shows up. If I do that, the boot process will continue and the ThingMagic device is successfully recognized. So something is happening during that time that messes up the ThinkgMagic serail communications.

In case its relevant, this is what I get during the initial boot screen, the xhc-cmd err only shows if the ThinngMagic device is plugged in:

image

timg236 commented 2 years ago

The USB power off happens all the time on R1.4 during sdram init or before the first boot mode on r1.1. There’s no way to make it zero since the hardware will cause a very brief power off by itself. During boot mode 4 you can tell the bootloader by excluding by VID/PID (see eeprom config docs). It’s worth a shot but probably won’t make a difference!

ReneElizondo commented 2 years ago

mmm... this may be a little over my skill set (I am very new to the Raspberry Pi), I could try this but I may need some more specific instructions to be able to test that if its ok.

I am curious though about the significance of the xHC-CMD err: 36 type: 11 error, this is happening during the "core" boot stage, I don't even have the sd card inserted in the Pi and I still see the error. The error only shows up if the ThingMagic devic is connected, if the ThingMagic device is not connected there are no error whatsoever. Also, under previous conditions, I would just unplug and replug the ThingMagic device and things would work, this time, no matter how many time I unplug and replug the ThingMagic device the xHC-CMD error keeps showing up.

As usually, have no clue what I am talking about but it almost seems to me as if the USB issue was at the hart of the Raspberry Pi functionality given that the OS is not even playing a part at the time of the error.

P33M commented 2 years ago

The command response code is the same as is seen in Linux - split transaction error. The difference in behaviour between a replug on Linux and a replug with the bootloader is likely due to timing - the bootloader has nothing better to do except pay attention to USB whereas Linux can be a little slower on the uptake.

Given that device enumeration fails right out of the gate, what happens if you change the probing scheme that Linux uses by adding usbcore.old_scheme_first=1 to /boot/config.txt ?

popcornmix commented 2 years ago

by adding usbcore.old_scheme_first=1 to /boot/config.txt ?

I think this should be /boot/cmdline.txt

ReneElizondo commented 2 years ago

Unfortunately, adding usbcore.old_scheme_first=1 to the cmdline.txt did not work.

dmesg output:

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 5.15.32-v7l+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1538 SMP Thu Mar 31 19:39:41 BST 2022
[    0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.5
[    0.000000] random: fast init done
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] Reserved memory: created CMA memory pool at 0x000000001ac00000, size 320 MiB
[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000000000-0x000000002fffffff]
[    0.000000]   Normal   empty
[    0.000000]   HighMem  [mem 0x0000000030000000-0x000000007fffffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x000000003b3fffff]
[    0.000000]   node   0: [mem 0x0000000040000000-0x000000007fffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x000000007fffffff]
[    0.000000] percpu: Embedded 16 pages/cpu s35788 r8192 d21556 u65536
[    0.000000] pcpu-alloc: s35788 r8192 d21556 u65536 alloc=16*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 503104
[    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 video=HDMI-A-1:1920x1080M@60 smsc95xx.macaddr=E4:5F:01:A3:0B:24 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  console=ttyS0,115200 console=tty1 root=PARTUUID=e2d5ff95-02 rootfstype=ext4 fsck.repair=yes rootwait quiet splash plymouth.ignore-serial-consoles usbcore.old_scheme_first=1
[    0.000000] Unknown kernel command line parameters "splash", will be passed to user space.
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] software IO TLB: mapped [mem 0x0000000015a00000-0x0000000019a00000] (64MB)
[    0.000000] Memory: 1587560K/2019328K available (10240K kernel code, 1390K rwdata, 3292K rodata, 2048K init, 590K bss, 104088K reserved, 327680K cma-reserved, 1232896K highmem)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 35355 entries in 104 pages
[    0.000000] ftrace: allocated 104 pages with 3 groups
[    0.000000] trace event string verifier disabled
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000]  Rude variant of Tasks RCU enabled.
[    0.000000]  Tracing variant of Tasks RCU enabled.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] GIC: Using split EOI/Deactivate mode
[    0.000000] irq_brcmstb_l2: registered L2 intc (/soc/interrupt-controller@7ef00100, parent irq: 25)
[    0.000000] random: get_random_bytes called from start_kernel+0x574/0x758 with crng_init=1
[    0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
[    0.000002] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
[    0.000021] Switching to timer-based delay loop, resolution 18ns
[    0.000330] Console: colour dummy device 80x30
[    0.000398] printk: console [tty1] enabled
[    0.000466] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000)
[    0.000496] pid_max: default: 32768 minimum: 301
[    0.000640] LSM: Security Framework initializing
[    0.000802] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.000833] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.002438] cgroup: Disabling memory control group subsystem
[    0.002690] CPU: Testing write buffer coherency: ok
[    0.002749] CPU0: Spectre BHB: using loop workaround
[    0.003212] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.004463] Setting up static identity map for 0x200000 - 0x20003c
[    0.004687] rcu: Hierarchical SRCU implementation.
[    0.005639] smp: Bringing up secondary CPUs ...
[    0.006873] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.006891] CPU1: Spectre BHB: using loop workaround
[    0.008245] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.008263] CPU2: Spectre BHB: using loop workaround
[    0.009589] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.009607] CPU3: Spectre BHB: using loop workaround
[    0.009766] smp: Brought up 1 node, 4 CPUs
[    0.009786] SMP: Total of 4 processors activated (432.00 BogoMIPS).
[    0.009806] CPU: All CPU(s) started in HYP mode.
[    0.009820] CPU: Virtualization extensions available.
[    0.010722] devtmpfs: initialized
[    0.026517] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0
[    0.026761] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.026795] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[    0.037340] pinctrl core: initialized pinctrl subsystem
[    0.038685] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[    0.043402] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.044191] audit: initializing netlink subsys (disabled)
[    0.044464] audit: type=2000 audit(0.040:1): state=initialized audit_enabled=0 res=1
[    0.045061] thermal_sys: Registered thermal governor 'step_wise'
[    0.045879] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.045901] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.046359] Serial: AMBA PL011 UART driver
[    0.061224] bcm2835-mbox fe00b880.mailbox: mailbox enabled
[    0.097039] raspberrypi-firmware soc:firmware: Attached to firmware from 2022-03-24T13:19:26, variant start
[    0.107046] raspberrypi-firmware soc:firmware: Firmware hash is e5a963efa66a1974127860b42e913d2374139ff5
[    0.166970] Kprobes globally optimized
[    0.172715] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1
[    0.177611] vgaarb: loaded
[    0.178094] SCSI subsystem initialized
[    0.178346] usbcore: registered new interface driver usbfs
[    0.178407] usbcore: registered new interface driver hub
[    0.178493] usbcore: registered new device driver usb
[    0.178916] usb_phy_generic phy: supply vcc not found, using dummy regulator
[    0.179426] pps_core: LinuxPPS API ver. 1 registered
[    0.179442] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.179471] PTP clock support registered
[    0.181217] clocksource: Switched to clocksource arch_sys_counter
[    0.261820] VFS: Disk quotas dquot_6.6.0
[    0.261935] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.262131] FS-Cache: Loaded
[    0.262346] CacheFiles: Loaded
[    0.263524] simple-framebuffer 3e402000.framebuffer: framebuffer at 0x3e402000, 0x7f8000 bytes
[    0.263548] simple-framebuffer 3e402000.framebuffer: format=a8r8g8b8, mode=1920x1080x32, linelength=7680
[    0.264072] Console: switching to colour frame buffer device 240x67
[    0.274730] simple-framebuffer 3e402000.framebuffer: fb0: simplefb registered!
[    0.283640] NET: Registered PF_INET protocol family
[    0.283906] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
[    0.285528] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    0.285563] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
[    0.285630] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    0.285712] TCP: Hash tables configured (established 8192 bind 8192)
[    0.285890] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
[    0.285929] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
[    0.286189] NET: Registered PF_UNIX/PF_LOCAL protocol family
[    0.292202] RPC: Registered named UNIX socket transport module.
[    0.292222] RPC: Registered udp transport module.
[    0.292236] RPC: Registered tcp transport module.
[    0.292250] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.292274] PCI: CLS 0 bytes, default 64
[    1.135015] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available
[    1.137766] Initialise system trusted keyrings
[    1.138079] workingset: timestamp_bits=14 max_order=19 bucket_order=5
[    1.147316] zbud: loaded
[    1.149197] FS-Cache: Netfs 'nfs' registered for caching
[    1.150084] NFS: Registering the id_resolver key type
[    1.150141] Key type id_resolver registered
[    1.150156] Key type id_legacy registered
[    1.150309] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    1.150328] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[    1.151537] Key type asymmetric registered
[    1.151558] Asymmetric key parser 'x509' registered
[    1.151782] bounce: pool size: 64 pages
[    1.151849] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247)
[    1.152086] io scheduler mq-deadline registered
[    1.152104] io scheduler kyber registered
[    1.161453] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
[    1.161498] brcm-pcie fd500000.pcie:   No bus range found for /scb/pcie@7d500000, using [bus 00-ff]
[    1.161593] brcm-pcie fd500000.pcie:      MEM 0x0600000000..0x063fffffff -> 0x00c0000000
[    1.161687] brcm-pcie fd500000.pcie:   IB MEM 0x0000000000..0x007fffffff -> 0x0400000000
[    1.223323] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC)
[    1.223733] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
[    1.223754] pci_bus 0000:00: root bus resource [bus 00-ff]
[    1.223775] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff])
[    1.223871] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
[    1.224123] pci 0000:00:00.0: PME# supported from D0 D3hot
[    1.227958] PCI: bus0: Fast back to back transfers disabled
[    1.227981] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[    1.228356] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330
[    1.228486] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
[    1.228953] pci 0000:01:00.0: PME# supported from D0 D3hot
[    1.232838] PCI: bus1: Fast back to back transfers disabled
[    1.232859] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01
[    1.232904] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
[    1.232930] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]
[    1.233016] pci 0000:00:00.0: PCI bridge to [bus 01]
[    1.233042] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]
[    1.233466] pcieport 0000:00:00.0: enabling device (0140 -> 0142)
[    1.233700] pcieport 0000:00:00.0: PME: Signaling with IRQ 79
[    1.245101] iproc-rng200 fe104000.rng: hwrng registered
[    1.245508] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[    1.247085] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
[    1.260193] brd: module loaded
[    1.270776] loop: module loaded
[    1.271683] Loading iSCSI transport class v2.0-870.
[    1.277092] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000
[    1.381399] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus
[    1.382760] usbcore: registered new interface driver r8152
[    1.382831] usbcore: registered new interface driver lan78xx
[    1.382895] usbcore: registered new interface driver smsc95xx
[    1.434557] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    1.434598] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
[    1.440248] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x00003c0000000890
[    1.441665] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15
[    1.441689] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.441708] usb usb1: Product: xHCI Host Controller
[    1.441726] usb usb1: Manufacturer: Linux 5.15.32-v7l+ xhci-hcd
[    1.441743] usb usb1: SerialNumber: 0000:01:00.0
[    1.442547] hub 1-0:1.0: USB hub found
[    1.442646] hub 1-0:1.0: 1 port detected
[    1.443338] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    1.443365] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
[    1.443390] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[    1.443856] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.15
[    1.443878] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.443897] usb usb2: Product: xHCI Host Controller
[    1.443914] usb usb2: Manufacturer: Linux 5.15.32-v7l+ xhci-hcd
[    1.443930] usb usb2: SerialNumber: 0000:01:00.0
[    1.444662] hub 2-0:1.0: USB hub found
[    1.444733] hub 2-0:1.0: 4 ports detected
[    1.446627] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    1.447021] dwc_otg: FIQ enabled
[    1.447037] dwc_otg: NAK holdoff enabled
[    1.447050] dwc_otg: FIQ split-transaction FSM enabled
[    1.447069] Module dwc_common_port init
[    1.447562] usbcore: registered new interface driver uas
[    1.447681] usbcore: registered new interface driver usb-storage
[    1.447892] mousedev: PS/2 mouse device common for all mice
[    1.453663] sdhci: Secure Digital Host Controller Interface driver
[    1.453681] sdhci: Copyright(c) Pierre Ossman
[    1.454474] sdhci-pltfm: SDHCI platform and OF driver helper
[    1.458676] ledtrig-cpu: registered to indicate activity on CPUs
[    1.459027] hid: raw HID events driver (C) Jiri Kosina
[    1.459202] usbcore: registered new interface driver usbhid
[    1.459218] usbhid: USB HID core driver
[    1.465873] Initializing XFRM netlink socket
[    1.465919] NET: Registered PF_PACKET protocol family
[    1.466047] Key type dns_resolver registered
[    1.466548] Registering SWP/SWPB emulation handler
[    1.467380] registered taskstats version 1
[    1.467411] Loading compiled-in X.509 certificates
[    1.468307] Key type ._fscrypt registered
[    1.468324] Key type .fscrypt registered
[    1.468340] Key type fscrypt-provisioning registered
[    1.481109] uart-pl011 fe201000.serial: there is not valid maps for state default
[    1.481472] uart-pl011 fe201000.serial: cts_event_workaround enabled
[    1.481626] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 34, base_baud = 0) is a PL011 rev2
[    1.491075] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[    1.491670] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[    1.492946] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0
[    1.492967] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated
[    1.523604] of_cfs_init
[    1.523915] of_cfs_init: OK
[    1.559106] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA
[    1.559554] Waiting for root device PARTUUID=e2d5ff95-02...
[    1.611620] mmc1: new high speed SDIO card at address 0001
[    1.663036] mmc0: new ultra high speed DDR50 SDXC card at address aaaa
[    1.664108] mmcblk0: mmc0:aaaa SF128 119 GiB
[    1.667695]  mmcblk0: p1 p2
[    1.668257] mmcblk0: mmc0:aaaa SF128 119 GiB
[    1.688748] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none.
[    1.688852] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    1.689803] devtmpfs: mounted
[    1.701433] Freeing unused kernel image (initmem) memory: 2048K
[    1.711550] Run /sbin/init as init process
[    1.711567]   with arguments:
[    1.711579]     /sbin/init
[    1.711592]     splash
[    1.711605]   with environment:
[    1.711617]     HOME=/
[    1.711630]     TERM=linux
[    1.731272] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[    1.764289] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21
[    1.764321] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[    1.764341] usb 1-1: Product: USB2.0 Hub
[    1.766758] hub 1-1:1.0: USB hub found
[    1.767036] hub 1-1:1.0: 4 ports detected
[    2.032572] systemd[1]: System time before build time, advancing clock.
[    2.091274] usb 1-1.1: new low-speed USB device number 3 using xhci_hcd
[    2.130580] usb 1-1.1: New USB device found, idVendor=413c, idProduct=3012, bcdDevice=43.01
[    2.130611] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    2.130631] usb 1-1.1: Product: Dell USB Optical Mouse
[    2.130648] usb 1-1.1: Manufacturer: Dell
[    2.137926] NET: Registered PF_INET6 protocol family
[    2.139750] Segment Routing with IPv6
[    2.139813] In-situ OAM (IOAM) with IPv6
[    2.146602] input: Dell Dell USB Optical Mouse as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.1/1-1.1:1.0/0003:413C:3012.0001/input/input0
[    2.147175] hid-generic 0003:413C:3012.0001: input,hidraw0: USB HID v1.11 Mouse [Dell Dell USB Optical Mouse] on usb-0000:01:00.0-1.1/input0
[    2.200040] systemd[1]: systemd 247.3-7+rpi1 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +ZSTD +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=unified)
[    2.200956] systemd[1]: Detected architecture arm.
[    2.203151] systemd[1]: Set hostname to <raspberrypi>.
[    2.241274] usb 1-1.2: new low-speed USB device number 4 using xhci_hcd
[    2.285501] usb 1-1.2: New USB device found, idVendor=413c, idProduct=2003, bcdDevice= 3.01
[    2.285538] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    2.285561] usb 1-1.2: Product: Dell USB Keyboard
[    2.285578] usb 1-1.2: Manufacturer: Dell
[    2.298670] input: Dell Dell USB Keyboard as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2/1-1.2:1.0/0003:413C:2003.0002/input/input1
[    2.362189] hid-generic 0003:413C:2003.0002: input,hidraw1: USB HID v1.10 Keyboard [Dell Dell USB Keyboard] on usb-0000:01:00.0-1.2/input0
[    2.461306] usb 1-1.3: new full-speed USB device number 5 using xhci_hcd
[    2.974059] systemd[1]: /lib/systemd/system/plymouth-start.service:16: Unit configured to use KillMode=none. This is unsafe, as it disables systemd's process lifecycle management for the service. Please update your service to use a safer KillMode=, such as 'mixed' or 'control-group'. Support for KillMode=none is deprecated and will eventually be removed.
[    3.081972] xhci_hcd 0000:01:00.0: ERROR: unexpected setup address command completion code 0x24.
[    3.170307] systemd[1]: Queued start job for default target Graphical Interface.
[    3.172043] random: systemd: uninitialized urandom read (16 bytes read)
[    3.176011] systemd[1]: Created slice system-getty.slice.
[    3.176415] random: systemd: uninitialized urandom read (16 bytes read)
[    3.177489] systemd[1]: Created slice system-modprobe.slice.
[    3.177603] random: systemd: uninitialized urandom read (16 bytes read)
[    3.178564] systemd[1]: Created slice system-systemd\x2dfsck.slice.
[    3.179504] systemd[1]: Created slice User and Session Slice.
[    3.180075] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    3.181632] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[    3.182427] systemd[1]: Reached target Slices.
[    3.182671] systemd[1]: Reached target Swap.
[    3.183819] systemd[1]: Listening on Syslog Socket.
[    3.184637] systemd[1]: Listening on fsck to fsckd communication Socket.
[    3.185089] systemd[1]: Listening on initctl Compatibility Named Pipe.
[    3.186331] systemd[1]: Listening on Journal Audit Socket.
[    3.187167] systemd[1]: Listening on Journal Socket (/dev/log).
[    3.188208] systemd[1]: Listening on Journal Socket.
[    3.190131] systemd[1]: Listening on udev Control Socket.
[    3.191044] systemd[1]: Listening on udev Kernel Socket.
[    3.192067] systemd[1]: Condition check resulted in Huge Pages File System being skipped.
[    3.197550] systemd[1]: Mounting POSIX Message Queue File System...
[    3.204062] systemd[1]: Mounting RPC Pipe File System...
[    3.211387] systemd[1]: Mounting Kernel Debug File System...
[    3.218989] systemd[1]: Mounting Kernel Trace File System...
[    3.219785] systemd[1]: Condition check resulted in Kernel Module supporting RPCSEC_GSS being skipped.
[    3.229546] systemd[1]: Starting Restore / save the current clock...
[    3.238673] systemd[1]: Starting Set the console keyboard layout...
[    3.246242] systemd[1]: Starting Create list of static device nodes for the current kernel...
[    3.255637] systemd[1]: Starting Load Kernel Module configfs...
[    3.264359] systemd[1]: Starting Load Kernel Module drm...
[    3.273202] systemd[1]: Starting Load Kernel Module fuse...
[    3.277261] systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
[    3.291722] systemd[1]: Starting File System Check on Root Device...
[    3.308072] systemd[1]: Starting Journal Service...
[    3.318783] systemd[1]: Starting Load Kernel Modules...
[    3.338334] fuse: init (API version 7.34)
[    3.342346] systemd[1]: Starting Coldplug All udev Devices...
[    3.356839] systemd[1]: Mounted POSIX Message Queue File System.
[    3.357771] systemd[1]: Mounted RPC Pipe File System.
[    3.358645] systemd[1]: Mounted Kernel Debug File System.
[    3.359458] systemd[1]: Mounted Kernel Trace File System.
[    3.361906] systemd[1]: Finished Restore / save the current clock.
[    3.364877] systemd[1]: Finished Create list of static device nodes for the current kernel.
[    3.367036] systemd[1]: modprobe@configfs.service: Succeeded.
[    3.368591] systemd[1]: Finished Load Kernel Module configfs.
[    3.370999] systemd[1]: modprobe@fuse.service: Succeeded.
[    3.372900] systemd[1]: Finished Load Kernel Module fuse.
[    3.380732] systemd[1]: Mounting FUSE Control File System...
[    3.405338] systemd[1]: Mounting Kernel Configuration File System...
[    3.434026] systemd[1]: Started File System Check Daemon to report status.
[    3.436632] i2c_dev: i2c /dev entries driver
[    3.474843] systemd[1]: modprobe@drm.service: Succeeded.
[    3.488031] systemd[1]: Finished Load Kernel Module drm.
[    3.506884] systemd[1]: Finished Load Kernel Modules.
[    3.508034] systemd[1]: Mounted FUSE Control File System.
[    3.508788] systemd[1]: Mounted Kernel Configuration File System.
[    3.515579] systemd[1]: Starting Apply Kernel Variables...
[    3.603850] systemd[1]: Finished Apply Kernel Variables.
[    3.715682] systemd[1]: Started Journal Service.
[    3.929626] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null). Quota mode: none.
[    3.931844] xhci_hcd 0000:01:00.0: ERROR: unexpected setup address command completion code 0x24.
[    4.001138] systemd-journald[136]: Received client request to flush runtime journal.
[    4.013766] systemd-journald[136]: File /var/log/journal/25070aeb79f44c94a7f7bcc85e4ba968/system.journal corrupted or uncleanly shut down, renaming and replacing.
[    4.161264] usb 1-1.3: device not accepting address 5, error -22
[    4.261329] usb 1-1.3: new full-speed USB device number 6 using xhci_hcd
[    4.881948] xhci_hcd 0000:01:00.0: ERROR: unexpected setup address command completion code 0x24.
[    5.219534] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000
[    5.221613] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000
[    5.242331] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000
[    5.331349] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000
[    5.523945] mc: Linux media interface: v0.10
[    5.541878] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
[    5.598571] videodev: Linux video capture interface: v2.00
[    5.601167] bcm2835_audio bcm2835_audio: card created with 8 channels
[    5.647860] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    5.656716] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[    5.656750] [vc_sm_connected_init]: start
[    5.675712] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    5.681722] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    5.682866] [drm] Initialized v3d 1.0.0 20180419 for fec00000.v3d on minor 0
[    5.687050] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    5.699303] [vc_sm_connected_init]: installed successfully
[    5.702019] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    5.707182] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
[    5.711708] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    5.721914] xhci_hcd 0000:01:00.0: ERROR: unexpected setup address command completion code 0x24.
[    5.722136] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    5.722625] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13
[    5.723153] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14
[    5.723617] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15
[    5.724004] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16
[    5.724036] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
[    5.724063] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
[    5.724086] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
[    5.724109] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
[    5.725607] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
[    5.740225] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
[    5.749619] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20
[    5.750190] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21
[    5.750635] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22
[    5.751006] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23
[    5.751054] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
[    5.751080] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
[    5.751103] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
[    5.751125] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
[    5.751990] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp
[    5.773628] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
[    5.773718] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
[    5.848835] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
[    5.848904] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
[    5.874018] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
[    5.874081] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
[    5.877531] bcm2835-codec bcm2835-codec: Device registered as /dev/video18
[    5.877579] bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx
[    5.881472] bcm2835-codec bcm2835-codec: Device registered as /dev/video31
[    5.881540] bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image
[    5.941310] usb 1-1.3: device not accepting address 6, error -22
[    5.942193] usb 1-1-port3: attempt power cycle
[    6.032488] checking generic (3e402000 7f8000) vs hw (0 ffffffffffffffff)
[    6.032518] fb0: switching to vc4 from simple
[    6.055534] Console: switching to colour dummy device 80x30
[    6.100381] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops [vc4])
[    6.112662] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops [vc4])
[    6.179759] i2c i2c-22: Added multiplexed i2c bus 0
[    6.180750] brcmstb-i2c fef04500.i2c:  @97500hz registered in polling mode
[    6.180973] i2c 10-0010: Fixing up cyclic dependency with fe801000.csi
[    6.181728] i2c i2c-22: Added multiplexed i2c bus 10
[    6.204269] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops [vc4])
[    6.208459] brcmstb-i2c fef09500.i2c:  @97500hz registered in polling mode
[    6.269715] Registered IR keymap rc-cec
[    6.269955] rc rc0: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0
[    6.270180] input: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0/input2
[    6.420031] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops [vc4])
[    6.444360] Registered IR keymap rc-cec
[    6.444578] rc rc0: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0
[    6.444921] input: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0/input3
[    6.574298] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    6.601374] usb 1-1.3: new full-speed USB device number 7 using xhci_hcd
[    6.683577] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    6.702223] cfg80211: loaded regulatory.db is malformed or signature is missing/invalid
[    6.767549] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops [vc4])
[    6.772441] brcmfmac: F1 signature read @0x18000000=0x15264345
[    6.799250] Registered IR keymap rc-cec
[    6.799467] rc rc0: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0
[    6.799751] input: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0/input4
[    6.801701] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    6.802784] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,4-model-b.bin failed with error -2
[    6.803402] usbcore: registered new interface driver brcmfmac
[    6.924270] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops [vc4])
[    6.930840] Registered IR keymap rc-cec
[    6.931035] rc rc0: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0
[    6.935664] input: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0/input5
[    7.083099] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    7.083239] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    7.088802] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov  1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60
[    7.221356] random: crng init done
[    7.221403] random: 7 urandom warning(s) missed due to ratelimiting
[    7.870829] uart-pl011 fe201000.serial: no DMA platform data
[    7.895152] 8021q: 802.1Q VLAN Support v1.8
[    8.034375] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)
[    8.035601] bcmgenet fd580000.ethernet eth0: Link is Down
[    8.195613] Adding 102396k swap on /var/swap.  Priority:-2 extents:1 across:102396k SSFS
[    8.375986] vc4-drm gpu: bound fe400000.hvs (ops vc4_hvs_ops [vc4])
[    8.404244] Registered IR keymap rc-cec
[    8.404455] rc rc0: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0
[    8.404706] input: vc4 as /devices/platform/soc/fef00700.hdmi/rc/rc0/input6
[    8.423776] vc4-drm gpu: bound fef00700.hdmi (ops vc4_hdmi_ops [vc4])
[    8.462514] Registered IR keymap rc-cec
[    8.462712] rc rc1: vc4 as /devices/platform/soc/fef05700.hdmi/rc/rc1
[    8.462956] input: vc4 as /devices/platform/soc/fef05700.hdmi/rc/rc1/input7
[    8.480887] vc4-drm gpu: bound fef05700.hdmi (ops vc4_hdmi_ops [vc4])
[    8.481506] vc4-drm gpu: bound fe004000.txp (ops vc4_txp_ops [vc4])
[    8.482012] vc4-drm gpu: bound fe206000.pixelvalve (ops vc4_crtc_ops [vc4])
[    8.482492] vc4-drm gpu: bound fe207000.pixelvalve (ops vc4_crtc_ops [vc4])
[    8.482934] vc4-drm gpu: bound fe20a000.pixelvalve (ops vc4_crtc_ops [vc4])
[    8.483275] vc4-drm gpu: bound fe216000.pixelvalve (ops vc4_crtc_ops [vc4])
[    8.483710] vc4-drm gpu: bound fec12000.pixelvalve (ops vc4_crtc_ops [vc4])
[    8.534451] [drm] Initialized vc4 0.0.0 20140616 for gpu on minor 1
[    8.649008] Console: switching to colour frame buffer device 240x67
[    8.649062] vc4-drm gpu: [drm] fb0: vc4drmfb frame buffer device
[    9.275559] imx219 10-0010: Consider updating driver imx219 to match on endpoints
[    9.590635] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
[   12.231374] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
[   12.231406] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   13.522624] ICMPv6: process `dhcpcd' is using deprecated sysctl (syscall) net.ipv6.neigh.eth0.retrans_time - use net.ipv6.neigh.eth0.retrans_time_ms instead
[   13.743082] hdmi-audio-codec hdmi-audio-codec.4.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
[   13.743117]  MAI: soc_pcm_open() failed (-19)
[   13.744142] hdmi-audio-codec hdmi-audio-codec.4.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
[   13.744175]  MAI: soc_pcm_open() failed (-19)
[   13.745062] hdmi-audio-codec hdmi-audio-codec.4.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
[   13.745098]  MAI: soc_pcm_open() failed (-19)
[   13.757949] hdmi-audio-codec hdmi-audio-codec.4.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
[   13.757988]  MAI: soc_pcm_open() failed (-19)
[   13.758455] hdmi-audio-codec hdmi-audio-codec.4.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
[   13.758483]  MAI: soc_pcm_open() failed (-19)
[   13.758890] hdmi-audio-codec hdmi-audio-codec.4.auto: ASoC: error at snd_soc_dai_startup on i2s-hifi: -19
[   13.758920]  MAI: soc_pcm_open() failed (-19)
[   14.892023] Bluetooth: Core ver 2.22
[   14.892165] NET: Registered PF_BLUETOOTH protocol family
[   14.892181] Bluetooth: HCI device and connection manager initialized
[   14.892211] Bluetooth: HCI socket layer initialized
[   14.892232] Bluetooth: L2CAP socket layer initialized
[   14.892279] Bluetooth: SCO socket layer initialized
[   14.910074] Bluetooth: HCI UART driver ver 2.3
[   14.910091] Bluetooth: HCI UART protocol H4 registered
[   14.910155] Bluetooth: HCI UART protocol Three-wire (H5) registered
[   14.910840] Bluetooth: HCI UART protocol Broadcom registered
[   15.135394] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[   15.135411] Bluetooth: BNEP filters: protocol multicast
[   15.135424] Bluetooth: BNEP socket layer initialized
[   15.159927] NET: Registered PF_ALG protocol family
[   15.188321] cryptd: max_cpu_qlen set to 1000
[   15.410006] Bluetooth: RFCOMM TTY layer initialized
[   15.410033] Bluetooth: RFCOMM socket layer initialized
[   15.410047] Bluetooth: RFCOMM ver 1.11
[   21.851570] usb 1-1.3: device descriptor read/64, error -110
[   31.831942] cam-dummy-reg: disabling
[   37.212603] usb 1-1.3: device descriptor read/64, error -110
[   37.432325] usb 1-1.3: new full-speed USB device number 8 using xhci_hcd
[   52.653227] usb 1-1.3: device descriptor read/64, error -110
[   68.013445] usb 1-1.3: device descriptor read/64, error -110
[   68.133934] usb 1-1-port3: unable to enumerate USB device
[  103.775993] v3d fec00000.v3d: MMU error from client CLE (4) at 0x14a1000, pte invalid
popcornmix commented 2 years ago

Unfortunately, adding usbcore.old_scheme_first=1 to the cmdline.txt did not work.

You can confirm adding the option has worked with cat /proc/cmdline and checking for usbcore.old_scheme_first=1

6by9 commented 2 years ago
[    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 video=HDMI-A-1:1920x1080M@60 smsc95xx.macaddr=E4:5F:01:A3:0B:24 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  console=ttyS0,115200 console=tty1 root=PARTUUID=e2d5ff95-02 rootfstype=ext4 fsck.repair=yes rootwait quiet splash plymouth.ignore-serial-consoles usbcore.old_scheme_first=1
[    0.000000] Unknown kernel command line parameters "splash", will be passed to user space.

usbcore.old_scheme_first=1 is there on the end.

P33M commented 2 years ago

In that case that pretty much exhausts all the tunable options for altering device probe behaviour. Does the device work when plugged into a Linux x86 PC with xHCI controllers?

ReneElizondo commented 2 years ago

Thanks everyone for your help.

I am still struggling with the fact that if I plug the ThingMagic device 2 or 3 seconds after the Pi starts the bootup process everything works fine. Also, I can unplug and re-plug the ThingMagic device while the Pi is on as many times as I want (we have done that literally hundreds of times) and everything works just fine. To me, this feels more like right at startup (very early in the bootup process), something in the hardware or software is happening that puts the ThingMagic device on a bad and unrecoverable state rendering the device unusable. Is this not a possible scenario?

Other potential relevant info may be that we have been using these devices for years (5 or 6 years) on Windows (laptop / desktops) and we have never experienced any problems (I am sure those computers use xHCI controllers).

I will try to put together a Linux computer where I can try this out, however, the company that sells the ThingMagic device said that they have tested this in Linux and they experienced no issues. They did test the ThingMagic device on a Raspberry Pi 4 after I reported the issue to them and they were able to reproduce the problem but they have no intention of fixing the problem on their side because they claim it only fails on Raspberry Pi 4 computers.

Would it help if I ship you guys a ThingMagic device for you to test with? Those things are very expensive but its worth it for us given that we have developed a product that uses the Raspberry Pi that worked in a test environment but is failing big time in a production environment (after it has been deployed for a couple for days).... this is not the only issue we are experiencing by the way, there is another big issue but we are hoping that if we can fix this issue the other issue may get fixed too...

Also, we are ok with paying for this issue to get fixed (assuming the cost is reasonable), we are petty desperate to get this fixed.

Please let me know.

Thanks.

ReneElizondo commented 2 years ago

In case it matters, the other issue we are experiencing has to do with the ThingMagic USB device constantly disconnecting and reconnecting. Example log below:

Jun 14 19:26:56 raspberrypi kernel: usb 1-1.2: USB disconnect, device number 5
Jun 14 19:26:56 raspberrypi kernel: usb 1-1.2.1: USB disconnect, device number 6
Jun 14 19:26:57 raspberrypi kernel: usb 1-1.2: new high-speed USB device number 7 using xhci_hcd
Jun 14 19:26:57 raspberrypi kernel: usb 1-1.2: New USB device found, idVendor=1a40, idProduct=0101, bcdDevice= 1.00
Jun 14 19:26:57 raspberrypi kernel: usb 1-1.2: New USB device strings: Mfr=0, Product=1, SerialNumber=0
Jun 14 19:26:57 raspberrypi kernel: usb 1-1.2: Product: USB2.0 HUB
Jun 14 19:26:57 raspberrypi kernel: hub 1-1.2:1.0: USB hub found
Jun 14 19:26:57 raspberrypi kernel: hub 1-1.2:1.0: 4 ports detected
Jun 14 19:26:57 raspberrypi kernel: usb 1-1.2.1: new full-speed USB device number 8 using xhci_hcd
Jun 14 19:26:57 raspberrypi kernel: usb 1-1.2.1: New USB device found, idVendor=2008, idProduct=1004, bcdDevice= 0.01
Jun 14 19:26:57 raspberrypi kernel: usb 1-1.2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Jun 14 19:26:57 raspberrypi kernel: usb 1-1.2.1: Product: USBPro5121348010572KH+
Jun 14 19:26:57 raspberrypi kernel: usb 1-1.2.1: Manufacturer: ThingMagic, Inc.
Jun 14 19:26:57 raspberrypi kernel: cdc_acm 1-1.2.1:1.0: ttyACM0: USB ACM device

This happens many times a day, eventually unfortunately, luck runs out and at some point, when the ThingMagic USB device tries to reconnect you start seeming errors such as:

Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2: clear tt 1 (8000) error -71
Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2: clear tt 1 (8000) error -71
Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2: clear tt 1 (8000) error -71
Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2-port1: cannot reset (err = -71)
Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2-port1: cannot reset (err = -71)
Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2-port1: cannot reset (err = -71)
Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2-port1: cannot reset (err = -71)
Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2-port1: cannot reset (err = -71)
Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2-port1: Cannot enable. Maybe the USB cable is bad?
Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2-port1: cannot disable (err = -71)
Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2-port1: cannot reset (err = -71)
Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2-port1: cannot reset (err = -71)
Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2-port1: cannot reset (err = -71)
Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2-port1: cannot reset (err = -71)
Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2-port1: cannot reset (err = -71)
Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2-port1: Cannot enable. Maybe the USB cable is bad?
Jun 15 23:58:09 raspberrypi kernel: usb 1-1.2-port1: cannot disable (err = -71)
Jun 16 06:17:03 raspberrypi kernel: hub 1-1.2:1.0: hub_ext_port_status failed (err = -71)
Jun 16 06:17:03 raspberrypi kernel: usb 1-1.2: Failed to suspend device, error -71
Jun 16 08:36:14 raspberrypi kernel: usb 1-1.2: device descriptor read/64, error -71
Jun 16 08:36:14 raspberrypi kernel: usb 1-1.2: New USB device found, idVendor=1a40, idProduct=0101, bcdDevice= 1.00
Jun 16 08:36:14 raspberrypi kernel: usb 1-1.2: New USB device strings: Mfr=0, Product=1, SerialNumber=0
Jun 16 08:36:14 raspberrypi kernel: usb 1-1.2: Product: USB2.0 HUB
Jun 16 08:36:14 raspberrypi kernel: hub 1-1.2:1.0: USB hub found
Jun 16 08:36:14 raspberrypi kernel: hub 1-1.2:1.0: 4 ports detected
Jun 16 08:36:15 raspberrypi kernel: usb 1-1.2.1: new full-speed USB device number 26 using xhci_hcd
Jun 16 08:36:16 raspberrypi kernel: xhci_hcd 0000:01:00.0: Setup ERROR: setup address command for slot 3.
Jun 16 08:36:16 raspberrypi kernel: usb 1-1.2: USB disconnect, device number 25
Jun 16 08:36:16 raspberrypi kernel: xhci_hcd 0000:01:00.0: Setup ERROR: setup address command for slot 3.
Jun 16 08:36:16 raspberrypi kernel: usb 1-1.2.1: device not accepting address 26, error -22

usb 1-1-port2: Cannot enable. Maybe the USB cable is bad?

Thanks.

antonypenn commented 2 years ago

You could make a small piece of hardware to fix your issue. Make a small USB male-female lead, cut the +5v lead and connect that to a MOSFET transistor, controlled by a GPIO pin. That way, you can power it on and off via one of the GPIO pins. I do this to control other pieces of hardware.

ReneElizondo commented 2 years ago

@antonypenn Thanks, we actually thought of doing something similar to your suggestion, the problem is that we also discovered that the ThingMagic USB device disconnects and reconnects all the time while the Pi is on (https://github.com/raspberrypi/linux/issues/5046#issuecomment-1159818309), eventually the reconnect starts failing and thing go downhill from there. Its gets bad enough that eventually, the device will fail to reconnect and even un-plugiin and re-plugin the ThingMagic USB Device will still fail, only a reboot can get things to work again.

I am starting to think the issue may be related to USB hardware issues, even the smallest voltage change appears to trigger a disconnect / reconnect on the ThingMagic USB device. Some USB devices like mouse and keyboards appear to be less sensitive to voltage changes. It make look like this is unique to the ThingMagic device but I see others have similar issues.

Just keep hoping a solution will be found at sometime, or at least find the source cause even with no solution, jus an answer of what may be going on would be great.

antonypenn commented 2 years ago

You might want to try a different USB cable. I think you mentioned that your cable is captive, which is a shame. I have just solved a problem that uses the same chip as your product (thats how I came across your post) and solved it by replacing the OEM's supplied cable, with one I had lying around here. Especially for high speed (USB2) and over, the cable quality (screening etc) is very important. One option (if you are brave enough) is to cut your cable off the device, just a few inches long, and put a USB plug on it, then use a good quality USB extension lead.

ReneElizondo commented 2 years ago

@P33M

In that case that pretty much exhausts all the tunable options for altering device probe behavior. Does the device work when plugged into a Linux x86 PC with xHCI controllers?

We ended up putting together a computer and installed Debian OS (the latest versions), the install was "pure" (no dual boot, no windows, no nothing), just pure Linux on that machine. We rebooted the machine several times as well as turn the computer off and on several times and every single time the ThingMagic USB device was recognized without a problem. I have included the dmesg below in case you may find it useful.

That said, this (to me at least) appears to indicate that this is a bug with the Raspberry Pi. If that is the case, what is the next step? Is this something that you guys would look into and attempt to fix? We would really like to get this issue resolved even if it means having to pay to fix the issue (assuming the cost is reasonable).

Thanks.

[    0.000000] Linux version 5.10.0-15-amd64 (debian-kernel@lists.debian.org) (gcc-10 (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2) #1 SMP Debian 5.10.120-1 (2022-06-09)
[    0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-5.10.0-15-amd64 root=UUID=81d46985-fa68-408f-85c0-ebc2a40740e0 ro quiet
[    0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x008: 'MPX bounds registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x010: 'MPX CSR'
[    0.000000] x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
[    0.000000] x86/fpu: xstate_offset[3]:  832, xstate_sizes[3]:   64
[    0.000000] x86/fpu: xstate_offset[4]:  896, xstate_sizes[4]:   64
[    0.000000] x86/fpu: Enabled xstate features 0x1f, context size is 960 bytes, using 'compacted' format.
[    0.000000] BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009efff] usable
[    0.000000] BIOS-e820: [mem 0x000000000009f000-0x00000000000fffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000b66aafff] usable
[    0.000000] BIOS-e820: [mem 0x00000000b66ab000-0x00000000b798efff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000b798f000-0x00000000b7b8efff] ACPI NVS
[    0.000000] BIOS-e820: [mem 0x00000000b7b8f000-0x00000000b7c0efff] ACPI data
[    0.000000] BIOS-e820: [mem 0x00000000b7c0f000-0x00000000b7c0ffff] usable
[    0.000000] BIOS-e820: [mem 0x00000000b7c10000-0x00000000be7fffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fe010000-0x00000000fe010fff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000ff000000-0x00000000ffffffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000100000000-0x000000023d7fffff] usable
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] efi: EFI v2.60 by HP
[    0.000000] efi: ACPI=0xb7c0e000 ACPI 2.0=0xb7c0e014 ESRT=0xb6e75b98 TPMFinalLog=0xb7b37000 SMBIOS=0xb6e74000 MEMATTR=0xb2cdd018 MOKvar=0xb2849000 RNG=0xb6e72d98 TPMEventLog=0xa4f72018 
[    0.000000] efi: seeding entropy pool
[    0.000000] Kernel is locked down from EFI Secure Boot; see man kernel_lockdown.7
[    0.000000] secureboot: Secure boot enabled
[    0.000000] SMBIOS 3.1 present.
[    0.000000] DMI: HP HP EliteBook 840 G6/8549, BIOS R70 Ver. 01.06.00 08/03/2020
[    0.000000] tsc: Detected 1800.000 MHz processor
[    0.000013] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[    0.000018] e820: remove [mem 0x000a0000-0x000fffff] usable
[    0.000026] last_pfn = 0x23d800 max_arch_pfn = 0x400000000
[    0.000032] MTRR default type: write-back
[    0.000033] MTRR fixed ranges enabled:
[    0.000035]   00000-9FFFF write-back
[    0.000037]   A0000-BFFFF uncachable
[    0.000039]   C0000-FFFFF write-protect
[    0.000040] MTRR variable ranges enabled:
[    0.000042]   0 base 00C0000000 mask 7FC0000000 uncachable
[    0.000044]   1 base 00BC000000 mask 7FFC000000 uncachable
[    0.000046]   2 base 2000000000 mask 6000000000 uncachable
[    0.000048]   3 base 1000000000 mask 7000000000 uncachable
[    0.000049]   4 base 0800000000 mask 7800000000 uncachable
[    0.000051]   5 base 0400000000 mask 7C00000000 uncachable
[    0.000052]   6 base 4000000000 mask 4000000000 uncachable
[    0.000053]   7 disabled
[    0.000054]   8 disabled
[    0.000055]   9 disabled
[    0.000835] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WP  UC- WT  
[    0.001388] last_pfn = 0xb7c10 max_arch_pfn = 0x400000000
[    0.015384] esrt: Reserving ESRT space from 0x00000000b6e75b98 to 0x00000000b6e75bf8.
[    0.015395] e820: update [mem 0xb2849000-0xb284bfff] usable ==> reserved
[    0.015420] Using GB pages for direct mapping
[    0.016146] RAMDISK: [mem 0x3b468000-0x3dc47fff]
[    0.016149] ACPI: Early table checksum verification disabled
[    0.016153] ACPI: RSDP 0x00000000B7C0E014 000024 (v02 HPQOEM)
[    0.016158] ACPI: XSDT 0x00000000B7BB9188 000154 (v01 HPQOEM SLIC-BPC 00000000 INTL 20160422)
[    0.016167] ACPI: FACP 0x00000000B7BF2000 000114 (v06 HPQOEM SLIC-BPC 00000000 HP   00000001)
[    0.016175] ACPI: DSDT 0x00000000B7BC6000 028181 (v02 HPQOEM 8549     00000000 INTL 20160527)
[    0.016180] ACPI: FACS 0x00000000B7B31000 000040
[    0.016184] ACPI: SSDT 0x00000000B7C0C000 0002D7 (v01 HP     NVTEC    00000001 INTL 20160527)
[    0.016188] ACPI: SSDT 0x00000000B7C0B000 00012A (v02 HP     ShmTable 00000001 INTL 20160527)
[    0.016193] ACPI: SSDT 0x00000000B7C09000 001B5F (v02 CpuRef CpuSsdt  00003000 INTL 20160527)
[    0.016198] ACPI: SSDT 0x00000000B7C08000 0009CF (v02 CtdpB  CtdpB    00001000 INTL 20160527)
[    0.016203] ACPI: SSDT 0x00000000B7BFB000 00CE82 (v02 AcpiRe PLT_RTD3 00001000 INTL 20160527)
[    0.016207] ACPI: RTMA 0x00000000B7BF9000 00009E (v01 HP     _HBMART_ 00001000 HP   00000001)
[    0.016212] ACPI: SSDT 0x00000000B7BF7000 001575 (v02 HP     UcsiAcpi 00000001 INTL 20160527)
[    0.016217] ACPI: SSDT 0x00000000B7BF6000 0000FB (v02 HP     UcsiCntr 00000001 INTL 20160527)
[    0.016221] ACPI: MSDM 0x00000000B7BF5000 000055 (v03 HPQOEM SLIC-BPC 00000000 HP   00000001)
[    0.016226] ACPI: SLIC 0x00000000B7BF4000 000176 (v01 HPQOEM SLIC-BPC 00000001 HP   00000001)
[    0.016230] ACPI: WSMT 0x00000000B7BF3000 000028 (v01 HPQOEM 8549     00000001 HP   00000001)
[    0.016235] ACPI: HPET 0x00000000B7BF1000 000038 (v01 HPQOEM 8549     00000001 HP   00000001)
[    0.016239] ACPI: APIC 0x00000000B7BF0000 00012C (v03 HPQOEM 8549     00000001 HP   00000001)
[    0.016243] ACPI: MCFG 0x00000000B7BEF000 00003C (v01 HPQOEM 8549     00000001 HP   00000001)
[    0.016248] ACPI: SSDT 0x00000000B7BC5000 000746 (v02 HPQOEM PtidDevc 00001000 INTL 20160527)
[    0.016252] ACPI: SSDT 0x00000000B7BC4000 00089D (v02 HPQOEM HP_XHC_P 00000000 INTL 20160527)
[    0.016257] ACPI: NHLT 0x00000000B7BC2000 0017F1 (v00 INTEL  CFL-ULT  20170001 INTL 20160422)
[    0.016262] ACPI: SSDT 0x00000000B7BBE000 003CEE (v02 DptfTa DptfTabl 00001000 INTL 20160527)
[    0.016266] ACPI: SSDT 0x00000000B7BBA000 003125 (v02 SaSsdt SaSsdt   00003000 INTL 20160527)
[    0.016271] ACPI: LPIT 0x00000000B7C0D000 000094 (v01 INTEL  CFL-ULT  20170001 INTL 20160422)
[    0.016275] ACPI: WSMT 0x00000000B7BB8000 000028 (v01 INTEL  CFL-ULT  20170001 INTL 20160422)
[    0.016280] ACPI: SSDT 0x00000000B7BB7000 0003CE (v02 INTEL  Tpm2Tabl 00001000 INTL 20160527)
[    0.016284] ACPI: TPM2 0x00000000B7BB6000 000034 (v04 INTEL  CFL-ULT  20170001 INTL 20160422)
[    0.016289] ACPI: UEFI 0x00000000B7B2B000 000042 (v01 INTEL  CFL-ULT  20170001 INTL 20160422)
[    0.016293] ACPI: OEML 0x00000000B7BB5000 000028 (v03 INTEL  CFL-ULT  20170001 INTL 20160422)
[    0.016298] ACPI: SSDT 0x00000000B7BA0000 013C48 (v02 HP     HPTBT    00001000 INTL 20160527)
[    0.016303] ACPI: SSDT 0x00000000B7B9F000 000989 (v01 HP     HPINWWAN 00001000 INTL 20160527)
[    0.016307] ACPI: SSDT 0x00000000B7B9E000 00013B (v01 HP     HPNBCONV 00001000 INTL 20160527)
[    0.016312] ACPI: SSDT 0x00000000B7B9D000 000328 (v01 HP     INTTPL   00001000 INTL 20160527)
[    0.016316] ACPI: SSDT 0x00000000B7B9B000 001377 (v01 HP     HPINNBWL 00001000 INTL 20160527)
[    0.016321] ACPI: SSDT 0x00000000B7B9A000 000032 (v01 HP     HPCONDEV 00001000 INTL 20160527)
[    0.016325] ACPI: SSDT 0x00000000B7B99000 000115 (v01 HP     HPSANIMD 00001000 INTL 20160527)
[    0.016330] ACPI: SSDT 0x00000000B7B98000 000069 (v01 HP     HPCAHWID 00001000 INTL 20160527)
[    0.016334] ACPI: DMAR 0x00000000B7BB4000 0000C8 (v01 INTEL  WHL      00000002 INTL 01000013)
[    0.016339] ACPI: FPDT 0x00000000B7B97000 000044 (v01 INTEL  CFL-ULT  20170001 INTL 20160422)
[    0.016343] ACPI: BGRT 0x00000000B7B96000 000038 (v01 INTEL  CFL-ULT  20170001 INTL 20160422)
[    0.016348] ACPI: SSDT 0x00000000B7BFA000 0002F9 (v02 HP     PwrCtlEv 00000001 INTL 20160527)
[    0.016353] ACPI: Reserving FACP table memory at [mem 0xb7bf2000-0xb7bf2113]
[    0.016355] ACPI: Reserving DSDT table memory at [mem 0xb7bc6000-0xb7bee180]
[    0.016356] ACPI: Reserving FACS table memory at [mem 0xb7b31000-0xb7b3103f]
[    0.016358] ACPI: Reserving SSDT table memory at [mem 0xb7c0c000-0xb7c0c2d6]
[    0.016359] ACPI: Reserving SSDT table memory at [mem 0xb7c0b000-0xb7c0b129]
[    0.016361] ACPI: Reserving SSDT table memory at [mem 0xb7c09000-0xb7c0ab5e]
[    0.016362] ACPI: Reserving SSDT table memory at [mem 0xb7c08000-0xb7c089ce]
[    0.016364] ACPI: Reserving SSDT table memory at [mem 0xb7bfb000-0xb7c07e81]
[    0.016365] ACPI: Reserving RTMA table memory at [mem 0xb7bf9000-0xb7bf909d]
[    0.016367] ACPI: Reserving SSDT table memory at [mem 0xb7bf7000-0xb7bf8574]
[    0.016368] ACPI: Reserving SSDT table memory at [mem 0xb7bf6000-0xb7bf60fa]
[    0.016370] ACPI: Reserving MSDM table memory at [mem 0xb7bf5000-0xb7bf5054]
[    0.016371] ACPI: Reserving SLIC table memory at [mem 0xb7bf4000-0xb7bf4175]
[    0.016373] ACPI: Reserving WSMT table memory at [mem 0xb7bf3000-0xb7bf3027]
[    0.016374] ACPI: Reserving HPET table memory at [mem 0xb7bf1000-0xb7bf1037]
[    0.016376] ACPI: Reserving APIC table memory at [mem 0xb7bf0000-0xb7bf012b]
[    0.016377] ACPI: Reserving MCFG table memory at [mem 0xb7bef000-0xb7bef03b]
[    0.016379] ACPI: Reserving SSDT table memory at [mem 0xb7bc5000-0xb7bc5745]
[    0.016381] ACPI: Reserving SSDT table memory at [mem 0xb7bc4000-0xb7bc489c]
[    0.016382] ACPI: Reserving NHLT table memory at [mem 0xb7bc2000-0xb7bc37f0]
[    0.016384] ACPI: Reserving SSDT table memory at [mem 0xb7bbe000-0xb7bc1ced]
[    0.016385] ACPI: Reserving SSDT table memory at [mem 0xb7bba000-0xb7bbd124]
[    0.016387] ACPI: Reserving LPIT table memory at [mem 0xb7c0d000-0xb7c0d093]
[    0.016389] ACPI: Reserving WSMT table memory at [mem 0xb7bb8000-0xb7bb8027]
[    0.016391] ACPI: Reserving SSDT table memory at [mem 0xb7bb7000-0xb7bb73cd]
[    0.016393] ACPI: Reserving TPM2 table memory at [mem 0xb7bb6000-0xb7bb6033]
[    0.016394] ACPI: Reserving UEFI table memory at [mem 0xb7b2b000-0xb7b2b041]
[    0.016396] ACPI: Reserving OEML table memory at [mem 0xb7bb5000-0xb7bb5027]
[    0.016398] ACPI: Reserving SSDT table memory at [mem 0xb7ba0000-0xb7bb3c47]
[    0.016399] ACPI: Reserving SSDT table memory at [mem 0xb7b9f000-0xb7b9f988]
[    0.016401] ACPI: Reserving SSDT table memory at [mem 0xb7b9e000-0xb7b9e13a]
[    0.016403] ACPI: Reserving SSDT table memory at [mem 0xb7b9d000-0xb7b9d327]
[    0.016404] ACPI: Reserving SSDT table memory at [mem 0xb7b9b000-0xb7b9c376]
[    0.016406] ACPI: Reserving SSDT table memory at [mem 0xb7b9a000-0xb7b9a031]
[    0.016408] ACPI: Reserving SSDT table memory at [mem 0xb7b99000-0xb7b99114]
[    0.016409] ACPI: Reserving SSDT table memory at [mem 0xb7b98000-0xb7b98068]
[    0.016411] ACPI: Reserving DMAR table memory at [mem 0xb7bb4000-0xb7bb40c7]
[    0.016413] ACPI: Reserving FPDT table memory at [mem 0xb7b97000-0xb7b97043]
[    0.016414] ACPI: Reserving BGRT table memory at [mem 0xb7b96000-0xb7b96037]
[    0.016416] ACPI: Reserving SSDT table memory at [mem 0xb7bfa000-0xb7bfa2f8]
[    0.016432] ACPI: Local APIC address 0xfee00000
[    0.016637] No NUMA configuration found
[    0.016638] Faking a node at [mem 0x0000000000000000-0x000000023d7fffff]
[    0.016658] NODE_DATA(0) allocated [mem 0x23d7d6000-0x23d7fffff]
[    0.017232] Zone ranges:
[    0.017234]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.017236]   DMA32    [mem 0x0000000001000000-0x00000000ffffffff]
[    0.017238]   Normal   [mem 0x0000000100000000-0x000000023d7fffff]
[    0.017240]   Device   empty
[    0.017242] Movable zone start for each node
[    0.017247] Early memory node ranges
[    0.017249]   node   0: [mem 0x0000000000001000-0x000000000009efff]
[    0.017250]   node   0: [mem 0x0000000000100000-0x00000000b66aafff]
[    0.017252]   node   0: [mem 0x00000000b7c0f000-0x00000000b7c0ffff]
[    0.017253]   node   0: [mem 0x0000000100000000-0x000000023d7fffff]
[    0.017256] Initmem setup node 0 [mem 0x0000000000001000-0x000000023d7fffff]
[    0.017258] On node 0 totalpages: 2047562
[    0.017260]   DMA zone: 64 pages used for memmap
[    0.017261]   DMA zone: 22 pages reserved
[    0.017262]   DMA zone: 3998 pages, LIFO batch:0
[    0.017264]   DMA32 zone: 11611 pages used for memmap
[    0.017265]   DMA32 zone: 743084 pages, LIFO batch:63
[    0.017267]   Normal zone: 20320 pages used for memmap
[    0.017268]   Normal zone: 1300480 pages, LIFO batch:63
[    0.017272] On node 0, zone DMA: 1 pages in unavailable ranges
[    0.017349] On node 0, zone DMA: 97 pages in unavailable ranges
[    0.028686] On node 0, zone DMA32: 5476 pages in unavailable ranges
[    0.029219] On node 0, zone Normal: 1008 pages in unavailable ranges
[    0.029383] On node 0, zone Normal: 10240 pages in unavailable ranges
[    0.029401] Reserving Intel graphics memory at [mem 0xbc800000-0xbe7fffff]
[    0.030314] ACPI: PM-Timer IO Port: 0x1808
[    0.030316] ACPI: Local APIC address 0xfee00000
[    0.030325] ACPI: LAPIC_NMI (acpi_id[0x01] high edge lint[0x1])
[    0.030326] ACPI: LAPIC_NMI (acpi_id[0x02] high edge lint[0x1])
[    0.030327] ACPI: LAPIC_NMI (acpi_id[0x03] high edge lint[0x1])
[    0.030328] ACPI: LAPIC_NMI (acpi_id[0x04] high edge lint[0x1])
[    0.030329] ACPI: LAPIC_NMI (acpi_id[0x05] high edge lint[0x1])
[    0.030330] ACPI: LAPIC_NMI (acpi_id[0x06] high edge lint[0x1])
[    0.030331] ACPI: LAPIC_NMI (acpi_id[0x07] high edge lint[0x1])
[    0.030332] ACPI: LAPIC_NMI (acpi_id[0x08] high edge lint[0x1])
[    0.030333] ACPI: LAPIC_NMI (acpi_id[0x09] high edge lint[0x1])
[    0.030334] ACPI: LAPIC_NMI (acpi_id[0x0a] high edge lint[0x1])
[    0.030335] ACPI: LAPIC_NMI (acpi_id[0x0b] high edge lint[0x1])
[    0.030336] ACPI: LAPIC_NMI (acpi_id[0x0c] high edge lint[0x1])
[    0.030337] ACPI: LAPIC_NMI (acpi_id[0x0d] high edge lint[0x1])
[    0.030338] ACPI: LAPIC_NMI (acpi_id[0x0e] high edge lint[0x1])
[    0.030339] ACPI: LAPIC_NMI (acpi_id[0x0f] high edge lint[0x1])
[    0.030340] ACPI: LAPIC_NMI (acpi_id[0x10] high edge lint[0x1])
[    0.030394] IOAPIC[0]: apic_id 2, version 32, address 0xfec00000, GSI 0-119
[    0.030397] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[    0.030399] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[    0.030401] ACPI: IRQ0 used by override.
[    0.030403] ACPI: IRQ9 used by override.
[    0.030406] Using ACPI (MADT) for SMP configuration information
[    0.030407] ACPI: HPET id: 0x8086a201 base: 0xfed00000
[    0.030418] e820: update [mem 0xb2194000-0xb21dcfff] usable ==> reserved
[    0.030428] TSC deadline timer available
[    0.030429] smpboot: Allowing 8 CPUs, 0 hotplug CPUs
[    0.030454] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
[    0.030457] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]
[    0.030460] PM: hibernation: Registered nosave memory: [mem 0xb2194000-0xb21dcfff]
[    0.030463] PM: hibernation: Registered nosave memory: [mem 0xb2849000-0xb284bfff]
[    0.030465] PM: hibernation: Registered nosave memory: [mem 0xb66ab000-0xb798efff]
[    0.030466] PM: hibernation: Registered nosave memory: [mem 0xb798f000-0xb7b8efff]
[    0.030467] PM: hibernation: Registered nosave memory: [mem 0xb7b8f000-0xb7c0efff]
[    0.030470] PM: hibernation: Registered nosave memory: [mem 0xb7c10000-0xbe7fffff]
[    0.030471] PM: hibernation: Registered nosave memory: [mem 0xbe800000-0xfe00ffff]
[    0.030472] PM: hibernation: Registered nosave memory: [mem 0xfe010000-0xfe010fff]
[    0.030473] PM: hibernation: Registered nosave memory: [mem 0xfe011000-0xfeffffff]
[    0.030474] PM: hibernation: Registered nosave memory: [mem 0xff000000-0xffffffff]
[    0.030476] [mem 0xbe800000-0xfe00ffff] available for PCI devices
[    0.030478] Booting paravirtualized kernel on bare hardware
[    0.030481] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns
[    0.037629] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:8 nr_cpu_ids:8 nr_node_ids:1
[    0.037970] percpu: Embedded 58 pages/cpu s200664 r8192 d28712 u262144
[    0.037981] pcpu-alloc: s200664 r8192 d28712 u262144 alloc=1*2097152
[    0.037982] pcpu-alloc: [0] 0 1 2 3 4 5 6 7 
[    0.038032] Built 1 zonelists, mobility grouping on.  Total pages: 2015545
[    0.038033] Policy zone: Normal
[    0.038035] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-5.10.0-15-amd64 root=UUID=81d46985-fa68-408f-85c0-ebc2a40740e0 ro quiet
[    0.038907] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, linear)
[    0.039366] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)
[    0.039469] mem auto-init: stack:off, heap alloc:on, heap free:off
[    0.065878] Memory: 2846588K/8190248K available (12295K kernel code, 2536K rwdata, 7564K rodata, 2424K init, 3680K bss, 451212K reserved, 0K cma-reserved)
[    0.067131] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=8, Nodes=1
[    0.067188] ftrace: allocating 36451 entries in 143 pages
[    0.089126] ftrace: allocated 143 pages with 5 groups
[    0.089403] rcu: Hierarchical RCU implementation.
[    0.089406] rcu:     RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=8.
[    0.089407]  Rude variant of Tasks RCU enabled.
[    0.089408]  Tracing variant of Tasks RCU enabled.
[    0.089410] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
[    0.089411] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=8
[    0.096288] NR_IRQS: 524544, nr_irqs: 2048, preallocated irqs: 16
[    0.096816] random: crng init done
[    0.096846] Console: colour dummy device 80x25
[    0.096871] printk: console [tty0] enabled
[    0.096892] ACPI: Core revision 20200925
[    0.097551] hpet: HPET dysfunctional in PC10. Force disabled.
[    0.097552] APIC: Switch to symmetric I/O mode setup
[    0.097555] DMAR: Host address width 39
[    0.097557] DMAR: DRHD base: 0x000000fed90000 flags: 0x0
[    0.097564] DMAR: dmar0: reg_base_addr fed90000 ver 1:0 cap 1c0000c40660462 ecap 19e2ff0505e
[    0.097566] DMAR: DRHD base: 0x000000fed91000 flags: 0x1
[    0.097571] DMAR: dmar1: reg_base_addr fed91000 ver 1:0 cap d2008c40660462 ecap f050da
[    0.097572] DMAR: RMRR base: 0x000000b781d000 end: 0x000000b783cfff
[    0.097574] DMAR: RMRR base: 0x000000bc000000 end: 0x000000be7fffff
[    0.097575] DMAR: RMRR base: 0x000000b786e000 end: 0x000000b78edfff
[    0.097578] DMAR-IR: IOAPIC id 2 under DRHD base  0xfed91000 IOMMU 1
[    0.097579] DMAR-IR: HPET id 0 under DRHD base 0xfed91000
[    0.097580] DMAR-IR: Queued invalidation will be enabled to support x2apic and Intr-remapping.
[    0.100437] DMAR-IR: Enabled IRQ remapping in x2apic mode
[    0.100439] x2apic enabled
[    0.100469] Switched APIC routing to cluster x2apic.
[    0.107398] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x19f2297dd97, max_idle_ns: 440795236593 ns
[    0.107403] Calibrating delay loop (skipped), value calculated using timer frequency.. 3600.00 BogoMIPS (lpj=7200000)
[    0.107407] pid_max: default: 32768 minimum: 301
[    0.111401] LSM: Security Framework initializing
[    0.111401] Yama: disabled by default; enable with sysctl kernel.yama.*
[    0.111401] AppArmor: AppArmor initialized
[    0.111401] TOMOYO Linux initialized
[    0.111401] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, linear)
[    0.111401] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, linear)
[    0.111401] mce: CPU0: Thermal monitoring enabled (TM1)
[    0.111401] process: using mwait in idle threads
[    0.111401] Last level iTLB entries: 4KB 64, 2MB 8, 4MB 8
[    0.111401] Last level dTLB entries: 4KB 64, 2MB 0, 4MB 0, 1GB 4
[    0.111401] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[    0.111401] Spectre V2 : Mitigation: Enhanced IBRS
[    0.111401] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[    0.111401] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
[    0.111401] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl and seccomp
[    0.111401] SRBDS: Mitigation: TSX disabled
[    0.111401] Freeing SMP alternatives memory: 32K
[    0.111401] smpboot: CPU0: Intel(R) Core(TM) i5-8265U CPU @ 1.60GHz (family: 0x6, model: 0x8e, stepping: 0xc)
[    0.111401] Performance Events: PEBS fmt3+, Skylake events, 32-deep LBR, full-width counters, Intel PMU driver.
[    0.111401] ... version:                4
[    0.111401] ... bit width:              48
[    0.111401] ... generic registers:      4
[    0.111401] ... value mask:             0000ffffffffffff
[    0.111401] ... max period:             00007fffffffffff
[    0.111401] ... fixed-purpose events:   3
[    0.111401] ... event mask:             000000070000000f
[    0.111401] rcu: Hierarchical SRCU implementation.
[    0.111401] NMI watchdog: Enabled. Permanently consumes one hw-PMU counter.
[    0.111401] smp: Bringing up secondary CPUs ...
[    0.111401] x86: Booting SMP configuration:
[    0.111401] .... node  #0, CPUs:      #1 #2 #3 #4 #5 #6 #7
[    0.112278] smp: Brought up 1 node, 8 CPUs
[    0.112278] smpboot: Max logical packages: 1
[    0.112278] smpboot: Total of 8 processors activated (28800.00 BogoMIPS)
[    0.134393] node 0 deferred pages initialised in 16ms
[    0.134397] devtmpfs: initialized
[    0.134397] x86/mm: Memory block size: 128MB
[    0.135837] PM: Registering ACPI NVS region [mem 0xb798f000-0xb7b8efff] (2097152 bytes)
[    0.135837] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[    0.135837] futex hash table entries: 2048 (order: 5, 131072 bytes, linear)
[    0.135837] pinctrl core: initialized pinctrl subsystem
[    0.135926] NET: Registered protocol family 16
[    0.136066] audit: initializing netlink subsys (disabled)
[    0.136075] audit: type=2000 audit(1657119763.028:1): state=initialized audit_enabled=0 res=1
[    0.136075] thermal_sys: Registered thermal governor 'fair_share'
[    0.136075] thermal_sys: Registered thermal governor 'bang_bang'
[    0.136075] thermal_sys: Registered thermal governor 'step_wise'
[    0.136075] thermal_sys: Registered thermal governor 'user_space'
[    0.136075] thermal_sys: Registered thermal governor 'power_allocator'
[    0.136075] cpuidle: using governor ladder
[    0.136075] cpuidle: using governor menu
[    0.136075] ACPI: bus type PCI registered
[    0.136075] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
[    0.136075] PCI: MMCONFIG for domain 0000 [bus 00-7f] at [mem 0xf0000000-0xf7ffffff] (base 0xf0000000)
[    0.136075] PCI: not using MMCONFIG
[    0.136075] PCI: Using configuration type 1 for base access
[    0.136075] ENERGY_PERF_BIAS: Set to 'normal', was 'performance'
[    0.136465] Kprobes globally optimized
[    0.136473] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
[    0.136473] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[    0.331919] ACPI: Added _OSI(Module Device)
[    0.331919] ACPI: Added _OSI(Processor Device)
[    0.331919] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.331919] ACPI: Added _OSI(Processor Aggregator Device)
[    0.331919] ACPI: Added _OSI(Linux-Dell-Video)
[    0.331919] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio)
[    0.331919] ACPI: Added _OSI(Linux-HPI-Hybrid-Graphics)
[    0.421323] ACPI: 22 ACPI AML tables successfully acquired and loaded
[    0.425561] ACPI: [Firmware Bug]: BIOS _OSI(Linux) query ignored
[    0.501667] ACPI: Dynamic OEM Table Load:
[    0.501692] ACPI: SSDT 0xFFFF981D66CE1C00 0000F4 (v02 PmRef  Cpu0Psd  00003000 INTL 20160527)
[    0.503252] ACPI: \_SB_.PR00: _OSC native thermal LVT Acked
[    0.504122] ACPI BIOS Error (bug): AE_AML_BUFFER_LIMIT, Field [CAP1] at bit offset/length 64/32 exceeds size of target Buffer (64 bits) (20200925/dsopcode-198)
[    0.504133] ACPI Error: Aborting method \_SB._OSC due to previous error (AE_AML_BUFFER_LIMIT) (20200925/psparse-529)
[    0.504734] ACPI: Dynamic OEM Table Load:
[    0.504748] ACPI: SSDT 0xFFFF981CC0E5B800 000400 (v02 PmRef  Cpu0Cst  00003001 INTL 20160527)
[    0.506444] ACPI: Dynamic OEM Table Load:
[    0.506458] ACPI: SSDT 0xFFFF981CC0BE2800 0004FD (v02 PmRef  Cpu0Ist  00003000 INTL 20160527)
[    0.508640] ACPI: Dynamic OEM Table Load:
[    0.508655] ACPI: SSDT 0xFFFF981CC0BE0000 0005FC (v02 PmRef  ApIst    00003000 INTL 20160527)
[    0.510536] ACPI: Dynamic OEM Table Load:
[    0.510551] ACPI: SSDT 0xFFFF981D66D75000 000AB0 (v02 PmRef  ApPsd    00003000 INTL 20160527)
[    0.513163] ACPI: Dynamic OEM Table Load:
[    0.513176] ACPI: SSDT 0xFFFF981CC0E59C00 00030A (v02 PmRef  ApCst    00003000 INTL 20160527)
[    0.518877] ACPI: EC: EC started
[    0.518879] ACPI: EC: interrupt blocked
[    0.535873] ACPI: EC: EC_CMD/EC_SC=0x66, EC_DATA=0x62
[    0.535876] ACPI: \_SB_.PCI0.LPCB.EC0_: Boot DSDT EC used to handle transactions
[    0.535877] ACPI: Interpreter enabled
[    0.535990] ACPI: (supports S0 S3 S4 S5)
[    0.535992] ACPI: Using IOAPIC for interrupt routing
[    0.536066] PCI: MMCONFIG for domain 0000 [bus 00-7f] at [mem 0xf0000000-0xf7ffffff] (base 0xf0000000)
[    0.540452] PCI: MMCONFIG at [mem 0xf0000000-0xf7ffffff] reserved in ACPI motherboard resources
[    0.540465] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    0.541432] ACPI: Enabled 8 GPEs in block 00 to 7F
[    0.551089] ACPI: Power Resource [USBC] (on)
[    0.553244] ACPI: Power Resource [PXP] (off)
[    0.556226] ACPI: Power Resource [PXP] (on)
[    0.561799] ACPI: Power Resource [WRST] (on)
[    0.570140] ACPI: Power Resource [V0PR] (on)
[    0.570402] ACPI: Power Resource [V1PR] (on)
[    0.570659] ACPI: Power Resource [V2PR] (on)
[    0.579351] ACPI: Power Resource [WRST] (on)
[    0.581868] ACPI: Power Resource [PIN] (off)
[    0.583370] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-7e])
[    0.583378] acpi PNP0A08:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]
[    0.584844] acpi PNP0A08:00: _OSC: platform does not support [AER]
[    0.587328] acpi PNP0A08:00: _OSC: OS now controls [PCIeHotplug SHPCHotplug PME PCIeCapability LTR]
[    0.591461] PCI host bridge to bus 0000:00
[    0.591464] pci_bus 0000:00: root bus resource [io  0x0000-0x0cf7 window]
[    0.591466] pci_bus 0000:00: root bus resource [io  0x0d00-0xffff window]
[    0.591467] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
[    0.591469] pci_bus 0000:00: root bus resource [mem 0xbe800000-0xefffffff window]
[    0.591470] pci_bus 0000:00: root bus resource [mem 0x4000000000-0x7fffffffff window]
[    0.591471] pci_bus 0000:00: root bus resource [mem 0xfc800000-0xfe7fffff window]
[    0.591473] pci_bus 0000:00: root bus resource [bus 00-7e]
[    0.591496] pci 0000:00:00.0: [8086:3e34] type 00 class 0x060000
[    0.593106] pci 0000:00:02.0: [8086:3ea0] type 00 class 0x030000
[    0.593118] pci 0000:00:02.0: reg 0x10: [mem 0xe7000000-0xe7ffffff 64bit]
[    0.593126] pci 0000:00:02.0: reg 0x18: [mem 0xc0000000-0xcfffffff 64bit pref]
[    0.593131] pci 0000:00:02.0: reg 0x20: [io  0x3000-0x303f]
[    0.593154] pci 0000:00:02.0: BAR 2: assigned to efifb
[    0.594782] pci 0000:00:04.0: [8086:1903] type 00 class 0x118000
[    0.594794] pci 0000:00:04.0: reg 0x10: [mem 0x4022100000-0x4022107fff 64bit]
[    0.596551] pci 0000:00:12.0: [8086:9df9] type 00 class 0x118000
[    0.596570] pci 0000:00:12.0: reg 0x10: [mem 0x4022113000-0x4022113fff 64bit]
[    0.598231] pci 0000:00:13.0: [8086:9dfc] type 00 class 0x070000
[    0.598252] pci 0000:00:13.0: reg 0x10: [mem 0x402210c000-0x402210dfff 64bit]
[    0.598325] pci 0000:00:13.0: PME# supported from D0 D3hot
[    0.600047] pci 0000:00:14.0: [8086:9ded] type 00 class 0x0c0330
[    0.600064] pci 0000:00:14.0: reg 0x10: [mem 0xe8220000-0xe822ffff 64bit]
[    0.600127] pci 0000:00:14.0: PME# supported from D3hot D3cold
[    0.601832] pci 0000:00:14.2: [8086:9def] type 00 class 0x050000
[    0.601851] pci 0000:00:14.2: reg 0x10: [mem 0xe8230000-0xe8231fff 64bit]
[    0.601864] pci 0000:00:14.2: reg 0x18: [mem 0x4022112000-0x4022112fff 64bit]
[    0.603593] pci 0000:00:15.0: [8086:9de8] type 00 class 0x0c8000
[    0.603682] pci 0000:00:15.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
[    0.605748] pci 0000:00:15.1: [8086:9de9] type 00 class 0x0c8000
[    0.605837] pci 0000:00:15.1: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
[    0.607845] pci 0000:00:16.0: [8086:9de0] type 00 class 0x078000
[    0.607868] pci 0000:00:16.0: reg 0x10: [mem 0x402210f000-0x402210ffff 64bit]
[    0.607961] pci 0000:00:16.0: PME# supported from D3hot
[    0.609717] pci 0000:00:1c.0: [8086:9dbc] type 01 class 0x060400
[    0.611340] pci 0000:00:1c.0: PME# supported from D0 D3hot D3cold
[    0.611372] pci 0000:00:1c.0: PTM enabled (root), 4ns granularity
[    0.611609] pci 0000:00:1c.7: [8086:9dbf] type 01 class 0x060400
[    0.611712] pci 0000:00:1c.7: PME# supported from D0 D3hot D3cold
[    0.611743] pci 0000:00:1c.7: PTM enabled (root), 4ns granularity
[    0.613449] pci 0000:00:1d.0: [8086:9db4] type 01 class 0x060400
[    0.613541] pci 0000:00:1d.0: PME# supported from D0 D3hot D3cold
[    0.613568] pci 0000:00:1d.0: PTM enabled (root), 4ns granularity
[    0.615314] pci 0000:00:1f.0: [8086:9d84] type 00 class 0x060100
[    0.617076] pci 0000:00:1f.3: [8086:9dc8] type 00 class 0x040100
[    0.617127] pci 0000:00:1f.3: reg 0x10: [mem 0x4022108000-0x402210bfff 64bit]
[    0.617191] pci 0000:00:1f.3: reg 0x20: [mem 0x4022000000-0x40220fffff 64bit]
[    0.617323] pci 0000:00:1f.3: PME# supported from D3hot D3cold
[    0.619198] pci 0000:00:1f.4: [8086:9da3] type 00 class 0x0c0500
[    0.619223] pci 0000:00:1f.4: reg 0x10: [mem 0x402210e000-0x402210e0ff 64bit]
[    0.619248] pci 0000:00:1f.4: reg 0x20: [io  0xefa0-0xefbf]
[    0.620923] pci 0000:00:1f.5: [8086:9da4] type 00 class 0x0c8000
[    0.620940] pci 0000:00:1f.5: reg 0x10: [mem 0xfe010000-0xfe010fff]
[    0.622591] pci 0000:00:1f.6: [8086:15be] type 00 class 0x020000
[    0.622628] pci 0000:00:1f.6: reg 0x10: [mem 0xe8200000-0xe821ffff]
[    0.622826] pci 0000:00:1f.6: PME# supported from D0 D3hot D3cold
[    0.624639] pci 0000:01:00.0: [8086:15e7] type 01 class 0x060400
[    0.624697] pci 0000:01:00.0: enabling Extended Tags
[    0.624812] pci 0000:01:00.0: supports D1 D2
[    0.624813] pci 0000:01:00.0: PME# supported from D0 D1 D2 D3hot D3cold
[    0.624903] pci 0000:01:00.0: PTM enabled, 4ns granularity
[    0.624926] pci 0000:01:00.0: 15.752 Gb/s available PCIe bandwidth, limited by 8.0 GT/s PCIe x2 link at 0000:00:1c.0 (capable of 31.504 Gb/s with 8.0 GT/s PCIe x4 link)
[    0.625023] pci 0000:00:1c.0: PCI bridge to [bus 01-39]
[    0.625028] pci 0000:00:1c.0:   bridge window [mem 0xd0000000-0xe60fffff]
[    0.625033] pci 0000:00:1c.0:   bridge window [mem 0x4000000000-0x4021ffffff 64bit pref]
[    0.625118] pci 0000:02:00.0: [8086:15e7] type 01 class 0x060400
[    0.625179] pci 0000:02:00.0: enabling Extended Tags
[    0.625297] pci 0000:02:00.0: supports D1 D2
[    0.625298] pci 0000:02:00.0: PME# supported from D0 D1 D2 D3hot D3cold
[    0.625446] pci 0000:02:01.0: [8086:15e7] type 01 class 0x060400
[    0.625506] pci 0000:02:01.0: enabling Extended Tags
[    0.625622] pci 0000:02:01.0: supports D1 D2
[    0.625623] pci 0000:02:01.0: PME# supported from D0 D1 D2 D3hot D3cold
[    0.625770] pci 0000:02:02.0: [8086:15e7] type 01 class 0x060400
[    0.625831] pci 0000:02:02.0: enabling Extended Tags
[    0.625944] pci 0000:02:02.0: supports D1 D2
[    0.625945] pci 0000:02:02.0: PME# supported from D0 D1 D2 D3hot D3cold
[    0.626124] pci 0000:01:00.0: PCI bridge to [bus 02-39]
[    0.626134] pci 0000:01:00.0:   bridge window [mem 0xd0000000-0xe60fffff]
[    0.626141] pci 0000:01:00.0:   bridge window [mem 0x4000000000-0x4021ffffff 64bit pref]
[    0.626219] pci 0000:03:00.0: [8086:15e8] type 00 class 0x088000
[    0.626242] pci 0000:03:00.0: reg 0x10: [mem 0xe6000000-0xe603ffff]
[    0.626255] pci 0000:03:00.0: reg 0x14: [mem 0xe6040000-0xe6040fff]
[    0.626321] pci 0000:03:00.0: enabling Extended Tags
[    0.626444] pci 0000:03:00.0: supports D1 D2
[    0.626446] pci 0000:03:00.0: PME# supported from D0 D1 D2 D3hot D3cold
[    0.626595] pci 0000:02:00.0: PCI bridge to [bus 03]
[    0.626604] pci 0000:02:00.0:   bridge window [mem 0xe6000000-0xe60fffff]
[    0.626772] pci 0000:04:00.0: [8086:15ef] type 01 class 0x060400
[    0.626883] pci 0000:04:00.0: enabling Extended Tags
[    0.627110] pci 0000:04:00.0: supports D1 D2
[    0.627111] pci 0000:04:00.0: PME# supported from D0 D1 D2 D3hot D3cold
[    0.627277] pci 0000:04:00.0: PTM enabled, 4ns granularity
[    0.627323] pci 0000:04:00.0: 8.000 Gb/s available PCIe bandwidth, limited by 2.5 GT/s PCIe x4 link at 0000:02:01.0 (capable of 31.504 Gb/s with 8.0 GT/s PCIe x4 link)
[    0.639429] pci 0000:02:01.0: PCI bridge to [bus 04-38]
[    0.639438] pci 0000:02:01.0:   bridge window [mem 0xd0000000-0xe5efffff]
[    0.639446] pci 0000:02:01.0:   bridge window [mem 0x4000000000-0x4021ffffff 64bit pref]
[    0.639589] pci 0000:05:02.0: [8086:15ef] type 01 class 0x060400
[    0.639706] pci 0000:05:02.0: enabling Extended Tags
[    0.639928] pci 0000:05:02.0: supports D1 D2
[    0.639929] pci 0000:05:02.0: PME# supported from D0 D1 D2 D3hot D3cold
[    0.640193] pci 0000:05:04.0: [8086:15ef] type 01 class 0x060400
[    0.640309] pci 0000:05:04.0: enabling Extended Tags
[    0.640536] pci 0000:05:04.0: supports D1 D2
[    0.640537] pci 0000:05:04.0: PME# supported from D0 D1 D2 D3hot D3cold
[    0.640814] pci 0000:04:00.0: PCI bridge to [bus 05-38]
[    0.640831] pci 0000:04:00.0:   bridge window [mem 0xd0000000-0xe5efffff]
[    0.640843] pci 0000:04:00.0:   bridge window [mem 0x4000000000-0x4021ffffff 64bit pref]
[    0.640980] pci 0000:06:00.0: [8086:15ec] type 00 class 0x0c0330
[    0.641020] pci 0000:06:00.0: reg 0x10: [mem 0xd0000000-0xd000ffff]
[    0.641163] pci 0000:06:00.0: enabling Extended Tags
[    0.641390] pci 0000:06:00.0: supports D1 D2
[    0.641392] pci 0000:06:00.0: PME# supported from D0 D1 D2 D3hot D3cold
[    0.641579] pci 0000:06:00.0: 8.000 Gb/s available PCIe bandwidth, limited by 2.5 GT/s PCIe x4 link at 0000:02:01.0 (capable of 31.504 Gb/s with 8.0 GT/s PCIe x4 link)
[    0.641693] pci 0000:05:02.0: PCI bridge to [bus 06]
[    0.641709] pci 0000:05:02.0:   bridge window [mem 0xd0000000-0xd00fffff]
[    0.641805] pci 0000:05:04.0: PCI bridge to [bus 07-38]
[    0.641822] pci 0000:05:04.0:   bridge window [mem 0xd0100000-0xe5efffff]
[    0.641834] pci 0000:05:04.0:   bridge window [mem 0x4000000000-0x4021ffffff 64bit pref]
[    0.641965] pci 0000:39:00.0: [8086:15e9] type 00 class 0x0c0330
[    0.641990] pci 0000:39:00.0: reg 0x10: [mem 0xe5f00000-0xe5f0ffff]
[    0.642074] pci 0000:39:00.0: enabling Extended Tags
[    0.642208] pci 0000:39:00.0: supports D1 D2
[    0.642209] pci 0000:39:00.0: PME# supported from D0 D1 D2 D3hot D3cold
[    0.642312] pci 0000:39:00.0: 8.000 Gb/s available PCIe bandwidth, limited by 2.5 GT/s PCIe x4 link at 0000:02:02.0 (capable of 31.504 Gb/s with 8.0 GT/s PCIe x4 link)
[    0.642401] pci 0000:02:02.0: PCI bridge to [bus 39]
[    0.642410] pci 0000:02:02.0:   bridge window [mem 0xe5f00000-0xe5ffffff]
[    0.642664] pci 0000:3a:00.0: [8086:2723] type 00 class 0x028000
[    0.642737] pci 0000:3a:00.0: reg 0x10: [mem 0xe8100000-0xe8103fff 64bit]
[    0.643082] pci 0000:3a:00.0: PME# supported from D0 D3hot D3cold
[    0.647751] pci 0000:00:1c.7: PCI bridge to [bus 3a]
[    0.647756] pci 0000:00:1c.7:   bridge window [mem 0xe8100000-0xe81fffff]
[    0.647830] pci 0000:3b:00.0: [15b7:5003] type 00 class 0x010802
[    0.647854] pci 0000:3b:00.0: reg 0x10: [mem 0xe8000000-0xe8003fff 64bit]
[    0.648122] pci 0000:00:1d.0: PCI bridge to [bus 3b]
[    0.648126] pci 0000:00:1d.0:   bridge window [mem 0xe8000000-0xe80fffff]
[    0.654514] ACPI: EC: interrupt unblocked
[    0.654516] ACPI: EC: event unblocked
[    0.654533] ACPI: EC: EC_CMD/EC_SC=0x66, EC_DATA=0x62
[    0.654534] ACPI: EC: GPE=0x6e
[    0.654537] ACPI: \_SB_.PCI0.LPCB.EC0_: Boot DSDT EC initialization complete
[    0.654538] ACPI: \_SB_.PCI0.LPCB.EC0_: EC: Used to handle transactions and events
[    0.654614] iommu: Default domain type: Translated 
[    0.654631] pci 0000:00:02.0: vgaarb: setting as boot VGA device
[    0.654631] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
[    0.654631] pci 0000:00:02.0: vgaarb: bridge control possible
[    0.654631] vgaarb: loaded
[    0.654631] EDAC MC: Ver: 3.0.0
[    0.654631] Registered efivars operations
[    0.654631] NetLabel: Initializing
[    0.654631] NetLabel:  domain hash size = 128
[    0.654631] NetLabel:  protocols = UNLABELED CIPSOv4 CALIPSO
[    0.654631] NetLabel:  unlabeled traffic allowed by default
[    0.654631] PCI: Using ACPI for IRQ routing
[    0.667566] PCI: pci_cache_line_size set to 64 bytes
[    0.667974] e820: reserve RAM buffer [mem 0x0009f000-0x0009ffff]
[    0.667975] e820: reserve RAM buffer [mem 0xb2194000-0xb3ffffff]
[    0.667977] e820: reserve RAM buffer [mem 0xb2849000-0xb3ffffff]
[    0.667978] e820: reserve RAM buffer [mem 0xb66ab000-0xb7ffffff]
[    0.667979] e820: reserve RAM buffer [mem 0xb7c10000-0xb7ffffff]
[    0.667980] e820: reserve RAM buffer [mem 0x23d800000-0x23fffffff]
[    0.671403] clocksource: Switched to clocksource tsc-early
[    0.683275] VFS: Disk quotas dquot_6.6.0
[    0.683296] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.683436] AppArmor: AppArmor Filesystem Enabled
[    0.683456] pnp: PnP ACPI init
[    0.683635] system 00:00: [mem 0x40000000-0x403fffff] could not be reserved
[    0.683645] system 00:00: Plug and Play ACPI device, IDs PNP0c02 (active)
[    0.684202] system 00:01: [io  0x1800-0x18fe] has been reserved
[    0.684205] system 00:01: [mem 0xfd000000-0xfd69ffff] has been reserved
[    0.684207] system 00:01: [mem 0xfd6b0000-0xfd6cffff] has been reserved
[    0.684208] system 00:01: [mem 0xfd6f0000-0xfdffffff] has been reserved
[    0.684210] system 00:01: [mem 0xfe000000-0xfe01ffff] could not be reserved
[    0.684212] system 00:01: [mem 0xfe200000-0xfe7fffff] has been reserved
[    0.684213] system 00:01: [mem 0xff000000-0xffffffff] has been reserved
[    0.684218] system 00:01: Plug and Play ACPI device, IDs PNP0c02 (active)
[    0.684764] system 00:02: [io  0x2000-0x20fe] has been reserved
[    0.684768] system 00:02: Plug and Play ACPI device, IDs PNP0c02 (active)
[    0.685002] system 00:03: [io  0x0680-0x069f] has been reserved
[    0.685004] system 00:03: [io  0x164e-0x164f] has been reserved
[    0.685008] system 00:03: Plug and Play ACPI device, IDs PNP0c02 (active)
[    0.685080] pnp 00:04: Plug and Play ACPI device, IDs PNP0b00 (active)
[    0.685226] system 00:05: [io  0x1854-0x1857] has been reserved
[    0.685231] system 00:05: Plug and Play ACPI device, IDs INT3f0d PNP0c02 (active)
[    0.685252] pnp 00:06: Plug and Play ACPI device, IDs HPQ8002 PNP0303 (active)
[    0.685272] pnp 00:07: Plug and Play ACPI device, IDs SYN3091 SYN0100 SYN0002 PNP0f13 (active)
[    0.685350] system 00:08: [io  0x0200-0x027f] has been reserved
[    0.685353] system 00:08: [mem 0xfedf0000-0xfedfffff] has been reserved
[    0.685356] system 00:08: Plug and Play ACPI device, IDs PNP0c02 (active)
[    0.687246] system 00:09: Plug and Play ACPI device, IDs PNP0c02 (active)
[    0.688177] system 00:0a: [mem 0xfed10000-0xfed17fff] has been reserved
[    0.688179] system 00:0a: [mem 0xfed18000-0xfed18fff] has been reserved
[    0.688181] system 00:0a: [mem 0xfed19000-0xfed19fff] has been reserved
[    0.688182] system 00:0a: [mem 0xf0000000-0xf7ffffff] has been reserved
[    0.688184] system 00:0a: [mem 0xfed20000-0xfed3ffff] has been reserved
[    0.688186] system 00:0a: [mem 0xfed90000-0xfed93fff] could not be reserved
[    0.688187] system 00:0a: [mem 0xfed45000-0xfed8ffff] has been reserved
[    0.688189] system 00:0a: [mem 0xfee00000-0xfeefffff] has been reserved
[    0.688193] system 00:0a: Plug and Play ACPI device, IDs PNP0c02 (active)
[    0.688540] pnp: PnP ACPI: found 11 devices
[    0.694581] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[    0.694654] NET: Registered protocol family 2
[    0.694800] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[    0.696355] tcp_listen_portaddr_hash hash table entries: 4096 (order: 4, 65536 bytes, linear)
[    0.696414] TCP established hash table entries: 65536 (order: 7, 524288 bytes, linear)
[    0.696612] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes, linear)
[    0.696710] TCP: Hash tables configured (established 65536 bind 65536)
[    0.696755] UDP hash table entries: 4096 (order: 5, 131072 bytes, linear)
[    0.696786] UDP-Lite hash table entries: 4096 (order: 5, 131072 bytes, linear)
[    0.696840] NET: Registered protocol family 1
[    0.696846] NET: Registered protocol family 44
[    0.696860] pci 0000:05:04.0: bridge window [io  0x1000-0x0fff] to [bus 07-38] add_size 1000
[    0.696862] pci 0000:04:00.0: bridge window [io  0x1000-0x0fff] to [bus 05-38] add_size 1000
[    0.696864] pci 0000:02:01.0: bridge window [io  0x1000-0x0fff] to [bus 04-38] add_size 2000
[    0.696867] pci 0000:01:00.0: bridge window [io  0x1000-0x0fff] to [bus 02-39] add_size 2000
[    0.696869] pci 0000:00:1c.0: bridge window [io  0x1000-0x0fff] to [bus 01-39] add_size 3000
[    0.696880] pci 0000:00:15.0: BAR 0: assigned [mem 0x4022110000-0x4022110fff 64bit]
[    0.696945] pci 0000:00:15.1: BAR 0: assigned [mem 0x4022111000-0x4022111fff 64bit]
[    0.697002] pci 0000:00:1c.0: BAR 13: assigned [io  0x4000-0x6fff]
[    0.697006] pci 0000:01:00.0: BAR 13: assigned [io  0x4000-0x5fff]
[    0.697008] pci 0000:02:01.0: BAR 13: assigned [io  0x4000-0x5fff]
[    0.697011] pci 0000:02:00.0: PCI bridge to [bus 03]
[    0.697018] pci 0000:02:00.0:   bridge window [mem 0xe6000000-0xe60fffff]
[    0.697028] pci 0000:04:00.0: BAR 13: assigned [io  0x4000-0x4fff]
[    0.697031] pci 0000:05:04.0: BAR 13: assigned [io  0x4000-0x4fff]
[    0.697035] pci 0000:05:02.0: PCI bridge to [bus 06]
[    0.697047] pci 0000:05:02.0:   bridge window [mem 0xd0000000-0xd00fffff]
[    0.697064] pci 0000:05:04.0: PCI bridge to [bus 07-38]
[    0.697068] pci 0000:05:04.0:   bridge window [io  0x4000-0x4fff]
[    0.697077] pci 0000:05:04.0:   bridge window [mem 0xd0100000-0xe5efffff]
[    0.697083] pci 0000:05:04.0:   bridge window [mem 0x4000000000-0x4021ffffff 64bit pref]
[    0.697095] pci 0000:04:00.0: PCI bridge to [bus 05-38]
[    0.697099] pci 0000:04:00.0:   bridge window [io  0x4000-0x4fff]
[    0.697108] pci 0000:04:00.0:   bridge window [mem 0xd0000000-0xe5efffff]
[    0.697114] pci 0000:04:00.0:   bridge window [mem 0x4000000000-0x4021ffffff 64bit pref]
[    0.697125] pci 0000:02:01.0: PCI bridge to [bus 04-38]
[    0.697128] pci 0000:02:01.0:   bridge window [io  0x4000-0x5fff]
[    0.697133] pci 0000:02:01.0:   bridge window [mem 0xd0000000-0xe5efffff]
[    0.697137] pci 0000:02:01.0:   bridge window [mem 0x4000000000-0x4021ffffff 64bit pref]
[    0.697144] pci 0000:02:02.0: PCI bridge to [bus 39]
[    0.697149] pci 0000:02:02.0:   bridge window [mem 0xe5f00000-0xe5ffffff]
[    0.697159] pci 0000:01:00.0: PCI bridge to [bus 02-39]
[    0.697161] pci 0000:01:00.0:   bridge window [io  0x4000-0x5fff]
[    0.697167] pci 0000:01:00.0:   bridge window [mem 0xd0000000-0xe60fffff]
[    0.697171] pci 0000:01:00.0:   bridge window [mem 0x4000000000-0x4021ffffff 64bit pref]
[    0.697177] pci 0000:00:1c.0: PCI bridge to [bus 01-39]
[    0.697179] pci 0000:00:1c.0:   bridge window [io  0x4000-0x6fff]
[    0.697183] pci 0000:00:1c.0:   bridge window [mem 0xd0000000-0xe60fffff]
[    0.697186] pci 0000:00:1c.0:   bridge window [mem 0x4000000000-0x4021ffffff 64bit pref]
[    0.697190] pci 0000:00:1c.7: PCI bridge to [bus 3a]
[    0.697194] pci 0000:00:1c.7:   bridge window [mem 0xe8100000-0xe81fffff]
[    0.697201] pci 0000:00:1d.0: PCI bridge to [bus 3b]
[    0.697204] pci 0000:00:1d.0:   bridge window [mem 0xe8000000-0xe80fffff]
[    0.697212] pci_bus 0000:00: resource 4 [io  0x0000-0x0cf7 window]
[    0.697214] pci_bus 0000:00: resource 5 [io  0x0d00-0xffff window]
[    0.697215] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
[    0.697216] pci_bus 0000:00: resource 7 [mem 0xbe800000-0xefffffff window]
[    0.697218] pci_bus 0000:00: resource 8 [mem 0x4000000000-0x7fffffffff window]
[    0.697219] pci_bus 0000:00: resource 9 [mem 0xfc800000-0xfe7fffff window]
[    0.697221] pci_bus 0000:01: resource 0 [io  0x4000-0x6fff]
[    0.697222] pci_bus 0000:01: resource 1 [mem 0xd0000000-0xe60fffff]
[    0.697224] pci_bus 0000:01: resource 2 [mem 0x4000000000-0x4021ffffff 64bit pref]
[    0.697225] pci_bus 0000:02: resource 0 [io  0x4000-0x5fff]
[    0.697226] pci_bus 0000:02: resource 1 [mem 0xd0000000-0xe60fffff]
[    0.697228] pci_bus 0000:02: resource 2 [mem 0x4000000000-0x4021ffffff 64bit pref]
[    0.697229] pci_bus 0000:03: resource 1 [mem 0xe6000000-0xe60fffff]
[    0.697231] pci_bus 0000:04: resource 0 [io  0x4000-0x5fff]
[    0.697232] pci_bus 0000:04: resource 1 [mem 0xd0000000-0xe5efffff]
[    0.697233] pci_bus 0000:04: resource 2 [mem 0x4000000000-0x4021ffffff 64bit pref]
[    0.697235] pci_bus 0000:05: resource 0 [io  0x4000-0x4fff]
[    0.697236] pci_bus 0000:05: resource 1 [mem 0xd0000000-0xe5efffff]
[    0.697237] pci_bus 0000:05: resource 2 [mem 0x4000000000-0x4021ffffff 64bit pref]
[    0.697239] pci_bus 0000:06: resource 1 [mem 0xd0000000-0xd00fffff]
[    0.697240] pci_bus 0000:07: resource 0 [io  0x4000-0x4fff]
[    0.697241] pci_bus 0000:07: resource 1 [mem 0xd0100000-0xe5efffff]
[    0.697243] pci_bus 0000:07: resource 2 [mem 0x4000000000-0x4021ffffff 64bit pref]
[    0.697244] pci_bus 0000:39: resource 1 [mem 0xe5f00000-0xe5ffffff]
[    0.697245] pci_bus 0000:3a: resource 1 [mem 0xe8100000-0xe81fffff]
[    0.697247] pci_bus 0000:3b: resource 1 [mem 0xe8000000-0xe80fffff]
[    0.697412] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
[    0.697431] pci 0000:00:14.0: enabling device (0000 -> 0002)
[    0.699400] PCI: CLS 128 bytes, default 64
[    0.699458] Trying to unpack rootfs image as initramfs...
[    1.620809] Freeing initrd memory: 40832K
[    1.621000] DMAR: No ATSR found
[    1.621083] DMAR: dmar0: Using Queued invalidation
[    1.621087] DMAR: dmar1: Using Queued invalidation
[    1.621548] pci 0000:00:00.0: Adding to iommu group 0
[    1.621562] pci 0000:00:02.0: Adding to iommu group 1
[    1.621573] pci 0000:00:04.0: Adding to iommu group 2
[    1.621596] pci 0000:00:12.0: Adding to iommu group 3
[    1.621608] pci 0000:00:13.0: Adding to iommu group 4
[    1.621630] pci 0000:00:14.0: Adding to iommu group 5
[    1.621641] pci 0000:00:14.2: Adding to iommu group 5
[    1.621664] pci 0000:00:15.0: Adding to iommu group 6
[    1.621676] pci 0000:00:15.1: Adding to iommu group 6
[    1.621692] pci 0000:00:16.0: Adding to iommu group 7
[    1.621709] pci 0000:00:1c.0: Adding to iommu group 8
[    1.621723] pci 0000:00:1c.7: Adding to iommu group 9
[    1.621738] pci 0000:00:1d.0: Adding to iommu group 10
[    1.621777] pci 0000:00:1f.0: Adding to iommu group 11
[    1.621789] pci 0000:00:1f.3: Adding to iommu group 11
[    1.621802] pci 0000:00:1f.4: Adding to iommu group 11
[    1.621817] pci 0000:00:1f.5: Adding to iommu group 11
[    1.621832] pci 0000:00:1f.6: Adding to iommu group 11
[    1.621848] pci 0000:01:00.0: Adding to iommu group 12
[    1.621863] pci 0000:02:00.0: Adding to iommu group 13
[    1.621878] pci 0000:02:01.0: Adding to iommu group 14
[    1.621892] pci 0000:02:02.0: Adding to iommu group 15
[    1.621911] pci 0000:03:00.0: Adding to iommu group 16
[    1.621927] pci 0000:04:00.0: Adding to iommu group 17
[    1.621945] pci 0000:05:02.0: Adding to iommu group 18
[    1.621963] pci 0000:05:04.0: Adding to iommu group 19
[    1.621985] pci 0000:06:00.0: Adding to iommu group 20
[    1.622002] pci 0000:39:00.0: Adding to iommu group 21
[    1.622020] pci 0000:3a:00.0: Adding to iommu group 22
[    1.622034] pci 0000:3b:00.0: Adding to iommu group 23
[    1.625946] DMAR: Intel(R) Virtualization Technology for Directed I/O
[    1.625947] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[    1.625950] software IO TLB: mapped [mem 0x00000000ad67d000-0x00000000b167d000] (64MB)
[    1.626649] Initialise system trusted keyrings
[    1.626658] Key type blacklist registered
[    1.626717] workingset: timestamp_bits=36 max_order=21 bucket_order=0
[    1.628192] zbud: loaded
[    1.628414] integrity: Platform Keyring initialized
[    1.628417] Key type asymmetric registered
[    1.628418] Asymmetric key parser 'x509' registered
[    1.628426] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[    1.628468] io scheduler mq-deadline registered
[    1.631333] pcieport 0000:00:1c.0: PME: Signaling with IRQ 122
[    1.631377] pcieport 0000:00:1c.0: pciehp: Slot #4 AttnBtn- PwrCtrl- MRL- AttnInd- PwrInd- HotPlug+ Surprise+ Interlock- NoCompl+ IbPresDis- LLActRep+
[    1.631828] pcieport 0000:00:1c.7: PME: Signaling with IRQ 123
[    1.632129] pcieport 0000:00:1d.0: PME: Signaling with IRQ 124
[    1.632665] pcieport 0000:02:01.0: pciehp: Slot #1 AttnBtn- PwrCtrl- MRL- AttnInd- PwrInd- HotPlug+ Surprise+ Interlock- NoCompl+ IbPresDis- LLActRep+
[    1.633691] pcieport 0000:05:04.0: pciehp: Slot #4 AttnBtn- PwrCtrl- MRL- AttnInd- PwrInd- HotPlug+ Surprise+ Interlock- NoCompl+ IbPresDis- LLActRep+
[    1.633996] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4
[    1.634015] efifb: probing for efifb
[    1.634031] efifb: framebuffer at 0xc0000000, using 8100k, total 8100k
[    1.634032] efifb: mode is 1920x1080x32, linelength=7680, pages=1
[    1.634033] efifb: scrolling: redraw
[    1.634035] efifb: Truecolor: size=8:8:8:8, shift=24:16:8:0
[    1.634139] Console: switching to colour frame buffer device 240x67
[    1.641520] fb0: EFI VGA frame buffer device
[    1.641530] intel_idle: MWAIT substates: 0x11142120
[    1.641531] intel_idle: v0.5.1 model 0x8E
[    1.642178] intel_idle: Local APIC timer is reliable in all C-states
[    1.643442] thermal LNXTHERM:00: registered as thermal_zone0
[    1.643444] ACPI: Thermal Zone [HEPZ] (30 C)
[    1.651959] thermal LNXTHERM:01: registered as thermal_zone1
[    1.651962] ACPI: Thermal Zone [CPUZ] (38 C)
[    1.660069] thermal LNXTHERM:02: registered as thermal_zone2
[    1.660072] ACPI: Thermal Zone [GFXZ] (0 C)
[    1.664103] thermal LNXTHERM:03: registered as thermal_zone3
[    1.664105] ACPI: Thermal Zone [EXTZ] (34 C)
[    1.667811] thermal LNXTHERM:04: registered as thermal_zone4
[    1.667813] ACPI: Thermal Zone [LOCZ] (32 C)
[    1.675944] thermal LNXTHERM:05: registered as thermal_zone5
[    1.675946] ACPI: Thermal Zone [BATZ] (28 C)
[    1.675989] ACPI BIOS Error (bug): AE_AML_PACKAGE_LIMIT, Index (0x000000005) is beyond end of object (length 0x5) (20200925/exoparg2-393)
[    1.676076] ACPI Error: Aborting method \_TZ.GETP due to previous error (AE_AML_PACKAGE_LIMIT) (20200925/psparse-529)
[    1.676149] ACPI Error: Aborting method \_TZ.CHGZ._CRT due to previous error (AE_AML_PACKAGE_LIMIT) (20200925/psparse-529)
[    1.677519] ACPI BIOS Error (bug): AE_AML_PACKAGE_LIMIT, Index (0x000000005) is beyond end of object (length 0x5) (20200925/exoparg2-393)
[    1.677602] ACPI Error: Aborting method \_TZ.GETP due to previous error (AE_AML_PACKAGE_LIMIT) (20200925/psparse-529)
[    1.677670] ACPI Error: Aborting method \_TZ.CHGZ._CRT due to previous error (AE_AML_PACKAGE_LIMIT) (20200925/psparse-529)
[    1.677742] [Firmware Bug]: No valid trip found
[    1.682343] thermal LNXTHERM:07: registered as thermal_zone6
[    1.682345] ACPI: Thermal Zone [PCHZ] (0 C)
[    1.682658] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    1.683478] serial 0000:00:13.0: enabling device (0000 -> 0002)
[    1.684184] hpet_acpi_add: no address or irqs in _CRS
[    1.684218] Linux agpgart interface v0.103
[    1.684267] AMD-Vi: AMD IOMMUv2 functionality not available on this system - This is not a bug.
[    1.684961] i8042: PNP: PS/2 Controller [PNP0303:PS2K,PNP0f13:PS2M] at 0x60,0x64 irq 1,12
[    1.685738] i8042: Detected active multiplexing controller, rev 1.1
[    1.686050] serio: i8042 KBD port at 0x60,0x64 irq 1
[    1.686055] serio: i8042 AUX0 port at 0x60,0x64 irq 12
[    1.686087] serio: i8042 AUX1 port at 0x60,0x64 irq 12
[    1.686110] serio: i8042 AUX2 port at 0x60,0x64 irq 12
[    1.686134] serio: i8042 AUX3 port at 0x60,0x64 irq 12
[    1.686232] mousedev: PS/2 mouse device common for all mice
[    1.686296] rtc_cmos 00:04: RTC can wake from S4
[    1.707084] rtc_cmos 00:04: registered as rtc0
[    1.707317] rtc_cmos 00:04: setting system clock to 2022-07-06T15:02:45 UTC (1657119765)
[    1.707337] rtc_cmos 00:04: alarms up to one month, y3k, 242 bytes nvram
[    1.707348] intel_pstate: Intel P-state driver initializing
[    1.708020] intel_pstate: HWP enabled
[    1.708366] ledtrig-cpu: registered to indicate activity on CPUs
[    1.708645] NET: Registered protocol family 10
[    1.715876] Segment Routing with IPv6
[    1.715897] mip6: Mobile IPv6
[    1.715898] NET: Registered protocol family 17
[    1.716013] mpls_gso: MPLS GSO support
[    1.716781] microcode: sig=0x806ec, pf=0x80, revision=0xd6
[    1.716993] microcode: Microcode Update Driver: v2.2.
[    1.716996] IPI shorthand broadcast: enabled
[    1.717002] sched_clock: Marking stable (1706020707, 10631944)->(1735832790, -19180139)
[    1.717172] registered taskstats version 1
[    1.717174] Loading compiled-in X.509 certificates
[    1.722678] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
[    1.740560] Loaded X.509 cert 'Debian Secure Boot CA: 6ccece7e4c6c0d1f6149f3dd27dfcc5cbb419ea1'
[    1.740569] Loaded X.509 cert 'Debian Secure Boot Signer 2021 - linux: 4b6ef5abca669825178e052c84667ccbc0531f8c'
[    1.740590] zswap: loaded using pool lzo/zbud
[    1.741036] Key type ._fscrypt registered
[    1.741036] Key type .fscrypt registered
[    1.741037] Key type fscrypt-provisioning registered
[    1.741071] AppArmor: AppArmor sha1 policy hashing enabled
[    1.741960] integrity: Loading X.509 certificate: UEFI:db
[    1.741976] integrity: Loaded X.509 cert 'HP Inc.: HP UEFI Secure Boot DB 2017: d9c01b50cfcae89d3b05345c163aa76e5dd589e7'
[    1.741977] integrity: Loading X.509 certificate: UEFI:db
[    1.742002] integrity: Loaded X.509 cert 'Microsoft Windows Production PCA 2011: a92902398e16c49778cd90f99e4f9ae17c55af53'
[    1.742002] integrity: Loading X.509 certificate: UEFI:db
[    1.742013] integrity: Loaded X.509 cert 'Microsoft Corporation UEFI CA 2011: 13adbf4309bd82709c8cd54f316ed522988a1bd4'
[    1.743288] integrity: Loading X.509 certificate: UEFI:MokListRT (MOKvar table)
[    1.743447] integrity: Loaded X.509 cert 'Debian Secure Boot CA: 6ccece7e4c6c0d1f6149f3dd27dfcc5cbb419ea1'
[    1.744474] Lockdown: swapper/0: hibernation is restricted; see man kernel_lockdown.7
[    1.745243] Freeing unused kernel image (initmem) memory: 2424K
[    1.807726] Write protecting the kernel read-only data: 22528k
[    1.808646] Freeing unused kernel image (text/rodata gap) memory: 2040K
[    1.808981] Freeing unused kernel image (rodata/data gap) memory: 628K
[    1.822096] x86/mm: Checked W+X mappings: passed, no W+X pages found.
[    1.822101] Run /init as init process
[    1.822102]   with arguments:
[    1.822103]     /init
[    1.822103]   with environment:
[    1.822104]     HOME=/
[    1.822104]     TERM=linux
[    1.822105]     BOOT_IMAGE=/boot/vmlinuz-5.10.0-15-amd64
[    1.860652] input: Sleep Button as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0E:00/input/input5
[    1.860685] ACPI: Sleep Button [SLPB]
[    1.860736] input: Lid Switch as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0D:00/input/input6
[    1.860758] ACPI: Lid Switch [LID]
[    1.860793] input: Power Button as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0C:00/input/input7
[    1.860813] ACPI: Power Button [PWRB]
[    1.860860] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input8
[    1.871794] acpi PNP0C14:01: duplicate WMI GUID 05901221-D566-11D1-B2F0-00A0C9062910 (first instance was on PNP0C14:00)
[    1.871865] acpi PNP0C14:02: duplicate WMI GUID 05901221-D566-11D1-B2F0-00A0C9062910 (first instance was on PNP0C14:00)
[    1.876242] hid: raw HID events driver (C) Jiri Kosina
[    1.877152] ACPI: Power Button [PWRF]
[    1.879029] pps_core: LinuxPPS API ver. 1 registered
[    1.879030] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    1.886174] ACPI: bus type USB registered
[    1.886193] usbcore: registered new interface driver usbfs
[    1.886200] usbcore: registered new interface driver hub
[    1.886211] usbcore: registered new device driver usb
[    1.889601] battery: ACPI: Battery Slot [BAT0] (battery present)
[    1.890919] intel-lpss 0000:00:15.0: enabling device (0000 -> 0002)
[    1.890955] PTP clock support registered
[    1.891206] idma64 idma64.0: Found Intel integrated DMA 64-bit
[    1.891662] i801_smbus 0000:00:1f.4: enabling device (0000 -> 0003)
[    1.893118] i801_smbus 0000:00:1f.4: SPD Write Disable is set
[    1.893168] i801_smbus 0000:00:1f.4: SMBus using PCI interrupt
[    1.902462] i2c i2c-0: 1/2 memory slots populated (from DMI)
[    1.902888] i2c i2c-0: Successfully instantiated SPD at 0x50
[    1.903291] xhci_hcd 0000:00:14.0: xHCI Host Controller
[    1.903297] xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 1
[    1.904126] e1000e: Intel(R) PRO/1000 Network Driver
[    1.904127] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
[    1.904154] e1000e 0000:00:1f.6: enabling device (0000 -> 0002)
[    1.904485] xhci_hcd 0000:00:14.0: hcc params 0x200077c1 hci version 0x110 quirks 0x0000000000009810
[    1.904490] xhci_hcd 0000:00:14.0: cache line size of 128 is not supported
[    1.904698] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10
[    1.904700] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.904701] usb usb1: Product: xHCI Host Controller
[    1.904702] usb usb1: Manufacturer: Linux 5.10.0-15-amd64 xhci-hcd
[    1.904702] usb usb1: SerialNumber: 0000:00:14.0
[    1.906418] hub 1-0:1.0: USB hub found
[    1.906440] hub 1-0:1.0: 12 ports detected
[    1.906473] e1000e 0000:00:1f.6: Interrupt Throttling Rate (ints/sec) set to dynamic conservative mode
[    1.909011] xhci_hcd 0000:00:14.0: xHCI Host Controller
[    1.909014] xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 2
[    1.909018] xhci_hcd 0000:00:14.0: Host supports USB 3.1 Enhanced SuperSpeed
[    1.909107] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.10
[    1.909107] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.909108] usb usb2: Product: xHCI Host Controller
[    1.909109] usb usb2: Manufacturer: Linux 5.10.0-15-amd64 xhci-hcd
[    1.909109] usb usb2: SerialNumber: 0000:00:14.0
[    1.909233] intel-lpss 0000:00:15.1: enabling device (0000 -> 0002)
[    1.909285] hub 2-0:1.0: USB hub found
[    1.909295] hub 2-0:1.0: 6 ports detected
[    1.909473] idma64 idma64.1: Found Intel integrated DMA 64-bit
[    1.909548] usb: port power management may be unreliable
[    1.910328] xhci_hcd 0000:06:00.0: xHCI Host Controller
[    1.910331] xhci_hcd 0000:06:00.0: new USB bus registered, assigned bus number 3
[    1.911585] xhci_hcd 0000:06:00.0: hcc params 0x200077c1 hci version 0x110 quirks 0x0000000200009810
[    1.911848] usb usb3: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10
[    1.911849] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.911850] usb usb3: Product: xHCI Host Controller
[    1.911851] usb usb3: Manufacturer: Linux 5.10.0-15-amd64 xhci-hcd
[    1.911851] usb usb3: SerialNumber: 0000:06:00.0
[    1.911909] hub 3-0:1.0: USB hub found
[    1.911919] hub 3-0:1.0: 2 ports detected
[    1.912129] xhci_hcd 0000:06:00.0: xHCI Host Controller
[    1.912131] xhci_hcd 0000:06:00.0: new USB bus registered, assigned bus number 4
[    1.912133] xhci_hcd 0000:06:00.0: Host supports USB 3.1 Enhanced SuperSpeed
[    1.912159] usb usb4: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.10
[    1.912160] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.912161] usb usb4: Product: xHCI Host Controller
[    1.912161] usb usb4: Manufacturer: Linux 5.10.0-15-amd64 xhci-hcd
[    1.912162] usb usb4: SerialNumber: 0000:06:00.0
[    1.912212] hub 4-0:1.0: USB hub found
[    1.912222] hub 4-0:1.0: 2 ports detected
[    1.912599] xhci_hcd 0000:39:00.0: xHCI Host Controller
[    1.912603] xhci_hcd 0000:39:00.0: new USB bus registered, assigned bus number 5
[    1.913768] xhci_hcd 0000:39:00.0: hcc params 0x200077c1 hci version 0x110 quirks 0x0000000200009810
[    1.913933] usb usb5: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10
[    1.913934] usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.913934] usb usb5: Product: xHCI Host Controller
[    1.913935] usb usb5: Manufacturer: Linux 5.10.0-15-amd64 xhci-hcd
[    1.913936] usb usb5: SerialNumber: 0000:39:00.0
[    1.914024] hub 5-0:1.0: USB hub found
[    1.914032] hub 5-0:1.0: 2 ports detected
[    1.914447] xhci_hcd 0000:39:00.0: xHCI Host Controller
[    1.914448] xhci_hcd 0000:39:00.0: new USB bus registered, assigned bus number 6
[    1.914450] xhci_hcd 0000:39:00.0: Host supports USB 3.1 Enhanced SuperSpeed
[    1.914472] usb usb6: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.10
[    1.914473] usb usb6: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.914474] usb usb6: Product: xHCI Host Controller
[    1.914474] usb usb6: Manufacturer: Linux 5.10.0-15-amd64 xhci-hcd
[    1.914475] usb usb6: SerialNumber: 0000:39:00.0
[    1.914545] hub 6-0:1.0: USB hub found
[    1.914553] hub 6-0:1.0: 2 ports detected
[    1.916794] i2c_hid i2c-SYNA3091:00: supply vdd not found, using dummy regulator
[    1.916822] i2c_hid i2c-SYNA3091:00: supply vddl not found, using dummy regulator
[    1.917220] nvme nvme0: pci function 0000:3b:00.0
[    1.925035] nvme nvme0: 8/0/0 default/read/poll queues
[    1.927366]  nvme0n1: p1 p2 p3
[    1.974452] i915 0000:00:02.0: [drm] VT-d active for gfx access
[    1.974454] checking generic (c0000000 7e9000) vs hw (e7000000 1000000)
[    1.974455] checking generic (c0000000 7e9000) vs hw (c0000000 10000000)
[    1.974455] fb0: switching to inteldrmfb from EFI VGA
[    1.974532] Console: switching to colour dummy device 80x25
[    1.974560] i915 0000:00:02.0: vgaarb: deactivate vga console
[    1.976787] i915 0000:00:02.0: vgaarb: changed VGA decodes: olddecodes=io+mem,decodes=io+mem:owns=io+mem
[    1.976814] i915 0000:00:02.0: firmware: failed to load i915/kbl_dmc_ver1_04.bin (-2)
[    1.976817] firmware_class: See https://wiki.debian.org/Firmware for information about missing firmware
[    1.976819] i915 0000:00:02.0: Direct firmware load for i915/kbl_dmc_ver1_04.bin failed with error -2
[    1.976820] i915 0000:00:02.0: [drm] Failed to load DMC firmware i915/kbl_dmc_ver1_04.bin. Disabling runtime power management.
[    1.976821] i915 0000:00:02.0: [drm] DMC firmware homepage: https://git.kernel.org/pub/scm/linux/kernel/git/firmware/linux-firmware.git/tree/i915
[    2.073970] input: SYNA3091:00 06CB:82F5 Mouse as /devices/pci0000:00/0000:00:15.1/i2c_designware.1/i2c-2/i2c-SYNA3091:00/0018:06CB:82F5.0001/input/input11
[    2.074085] input: SYNA3091:00 06CB:82F5 Touchpad as /devices/pci0000:00/0000:00:15.1/i2c_designware.1/i2c-2/i2c-SYNA3091:00/0018:06CB:82F5.0001/input/input12
[    2.074169] hid-generic 0018:06CB:82F5.0001: input,hidraw0: I2C HID v1.00 Mouse [SYNA3091:00 06CB:82F5] on i2c-SYNA3091:00
[    2.095689] e1000e 0000:00:1f.6 0000:00:1f.6 (uninitialized): registered PHC clock
[    2.163483] usb 1-1: new full-speed USB device number 2 using xhci_hcd
[    2.163586] e1000e 0000:00:1f.6 eth0: (PCI Express:2.5GT/s:Width x1) 30:24:a9:43:83:c7
[    2.163589] e1000e 0000:00:1f.6 eth0: Intel(R) PRO/1000 Network Connection
[    2.163688] e1000e 0000:00:1f.6 eth0: MAC: 13, PHY: 12, PBA No: FFFFFF-0FF
[    2.165119] e1000e 0000:00:1f.6 enp0s31f6: renamed from eth0
[    2.175438] usb 3-1: new high-speed USB device number 2 using xhci_hcd
[    2.321569] usb 1-1: New USB device found, idVendor=2008, idProduct=1004, bcdDevice= 0.01
[    2.321573] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    2.321575] usb 1-1: Product: USBPro5121348013492KH+
[    2.321577] usb 1-1: Manufacturer: ThingMagic, Inc.
[    2.326460] usb 3-1: New USB device found, idVendor=2109, idProduct=2820, bcdDevice=70.13
[    2.326463] usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    2.326467] usb 3-1: Product: USB2.0 Hub             
[    2.326469] usb 3-1: Manufacturer: VIA Labs, Inc.         
[    2.327696] hub 3-1:1.0: USB hub found
[    2.327967] hub 3-1:1.0: 5 ports detected
[    2.447418] usb 1-8: new full-speed USB device number 3 using xhci_hcd
[    2.459590] usb 4-1: new SuperSpeedPlus Gen 2 USB device number 2 using xhci_hcd
[    2.482428] usb 4-1: New USB device found, idVendor=2109, idProduct=0820, bcdDevice=70.13
[    2.482431] usb 4-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    2.482433] usb 4-1: Product: USB3.1 Hub             
[    2.482434] usb 4-1: Manufacturer: VIA Labs, Inc.         
[    2.485534] hub 4-1:1.0: USB hub found
[    2.485851] hub 4-1:1.0: 4 ports detected
[    2.508562] ish-hid {33AECD58-B679-4E54-9BD9-A04D34F0C226}: [hid-ish]: enum_devices_done OK, num_hid_devices=1
[    2.510127] hid-generic 001F:8087:0AC2.0002: hidraw1: <UNKNOWN> HID v2.00 Device [hid-ishtp 8087:0AC2] on 
[    2.597093] usb 1-8: New USB device found, idVendor=06cb, idProduct=00b7, bcdDevice= 1.64
[    2.597098] usb 1-8: New USB device strings: Mfr=0, Product=0, SerialNumber=1
[    2.597100] usb 1-8: SerialNumber: 2d039c86e4cd
[    2.631472] tsc: Refined TSC clocksource calibration: 1800.000 MHz
[    2.631482] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x19f2297dd97, max_idle_ns: 440795236593 ns
[    2.631551] clocksource: Switched to clocksource tsc
[    2.667283] thunderbolt 0-1: new device found, vendor=0xf0 device=0x467
[    2.667286] thunderbolt 0-1: HP Thunderbolt Dock G2
[    2.723540] usb 1-9: new high-speed USB device number 4 using xhci_hcd
[    2.808763] input: PS/2 Generic Mouse as /devices/platform/i8042/serio2/input/input10
[    2.920774] usb 1-9: New USB device found, idVendor=0408, idProduct=5343, bcdDevice= 0.11
[    2.920779] usb 1-9: New USB device strings: Mfr=3, Product=1, SerialNumber=2
[    2.920781] usb 1-9: Product: HP HD Camera
[    2.920784] usb 1-9: Manufacturer: Quanta
[    2.920785] usb 1-9: SerialNumber: 0x0001
[    3.051610] usb 1-10: new full-speed USB device number 5 using xhci_hcd
[    3.059517] usb 3-1.3: new high-speed USB device number 3 using xhci_hcd
[    3.139544] [drm] Initialized i915 1.6.0 20200917 for 0000:00:02.0 on minor 0
[    3.147349] ACPI: Video Device [GFX0] (multi-head: yes  rom: no  post: no)
[    3.147640] input: Video Bus as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:00/LNXVIDEO:00/input/input15
[    3.161507] fbcon: i915drmfb (fb0) is primary device
[    3.206153] usb 1-10: New USB device found, idVendor=8087, idProduct=0029, bcdDevice= 0.01
[    3.206157] usb 1-10: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    3.217016] usb 3-1.3: New USB device found, idVendor=0424, idProduct=2807, bcdDevice= 2.04
[    3.217020] usb 3-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    3.217022] usb 3-1.3: Product: USB2807 Hub
[    3.217024] usb 3-1.3: Manufacturer: Microchip
[    3.218871] hub 3-1.3:1.0: USB hub found
[    3.218988] hub 3-1.3:1.0: 7 ports detected
[    3.295679] usb 4-1.3: new SuperSpeed Gen 1 USB device number 3 using xhci_hcd
[    3.320714] usb 4-1.3: New USB device found, idVendor=0424, idProduct=5807, bcdDevice= 2.04
[    3.320718] usb 4-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    3.320721] usb 4-1.3: Product: USB5807 Hub
[    3.320723] usb 4-1.3: Manufacturer: Microchip
[    3.323883] hub 4-1.3:1.0: USB hub found
[    3.324035] hub 4-1.3:1.0: 7 ports detected
[    3.399548] usb 3-1.5: new high-speed USB device number 4 using xhci_hcd
[    3.502039] usb 3-1.5: New USB device found, idVendor=2109, idProduct=8888, bcdDevice= 0.01
[    3.502043] usb 3-1.5: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    3.502045] usb 3-1.5: Product: USB Billboard Device   
[    3.502047] usb 3-1.5: Manufacturer: VIA Labs, Inc.         
[    3.502049] usb 3-1.5: SerialNumber: 0000000000000001
[    3.579480] usb 3-1.3.5: new high-speed USB device number 5 using xhci_hcd
[    3.589954] psmouse serio3: synaptics: queried max coordinates: x [..5658], y [..4730]
[    3.622046] psmouse serio3: synaptics: queried min coordinates: x [1286..], y [1184..]
[    3.622063] psmouse serio3: synaptics: Your touchpad (PNP: SYN3091 SYN0100 SYN0002 PNP0f13) says it can support a different bus. If i2c-hid and hid-rmi are not used, you might want to try setting psmouse.synaptics_intertouch to 1 and report this to linux-input@vger.kernel.org.
[    3.679441] psmouse serio3: synaptics: Touchpad model: 1, fw: 10.16, id: 0x1e2a1, caps: 0xf00523/0x840300/0x12e800/0x500000, board id: 3352, fw id: 2888704
[    3.716290] input: SynPS/2 Synaptics TouchPad as /devices/platform/i8042/serio3/input/input14
[    4.247450] usb 3-1.3.5: New USB device found, idVendor=03f0, idProduct=0269, bcdDevice= 0.17
[    4.247454] usb 3-1.3.5: New USB device strings: Mfr=3, Product=1, SerialNumber=2
[    4.247456] usb 3-1.3.5: Product: USB Audio
[    4.247459] usb 3-1.3.5: Manufacturer: Generic
[    4.247461] usb 3-1.3.5: SerialNumber: 201604140001
[    4.263150] input: Generic USB Audio Consumer Control as /devices/pci0000:00/0000:00:1c.0/0000:01:00.0/0000:02:01.0/0000:04:00.0/0000:05:02.0/0000:06:00.0/usb3/3-1/3-1.3/3-1.3.5/3-1.3.5:1.3/0003:03F0:0269.0003/input/input17
[    4.299687] usb 4-1.3.3: new SuperSpeed Gen 1 USB device number 4 using xhci_hcd
[    4.319673] input: Generic USB Audio as /devices/pci0000:00/0000:00:1c.0/0000:01:00.0/0000:02:01.0/0000:04:00.0/0000:05:02.0/0000:06:00.0/usb3/3-1/3-1.3/3-1.3.5/3-1.3.5:1.3/0003:03F0:0269.0003/input/input18
[    4.319986] Console: switching to colour frame buffer device 240x67
[    4.320214] hid-generic 0003:03F0:0269.0003: input,hiddev0,hidraw1: USB HID v1.11 Device [Generic USB Audio] on usb-0000:06:00.0-1.3.5/input3
[    4.320342] usbcore: registered new interface driver usbhid
[    4.320344] usbhid: USB HID core driver
[    4.320883] usb 4-1.3.3: New USB device found, idVendor=0bda, idProduct=8153, bcdDevice=30.01
[    4.320888] usb 4-1.3.3: New USB device strings: Mfr=1, Product=2, SerialNumber=6
[    4.320891] usb 4-1.3.3: Product: USB 10/100/1000 LAN
[    4.320893] usb 4-1.3.3: Manufacturer: Realtek
[    4.320895] usb 4-1.3.3: SerialNumber: 000001000000
[    4.344398] i915 0000:00:02.0: [drm] fb0: i915drmfb frame buffer device
[    4.399503] usb 3-1.3.7: new full-speed USB device number 6 using xhci_hcd
[    4.446971] Lockdown: resume: hibernation is restricted; see man kernel_lockdown.7
[    4.569190] EXT4-fs (nvme0n1p2): mounted filesystem with ordered data mode. Opts: (null)
[    4.596627] Not activating Mandatory Access Control as /sbin/tomoyo-init does not exist.
[    4.641038] systemd[1]: Inserted module 'autofs4'
[    4.763076] systemd[1]: systemd 247.3-7 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +ZSTD +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=unified)
[    4.779927] systemd[1]: Detected architecture x86-64.
[    4.780192] systemd[1]: Set hostname to <internProject>.
[    4.780878] Lockdown: systemd: /dev/mem,kmem,port is restricted; see man kernel_lockdown.7
[    4.841684] systemd[1]: /lib/systemd/system/plymouth-start.service:16: Unit configured to use KillMode=none. This is unsafe, as it disables systemd's process lifecycle management for the service. Please update your service to use a safer KillMode=, such as 'mixed' or 'control-group'. Support for KillMode=none is deprecated and will eventually be removed.
[    4.854861] systemd[1]: Queued start job for default target Graphical Interface.
[    4.855599] systemd[1]: Created slice system-getty.slice.
[    4.855729] systemd[1]: Created slice system-modprobe.slice.
[    4.855868] systemd[1]: Created slice system-systemd\x2dfsck.slice.
[    4.855960] systemd[1]: Created slice User and Session Slice.
[    4.855993] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    4.856085] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[    4.856121] systemd[1]: Reached target User and Group Name Lookups.
[    4.856129] systemd[1]: Reached target Remote File Systems.
[    4.856134] systemd[1]: Reached target Slices.
[    4.856209] systemd[1]: Listening on Syslog Socket.
[    4.856253] systemd[1]: Listening on fsck to fsckd communication Socket.
[    4.856282] systemd[1]: Listening on initctl Compatibility Named Pipe.
[    4.856363] systemd[1]: Listening on Journal Audit Socket.
[    4.856406] systemd[1]: Listening on Journal Socket (/dev/log).
[    4.856454] systemd[1]: Listening on Journal Socket.
[    4.856599] systemd[1]: Listening on udev Control Socket.
[    4.856643] systemd[1]: Listening on udev Kernel Socket.
[    4.857038] systemd[1]: Mounting Huge Pages File System...
[    4.857414] systemd[1]: Mounting POSIX Message Queue File System...
[    4.857816] systemd[1]: Mounting Kernel Debug File System...
[    4.858222] systemd[1]: Mounting Kernel Trace File System...
[    4.859230] systemd[1]: Starting Set the console keyboard layout...
[    4.859694] systemd[1]: Starting Create list of static device nodes for the current kernel...
[    4.860138] systemd[1]: Starting Load Kernel Module configfs...
[    4.860635] systemd[1]: Starting Load Kernel Module drm...
[    4.861541] systemd[1]: Starting Load Kernel Module fuse...
[    4.861988] systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
[    4.862027] systemd[1]: Condition check resulted in File System Check on Root Device being skipped.
[    4.863091] systemd[1]: Starting Journal Service...
[    4.863809] systemd[1]: Starting Load Kernel Modules...
[    4.864239] systemd[1]: Starting Remount Root and Kernel File Systems...
[    4.864757] systemd[1]: Starting Coldplug All udev Devices...
[    4.865822] systemd[1]: Mounted Huge Pages File System.
[    4.865924] systemd[1]: Mounted POSIX Message Queue File System.
[    4.866010] systemd[1]: Mounted Kernel Debug File System.
[    4.866087] systemd[1]: Mounted Kernel Trace File System.
[    4.866300] systemd[1]: Finished Create list of static device nodes for the current kernel.
[    4.866518] systemd[1]: modprobe@configfs.service: Succeeded.
[    4.866662] systemd[1]: Finished Load Kernel Module configfs.
[    4.866816] systemd[1]: modprobe@drm.service: Succeeded.
[    4.866915] systemd[1]: Finished Load Kernel Module drm.
[    4.867472] systemd[1]: Mounting Kernel Configuration File System...
[    4.868761] fuse: init (API version 7.32)
[    4.869153] systemd[1]: modprobe@fuse.service: Succeeded.
[    4.869304] systemd[1]: Finished Load Kernel Module fuse.
[    4.869409] systemd[1]: Mounted Kernel Configuration File System.
[    4.869519] EXT4-fs (nvme0n1p2): re-mounted. Opts: errors=remount-ro
[    4.870038] systemd[1]: Mounting FUSE Control File System...
[    4.870941] systemd[1]: Finished Remount Root and Kernel File Systems.
[    4.871455] systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
[    4.871490] systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped.
[    4.872053] systemd[1]: Starting Load/Save Random Seed...
[    4.872717] systemd[1]: Starting Create System Users...
[    4.873493] systemd[1]: Mounted FUSE Control File System.
[    4.874742] lp: driver loaded but no devices found
[    4.877138] systemd[1]: Finished Load/Save Random Seed.
[    4.877156] ppdev: user-space parallel port driver
[    4.877269] systemd[1]: Condition check resulted in First Boot Complete being skipped.
[    4.879818] systemd[1]: Finished Create System Users.
[    4.880445] systemd[1]: Starting Create Static Device Nodes in /dev...
[    4.881997] systemd[1]: Finished Load Kernel Modules.
[    4.882573] systemd[1]: Starting Apply Kernel Variables...
[    4.888226] systemd[1]: Finished Apply Kernel Variables.
[    4.889041] systemd[1]: Finished Create Static Device Nodes in /dev.
[    4.890218] systemd[1]: Starting Rule-based Manager for Device Events and Files...
[    4.907074] systemd[1]: Finished Set the console keyboard layout.
[    4.907204] systemd[1]: Reached target Local File Systems (Pre).
[    4.917419] systemd[1]: Finished Coldplug All udev Devices.
[    4.918088] systemd[1]: Starting Helper to synchronize boot up for ifupdown...
[    4.920210] systemd[1]: Finished Helper to synchronize boot up for ifupdown.
[    4.925919] systemd[1]: Started Rule-based Manager for Device Events and Files.
[    4.926460] systemd[1]: Starting Show Plymouth Boot Screen...
[    4.928682] systemd[1]: Started Journal Service.
[    4.939275] systemd-journald[276]: Received client request to flush runtime journal.
[    4.953763] input: HP Wireless hotkeys as /devices/virtual/input/input20
[    4.954033] ACPI: AC Adapter [AC] (on-line)
[    4.968153] tpm_tis IFX0785:00: 2.0 TPM (device-id 0x1B, rev-id 22)
[    4.988120] intel_pch_thermal 0000:00:12.0: enabling device (0000 -> 0002)
[    5.016081] proc_thermal 0000:00:04.0: enabling device (0000 -> 0002)
[    5.016966] intel_rapl_common: Found RAPL domain package
[    5.016967] intel_rapl_common: Found RAPL domain dram
[    5.017158] mc: Linux media interface: v0.10
[    5.017208] cdc_acm 1-1:1.0: ttyACM0: USB ACM device
[    5.017532] usbcore: registered new interface driver cdc_acm
[    5.017534] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[    5.020254] mei_me 0000:00:16.0: enabling device (0000 -> 0002)
[    5.020993] ee1004 0-0050: 512 byte EE1004-compliant SPD EEPROM, read-only
[    5.022296] proc_thermal 0000:00:04.0: Creating sysfs group for PROC_THERMAL_PCI
[    5.030934] videodev: Linux video capture interface: v2.00
[    5.032194] iTCO_vendor_support: vendor-support=0
[    5.033254] usbcore: registered new interface driver r8152
[    5.035939] iTCO_wdt: Intel TCO WatchDog Timer Driver v1.11
[    5.035978] iTCO_wdt: Found a Intel PCH TCO device (Version=6, TCOBASE=0x0400)
[    5.036064] iTCO_wdt: initialized. heartbeat=30 sec (nowayout=0)
[    5.039100] usbcore: registered new interface driver cdc_ether
[    5.083458] Adding 1000444k swap on /dev/nvme0n1p3.  Priority:-2 extents:1 across:1000444k SSFS
[    5.111664] uvcvideo: Found UVC 1.50 device HP HD Camera (0408:5343)
[    5.116052] usb 4-1.3.3: reset SuperSpeed Gen 1 USB device number 4 using xhci_hcd
[    5.117288] hp_wmi: query 0x4 returned error 0x5
[    5.121239] input: HP HD Camera: HP HD Camera as /devices/pci0000:00/0000:00:14.0/usb1/1-9/1-9:1.0/input/input22
[    5.131692] hp_wmi: query 0xb returned error 0x5
[    5.142570] cryptd: max_cpu_qlen set to 1000
[    5.143056] input: HP WMI hotkeys as /devices/virtual/input/input21
[    5.144442] input: PC Speaker as /devices/platform/pcspkr/input/input23
[    5.147581] r8152 4-1.3.3:1.0: firmware: failed to load rtl_nic/rtl8153a-3.fw (-2)
[    5.147608] r8152 4-1.3.3:1.0: Direct firmware load for rtl_nic/rtl8153a-3.fw failed with error -2
[    5.147610] r8152 4-1.3.3:1.0: unable to load firmware patch rtl_nic/rtl8153a-3.fw (-2)
[    5.168942] pstore: Using crash dump compression: deflate
[    5.168969] pstore: Registered efi as persistent store backend
[    5.169038] AVX2 version of gcm_enc/dec engaged.
[    5.169038] AES CTR mode by8 optimization enabled
[    5.179993] r8152 4-1.3.3:1.0 eth0: v1.11.11
[    5.180542] uvcvideo: Found UVC 1.50 device HP HD Camera (0408:5343)
[    5.183025] input: HP HD Camera: HP IR Camera as /devices/pci0000:00/0000:00:14.0/usb1/1-9/1-9:1.2/input/input24
[    5.183084] usbcore: registered new interface driver uvcvideo
[    5.183085] USB Video Class driver (1.1.1)
[    5.183298] hp_wmi: query 0x1b returned error 0x5
[    5.189415] input: SYNA3091:00 06CB:82F5 Mouse as /devices/pci0000:00/0000:00:15.1/i2c_designware.1/i2c-2/i2c-SYNA3091:00/0018:06CB:82F5.0001/input/input25
[    5.189593] input: SYNA3091:00 06CB:82F5 Touchpad as /devices/pci0000:00/0000:00:15.1/i2c_designware.1/i2c-2/i2c-SYNA3091:00/0018:06CB:82F5.0001/input/input26
[    5.189835] hid-multitouch 0018:06CB:82F5.0001: input,hidraw0: I2C HID v1.00 Mouse [SYNA3091:00 06CB:82F5] on i2c-SYNA3091:00
[    5.190416] audit: type=1400 audit(1657119768.976:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="libreoffice-xpdfimport" pid=404 comm="apparmor_parser"
[    5.190576] audit: type=1400 audit(1657119768.976:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="lsb_release" pid=406 comm="apparmor_parser"
[    5.190847] audit: type=1400 audit(1657119768.976:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="libreoffice-senddoc" pid=408 comm="apparmor_parser"
[    5.191761] audit: type=1400 audit(1657119768.980:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/man" pid=403 comm="apparmor_parser"
[    5.191763] audit: type=1400 audit(1657119768.980:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_filter" pid=403 comm="apparmor_parser"
[    5.191764] audit: type=1400 audit(1657119768.980:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_groff" pid=403 comm="apparmor_parser"
[    5.191782] audit: type=1400 audit(1657119768.980:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="libreoffice-oopslash" pid=401 comm="apparmor_parser"
[    5.193771] audit: type=1400 audit(1657119768.980:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/cups-browsed" pid=402 comm="apparmor_parser"
[    5.194104] audit: type=1400 audit(1657119768.980:10): apparmor="STATUS" operation="profile_load" profile="unconfined" name="nvidia_modprobe" pid=417 comm="apparmor_parser"
[    5.194107] audit: type=1400 audit(1657119768.980:11): apparmor="STATUS" operation="profile_load" profile="unconfined" name="nvidia_modprobe//kmod" pid=417 comm="apparmor_parser"
[    5.315684] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    5.315860] cfg80211: Loaded X.509 cert 'benh@debian.org: 577e021cb980e0e820821ba7b54b4961b8b4fadf'
[    5.316009] cfg80211: Loaded X.509 cert 'romain.perier@gmail.com: 3abbc6ec146e09d1b6016ab9d6cf71dd233f0328'
[    5.316191] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    5.316338] platform regulatory.0: firmware: direct-loading firmware regulatory.db
[    5.317014] platform regulatory.0: firmware: direct-loading firmware regulatory.db.p7s
[    5.326066] snd_hda_intel 0000:00:1f.3: DSP detected with PCI class/subclass/prog-if info 0x040100
[    5.326083] snd_hda_intel 0000:00:1f.3: Digital mics found on Skylake+ platform, using SOF driver
[    5.327807] RAPL PMU: API unit is 2^-32 Joules, 5 fixed counters, 655360 ms ovfl timer
[    5.327809] RAPL PMU: hw unit of domain pp0-core 2^-14 Joules
[    5.327809] RAPL PMU: hw unit of domain package 2^-14 Joules
[    5.327810] RAPL PMU: hw unit of domain dram 2^-14 Joules
[    5.327810] RAPL PMU: hw unit of domain pp1-gpu 2^-14 Joules
[    5.327811] RAPL PMU: hw unit of domain psys 2^-14 Joules
[    5.340327] Intel(R) Wireless WiFi driver for Linux
[    5.340503] iwlwifi 0000:3a:00.0: enabling device (0000 -> 0002)
[    5.342254] snd_soc_skl 0000:00:1f.3: DSP detected with PCI class/subclass/prog-if info 0x040100
[    5.342273] snd_soc_skl 0000:00:1f.3: Digital mics found on Skylake+ platform, using SOF driver
[    5.349701] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-59.ucode (-2)
[    5.349703] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-59.ucode failed with error -2
[    5.349713] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-58.ucode (-2)
[    5.349714] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-58.ucode failed with error -2
[    5.349722] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-57.ucode (-2)
[    5.349723] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-57.ucode failed with error -2
[    5.349731] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-56.ucode (-2)
[    5.349732] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-56.ucode failed with error -2
[    5.349740] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-55.ucode (-2)
[    5.349741] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-55.ucode failed with error -2
[    5.349748] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-54.ucode (-2)
[    5.349749] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-54.ucode failed with error -2
[    5.349757] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-53.ucode (-2)
[    5.349758] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-53.ucode failed with error -2
[    5.349766] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-52.ucode (-2)
[    5.349767] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-52.ucode failed with error -2
[    5.349775] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-51.ucode (-2)
[    5.349776] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-51.ucode failed with error -2
[    5.349785] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-50.ucode (-2)
[    5.349786] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-50.ucode failed with error -2
[    5.349793] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-49.ucode (-2)
[    5.349794] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-49.ucode failed with error -2
[    5.349801] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-48.ucode (-2)
[    5.349802] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-48.ucode failed with error -2
[    5.349809] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-47.ucode (-2)
[    5.349810] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-47.ucode failed with error -2
[    5.349818] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-46.ucode (-2)
[    5.349819] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-46.ucode failed with error -2
[    5.349827] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-45.ucode (-2)
[    5.349828] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-45.ucode failed with error -2
[    5.349835] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-44.ucode (-2)
[    5.349836] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-44.ucode failed with error -2
[    5.349844] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-43.ucode (-2)
[    5.349844] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-43.ucode failed with error -2
[    5.349852] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-42.ucode (-2)
[    5.349853] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-42.ucode failed with error -2
[    5.349861] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-41.ucode (-2)
[    5.349862] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-41.ucode failed with error -2
[    5.349872] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-40.ucode (-2)
[    5.349873] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-40.ucode failed with error -2
[    5.349880] iwlwifi 0000:3a:00.0: firmware: failed to load iwlwifi-cc-a0-39.ucode (-2)
[    5.349881] iwlwifi 0000:3a:00.0: Direct firmware load for iwlwifi-cc-a0-39.ucode failed with error -2
[    5.349883] iwlwifi 0000:3a:00.0: minimum version required: iwlwifi-cc-a0-39
[    5.349883] iwlwifi 0000:3a:00.0: maximum version supported: iwlwifi-cc-a0-59
[    5.349884] iwlwifi 0000:3a:00.0: check git://git.kernel.org/pub/scm/linux/kernel/git/firmware/linux-firmware.git
[    5.435174] alg: No test for fips(ansi_cprng) (fips_ansi_cprng)
[    5.487844] sof-audio-pci 0000:00:1f.3: DSP detected with PCI class/subclass/prog-if info 0x040100
[    5.487863] sof-audio-pci 0000:00:1f.3: Digital mics found on Skylake+ platform, using SOF driver
[    5.487876] sof-audio-pci 0000:00:1f.3: enabling device (0000 -> 0002)
[    5.488063] sof-audio-pci 0000:00:1f.3: DSP detected with PCI class/subclass/prog-if 0x040100
[    5.489500] sof-audio-pci 0000:00:1f.3: bound 0000:00:02.0 (ops i915_audio_component_bind_ops [i915])
[    5.509681] sof-audio-pci 0000:00:1f.3: use msi interrupt mode
[    5.520397] Bluetooth: Core ver 2.22
[    5.520417] NET: Registered protocol family 31
[    5.520417] Bluetooth: HCI device and connection manager initialized
[    5.520420] Bluetooth: HCI socket layer initialized
[    5.520422] Bluetooth: L2CAP socket layer initialized
[    5.520425] Bluetooth: SCO socket layer initialized
[    5.588729] usbcore: registered new interface driver btusb
[    5.589292] sof-audio-pci 0000:00:1f.3: hda codecs found, mask 5
[    5.589294] sof-audio-pci 0000:00:1f.3: using HDA machine driver skl_hda_dsp_generic now
[    5.589299] sof-audio-pci 0000:00:1f.3: DMICs detected in NHLT tables: 4
[    5.589322] sof-audio-pci 0000:00:1f.3: firmware: failed to load intel/sof/sof-cnl.ri (-2)
[    5.590114] sof-audio-pci 0000:00:1f.3: Direct firmware load for intel/sof/sof-cnl.ri failed with error -2
[    5.590119] Bluetooth: hci0: Bootloader revision 0.3 build 0 week 24 2017
[    5.590119] sof-audio-pci 0000:00:1f.3: error: request firmware intel/sof/sof-cnl.ri failed err: -2
[    5.590121] sof-audio-pci 0000:00:1f.3: error: failed to load DSP firmware -2
[    5.590232] intel_rapl_common: Found RAPL domain package
[    5.590234] intel_rapl_common: Found RAPL domain core
[    5.590235] intel_rapl_common: Found RAPL domain uncore
[    5.590235] intel_rapl_common: Found RAPL domain dram
[    5.590236] intel_rapl_common: Found RAPL domain psys
[    5.592112] Bluetooth: hci0: Device revision is 1
[    5.592113] Bluetooth: hci0: Secure boot is enabled
[    5.592114] Bluetooth: hci0: OTP lock is enabled
[    5.592114] Bluetooth: hci0: API lock is enabled
[    5.592115] Bluetooth: hci0: Debug lock is disabled
[    5.592116] Bluetooth: hci0: Minimum firmware build 1 week 10 2014
[    5.592128] bluetooth hci0: firmware: failed to load intel/ibt-20-1-3.sfi (-2)
[    5.593083] sof-audio-pci 0000:00:1f.3: error: sof_probe_work failed err: -2
[    5.593189] bluetooth hci0: Direct firmware load for intel/ibt-20-1-3.sfi failed with error -2
[    5.593932] Bluetooth: hci0: Failed to load Intel firmware file (-2)
[    5.610571] mei_hdcp 0000:00:16.0-b638ab7e-94e2-4ea2-a552-d1c54b627f04: bound 0000:00:02.0 (ops i915_hdcp_component_ops [i915])
[    5.660075] r8152 4-1.3.3:1.0 enx3024a94383c9: renamed from eth0
[    5.688611] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[    5.688614] Bluetooth: BNEP filters: protocol multicast
[    5.688620] Bluetooth: BNEP socket layer initialized
[    5.830591] intel_pmc_core intel_pmc_core.0:  initialized
[    6.858696] Lockdown: systemd-logind: hibernation is restricted; see man kernel_lockdown.7
[    6.978247] rfkill: input handler disabled
[    8.809290] IPv6: ADDRCONF(NETDEV_CHANGE): enx3024a94383c9: link becomes ready
[    8.809607] r8152 4-1.3.3:1.0 enx3024a94383c9: carrier on
[    9.550106] usb 3-1.3.7: New USB device found, idVendor=03f0, idProduct=0667, bcdDevice= 1.00
[    9.550113] usb 3-1.3.7: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    9.550116] usb 3-1.3.7: Product: WinUSB
[    9.550120] usb 3-1.3.7: Manufacturer: Cypress Semiconductor
[    9.550122] usb 3-1.3.7: SerialNumber: 1.0
[    9.572435] hid-generic 0003:03F0:0667.0004: hiddev1,hidraw2: USB HID v1.11 Device [Cypress Semiconductor WinUSB] on usb-0000:06:00.0-1.3.7/input1
[   10.152189] usbcore: registered new interface driver snd-usb-audio
[   13.954540] rfkill: input handler enabled
[   14.901935] Lockdown: systemd-logind: hibernation is restricted; see man kernel_lockdown.7
[   15.125115] rfkill: input handler disabled
[  133.365636] Lockdown: systemd-logind: hibernation is restricted; see man kernel_lockdown.7
P33M commented 2 years ago

Without representative hardware there is little chance of a diagnosis. If you have a unit spare that you can loan, then please email info << at >> raspberrypi.com quoting this issue link and we can take a look.

P33M commented 2 years ago

I've now got one in my possession. The device can't handle being suspended, and never responds to SETUP packets after a resume.

You can reproduce this without a Pi 4 - using a powered USB hub that does not switch its downstream port power, plug the RFID reader into the downstream port. Then connect the upstream port to a PC, and the device fails to enumerate.

The glitchy mouse behaviour on a Pi 4 is because Linux is trying to power-cycle the hub port. The upstream root ports need to be power cycled.

P33M commented 2 years ago

I can recover the port state by forcibly power cycling the Pi 4's downstream ports with uhubctl.

sudo uhubctl -l 1-1 -a 2 brings it back to life.

It's not included in Raspberry Pi OS by default - install it with sudo apt install uhubctl.

ReneElizondo commented 2 years ago

Thanks @P33M

Its great to know that we now have a diagnosis. Quick questions if you don't mind. What do you mean by "does not switch its downstream port power"? You mean the port does not switch its power on and off? Just trying to make sure I understand what is going on and may need more of a layman's terms explanation!

Thanks.

P33M commented 2 years ago

As in, the hub either does not implement any Vbus switching at all (no hardware support) or it doesn't use an upstream port disconnect to imply "turn off downstream Vbus".

ReneElizondo commented 2 years ago

So what changed between the Pi 3 and Pi 4 so that in the Pi 3 things work just fine but in the Pi 4 things fail? Why can't the Pi 4 do what the Pi 3 does?

JamesH65 commented 2 years ago

The Pi4 uses a completely different USB hub chip that is directly connected to the PCIe port on the Pi4 SoC. The Pi3 has a USB hub attached to the USB2 port.

P33M commented 2 years ago

USB port suspend is a state inferred by the /absence/ of any activity following a port reset, start-of-frame token or host data token for more than 3ms. It seems that the reboot sequence of a Pi 4 has a transient state where suspend is being inferred, and this breaks the RFID reader. It's almost certainly a firmware flaw with the device.

ReneElizondo commented 2 years ago

I finally got the chance to do some more research on this. As you correctly stated, I was able to reproduce the hub problem even in Windows. I think this information is going to be incredibly helpful (THANK YOU), I will send this new discovery to the people that created the ThingMagic device to see if they can use this info to fix their stuff.... although I seriously doubt it.

That said, there is something that just does not feel right about all this. I understand that the ThingMagic device has some issues, nevertheless, even with those issues the device works on most computers under the typical use case (which is plugging the device directly to the computer USB port).

Now, I understand that this is not the kind of device you can buy at the corner store but its a very popular device among RFID users and they sell millions of these things worldwide. These millions of ThingMagic devices are used by millions of different computers and they all work just fine (under the mentioned typical use case).... except on the Raspberry Pi 4.

So the question that begs to be asked is why does the Raspberry Pi 4 does things differently? I am not saying that the Raspberry Pi 4 is doing the wrong thing, I am simply saying that it is doing things differently than most if not all other computers out there (including the Pi 3). Why not simply take the tried and true protocol / exact sequence of events that happens when plugging a USB device into a normal computer and make those sequence of events to be the same in the Pi 4 so that the behavior on the Pi 4 is the same as the rest of the computers? Which means, there would be no issues just plugin the ThingMagic device directly in the Pi 4 (typical use case). What harm or negative effect can come from that?

Thanks.

JamesH65 commented 2 years ago

The specific behaviour here is that provided by the PCIe USB hub chip. This is provided by a third party, I think a different manufacturer to the completely different chip used on the Pi3. They obviously do something slightly different, as is common between manufacturers. We buy these devices in, and rely on the manufacturers to adhere to the specifications, which on the whole they do. In this case it looks like there is some very specific behaviour that is different between the chips, despite both adhering to the USB specification. The issue is that the ThingMagic device does NOT appear to adhere to the USB specification (although P33M will confirm). This is apparently fine in most circumstances, but not in this specific one. Whether the manufacturer of the PCIe hub chip would be willing to update their firmware to compensate for the Thingmagic's fault is unknown. It might also not be "get roundable".

JamesH65 commented 2 years ago

Worth adding that the huge majority of USB devices work absolutely fine on the Pi4.

P33M commented 2 years ago

Out of interest, the USB device controller is an Atmel AT91SAM7S256. Fairly common, used a lot in custom USB peripherals.

In absence of a device firmware update the fix is to add a systemd startup script or command in rc.local to invoke uhubctl to power-cycle the downstream ports as shown above.

ReneElizondo commented 2 years ago

Thank you guys for all the help with trying to figure out what the issue with the ThingMagic device was even though as it turns out this wasn't really a Raspberry Pi 4 issue (sorry about that). I have reported the new findings to the company that makes the ThingMagic device, lets see how things go from here.

Before moving on from this issue, I was wondering, given that you guys have a ThingMagic device there to play with, any chance you guys would have some time to investigate why the device constantly disconnects and reconnects after the Pi 4 registers the ThingMagic device? This appears to be a similar issue as to what other are experiencing with SSDs.

The only way to stop that problem from happening is by adding a USB hub between the Pi and the ThingMagic device (in our case, this needs to be a powered USB hub 2.0 since USB 2.0 hubs seem to play well with the Pi 4). But what is puzzling is that the device seems to disconnect / reconnect even when the ThingMagic device is idling (using almost zero power). So I don't think this is an issue with the Pi 4 not being able to deliver enough power, I think there is more to the story.

To reproduce the issue simply plug the ThingMagic device into the Pi 4, make sure its property registered by the Pi 4 and then just wait. For a more realistic scenario I can provide a script that calls the ThingMagic reader every minute but I was able to replicate the issue even without making calls to the ThingMagic reader.

The problem with testing this is that the issue does not surface immediately, sometimes you see it happening in the same day, sometimes things work great for 10 days and then everything starts crashing. But eventually, it does happen.

Here is the link where I previously reported the issue in case you guys are interested in pursuing this: https://github.com/raspberrypi/linux/issues/5046#issuecomment-1159818309

Thanks.

solmoller commented 2 years ago

Very interesting thread. Pls remember, that there probably are more devices out there with the same issue - I have a UPS that has the same problem, fixed by adding a cheapo USB hub.

Great work, thanks!

P33M commented 2 years ago

After 16 hours of connection via a USB analyzer there hasn't been a single instance of disconnection. Not seen any disconnects when directly connected either.

ReneElizondo commented 2 years ago

I've now got one in my possession. The device can't handle being suspended, and never responds to SETUP packets after a resume.

You can reproduce this without a Pi 4 - using a powered USB hub that does not switch its downstream port power, plug the RFID reader into the downstream port. Then connect the upstream port to a PC, and the device fails to enumerate.

@P33M So I ended up reporting this issue to the guys that manufacture the ThingMagic device, not surprisingly they were not able to replicate the issue. By the way, we had no problem replicating the issue here with multiple USB hubs from multiple manufacturers but somehow for some reason, they could not.

The thing about this is that there are powered USB hubs that do not work (I think that is the majority) but there are indeed some powered USB hubs that actually do work. Do you happen to know of a way to detect if a powered USB hub would work or not based on something such as product description or perhaps based on the chip the USB hub uses? In other words, how can I know if the powered USB hub does not switch its downstream port power?

Perhaps if you give me the exact brand and model of the USB hub you tested this on I can send those guys the link so they can buy that one, I am asking you because I am pretty sure those guys are based in India and I wonder if USB hub brands like the one you have are more easily available on the other side of the world (I am based in the USA).

Thanks.

P33M commented 2 years ago

Have they replicated the issue with a Raspberry Pi 4 Model B? The mode of failure is the same in either case, the hub test was specifically designed to eliminate the Pi as a source of misbehaviour.

ReneElizondo commented 2 years ago

They did replicate the issue with the Pi 4, however, they claimed that they had no interest in fixing the issue because I was the only one having that issue and because the problem was specific to the Pi 4 (which that part is true).

However, now that we are able to reproduce the issue in Windows things are different, if the issue happens in Windows they may address the problem. To be honest, I don't care about Windows, what I care about is that if the problem is addressed in Windows it will automatically be addressed in the Pi. But before we get there, they need to be able to replicate the problem using the powered USB hub and so far no success.

Hey, do you happen to have the brand and model of the USB hub you used to replicate the issue?

Thanks.

P33M commented 2 years ago

The hub was a Startech.com ST7300U3M.

ReneElizondo commented 2 years ago

So in case anyone is curious about this, the company that makes the ThingMagic device presumably tested this issue using no less than five USB hubs:

According to them, they tested this on two computers running Windows 10 and none of the hubs experience the issue. I happen to have the StarTech hub and tested this on three computers and the issue showed up on the tree computers....

The experiment was conducted as follows:

  1. Get the powered hub.
  2. Plug the USB hub to its power supply.
  3. Plug the ThingMagic device to the USB hub.
  4. Plug the USB hub to a computer.
  5. Unplug and re-plug the hub from the computer (not the ThingMagic device from the hub) a couple of times to see the error show up every time the hub is disconnected.

So tired of dealing with this.... about to throw the towel and call it a day.

symbios24 commented 2 years ago

So in case anyone is curious about this, the company that makes the ThingMagic device presumably tested this issue using no less than five USB hubs:

  • USB 3 Hub: Anker 4-Port Ultra Slim USB3.0 Data Hub. Model Number: A7516.
  • USB 2.0 Hub Belkin F4U020
  • USB 3.0 Hub StarTech.com ST4300MINI
  • USB 3.0 Hub: Dhruvga DHV-HUB-0107 USB 4 Port
  • USB 3.0 Hub: Anker 10-port USB hub Model Number: A7515

According to them, they tested this on two computers running Windows 10 and none of the hubs experience the issue. I happen to have the StarTech hub and tested this on three computers and the issue showed up on the tree computers....

The experiment was conducted as follows:

  1. Get the powered hub.
  2. Plug the USB hub to its power supply.
  3. Plug the ThingMagic device to the USB hub.
  4. Plug the USB hub to a computer.
  5. Unplug and re-plug the hub from the computer (not the ThingMagic device from the hub) a couple of times to see the error show up every time the hub is disconnected.

So tired of dealing with this.... about to throw the towel and call it a day.

Hi, you said in win 10 it works ok why you dont put windows 10 arm on the Raspberry Pi 4?

ReneElizondo commented 2 years ago

Windows is not really a contender when it comes to embedded operating systems (everything is Linux based now). I am not even sure their are still seriously supporting their Windows IoT platform. If at some point in the future, I see the option to install Windows from the "Raspberry pi imager" application, then maybe.... just maybe there will be a glimpse of hope that "Windows is back". In the meantime, Windows on the Pi sound as realistic as Windows on a smart phone.

symbios24 commented 2 years ago

You can always try them, from what i read from reviews they don't perform bad if installed in ssd drive

P33M commented 1 year ago

This device doesn't adhere to the USB spec, but there is a workaround - power cycling it after Linux comes back up. There won't be a software change to special-case this device.

geekifier commented 1 year ago

@ReneElizondo I just came across this. I am running into a similar issue with a Cyberpower UPS serial interface, which fails intermittently after Rpi4 is rebooted. Just like in your case, unplugging and plugging the cable back resolves it. I initially reported it in the Home Assistant OS repo, which uses the same kernel (https://github.com/home-assistant/operating-system/issues/2574).

Have you found a way to toggle/unbind the affected USB device after reboots via software?

ReneElizondo commented 1 year ago

No software fix, I essentially continued talking to the company that makes the device and after they were able to reproduce the issue on Windows using the USB hub suggested by P33M (Startech.com ST7300U3M - but most USB 3 based hubs will have the same issue), the company went back and did a firmware update on the device that fixed the issue.

Have you try connecting your Cyberpower UPS to a USB 3 based hub on Windows? If you do, I bet you will have the same issue even in Windows and if that is the case, the company that makes that device may consider fixing the product (if you are very lucky).

Thanks.

jedi-ml commented 1 year ago

@ReneElizondo Did you find any way to fix this problem? we have same problem with that case :(