A little hello there, as we are some folks (at least 2 probably 3) having the same issue (from another thread).
After this error appeared I am unable to play the following command
cat /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_cur_freq
And as someone else mentioned,
The load value reported by the web ui is pretty high. However "top" shows no usage.
Network performance dropped a little bit too: I believe this clock story is sticking the CPU at his frequency when the message happen. But that's just a guess, it should be double checked!
Full kernel log:
[ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083]
[ 0.000000] Linux version 5.4.96 (builder@buildhost) (gcc version 8.4.0 (OpenWrt GCC 8.4.0 r15727-c382fe857d)) #0 SMP Wed Feb 10 10:28:04 2021
[ 0.000000] Machine model: Raspberry Pi 4 Model B Rev 1.1
[ 0.000000] Reserved memory: created CMA memory pool at 0x000000002ac00000, size 64 MiB
[ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[ 0.000000] On node 0 totalpages: 504832
[ 0.000000] DMA zone: 3792 pages used for memmap
[ 0.000000] DMA zone: 0 pages reserved
[ 0.000000] DMA zone: 242688 pages, LIFO batch:63
[ 0.000000] DMA32 zone: 4096 pages used for memmap
[ 0.000000] DMA32 zone: 262144 pages, LIFO batch:63
[ 0.000000] percpu: Embedded 21 pages/cpu s45272 r8192 d32552 u86016
[ 0.000000] pcpu-alloc: s45272 r8192 d32552 u86016 alloc=21*4096
[ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[ 0.000000] Detected PIPT I-cache on CPU0
[ 0.000000] CPU features: detected: EL2 vector hardening
[ 0.000000] ARM_SMCCC_ARCH_WORKAROUND_1 missing from firmware
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 496944
[ 0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=1 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 bcm2708_fb.fbwidth=0 bcm2708_fb.fbheight=0 bcm2708_fb.fbswap=1 smsc95xx.macaddr=DC:A6:32:05:D5:C2 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 console=ttyAMA0,115200 console=tty1 root=/dev/mmcblk0p2 rootfstype=squashfs,ext4 rootwait
[ 0.000000] Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[ 0.000000] Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.000000] software IO TLB: mapped [mem 0x37400000-0x3b400000] (64MB)
[ 0.000000] Memory: 1836928K/2019328K available (7102K kernel code, 430K rwdata, 1848K rodata, 512K init, 539K bss, 116864K reserved, 65536K cma-reserved)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[ 0.000000] rcu: Hierarchical RCU implementation.
[ 0.000000] rcu: CONFIG_RCU_FANOUT set to non-default value of 32.
[ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
[ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
[ 0.000000] GIC: Using split EOI/Deactivate mode
[ 0.000000] random: get_random_bytes called from start_kernel+0x2dc/0x3dc with crng_init=0
[ 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.000005] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
[ 0.000155] Console: colour dummy device 80x25
[ 0.000386] printk: console [tty1] enabled
[ 0.000419] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000)
[ 0.000440] pid_max: default: 32768 minimum: 301
[ 0.000604] Mount-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
[ 0.000656] Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
[ 0.001339] Disabling memory control group subsystem
[ 0.002040] ASID allocator initialised with 32768 entries
[ 0.002131] rcu: Hierarchical SRCU implementation.
[ 0.002750] smp: Bringing up secondary CPUs ...
[ 0.003134] Detected PIPT I-cache on CPU1
[ 0.003185] CPU1: Booted secondary processor 0x0000000001 [0x410fd083]
[ 0.003627] Detected PIPT I-cache on CPU2
[ 0.003661] CPU2: Booted secondary processor 0x0000000002 [0x410fd083]
[ 0.004158] Detected PIPT I-cache on CPU3
[ 0.004191] CPU3: Booted secondary processor 0x0000000003 [0x410fd083]
[ 0.004260] smp: Brought up 1 node, 4 CPUs
[ 0.004287] SMP: Total of 4 processors activated.
[ 0.004300] CPU features: detected: 32-bit EL0 Support
[ 0.004313] CPU features: detected: CRC32 instructions
[ 0.004369] CPU features: emulated: Privileged Access Never (PAN) using TTBR0_EL1 switching
[ 0.004385] CPU: All CPU(s) started at EL2
[ 0.004413] alternatives: patching kernel code
[ 0.011927] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[ 0.011994] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[ 0.013715] pinctrl core: initialized pinctrl subsystem
[ 0.014626] NET: Registered protocol family 16
[ 0.016047] DMA: preallocated 1024 KiB pool for atomic allocations
[ 0.016595] cpuidle: using governor ladder
[ 0.016626] cpuidle: using governor menu
[ 0.016900] Serial: AMBA PL011 UART driver
[ 0.018362] bcm2835-mbox fe00b880.mailbox: mailbox enabled
[ 0.028043] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-04-15 11:41, variant start
[ 0.032041] raspberrypi-firmware soc:firmware: Firmware hash is 1103ec16df2571274600b377411499bf5aed6d0d
[ 0.056706] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1
[ 0.058398] SCSI subsystem initialized
[ 0.058549] usbcore: registered new interface driver usbfs
[ 0.058592] usbcore: registered new interface driver hub
[ 0.058650] usbcore: registered new device driver usb
[ 0.058820] workqueue: max_active 576 requested for napi_workq is out of range, clamping between 1 and 512
[ 0.059662] clocksource: Switched to clocksource arch_sys_counter
[ 0.062881] thermal_sys: Registered thermal governor 'step_wise'
[ 0.063117] NET: Registered protocol family 2
[ 0.063811] tcp_listen_portaddr_hash hash table entries: 1024 (order: 2, 16384 bytes, linear)
[ 0.063856] TCP established hash table entries: 16384 (order: 5, 131072 bytes, linear)
[ 0.063967] TCP bind hash table entries: 16384 (order: 6, 262144 bytes, linear)
[ 0.064218] TCP: Hash tables configured (established 16384 bind 16384)
[ 0.064399] UDP hash table entries: 1024 (order: 3, 32768 bytes, linear)
[ 0.064438] UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes, linear)
[ 0.064610] NET: Registered protocol family 1
[ 0.064648] PCI: CLS 0 bytes, default 64
[ 0.065783] workingset: timestamp_bits=46 max_order=19 bucket_order=0
[ 0.070270] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 0.093191] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[ 0.129842] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
[ 0.129869] brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff]
[ 0.129905] brcm-pcie fd500000.pcie: MEM 0x0600000000..0x0603ffffff -> 0x00f8000000
[ 0.129939] brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x007fffffff -> 0x0000000000
[ 0.177729] brcm-pcie fd500000.pcie: link up, 5 GT/s x1 (SSC)
[ 0.177877] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
[ 0.177895] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 0.177913] pci_bus 0000:00: root bus resource [mem 0x600000000-0x603ffffff] (bus address [0xf8000000-0xfbffffff])
[ 0.177957] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
[ 0.178048] pci 0000:00:00.0: PME# supported from D0 D3hot
[ 0.181496] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330
[ 0.181577] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
[ 0.181745] pci 0000:01:00.0: PME# supported from D0 D3cold
[ 0.185051] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
[ 0.185073] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]
[ 0.185131] pci 0000:00:00.0: PCI bridge to [bus 01]
[ 0.185146] pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff]
[ 0.185293] pcieport 0000:00:00.0: enabling device (0000 -> 0002)
[ 0.185420] pcieport 0000:00:00.0: PME: Signaling with IRQ 38
[ 0.185624] pcieport 0000:00:00.0: AER: enabled with IRQ 38
[ 0.185793] pci 0000:01:00.0: enabling device (0000 -> 0002)
[ 0.190884] bcm2708_fb soc:fb: Unable to determine number of FBs. Disabling driver.
[ 0.190912] bcm2708_fb: probe of soc:fb failed with error -2
[ 0.215887] raspberrypi-clk firmware-clocks: CPU frequency range: min 600000000, max 1500000000
[ 0.281220] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled
[ 0.281972] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[ 0.282334] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
[ 0.282545] cacheinfo: Unable to detect cache hierarchy for CPU 0
[ 0.288610] brd: module loaded
[ 0.291718] loop: module loaded
[ 0.292362] Loading iSCSI transport class v2.0-870.
[ 0.293482] libphy: Fixed MDIO Bus: probed
[ 0.293714] bcmgenet fd580000.ethernet: failed to get enet clock
[ 0.293734] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000
[ 0.293751] bcmgenet fd580000.ethernet: failed to get enet-wol clock
[ 0.293767] bcmgenet fd580000.ethernet: failed to get enet-eee clock
[ 0.293790] bcmgenet: Skipping UMAC reset
[ 0.303666] libphy: bcmgenet MII bus: probed
[ 0.351703] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus
[ 0.352549] xhci_hcd 0000:01:00.0: xHCI Host Controller
[ 0.352585] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
[ 0.353271] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000001000000890
[ 0.353923] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.04
[ 0.353944] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.353961] usb usb1: Product: xHCI Host Controller
[ 0.353974] usb usb1: Manufacturer: Linux 5.4.96 xhci-hcd
[ 0.353986] usb usb1: SerialNumber: 0000:01:00.0
[ 0.354282] hub 1-0:1.0: USB hub found
[ 0.354350] hub 1-0:1.0: 1 port detected
[ 0.354741] xhci_hcd 0000:01:00.0: xHCI Host Controller
[ 0.354763] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
[ 0.354785] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[ 0.355041] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.04
[ 0.355061] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.355077] usb usb2: Product: xHCI Host Controller
[ 0.355089] usb usb2: Manufacturer: Linux 5.4.96 xhci-hcd
[ 0.355102] usb usb2: SerialNumber: 0000:01:00.0
[ 0.355377] hub 2-0:1.0: USB hub found
[ 0.355445] hub 2-0:1.0: 4 ports detected
[ 0.356204] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[ 0.356298] dwc_otg: FIQ enabled
[ 0.356302] dwc_otg: NAK holdoff enabled
[ 0.356305] dwc_otg: FIQ split-transaction FSM enabled
[ 0.356311] Module dwc_common_port init
[ 0.356534] usbcore: registered new interface driver uas
[ 0.356604] usbcore: registered new interface driver usb-storage
[ 0.356676] mousedev: PS/2 mouse device common for all mice
[ 0.357092] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[ 0.358004] sdhci: Secure Digital Host Controller Interface driver
[ 0.358018] sdhci: Copyright(c) Pierre Ossman
[ 0.358279] mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe
[ 0.358504] Error: Driver 'sdhost-bcm2835' is already registered, aborting...
[ 0.358518] sdhci-pltfm: SDHCI platform and OF driver helper
[ 0.384708] vchiq: vchiq_init_state: slot_zero = (____ptrval____)
[ 0.405425] NET: Registered protocol family 10
[ 0.406312] Segment Routing with IPv6
[ 0.406397] NET: Registered protocol family 17
[ 0.406440] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[ 0.406459] 8021q: 802.1Q VLAN Support v1.8
[ 0.406827] Key type ._fscrypt registered
[ 0.406840] Key type .fscrypt registered
[ 0.421971] uart-pl011 fe201000.serial: cts_event_workaround enabled
[ 0.422051] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 14, base_baud = 0) is a PL011 rev2
[ 0.698779] usb 2-1: new SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[ 0.705293] printk: console [ttyAMA0] enabled
[ 0.799253] usb 2-1: New USB device found, idVendor=2357, idProduct=0601, bcdDevice=30.00
[ 0.833770] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[ 0.838538] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=6
[ 0.838541] usb 2-1: Product: USB 10/100/1000 LAN
[ 0.842485] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0
[ 0.847757] usb 2-1: Manufacturer: TP-LINK
[ 0.847759] usb 2-1: SerialNumber: 000001000000
[ 0.853061] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated
[ 0.902615] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[ 0.967657] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[ 0.974009] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 1.185881] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21
[ 1.189900] mmc0: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA
[ 1.194140] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[ 1.194143] usb 1-1: Product: USB2.0 Hub
[ 1.222145] hub 1-1:1.0: USB hub found
[ 1.230959] of_cfs_init
[ 1.242487] hub 1-1:1.0: 4 ports detected
[ 1.247925] of_cfs_init: OK
[ 1.553341] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 1.561563] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[ 1.568527] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 1.591799] random: fast init done
[ 1.605965] mmc0: new high speed SDHC card at address 878b
[ 1.611938] mmcblk0: mmc0:878b SU08G 7.40 GiB
[ 1.620309] mmcblk0: p1 p2
[ 1.643984] mmc1: new high speed SDIO card at address 0001
[ 1.656667] EXT4-fs (mmcblk0p2): mounted filesystem without journal. Opts: (null)
[ 1.664186] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[ 1.671298] Freeing unused kernel memory: 512K
[ 1.675811] Run /sbin/init as init process
[ 1.849613] init: Console is alive
[ 1.853106] init: - watchdog -
[ 2.380695] kmodloader: loading kernel modules from /etc/modules-boot.d/*
[ 2.404598] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
[ 2.421098] init: - preinit -
[ 2.670335] bcmgenet: Skipping UMAC reset
[ 2.675577] bcmgenet fd580000.ethernet: configuring instance for external RGMII
[ 2.683057] bcmgenet fd580000.ethernet eth0: Link is Down
[ 6.745091] mount_root: mounting /dev/root
[ 6.751642] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[ 6.763598] random: procd: uninitialized urandom read (4 bytes read)
[ 6.799870] urandom-seed: Seeding with /etc/urandom.seed
[ 6.870805] procd: - early -
[ 6.873781] procd: - watchdog -
[ 7.406754] procd: - watchdog -
[ 7.413776] procd: - ubus -
[ 7.438622] random: ubusd: uninitialized urandom read (4 bytes read)
[ 7.467006] random: ubusd: uninitialized urandom read (4 bytes read)
[ 7.475315] procd: - init -
[ 7.481854] uart-pl011 fe201000.serial: no DMA platform data
[ 7.706439] urngd: v1.0.2 started.
[ 7.707850] kmodloader: loading kernel modules from /etc/modules.d/*
[ 7.725588] random: crng init done
[ 7.728999] random: 7 urandom warning(s) missed due to ratelimiting
[ 7.788591] hidraw: raw HID events driver (C) Jiri Kosina
[ 7.797000] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
[ 7.880581] Loading modules backported from Linux version v5.8.18-0-gab435ce49bd1
[ 7.888112] Backport generated by backports.git v5.8.18-1-0-ga630fd46
[ 7.933188] usbcore: registered new interface driver r8152
[ 7.942962] usbcore: registered new interface driver usbhid
[ 7.948577] usbhid: USB HID core driver
[ 7.957019] xt_time: kernel timezone is -0000
[ 7.961830] usbcore: registered new interface driver ax88179_178a
[ 8.080594] usb 2-1: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[ 8.090027] PPP generic driver version 2.4.2
[ 8.095003] NET: Registered protocol family 24
[ 8.131517] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[ 8.152506] r8152 2-1:1.0 eth1: v1.10.11
[ 8.348863] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[ 8.371615] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Mar 23 2020 02:20:01 version 7.45.206 (r725000 CY) FWID 01-febaba43
[ 8.412854] usbcore: registered new interface driver brcmfmac
[ 8.464263] usbcore: registered new interface driver rt2800usb
[ 8.470344] kmodloader: done loading kernel modules from /etc/modules.d/*
[ 10.440234] bcmgenet: Skipping UMAC reset
[ 10.445465] bcmgenet fd580000.ethernet: configuring instance for external RGMII
[ 10.453081] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
[ 10.454033] br-lan: port 1(eth0) entered blocking state
[ 10.466568] br-lan: port 1(eth0) entered disabled state
[ 10.471946] device eth0 entered promiscuous mode
[ 10.477379] br-lan: port 1(eth0) entered blocking state
[ 10.482645] br-lan: port 1(eth0) entered forwarding state
[ 10.644653] IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
[ 10.651314] r8152 2-1:1.0 eth1: carrier on
[ 11.455687] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
[11310.260222] raspberrypi-firmware soc:firmware: mbox_send_message returned -62
[11310.267387] raspberrypi-clk firmware-clocks: Failed to change pllb frequency: -62
The board booted the last upgraded raspbian today so EEPROM is up to date, however the fixup / start .dat files into the boot part are the "OpenWrt" ones (not sure they are the last ones).