home-assistant / operating-system

:beginner: Home Assistant Operating System
Apache License 2.0
4.99k stars 977 forks source link

OS 5.11 freezes my Pi4 on SSD #1201

Closed bschatzow closed 3 years ago

bschatzow commented 3 years ago

Hardware Environment

Home Assistant OS release:

alex88 commented 3 years ago

This is probably a duplicate of #1119, quite a few people are experiencing this bug

bschatzow commented 3 years ago

I realize this. I was told to open a new one.

agners commented 3 years ago

For the

mmc0: Timeout waiting for hardware cmd interrupt.

messages a fix is available, see: https://github.com/home-assistant/operating-system/tree/dev/Documentation/boards/raspberrypi#usb-boot

Do you experience problems even after setting sd_poll_once=on?

agners commented 3 years ago

The Linux kernel has been updated to Linux 5.4 with HAOS release 5.5, and I think some problems might be related to that. But it sounds like HAOS 5.4 already causes problems for you? If the above does not help, can you recheck if it starts with HAOS 5.4 or 5.5?

bschatzow commented 3 years ago

Are you saying to change this sd_poll_once=on? This seems related to boot on SSD, which is not my issue.

I am also confuse on when the kernel was changed It shows it on HassOS Release-4 build 16 (Stable). Not sure why there is a different numbering scheme? I did not try 5.4, but others in the 1119 did and it did not work for them. I try this update and get back to you. If it fails and it has the same kernel as 5.3, maybe it is something else? By the way a spreadsheet was created on 1119 where users are putting in all their information. If you get a chance can you take a look and add a column for any additional information you need.

agners commented 3 years ago

Are you saying to change this sd_poll_once=on? This seems related to boot on SSD, which is not my issue.

But you are booting from SSD right? Or do you have a SD card as well?

If you do boot from SD, then all this mmc0: Timeout waiting for hardware cmd interrupt. messages should disappear with sd_poll_once=on. It could be that this is the root cause of the problems you are seeing.

I am also confuse on when the kernel was changed It shows it on HassOS Release-4 build 16 (Stable).

HAOS updates the kernel quite often, but often its only minor security/bug fixes. However in HA OS release 5.5 we moved from Linux 4.19 to 5.4 for all Raspberry Pi's, so this can change behavior etc...

bschatzow commented 3 years ago

Only boot Home Assistant on SSD. If I need to update the firmware I use a SD card. I have updated to 5.4. If this works I can try the mmc0 and then try the 5.11 again. I don't understand why this change is needed for the kernel change and not an issue in older versions? I am also a little confused with the directions on sd_poll_once=on to dtparam in the config.txt. I do not have a dtparam in my config.txt file on the SSD.

bschatzow commented 3 years ago

I figured out how to change the config.txt file and added dtparam=sd_poll_once=on. OS 5.4 seemed fine before the change. I just made the change then upgraded the OS to 5.11 at 6PM EST. I'll let you know if the config.txt change fixes the issue. Thanks for the help.

bschatzow commented 3 years ago

hardware cmd interrupt. messages should disappear with sd_poll_once=on. It could be that this is the root cause of the problems you are seeing. @agners Made the changes and system froze after 7 hrs 57 minutes. Going back to 5.4. No errors in any logs. Seems unrelated to SSD and controller. Not sure what to try next.

bschatzow commented 3 years ago

New dmseg

# dmesg
[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083]
[    0.000000] Linux version 5.4.83-v8 (builder@465349041c38) (gcc version 9.3.0 (Buildroot -g1a551c07)) #1 SMP PREEMPT Sun Jan 31 04:08:28 UTC 2021
[    0.000000] Machine model: Raspberry Pi 4 Model B Rev 1.2
[    0.000000] efi: Getting EFI parameters from FDT:
[    0.000000] efi: UEFI not found.
[    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: 1012480
[    0.000000]   DMA zone: 3788 pages used for memmap
[    0.000000]   DMA zone: 0 pages reserved
[    0.000000]   DMA zone: 242432 pages, LIFO batch:63
[    0.000000]   DMA32 zone: 12032 pages used for memmap
[    0.000000]   DMA32 zone: 770048 pages, LIFO batch:63
[    0.000000] percpu: Embedded 31 pages/cpu s89432 r8192 d29352 u126976
[    0.000000] pcpu-alloc: s89432 r8192 d29352 u126976 alloc=31*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: 996660
[    0.000000] Kernel command line: zram.enabled=1 zram.num_devices=3 apparmor=1 security=apparmor rootwait systemd.machine_id=4247b5e639ba4e3887466667a2fb6eaf cgroup_enable=memory fsck.repair=yes coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=592 bcm2708_fb.fbheight=448 bcm2708_fb.fbswap=1 smsc95xx.macaddr=DC:A6:32:75:DC:C6 vc_mem.mem_base=0x3eb00000 vc_mem.mem_size=0x3ff00000  dwc_otg.lpm_enable=0 console=tty1 root=PARTUUID=8d3d53e3-6d49-4c38-8349-aff6859e82fd rootfstype=squashfs ro rauc.slot=A
[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)
[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] software IO TLB: mapped [mem 0x37300000-0x3b300000] (64MB)
[    0.000000] Memory: 3819772K/4049920K available (11004K kernel code, 1176K rwdata, 3744K rodata, 1088K init, 1232K bss, 164612K reserved, 65536K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 36308 entries in 142 pages
[    0.000000] rcu: Preemptible hierarchical RCU implementation.
[    0.000000] rcu:     RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4.
[    0.000000]  Tasks RCU enabled.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4
[    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+0x320/0x4b0 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.000223] Console: colour dummy device 80x25
[    0.000649] printk: console [tty1] enabled
[    0.000705] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000)
[    0.000738] pid_max: default: 32768 minimum: 301
[    0.000875] LSM: Security Framework initializing
[    0.001001] AppArmor: AppArmor initialized
[    0.001207] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    0.001277] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    0.003547] ASID allocator initialised with 32768 entries
[    0.003756] rcu: Hierarchical SRCU implementation.
[    0.004470] EFI services will not be available.
[    0.004926] smp: Bringing up secondary CPUs ...
[    0.005804] Detected PIPT I-cache on CPU1
[    0.005861] CPU1: Booted secondary processor 0x0000000001 [0x410fd083]
[    0.006846] Detected PIPT I-cache on CPU2
[    0.006884] CPU2: Booted secondary processor 0x0000000002 [0x410fd083]
[    0.007802] Detected PIPT I-cache on CPU3
[    0.007841] CPU3: Booted secondary processor 0x0000000003 [0x410fd083]
[    0.007974] smp: Brought up 1 node, 4 CPUs
[    0.008061] SMP: Total of 4 processors activated.
[    0.008082] CPU features: detected: 32-bit EL0 Support
[    0.008105] CPU features: detected: CRC32 instructions
[    0.033608] CPU: All CPU(s) started at EL2
[    0.033677] alternatives: patching kernel code
[    0.035268] devtmpfs: initialized
[    0.045214] Enabled cp15_barrier support
[    0.045265] Enabled setend support
[    0.045672] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[    0.045716] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[    0.047742] pinctrl core: initialized pinctrl subsystem
[    0.048457] DMI not present or invalid.
[    0.048811] NET: Registered protocol family 16
[    0.051599] DMA: preallocated 1024 KiB pool for atomic allocations
[    0.051632] audit: initializing netlink subsys (disabled)
[    0.051938] audit: type=2000 audit(0.048:1): state=initialized audit_enabled=0 res=1
[    0.052660] cpuidle: using governor menu
[    0.053151] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[    0.053387] Serial: AMBA PL011 UART driver
[    0.056470] bcm2835-mbox fe00b880.mailbox: mailbox enabled
[    0.068184] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-10-22 13:59, variant start
[    0.072214] raspberrypi-firmware soc:firmware: Firmware hash is 74e754ff8947c58d2773253f77f6f68a303188f8
[    0.112096] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1
[    0.115471] vgaarb: loaded
[    0.115884] SCSI subsystem initialized
[    0.116101] usbcore: registered new interface driver usbfs
[    0.116171] usbcore: registered new interface driver hub
[    0.116334] usbcore: registered new device driver usb
[    0.116621] usb_phy_generic phy: phy supply vcc not found, using dummy regulator
[    0.116903] mc: Linux media interface: v0.10
[    0.116948] videodev: Linux video capture interface: v2.00
[    0.118446] clocksource: Switched to clocksource arch_sys_counter
[    0.857534] VFS: Disk quotas dquot_6.6.0
[    0.857639] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.857843] FS-Cache: Loaded
[    0.858058] CacheFiles: Loaded
[    0.858781] AppArmor: AppArmor Filesystem Enabled
[    0.868270] thermal_sys: Registered thermal governor 'step_wise'
[    0.868602] NET: Registered protocol family 2
[    0.869372] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)
[    0.869438] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)
[    0.869652] TCP bind hash table entries: 32768 (order: 7, 524288 bytes, linear)
[    0.870094] TCP: Hash tables configured (established 32768 bind 32768)
[    0.870337] UDP hash table entries: 2048 (order: 4, 65536 bytes, linear)
[    0.870415] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear)
[    0.870806] NET: Registered protocol family 1
[    0.871626] RPC: Registered named UNIX socket transport module.
[    0.871651] RPC: Registered udp transport module.
[    0.871670] RPC: Registered tcp transport module.
[    0.871688] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.871718] PCI: CLS 0 bytes, default 64
[    0.873751] hw perfevents: enabled with armv8_cortex_a72 PMU driver, 7 counters available
[    0.873981] kvm: Limiting the IPA size due to kernel Virtual Address limit
[    0.874004] kvm [1]: IPA Size Limit: 43bits
[    0.874869] kvm [1]: vgic interrupt IRQ1
[    0.875118] kvm [1]: Hyp mode initialized successfully
[    0.876977] Initialise system trusted keyrings
[    0.877274] workingset: timestamp_bits=46 max_order=20 bucket_order=0
[    0.885702] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.885976] FS-Cache: Netfs 'nfs' registered for caching
[    0.886682] NFS: Registering the id_resolver key type
[    0.886729] Key type id_resolver registered
[    0.886749] Key type id_legacy registered
[    0.886785] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    0.888055] Key type asymmetric registered
[    0.888080] Asymmetric key parser 'x509' registered
[    0.888135] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248)
[    0.888390] io scheduler mq-deadline registered
[    0.888414] io scheduler kyber registered
[    0.891759] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
[    0.891796] brcm-pcie fd500000.pcie:   No bus range found for /scb/pcie@7d500000, using [bus 00-ff]
[    0.891869] brcm-pcie fd500000.pcie:      MEM 0x0600000000..0x0603ffffff -> 0x00f8000000
[    0.891941] brcm-pcie fd500000.pcie:   IB MEM 0x0000000000..0x00bfffffff -> 0x0000000000
[    0.940541] brcm-pcie fd500000.pcie: link up, 5 GT/s x1 (SSC)
[    0.940855] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
[    0.940884] pci_bus 0000:00: root bus resource [bus 00-ff]
[    0.940911] pci_bus 0000:00: root bus resource [mem 0x600000000-0x603ffffff] (bus address [0xf8000000-0xfbffffff])
[    0.940982] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
[    0.941208] pci 0000:00:00.0: PME# supported from D0 D3hot
[    0.945018] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330
[    0.945167] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
[    0.945565] pci 0000:01:00.0: PME# supported from D0 D3cold
[    0.949138] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
[    0.949173] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]
[    0.949262] pci 0000:00:00.0: PCI bridge to [bus 01]
[    0.949292] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]
[    0.949410] pci 0000:00:00.0: enabling device (0000 -> 0002)
[    0.949476] pci 0000:01:00.0: enabling device (0000 -> 0002)
[    0.950089] bcm2708_fb soc:fb: FB found 1 display(s)
[    0.959859] Console: switching to colour frame buffer device 74x28
[    0.961872] bcm2708_fb soc:fb: Registered framebuffer for display 0, size 592x448
[    0.967200] iproc-rng200 fe104000.rng: hwrng registered
[    0.968640] vc-mem: phys_addr:0x00000000 mem_base=0x3eb00000 mem_size:0x3ff00000(1023 MiB)
[    0.971583] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
[    0.974063] cacheinfo: Unable to detect cache hierarchy for CPU 0
[    0.985179] brd: module loaded
[    0.997905] loop: module loaded
[    0.999626] zram: Added device: zram0
[    1.001147] zram: Added device: zram1
[    1.002749] zram: Added device: zram2
[    1.004982] Loading iSCSI transport class v2.0-870.
[    1.008361] libphy: Fixed MDIO Bus: probed
[    1.009385] tun: Universal TUN/TAP device driver, 1.6
[    1.011110] bcmgenet fd580000.ethernet: failed to get enet clock
[    1.012138] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000
[    1.013147] bcmgenet fd580000.ethernet: failed to get enet-wol clock
[    1.014149] bcmgenet fd580000.ethernet: failed to get enet-eee clock
[    1.015191] bcmgenet: Skipping UMAC reset
[    1.026484] libphy: bcmgenet MII bus: probed
[    1.074544] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus
[    1.076372] usbcore: registered new interface driver r8152
[    1.077417] usbcore: registered new interface driver lan78xx
[    1.078946] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    1.079956] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
[    1.082838] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000003000000890
[    1.086012] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.04
[    1.088009] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.089961] usb usb1: Product: xHCI Host Controller
[    1.090978] usb usb1: Manufacturer: Linux 5.4.83-v8 xhci-hcd
[    1.091962] usb usb1: SerialNumber: 0000:01:00.0
[    1.093523] hub 1-0:1.0: USB hub found
[    1.094621] hub 1-0:1.0: 1 port detected
[    1.096130] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    1.097174] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
[    1.099236] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[    1.100734] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.04
[    1.102896] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.105141] usb usb2: Product: xHCI Host Controller
[    1.106305] usb usb2: Manufacturer: Linux 5.4.83-v8 xhci-hcd
[    1.107499] usb usb2: SerialNumber: 0000:01:00.0
[    1.109190] hub 2-0:1.0: USB hub found
[    1.110391] hub 2-0:1.0: 4 ports detected
[    1.112849] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    1.114232] dwc_otg: FIQ enabled
[    1.114241] dwc_otg: NAK holdoff enabled
[    1.114249] dwc_otg: FIQ split-transaction FSM enabled
[    1.114261] Module dwc_common_port init
[    1.114803] usbcore: registered new interface driver uas
[    1.116058] usbcore: registered new interface driver usb-storage
[    1.117304] usbcore: registered new interface driver usbserial_generic
[    1.118464] usbserial: USB Serial support registered for generic
[    1.119770] mousedev: PS/2 mouse device common for all mice
[    1.122472] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[    1.126740] sdhci: Secure Digital Host Controller Interface driver
[    1.127819] sdhci: Copyright(c) Pierre Ossman
[    1.129377] mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe
[    1.130860] sdhci-pltfm: SDHCI platform and OF driver helper
[    1.133490] ledtrig-cpu: registered to indicate activity on CPUs
[    1.134139] hidraw: raw HID events driver (C) Jiri Kosina
[    1.134761] usbcore: registered new interface driver usbhid
[    1.135282] usbhid: USB HID core driver
[    1.136370] vchiq: vchiq_init_state: slot_zero = (____ptrval____)
[    1.140821] IPVS: Registered protocols (TCP, UDP, SCTP, AH, ESP)
[    1.141475] IPVS: Connection hash table configured (size=4096, memory=64Kbytes)
[    1.142765] IPVS: ipvs loaded.
[    1.143350] IPVS: [rr] scheduler registered.
[    1.144423] NET: Registered protocol family 10
[    1.145853] Segment Routing with IPv6
[    1.146536] NET: Registered protocol family 17
[    1.147113] Bridge firewalling registered
[    1.147808] Key type dns_resolver registered
[    1.148702] registered taskstats version 1
[    1.149203] Loading compiled-in X.509 certificates
[    1.149889] Key type ._fscrypt registered
[    1.150420] Key type .fscrypt registered
[    1.151012] AppArmor: AppArmor sha1 policy hashing enabled
[    1.156271] uart-pl011 fe201000.serial: cts_event_workaround enabled
[    1.156880] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 14, base_baud = 0) is a PL011 rev2
[    1.163764] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[    1.165084] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0
[    1.165580] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated
[    1.215373] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[    1.217635] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    1.219731] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    1.223299] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[    1.225585] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    1.226647] mmc0: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA
[    1.230110] printk: console [netcon0] enabled
[    1.230785] netconsole: network logging started
[    1.231376] of_cfs_init
[    1.232005] of_cfs_init: OK
[    1.233221] Waiting for root device PARTUUID=8d3d53e3-6d49-4c38-8349-aff6859e82fd...
[    1.254830] random: fast init done
[    1.288765] mmc1: new high speed SDIO card at address 0001
[    1.430483] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[    1.581125] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21
[    1.583088] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[    1.585111] usb 1-1: Product: USB2.0 Hub
[    1.587637] hub 1-1:1.0: USB hub found
[    1.589066] hub 1-1:1.0: 4 ports detected
[    1.706899] usb 2-2: new SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[    1.727967] usb 2-2: New USB device found, idVendor=174c, idProduct=55aa, bcdDevice= 1.00
[    1.729889] usb 2-2: New USB device strings: Mfr=2, Product=3, SerialNumber=1
[    1.731640] usb 2-2: Product: ASMT1051
[    1.732559] usb 2-2: Manufacturer: asmedia
[    1.733482] usb 2-2: SerialNumber: 12345679A6EE
[    1.743865] scsi host0: uas
[    1.745240] scsi 0:0:0:0: Direct-Access     KINGSTON  SA400S37120G    0    PQ: 0 ANSI: 6
[    1.747457] sd 0:0:0:0: [sda] 234441648 512-byte logical blocks: (120 GB/112 GiB)
[    1.748745] sd 0:0:0:0: [sda] Write Protect is off
[    1.749377] sd 0:0:0:0: [sda] Mode Sense: 43 00 00 00
[    1.749595] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    1.751352] sd 0:0:0:0: [sda] Optimal transfer size 33553920 bytes
[    1.755917]  sda: sda1 sda2 sda3 sda4 sda5 sda6 sda7 sda8
[    1.758882] sd 0:0:0:0: [sda] Attached SCSI disk
[    1.776728] VFS: Mounted root (squashfs filesystem) readonly on device 8:3.
[    1.779986] devtmpfs: mounted
[    1.784379] Freeing unused kernel memory: 1088K
[    1.790503] Run /sbin/init as init process
[    1.882482] usb 1-1.4: new full-speed USB device number 3 using xhci_hcd
[    1.918538] systemd[1]: System time before build time, advancing clock.
[    1.930654] systemd[1]: systemd 246 running in system mode. (+PAM -AUDIT -SELINUX -IMA +APPARMOR -SMACK -SYSVINIT -UTMP -LIBCRYPTSETUP +GCRYPT +GNUTLS -ACL -XZ -LZ4 -ZSTD -SECCOMP +BLKID -ELFUTILS +KMOD -IDN2 -IDN -PCRE2 default-hierarchy=hybrid)
[    1.933379] systemd[1]: Detected architecture arm64.
[    1.958633] systemd[1]: Set hostname to <homeassistant>.
[    1.960139] systemd[1]: Installed transient /etc/machine-id file.
[    1.984684] usb 1-1.4: New USB device found, idVendor=1a86, idProduct=e024, bcdDevice= 1.0c
[    1.986226] usb 1-1.4: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    1.993571] hid-generic 0003:1A86:E024.0001: hiddev96,hidraw0: USB HID v1.00 Device [HID 1a86:e024] on usb-0000:01:00.0-1.4/input0
[    2.089267] systemd[1]: /usr/lib/systemd/system/docker.socket:6: ListenStream= references a path below legacy directory /var/run/, updating /var/run/docker.sock \xe2\x86\x92 /run/docker.sock; please update the unit file accordingly.
[    2.164509] systemd[1]: Queued start job for default target Multi-User System.
[    2.166392] random: systemd: uninitialized urandom read (16 bytes read)
[    2.169598] systemd[1]: Created slice system-getty.slice.
[    2.171315] random: systemd: uninitialized urandom read (16 bytes read)
[    2.172986] systemd[1]: Created slice system-modprobe.slice.
[    2.174589] random: systemd: uninitialized urandom read (16 bytes read)
[    2.176230] systemd[1]: Created slice system-systemd\x2dfsck.slice.
[    2.179122] systemd[1]: Created slice system-systemd\x2dgrowfs.slice.
[    2.181633] systemd[1]: Created slice User and Session Slice.
[    2.183500] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[    2.185877] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    2.188301] systemd[1]: Reached target HassOS zram targets.
[    2.189855] systemd[1]: Reached target Paths.
[    2.191478] systemd[1]: Reached target Remote File Systems.
[    2.192965] systemd[1]: Reached target Slices.
[    2.196555] systemd[1]: Listening on Process Core Dump Socket.
[    2.198528] systemd[1]: Listening on Journal Audit Socket.
[    2.200232] systemd[1]: Listening on Journal Socket (/dev/log).
[    2.201951] systemd[1]: Listening on Journal Socket.
[    2.203759] systemd[1]: Listening on udev Control Socket.
[    2.205353] systemd[1]: Listening on udev Kernel Socket.
[    2.206991] systemd[1]: Condition check resulted in Huge Pages File System being skipped.
[    2.210912] systemd[1]: Mounting POSIX Message Queue File System...
[    2.216106] systemd[1]: Mounting Kernel Debug File System...
[    2.221129] systemd[1]: Mounting Kernel Trace File System...
[    2.226719] systemd[1]: Starting Create list of static device nodes for the current kernel...
[    2.232286] systemd[1]: Starting Load Kernel Module configfs...
[    2.237559] systemd[1]: Starting Load Kernel Module drm...
[    2.243018] systemd[1]: Starting Load Kernel Module fuse...
[    2.250341] systemd[1]: Starting Journal Service...
[    2.256676] systemd[1]: Starting Remount Root and Kernel File Systems...
[    2.257234] fuse: init (API version 7.31)
[    2.265515] systemd[1]: Starting Coldplug All udev Devices...
[    2.271921] systemd[1]: Starting HassOS ZRAM swap...
[    2.278221] systemd[1]: Starting HassOS ZRAM tmp...
[    2.284011] systemd[1]: Starting HassOS ZRAM var...
[    2.291776] systemd[1]: Mounted POSIX Message Queue File System.
[    2.293720] systemd[1]: Mounted Kernel Debug File System.
[    2.296181] systemd[1]: Mounted Kernel Trace File System.
[    2.300564] systemd[1]: Finished Create list of static device nodes for the current kernel.
[    2.304259] systemd[1]: modprobe@configfs.service: Succeeded.
[    2.306660] systemd[1]: Finished Load Kernel Module configfs.
[    2.309610] systemd[1]: modprobe@fuse.service: Succeeded.
[    2.311896] systemd[1]: Finished Load Kernel Module fuse.
[    2.315355] zram1: detected capacity change from 0 to 33554432
[    2.316887] systemd[1]: Finished Remount Root and Kernel File Systems.
[    2.318770] zram2: detected capacity change from 0 to 16777216
[    2.321781] zram0: detected capacity change from 0 to 994918400
[    2.322082] systemd[1]: modprobe@drm.service: Succeeded.
[    2.326238] systemd[1]: Finished Load Kernel Module drm.
[    2.332082] systemd[1]: Mounting FUSE Control File System...
[    2.338588] systemd[1]: Mounting Kernel Configuration File System...
[    2.344232] systemd[1]: Starting Create Static Device Nodes in /dev...
[    2.350048] systemd[1]: Mounted FUSE Control File System.
[    2.353029] systemd[1]: Mounted Kernel Configuration File System.
[    2.371003] systemd[1]: Started Journal Service.
[    2.560242] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000
[    2.561818] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000
[    2.568509] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000
[    2.570998] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000
[    2.578719] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    2.581495] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[    2.582236] [vc_sm_connected_init]: start
[    2.593377] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    2.595261] [vc_sm_connected_init]: installed successfully
[    2.595459] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    2.598467] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    2.612478] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
[    2.615691] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    2.623857] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
[    2.633727] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
[    2.644807] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
[    2.647347] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
[    2.649133] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13
[    2.674389] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
[    2.680156] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14
[    2.692742] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15
[    2.700048] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16
[    2.701937] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
[    2.712158] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
[    2.713989] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
[    2.717830] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
[    2.720046] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
[    2.724886] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
[    2.727831] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
[    2.730159] bcm2835_audio bcm2835_audio: card created with 4 channels
[    2.732968] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
[    2.765339] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp
[    2.767244] bcm2835_audio bcm2835_audio: card created with 4 channels
[    2.789749] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    2.831932] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    2.872725] brcmfmac: F1 signature read @0x18000000=0x15264345
[    2.876569] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    2.879156] usbcore: registered new interface driver brcmfmac
[    2.888572] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,4-model-b.txt failed with error -2
[    2.968646] FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[    3.066922] EXT4-fs (sda7): mounted filesystem with ordered data mode. Opts: (null)
[    3.069017] ext4 filesystem being mounted at /mnt/overlay supports timestamps until 2038 (0x7fffffff)
[    3.084922] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    3.104576] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Feb 27 2018 03:15:32 version 7.45.154 (r684107 CY) FWID 01-4fbe0b04
[    3.398641] Adding 971596k swap on /dev/zram0.  Priority:-2 extents:1 across:971596k SSFS
[    3.705568] EXT4-fs (sda8): mounted filesystem with ordered data mode. Opts: (null)
[    3.739778] EXT4-fs (sda8): resizing filesystem from 29126769 to 29126769 blocks
[    4.384339] EXT4-fs (zram2): mounted filesystem without journal. Opts: nobarrier
[    4.384366] ext4 filesystem being mounted at /tmp supports timestamps until 2038 (0x7fffffff)
[    4.387785] EXT4-fs (zram1): mounted filesystem without journal. Opts: nobarrier
[    4.387807] ext4 filesystem being mounted at /var supports timestamps until 2038 (0x7fffffff)
[    4.412667] random: crng init done
[    4.412674] random: 7 urandom warning(s) missed due to ratelimiting
[    4.958412] uart-pl011 fe201000.serial: no DMA platform data
[    4.989711] audit: type=1400 audit(1612419898.203:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="hassio-supervisor" pid=332 comm="apparmor_parser"
[    4.991847] audit: type=1400 audit(1612419898.203:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="hassio-supervisor///usr/bin/gdbus" pid=332 comm="apparmor_parser"
[    4.992168] audit: type=1400 audit(1612419898.203:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="hassio-supervisor///usr/bin/git" pid=332 comm="apparmor_parser"
[    4.992333] audit: type=1400 audit(1612419898.203:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="hassio-supervisor///usr/bin/socat" pid=332 comm="apparmor_parser"
[    5.394978] bcmgenet: Skipping UMAC reset
[    5.398966] bcmgenet fd580000.ethernet: configuring instance for external RGMII
[    5.399137] bcmgenet fd580000.ethernet eth0: Link is Down
[    5.439803] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
[    5.567648] Bluetooth: Core ver 2.22
[    5.567702] NET: Registered protocol family 31
[    5.567706] Bluetooth: HCI device and connection manager initialized
[    5.567720] Bluetooth: HCI socket layer initialized
[    5.567727] Bluetooth: L2CAP socket layer initialized
[    5.567744] Bluetooth: SCO socket layer initialized
[    5.578061] Bluetooth: HCI UART driver ver 2.3
[    5.578070] Bluetooth: HCI UART protocol H4 registered
[    5.578108] Bluetooth: HCI UART protocol Three-wire (H5) registered
[    5.578235] Bluetooth: HCI UART protocol Broadcom registered
[    5.675092] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[    5.675099] Bluetooth: BNEP filters: protocol multicast
[    5.675112] Bluetooth: BNEP socket layer initialized
[    5.694996] NET: Registered protocol family 38
[    5.726507] cryptd: max_cpu_qlen set to 1000
[   10.526520] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
[   10.526547] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   12.931010] audit: type=1400 audit(1612419906.147:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="docker-default" pid=429 comm="apparmor_parser"
[   14.571084] audit: type=1325 audit(1612419907.787:4): table=nat family=2 entries=5
[   14.578281] audit: type=1325 audit(1612419907.791:5): table=filter family=2 entries=4
[   14.584817] audit: type=1325 audit(1612419907.799:6): table=filter family=2 entries=6
[   14.592794] audit: type=1325 audit(1612419907.807:7): table=filter family=2 entries=8
[   14.600469] audit: type=1325 audit(1612419907.815:8): table=filter family=2 entries=10
[   14.605823] audit: type=1325 audit(1612419907.819:9): table=filter family=2 entries=11
[   14.608479] audit: type=1325 audit(1612419907.823:10): table=filter family=2 entries=12
[   14.627072] Initializing XFRM netlink socket
[   14.656449] audit: type=1325 audit(1612419907.871:11): table=nat family=2 entries=7
[   14.674652] audit: type=1325 audit(1612419907.891:12): table=nat family=2 entries=8
[   18.319295] kauditd_printk_skb: 43 callbacks suppressed
[   18.319301] audit: type=1325 audit(1612419911.535:56): table=nat family=2 entries=25
[   18.326122] audit: type=1325 audit(1612419911.539:57): table=filter family=2 entries=31
[   18.333107] audit: type=1325 audit(1612419911.547:58): table=nat family=2 entries=24
[   18.342311] audit: type=1325 audit(1612419911.555:59): table=nat family=2 entries=23
[   18.350600] audit: type=1325 audit(1612419911.563:60): table=filter family=2 entries=30
[   18.359294] audit: type=1325 audit(1612419911.575:61): table=nat family=2 entries=22
[   18.367635] audit: type=1325 audit(1612419911.583:62): table=nat family=2 entries=21
[   18.374865] audit: type=1325 audit(1612419911.591:63): table=filter family=2 entries=29
[   18.382924] audit: type=1325 audit(1612419911.599:64): table=nat family=2 entries=20
[   18.392178] audit: type=1325 audit(1612419911.607:65): table=nat family=2 entries=19
[   20.837261] hassio: port 1(veth124ae15) entered blocking state
[   20.837270] hassio: port 1(veth124ae15) entered disabled state
[   20.837425] device veth124ae15 entered promiscuous mode
[   21.150753] cgroup: cgroup: disabling cgroup2 socket matching due to net_prio or net_cls activation
[   21.498672] eth0: renamed from vethb2c9624
[   21.531941] IPv6: ADDRCONF(NETDEV_CHANGE): veth124ae15: link becomes ready
[   21.532125] hassio: port 1(veth124ae15) entered blocking state
[   21.532136] hassio: port 1(veth124ae15) entered forwarding state
[   21.532383] IPv6: ADDRCONF(NETDEV_CHANGE): hassio: link becomes ready
[   22.584533] docker0: port 1(vethcbbf15d) entered blocking state
[   22.584544] docker0: port 1(vethcbbf15d) entered disabled state
[   22.584786] device vethcbbf15d entered promiscuous mode
[   22.616006] hassio: port 2(veth0755c9e) entered blocking state
[   22.616015] hassio: port 2(veth0755c9e) entered disabled state
[   22.616235] device veth0755c9e entered promiscuous mode
[   22.616529] hassio: port 2(veth0755c9e) entered blocking state
[   22.616536] hassio: port 2(veth0755c9e) entered forwarding state
[   22.974991] eth0: renamed from veth9cb7636
[   23.000088] hassio: port 2(veth0755c9e) entered disabled state
[   23.000320] IPv6: ADDRCONF(NETDEV_CHANGE): vethcbbf15d: link becomes ready
[   23.000494] docker0: port 1(vethcbbf15d) entered blocking state
[   23.000506] docker0: port 1(vethcbbf15d) entered forwarding state
[   23.000745] IPv6: ADDRCONF(NETDEV_CHANGE): docker0: link becomes ready
[   23.175913] eth1: renamed from veth2c4394e
[   23.191687] IPv6: ADDRCONF(NETDEV_CHANGE): veth0755c9e: link becomes ready
[   23.191826] hassio: port 2(veth0755c9e) entered blocking state
[   23.191835] hassio: port 2(veth0755c9e) entered forwarding state
[   23.689877] udevd[205]: starting version 3.2.9
[   23.704815] udevd[206]: starting eudev-3.2.9
[   29.773238] kauditd_printk_skb: 55 callbacks suppressed
[   29.773244] audit: type=1400 audit(1612419922.987:121): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="hassio-supervisor" pid=2012 comm="apparmor_parser"
[   29.773263] audit: type=1400 audit(1612419922.987:121): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="hassio-supervisor///usr/bin/gdbus" pid=2012 comm="apparmor_parser"
[   29.773276] audit: type=1400 audit(1612419922.987:121): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="hassio-supervisor///usr/bin/git" pid=2012 comm="apparmor_parser"
[   29.773288] audit: type=1400 audit(1612419922.987:121): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="hassio-supervisor///usr/bin/socat" pid=2012 comm="apparmor_parser"
[   29.988654] hassio: port 3(veth40c117e) entered blocking state
[   29.988671] hassio: port 3(veth40c117e) entered disabled state
[   29.988890] device veth40c117e entered promiscuous mode
[   29.988953] audit: type=1700 audit(1612419923.203:122): dev=veth40c117e prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
[   30.371718] audit: type=1325 audit(1612419923.587:123): table=nat family=2 entries=0
[   30.378625] audit: type=1325 audit(1612419923.595:124): table=filter family=2 entries=0
[   30.388340] audit: type=1325 audit(1612419923.603:125): table=nat family=2 entries=5
[   30.391721] audit: type=1325 audit(1612419923.607:126): table=nat family=2 entries=7
[   30.397978] audit: type=1325 audit(1612419923.611:127): table=nat family=2 entries=8
[   30.451787] eth0: renamed from vethbd2021f
[   30.467717] IPv6: ADDRCONF(NETDEV_CHANGE): veth40c117e: link becomes ready
[   30.467852] hassio: port 3(veth40c117e) entered blocking state
[   30.467861] hassio: port 3(veth40c117e) entered forwarding state
[   30.796335] hassio: port 4(veth1e09c16) entered blocking state
[   30.796346] hassio: port 4(veth1e09c16) entered disabled state
[   30.796560] device veth1e09c16 entered promiscuous mode
[   30.797482] hassio: port 4(veth1e09c16) entered blocking state
[   30.797492] hassio: port 4(veth1e09c16) entered forwarding state
[   30.982609] hassio: port 4(veth1e09c16) entered disabled state
[   31.347648] eth0: renamed from veth54148a0
[   31.384070] IPv6: ADDRCONF(NETDEV_CHANGE): veth1e09c16: link becomes ready
[   31.384259] hassio: port 4(veth1e09c16) entered blocking state
[   31.384271] hassio: port 4(veth1e09c16) entered forwarding state
[   31.662351] hassio: port 5(veth1aeb283) entered blocking state
[   31.662362] hassio: port 5(veth1aeb283) entered disabled state
[   31.662744] device veth1aeb283 entered promiscuous mode
[   31.663082] hassio: port 5(veth1aeb283) entered blocking state
[   31.663090] hassio: port 5(veth1aeb283) entered forwarding state
[   31.710492] vcc-sd: disabling
[   32.002845] hassio: port 5(veth1aeb283) entered disabled state
[   32.166815] eth0: renamed from veth8c3b32a
[   32.191262] IPv6: ADDRCONF(NETDEV_CHANGE): veth1aeb283: link becomes ready
[   32.191367] hassio: port 5(veth1aeb283) entered blocking state
[   32.191372] hassio: port 5(veth1aeb283) entered forwarding state
[   35.248242] udevd[639]: starting version 3.2.9
[   35.264664] udevd[640]: starting eudev-3.2.9
[   35.750041] Bluetooth: RFCOMM TTY layer initialized
[   35.750059] Bluetooth: RFCOMM socket layer initialized
[   35.750077] Bluetooth: RFCOMM ver 1.11
[   36.010494] hassio: port 6(vethd4d06dc) entered blocking state
[   36.010504] hassio: port 6(vethd4d06dc) entered disabled state
[   36.010744] device vethd4d06dc entered promiscuous mode
[   36.010811] kauditd_printk_skb: 27 callbacks suppressed
[   36.010815] audit: type=1700 audit(1612429421.590:155): dev=vethd4d06dc prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
[   36.045258] audit: type=1325 audit(1612429421.626:156): table=nat family=2 entries=15
[   36.052373] audit: type=1325 audit(1612429421.634:157): table=filter family=2 entries=30
[   36.059764] audit: type=1325 audit(1612429421.642:158): table=nat family=2 entries=16
[   36.073540] audit: type=1325 audit(1612429421.654:159): table=nat family=2 entries=17
[   36.081496] audit: type=1325 audit(1612429421.662:160): table=filter family=2 entries=31
[   36.089341] audit: type=1325 audit(1612429421.670:161): table=nat family=2 entries=18
[   36.103840] audit: type=1325 audit(1612429421.686:162): table=nat family=2 entries=19
[   36.111893] audit: type=1325 audit(1612429421.694:163): table=filter family=2 entries=32
[   36.119221] audit: type=1325 audit(1612429421.702:164): table=nat family=2 entries=20
[   36.593401] eth0: renamed from veth14cda6b
[   36.611426] IPv6: ADDRCONF(NETDEV_CHANGE): vethd4d06dc: link becomes ready
[   36.611540] hassio: port 6(vethd4d06dc) entered blocking state
[   36.611545] hassio: port 6(vethd4d06dc) entered forwarding state
[   37.052707] hassio: port 7(veth56d3406) entered blocking state
[   37.052718] hassio: port 7(veth56d3406) entered disabled state
[   37.056308] device veth56d3406 entered promiscuous mode
[   37.640258] eth0: renamed from veth3f742b8
[   37.660225] IPv6: ADDRCONF(NETDEV_CHANGE): veth56d3406: link becomes ready
[   37.660330] hassio: port 7(veth56d3406) entered blocking state
[   37.660335] hassio: port 7(veth56d3406) entered forwarding state
[   38.077185] hassio: port 8(veth38b5ec7) entered blocking state
[   38.077196] hassio: port 8(veth38b5ec7) entered disabled state
[   38.077636] device veth38b5ec7 entered promiscuous mode
[   38.710424] eth0: renamed from veth2062a1f
[   38.732809] IPv6: ADDRCONF(NETDEV_CHANGE): veth38b5ec7: link becomes ready
[   38.732950] hassio: port 8(veth38b5ec7) entered blocking state
[   38.732956] hassio: port 8(veth38b5ec7) entered forwarding state
[   44.934876] hassio: port 9(veth083931f) entered blocking state
[   44.934887] hassio: port 9(veth083931f) entered disabled state
[   44.935138] device veth083931f entered promiscuous mode
[   44.935222] kauditd_printk_skb: 38 callbacks suppressed
[   44.935226] audit: type=1700 audit(1612429430.518:203): dev=veth083931f prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
[   45.434232] audit: type=1325 audit(1612429431.014:204): table=nat family=2 entries=0
[   45.444880] audit: type=1325 audit(1612429431.026:205): table=filter family=2 entries=0
[   45.456270] audit: type=1325 audit(1612429431.038:206): table=nat family=2 entries=5
[   45.459624] audit: type=1325 audit(1612429431.042:207): table=nat family=2 entries=7
[   45.468032] audit: type=1325 audit(1612429431.050:208): table=nat family=2 entries=8
[   45.471828] audit: type=1325 audit(1612429431.054:209): table=nat family=2 entries=10
[   45.478131] audit: type=1325 audit(1612429431.058:210): table=nat family=2 entries=11
[   45.485567] audit: type=1325 audit(1612429431.066:211): table=nat family=2 entries=12
[   45.493417] audit: type=1325 audit(1612429431.074:212): table=nat family=2 entries=13
[   45.531680] eth0: renamed from vethc8f6ee4
[   45.564642] IPv6: ADDRCONF(NETDEV_CHANGE): veth083931f: link becomes ready
[   45.564768] hassio: port 9(veth083931f) entered blocking state
[   45.564773] hassio: port 9(veth083931f) entered forwarding state
[   47.507334] hassio: port 10(veth9fc2251) entered blocking state
[   47.507342] hassio: port 10(veth9fc2251) entered disabled state
[   47.509364] device veth9fc2251 entered promiscuous mode
[   48.851873] eth0: renamed from veth9edff32
[   48.880297] IPv6: ADDRCONF(NETDEV_CHANGE): veth9fc2251: link becomes ready
[   48.880520] hassio: port 10(veth9fc2251) entered blocking state
[   48.880530] hassio: port 10(veth9fc2251) entered forwarding state
[   50.652395] hassio: port 11(veth4db5607) entered blocking state
[   50.652403] hassio: port 11(veth4db5607) entered disabled state
[   50.652701] device veth4db5607 entered promiscuous mode
[   50.652758] kauditd_printk_skb: 12 callbacks suppressed
[   50.652767] audit: type=1700 audit(1612429436.234:225): dev=veth4db5607 prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
[   51.449040] audit: type=1325 audit(1612429437.030:226): table=nat family=2 entries=0
[   51.468940] audit: type=1325 audit(1612429437.050:227): table=filter family=2 entries=0
[   51.495307] audit: type=1325 audit(1612429437.078:228): table=nat family=2 entries=5
[   51.503892] audit: type=1325 audit(1612429437.086:229): table=nat family=2 entries=7
[   51.520675] audit: type=1325 audit(1612429437.102:230): table=nat family=2 entries=8
[   51.526917] audit: type=1325 audit(1612429437.110:231): table=nat family=2 entries=10
[   51.538292] audit: type=1325 audit(1612429437.118:232): table=nat family=2 entries=11
[   51.552647] audit: type=1325 audit(1612429437.134:233): table=nat family=2 entries=12
[   51.562270] audit: type=1325 audit(1612429437.142:234): table=nat family=2 entries=13
[   51.616997] eth0: renamed from vethe834c8f
[   51.641194] IPv6: ADDRCONF(NETDEV_CHANGE): veth4db5607: link becomes ready
[   51.641349] hassio: port 11(veth4db5607) entered blocking state
[   51.641355] hassio: port 11(veth4db5607) entered forwarding state
[   59.808023] udevd[193]: starting version 3.2.9
[   59.884963] udevd[194]: starting eudev-3.2.9
[   66.732274] hassio: port 11(veth4db5607) entered disabled state
[   66.732677] vethe834c8f: renamed from eth0
[   66.805034] hassio: port 11(veth4db5607) entered disabled state
[   66.807003] device veth4db5607 left promiscuous mode
[   66.807051] hassio: port 11(veth4db5607) entered disabled state
[   66.807106] kauditd_printk_skb: 1 callbacks suppressed
[   66.807111] audit: type=1700 audit(1612429452.362:236): dev=veth4db5607 prom=0 old_prom=256 auid=4294967295 uid=0 gid=0 ses=4294967295
[  252.827939] device eth0 entered promiscuous mode
[  252.828040] audit: type=1700 audit(1612429638.410:237): dev=eth0 prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
[  252.851621] device eth0 left promiscuous mode
[  252.851709] audit: type=1700 audit(1612429638.434:238): dev=eth0 prom=0 old_prom=256 auid=4294967295 uid=0 gid=0 ses=4294967295
[  253.154607] hassio: port 11(vethcdbc520) entered blocking state
[  253.154615] hassio: port 11(vethcdbc520) entered disabled state
[  253.154800] device vethcdbc520 entered promiscuous mode
[  253.154881] audit: type=1700 audit(1612429638.734:239): dev=vethcdbc520 prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
[  253.196716] audit: type=1325 audit(1612429638.778:240): table=nat family=2 entries=25
[  253.242701] audit: type=1325 audit(1612429638.822:241): table=filter family=2 entries=35
[  253.267497] audit: type=1325 audit(1612429638.850:242): table=nat family=2 entries=26
[  253.318701] device eth0 entered promiscuous mode
[  253.318797] audit: type=1700 audit(1612429638.898:243): dev=eth0 prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
[  253.853848] audit: type=1325 audit(1612429639.434:244): table=nat family=2 entries=0
[  253.864241] audit: type=1325 audit(1612429639.446:245): table=filter family=2 entries=0
[  253.875112] audit: type=1325 audit(1612429639.454:246): table=nat family=2 entries=5
[  253.944678] eth0: renamed from veth50ac443
[  253.972836] IPv6: ADDRCONF(NETDEV_CHANGE): vethcdbc520: link becomes ready
[  253.972961] hassio: port 11(vethcdbc520) entered blocking state
[  253.972966] hassio: port 11(vethcdbc520) entered forwarding state
[  254.430717] hassio: port 12(veth36bf96b) entered blocking state
[  254.430730] hassio: port 12(veth36bf96b) entered disabled state
[  254.431210] device veth36bf96b entered promiscuous mode
[  255.081933] eth0: renamed from veth7866165
[  255.101001] IPv6: ADDRCONF(NETDEV_CHANGE): veth36bf96b: link becomes ready
[  255.101142] hassio: port 12(veth36bf96b) entered blocking state
[  255.101149] hassio: port 12(veth36bf96b) entered forwarding state
[  255.640955] hassio: port 13(veth4301d91) entered blocking state
[  255.640989] hassio: port 13(veth4301d91) entered disabled state
[  255.642061] device veth4301d91 entered promiscuous mode
[  256.508760] eth0: renamed from vethe5d760a
[  256.526091] IPv6: ADDRCONF(NETDEV_CHANGE): veth4301d91: link becomes ready
[  256.526230] hassio: port 13(veth4301d91) entered blocking state
[  256.526237] hassio: port 13(veth4301d91) entered forwarding state
[  257.473740] hassio: port 14(veth57903b1) entered blocking state
[  257.473752] hassio: port 14(veth57903b1) entered disabled state
[  257.474328] device veth57903b1 entered promiscuous mode
[  258.317632] kauditd_printk_skb: 30 callbacks suppressed
[  258.317637] audit: type=1325 audit(1612429643.898:277): table=nat family=2 entries=0
[  258.332114] audit: type=1325 audit(1612429643.914:278): table=filter family=2 entries=0
[  258.345468] audit: type=1325 audit(1612429643.926:279): table=nat family=2 entries=5
[  258.351929] audit: type=1325 audit(1612429643.934:280): table=nat family=2 entries=7
[  258.361152] audit: type=1325 audit(1612429643.942:281): table=nat family=2 entries=8
[  258.370056] audit: type=1325 audit(1612429643.950:282): table=nat family=2 entries=10
[  258.377124] audit: type=1325 audit(1612429643.958:283): table=nat family=2 entries=11
[  258.384660] audit: type=1325 audit(1612429643.966:284): table=nat family=2 entries=12
[  258.390879] audit: type=1325 audit(1612429643.970:285): table=nat family=2 entries=13
[  258.397498] audit: type=1325 audit(1612429643.978:286): table=nat family=2 entries=14
[  258.436938] eth0: renamed from vethbecdfbb
[  258.461257] IPv6: ADDRCONF(NETDEV_CHANGE): veth57903b1: link becomes ready
[  258.461386] hassio: port 14(veth57903b1) entered blocking state
[  258.461392] hassio: port 14(veth57903b1) entered forwarding state
#
bschatzow commented 3 years ago

Tried to capture the journalctl from the new install of 5.11 until just after it froze and I reset.

journalctl --since "2021-02-03 23:00:00" --until "2021-02-04 09:03:41" >/mnt/data/supervisor/homeassistant/jour8.txt 2>&1 jour8.txt

This is the span it was running and the start of the reboot. Looks like system froze at 06:25:28 UTC

agners commented 3 years ago

Hm, I don't see anything unusual in that log. Btw, you can use journalctl -b -1 to display the complete log of the last boot.

It really seems like the system just freezes for some reason. What would be interesting if a Raspberry Pi OS installation on the SSD behaves the same way (in HAOS 5.10 we use the very same Linux kernel version as the December release of Raspberry Pi OS, and in the HAOS 5.11 release we use the same kernel as in their January release).

Maybe also worth a try: Is the 32-bit variant stable?

bschatzow commented 3 years ago

@agners

Hm, I don't see anything unusual in that log. Btw, you can use journalctl -b -1 to display the complete log of the last boot. I understood this. I didn't want you to have to go through more than what was necessary.

It really seems like the system just freezes for some reason. What would be interesting if a Raspberry Pi OS installation on the SSD behaves the same way (in HAOS 5.10 we use the very same Linux kernel version as the December release of Raspberry Pi OS, and in the HAOS 5.11 release we use the same kernel as in their January release). I only use the Raspberry PI OS to update the EEPROM. Very rare and not up for more than a couple of minutes. Also I use the 32 bit version. I need the 64bit version version on Home Assistant as I was told this is the only version that supports SSD boot. Is there a way to get a custom with all the OS updates except using the Kernel from prior to 5.5?

In the spreadsheet in the 1119 issue there are currently 10 users. All but 2 are using the 64bit version. I had no issues with the 32 bit on the SD card and OS 5.8 (last that I tried before updating to SSD).

bschatzow commented 3 years ago

Just had 5.4 freeze. On terminal it says wlan link is not ready. Disconnected lan cable reconnect and it works again.

agners commented 3 years ago

So, that is not a freeze, but just a networking issue then?

bschatzow commented 3 years ago

On 5.4 it was a network issue. Never had this with 5.2 or 5.3. This happened on day four. 5.3 never had this issue. On 5.8 and above it is a freeze. No activity. Plug /unplug does nothing. System is dead except for the network light on the pi blinking rapidly. Only recovery is remove power. Is there anyway to do a custom build with the old kernel and everything else at the 5.11 level so I can try and troubleshoot the issues? jour7.txt jour8.txt

Jour7.txt is the file from just before I received notification that the network was down. Jour8.txt is after the network came back on line (reconnected) I needed to go +/- a few minutes as not sure about the delay in the notification. I believe I captured the issue. The time stamps from my network notifications were 2021-02-07 15:14:01 off and 2021-02-07 19:47:23 on (UTC).

cjmjmartens commented 3 years ago

Hi all, I just upgraded Home Assistant OS to 5.11 and now I am not able to access the system anymore. How can I restore the system or downgrade the OS to 5.10? I am using a Raspberry 4 in combination with a Samsung T5 SSD. I have installed the latest version of Home Assistant 2021.2.1. Thanks in advance for your help.

bschatzow commented 3 years ago

I don't believe this is the proper place to ask. PM me and I'll try to help. You can also a ask in the forums or discord.

agners commented 3 years ago

@bschatzow that HAOS 5.4 does not show the freeze (but a different network issue) makes the theory that it is related to Linux 5.4 more plausible.

Yes you can compile Home Assistant OS on your end to test things. It takes a while since it downloads and builds everything from scratch (depending on your connectivity and machine 30min to several hours). There is a getting started development file in the Documentation section.

Make sure to checkout branch rel-5 and revert the RPi kernel bump commits (846512a2830b96ddd897533d458b82c85ccf6c16 and friends).

bschatzow commented 3 years ago

Yes you can compile Home Assistant OS on your end to test things. It takes a while since it downloads and builds everything from scratch (depending on your connectivity and machine 30min to several hours). There is a getting started development file in the Documentation section.

Make sure to checkout branch rel-5 and revert the RPi kernel bump commits (846512a and friends).

Thanks. A couple of problems, I do not have a Linux system and a bigger one, this requires a lot more knowledge than I currently have. I was hoping there was a way to build it on the github server with a script file and than download it when completed. Similar to my custom Android files that I download on the lineage servers. I'll ask around the "1119" issue and see if anyone has knowledge there and a system to build it on.

bschatzow commented 3 years ago

@agners I see that the Pi OS is moving to 5.10 . As far as I know the current release is using 5.4.83 or 5.4.84. Is there a beta available that is using the newer 5.10 kernel? If so, I'll install it and see if it fixes my freeze issue. Thanks.

agners commented 3 years ago

the current release is using 5.83 or 5.84

There is a 4 missing, 5.4.83/5.4.84.

Moving the RPi's to 5.10 is on my todo list, probably next week.

bschatzow commented 3 years ago

the current release is using 5.83 or 5.84

There is a 4 missing, 5.4.83/5.4.84.

Moving the RPi's to 5.10 is on my todo list, probably next week. I would be happy to beta test and capture information for you. If you need others, I can ask on issue 1119. Let me know.

bschatzow commented 3 years ago

@agners I see that there is a new beta for various hardware but none for the RPI4. Is this in the works? Let me know when it is available and I will test it.

bschatzow commented 3 years ago

@agners , I see version 5.12 is now released as stable. I updated to it as well as to the new supervisor beta -2021.02.11. In the release note it mention a new pi firmware. Not sure what version the 5.12 is installing. The latest stable is 1/16. Beta is available as of 2/16. Do you think I should install this version?

bschatzow commented 3 years ago

jour7.txt @agners - 5.12 just froze at 6 hours. No log errors. Same as before.

bschatzow commented 3 years ago

@agners, Is there a developers version you would like me to try to see if this fixes the freeze issue?

bschatzow commented 3 years ago

@agners , I have setup my system with the split configuration and so far no freezes with the latest OS, pi4 Feb firmware and the latest Mar Home assistant beta. If this freezes I'll open a new issue and capture the logs. I kept the old SSD so if you want me to test something with just the the SSD connected, I can. Thanks for your help.