Re: USB Bluetooth dongle stop response with timeout error

[Morikazu Fumita <mfumita@electromag.com.au>]

[-- Attachment #1: Type: text/plain, Size: 2630 bytes --]

Hello there,

I am working on an embedded system to support USB Bluetooth dongles.
* Soc: Altera Cyclone V SoC FPGA
* Linux: Ångström distribution with kernel version is 4.17 and 4.19
* USB Bluetooth dongle: Broadcom chip, connected as USB1.1

I have a problem of that an USB Bluetooth dongle seems to stop 
responding to host's HCI commands suddenly.
These are example error messages I got when it stops response.
[  145.046503] Bluetooth: hci0: command 0x1002 tx timeout
[  147.086503] Bluetooth: hci0: command 0x0c52 tx timeout
[  149.121499] Bluetooth: hci0: command 0x0c45 tx timeout
[  151.166503] Bluetooth: hci0: command 0x0c58 tx timeout

I do not find out what is the trigger of this problem.
Sometimes the dongle is working (used as a Bluetooth PAN server) 
initially but suddenly gives the timeout error then stop responding.
Sometimes the error happens just immediately after I insert the dongle.
There does not seem to be specific HCI commands to cause the error. The 
command in the error messages varies.

The attached dmesg log (dmesg_log.txt) and USB packet dump 
(USB_Dump.pcapng can be opened by Wireshark) have been taken while the 
system cold boot, inserting the dongle and the error happens.

In frame no. 161 of the packet dump, the host sent HCI command 0x1002 
(Read Local Supported Commands).
Then the USB dongle tried to respond to that from frame no. 163 but it 
did not sent all fragment packets. It seems to stop response in the middle.
Finally, "[  145.046503] Bluetooth: hci0: command 0x1002 tx timeout" 
happened (Please refer dmesg_log.txt attached).

As for frame no. 165, the host sent 0x0c52 (Write Extended Inquiry 
Response) but there was no response to it then "[  147.086503] 
Bluetooth: hci0: command 0x0c52 tx timeout" happened.


I disabled the following kernel options related to power management but 
the error still happening.
* CPU Frequency scaling
* CPU idle PM support
* Suspend to RAM and standby
* Hibernation (aka 'suspend to disk')
* Device power management core functionality
* Advanced Power Management Emulation

I also disabled kernel options under "Bluetooth subsystem support" (so 
only "Bluetooth subsystem support" is enabled) but still it is happening.

I tried to reduce some USB kernel options and enabled just only the 
following stuff but it did not make any difference.
* Support for Host-side USB
* USB announce new devices
* DesignWare USB2 DRD Core Support

The dongle is detected in hardware level even when this problem is 
happening as I can see it on "hciconfig".


It would be great if you would give me your thoughts.

Thank you in advance,

Mori


[-- Attachment #2: USB_Dump.pcapng --]
[-- Type: application/octet-stream, Size: 18060 bytes --]

[-- Attachment #3: dmesg_log.txt --]
[-- Type: text/plain, Size: 24695 bytes --]

U-Boot 2018.05-00021-gdca61cc (2018-10-01 - 09:16:23 +0000)

CPU:   Altera SoCFPGA Platform
FPGA:  Altera Cyclone V, SE/A5 or SX/C5 or ST/D5, version 0x0
BOOT:  SD/MMC Internal Transceiver (3.0V)
       Watchdog enabled
DRAM:  2 GiB
MMC:   dwmmc0@ff704000: 0
Loading Environment from MMC... *** Warning - bad CRC, using default environment

Failed (-5)
In:    serial
Out:   serial
Err:   serial
Model: SocFPGA EMIT
Netadr:d8:80:39:63:da:f2
MainBd:01
Config: Default Rev 1
Net:   eth0: ethernet@ff702000
Net:   Switch Configured
gpio: pin portc3 (gpio 61) value is 1
** Unable to read file update.scr **
FPGA Read: 0:2 /boot/Default.rbf
2279040 bytes read in 332 ms (6.5 MiB/s)
FPGA: Loaded
Hit any key to stop autoboot:  0
KERNEL: Reading 0:2 /boot/zImage /boot/Default_01.dtb
5382304 bytes read in 790 ms (6.5 MiB/s)
43344 bytes read in 33 ms (1.3 MiB/s)
KERNEL: Running
## Flattened Device Tree blob at 00000100
   Booting using the fdt blob at 0x000100
   reserving fdt memory region: addr=0 size=1000
   Loading Device Tree to 03ff2000, end 03fff94f ... OK

Starting kernel ...

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.17.0-00149-g192a335 (mfumita@localhost.localdomain) (gcc version 7.3.0 (GCC)) #7 SMP PREEMPT 2018-11-06 04:22:38 +0000
[    0.000000] CPU: ARMv7 Processor [413fc090] revision 0 (ARMv7), cr=10c5387d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] OF: fdt: Machine model: EMIT Soc-Core
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] Ignoring RAM at 0x70000000-0x80000000
[    0.000000] Consider using a HIGHMEM enabled kernel.
[    0.000000] random: get_random_bytes called from start_kernel+0xa8/0x434 with crng_init=0
[    0.000000] percpu: Embedded 17 pages/cpu @(ptrval) s37388 r8192 d24052 u69632
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 455168
[    0.000000] Kernel command line: coherent_pool=1M console=ttyS0,230400 root=/dev/mmcblk0p2 rw rootwait
[    0.000000] Dentry cache hash table entries: 262144 (order: 8, 1048576 bytes)
[    0.000000] Inode-cache hash table entries: 131072 (order: 7, 524288 bytes)
[    0.000000] Memory: 1805524K/1835008K available (8192K kernel code, 624K rwdata, 1764K rodata, 1024K init, 368K bss, 29484K reserved, 0K cma-reserved)
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
[    0.000000]     vmalloc : 0xf0800000 - 0xff800000   ( 240 MB)
[    0.000000]     lowmem  : 0x80000000 - 0xf0000000   (1792 MB)
[    0.000000]     modules : 0x7f000000 - 0x80000000   (  16 MB)
[    0.000000]       .text : 0x(ptrval) - 0x(ptrval)   (9184 kB)
[    0.000000]       .init : 0x(ptrval) - 0x(ptrval)   (1024 kB)
[    0.000000]       .data : 0x(ptrval) - 0x(ptrval)   ( 625 kB)
[    0.000000]        .bss : 0x(ptrval) - 0x(ptrval)   ( 369 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    0.000000] ftrace: allocating 27932 entries in 82 pages
[    0.000000] Preemptible hierarchical RCU implementation.
[    0.000000]  Tasks RCU enabled.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] L2C-310 erratum 769419 enabled
[    0.000000] L2C-310 enabling early BRESP for Cortex-A9
[    0.000000] L2C-310 full line of zeros enabled for Cortex-A9
[    0.000000] L2C-310 ID prefetch enabled, offset 8 lines
[    0.000000] L2C-310 dynamic clock gating enabled, standby mode enabled
[    0.000000] L2C-310 cache controller enabled, 8 ways, 512 kB
[    0.000000] L2C-310: CACHE_ID 0x410030c9, AUX_CTRL 0x76460001
[    0.000000] clocksource: timer1: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
[    0.000006] sched_clock: 32 bits at 100MHz, resolution 10ns, wraps every 21474836475ns
[    0.000020] Switching to timer-based delay loop, resolution 10ns
[    0.000328] Console: colour dummy device 80x30
[    0.000356] Calibrating delay loop (skipped), value calculated using timer frequency.. 200.00 BogoMIPS (lpj=500000)
[    0.000373] pid_max: default: 32768 minimum: 301
[    0.000523] Mount-cache hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000540] Mountpoint-cache hash table entries: 4096 (order: 2, 16384 bytes)
[    0.001117] CPU: Testing write buffer coherency: ok
[    0.001381] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.024809] Setting up static identity map for 0x100000 - 0x100060
[    0.029790] Hierarchical SRCU implementation.
[    0.039802] smp: Bringing up secondary CPUs ...
[    0.065077] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.065213] smp: Brought up 1 node, 2 CPUs
[    0.065230] SMP: Total of 2 processors activated (400.00 BogoMIPS).
[    0.065239] CPU: All CPU(s) started in SVC mode.
[    0.066290] devtmpfs: initialized
[    0.074839] VFP support v0.3: implementor 41 architecture 3 part 30 variant 9 rev 4
[    0.075229] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 9556302231375000 ns
[    0.075251] futex hash table entries: 512 (order: 3, 32768 bytes)
[    0.075497] pinctrl core: initialized pinctrl subsystem
[    0.076340] NET: Registered protocol family 16
[    0.078889] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.080006] cpuidle: using governor ladder
[    0.080254] hw-breakpoint: found 5 (+1 reserved) breakpoint and 1 watchpoint registers.
[    0.080265] hw-breakpoint: maximum watchpoint size is 4 bytes.
[    0.102811] SCSI subsystem initialized
[    0.103064] usbcore: registered new interface driver usbfs
[    0.103122] usbcore: registered new interface driver hub
[    0.103231] usbcore: registered new device driver usb
[    0.103588] usb_phy_generic soc:usbphy: soc:usbphy supply vcc not found, using dummy regulator
[    0.104955] gpio-2034 (soc:i2c): enforced open drain please flag it properly in DT/ACPI DSDT/board file
[    0.105072] gpio-2033 (soc:i2c): enforced open drain please flag it properly in DT/ACPI DSDT/board file
[    0.105242] i2c-gpio soc:i2c: using lines 2034 (SDA) and 2033 (SCL)
[    0.105363] pps_core: LinuxPPS API ver. 1 registered
[    0.105373] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.105408] PTP clock support registered
[    0.105651] FPGA manager framework
[    0.106480] clocksource: Switched to clocksource timer1
[    0.177582] NET: Registered protocol family 2
[    0.178207] tcp_listen_portaddr_hash hash table entries: 1024 (order: 1, 12288 bytes)
[    0.178249] TCP established hash table entries: 16384 (order: 4, 65536 bytes)
[    0.178389] TCP bind hash table entries: 16384 (order: 5, 131072 bytes)
[    0.178634] TCP: Hash tables configured (established 16384 bind 16384)
[    0.178756] UDP hash table entries: 1024 (order: 3, 32768 bytes)
[    0.178827] UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes)
[    0.179053] NET: Registered protocol family 1
[    0.179624] RPC: Registered named UNIX socket transport module.
[    0.179637] RPC: Registered udp transport module.
[    0.179646] RPC: Registered tcp transport module.
[    0.179654] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.180692] hw perfevents: enabled with armv7_cortex_a9 PMU driver, 7 counters available
[    0.180993] hw perfevents: no interrupt-affinity property for /soc/pmu, guessing.
[    0.181046] ------------[ cut here ]------------
[    0.181070] WARNING: CPU: 0 PID: 1 at kernel/irq/chip.c:1034 irq_modify_status+0x160/0x168
[    0.181442] ---[ end trace 7418234f6939a45f ]---
[    0.181457] genirq: Flags mismatch irq 18. 00010c04 (arm-pmu) vs. 00010c04 (arm-pmu)
[    0.181524] hw perfevents: unable to request IRQ18 for ARM PMU counters
[    0.181558] hw perfevents: /soc/pmu: failed to register PMU devices!
[    0.181588] armv7-pmu: probe of soc:pmu failed with error -16
[    0.183258] Initialise system trusted keyrings
[    0.183449] workingset: timestamp_bits=30 max_order=19 bucket_order=0
[    0.191095] NFS: Registering the id_resolver key type
[    0.191126] Key type id_resolver registered
[    0.191136] Key type id_legacy registered
[    0.191182] ntfs: driver 2.1.32 [Flags: R/W].
[    0.191581] jffs2: version 2.2. (NAND) © 2001-2006 Red Hat, Inc.
[    0.192123] fuse init (API version 7.26)
[    0.196062] Key type asymmetric registered
[    0.196078] Asymmetric key parser 'x509' registered
[    0.196107] io scheduler noop registered (default)
[    0.196117] io scheduler mq-deadline registered
[    0.196126] io scheduler kyber registered
[    0.203259] dma-pl330 ffe01000.pdma: Loaded driver for PL330 DMAC-341330
[    0.203276] dma-pl330 ffe01000.pdma:         DBUFF-512x8bytes Num_Chans-8 Num_Peri-32 Num_Events-8
[    0.208014] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[    0.209701] console [ttyS0] disabled
[    0.209765] ffc02000.serial0: ttyS0 at MMIO 0xffc02000 (irq = 43, base_baud = 6250000) is a 16550A
[    0.559162] console [ttyS0] enabled
[    0.561719] ffc03000.serial1: ttyS3 at MMIO 0xffc03000 (irq = 44, base_baud = 6250000) is a 16550A
[    0.567417] ff207000.serial: ttyS2 at MMIO 0xff207000 (irq = 47, base_baud = 6250000) is a Altera 16550 FIFO128
[    0.573210] ff208000.serial: ttyS1 at MMIO 0xff208000 (irq = 48, base_baud = 6250000) is a Altera 16550 FIFO128
[    0.580178] brd: module loaded
[    0.586419] libphy: Fixed MDIO Bus: probed
[    0.589390] CAN device driver interface
[    0.592509] socfpga-dwmac ff702000.ethernet: PTP uses main clock
[    0.595788] socfpga-dwmac ff702000.ethernet: Ring mode enabled
[    0.598750] socfpga-dwmac ff702000.ethernet: DMA HW capability register supported
[    0.602510] socfpga-dwmac ff702000.ethernet: Enhanced/Alternate descriptors
[    0.605986] socfpga-dwmac ff702000.ethernet: Extended descriptors not supported
[    0.609657] socfpga-dwmac ff702000.ethernet: RX Checksum Offload Engine supported
[    0.613429] socfpga-dwmac ff702000.ethernet: COE Type 2
[    0.616039] socfpga-dwmac ff702000.ethernet: TX Checksum insertion supported
[    0.619780] libphy: stmmac: probed
[    0.621917] mv88e6085 stmmac-0:00: switch 0x3520 detected: Marvell 88E6352, revision 1
[    0.634858] libphy: mdio: probed
[    0.657158] usbcore: registered new interface driver usb-storage
[    0.660204] usbcore: registered new interface driver usb_ehset_test
[    0.663728] i2c /dev entries driver
[    0.665698] pps_ldisc: PPS line discipline registered
[    0.669956] Synopsys Designware Multimedia Card Interface Driver
[    0.673540] dw_mmc ff704000.dwmmc0: IDMAC supports 32-bit address mode.
[    0.676921] dw_mmc ff704000.dwmmc0: Using internal DMA controller.
[    0.680015] dw_mmc ff704000.dwmmc0: Version ID is 240a
[    0.682663] dw_mmc ff704000.dwmmc0: DW MMC controller at irq 35,32 bit host data width,1024 deep fifo
[    0.687662] mmc_host mmc0: card is polling.
[    0.701509] mmc_host mmc0: Bus speed (slot 0) = 50000000Hz (slot req 400000Hz, actual 396825HZ div = 63)
[    0.720461] ledtrig-cpu: registered to indicate activity on CPUs
[    0.723702] usbcore: registered new interface driver usbhid
[    0.726538] usbhid: USB HID core driver
[    0.730048] fpga_manager fpga0: Altera SOCFPGA FPGA Manager registered
[    0.734028] altera_hps2fpga_bridge ff400000.fpga_bridge: fpga bridge [lwhps2fpga] registered
[    0.738663] altera_hps2fpga_bridge ff500000.fpga_bridge: fpga bridge [hps2fpga] registered
[    0.744004] brd_rev brdid-core: brd_rev_drv_probe: brd_rev bits 4
[    0.747412] brd_rev brdid-core: brd_rev_drv_probe: loaded dev (ptrval)
[    0.750814] brd_rev brdid-main: brd_rev_drv_probe: brd_rev bits 4
[    0.754266] buzzer ff205000.audio: emit_probe: pd (ptrval) d (ptrval) p (ptrval)
[    0.758022] buzzer ff205000.audio: emit_probe: pnode:   (null)
[    0.760990] buzzer ff205000.audio: emit_probe: label: buzzer
[    0.764025] input: ff205000.audio as /devices/platform/soc/c0000000.bridge/ff205000.audio/input/input0
[    0.769039] buzzer ff205000.audio: emit_drv_probe_alloc: (ptrval),132 (ptrval),8
[    0.772794] buzzer ff205000.audio: emit_drv_probe_alloc: - successfully registered
[    0.776997] fbtft_of_value: buswidth = 8
[    0.778962] fbtft_of_value: debug = 3
[    0.780794] fbtft_of_value: rotate = 0
[    0.782872] fb_ra8835 ff20a000.unknown: fbtft_request_one_gpio: 'reset-gpios' = GPIO2020
[    0.787001] fb_ra8835 ff20a000.unknown: fbtft_request_one_gpio: 'aux-gpios' = GPIO2021
[    0.791310] fb_ra8835 ff20a000.unknown: ra_verify_gpios()
[    0.794105] fb_ra8835 ff20a000.unknown: ra_verify_gpios() failed getting backlight / contrast
[    0.798866] fpgaver ff209000.fpga_version: emit_probe: pd (ptrval) d (ptrval) p (ptrval)
[    0.802978] fpgaver ff209000.fpga_version: emit_probe: pnode:   (null)
[    0.806286] fpgaver ff209000.fpga_version: emit_probe: label: fpga_version
[    0.809941] fpgaver ff209000.fpga_version: emit_drv_probe_alloc: (ptrval),128 (ptrval),128
[    0.814137] fpgaver ff209000.fpga_version: emit_drv_probe_alloc: - successfully registered
[    0.818822] sync_ctl ff210000.SyncCtl: emit_probe: pd (ptrval) d (ptrval) p (ptrval)
[    0.822770] sync_ctl ff210000.SyncCtl: emit_probe: pnode:   (null)
[    0.825920] sync_ctl ff210000.SyncCtl: emit_probe: label: sync
[    0.828999] mmc_host mmc0: Bus speed (slot 0) = 50000000Hz (slot req 50000000Hz, actual 50000000HZ div = 0)
[    0.833947] mmc0: new high speed SDXC card at address e624
[    0.837638] oprofile: using arm/armv7-ca9
[    0.837747] mmcblk0: mmc0:e624 SP64G 59.5 GiB
[    0.840603] NET: Registered protocol family 10
[    0.847375]  mmcblk0: p1 p2 p3 p4
[    0.850577] Segment Routing with IPv6
[    0.852580] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[    0.856145] NET: Registered protocol family 17
[    0.858417] NET: Registered protocol family 15
[    0.861025] can: controller area network core (rev 20170425 abi 9)
[    0.864218] NET: Registered protocol family 29
[    0.866444] can: raw protocol (rev 20170425)
[    0.868601] can: broadcast manager protocol (rev 20170425 t)
[    0.871434] can: netlink gateway (rev 20170425) max_hops=1
[    0.874393] 8021q: 802.1Q VLAN Support v1.8
[    0.876556] Key type dns_resolver registered
[    0.878800] ThumbEE CPU extension supported.
[    0.880941] Registering SWP/SWPB emulation handler
[    0.884022] registered taskstats version 1
[    0.886070] Loading compiled-in X.509 certificates
[    0.892909] i2c_designware ffc04000.i2c: running with gpio recovery mode! scl,sda
[    0.899653] at24 3-0050: 256 byte 24c02 EEPROM, writable, 8 bytes/write
[    0.903314] ad7418 3-0028: ad7417 chip found
[    0.905593] ad7418 3-0028: configuring for mode 1
[    0.908371] i2c i2c-2: Added multiplexed i2c bus 3
[    0.911403] pca953x 4-0020: 4-0020 supply vcc not found, using dummy regulator
[    0.915952] pca953x 4-0020: interrupt support not compiled in
[    0.919226] pca953x 4-0049: 4-0049 supply vcc not found, using dummy regulator
[    0.923581] pca953x 4-0049: interrupt support not compiled in
[    0.926844] pca953x 4-0041: 4-0041 supply vcc not found, using dummy regulator
[    0.933727] rtc-ds3232 4-0068: rtc core: registered ds3232 as rtc0
[    0.937742] at24 4-0050: 8192 byte 24c64 EEPROM, writable, 32 bytes/write
[    0.941447] ad7418 4-002b: ad7417 chip found
[    0.943757] ad7418 4-002b: configuring for mode 1
[    0.946757] ad7418 4-002e: ad7417 chip found
[    0.949033] ad7418 4-002e: configuring for mode 1
[    0.957432] leds-pca953x 4-0060: setting platform data
[    0.963754] i2c i2c-2: Added multiplexed i2c bus 4
[    0.966155] pca954x 2-0070: registered 2 multiplexed busses for I2C mux pca9540
[    2.001499] i2c_designware ffc06000.i2c: controller timed out
[    2.004380] pca954x 5-0070: probe failed
[    2.007502] mv88e6085 stmmac-0:00: switch 0x3520 detected: Marvell 88E6352, revision 1
[    2.020089] libphy: mdio: probed
[    2.445551] Marvell 88E1540 !soc!ethernet@ff702000!mdio!switch0@0!mdio:02: attached PHY driver [Marvell 88E1540] (mii_bus:phy_addr=!soc!ethernet@ff702000!mdio!switch0@0!mdio:02, irq=124)
[    2.544969] Marvell 88E1540 !soc!ethernet@ff702000!mdio!switch0@0!mdio:03: attached PHY driver [Marvell 88E1540] (mii_bus:phy_addr=!soc!ethernet@ff702000!mdio!switch0@0!mdio:03, irq=125)
[    2.646628] Marvell 88E1540 !soc!ethernet@ff702000!mdio!switch0@0!mdio:04: attached PHY driver [Marvell 88E1540] (mii_bus:phy_addr=!soc!ethernet@ff702000!mdio!switch0@0!mdio:04, irq=126)
[    2.656065] Generic PHY fixed-0:01: attached PHY driver [Generic PHY] (mii_bus:phy_addr=fixed-0:01, irq=POLL)
[    2.663183] DSA: tree 0 setup
[    2.665587] brd_rev brdid-main: brd_rev_drv_probe: brd_rev bits 4
[    2.669854] brd_rev brdid-main: brd_rev_drv_probe: loaded dev (ptrval)
[    2.673385] fb_ra8835 ff20a000.unknown: fbtft_probe_common()
[    2.676218] fbtft_of_value: buswidth = 8
[    2.678206] fbtft_of_value: debug = 3
[    2.680038] fbtft_of_value: rotate = 0
[    2.682110] fb_ra8835 ff20a000.unknown: fbtft_request_one_gpio: 'reset-gpios' = GPIO2020
[    2.686191] fb_ra8835 ff20a000.unknown: fbtft_request_one_gpio: 'aux-gpios' = GPIO2021
[    2.690438] fb_ra8835 ff20a000.unknown: ra_verify_gpios()
[    2.693213] fb_ra8835 ff20a000.unknown: ra_verify_gpios() setting backlight / contrast
[    2.697483] fb_ra8835 ff20a000.unknown: +ra_init_display()
[    2.700226] fb_ra8835 ff20a000.unknown: fbtft_reset()
[    2.836457] fb_ra8835 ff20a000.unknown: -ra_init_display()
[    2.844763] fb_ra8835 ff20a000.unknown: Display update: 27114 kB/s, fps=0
[    2.848170] fb_ra8835 ff20a000.unknown: ra_bl_reg
[    2.850954] graphics fb0: fb_ra8835 frame buffer, 320x240, 150 KiB video memory, 9 KiB buffer memory, fps=20
[    2.855887] fb_ra8835 ff20a000.unknown: ra_bl_update_status: brightness=0, power=0, fb_blank=0
[    2.860579] sync_ctl ff210000.SyncCtl: emit_probe: pd (ptrval) d (ptrval) p (ptrval)
[    2.864478] sync_ctl ff210000.SyncCtl: emit_probe: pnode:   (null)
[    2.867611] sync_ctl ff210000.SyncCtl: emit_probe: label: sync
[    2.870758] pps pps0: new PPS source pps_out
[    2.873062] pps pps1: new PPS source pps_gps
[    2.875334] pps pps2: new PPS source pps_net
[    2.877643] pps pps3: new PPS source pps_ptp
[    2.879910] pps pps4: new PPS source hw_pps_gps
[    2.882346] pps pps5: new PPS source hw_pps_net
[    2.884762] pps pps6: new PPS source hw_pps_ptp
[    2.887055] sync_ctl ff210000.SyncCtl: posix_clock_register 0
[    2.890612] sync_ctl ff210000.SyncCtl: emit_drv_probe_alloc: (ptrval),304 (ptrval),64
[    2.894546] sync_ctl ff210000.SyncCtl: emit_drv_probe_alloc: - successfully registered
[    2.977259] random: fast init done
[    2.979776] i2c i2c-7: supports SMBALERT#
[    2.983508] sbs-battery 8-000b: Failed to get gpio: -517
[    2.986251] i2c i2c-7: Added multiplexed i2c bus 8
[    2.989282] sbs-battery 9-000b: Failed to get gpio: -517
[    2.992046] i2c i2c-7: Added multiplexed i2c bus 9
[    2.996002] i2c i2c-1: Added multiplexed i2c bus 7
[    2.999067][    3.241279] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    3.245395] VFS: Mounted root (ext4 filesystem) on device 179:2.
[    3.253501] devtmpfs: mounted
[    3.257901] Freeing unused kernel memory: 1024K
[    3.526682] systemd[1]: System time before build time, advancing clock.
[    3.563800] systemd[1]: systemd 237 running in system mode. (+PAM -AUDIT -SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP -LIBCRYPTSETUP -GCRYPT +GNUTLS +ACL -XZ +LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN2 -IDN -PCRE2 default-hierarchy=hybrid)
[    3.574916] systemd[1]: Detected architecture arm.
[    3.599055] systemd[1]: Set hostname to <cyclone5>.
[    3.781111] systemd[1]: File /lib/systemd/system/systemd-journald.service:35 configures an IP firewall (IPAddressDeny=any), but the local system does not support BPF/cgroup based firewalling.
[    3.789695] systemd[1]: Proceeding WITHOUT firewalling in effect! (This warning is only shown for the first loaded unit using IP firewalling.)
[    3.963147] random: systemd: uninitialized urandom read (16 bytes read)
[    3.967023] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    3.986691] random: systemd: uninitialized urandom read (16 bytes read)
[    3.990062] systemd[1]: Reached target Remote File Systems.
[    4.006681] random: systemd: uninitialized urandom read (16 bytes read)
[    4.010539] systemd[1]: Created slice System Slice.
[    4.027245] systemd[1]: Listening on Network Service Netlink Socket.
[    4.042028] systemd[1]: Listening on udev Kernel Socket.
[    4.268129] EXT4-fs (mmcblk0p2): re-mounted. Opts: discard
[    5.367398] systemd-journald[125]: Received request to flush runtime journal from PID 1
[    5.391349] systemd-journald[125]: File /var/log/journal/40939e1875134e14a7865de4bc8a14a8/system.journal corrupted or uncleanly shut down, renaming and replacing.
[    7.385312] input: gpio-keys as /devices/platform/gpio-keys/input/input1
[    7.580809] Generic PHY fixed-0:00: attached PHY driver [Generic PHY] (mii_bus:phy_addr=fixed-0:00, irq=POLL)
[    7.585996] dwc2 ffb40000.usb: ffb40000.usb supply vusb_d not found, using dummy regulator
[    7.627584] dwc2 ffb40000.usb: ffb40000.usb supply vusb_a not found, using dummy regulator
[    7.650912] dwc2 ffb40000.usb: Configuration mismatch. dr_mode forced to host
[    7.655085] socfpga-dwmac ff702000.ethernet eth0: registered PTP clock
[    7.661249] dwc2 ffb40000.usb: dwc2_check_params: Invalid parameter lpm=1
[    7.671634] dwc2 ffb40000.usb: dwc2_check_params: Invalid parameter lpm_clock_gating=1
[    7.681948] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[    7.688335] dwc2 ffb40000.usb: dwc2_check_params: Invalid parameter besl=1
[    7.707838] dwc2 ffb40000.usb: dwc2_check_params: Invalid parameter hird_threshold_en=1
[    7.714863] dwc2 ffb40000.usb: DWC OTG Controller
[    7.715178] dwc2 ffb40000.usb: new USB bus registered, assigned bus number 1
[    7.715224] dwc2 ffb40000.usb: irq 45, io mem 0xffb40000
[    7.715563] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.17
[    7.715573] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    7.715580] usb usb1: Product: DWC OTG Controller
[    7.715586] usb usb1: Manufacturer: Linux 4.17.0-00149-g192a335 dwc2_hsotg
[    7.715592] usb usb1: SerialNumber: ffb40000.usb
[    7.716285] hub 1-0:1.0: USB hub found
[    7.716338] hub 1-0:1.0: 1 port detected
[    8.074915] fb_ra8835 ff20a000.unknown: ra_bl_update_status: brightness=204, power=0, fb_blank=0
[    8.721555] socfpga-dwmac ff702000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off
[    8.725786] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[    8.743355] IPv6: ADDRCONF(NETDEV_UP): wifi: link is not ready
[    8.749725] IPv6: ADDRCONF(NETDEV_UP): lan3: link is not ready
[    8.768064] IPv6: ADDRCONF(NETDEV_UP): lan1: link is not ready
[    8.773565] IPv6: ADDRCONF(NETDEV_UP): lan2: link is not ready
[    8.994879] mv88e6085 stmmac-0:00 lan2: Link is Down
[    9.761627] IPv6: ADDRCONF(NETDEV_CHANGE): wifi: link becomes ready
[    9.766229] mv88e6085 stmmac-0:00 wifi: Link is Up - 100Mbps/Full - flow control off
[   11.934354] mv88e6085 stmmac-0:00 lan2: Link is Up - 1Gbps/Full - flow control rx/tx
[   11.938267] IPv6: ADDRCONF(NETDEV_CHANGE): lan2: link becomes ready
[   39.153512] random: crng init done
[   39.155228] random: 7 urandom warning(s) missed due to ratelimiting
[  141.811511] usb 1-1: new full-speed USB device number 2 using dwc2
[  142.001509] usb 1-1: device descriptor read/64, error -71
[  142.373525] usb 1-1: New USB device found, idVendor=0a12, idProduct=0001, bcdDevice=88.91
[  142.377642] usb 1-1: New USB device strings: Mfr=0, Product=2, SerialNumber=0
[  142.381204] usb 1-1: Product: CSR8510 A10
[  142.724485] Bluetooth: Core ver 2.22
[  142.726384] NET: Registered protocol family 31
[  142.729838] Bluetooth: HCI device and connection manager initialized
[  142.733199] Bluetooth: HCI socket layer initialized
[  142.735649] Bluetooth: L2CAP socket layer initialized
[  142.738395] Bluetooth: SCO socket layer initialized
[  142.818233] usbcore: registered new interface driver btusb
[  143.004182] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[  143.007009] Bluetooth: BNEP filters: protocol multicast
[  143.009670] Bluetooth: BNEP socket layer initialized
[  145.046503] Bluetooth: hci0: command 0x1002 tx timeout
[  147.086503] Bluetooth: hci0: command 0x0c52 tx timeout
[  149.121499] Bluetooth: hci0: command 0x0c45 tx timeout
[  151.166503] Bluetooth: hci0: command 0x0c58 tx timeout
[  153.201501] Bluetooth: hci0: command tx timeout