Skip to content

Official PoE HAT Fan never turns on after upgrade to 5.10.y #1532

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
ndanyluk opened this issue Feb 5, 2021 · 11 comments
Closed

Official PoE HAT Fan never turns on after upgrade to 5.10.y #1532

ndanyluk opened this issue Feb 5, 2021 · 11 comments

Comments

@ndanyluk
Copy link

ndanyluk commented Feb 5, 2021

Describe the bug
After standard apt update && apt upgrade -y, which upgrades the kernel to 5.10.y and all firmware, the Pi PoE HAT Fan never turns on again despite various different configuration steps. The systems in question are all running stock Raspberry Pi OS 32-bit Lite

To reproduce
From last 2020 lite image:

apt update && apt upgrade -y
shutdown -r now

I also added the following line to config.txt with no success (same result)

dtoverlay=rpi-poe,poe_fan_temp0=40000,poe_fan_temp0_hyst=2000,poe_fan_temp1=45000,poe_fan_temp1_hyst=2000,poe_fan_temp2=50000,poe_fan_temp2_hyst=2000,poe_fan_temp3=55000,poe_fan_temp3_hyst=5000

Expected behaviour
The Pi boots and the PoE fan starts

Actual behaviour
The Pi boots, but the PoE fan does not start at all.

System

System Information
------------------

Raspberry Pi 3 Model B Plus Rev 1.3
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"

Raspberry Pi reference 2020-12-02
Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, cce27bd6f44a3b2e83855645986b3e21f771e852, stage2

Linux pi-leader 5.10.11-v7+ #1399 SMP Thu Jan 28 12:06:05 GMT 2021 armv7l GNU/Linux
Revision        : a020d3
Serial          : 000000000f963a2a
Model           : Raspberry Pi 3 Model B Plus Rev 1.3
Throttled flag  : throttled=0x80000
Camera          : supported=0 detected=0

Videocore information
---------------------

Jan 27 2021 22:27:11
Copyright (c) 2012 Broadcom
version 99d9a48302e4553cff3688692bb7e9ac760a03fa (clean) (release) (start_cd)

alloc failures:     0
compactions:        0
legacy block fails: 0

Filesystem information
----------------------
Filesystem                                       1K-blocks       Used  Available Use% Mounted on
192.168.0.2:/data/fastnas/nfsroot/pi-leader       52132864    2806784   49326080   6% /
devtmpfs                                            465280          0     465280   0% /dev
tmpfs                                               498560          0     498560   0% /dev/shm
tmpfs                                               498560       6932     491628   2% /run
tmpfs                                                 5120          4       5116   1% /run/lock
tmpfs                                               498560          0     498560   0% /sys/fs/cgroup
tmpfs                                                  100          8         92   8% /var/metrics/prom
192.168.0.2:/var/metrics/environment                  1024          0       1024   0% /var/metrics/environment
192.168.0.2:/data/fastnas/tftpboot/192.168.0.3    91286528     205824   91080704   1% /boot
192.168.0.2:/data/nas                           4647582720   39214080 4608368640   1% /data/nas
192.168.0.2:/data/nas/docker-data/media        10890474496 6282105856 4608368640  58% /data/nas/docker-data/media
/dev/dm-1                                         10255636      48856    9666108   1% /var/lib/docker/devicemapper/mnt/a815b99d5127306aa8322bdc8f2bd7707ce8a24ea964276262868ea62e57f247
/dev/dm-2                                         10255636     109544    9605420   2% /var/lib/docker/devicemapper/mnt/1fc5909a0d99ae7adaa03683c788f8aacf046f153b65860f07ee8607e9a2a341
/dev/dm-3                                         10255636     167052    9547912   2% /var/lib/docker/devicemapper/mnt/4154e92650db1d7a450970210a7f321b34dfc6ef84e0f45f0dfa1bae0cea9076
/dev/dm-4                                         10255636      63072    9651892   1% /var/lib/docker/devicemapper/mnt/8af47120abdd6dd2d07b2a0ac206bf3e96787732389aa7bb217f3b1d6085dc06
tmpfs                                                99712          0      99712   0% /run/user/1000

Filename                                Type            Size            Used            Priority
/dev/zram0                              partition       131068          0               100
/dev/zram1                              partition       131068          0               100
/dev/zram2                              partition       131068          0               100
/dev/zram3                              partition       131068          0               100

Package version information
---------------------------
raspberrypi-ui-mods:
  Installed: (none)
raspberrypi-sys-mods:
  Installed: 20210125
openbox:
  Installed: (none)
lxpanel:
  Installed: (none)
pcmanfm:
  Installed: (none)
rpd-plym-splash:
  Installed: (none)

Networking Information
----------------------

docker0: flags=4099<UP,BROADCAST,MULTICAST>  mtu 1500
        inet x.x.x.x  netmask x.x.x.x  broadcast x.x.x.x
        ether m.m.m.m  txqueuelen 0  (Ethernet)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 0  bytes 0 (0.0 B)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

docker_gwbridge: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet x.x.x.x  netmask x.x.x.x  broadcast x.x.x.x
        inet6 y::y.y.y.y  prefixlen 64  scopeid 0x20<link>
        ether m.m.m.m  txqueuelen 0  (Ethernet)
        RX packets 61  bytes 5660 (5.5 KiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 49  bytes 4633 (4.5 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

eth0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet x.x.x.x  netmask x.x.x.x  broadcast x.x.x.x
        inet6 y::y.y.y.y  prefixlen 64  scopeid 0x20<link>
        ether m.m.m.m  txqueuelen 1000  (Ethernet)
        RX packets 239006  bytes 313689208 (299.1 MiB)
        RX errors 1  dropped 0  overruns 0  frame 1
        TX packets 101087  bytes 28890878 (27.5 MiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

lo: flags=73<UP,LOOPBACK,RUNNING>  mtu 65536
        inet x.x.x.x  netmask x.x.x.x
        inet6 ::1  prefixlen 128  scopeid 0x10<host>
        loop  txqueuelen 1000  (Local Loopback)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 0  bytes 0 (0.0 B)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

veth4b78a65: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet x.x.x.x  netmask x.x.x.x  broadcast x.x.x.x
        inet6 y::y.y.y.y  prefixlen 64  scopeid 0x20<link>
        ether m.m.m.m  txqueuelen 0  (Ethernet)
        RX packets 8  bytes 1180 (1.1 KiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 62  bytes 9580 (9.3 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

veth6c0edad: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet x.x.x.x  netmask x.x.x.x  broadcast x.x.x.x
        inet6 y::y.y.y.y  prefixlen 64  scopeid 0x20<link>
        ether m.m.m.m  txqueuelen 0  (Ethernet)
        RX packets 37  bytes 2974 (2.9 KiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 93  bytes 11833 (11.5 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

veth6f5d04e: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet x.x.x.x  netmask x.x.x.x  broadcast x.x.x.x
        inet6 y::y.y.y.y  prefixlen 64  scopeid 0x20<link>
        ether m.m.m.m  txqueuelen 0  (Ethernet)
        RX packets 8  bytes 1180 (1.1 KiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 63  bytes 10215 (9.9 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

veth74cc2f0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet x.x.x.x  netmask x.x.x.x  broadcast x.x.x.x
        inet6 y::y.y.y.y  prefixlen 64  scopeid 0x20<link>
        inet6 y::y.y.y.y  prefixlen 64  scopeid 0x20<link>
        ether m.m.m.m  txqueuelen 0  (Ethernet)
        RX packets 0  bytes 0 (0.0 B)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 89  bytes 14296 (13.9 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

veth909ad26: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet x.x.x.x  netmask x.x.x.x  broadcast x.x.x.x
        inet6 y::y.y.y.y  prefixlen 64  scopeid 0x20<link>
        ether m.m.m.m  txqueuelen 0  (Ethernet)
        RX packets 8  bytes 1180 (1.1 KiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 43  bytes 7484 (7.3 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

wlan0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet x.x.x.x  netmask x.x.x.x  broadcast x.x.x.x
        inet6 y::y.y.y.y  prefixlen 64  scopeid 0x20<link>
        ether m.m.m.m  txqueuelen 1000  (Ethernet)
        RX packets 179  bytes 35354 (34.5 KiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 25  bytes 3964 (3.8 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0


USB Information
---------------

/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=dwc_otg/1p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M
        |__ Port 1: Dev 3, If 0, Class=Hub, Driver=hub/3p, 480M
            |__ Port 1: Dev 4, If 0, Class=Vendor Specific Class, Driver=lan78xx, 480M

config.txt
----------

aphy_params_current=819
arm_freq=1400
arm_freq_min=600
audio_pwm_mode=514
config_hdmi_boost=5
core_freq=400
desired_osc_freq=0x331df0
desired_osc_freq_boost=0x3c45b0
disable_commandline_tags=2
disable_l2cache=1
display_hdmi_rotate=-1
display_lcd_rotate=-1
dphy_params_current=547
dvfs=2
enable_tvout=1
force_eeprom_read=1
force_pwm_open=1
framebuffer_depth=16
framebuffer_ignore_alpha=1
framebuffer_swap=1
gpu_freq=300
init_uart_clock=0x2dc6c00
lcd_framerate=60
max_framebuffers=-1
over_voltage_avs=31250
over_voltage_avs_boost=0x2191c
pause_burst_frames=1
program_serial_random=1
sdram_freq=450
total_mem=1024
hdmi_force_cec_address:0=65535
hdmi_force_cec_address:1=65535
hdmi_pixel_freq_limit:0=0x9a7ec80
device_tree=-
overlay_prefix=overlays/
hdmi_cvt:0=
hdmi_cvt:1=
hdmi_edid_filename:0=
hdmi_edid_filename:1=
hdmi_timings:0=
hdmi_timings:1=

cmdline.txt
-----------
coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2708_fb.fbdepth=16 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3f000000 vc_mem.mem_size=0x3f600000  console=ttyS0,115200 console=tty1 root=/dev/nfs nfsroot=192.168.0.2:/data/fastnas/nfsroot/pi-leader,vers=4.2,proto=tcp,rsize=1048576,wsize=1048576 rw ip=dhcp rootwait elevator=deadline

raspi-gpio settings
-------------------

BANK0 (GPIO 0 to 27):
GPIO 0: level=1 fsel=0 func=INPUT
GPIO 1: level=1 fsel=0 func=INPUT
GPIO 2: level=1 fsel=0 func=INPUT
GPIO 3: level=1 fsel=0 func=INPUT
GPIO 4: level=1 fsel=0 func=INPUT
GPIO 5: level=1 fsel=0 func=INPUT
GPIO 6: level=1 fsel=0 func=INPUT
GPIO 7: level=1 fsel=0 func=INPUT
GPIO 8: level=1 fsel=0 func=INPUT
GPIO 9: level=0 fsel=0 func=INPUT
GPIO 10: level=0 fsel=0 func=INPUT
GPIO 11: level=0 fsel=0 func=INPUT
GPIO 12: level=0 fsel=0 func=INPUT
GPIO 13: level=0 fsel=0 func=INPUT
GPIO 14: level=0 fsel=0 func=INPUT
GPIO 15: level=1 fsel=0 func=INPUT
GPIO 16: level=0 fsel=0 func=INPUT
GPIO 17: level=0 fsel=0 func=INPUT
GPIO 18: level=0 fsel=0 func=INPUT
GPIO 19: level=0 fsel=0 func=INPUT
GPIO 20: level=0 fsel=0 func=INPUT
GPIO 21: level=0 fsel=0 func=INPUT
GPIO 22: level=0 fsel=0 func=INPUT
GPIO 23: level=0 fsel=0 func=INPUT
GPIO 24: level=0 fsel=0 func=INPUT
GPIO 25: level=0 fsel=0 func=INPUT
GPIO 26: level=0 fsel=0 func=INPUT
GPIO 27: level=0 fsel=0 func=INPUT
BANK1 (GPIO 28 to 45):
GPIO 28: level=1 fsel=0 func=INPUT
GPIO 29: level=0 fsel=1 func=OUTPUT
GPIO 30: level=0 fsel=7 alt=3 func=CTS0
GPIO 31: level=0 fsel=7 alt=3 func=RTS0
GPIO 32: level=1 fsel=7 alt=3 func=TXD0
GPIO 33: level=1 fsel=7 alt=3 func=RXD0
GPIO 34: level=0 fsel=7 alt=3 func=SD1_CLK
GPIO 35: level=1 fsel=7 alt=3 func=SD1_CMD
GPIO 36: level=1 fsel=7 alt=3 func=SD1_DAT0
GPIO 37: level=1 fsel=7 alt=3 func=SD1_DAT1
GPIO 38: level=1 fsel=7 alt=3 func=SD1_DAT2
GPIO 39: level=1 fsel=7 alt=3 func=SD1_DAT3
GPIO 40: level=0 fsel=4 alt=0 func=PWM0
GPIO 41: level=0 fsel=4 alt=0 func=PWM1
GPIO 42: level=1 fsel=4 alt=0 func=GPCLK1
GPIO 43: level=0 fsel=4 alt=0 func=GPCLK2
GPIO 44: level=1 fsel=0 func=INPUT
GPIO 45: level=1 fsel=0 func=INPUT
BANK2 (GPIO 46 to 53):
GPIO 46: level=1 fsel=0 func=INPUT
GPIO 47: level=1 fsel=1 func=OUTPUT
GPIO 48: level=0 fsel=4 alt=0 func=SD0_CLK
GPIO 49: level=1 fsel=4 alt=0 func=SD0_CMD
GPIO 50: level=1 fsel=4 alt=0 func=SD0_DAT0
GPIO 51: level=1 fsel=4 alt=0 func=SD0_DAT1
GPIO 52: level=1 fsel=4 alt=0 func=SD0_DAT2
GPIO 53: level=1 fsel=4 alt=0 func=SD0_DAT3

Logs

vcdbg log messages
------------------

Unable to determine the value of __LOG_START
Unable to read logging_header from 0x00000000

dmesg log
---------
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 5.10.11-v7+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1399 SMP Thu Jan 28 12:06:05 GMT 2021
[    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] Reserved memory: created CMA memory pool at 0x3a400000, size 64 MiB
[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000000000-0x000000003e5fffff]
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x000000003e5fffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x000000003e5fffff]
[    0.000000] On node 0 totalpages: 255488
[    0.000000]   DMA zone: 2246 pages used for memmap
[    0.000000]   DMA zone: 0 pages reserved
[    0.000000]   DMA zone: 255488 pages, LIFO batch:63
[    0.000000] percpu: Embedded 20 pages/cpu s50636 r8192 d23092 u81920
[    0.000000] pcpu-alloc: s50636 r8192 d23092 u81920 alloc=20*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 253242
[    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2708_fb.fbdepth=16 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3f000000 vc_mem.mem_size=0x3f600000  console=ttyS0,115200 console=tty1 root=/dev/nfs nfsroot=192.168.0.2:/data/fastnas/nfsroot/pi-leader,vers=4.2,proto=tcp,rsize=1048576,wsize=1048576 rw ip=dhcp rootwait elevator=deadline
[    0.000000] Kernel parameter elevator= does not have any effect anymore.
               Please use sysfs to set IO scheduler for individual devices.
[    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] Memory: 930560K/1021952K available (9216K kernel code, 1311K rwdata, 2936K rodata, 1024K init, 860K bss, 25856K reserved, 65536K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 31819 entries in 63 pages
[    0.000000] ftrace: allocated 63 pages with 6 groups
[    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] random: get_random_bytes called from start_kernel+0x3ac/0x580 with crng_init=0
[    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.000008] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[    0.000025] Switching to timer-based delay loop, resolution 52ns
[    0.000318] Console: colour dummy device 80x30
[    0.001185] printk: console [tty1] enabled
[    0.001252] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[    0.001311] pid_max: default: 32768 minimum: 301
[    0.001541] LSM: Security Framework initializing
[    0.001800] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.001850] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.003469] Disabling memory control group subsystem
[    0.003608] CPU: Testing write buffer coherency: ok
[    0.004124] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.005383] Setting up static identity map for 0x100000 - 0x10003c
[    0.005591] rcu: Hierarchical SRCU implementation.
[    0.006533] smp: Bringing up secondary CPUs ...
[    0.007730] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.009022] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.010386] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.010545] smp: Brought up 1 node, 4 CPUs
[    0.010599] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[    0.010631] CPU: All CPU(s) started in HYP mode.
[    0.010659] CPU: Virtualization extensions available.
[    0.011682] devtmpfs: initialized
[    0.029741] VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4
[    0.030071] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.030133] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[    0.033342] pinctrl core: initialized pinctrl subsystem
[    0.034568] NET: Registered protocol family 16
[    0.038889] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.044606] audit: initializing netlink subsys (disabled)
[    0.044919] audit: type=2000 audit(0.040:1): state=initialized audit_enabled=0 res=1
[    0.045517] thermal_sys: Registered thermal governor 'step_wise'
[    0.046763] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.046828] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.047128] Serial: AMBA PL011 UART driver
[    0.065237] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
[    0.080147] raspberrypi-firmware soc:firmware: Attached to firmware from 2021-01-27T22:27:11, variant start_cd
[    0.090158] raspberrypi-firmware soc:firmware: Firmware hash is 99d9a48302e4553cff3688692bb7e9ac760a03fa
[    0.138958] bcm2835-dma 3f007000.dma: DMA legacy API manager, dmachans=0x1
[    0.141492] SCSI subsystem initialized
[    0.141780] usbcore: registered new interface driver usbfs
[    0.141867] usbcore: registered new interface driver hub
[    0.141957] usbcore: registered new device driver usb
[    0.143965] clocksource: Switched to clocksource arch_sys_counter
[    1.870840] VFS: Disk quotas dquot_6.6.0
[    1.870984] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    1.871214] FS-Cache: Loaded
[    1.871468] CacheFiles: Loaded
[    1.881315] NET: Registered protocol family 2
[    1.882335] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    1.882524] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
[    1.882671] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    1.882885] TCP: Hash tables configured (established 8192 bind 8192)
[    1.883087] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
[    1.883166] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
[    1.883660] NET: Registered protocol family 1
[    1.884527] RPC: Registered named UNIX socket transport module.
[    1.884563] RPC: Registered udp transport module.
[    1.884593] RPC: Registered tcp transport module.
[    1.884622] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    1.886327] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available
[    1.890034] Initialise system trusted keyrings
[    1.890320] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[    1.899877] zbud: loaded
[    1.901972] FS-Cache: Netfs 'nfs' registered for caching
[    1.902865] NFS: Registering the id_resolver key type
[    1.902932] Key type id_resolver registered
[    1.902963] Key type id_legacy registered
[    1.903137] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    1.904421] Key type asymmetric registered
[    1.904455] Asymmetric key parser 'x509' registered
[    1.904528] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
[    1.904569] io scheduler mq-deadline registered
[    1.904599] io scheduler kyber registered
[    1.908105] bcm2708_fb soc:fb: FB found 1 display(s)
[    1.915917] Console: switching to colour frame buffer device 82x26
[    1.919882] bcm2708_fb soc:fb: Registered framebuffer for display 0, size 656x416
[    1.927869] bcm2835-rng 3f104000.rng: hwrng registered
[    1.929635] vc-mem: phys_addr:0x00000000 mem_base=0x3f000000 mem_size:0x3f600000(1014 MiB)
[    1.933040] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000
[    1.948824] brd: module loaded
[    1.962239] loop: module loaded
[    1.965205] Loading iSCSI transport class v2.0-870.
[    1.968146] libphy: Fixed MDIO Bus: probed
[    1.969785] usbcore: registered new interface driver lan78xx
[    1.971199] usbcore: registered new interface driver smsc95xx
[    1.972520] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    2.701793] Core Release: 2.80a
[    2.703081] Setting default values for core params
[    2.704385] Finished setting default values for core params
[    2.906033] Using Buffer DMA mode
[    2.907313] Periodic Transfer Interrupt Enhancement - disabled
[    2.908624] Multiprocessor Interrupt Enhancement - disabled
[    2.909928] OTG VER PARAM: 0, OTG VER FLAG: 0
[    2.911216] Dedicated Tx FIFOs mode

[    2.912988] WARN::dwc_otg_hcd_init:1074: FIQ DMA bounce buffers: virt = ba514000 dma = 0xfa514000 len=9024
[    2.916601] FIQ FSM acceleration enabled for :
               Non-periodic Split Transactions
               Periodic Split Transactions
               High-Speed Isochronous Endpoints
               Interrupt/Control Split Transaction hack enabled
[    2.922211] dwc_otg: Microframe scheduler enabled

[    2.922291] WARN::hcd_init_fiq:457: FIQ on core 1

[    2.924536] WARN::hcd_init_fiq:458: FIQ ASM at 807bae50 length 36

[    2.926837] WARN::hcd_init_fiq:497: MPHI regs_base at be810000
[    2.929153] dwc_otg 3f980000.usb: DWC OTG Controller
[    2.930368] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
[    2.931620] dwc_otg 3f980000.usb: irq 89, io mem 0x00000000
[    2.932846] Init: Port Power? op_state=1
[    2.934028] Init: Power Port (0)
[    2.935522] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10
[    2.937905] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.939183] usb usb1: Product: DWC OTG Controller
[    2.940410] usb usb1: Manufacturer: Linux 5.10.11-v7+ dwc_otg_hcd
[    2.941651] usb usb1: SerialNumber: 3f980000.usb
[    2.943628] hub 1-0:1.0: USB hub found
[    2.944999] hub 1-0:1.0: 1 port detected
[    2.947279] dwc_otg: FIQ enabled
[    2.947292] dwc_otg: NAK holdoff enabled
[    2.947304] dwc_otg: FIQ split-transaction FSM enabled
[    2.947322] Module dwc_common_port init
[    2.947658] usbcore: registered new interface driver usb-storage
[    2.949128] mousedev: PS/2 mouse device common for all mice
[    2.951554] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[    2.955778] sdhci: Secure Digital Host Controller Interface driver
[    2.957087] sdhci: Copyright(c) Pierre Ossman
[    2.958971] mmc-bcm2835 3f300000.mmcnr: could not get clk, deferring probe
[    2.960975] sdhost-bcm2835 3f202000.mmc: could not get clk, deferring probe
[    2.962521] sdhci-pltfm: SDHCI platform and OF driver helper
[    2.965860] ledtrig-cpu: registered to indicate activity on CPUs
[    2.967600] hid: raw HID events driver (C) Jiri Kosina
[    2.969095] usbcore: registered new interface driver usbhid
[    2.970427] usbhid: USB HID core driver
[    2.976688] Initializing XFRM netlink socket
[    2.978048] NET: Registered protocol family 17
[    2.979454] Key type dns_resolver registered
[    2.981316] Registering SWP/SWPB emulation handler
[    2.982655] registered taskstats version 1
[    2.983862] Loading compiled-in X.509 certificates
[    2.986018] Key type ._fscrypt registered
[    2.987208] Key type .fscrypt registered
[    2.988393] Key type fscrypt-provisioning registered
[    3.000989] uart-pl011 3f201000.serial: cts_event_workaround enabled
[    3.002325] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 114, base_baud = 0) is a PL011 rev2
[    3.007101] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[    3.010080] mmc-bcm2835 3f300000.mmcnr: mmc_debug:0 mmc_debug2:0
[    3.011351] mmc-bcm2835 3f300000.mmcnr: DMA channel allocated
[    3.038254] sdhost: log_buf @ (ptrval) (fa513000)
[    3.074251] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[    3.077110] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    3.079903] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    3.083969] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[    3.088056] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[    3.092150] of_cfs_init
[    3.093445] of_cfs_init: OK
[    3.152016] random: fast init done
[    3.179177] Indeed it is in host mode hprt0 = 00021501
[    3.256245] mmc1: new high speed SDIO card at address 0001
[    3.386531] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    3.387779] Indeed it is in host mode hprt0 = 00001101
[    3.624306] usb 1-1: New USB device found, idVendor=0424, idProduct=2514, bcdDevice= b.b3
[    3.626609] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    3.628542] hub 1-1:1.0: USB hub found
[    3.629808] hub 1-1:1.0: 4 ports detected
[    3.943996] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    4.074349] usb 1-1.1: New USB device found, idVendor=0424, idProduct=2514, bcdDevice= b.b3
[    4.076617] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    4.078526] hub 1-1.1:1.0: USB hub found
[    4.079883] hub 1-1.1:1.0: 3 ports detected
[    4.434106] dwc_otg_handle_wakeup_detected_intr lxstate = 2
[    4.833995] usb 1-1.1.1: new high-speed USB device number 4 using dwc_otg
[    4.964491] usb 1-1.1.1: New USB device found, idVendor=0424, idProduct=7800, bcdDevice= 3.00
[    4.967214] usb 1-1.1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    5.235544] lan78xx 1-1.1.1:1.0 (unnamed net_device) (uninitialized): No External EEPROM. Setting MAC Speed
[    5.240339] libphy: lan78xx-mdiobus: probed
[    5.250243] lan78xx 1-1.1.1:1.0 (unnamed net_device) (uninitialized): int urb period 64
[    8.433995] Sending DHCP requests ., OK
[    8.681978] IP-Config: Got DHCP answer from 192.168.0.1, my address is 192.168.0.3
[    8.685047] IP-Config: Complete:
[    8.686576]      device=eth0, hwaddr=m.m.m.m, ipaddr=192.168.0.3, mask=255.255.255.0, gw=192.168.0.1
[    8.689646]      host=pi-leader, domain=lan, nis-domain=(none)
[    8.691183]      bootserver=192.168.0.2, rootserver=192.168.0.2, rootpath=
[    8.691197]      nameserver0=192.168.0.1
[    8.730343] VFS: Mounted root (nfs4 filesystem) on device 0:20.
[    8.732577] devtmpfs: mounted
[    8.753033] Freeing unused kernel memory: 1024K
[    8.824480] Run /sbin/init as init process
[    8.825962]   with arguments:
[    8.825975]     /sbin/init
[    8.825985]   with environment:
[    8.825997]     HOME=/
[    8.826008]     TERM=linux
[    9.427917] systemd[1]: System time before build time, advancing clock.
[    9.541917] NET: Registered protocol family 10
[    9.545581] Segment Routing with IPv6
[    9.635221] random: crng init done
[    9.646577] 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)
[    9.651931] systemd[1]: Detected architecture arm.
[    9.721343] systemd[1]: Set hostname to <pi-leader>.
[   10.989590] systemd[1]: Created slice system-getty.slice.
[   10.995282] systemd[1]: Listening on Journal Audit Socket.
[   10.999671] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[   11.006332] systemd[1]: Listening on Journal Socket.
[   11.016500] systemd[1]: Mounting Kernel Debug File System...
[   11.030128] systemd[1]: Starting Create list of required static device nodes for the current kernel...
[   11.047745] systemd[1]: Mounting POSIX Message Queue File System...
[   11.612221] systemd-journald[117]: Received request to flush runtime journal from PID 1
[   12.505687] rpi-poe-fan rpi-poe-fan@0: Failed to get default PWM value: -5
[   12.505746] rpi-poe-fan: probe of rpi-poe-fan@0 failed with error -5
[   12.660077] mc: Linux media interface: v0.10
[   12.664713] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[   12.667295] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[   12.667322] [vc_sm_connected_init]: start
[   12.671557] vc_sm_cma_vchi_init: failed to open VCHI service (-1)
[   12.671581] [vc_sm_connected_init]: failed to initialize shared memory service
[   12.733879] videodev: Linux video capture interface: v2.00
[   12.752275] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
[   12.780629] bcm2835_audio bcm2835_audio: card created with 8 channels
[   12.824378] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[   12.845605] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
[   12.871210] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
[   12.889201] bcm2835_mmal_vchiq: Failed to open VCHI service connection (status=-1)
[   12.900808] bcm2835_mmal_vchiq: Failed to open VCHI service connection (status=-1)
[   12.923778] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
[   12.929582] bcm2835_mmal_vchiq: Failed to open VCHI service connection (status=-1)
[   13.192243] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[   13.396717] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[   13.477379] brcmfmac: F1 signature read @0x18000000=0x15264345
[   13.490150] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[   13.491098] usbcore: registered new interface driver brcmfmac
[   13.550544] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,3-model-b-plus.txt failed with error -2
[   13.783593] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[   13.795686] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Jan  4 2021 19:56:29 version 7.45.229 (617f1f5 CY) FWID 01-2dbd9d2e
[   15.397107] 8021q: 802.1Q VLAN Support v1.8
[   15.397203] 8021q: adding VLAN 0 to HW filter on device eth0
[   15.440965] zram: Added device: zram0
[   15.442074] zram: Added device: zram1
[   15.443087] zram: Added device: zram2
[   15.446519] zram: Added device: zram3
[   15.490170] zram0: detected capacity change from 0 to 134217728
[   15.668940] Adding 131068k swap on /dev/zram0.  Priority:100 extents:1 across:131068k SSFS
[   15.678470] uart-pl011 3f201000.serial: no DMA platform data
[   15.685405] zram1: detected capacity change from 0 to 134217728
[   15.844134] Adding 131068k swap on /dev/zram1.  Priority:100 extents:1 across:131068k SSFS
[   15.847176] zram2: detected capacity change from 0 to 134217728
[   15.974275] Adding 131068k swap on /dev/zram2.  Priority:100 extents:1 across:131068k SSFS
[   15.977845] zram3: detected capacity change from 0 to 134217728
[   16.026834] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
[   16.124136] Adding 131068k swap on /dev/zram3.  Priority:100 extents:1 across:131068k SSFS
[   21.931329] device-mapper: ioctl: 4.43.0-ioctl (2020-10-01) initialised: [email protected]
[   22.066535] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[   22.952606] Bluetooth: Core ver 2.22
[   22.952702] NET: Registered protocol family 31
[   22.952711] Bluetooth: HCI device and connection manager initialized
[   22.952739] Bluetooth: HCI socket layer initialized
[   22.952754] Bluetooth: L2CAP socket layer initialized
[   22.952781] Bluetooth: SCO socket layer initialized
[   22.975786] Bluetooth: HCI UART driver ver 2.3
[   22.975805] Bluetooth: HCI UART protocol H4 registered
[   22.975907] Bluetooth: HCI UART protocol Three-wire (H5) registered
[   22.976909] Bluetooth: HCI UART protocol Broadcom registered
[   23.302882] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[   23.302901] Bluetooth: BNEP filters: protocol multicast
[   23.302920] Bluetooth: BNEP socket layer initialized
[   24.855416] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[   24.861645] Bridge firewalling registered
[   31.009738] br0: renamed from ov-001002-inb72
[   31.156284] vxlan0: renamed from vx-001002-inb72
[   31.234379] br0: port 1(vxlan0) entered blocking state
[   31.234395] br0: port 1(vxlan0) entered disabled state
[   31.234684] device vxlan0 entered promiscuous mode
[   31.236125] br0: port 1(vxlan0) entered blocking state
[   31.236143] br0: port 1(vxlan0) entered forwarding state
[   31.299330] br0: renamed from ov-001000-c673w
[   31.436564] vxlan0: renamed from vx-001000-c673w
[   31.494955] br0: port 1(vxlan0) entered blocking state
[   31.494972] br0: port 1(vxlan0) entered disabled state
[   31.495238] device vxlan0 entered promiscuous mode
[   31.495904] br0: port 1(vxlan0) entered blocking state
[   31.495915] br0: port 1(vxlan0) entered forwarding state
[   31.496449] br0: renamed from ov-001003-2v0u7
[   31.586890] vxlan0: renamed from vx-001003-2v0u7
[   31.655649] br0: port 1(vxlan0) entered blocking state
[   31.655663] br0: port 1(vxlan0) entered disabled state
[   31.655897] device vxlan0 entered promiscuous mode
[   31.656537] br0: port 1(vxlan0) entered blocking state
[   31.656548] br0: port 1(vxlan0) entered forwarding state
[   31.782857] veth0: renamed from vethee4fd7b
[   31.855617] br0: port 2(veth0) entered blocking state
[   31.855638] br0: port 2(veth0) entered disabled state
[   31.856064] device veth0 entered promiscuous mode
[   31.856764] br0: port 2(veth0) entered blocking state
[   31.856777] br0: port 2(veth0) entered forwarding state
[   32.044707] veth0: renamed from veth5ce1a95
[   32.095167] br0: port 2(veth0) entered blocking state
[   32.095185] br0: port 2(veth0) entered disabled state
[   32.095710] device veth0 entered promiscuous mode
[   32.096604] br0: port 2(veth0) entered blocking state
[   32.096620] br0: port 2(veth0) entered forwarding state
[   32.308527] veth0: renamed from vethf722f2c
[   32.367699] br0: port 2(veth0) entered blocking state
[   32.367715] br0: port 2(veth0) entered disabled state
[   32.368000] device veth0 entered promiscuous mode
[   32.431409] IPv6: ADDRCONF(NETDEV_CHANGE): vethfa05e1e: link becomes ready
[   32.431613] br0: port 2(veth0) entered blocking state
[   32.431622] br0: port 2(veth0) entered forwarding state
[   32.785534] br0: port 2(veth0) entered disabled state
[   32.787119] eth0: renamed from veth0537971
[   32.876389] br0: port 2(veth0) entered blocking state
[   32.876408] br0: port 2(veth0) entered forwarding state
[   33.073565] br0: port 2(veth0) entered disabled state
[   33.077453] eth0: renamed from vethf41ea9d
[   33.118476] br0: port 2(veth0) entered blocking state
[   33.118500] br0: port 2(veth0) entered forwarding state
[   33.120747] IPVS: Registered protocols (TCP, UDP, SCTP, AH, ESP)
[   33.120810] IPVS: Connection hash table configured (size=4096, memory=32Kbytes)
[   33.121504] IPVS: ipvs loaded.
[   33.309322] br0: port 2(veth0) entered disabled state
[   33.312626] eth0: renamed from vethfa05e1e
[   33.338076] EXT4-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null)
[   33.346787] br0: port 2(veth0) entered blocking state
[   33.346804] br0: port 2(veth0) entered forwarding state
[   33.748770] EXT4-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null)
[   33.763338] br0: port 2(veth0) entered disabled state
[   33.763402] br0: port 1(vxlan0) entered disabled state
[   33.764446] ov-001003-2v0u7: renamed from br0
[   33.814842] device veth0 left promiscuous mode
[   33.814913] ov-001003-2v0u7: port 2(veth0) entered disabled state
[   33.815362] device vxlan0 left promiscuous mode
[   33.815413] ov-001003-2v0u7: port 1(vxlan0) entered disabled state
[   33.879965] docker_gwbridge: port 1(veth74cc2f0) entered blocking state
[   33.879980] docker_gwbridge: port 1(veth74cc2f0) entered disabled state
[   33.880372] device veth74cc2f0 entered promiscuous mode
[   33.881226] docker_gwbridge: port 1(veth74cc2f0) entered blocking state
[   33.881242] docker_gwbridge: port 1(veth74cc2f0) entered forwarding state
[   33.881588] docker_gwbridge: port 1(veth74cc2f0) entered disabled state
[   33.904156] IPVS: [rr] scheduler registered.
[   33.941902] vx-001003-2v0u7: renamed from vxlan0
[   34.028522] vethf722f2c: renamed from veth0
[   34.042484] EXT4-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null)
[   34.158267] eth1: renamed from veth0926bc4
[   34.220276] EXT4-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null)
[   34.313480] IPv6: ADDRCONF(NETDEV_CHANGE): veth74cc2f0: link becomes ready
[   34.313674] docker_gwbridge: port 1(veth74cc2f0) entered blocking state
[   34.313685] docker_gwbridge: port 1(veth74cc2f0) entered forwarding state
[   34.313917] IPv6: ADDRCONF(NETDEV_CHANGE): docker_gwbridge: link becomes ready
[   34.387111] vethfa05e1e: renamed from eth0
[   34.588997] EXT4-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null)
[   35.007799] EXT4-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null)
[   35.009202] br0: port 2(veth0) entered disabled state
[   35.009247] br0: port 1(vxlan0) entered disabled state
[   35.010208] ov-001002-inb72: renamed from br0
[   35.065407] device veth0 left promiscuous mode
[   35.065491] ov-001002-inb72: port 2(veth0) entered disabled state
[   35.067519] device vxlan0 left promiscuous mode
[   35.067608] ov-001002-inb72: port 1(vxlan0) entered disabled state
[   35.144902] EXT4-fs (dm-3): mounted filesystem with ordered data mode. Opts: (null)
[   35.246230] vx-001002-inb72: renamed from vxlan0
[   35.376198] vethee4fd7b: renamed from veth0
[   35.585871] veth0537971: renamed from eth0
[   36.094529] EXT4-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null)
[   36.361343] EXT4-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null)
[   36.671205] EXT4-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null)
[   37.918589] br0: renamed from ov-001002-inb72
[   38.067717] vxlan0: renamed from vx-001002-inb72
[   38.115132] br0: port 1(vxlan0) entered blocking state
[   38.115147] br0: port 1(vxlan0) entered disabled state
[   38.115376] device vxlan0 entered promiscuous mode
[   38.116538] br0: port 1(vxlan0) entered blocking state
[   38.116555] br0: port 1(vxlan0) entered forwarding state
[   38.123732] br0: renamed from ov-001003-2v0u7
[   38.245805] vxlan0: renamed from vx-001003-2v0u7
[   38.295911] br0: port 1(vxlan0) entered blocking state
[   38.295926] br0: port 1(vxlan0) entered disabled state
[   38.296180] device vxlan0 entered promiscuous mode
[   38.296895] br0: port 1(vxlan0) entered blocking state
[   38.296907] br0: port 1(vxlan0) entered forwarding state
[   38.547171] veth0: renamed from vethaef7eec
[   38.615033] br0: port 2(veth0) entered blocking state
[   38.615049] br0: port 2(veth0) entered disabled state
[   38.615446] device veth0 entered promiscuous mode
[   38.616349] br0: port 2(veth0) entered blocking state
[   38.616363] br0: port 2(veth0) entered forwarding state
[   38.767095] veth0: renamed from veth9f88e04
[   38.844124] br0: port 2(veth0) entered blocking state
[   38.844138] br0: port 2(veth0) entered disabled state
[   38.844390] device veth0 entered promiscuous mode
[   38.845069] br0: port 2(veth0) entered blocking state
[   38.845082] br0: port 2(veth0) entered forwarding state
[   39.374748] br0: port 2(veth0) entered disabled state
[   39.376692] eth0: renamed from vethca8372f
[   39.436242] br0: port 2(veth0) entered blocking state
[   39.436269] br0: port 2(veth0) entered forwarding state
[   39.605392] br0: port 2(veth0) entered disabled state
[   39.609262] eth0: renamed from veth9019e8d
[   39.649916] EXT4-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null)
[   39.657695] br0: port 2(veth0) entered blocking state
[   39.657715] br0: port 2(veth0) entered forwarding state
[   39.985713] veth1: renamed from vethe1d1065
[   40.034909] br0: port 3(veth1) entered blocking state
[   40.034936] br0: port 3(veth1) entered disabled state
[   40.035175] device veth1 entered promiscuous mode
[   40.035738] br0: port 3(veth1) entered blocking state
[   40.035747] br0: port 3(veth1) entered forwarding state
[   40.082221] EXT4-fs (dm-3): mounted filesystem with ordered data mode. Opts: (null)
[   40.134294] br0: port 3(veth1) entered disabled state
[   40.157918] IPv6: ADDRCONF(NETDEV_CHANGE): veth4ec0c0c: link becomes ready
[   40.158075] br0: port 3(veth1) entered blocking state
[   40.158085] br0: port 3(veth1) entered forwarding state
[   40.181392] docker_gwbridge: port 2(veth4b78a65) entered blocking state
[   40.181409] docker_gwbridge: port 2(veth4b78a65) entered disabled state
[   40.181771] device veth4b78a65 entered promiscuous mode
[   40.182460] docker_gwbridge: port 2(veth4b78a65) entered blocking state
[   40.182476] docker_gwbridge: port 2(veth4b78a65) entered forwarding state
[   40.344059] IPv6: ADDRCONF(NETDEV_CHANGE): veth4b78a65: link becomes ready
[   41.157254] cgroup: cgroup: disabling cgroup2 socket matching due to net_prio or net_cls activation
[   41.162373] veth1: renamed from veth7aa9eeb
[   41.209687] br0: port 3(veth1) entered blocking state
[   41.209704] br0: port 3(veth1) entered disabled state
[   41.209999] device veth1 entered promiscuous mode
[   41.266905] veth2: renamed from vethfa9d430
[   41.325241] br0: port 4(veth2) entered blocking state
[   41.325255] br0: port 4(veth2) entered disabled state
[   41.325620] device veth2 entered promiscuous mode
[   41.466234] docker_gwbridge: port 3(veth6f5d04e) entered blocking state
[   41.466249] docker_gwbridge: port 3(veth6f5d04e) entered disabled state
[   41.466808] device veth6f5d04e entered promiscuous mode
[   41.471903] docker_gwbridge: port 3(veth6f5d04e) entered blocking state
[   41.471921] docker_gwbridge: port 3(veth6f5d04e) entered forwarding state
[   41.604929] docker_gwbridge: port 3(veth6f5d04e) entered disabled state
[   41.605113] IPv6: ADDRCONF(NETDEV_CHANGE): veth935b170: link becomes ready
[   41.605274] br0: port 4(veth2) entered blocking state
[   41.605283] br0: port 4(veth2) entered forwarding state
[   41.706352] docker_gwbridge: port 4(veth6c0edad) entered blocking state
[   41.706368] docker_gwbridge: port 4(veth6c0edad) entered disabled state
[   41.706689] device veth6c0edad entered promiscuous mode
[   41.707280] docker_gwbridge: port 4(veth6c0edad) entered blocking state
[   41.707294] docker_gwbridge: port 4(veth6c0edad) entered forwarding state
[   41.820880] docker_gwbridge: port 4(veth6c0edad) entered disabled state
[   41.821620] IPv6: ADDRCONF(NETDEV_CHANGE): veth25ef554: link becomes ready
[   41.822248] br0: port 3(veth1) entered blocking state
[   41.822268] br0: port 3(veth1) entered forwarding state
[   41.977358] IPv6: ADDRCONF(NETDEV_CHANGE): veth6f5d04e: link becomes ready
[   41.977562] docker_gwbridge: port 3(veth6f5d04e) entered blocking state
[   41.977574] docker_gwbridge: port 3(veth6f5d04e) entered forwarding state
[   42.089763] IPv6: ADDRCONF(NETDEV_CHANGE): veth6c0edad: link becomes ready
[   42.089901] docker_gwbridge: port 4(veth6c0edad) entered blocking state
[   42.089910] docker_gwbridge: port 4(veth6c0edad) entered forwarding state
[   43.584597] br0: port 3(veth1) entered disabled state
[   43.586720] eth0: renamed from veth4ec0c0c
[   43.656289] br0: port 3(veth1) entered blocking state
[   43.656308] br0: port 3(veth1) entered forwarding state
[   43.777918] docker_gwbridge: port 2(veth4b78a65) entered disabled state
[   43.781064] eth1: renamed from veth1ac2abc
[   43.836420] docker_gwbridge: port 2(veth4b78a65) entered blocking state
[   43.836463] docker_gwbridge: port 2(veth4b78a65) entered forwarding state
[   44.579002] EXT4-fs (dm-4): mounted filesystem with ordered data mode. Opts: (null)
[   45.276927] EXT4-fs (dm-4): mounted filesystem with ordered data mode. Opts: (null)
[   45.575383] br0: port 4(veth2) entered disabled state
[   45.665118] br0: port 3(veth1) entered disabled state
[   45.666216] eth0: renamed from veth25ef554
[   45.754722] eth0: renamed from veth935b170
[   45.826720] br0: port 4(veth2) entered blocking state
[   45.826737] br0: port 4(veth2) entered forwarding state
[   45.828434] br0: port 3(veth1) entered blocking state
[   45.828456] br0: port 3(veth1) entered forwarding state
[   45.945714] docker_gwbridge: port 4(veth6c0edad) entered disabled state
[   46.034757] docker_gwbridge: port 3(veth6f5d04e) entered disabled state
[   46.036320] eth1: renamed from veth56a3588
[   46.085703] eth1: renamed from vethd97754c
[   46.206346] docker_gwbridge: port 3(veth6f5d04e) entered blocking state
[   46.206363] docker_gwbridge: port 3(veth6f5d04e) entered forwarding state
[   46.206967] docker_gwbridge: port 4(veth6c0edad) entered blocking state
[   46.206987] docker_gwbridge: port 4(veth6c0edad) entered forwarding state
[   49.168100] EXT4-fs (dm-4): mounted filesystem with ordered data mode. Opts: (null)
[   50.085406] veth3: renamed from veth4dcdf9c
[   50.127389] br0: port 5(veth3) entered blocking state
[   50.127405] br0: port 5(veth3) entered disabled state
[   50.127729] device veth3 entered promiscuous mode
[   50.225613] docker_gwbridge: port 5(veth909ad26) entered blocking state
[   50.225635] docker_gwbridge: port 5(veth909ad26) entered disabled state
[   50.226401] device veth909ad26 entered promiscuous mode
[   50.227618] docker_gwbridge: port 5(veth909ad26) entered blocking state
[   50.227644] docker_gwbridge: port 5(veth909ad26) entered forwarding state
[   50.296195] docker_gwbridge: port 5(veth909ad26) entered disabled state
[   50.296409] IPv6: ADDRCONF(NETDEV_CHANGE): vethabec150: link becomes ready
[   50.296586] br0: port 5(veth3) entered blocking state
[   50.296595] br0: port 5(veth3) entered forwarding state
[   50.489730] IPv6: ADDRCONF(NETDEV_CHANGE): veth909ad26: link becomes ready
[   50.489806] docker_gwbridge: port 5(veth909ad26) entered blocking state
[   50.489815] docker_gwbridge: port 5(veth909ad26) entered forwarding state
[   52.671919] br0: port 5(veth3) entered disabled state
[   52.673362] eth0: renamed from vethabec150
[   52.744452] br0: port 5(veth3) entered blocking state
[   52.744468] br0: port 5(veth3) entered forwarding state
[   52.857102] docker_gwbridge: port 5(veth909ad26) entered disabled state
[   52.858109] eth1: renamed from veth6a162ae
[   52.913946] docker_gwbridge: port 5(veth909ad26) entered blocking state
[   52.913963] docker_gwbridge: port 5(veth909ad26) entered forwarding state

Additional context
This issue is reproducible on all of my Pi 3B+ units (3x bought from different retailers at different times) and a Pi 4B unit. All 4 devices have the official PoE HAT and were working perfectly until earlier today when I upgraded the kernel. I didn't realize the fans stopped until I upgraded and rebooted the last Pi.

Additionally, all 4 are running stock Raspberry Pi OS 32-bit lite and no modifications were made to the config.txt directly (only through raspi-config).
@ndanyluk
Copy link
Author

ndanyluk commented Feb 5, 2021

Also appears related to #1531, but opposite (their fans don't turn off).

Is it possible that the kernel upgrade or bootloader upgrade broke the fan dtoverlay and they retain their last known settings?

@pelwell
Copy link
Contributor

pelwell commented Feb 5, 2021

Your dtoverlay line is too long. Use sudo vcdbg log msg to see the warnings from the firmware.

Parameters to an overlay can be split over multiple lines by starting the continuations with dtparam=. The current overlay remains "in scope" until the next dtoverlay line.

@ndanyluk
Copy link
Author

ndanyluk commented Feb 5, 2021

Your dtoverlay line is too long. Use sudo vcdbg log msg to see the warnings from the firmware.

Parameters to an overlay can be split over multiple lines by starting the continuations with dtparam=. The current overlay remains "in scope" until the next dtoverlay line.

Fair enough, I'll reformat that and see what happens. Just to be clear though, the problem originated before adding anything to config.txt - that was only a troubleshooting step. Previously the fan "just worked" without any manual configuration required

@pelwell
Copy link
Contributor

pelwell commented Feb 5, 2021

Since writing that I have reproduced the problem, and am now confused.

@ndanyluk
Copy link
Author

ndanyluk commented Feb 5, 2021

Since writing that I have reproduced the problem, and am now confused.

I tried formatting my config.txt like you suggested but same vcdbg log msg output. There's some speculation that a particular commit might have caused the issue

@pelwell
Copy link
Contributor

pelwell commented Feb 5, 2021

I'm closing this issue as a duplicate of #1531.

@pelwell pelwell closed this as completed Feb 5, 2021
@pelwell pelwell reopened this Feb 8, 2021
@pelwell
Copy link
Contributor

pelwell commented Feb 8, 2021

This isn't a duplicate after all, but it has been diagnosed and fixed in the firmware development repo. Expect a fix to be released in the next few days.

@pelwell
Copy link
Contributor

pelwell commented Feb 8, 2021

rpi-update contains the potential fix. Please test and report.

@ndanyluk
Copy link
Author

ndanyluk commented Feb 8, 2021

rpi-update contains the potential fix. Please test and report.

That seems to have worked! Will report if any strange things happen

@ricktendo
Copy link

Working again!

@bondskin
Copy link

Working here, too, thanks.

@pelwell pelwell closed this as completed Feb 11, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@pelwell @ndanyluk @ricktendo @bondskin