raspberrypi / firmware

This repository contains pre-compiled binaries of the current Raspberry Pi kernel and modules, userspace libraries, and bootloader/GPU firmware.
5.15k stars 1.68k forks source link

brcmf_sdio_hostmail: mailbox indicates firmware halted (not running as AP, can reproduce, need help debugging) #1480

Open tayl opened 3 years ago

tayl commented 3 years ago

Hello,

Describe the bug Raspberry Pi 3B+ wireless connection hangs or fails to connect initially to wireless network. We have reason to believe the issue is caused by environmental factors. Specifically, this is only happening at one site, although the firmware and versions involved are the same.

To reproduce We have thousands of deployed devices, a specific subset of which in the same physical space experience this issue regularly. I have remote access to the devices, and can typically reproduce the issue in less than 30 minutes on at least one device. I'm just not sure how to grab relevant/useful information about what's going on.

Expected behaviour Raspberry Pi connects to wireless network and remains connected.

Actual behaviour Raspberry Pi frequently fails to connect to wireless network and does not remain connected once a connection is established.

System

Logs Two scenarios: scenario (1) is when the device starts up but is not able to connect to wifi right off the bat, scenario (2) is where the device has started up and is connected to wifi but some random time later experiences an issue that causes it to disconnect.

scenario (1):

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.19.66-v7+ (dom@buildbot) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1253 SMP Thu Aug 15 11:49:46 BST 2019
... startup ...
[   21.113271] brcmfmac: brcmf_sdio_hostmail: mailbox indicates firmware halted
[   30.391838] brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
[   30.392228] brcmfmac: brcmf_sdio_checkdied: firmware trap in dongle
[   30.392243] brcmfmac: brcmf_cfg80211_disconnect: error (-110)
[   32.951849] brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
[   32.952253] brcmfmac: brcmf_sdio_checkdied: firmware trap in dongle
[   32.952267] brcmfmac: brcmf_cfg80211_reg_notifier: Country code iovar returned err = -110
[   35.511841] brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
[   35.512226] brcmfmac: brcmf_sdio_checkdied: firmware trap in dongle
[   35.512240] brcmfmac: brcmf_run_escan: error (-110)
[   35.512250] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[   39.031855] brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
[   39.032273] brcmfmac: brcmf_sdio_checkdied: firmware trap in dongle
... repeats ...
[  156.872283] brcmfmac: brcmf_run_escan: error (-110)
[  156.872293] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[  160.391888] brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
[  160.392286] brcmfmac: brcmf_sdio_checkdied: firmware trap in dongle
[  160.392302] brcmfmac: brcmf_run_escan: error (-110)
[  160.392312] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[  163.911885] brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
[  163.912282] brcmfmac: brcmf_sdio_checkdied: firmware trap in dongle
[  163.912297] brcmfmac: brcmf_run_escan: error (-110)
[  163.912307] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[  167.431888] brcmfmac: brcmf_run_escan: error (-110)
[  167.431905] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
... repeats ...
[  649.671927] brcmfmac: brcmf_run_escan: error (-110)
[  649.671945] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[  653.191915] brcmfmac: brcmf_run_escan: error (-110)
[  653.191931] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
... device reboots intentionally

scenario (2):

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.19.66-v7+ (dom@buildbot) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1253 SMP Thu Aug 15 11:49:46 BST 2019
... startup ...
[86412.014522] brcmfmac: brcmf_sdio_hostmail: mailbox indicates firmware halted
[86420.334042] brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
[86420.334450] brcmfmac: brcmf_sdio_checkdied: firmware trap in dongle
[86420.334466] brcmfmac: brcmf_cfg80211_disconnect: error (-110)
[86422.894019] brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
[86422.894365] brcmfmac: brcmf_sdio_checkdied: firmware trap in dongle
[86422.894380] brcmfmac: brcmf_cfg80211_reg_notifier: Country code iovar returned err = -110
[86425.454051] brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
[86425.454469] brcmfmac: brcmf_sdio_checkdied: firmware trap in dongle
[86425.454484] brcmfmac: brcmf_run_escan: error (-110)
[86425.454494] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
... repeats ...
[86548.334564] brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
[86548.334959] brcmfmac: brcmf_sdio_checkdied: firmware trap in dongle
[86548.334974] brcmfmac: brcmf_run_escan: error (-110)
[86548.334984] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[86551.854583] brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
[86551.855037] brcmfmac: brcmf_sdio_checkdied: firmware trap in dongle
[86551.855052] brcmfmac: brcmf_run_escan: error (-110)
[86551.855062] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[86555.374613] brcmfmac: brcmf_run_escan: error (-110)
[86555.374628] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[86558.894623] brcmfmac: brcmf_run_escan: error (-110)
[86558.894640] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[86562.414630] brcmfmac: brcmf_run_escan: error (-110)
[86562.414645] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[86565.934642] brcmfmac: brcmf_run_escan: error (-110)
[86565.934658] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[86569.454675] brcmfmac: brcmf_run_escan: error (-110)
[86569.454691] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[86572.094669] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
[86572.094687] brcmfmac: brcmf_cfg80211_get_tx_power: error (-110)
[86574.654657] brcmfmac: brcmf_run_escan: error (-110)
[86574.654666] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[86578.174721] brcmfmac: brcmf_run_escan: error (-110)
[86578.174737] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
... repeats ...
[86627.454926] brcmfmac: brcmf_run_escan: error (-110)
[86627.454944] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[86630.974950] brcmfmac: brcmf_run_escan: error (-110)
[86630.974967] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[86633.534958] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
[86633.534991] brcmfmac: brcmf_cfg80211_get_tx_power: error (-110)
[86636.094960] brcmfmac: brcmf_run_escan: error (-110)
[86636.094976] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[86639.614998] brcmfmac: brcmf_run_escan: error (-110)
[86639.615014] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
... repeats ...
[87227.457787] brcmfmac: brcmf_run_escan: error (-110)
[87227.457802] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
[87230.977790] brcmfmac: brcmf_run_escan: error (-110)
[87230.977807] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
... device reboots intentionally

Additional context Possibly relevant is that the devices are using Cisco 3602 APs. The area is somewhat wirelessly congested, but no more than we see elsewhere so I don't believe that to be relevant.

tayl commented 3 years ago

Just noting.. I've seen similar issues reported, but all seem to be related to using the Raspberry Pi as an access point of some sort. In this scenario, we're only connecting to wireless networks. I believe for that reason that this is a fundamentally different issue although the generic output seen is the same or similar.

pelwell commented 3 years ago

Can you retest with brcmfmac.debug=0x100000 in /boot/cmdline.txt (keep everything in a single line)? The firmware should log debug into the kernel log, including details of the crash.

tayl commented 3 years ago

pelwell,

I put that in the cmdline.txt file and see it reflected in the dmesg output, but I don't see any additional debug information here. Should I be looking elsewhere?

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.19.66-v7+ (dom@buildbot) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1253 SMP Thu Aug 15 11:49:46 BST 2019
[    0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi 3 Model B Plus Rev 1.3
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] cma: Reserved 8 MiB at 0x3ac00000
[    0.000000] On node 0 totalpages: 242688
[    0.000000]   Normal zone: 2133 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 242688 pages, LIFO batch:63
[    0.000000] random: get_random_bytes called from start_kernel+0xac/0x4b4 with crng_init=0
[    0.000000] percpu: Embedded 17 pages/cpu s39488 r8192 d21952 u69632
[    0.000000] pcpu-alloc: s39488 r8192 d21952 u69632 alloc=17*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 240555
[    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  dwc_otg.lpm_enable=0 console=ttyS0,115200 console=tty1 root=PARTUUID=89c0edae-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait brcmfmac.debug=0x100000
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Memory: 939084K/970752K available (8192K kernel code, 629K rwdata, 2176K rodata, 1024K init, 821K bss, 23476K reserved, 8192K cma-reserved)
[    0.000000] Virtual kernel memory layout:
                   vector  : 0xffff0000 - 0xffff1000   (   4 kB)
                   fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
                   vmalloc : 0xbb800000 - 0xff800000   (1088 MB)
                   lowmem  : 0x80000000 - 0xbb400000   ( 948 MB)
                   modules : 0x7f000000 - 0x80000000   (  16 MB)
                     .text : 0x(ptrval) - 0x(ptrval)   (9184 kB)
                     .init : 0x(ptrval) - 0x(ptrval)   (1024 kB)
                     .data : 0x(ptrval) - 0x(ptrval)   ( 630 kB)
                      .bss : 0x(ptrval) - 0x(ptrval)   ( 822 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 26394 entries in 78 pages
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] arch_timer: cp15 timer(s) running at 19.20MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[    0.000007] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[    0.000023] Switching to timer-based delay loop, resolution 52ns
[    0.000291] Console: colour dummy device 80x30
[    0.000917] console [tty1] enabled
[    0.000975] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[    0.001020] pid_max: default: 32768 minimum: 301
[    0.001377] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.001412] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.002345] CPU: Testing write buffer coherency: ok
[    0.002831] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.003499] Setting up static identity map for 0x100000 - 0x10003c
[    0.003666] rcu: Hierarchical SRCU implementation.
[    0.004482] smp: Bringing up secondary CPUs ...
[    0.005344] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.006273] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.007137] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.007258] smp: Brought up 1 node, 4 CPUs
[    0.007340] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[    0.007364] CPU: All CPU(s) started in HYP mode.
[    0.007384] CPU: Virtualization extensions available.
[    0.008377] devtmpfs: initialized
[    0.021693] VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4
[    0.021969] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.022018] futex hash table entries: 1024 (order: 4, 65536 bytes)
[    0.022626] pinctrl core: initialized pinctrl subsystem
[    0.023501] NET: Registered protocol family 16
[    0.026530] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.032277] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.032314] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.032541] Serial: AMBA PL011 UART driver
[    0.034990] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
[    0.070250] bcm2835-dma 3f007000.dma: DMA legacy API manager at (ptrval), dmachans=0x1
[    0.071938] SCSI subsystem initialized
[    0.072182] usbcore: registered new interface driver usbfs
[    0.072258] usbcore: registered new interface driver hub
[    0.072374] usbcore: registered new device driver usb
[    0.090299] raspberrypi-firmware soc:firmware: Attached to firmware from 2019-08-15 12:06, variant start
[    0.100122] raspberrypi-firmware soc:firmware: Firmware hash is 0e6daa5106dd4164474616408e0dc24f997ffcf3
[    0.111849] clocksource: Switched to clocksource arch_sys_counter
[    0.200928] VFS: Disk quotas dquot_6.6.0
[    0.201040] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.201249] FS-Cache: Loaded
[    0.201477] CacheFiles: Loaded
[    0.211558] NET: Registered protocol family 2
[    0.212378] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes)
[    0.212443] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[    0.212573] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[    0.212777] TCP: Hash tables configured (established 8192 bind 8192)
[    0.212930] UDP hash table entries: 512 (order: 2, 16384 bytes)
[    0.212996] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[    0.213326] NET: Registered protocol family 1
[    0.213930] RPC: Registered named UNIX socket transport module.
[    0.213958] RPC: Registered udp transport module.
[    0.213980] RPC: Registered tcp transport module.
[    0.214001] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.215697] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available
[    0.218743] Initialise system trusted keyrings
[    0.218960] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[    0.228956] FS-Cache: Netfs 'nfs' registered for caching
[    0.229543] NFS: Registering the id_resolver key type
[    0.229589] Key type id_resolver registered
[    0.229611] Key type id_legacy registered
[    0.229643] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    0.231989] Key type asymmetric registered
[    0.232019] Asymmetric key parser 'x509' registered
[    0.232093] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)
[    0.232279] io scheduler noop registered
[    0.232304] io scheduler deadline registered (default)
[    0.232507] io scheduler cfq registered
[    0.232531] io scheduler mq-deadline registered (default)
[    0.232555] io scheduler kyber registered
[    0.234752] bcm2708_fb soc:fb: FB found 1 display(s)
[    0.244035] Console: switching to colour frame buffer device 82x26
[    0.250849] bcm2708_fb soc:fb: Registered framebuffer for display 0, size 656x416
[    0.257614] bcm2835-rng 3f104000.rng: hwrng registered
[    0.260298] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[    0.265636] vc-sm: Videocore shared memory driver
[    0.268386] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000
[    0.284256] brd: module loaded
[    0.296942] loop: module loaded
[    0.299992] Loading iSCSI transport class v2.0-870.
[    0.303181] libphy: Fixed MDIO Bus: probed
[    0.305695] usbcore: registered new interface driver lan78xx
[    0.308150] usbcore: registered new interface driver smsc95xx
[    0.310501] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    0.340767] dwc_otg 3f980000.usb: base=(ptrval)
[    0.543416] Core Release: 2.80a
[    0.545794] Setting default values for core params
[    0.548238] Finished setting default values for core params
[    0.750983] Using Buffer DMA mode
[    0.753390] Periodic Transfer Interrupt Enhancement - disabled
[    0.755815] Multiprocessor Interrupt Enhancement - disabled
[    0.758187] OTG VER PARAM: 0, OTG VER FLAG: 0
[    0.760528] Dedicated Tx FIFOs mode
[    0.763258] WARN::dwc_otg_hcd_init:1045: FIQ DMA bounce buffers: virt = bad14000 dma = 0xfad14000 len=9024
[    0.767828] FIQ FSM acceleration enabled for :
               Non-periodic Split Transactions
               Periodic Split Transactions
               High-Speed Isochronous Endpoints
               Interrupt/Control Split Transaction hack enabled
[    0.778741] dwc_otg: Microframe scheduler enabled
[    0.778800] WARN::hcd_init_fiq:457: FIQ on core 1
[    0.781031] WARN::hcd_init_fiq:458: FIQ ASM at 80654f4c length 36
[    0.783247] WARN::hcd_init_fiq:497: MPHI regs_base at bb810000
[    0.785507] dwc_otg 3f980000.usb: DWC OTG Controller
[    0.787767] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
[    0.790087] dwc_otg 3f980000.usb: irq 56, io mem 0x00000000
[    0.792410] Init: Port Power? op_state=1
[    0.794645] Init: Power Port (0)
[    0.797056] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
[    0.801549] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.803975] usb usb1: Product: DWC OTG Controller
[    0.806336] usb usb1: Manufacturer: Linux 4.19.66-v7+ dwc_otg_hcd
[    0.808750] usb usb1: SerialNumber: 3f980000.usb
[    0.811691] hub 1-0:1.0: USB hub found
[    0.813990] hub 1-0:1.0: 1 port detected
[    0.816736] dwc_otg: FIQ enabled
[    0.816742] dwc_otg: NAK holdoff enabled
[    0.816748] dwc_otg: FIQ split-transaction FSM enabled
[    0.816758] Module dwc_common_port init
[    0.817026] usbcore: registered new interface driver usb-storage
[    0.819474] mousedev: PS/2 mouse device common for all mice
[    0.822652] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[    0.825268] bcm2835-cpufreq: min=600000 max=1400000
[    0.828091] sdhci: Secure Digital Host Controller Interface driver
[    0.830498] sdhci: Copyright(c) Pierre Ossman
[    0.833296] mmc-bcm2835 3f300000.mmcnr: could not get clk, deferring probe
[    0.836197] sdhost-bcm2835 3f202000.mmc: could not get clk, deferring probe
[    0.838866] sdhci-pltfm: SDHCI platform and OF driver helper
[    0.842991] ledtrig-cpu: registered to indicate activity on CPUs
[    0.845720] hidraw: raw HID events driver (C) Jiri Kosina
[    0.848489] usbcore: registered new interface driver usbhid
[    0.851119] usbhid: USB HID core driver
[    0.854463] vchiq: vchiq_init_state: slot_zero = (ptrval), is_master = 0
[    0.858572] [vc_sm_connected_init]: start
[    0.867360] [vc_sm_connected_init]: end - returning 0
[    0.870893] Initializing XFRM netlink socket
[    0.873361] NET: Registered protocol family 17
[    0.875869] Key type dns_resolver registered
[    0.878757] Registering SWP/SWPB emulation handler
[    0.881885] registered taskstats version 1
[    0.884293] Loading compiled-in X.509 certificates
[    0.893943] uart-pl011 3f201000.serial: cts_event_workaround enabled
[    0.896469] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 81, base_baud = 0) is a PL011 rev2
[    0.903269] mmc-bcm2835 3f300000.mmcnr: mmc_debug:0 mmc_debug2:0
[    0.905804] mmc-bcm2835 3f300000.mmcnr: DMA channel allocated
[    0.934429] sdhost: log_buf @ (ptrval) (fad13000)
[    0.973150] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[    0.977114] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    0.980972] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    0.983210] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[    0.986684] of_cfs_init
[    0.988931] of_cfs_init: OK
[    0.991552] Waiting for root device PARTUUID=89c0edae-02...
[    1.007776] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[    1.031971] Indeed it is in host mode hprt0 = 00021501
[    1.101229] mmc0: host does not support reading read-only switch, assuming write-enable
[    1.105256] random: fast init done
[    1.108930] mmc0: new high speed SDHC card at address 0001
[    1.112498] mmcblk0: mmc0:0001 EB1QT 29.8 GiB
[    1.117295]  mmcblk0: p1 p2
[    1.146571] mmc1: new high speed SDIO card at address 0001
[    1.155832] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    1.160245] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    1.172484] devtmpfs: mounted
[    1.180086] Freeing unused kernel memory: 1024K
[    1.222258] Run /sbin/init as init process
[    1.241892] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    1.244545] Indeed it is in host mode hprt0 = 00001101
[    1.482189] usb 1-1: New USB device found, idVendor=0424, idProduct=2514, bcdDevice= b.b3
[    1.487427] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    1.490904] hub 1-1:1.0: USB hub found
[    1.493789] hub 1-1:1.0: 4 ports detected
[    1.811896] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    1.872221] systemd[1]: System time before build time, advancing clock.
[    1.942182] usb 1-1.1: New USB device found, idVendor=0424, idProduct=2514, bcdDevice= b.b3
[    1.947671] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    1.951245] hub 1-1.1:1.0: USB hub found
[    1.954296] hub 1-1.1:1.0: 3 ports detected
[    2.004573] NET: Registered protocol family 10
[    2.008660] Segment Routing with IPv6
[    2.050081] systemd[1]: systemd 241 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)
[    2.059462] systemd[1]: Detected architecture arm.
[    2.085465] systemd[1]: Set hostname to <abc>.
[    2.101312] systemd[1]: Failed to bump fs.file-max, ignoring: Invalid argument
[    2.310155] dwc_otg_handle_wakeup_detected_intr lxstate = 2
[    2.449132] systemd[1]: File /lib/systemd/system/systemd-journald.service:12 configures an IP firewall (IPAddressDeny=any), but the local system does not support BPF/cgroup based firewalling.
[    2.457826] systemd[1]: Proceeding WITHOUT firewalling in effect! (This warning is only shown for the first loaded unit using IP firewalling.)
[    2.831931] usb 1-1.1.1: new high-speed USB device number 4 using dwc_otg
[    2.962361] usb 1-1.1.1: New USB device found, idVendor=0424, idProduct=7800, bcdDevice= 3.00
[    2.968202] usb 1-1.1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    2.970667] random: systemd: uninitialized urandom read (16 bytes read)
[    2.989259] random: systemd: uninitialized urandom read (16 bytes read)
[    2.993102] systemd[1]: Listening on fsck to fsckd communication Socket.
[    3.000237] random: systemd: uninitialized urandom read (16 bytes read)
[    3.003709] systemd[1]: Listening on initctl Compatibility Named Pipe.
[    3.011508] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[    3.049883] systemd[1]: Condition check resulted in Journal Audit Socket being skipped.
[    3.246888] lan78xx 1-1.1.1:1.0 (unnamed net_device) (uninitialized): No External EEPROM. Setting MAC Speed
[    3.254971] libphy: lan78xx-mdiobus: probed
[    3.288565] lan78xx 1-1.1.1:1.0 (unnamed net_device) (uninitialized): int urb period 64
[    3.894054] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    4.046645] systemd-journald[102]: Received request to flush runtime journal from PID 1
[    5.037032] media: Linux media interface: v0.10
[    5.068517] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    5.071127] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[    5.071142] [vc_sm_connected_init]: start
[    5.074011] [vc_sm_connected_init]: installed successfully
[    5.086816] videodev: Linux video capture interface: v2.00
[    5.160401] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    5.161054] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    5.201230] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
[    5.210687] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
[    5.220455] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
[    5.227995] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
[    5.228010] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
[    5.230285] bcm2835_audio soc:audio: card created with 8 channels
[    5.238153] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
[    5.238169] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
[    5.245741] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
[    5.245755] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
[    5.351429] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    5.467779] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    5.558824] brcmfmac: F1 signature read @0x18000000=0x15264345
[    5.568749] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    5.569656] usbcore: registered new interface driver brcmfmac
[    5.773637] random: crng init done
[    5.773655] random: 7 urandom warning(s) missed due to ratelimiting
[    5.789934] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    5.821562] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Feb 27 2018 03:15:32 version 7.45.154 (r684107 CY) FWID 01-4fbe0b04
[    7.315683] uart-pl011 3f201000.serial: no DMA platform data
[    7.467831] 8021q: 802.1Q VLAN Support v1.8
[    7.745106] Adding 102396k swap on /var/swap.  Priority:-2 extents:1 across:102396k SSFS
[    7.786489] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[    7.786508] brcmfmac: power management disabled
[    8.048553] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[    8.048561] 8021q: adding VLAN 0 to HW filter on device eth0
[   14.110724] Bluetooth: Core ver 2.22
[   14.110820] NET: Registered protocol family 31
[   14.110828] Bluetooth: HCI device and connection manager initialized
[   14.110850] Bluetooth: HCI socket layer initialized
[   14.110864] Bluetooth: L2CAP socket layer initialized
[   14.110904] Bluetooth: SCO socket layer initialized
[   14.129679] Bluetooth: HCI UART driver ver 2.3
[   14.129694] Bluetooth: HCI UART protocol H4 registered
[   14.129813] Bluetooth: HCI UART protocol Three-wire (H5) registered
[   14.130053] Bluetooth: HCI UART protocol Broadcom registered
[   14.387429] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[   14.387435] Bluetooth: BNEP filters: protocol multicast
[   14.387450] Bluetooth: BNEP socket layer initialized
[   23.082157] brcmfmac: brcmf_sdio_hostmail: mailbox indicates firmware halted
[   31.271902] brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
[   31.272284] brcmfmac: brcmf_sdio_checkdied: firmware trap in dongle
[   31.272297] brcmfmac: brcmf_cfg80211_disconnect: error (-110)
[   33.831910] brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
[   33.832284] brcmfmac: brcmf_sdio_checkdied: firmware trap in dongle
[   33.832300] brcmfmac: brcmf_cfg80211_reg_notifier: Country code iovar returned err = -110
[   36.391904] brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
[   36.392302] brcmfmac: brcmf_sdio_checkdied: firmware trap in dongle
[   36.392318] brcmfmac: brcmf_run_escan: error (-110)
[   36.392328] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
...
[  164.711933] brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
[  164.712359] brcmfmac: brcmf_sdio_checkdied: firmware trap in dongle
[  164.712375] brcmfmac: brcmf_run_escan: error (-110)
[  164.712385] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
...
[  653.992014] brcmfmac: brcmf_run_escan: error (-110)
[  653.992033] brcmfmac: brcmf_cfg80211_scan: scan error (-110)
tayl commented 3 years ago

New development, I just realized that all the scenario 2 cases happen at or very soon after the 24 hour uptime mark. Still not sure where to see debug logs though. They don't show in dmesg for any of the logs I'm getting.