ioBroker nicht mehr erreichbar - objects.json "löscht" sich

[ReviewDiePie]

Hallo erstmal,

da ich bisher meine Probleme immer mithilfe von Google und dieser tollen Community relativ schnell selbstlösen konnte ist dies nun mein erster Post. Ich komme einfach nicht mehr weiter und hoffe ihr könnt mir helfen..!

Seit ein paar Wochen habe ich immense Probleme mit meinem ioBroker. Bei mir läuft der ioBroker auf einem RPi4, welches inzwischen per LAN direkt an der Fritzbox hängt.

Nun zum Problem: Alle 2-3 Tage (teilweise auch öfter) hört der ioBroker auf zu arbeiten. ioBroker ist dann nicht mehr über die Web-Maske zu erreichen und auch mein Pi ist nicht mehr per ssh / putty ansprechbar. Dann hilft nur noch vom Strom nehmen und neu starten. Nach dem Neustart ist das Pi dann per ssh wieder ansprechbar, aber iobroker bleibt tot ("iobroker list instances" zeigt keinerlei aktive Instanzen an).

Ich bin inzwischen so weit gekommen, dass ich rausgefunden habe, dass - warum auch immer - die objects.json zu diesem Zeitpunkt leer ist. Wenn ich per commandline wieder einen älteren Stand der objects.json in den entsprechenden Ordner (/opt/iobroker/iobroker-data) zurückspiele kann ich den iobroker wieder starten und dieser ist auch wieder erreichbar.

Da ich wirklich keine Ahnung hab woher diese seltsamen Crashs kommen, welche meine objects.json-Datei offenbar leeren/löschen hatte ich per Cron einen Befehl eingebaut welcher das Pi jede Nacht um 4 neustarten lässt (iobroker wird ordnungsgemäß runtergefahren, das Pi neugestartet und iobroker wieder gestartet) - das hat jetzt 3 Tage lang wunderbar funktioniert, bis heute morgen mal wieder nix ging (siehe Schilderung oben).

die objects.json wird übrigens nicht in dem Moment gelöscht, wo ich das Pi vom Strom nehme, sondern im Fall von heute morgen ist gegen 07:59 Uhr (siehe angehängte Logs) irgendwas passiert und die Datei wurde zur entsprechenden Uhrzeit offenbar korrumpiert. Ich habe dann um 08:47 das Pi vom Strom genommen und anschließend per Commandline wie beschrieben die alte objects.json wieder eingespielt, woraufhin ich den ioBroker um 08:56 Uhr wieder ordnungsgemäß hochfahren konnte.

Was mir noch aufgefallen ist (vielleicht irrelevant, aber wer weiß): im Ordner /opt/iobroker/iobroker-data/backup-objects wird alle 2 Stunden die objects.json und die states.json gebackupt, auch wenn ich absolut nichts am System mache, z.b. nachts läuft alle 2 Stunden ein neues BackUp rein... soll das so sein?

Anbei die Logs:

Log vom ioBroker zur fraglichen Zeit (mutmaßlich die Uhrzeit zu der ioBroker den Dienst quittiert hat):

2021-03-09 07:59:35.505  - info: host.raspberrypi iobroker.js-controller version 3.2.14 js-controller starting
2021-03-09 07:59:35.511  - info: host.raspberrypi Copyright (c) 2014-2021 bluefox, 2014 hobbyquaker
2021-03-09 07:59:35.511  - info: host.raspberrypi hostname: raspberrypi, node: v12.21.0
2021-03-09 07:59:35.512  - info: host.raspberrypi ip addresses: 192.168.178.50 fe80::2005:1697:5f9c:27c0
2021-03-09 07:59:35.566  - error: host.raspberrypi-Server Cannot load /opt/iobroker/iobroker-data/objects.json: /opt/iobroker/iobroker-data/objects.json: Unexpected end of JSON input. Try last Backup!
2021-03-09 07:59:35.568  - error: host.raspberrypi-Server Cannot load /opt/iobroker/iobroker-data/objects.json.bak: Database file /opt/iobroker/iobroker-data/objects.json.bak does not exists.. Continue with empty dataset!
2021-03-09 07:59:35.655  - error: host.raspberrypi Cannot read system.config: null (OK when migrating or restoring)
2021-03-09 07:59:35.870  - info: host.raspberrypi connected to Objects and States
2021-03-09 07:59:36.037  - warn: host.raspberrypi logger system.adapter.admin.0.logging was deleted
2021-03-09 07:59:36.038  - warn: host.raspberrypi logger system.adapter.javascript.0.logging was deleted
2021-03-09 07:59:36.078  - info: host.raspberrypi added notifications configuration of host
2021-03-09 07:59:36.085  - error: host.raspberrypi Cannot find view "system" for search "instance"
2021-03-09 07:59:36.087  - error: host.raspberrypi Could not add notifications config of this host: Could not get notifications setup from instances: Cannot find view "system"
2021-03-09 07:59:36.102  - info: host.raspberrypi Plugin sentry Sentry Plugin disabled for this process because sending of statistic data is disabled for the system
2021-03-09 07:59:36.110  - error: host.raspberrypi Cannot find view "system" for search "host"
2021-03-09 07:59:36.119  - error: host.raspberrypi Cannot find view "system" for search "state"
2021-03-09 07:59:36.120  - error: host.raspberrypi Cannot find view "system" for search "instance"
2021-03-09 07:59:36.122  - error: host.raspberrypi Could not collect system.host.raspberrypi states to check for obsolete states: Error: Cannot find view "system"
2021-03-09 07:59:36.123  - error: host.raspberrypi _design/system missing - call node iobroker.js setup
2021-03-09 07:59:36.398  - info: host.raspberrypi Created UUID: 97a2673b-c7b9-f210-4a39-11c80b0f14cd

und der Syslog (etwas ausführlicher, damit man sieht was so die Stunden vorm Crash auf dem System passiert ist bis hin zu dem Moment wo ich ihn vom Strom genommen habe und das Pi neugestartet hab und anschließend per commandline den iobroker gestoppt habe):

Mar  9 05:00:25 raspberrypi rngd[328]: stats: bits received from HRNG source: 80064
Mar  9 05:00:25 raspberrypi rngd[328]: stats: bits sent to kernel pool: 33824
Mar  9 05:00:25 raspberrypi rngd[328]: stats: entropy added to kernel pool: 33824
Mar  9 05:00:25 raspberrypi rngd[328]: stats: FIPS 140-2 successes: 4
Mar  9 05:00:25 raspberrypi rngd[328]: stats: FIPS 140-2 failures: 0
Mar  9 05:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Mar  9 05:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Poker: 0
Mar  9 05:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Runs: 0
Mar  9 05:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Long run: 0
Mar  9 05:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Mar  9 05:00:25 raspberrypi rngd[328]: stats: HRNG source speed: (min=260.796; avg=362.458; max=530.049)Kibits/s
Mar  9 05:00:25 raspberrypi rngd[328]: stats: FIPS tests speed: (min=12.034; avg=14.507; max=31.268)Mibits/s
Mar  9 05:00:25 raspberrypi rngd[328]: stats: Lowest ready-buffers level: 2
Mar  9 05:00:25 raspberrypi rngd[328]: stats: Entropy starvations: 0
Mar  9 05:00:25 raspberrypi rngd[328]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Mar  9 05:17:01 raspberrypi CRON[1530]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Mar  9 06:00:25 raspberrypi rngd[328]: stats: bits received from HRNG source: 120064
Mar  9 06:00:25 raspberrypi rngd[328]: stats: bits sent to kernel pool: 63584
Mar  9 06:00:25 raspberrypi rngd[328]: stats: entropy added to kernel pool: 63584
Mar  9 06:00:25 raspberrypi rngd[328]: stats: FIPS 140-2 successes: 6
Mar  9 06:00:25 raspberrypi rngd[328]: stats: FIPS 140-2 failures: 0
Mar  9 06:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Mar  9 06:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Poker: 0
Mar  9 06:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Runs: 0
Mar  9 06:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Long run: 0
Mar  9 06:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Mar  9 06:00:25 raspberrypi rngd[328]: stats: HRNG source speed: (min=260.796; avg=405.229; max=530.683)Kibits/s
Mar  9 06:00:25 raspberrypi rngd[328]: stats: FIPS tests speed: (min=12.034; avg=15.482; max=31.371)Mibits/s
Mar  9 06:00:25 raspberrypi rngd[328]: stats: Lowest ready-buffers level: 2
Mar  9 06:00:25 raspberrypi rngd[328]: stats: Entropy starvations: 0
Mar  9 06:00:25 raspberrypi rngd[328]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Mar  9 06:12:21 raspberrypi systemd[1]: Starting Daily apt upgrade and clean activities...
Mar  9 06:12:23 raspberrypi systemd[1]: apt-daily-upgrade.service: Succeeded.
Mar  9 06:12:23 raspberrypi systemd[1]: Started Daily apt upgrade and clean activities.
Mar  9 06:17:01 raspberrypi CRON[1683]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Mar  9 06:25:01 raspberrypi CRON[1703]: (root) CMD (test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily ))
Mar  9 07:00:25 raspberrypi rngd[328]: stats: bits received from HRNG source: 140064
Mar  9 07:00:25 raspberrypi rngd[328]: stats: bits sent to kernel pool: 93824
Mar  9 07:00:25 raspberrypi rngd[328]: stats: entropy added to kernel pool: 93824
Mar  9 07:00:25 raspberrypi rngd[328]: stats: FIPS 140-2 successes: 7
Mar  9 07:00:25 raspberrypi rngd[328]: stats: FIPS 140-2 failures: 0
Mar  9 07:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Mar  9 07:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Poker: 0
Mar  9 07:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Runs: 0
Mar  9 07:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Long run: 0
Mar  9 07:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Mar  9 07:00:25 raspberrypi rngd[328]: stats: HRNG source speed: (min=260.796; avg=419.385; max=530.683)Kibits/s
Mar  9 07:00:25 raspberrypi rngd[328]: stats: FIPS tests speed: (min=12.034; avg=16.685; max=31.371)Mibits/s
Mar  9 07:00:25 raspberrypi rngd[328]: stats: Lowest ready-buffers level: 2
Mar  9 07:00:25 raspberrypi rngd[328]: stats: Entropy starvations: 0
Mar  9 07:00:25 raspberrypi rngd[328]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Mar  9 07:17:01 raspberrypi CRON[1854]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Mar  9 08:00:25 raspberrypi rngd[328]: stats: bits received from HRNG source: 180064
Mar  9 08:00:25 raspberrypi rngd[328]: stats: bits sent to kernel pool: 123584
Mar  9 08:00:25 raspberrypi rngd[328]: stats: entropy added to kernel pool: 123584
Mar  9 08:00:25 raspberrypi rngd[328]: stats: FIPS 140-2 successes: 9
Mar  9 08:00:25 raspberrypi rngd[328]: stats: FIPS 140-2 failures: 0
Mar  9 08:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Mar  9 08:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Poker: 0
Mar  9 08:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Runs: 0
Mar  9 08:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Long run: 0
Mar  9 08:00:25 raspberrypi rngd[328]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Mar  9 08:00:25 raspberrypi rngd[328]: stats: HRNG source speed: (min=260.796; avg=439.895; max=530.827)Kibits/s
Mar  9 08:00:25 raspberrypi rngd[328]: stats: FIPS tests speed: (min=12.034; avg=15.536; max=31.371)Mibits/s
Mar  9 08:00:25 raspberrypi rngd[328]: stats: Lowest ready-buffers level: 2
Mar  9 08:00:25 raspberrypi rngd[328]: stats: Entropy starvations: 0
Mar  9 08:00:25 raspberrypi rngd[328]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Mar  9 07:59:22 raspberrypi fake-hwclock[110]: Di 9. Mär 06:17:01 UTC 2021
Mar  9 07:59:22 raspberrypi systemd-fsck[128]: e2fsck 1.44.5 (15-Dec-2018)
Mar  9 07:59:22 raspberrypi systemd-fsck[128]: rootfs: clean, 212355/3814752 files, 1421025/15525376 blocks
Mar  9 07:59:22 raspberrypi systemd[1]: Started File System Check on Root Device.
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Remount Root and Kernel File Systems...
Mar  9 07:59:22 raspberrypi systemd[1]: Started Set the console keyboard layout.
Mar  9 07:59:22 raspberrypi systemd[1]: Started udev Coldplug all Devices.
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] Booting Linux on physical CPU 0x0
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] Linux version 5.10.17-v7l+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1403 SMP Mon Feb 22 11:33:35 GMT 2021
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] CPU: div instructions available: patching division code
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.1
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] Memory policy: Data cache writealloc
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] Reserved memory: created CMA memory pool at 0x000000001ec00000, size 256 MiB
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] Zone ranges:
Mar  9 07:59:22 raspberrypi kernel: [    0.000000]   DMA      [mem 0x0000000000000000-0x000000002fffffff]
Mar  9 07:59:22 raspberrypi kernel: [    0.000000]   Normal   empty
Mar  9 07:59:22 raspberrypi kernel: [    0.000000]   HighMem  [mem 0x0000000030000000-0x000000007fffffff]
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] Movable zone start for each node
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] Early memory node ranges
Mar  9 07:59:22 raspberrypi kernel: [    0.000000]   node   0: [mem 0x0000000000000000-0x000000003b3fffff]
Mar  9 07:59:22 raspberrypi kernel: [    0.000000]   node   0: [mem 0x0000000040000000-0x000000007fffffff]
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x000000007fffffff]
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] On node 0 totalpages: 504832
Mar  9 07:59:22 raspberrypi kernel: [    0.000000]   DMA zone: 2304 pages used for memmap
Mar  9 07:59:22 raspberrypi kernel: [    0.000000]   DMA zone: 0 pages reserved
Mar  9 07:59:22 raspberrypi kernel: [    0.000000]   DMA zone: 196608 pages, LIFO batch:63
Mar  9 07:59:22 raspberrypi kernel: [    0.000000]   HighMem zone: 308224 pages, LIFO batch:63
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] percpu: Embedded 20 pages/cpu s50700 r8192 d23028 u81920
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] pcpu-alloc: s50700 r8192 d23028 u81920 alloc=20*4096
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 502528
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1  smsc95xx.macaddr=DC:A6:32:5B:8D:DC vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  console=ttyS0,115200 console=tty1 root=PARTUUID=6c586e13-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] Kernel parameter elevator= does not have any effect anymore.
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] Please use sysfs to set IO scheduler for individual devices.
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] software IO TLB: mapped [mem 0x0000000019400000-0x000000001d400000] (64MB)
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] Memory: 1647132K/2019328K available (10240K kernel code, 1358K rwdata, 3160K rodata, 2048K init, 890K bss, 110052K reserved, 262144K cma-reserved, 1232896K highmem)
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] ftrace: allocating 33942 entries in 67 pages
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] ftrace: allocated 67 pages with 3 groups
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] rcu: Hierarchical RCU implementation.
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] 	Rude variant of Tasks RCU enabled.
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] 	Tracing variant of Tasks RCU enabled.
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] GIC: Using split EOI/Deactivate mode
Mar  9 07:59:22 raspberrypi kernel: [    0.000000] random: get_random_bytes called from start_kernel+0x3c8/0x59c with crng_init=0
Mar  9 07:59:22 raspberrypi kernel: [    0.000008] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
Mar  9 07:59:22 raspberrypi kernel: [    0.000035] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
Mar  9 07:59:22 raspberrypi kernel: [    0.000099] bcm2835: system timer (irq = 25)
Mar  9 07:59:22 raspberrypi kernel: [    0.000751] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
Mar  9 07:59:22 raspberrypi kernel: [    0.000773] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
Mar  9 07:59:22 raspberrypi kernel: [    0.000795] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
Mar  9 07:59:22 raspberrypi kernel: [    0.000814] Switching to timer-based delay loop, resolution 18ns
Mar  9 07:59:22 raspberrypi kernel: [    0.001069] Console: colour dummy device 80x30
Mar  9 07:59:22 raspberrypi kernel: [    0.001804] printk: console [tty1] enabled
Mar  9 07:59:22 raspberrypi kernel: [    0.001869] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000)
Mar  9 07:59:22 raspberrypi kernel: [    0.001923] pid_max: default: 32768 minimum: 301
Mar  9 07:59:22 raspberrypi kernel: [    0.002105] LSM: Security Framework initializing
Mar  9 07:59:22 raspberrypi kernel: [    0.002304] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
Mar  9 07:59:22 raspberrypi kernel: [    0.002350] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
Mar  9 07:59:22 raspberrypi kernel: [    0.003939] Disabling memory control group subsystem
Mar  9 07:59:22 raspberrypi kernel: [    0.004075] CPU: Testing write buffer coherency: ok
Mar  9 07:59:22 raspberrypi kernel: [    0.004543] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
Mar  9 07:59:22 raspberrypi kernel: [    0.005764] Setting up static identity map for 0x200000 - 0x20003c
Mar  9 07:59:22 raspberrypi kernel: [    0.005979] rcu: Hierarchical SRCU implementation.
Mar  9 07:59:22 raspberrypi kernel: [    0.006918] smp: Bringing up secondary CPUs ...
Mar  9 07:59:22 raspberrypi kernel: [    0.008143] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
Mar  9 07:59:22 raspberrypi kernel: [    0.009507] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
Mar  9 07:59:22 raspberrypi kernel: [    0.010815] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
Mar  9 07:59:22 raspberrypi kernel: [    0.010971] smp: Brought up 1 node, 4 CPUs
Mar  9 07:59:22 raspberrypi kernel: [    0.011017] SMP: Total of 4 processors activated (432.00 BogoMIPS).
Mar  9 07:59:22 raspberrypi kernel: [    0.011048] CPU: All CPU(s) started in HYP mode.
Mar  9 07:59:22 raspberrypi kernel: [    0.011074] CPU: Virtualization extensions available.
Mar  9 07:59:22 raspberrypi kernel: [    0.011915] devtmpfs: initialized
Mar  9 07:59:22 raspberrypi kernel: [    0.025727] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0
Mar  9 07:59:22 raspberrypi kernel: [    0.025986] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
Mar  9 07:59:22 raspberrypi kernel: [    0.026039] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
Mar  9 07:59:22 raspberrypi kernel: [    0.033082] pinctrl core: initialized pinctrl subsystem
Mar  9 07:59:22 raspberrypi kernel: [    0.034170] NET: Registered protocol family 16
Mar  9 07:59:22 raspberrypi kernel: [    0.038165] DMA: preallocated 1024 KiB pool for atomic coherent allocations
Mar  9 07:59:22 raspberrypi kernel: [    0.038945] audit: initializing netlink subsys (disabled)
Mar  9 07:59:22 raspberrypi kernel: [    0.039230] audit: type=2000 audit(0.030:1): state=initialized audit_enabled=0 res=1
Mar  9 07:59:22 raspberrypi kernel: [    0.039790] thermal_sys: Registered thermal governor 'step_wise'
Mar  9 07:59:22 raspberrypi kernel: [    0.040473] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
Mar  9 07:59:22 raspberrypi kernel: [    0.040527] hw-breakpoint: maximum watchpoint size is 8 bytes.
Mar  9 07:59:22 raspberrypi kernel: [    0.040963] Serial: AMBA PL011 UART driver
Mar  9 07:59:22 raspberrypi kernel: [    0.071856] bcm2835-mbox fe00b880.mailbox: mailbox enabled
Mar  9 07:59:22 raspberrypi kernel: [    0.090935] raspberrypi-firmware soc:firmware: Attached to firmware from 2021-02-25T12:10:40, variant start
Mar  9 07:59:22 raspberrypi kernel: [    0.100949] raspberrypi-firmware soc:firmware: Firmware hash is 564e5f9b852b23a330b1764bcf0b2d022a20afd0
Mar  9 07:59:22 raspberrypi kernel: [    0.145632] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1
Mar  9 07:59:22 raspberrypi kernel: [    0.149745] vgaarb: loaded
Mar  9 07:59:22 raspberrypi kernel: [    0.150215] SCSI subsystem initialized
Mar  9 07:59:22 raspberrypi kernel: [    0.150454] usbcore: registered new interface driver usbfs
Mar  9 07:59:22 raspberrypi kernel: [    0.150542] usbcore: registered new interface driver hub
Mar  9 07:59:22 raspberrypi kernel: [    0.150629] usbcore: registered new device driver usb
Mar  9 07:59:22 raspberrypi kernel: [    0.150973] usb_phy_generic phy: supply vcc not found, using dummy regulator
Mar  9 07:59:22 raspberrypi kernel: [    0.153186] clocksource: Switched to clocksource arch_sys_counter
Mar  9 07:59:22 raspberrypi kernel: [    1.154073] VFS: Disk quotas dquot_6.6.0
Mar  9 07:59:22 raspberrypi kernel: [    1.154208] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
Mar  9 07:59:22 raspberrypi kernel: [    1.154409] FS-Cache: Loaded
Mar  9 07:59:22 raspberrypi kernel: [    1.154616] CacheFiles: Loaded
Mar  9 07:59:22 raspberrypi kernel: [    1.165065] NET: Registered protocol family 2
Mar  9 07:59:22 raspberrypi kernel: [    1.165958] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
Mar  9 07:59:22 raspberrypi kernel: [    1.166118] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
Mar  9 07:59:22 raspberrypi kernel: [    1.166200] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
Mar  9 07:59:22 raspberrypi kernel: [    1.166286] TCP: Hash tables configured (established 8192 bind 8192)
Mar  9 07:59:22 raspberrypi kernel: [    1.166458] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
Mar  9 07:59:22 raspberrypi kernel: [    1.166513] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
Mar  9 07:59:22 raspberrypi kernel: [    1.166793] NET: Registered protocol family 1
Mar  9 07:59:22 raspberrypi kernel: [    1.167525] RPC: Registered named UNIX socket transport module.
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Helper to synchronize boot up for ifupdown...
Mar  9 07:59:22 raspberrypi systemd[1]: Started Helper to synchronize boot up for ifupdown.
Mar  9 07:59:22 raspberrypi systemd[1]: Started Remount Root and Kernel File Systems.
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Create System Users...
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Load/Save Random Seed...
Mar  9 07:59:22 raspberrypi systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Flush Journal to Persistent Storage...
Mar  9 07:59:22 raspberrypi systemd[1]: Started Create System Users.
Mar  9 07:59:22 raspberrypi systemd[1]: Started Load/Save Random Seed.
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Create Static Device Nodes in /dev...
Mar  9 07:59:22 raspberrypi systemd[1]: Started Flush Journal to Persistent Storage.
Mar  9 07:59:22 raspberrypi systemd[1]: Started Create Static Device Nodes in /dev.
Mar  9 07:59:22 raspberrypi systemd[1]: Starting udev Kernel Device Manager...
Mar  9 07:59:22 raspberrypi systemd[1]: Reached target Local File Systems (Pre).
Mar  9 07:59:22 raspberrypi systemd[1]: Started udev Kernel Device Manager.
Mar  9 07:59:22 raspberrypi systemd-udevd[151]: Using default interface naming scheme 'v240'.
Mar  9 07:59:22 raspberrypi mtp-probe: checking bus 1, device 3: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.1"
Mar  9 07:59:22 raspberrypi mtp-probe: bus: 1, device: 3 was not an MTP device
Mar  9 07:59:22 raspberrypi systemd[1]: Found device /dev/disk/by-partuuid/6c586e13-01.
Mar  9 07:59:22 raspberrypi systemd[1]: Found device /dev/serial1.
Mar  9 07:59:22 raspberrypi systemd[1]: Condition check resulted in FUSE Control File System being skipped.
Mar  9 07:59:22 raspberrypi systemd[1]: Condition check resulted in Huge Pages File System being skipped.
Mar  9 07:59:22 raspberrypi systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
Mar  9 07:59:22 raspberrypi systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
Mar  9 07:59:22 raspberrypi systemd[1]: Starting File System Check on /dev/disk/by-partuuid/6c586e13-01...
Mar  9 07:59:22 raspberrypi systemd-fsck[248]: fsck.fat 4.1 (2017-01-24)
Mar  9 07:59:22 raspberrypi systemd-fsck[248]: 0x41: Dirty bit is set. Fs was not properly unmounted and some data may be corrupt.
Mar  9 07:59:22 raspberrypi systemd-fsck[248]:  Automatically removing dirty bit.
Mar  9 07:59:22 raspberrypi systemd-fsck[248]: Performing changes.
Mar  9 07:59:22 raspberrypi systemd-fsck[248]: /dev/mmcblk0p1: 264 files, 97566/516190 clusters
Mar  9 07:59:22 raspberrypi systemd[1]: Started File System Check on /dev/disk/by-partuuid/6c586e13-01.
Mar  9 07:59:22 raspberrypi systemd[1]: Mounting /boot...
Mar  9 07:59:22 raspberrypi systemd[1]: Mounted /boot.
Mar  9 07:59:22 raspberrypi systemd[1]: Reached target Local File Systems.
Mar  9 07:59:22 raspberrypi systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped.
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Set console font and keymap...
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Preprocess NFS configuration...
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Create Volatile Files and Directories...
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Raise network interfaces...
Mar  9 07:59:22 raspberrypi systemd[1]: Started Set console font and keymap.
Mar  9 07:59:22 raspberrypi systemd[1]: nfs-config.service: Succeeded.
Mar  9 07:59:22 raspberrypi systemd[1]: Started Preprocess NFS configuration.
Mar  9 07:59:22 raspberrypi systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped.
Mar  9 07:59:22 raspberrypi systemd[1]: Condition check resulted in RPC security service for NFS server being skipped.
Mar  9 07:59:22 raspberrypi systemd[1]: Reached target NFS client services.
Mar  9 07:59:22 raspberrypi systemd[1]: Reached target Remote File Systems (Pre).
Mar  9 07:59:22 raspberrypi systemd[1]: Reached target Remote File Systems.
Mar  9 07:59:22 raspberrypi systemd[1]: Started Create Volatile Files and Directories.
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Network Time Synchronization...
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Update UTMP about System Boot/Shutdown...
Mar  9 07:59:22 raspberrypi systemd[1]: Started Update UTMP about System Boot/Shutdown.
Mar  9 07:59:22 raspberrypi systemd[1]: Started Raise network interfaces.
Mar  9 07:59:22 raspberrypi systemd-timesyncd[273]: System clock time unset or jumped backwards, restoring from recorded timestamp: Tue 2021-03-09 07:59:22 CET
Mar  9 07:59:22 raspberrypi systemd[1]: Started Network Time Synchronization.
Mar  9 07:59:22 raspberrypi systemd[1]: Reached target System Time Synchronized.
Mar  9 07:59:22 raspberrypi systemd[1]: Reached target System Initialization.
Mar  9 07:59:22 raspberrypi kernel: [    1.167558] RPC: Registered udp transport module.
Mar  9 07:59:22 raspberrypi kernel: [    1.167586] RPC: Registered tcp transport module.
Mar  9 07:59:22 raspberrypi kernel: [    1.167614] RPC: Registered tcp NFSv4.1 backchannel transport module.
Mar  9 07:59:22 raspberrypi kernel: [    1.167651] PCI: CLS 0 bytes, default 64
Mar  9 07:59:22 raspberrypi kernel: [    1.170496] Initialise system trusted keyrings
Mar  9 07:59:22 raspberrypi kernel: [    1.170738] workingset: timestamp_bits=14 max_order=19 bucket_order=5
Mar  9 07:59:22 raspberrypi kernel: [    1.179361] zbud: loaded
Mar  9 07:59:22 raspberrypi kernel: [    1.181316] FS-Cache: Netfs 'nfs' registered for caching
Mar  9 07:59:22 raspberrypi kernel: [    1.182072] NFS: Registering the id_resolver key type
Mar  9 07:59:22 raspberrypi kernel: [    1.182156] Key type id_resolver registered
Mar  9 07:59:22 raspberrypi kernel: [    1.182184] Key type id_legacy registered
Mar  9 07:59:22 raspberrypi kernel: [    1.182349] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
Mar  9 07:59:22 raspberrypi kernel: [    1.183489] Key type asymmetric registered
Mar  9 07:59:22 raspberrypi kernel: [    1.183522] Asymmetric key parser 'x509' registered
Mar  9 07:59:22 raspberrypi kernel: [    1.183728] bounce: pool size: 64 pages
Mar  9 07:59:22 raspberrypi kernel: [    1.183784] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
Mar  9 07:59:22 raspberrypi kernel: [    1.184017] io scheduler mq-deadline registered
Mar  9 07:59:22 raspberrypi kernel: [    1.184048] io scheduler kyber registered
Mar  9 07:59:22 raspberrypi kernel: [    1.188519] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
Mar  9 07:59:22 raspberrypi kernel: [    1.188571] brcm-pcie fd500000.pcie:   No bus range found for /scb/pcie@7d500000, using [bus 00-ff]
Mar  9 07:59:22 raspberrypi kernel: [    1.188673] brcm-pcie fd500000.pcie:      MEM 0x0600000000..0x063fffffff -> 0x00c0000000
Mar  9 07:59:22 raspberrypi kernel: [    1.188783] brcm-pcie fd500000.pcie:   IB MEM 0x0000000000..0x007fffffff -> 0x0400000000
Mar  9 07:59:22 raspberrypi kernel: [    1.245290] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC)
Mar  9 07:59:22 raspberrypi kernel: [    1.245673] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
Mar  9 07:59:22 raspberrypi kernel: [    1.245710] pci_bus 0000:00: root bus resource [bus 00-ff]
Mar  9 07:59:22 raspberrypi kernel: [    1.245746] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff])
Mar  9 07:59:22 raspberrypi kernel: [    1.245855] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
Mar  9 07:59:22 raspberrypi kernel: [    1.246114] pci 0000:00:00.0: PME# supported from D0 D3hot
Mar  9 07:59:22 raspberrypi kernel: [    1.249620] PCI: bus0: Fast back to back transfers disabled
Mar  9 07:59:22 raspberrypi kernel: [    1.249977] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330
Mar  9 07:59:22 raspberrypi kernel: [    1.250121] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
Mar  9 07:59:22 raspberrypi kernel: [    1.250571] pci 0000:01:00.0: PME# supported from D0 D3cold
Mar  9 07:59:22 raspberrypi kernel: [    1.254081] PCI: bus1: Fast back to back transfers disabled
Mar  9 07:59:22 raspberrypi kernel: [    1.254196] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
Mar  9 07:59:22 raspberrypi kernel: [    1.254237] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]
Mar  9 07:59:22 raspberrypi kernel: [    1.254340] pci 0000:00:00.0: PCI bridge to [bus 01]
Mar  9 07:59:22 raspberrypi kernel: [    1.254380] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]
Mar  9 07:59:22 raspberrypi kernel: [    1.254797] pcieport 0000:00:00.0: enabling device (0140 -> 0142)
Mar  9 07:59:22 raspberrypi kernel: [    1.255060] pcieport 0000:00:00.0: PME: Signaling with IRQ 62
Mar  9 07:59:22 raspberrypi kernel: [    1.265793] iproc-rng200 fe104000.rng: hwrng registered
Mar  9 07:59:22 raspberrypi kernel: [    1.266109] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
Mar  9 07:59:22 raspberrypi kernel: [    1.266982] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
Mar  9 07:59:22 raspberrypi kernel: [    1.279314] brd: module loaded
Mar  9 07:59:22 raspberrypi kernel: [    1.291646] loop: module loaded
Mar  9 07:59:22 raspberrypi kernel: [    1.293418] Loading iSCSI transport class v2.0-870.
Mar  9 07:59:22 raspberrypi kernel: [    1.295843] libphy: Fixed MDIO Bus: probed
Mar  9 07:59:22 raspberrypi kernel: [    1.297537] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000
Mar  9 07:59:22 raspberrypi kernel: [    1.313254] libphy: bcmgenet MII bus: probed
Mar  9 07:59:22 raspberrypi kernel: [    1.393373] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus
Mar  9 07:59:22 raspberrypi kernel: [    1.394527] usbcore: registered new interface driver r8152
Mar  9 07:59:22 raspberrypi kernel: [    1.394629] usbcore: registered new interface driver lan78xx
Mar  9 07:59:22 raspberrypi kernel: [    1.394706] usbcore: registered new interface driver smsc95xx
Mar  9 07:59:22 raspberrypi kernel: [    1.396353] xhci_hcd 0000:01:00.0: enabling device (0140 -> 0142)
Mar  9 07:59:22 raspberrypi kernel: [    1.396544] xhci_hcd 0000:01:00.0: xHCI Host Controller
Mar  9 07:59:22 raspberrypi kernel: [    1.396595] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
Mar  9 07:59:22 raspberrypi kernel: [    1.399943] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000030000000890
Mar  9 07:59:22 raspberrypi kernel: [    1.401265] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10
Mar  9 07:59:22 raspberrypi kernel: [    1.401306] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Mar  9 07:59:22 raspberrypi kernel: [    1.401342] usb usb1: Product: xHCI Host Controller
Mar  9 07:59:22 raspberrypi kernel: [    1.401372] usb usb1: Manufacturer: Linux 5.10.17-v7l+ xhci-hcd
Mar  9 07:59:22 raspberrypi kernel: [    1.401403] usb usb1: SerialNumber: 0000:01:00.0
Mar  9 07:59:22 raspberrypi kernel: [    1.402154] hub 1-0:1.0: USB hub found
Mar  9 07:59:22 raspberrypi kernel: [    1.402267] hub 1-0:1.0: 1 port detected
Mar  9 07:59:22 raspberrypi kernel: [    1.402978] xhci_hcd 0000:01:00.0: xHCI Host Controller
Mar  9 07:59:22 raspberrypi kernel: [    1.403020] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
Mar  9 07:59:22 raspberrypi kernel: [    1.403066] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
Mar  9 07:59:22 raspberrypi kernel: [    1.403634] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.10
Mar  9 07:59:22 raspberrypi kernel: [    1.403674] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Mar  9 07:59:22 raspberrypi kernel: [    1.403710] usb usb2: Product: xHCI Host Controller
Mar  9 07:59:22 raspberrypi kernel: [    1.403740] usb usb2: Manufacturer: Linux 5.10.17-v7l+ xhci-hcd
Mar  9 07:59:22 raspberrypi kernel: [    1.403771] usb usb2: SerialNumber: 0000:01:00.0
Mar  9 07:59:22 raspberrypi kernel: [    1.404507] hub 2-0:1.0: USB hub found
Mar  9 07:59:22 raspberrypi kernel: [    1.404592] hub 2-0:1.0: 4 ports detected
Mar  9 07:59:22 raspberrypi kernel: [    1.406286] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
Mar  9 07:59:22 raspberrypi kernel: [    1.406599] dwc_otg: FIQ enabled
Mar  9 07:59:22 raspberrypi kernel: [    1.406614] dwc_otg: NAK holdoff enabled
Mar  9 07:59:22 raspberrypi kernel: [    1.406629] dwc_otg: FIQ split-transaction FSM enabled
Mar  9 07:59:22 raspberrypi kernel: [    1.406647] Module dwc_common_port init
Mar  9 07:59:22 raspberrypi kernel: [    1.407076] usbcore: registered new interface driver uas
Mar  9 07:59:22 raspberrypi kernel: [    1.407204] usbcore: registered new interface driver usb-storage
Mar  9 07:59:22 raspberrypi kernel: [    1.407411] mousedev: PS/2 mouse device common for all mice
Mar  9 07:59:22 raspberrypi kernel: [    1.409063] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
Mar  9 07:59:22 raspberrypi kernel: [    1.412552] sdhci: Secure Digital Host Controller Interface driver
Mar  9 07:59:22 raspberrypi kernel: [    1.412587] sdhci: Copyright(c) Pierre Ossman
Mar  9 07:59:22 raspberrypi kernel: [    1.413278] sdhci-pltfm: SDHCI platform and OF driver helper
Mar  9 07:59:22 raspberrypi kernel: [    1.416745] ledtrig-cpu: registered to indicate activity on CPUs
Mar  9 07:59:22 raspberrypi kernel: [    1.417109] hid: raw HID events driver (C) Jiri Kosina
Mar  9 07:59:22 raspberrypi kernel: [    1.417311] usbcore: registered new interface driver usbhid
Mar  9 07:59:22 raspberrypi kernel: [    1.417341] usbhid: USB HID core driver
Mar  9 07:59:22 raspberrypi kernel: [    1.423127] Initializing XFRM netlink socket
Mar  9 07:59:22 raspberrypi kernel: [    1.423229] NET: Registered protocol family 17
Mar  9 07:59:22 raspberrypi kernel: [    1.423353] Key type dns_resolver registered
Mar  9 07:59:22 raspberrypi kernel: [    1.423722] Registering SWP/SWPB emulation handler
Mar  9 07:59:22 raspberrypi kernel: [    1.423898] registered taskstats version 1
Mar  9 07:59:22 raspberrypi kernel: [    1.423939] Loading compiled-in X.509 certificates
Mar  9 07:59:22 raspberrypi kernel: [    1.424801] Key type ._fscrypt registered
Mar  9 07:59:22 raspberrypi kernel: [    1.424833] Key type .fscrypt registered
Mar  9 07:59:22 raspberrypi kernel: [    1.424861] Key type fscrypt-provisioning registered
Mar  9 07:59:22 raspberrypi kernel: [    1.436359] uart-pl011 fe201000.serial: there is not valid maps for state default
Mar  9 07:59:22 raspberrypi kernel: [    1.436690] uart-pl011 fe201000.serial: cts_event_workaround enabled
Mar  9 07:59:22 raspberrypi kernel: [    1.436781] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 36, base_baud = 0) is a PL011 rev2
Mar  9 07:59:22 raspberrypi kernel: [    1.443506] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
Mar  9 07:59:22 raspberrypi kernel: [    1.448069] of_cfs_init
Mar  9 07:59:22 raspberrypi kernel: [    1.448340] of_cfs_init: OK
Mar  9 07:59:22 raspberrypi kernel: [    1.482405] mmc0: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA
Mar  9 07:59:22 raspberrypi kernel: [    1.483270] Waiting for root device PARTUUID=6c586e13-02...
Mar  9 07:59:22 raspberrypi kernel: [    1.585331] mmc0: new ultra high speed DDR50 SDXC card at address aaaa
Mar  9 07:59:22 raspberrypi kernel: [    1.586243] mmcblk0: mmc0:aaaa SN64G 59.5 GiB
Mar  9 07:59:22 raspberrypi kernel: [    1.588332]  mmcblk0: p1 p2
Mar  9 07:59:22 raspberrypi kernel: [    1.610929] EXT4-fs (mmcblk0p2): INFO: recovery required on readonly filesystem
Mar  9 07:59:22 raspberrypi kernel: [    1.610973] EXT4-fs (mmcblk0p2): write access will be enabled during recovery
Mar  9 07:59:22 raspberrypi kernel: [    1.686991] random: fast init done
Mar  9 07:59:22 raspberrypi kernel: [    1.763240] usb 1-1: new high-speed USB device number 2 using xhci_hcd
Mar  9 07:59:22 raspberrypi kernel: [    1.838441] EXT4-fs (mmcblk0p2): orphan cleanup on readonly fs
Mar  9 07:59:22 raspberrypi kernel: [    1.838637] EXT4-fs (mmcblk0p2): 1 orphan inode deleted
Mar  9 07:59:22 raspberrypi kernel: [    1.838669] EXT4-fs (mmcblk0p2): recovery complete
Mar  9 07:59:22 raspberrypi kernel: [    1.847021] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
Mar  9 07:59:22 raspberrypi kernel: [    1.847127] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
Mar  9 07:59:22 raspberrypi kernel: [    1.852589] devtmpfs: mounted
Mar  9 07:59:22 raspberrypi systemd[1]: Listening on D-Bus System Message Bus Socket.
Mar  9 07:59:22 raspberrypi systemd[1]: Started Daily Cleanup of Temporary Directories.
Mar  9 07:59:22 raspberrypi systemd[1]: Started Daily man-db regeneration.
Mar  9 07:59:22 raspberrypi systemd[1]: Started Daily rotation of log files.
Mar  9 07:59:22 raspberrypi systemd[1]: Started Daily apt download activities.
Mar  9 07:59:22 raspberrypi systemd[1]: Listening on triggerhappy.socket.
Mar  9 07:59:22 raspberrypi systemd[1]: Started Daily apt upgrade and clean activities.
Mar  9 07:59:22 raspberrypi systemd[1]: Reached target Timers.
Mar  9 07:59:22 raspberrypi systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket.
Mar  9 07:59:22 raspberrypi systemd[1]: Reached target Sockets.
Mar  9 07:59:22 raspberrypi systemd[1]: Reached target Basic System.
Mar  9 07:59:22 raspberrypi systemd[1]: Starting triggerhappy global hotkey daemon...
Mar  9 07:59:22 raspberrypi systemd[1]: Starting System Logging Service...
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Login Service...
Mar  9 07:59:22 raspberrypi systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped.
Mar  9 07:59:22 raspberrypi systemd[1]: Starting dhcpcd on all interfaces...
Mar  9 07:59:22 raspberrypi systemd[1]: Started Regular background program processing daemon.
Mar  9 07:59:22 raspberrypi systemd[1]: Starting rng-tools.service...
Mar  9 07:59:22 raspberrypi systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped.
Mar  9 07:59:22 raspberrypi cron[313]: (CRON) INFO (pidfile fd = 3)
Mar  9 07:59:22 raspberrypi thd[309]: Found socket passed from systemd
Mar  9 07:59:22 raspberrypi kernel: [    1.861505] Freeing unused kernel memory: 2048K
Mar  9 07:59:22 raspberrypi kernel: [    1.873518] Run /sbin/init as init process
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Avahi mDNS/DNS-SD Stack...
Mar  9 07:59:22 raspberrypi systemd[1]: Condition check resulted in Turn on SSH if /boot/ssh is present being skipped.
Mar  9 07:59:22 raspberrypi systemd[1]: Starting LSB: Switch to ondemand cpu governor (unless shift key is pressed)...
Mar  9 07:59:22 raspberrypi systemd[1]: Started D-Bus System Message Bus.
Mar  9 07:59:22 raspberrypi rngd[321]: rngd 2-unofficial-mt.14 starting up...
Mar  9 07:59:22 raspberrypi rng-tools[314]: Starting Hardware RNG entropy gatherer daemon: rngd.
Mar  9 07:59:22 raspberrypi cron[313]: (CRON) INFO (Running @reboot jobs)
Mar  9 07:59:22 raspberrypi dhcpcd[312]: dev: loaded udev
Mar  9 07:59:22 raspberrypi rsyslogd: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd.  [v8.1901.0]
Mar  9 07:59:22 raspberrypi rsyslogd:  [origin software="rsyslogd" swVersion="8.1901.0" x-pid="310" x-info="https://www.rsyslog.com"] start
Mar  9 07:59:22 raspberrypi systemd[1]: Starting WPA supplicant...
Mar  9 07:59:22 raspberrypi kernel: [    1.873548]   with arguments:
Mar  9 07:59:22 raspberrypi kernel: [    1.873562]     /sbin/init
Mar  9 07:59:22 raspberrypi kernel: [    1.873577]   with environment:
Mar  9 07:59:22 raspberrypi kernel: [    1.873591]     HOME=/
Mar  9 07:59:22 raspberrypi kernel: [    1.873605]     TERM=linux
Mar  9 07:59:22 raspberrypi kernel: [    1.945915] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21
Mar  9 07:59:22 raspberrypi kernel: [    1.945963] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
Mar  9 07:59:22 raspberrypi kernel: [    1.945996] usb 1-1: Product: USB2.0 Hub
Mar  9 07:59:22 raspberrypi kernel: [    1.948007] hub 1-1:1.0: USB hub found
Mar  9 07:59:22 raspberrypi kernel: [    1.948305] hub 1-1:1.0: 4 ports detected
Mar  9 07:59:22 raspberrypi kernel: [    2.273247] usb 1-1.1: new full-speed USB device number 3 using xhci_hcd
Mar  9 07:59:22 raspberrypi kernel: [    2.412557] usb 1-1.1: New USB device found, idVendor=0451, idProduct=16a8, bcdDevice= 0.09
Mar  9 07:59:22 raspberrypi kernel: [    2.412606] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Mar  9 07:59:22 raspberrypi kernel: [    2.412643] usb 1-1.1: Product: TI CC2531 USB CDC
Mar  9 07:59:22 raspberrypi kernel: [    2.412672] usb 1-1.1: Manufacturer: Texas Instruments
Mar  9 07:59:22 raspberrypi kernel: [    2.412701] usb 1-1.1: SerialNumber: __0X00124B0018E28080
Mar  9 07:59:22 raspberrypi kernel: [    2.430105] NET: Registered protocol family 10
Mar  9 07:59:22 raspberrypi kernel: [    2.431556] Segment Routing with IPv6
Mar  9 07:59:22 raspberrypi kernel: [    3.244932] random: systemd: uninitialized urandom read (16 bytes read)
Mar  9 07:59:22 raspberrypi kernel: [    3.255257] random: systemd: uninitialized urandom read (16 bytes read)
Mar  9 07:59:22 raspberrypi kernel: [    3.256520] random: systemd: uninitialized urandom read (16 bytes read)
Mar  9 07:59:22 raspberrypi kernel: [    3.914958] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
Mar  9 07:59:22 raspberrypi kernel: [    4.563408] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000
Mar  9 07:59:22 raspberrypi kernel: [    4.566133] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000
Mar  9 07:59:22 raspberrypi kernel: [    4.567950] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000
Mar  9 07:59:22 raspberrypi kernel: [    4.569190] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000
Mar  9 07:59:22 raspberrypi kernel: [    4.608474] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
Mar  9 07:59:22 raspberrypi kernel: [    4.615742] mc: Linux media interface: v0.10
Mar  9 07:59:22 raspberrypi kernel: [    4.618204] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
Mar  9 07:59:22 raspberrypi kernel: [    4.618229] [vc_sm_connected_init]: start
Mar  9 07:59:22 raspberrypi kernel: [    4.619763] [vc_sm_connected_init]: installed successfully
Mar  9 07:59:22 raspberrypi kernel: [    4.651295] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
Mar  9 07:59:22 raspberrypi kernel: [    4.659633] bcm2835_audio bcm2835_audio: card created with 8 channels
Mar  9 07:59:22 raspberrypi kernel: [    4.722104] videodev: Linux video capture interface: v2.00
Mar  9 07:59:22 raspberrypi kernel: [    4.779814] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
Mar  9 07:59:22 raspberrypi kernel: [    4.788226] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
Mar  9 07:59:22 raspberrypi kernel: [    4.809912] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
Mar  9 07:59:22 raspberrypi kernel: [    4.838612] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
Mar  9 07:59:22 raspberrypi kernel: [    4.838695] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
Mar  9 07:59:22 raspberrypi kernel: [    4.844950] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
Mar  9 07:59:22 raspberrypi kernel: [    4.845003] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
Mar  9 07:59:22 raspberrypi kernel: [    4.850803] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
Mar  9 07:59:22 raspberrypi kernel: [    4.850849] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
Mar  9 07:59:22 raspberrypi kernel: [    4.875602] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
Mar  9 07:59:22 raspberrypi kernel: [    4.890028] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13
Mar  9 07:59:22 raspberrypi kernel: [    4.890548] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14
Mar  9 07:59:22 raspberrypi kernel: [    4.890993] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15
Mar  9 07:59:22 raspberrypi kernel: [    4.891356] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16
Mar  9 07:59:22 raspberrypi kernel: [    4.891386] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
Mar  9 07:59:22 raspberrypi kernel: [    4.891411] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
Mar  9 07:59:22 raspberrypi kernel: [    4.891434] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
Mar  9 07:59:22 raspberrypi kernel: [    4.891456] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
Mar  9 07:59:22 raspberrypi kernel: [    4.891680] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp
Mar  9 07:59:22 raspberrypi kernel: [    4.904978] [drm] No displays found. Consider forcing hotplug if HDMI is attached
Mar  9 07:59:22 raspberrypi kernel: [    4.905559] vc4-drm gpu: bound fe600000.firmwarekms (ops vc4_fkms_ops [vc4])
Mar  9 07:59:22 raspberrypi kernel: [    4.907432] [drm] Initialized vc4 0.0.0 20140616 for gpu on minor 0
Mar  9 07:59:22 raspberrypi kernel: [    4.948824] cdc_acm 1-1.1:1.0: ttyACM0: USB ACM device
Mar  9 07:59:22 raspberrypi kernel: [    4.951026] usbcore: registered new interface driver cdc_acm
Mar  9 07:59:22 raspberrypi kernel: [    4.951044] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
Mar  9 07:59:22 raspberrypi kernel: [    4.964782] [drm] Initialized v3d 1.0.0 20180419 for fec00000.v3d on minor 1
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Check for Raspberry Pi EEPROM updates...
Mar  9 07:59:22 raspberrypi systemd[1]: Started Manage Sound Card State (restore and store).
Mar  9 07:59:22 raspberrypi alsactl[333]: alsactl 1.1.8 daemon started
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Save/Restore Sound Card State...
Mar  9 07:59:22 raspberrypi rngd[321]: entropy feed to the kernel ready
Mar  9 07:59:22 raspberrypi kernel: [    7.053520] random: crng init done
Mar  9 07:59:22 raspberrypi kernel: [    7.053542] random: 7 urandom warning(s) missed due to ratelimiting
Mar  9 07:59:22 raspberrypi systemd[1]: Starting Configure Bluetooth Modems connected by UART...
Mar  9 07:59:22 raspberrypi avahi-daemon[316]: Found user 'avahi' (UID 108) and group 'avahi' (GID 113).
Mar  9 07:59:22 raspberrypi avahi-daemon[316]: Successfully dropped root privileges.
Mar  9 07:59:22 raspberrypi systemd[1]: Starting dphys-swapfile - set up, mount/unmount, and delete a swap file...
Mar  9 07:59:22 raspberrypi avahi-daemon[316]: avahi-daemon 0.7 starting up.
Mar  9 07:59:22 raspberrypi systemd[1]: Started triggerhappy global hotkey daemon.
Mar  9 07:59:22 raspberrypi systemd[1]: Started System Logging Service.
Mar  9 07:59:22 raspberrypi kernel: [    7.130531] 8021q: 802.1Q VLAN Support v1.8
Mar  9 07:59:22 raspberrypi systemd[1]: Started rng-tools.service.
Mar  9 07:59:22 raspberrypi systemd[1]: Started Save/Restore Sound Card State.
Mar  9 07:59:22 raspberrypi rpi-eeprom-update[332]: BCM2711 detected
Mar  9 07:59:22 raspberrypi rpi-eeprom-update[332]: Dedicated VL805 EEPROM detected
Mar  9 07:59:22 raspberrypi systemd[1]: Reached target Sound Card.
Mar  9 07:59:22 raspberrypi CRON[358]: (root) CMD (sudo sh -c 'echo 0 > /sys/class/leds/led1/brightness')
Mar  9 07:59:22 raspberrypi kernel: [    7.196387] uart-pl011 fe201000.serial: no DMA platform data
Mar  9 07:59:22 raspberrypi systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
Mar  9 07:59:22 raspberrypi kernel: [    7.291083] cfg80211: Loading compiled-in X.509 certificates for regulatory database
Mar  9 07:59:22 raspberrypi systemd[1]: Started Login Service.
Mar  9 07:59:22 raspberrypi avahi-daemon[316]: Successfully called chroot().
Mar  9 07:59:22 raspberrypi avahi-daemon[316]: Successfully dropped remaining capabilities.
Mar  9 07:59:22 raspberrypi wpa_supplicant[329]: Successfully initialized wpa_supplicant
Mar  9 07:59:22 raspberrypi avahi-daemon[316]: No service file found in /etc/avahi/services.
Mar  9 07:59:22 raspberrypi avahi-daemon[316]: Network interface enumeration completed.
Mar  9 07:59:22 raspberrypi avahi-daemon[316]: Server startup complete. Host name is raspberrypi.local. Local service cookie is 3628307838.
Mar  9 07:59:22 raspberrypi systemd[1]: Started Avahi mDNS/DNS-SD Stack.
Mar  9 07:59:22 raspberrypi systemd[1]: Started WPA supplicant.
Mar  9 07:59:22 raspberrypi raspi-config[318]: Checking if shift key is held down:Error opening '/dev/input/event*': No such file or directory
Mar  9 07:59:22 raspberrypi raspi-config[318]:  No. Switching to ondemand scaling governor.
Mar  9 07:59:22 raspberrypi systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed).
Mar  9 07:59:22 raspberrypi kernel: [    7.389236] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
Mar  9 07:59:22 raspberrypi dphys-swapfile[341]: want /var/swap=100MByte, checking existing: keeping it
Mar  9 07:59:22 raspberrypi dhcpcd[312]: eth0: waiting for carrier
Mar  9 07:59:22 raspberrypi kernel: [    7.464735] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)
Mar  9 07:59:22 raspberrypi kernel: [    7.465298] bcmgenet fd580000.ethernet eth0: Link is Down
Mar  9 07:59:22 raspberrypi systemd[1]: Started dphys-swapfile - set up, mount/unmount, and delete a swap file.
Mar  9 07:59:22 raspberrypi kernel: [    7.523403] Adding 102396k swap on /var/swap.  Priority:-2 extents:1 across:102396k SSFS
Mar  9 07:59:23 raspberrypi rpi-eeprom-update[332]: Checking for updates in /lib/firmware/raspberrypi/bootloader/default
Mar  9 07:59:23 raspberrypi rpi-eeprom-update[332]: Use raspi-config to select either the default-production release or latest update.
Mar  9 07:59:23 raspberrypi rpi-eeprom-update[332]: BOOTLOADER: up-to-date
Mar  9 07:59:23 raspberrypi rpi-eeprom-update[332]: CURRENT: Do 3. Sep 12:11:43 UTC 2020 (1599135103)
Mar  9 07:59:23 raspberrypi rpi-eeprom-update[332]:  LATEST: Do 3. Sep 12:11:43 UTC 2020 (1599135103)
Mar  9 07:59:23 raspberrypi rpi-eeprom-update[332]: RELEASE: default
Mar  9 07:59:23 raspberrypi rpi-eeprom-update[332]: VL805: up-to-date
Mar  9 07:59:23 raspberrypi rpi-eeprom-update[332]: CURRENT: 000138a1
Mar  9 07:59:23 raspberrypi rpi-eeprom-update[332]:  LATEST: 000138a1
Mar  9 07:59:23 raspberrypi systemd[1]: Started Check for Raspberry Pi EEPROM updates.
Mar  9 07:59:26 raspberrypi dhcpcd[312]: eth0: carrier acquired
Mar  9 07:59:26 raspberrypi kernel: [   10.553468] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off
Mar  9 07:59:26 raspberrypi kernel: [   10.553524] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Mar  9 07:59:26 raspberrypi dhcpcd[312]: DUID 00:01:00:01:25:1e:c1:bf:dc:a6:32:02:52:cc
Mar  9 07:59:26 raspberrypi dhcpcd[312]: eth0: IAID 32:5b:8d:dc
Mar  9 07:59:26 raspberrypi dhcpcd[312]: eth0: adding address fe80::2005:1697:5f9c:27c0
Mar  9 07:59:26 raspberrypi avahi-daemon[316]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::2005:1697:5f9c:27c0.
Mar  9 07:59:26 raspberrypi avahi-daemon[316]: New relevant interface eth0.IPv6 for mDNS.
Mar  9 07:59:26 raspberrypi avahi-daemon[316]: Registering new address record for fe80::2005:1697:5f9c:27c0 on eth0.*.
Mar  9 07:59:26 raspberrypi dhcpcd[312]: eth0: rebinding lease of 192.168.178.50
Mar  9 07:59:26 raspberrypi dhcpcd[312]: eth0: probing address 192.168.178.50/24
Mar  9 07:59:26 raspberrypi dhcpcd[312]: eth0: soliciting an IPv6 router
Mar  9 07:59:29 raspberrypi kernel: [   14.070864] Bluetooth: Core ver 2.22
Mar  9 07:59:29 raspberrypi kernel: [   14.070975] NET: Registered protocol family 31
Mar  9 07:59:29 raspberrypi kernel: [   14.070991] Bluetooth: HCI device and connection manager initialized
Mar  9 07:59:29 raspberrypi kernel: [   14.071021] Bluetooth: HCI socket layer initialized
Mar  9 07:59:29 raspberrypi kernel: [   14.071044] Bluetooth: L2CAP socket layer initialized
Mar  9 07:59:29 raspberrypi kernel: [   14.071081] Bluetooth: SCO socket layer initialized
Mar  9 07:59:29 raspberrypi kernel: [   14.081659] Bluetooth: HCI UART driver ver 2.3
Mar  9 07:59:29 raspberrypi kernel: [   14.081682] Bluetooth: HCI UART protocol H4 registered
Mar  9 07:59:29 raspberrypi kernel: [   14.081780] Bluetooth: HCI UART protocol Three-wire (H5) registered
Mar  9 07:59:29 raspberrypi kernel: [   14.082098] Bluetooth: HCI UART protocol Broadcom registered
Mar  9 07:59:29 raspberrypi btuart[338]: bcm43xx_init
Mar  9 07:59:29 raspberrypi btuart[338]: Flash firmware /lib/firmware/brcm/BCM4345C0.hcd
Mar  9 07:59:29 raspberrypi btuart[338]: Set Controller UART speed to 3000000 bit/s
Mar  9 07:59:29 raspberrypi btuart[338]: Device setup complete
Mar  9 07:59:29 raspberrypi systemd[1]: Starting Load/Save RF Kill Switch Status...
Mar  9 07:59:29 raspberrypi systemd[1]: Started Configure Bluetooth Modems connected by UART.
Mar  9 07:59:29 raspberrypi systemd[1]: Started Load/Save RF Kill Switch Status.
Mar  9 07:59:29 raspberrypi systemd[1]: Starting Bluetooth service...
Mar  9 07:59:29 raspberrypi systemd[1]: Created slice system-bthelper.slice.
Mar  9 07:59:29 raspberrypi bluetoothd[455]: Bluetooth daemon 5.50
Mar  9 07:59:29 raspberrypi systemd[1]: Started Bluetooth service.
Mar  9 07:59:29 raspberrypi systemd[1]: Started Raspberry Pi bluetooth helper.
Mar  9 07:59:29 raspberrypi systemd[1]: Reached target Bluetooth.
Mar  9 07:59:29 raspberrypi bluetoothd[455]: Starting SDP server
Mar  9 07:59:29 raspberrypi bluetoothd[455]: Bluetooth management interface 1.18 initialized
Mar  9 07:59:29 raspberrypi kernel: [   14.256861] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Mar  9 07:59:29 raspberrypi kernel: [   14.256870] Bluetooth: BNEP filters: protocol multicast
Mar  9 07:59:29 raspberrypi kernel: [   14.256884] Bluetooth: BNEP socket layer initialized
Mar  9 07:59:29 raspberrypi dbus-daemon[319]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.5' (uid=0 pid=455 comm="/usr/lib/bluetooth/bluetoothd ")
Mar  9 07:59:29 raspberrypi bluetoothd[455]: Sap driver initialization failed.
Mar  9 07:59:29 raspberrypi bluetoothd[455]: sap-server: Operation not permitted (1)
Mar  9 07:59:29 raspberrypi bthelper[456]: Raspberry Pi BDADDR already set
Mar  9 07:59:29 raspberrypi systemd[1]: Starting Hostname Service...
Mar  9 07:59:29 raspberrypi dbus-daemon[319]: [system] Successfully activated service 'org.freedesktop.hostname1'
Mar  9 07:59:29 raspberrypi systemd[1]: Started Hostname Service.
Mar  9 07:59:29 raspberrypi bluetoothd[455]: Failed to set privacy: Rejected (0x0b)
Mar  9 07:59:29 raspberrypi bthelper[456]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:5B:8D:DE Name: raspberrypi
Mar  9 07:59:29 raspberrypi bthelper[456]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:5B:8D:DE Alias: raspberrypi
Mar  9 07:59:29 raspberrypi bthelper[456]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:5B:8D:DE UUIDs: 00001801-0000-1000-8000-00805f9b34fb
Mar  9 07:59:29 raspberrypi bthelper[456]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:5B:8D:DE UUIDs: 0000110e-0000-1000-8000-00805f9b34fb
Mar  9 07:59:29 raspberrypi bthelper[456]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:5B:8D:DE UUIDs: 00001200-0000-1000-8000-00805f9b34fb
Mar  9 07:59:29 raspberrypi bthelper[456]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:5B:8D:DE UUIDs: 0000110c-0000-1000-8000-00805f9b34fb
Mar  9 07:59:29 raspberrypi bthelper[456]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:5B:8D:DE UUIDs: 00001800-0000-1000-8000-00805f9b34fb
Mar  9 07:59:29 raspberrypi bthelper[456]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:5B:8D:DE Alias: BlueZ 5.50
Mar  9 07:59:29 raspberrypi bthelper[456]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:5B:8D:DE Pairable: yes
Mar  9 07:59:29 raspberrypi bthelper[456]: Changing power off succeeded
Mar  9 07:59:29 raspberrypi bthelper[456]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:5B:8D:DE Powered: no
Mar  9 07:59:29 raspberrypi bthelper[456]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:5B:8D:DE Discovering: no
Mar  9 07:59:29 raspberrypi bthelper[456]: [#033[0;93mCHG#033[0m] Controller DC:A6:32:5B:8D:DE Alias: raspberrypi
Mar  9 07:59:30 raspberrypi bthelper[456]: Changing power on succeeded
Mar  9 07:59:30 raspberrypi systemd[1]: bthelper@hci0.service: Succeeded.
Mar  9 07:59:31 raspberrypi dhcpcd[312]: eth0: leased 192.168.178.50 for 864000 seconds
Mar  9 07:59:31 raspberrypi dhcpcd[312]: eth0: adding route to 192.168.178.0/24
Mar  9 07:59:31 raspberrypi avahi-daemon[316]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.178.50.
Mar  9 07:59:31 raspberrypi avahi-daemon[316]: New relevant interface eth0.IPv4 for mDNS.
Mar  9 07:59:31 raspberrypi dhcpcd[312]: eth0: adding default route via 192.168.178.1
Mar  9 07:59:31 raspberrypi avahi-daemon[316]: Registering new address record for 192.168.178.50 on eth0.IPv4.
Mar  9 07:59:32 raspberrypi dhcpcd[312]: forked to background, child pid 520
Mar  9 07:59:32 raspberrypi systemd[1]: Started dhcpcd on all interfaces.
Mar  9 07:59:32 raspberrypi systemd[1]: Reached target Network.
Mar  9 07:59:32 raspberrypi systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped.
Mar  9 07:59:32 raspberrypi systemd[1]: Starting Permit User Sessions...
Mar  9 07:59:32 raspberrypi systemd[1]: Reached target Network is Online.
Mar  9 07:59:32 raspberrypi systemd[1]: Starting /etc/rc.local Compatibility...
Mar  9 07:59:32 raspberrypi systemd[1]: Starting Homebridge...
Mar  9 07:59:32 raspberrypi systemd[1]: Started ioBroker Server.
Mar  9 07:59:32 raspberrypi systemd[1]: Starting OpenBSD Secure Shell server...
Mar  9 07:59:32 raspberrypi systemd[1]: Started Permit User Sessions.
Mar  9 07:59:32 raspberrypi run-parts[523]: Ensuring /var/lib/homebridge is owned by homebridge
Mar  9 07:59:32 raspberrypi systemd[1]: Started /etc/rc.local Compatibility.
Mar  9 07:59:32 raspberrypi systemd[1]: Started Getty on tty1.
Mar  9 07:59:32 raspberrypi systemd[1]: Reached target Login Prompts.
Mar  9 07:59:32 raspberrypi systemd[1]: Started OpenBSD Secure Shell server.
Mar  9 07:59:34 raspberrypi systemd[1]: Started Homebridge.
Mar  9 07:59:34 raspberrypi systemd[1]: Reached target Multi-User System.
Mar  9 07:59:34 raspberrypi systemd[1]: Reached target Graphical Interface.
Mar  9 07:59:34 raspberrypi systemd[1]: Starting Update UTMP about System Runlevel Changes...
Mar  9 07:59:34 raspberrypi systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Mar  9 07:59:34 raspberrypi systemd[1]: Started Update UTMP about System Runlevel Changes.
Mar  9 07:59:34 raspberrypi systemd[1]: Startup finished in 2.268s (kernel) + 16.788s (userspace) = 19.056s.
Mar  9 07:59:34 raspberrypi systemd[1]: systemd-rfkill.service: Succeeded.
Mar  9 07:59:35 raspberrypi hb-service.js[547]: #033[37m[2021-3-9 7:59:35]#033[0m #033[36m[HB Supervisor]#033[0m Homebridge Storage Path: /var/lib/homebridge
Mar  9 07:59:35 raspberrypi hb-service.js[547]: #033[37m[2021-3-9 7:59:35]#033[0m #033[36m[HB Supervisor]#033[0m Homebridge Config Path: /var/lib/homebridge/config.json
Mar  9 07:59:35 raspberrypi hb-service.js[547]: #033[37m[2021-3-9 7:59:35]#033[0m #033[36m[HB Supervisor]#033[0m Logging to /var/lib/homebridge/homebridge.log
Mar  9 07:59:36 raspberrypi bash[525]: ================================== > LOG REDIRECT system.adapter.admin.0 => false [system.adapter.admin.0.logging]
Mar  9 07:59:36 raspberrypi bash[525]: ================================== > LOG REDIRECT system.adapter.javascript.0 => false [system.adapter.javascript.0.logging]
Mar  9 07:59:36 raspberrypi bash[525]: object system.meta.uuid created: 97a2673b-c7b9-f210-4a39-11c80b0f14cd
Mar  9 07:59:36 raspberrypi bash[525]: object system.user.admin created
Mar  9 07:59:38 raspberrypi systemd[1]: Created slice User Slice of UID 1000.
Mar  9 07:59:38 raspberrypi systemd[1]: Starting User Runtime Directory /run/user/1000...
Mar  9 07:59:38 raspberrypi systemd[1]: Started User Runtime Directory /run/user/1000.
Mar  9 07:59:38 raspberrypi systemd[1]: Starting User Manager for UID 1000...
Mar  9 07:59:38 raspberrypi systemd[570]: Listening on GnuPG network certificate management daemon.
Mar  9 07:59:38 raspberrypi systemd[570]: Reached target Timers.
Mar  9 07:59:38 raspberrypi systemd[570]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Mar  9 07:59:38 raspberrypi systemd[570]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Mar  9 07:59:38 raspberrypi systemd[570]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Mar  9 07:59:38 raspberrypi systemd[570]: Listening on GnuPG cryptographic agent and passphrase cache.
Mar  9 07:59:38 raspberrypi systemd[570]: Reached target Sockets.
Mar  9 07:59:38 raspberrypi systemd[570]: Reached target Paths.
Mar  9 07:59:38 raspberrypi systemd[570]: Reached target Basic System.
Mar  9 07:59:38 raspberrypi systemd[570]: Reached target Default.
Mar  9 07:59:38 raspberrypi systemd[570]: Startup finished in 183ms.
Mar  9 07:59:38 raspberrypi systemd[1]: Started User Manager for UID 1000.
Mar  9 07:59:38 raspberrypi systemd[1]: Started Session 2 of user pi.
Mar  9 07:59:39 raspberrypi dhcpcd[520]: eth0: no IPv6 Routers available
Mar  9 07:59:51 raspberrypi systemd[1]: systemd-fsckd.service: Succeeded.
Mar  9 08:47:06 raspberrypi systemd-timesyncd[273]: Synchronized to time server for the first time 213.209.109.44:123 (2.debian.pool.ntp.org).
Mar  9 08:47:11 raspberrypi systemd[1]: Started Session 4 of user pi.
Mar  9 08:47:13 raspberrypi systemd[1]: systemd-hostnamed.service: Succeeded.
Mar  9 08:48:41 raspberrypi systemd[1]: Stopping ioBroker Server...
Mar  9 08:48:42 raspberrypi systemd[1]: iobroker.service: Main process exited, code=exited, status=1/FAILURE
Mar  9 08:48:42 raspberrypi systemd[1]: iobroker.service: Failed with result 'exit-code'.
Mar  9 08:48:42 raspberrypi systemd[1]: Stopped ioBroker Server.

Ich hoffe mir kann hier jemand weiterhelfen... ich hab schon alle möglichen Sachen ausprobiert, erst war ich auf dem Trichter, dass es möglicherweise ein DNS-Problem sein könnte, deshalb bin ich unter anderem auch von WLAN auf LAN umgestiegen. Auch eine defekte SD-Karte konnte ich mehr oder weniger ausschließen, habe das ganze Setup auf einer neuen SD-Card wiederhergestellt. Also ich denke, dass die Tatsache, dass sich die objects.json "willkürlich" löscht bzw. leert unter Umständen ein guter Anhaltspunkt sein kann, wo das Problem liegt - wie gesagt, nach Herstellung eines der zahlreichen automatischen objects.json-Backups läuft alles wieder einwandfrei...

Danke schonmal und beste Grüße
Niels

[AlCalzone]

Zur Erklärung, warum die objects.json sich scheinbar löscht:
Sie wird regelmäßig neu geschrieben und anscheinend läuft dabei was falsch (z.B. Absturz). Mehr kann ich leider nicht beitragen.

[UncleSam]

@reviewdiepie Deine Zeit im Syslog springt ja rum wie ein junges Reh im Wald!

Wie geht es der Stromversorgung des Pi? Das wäre das nächste, was ich nach der SD Karte im Verdacht hätte.

@reviewdiepie sagte in ioBroker nicht mehr erreichbar - objects.json "löscht" sich:

habe das ganze Setup auf einer neuen SD-Card wiederhergestellt

Was heisst das? Neu aufgesetzt oder rüber kopiert? Backup von ioBroker benutzt?

[ReviewDiePie]

@reviewdiepie Deine Zeit im Syslog springt ja rum wie ein junges Reh im Wald!

Nur bei dem außerplanmäßigen "was auch immer" um 07:59 Uhr oder?

Wie geht es der Stromversorgung des Pi? Das wäre das nächste, was ich nach der SD Karte im Verdacht hätte.

Die ist konstant, habe das selbe 3A 5V Netzteil, was ich seit knapp nem Jahr nutze dran. Habe auch das offizielle RPi-Netzteil rumliegen, mit dem hatte ich seltsamerweise eher Probleme... Hatte aber tatsächlich testweise mal kurz gewechselt, Probleme waren beständig.

EDIT: Habe jetzt mal wieder das offizielle Pi4-Netzteil angeschlossen u zu sehen ob es doch etwas ändert... wird man halt leider erst in 1-5 Tagen sehen, ob das Problem dennoch wieder auftaucht. Vielleicht kann ja jemand mehr aus dem Log "rauslesen"...

Was heisst das? Neu aufgesetzt oder rüber kopiert? Backup von ioBroker benutzt?

Heißt: SD-Karte als Image gezogen und auf eine neue SD-Karte "gebrannt". Die Sache ist, ich mache regelmäßig solche IMG-Backups, falls mal ne SD-Karte abraucht ist das am wenigsten arbeit. Ich habe ein Backup vom November auf die neue SD-Karte eingespielt. Dieses Setup lief ja von November bis Ende Januar noch problemlos weiter. Den kompletten Februar über hats nur noch Probleme gemacht und diese Probleme bestehen auch seit der Wiederherstellung des alten IMG auf neuer SD-Karte, daher bin ich "irritiert", da sich ja eigentlich nichts an meinem Setup geändert hat. Die Adapter halte ich immer auf dem neusten Stand...

Gruß
Niels

[Dr. Bakterius]

@reviewdiepie Der js-Controller hat mit einem seiner letzten Updates hier eine Änderung gebracht. Um die Schreibzugriffe zu senken, wird die Sicherung der objects.json und states.json anders gehandhabt. Offensichtlich erfolgt bei dir beim Neuschreiben der Datei(en) ein Schreibfehler. Die Frage ist aber jetzt warum das passiert. SD-Karte, Stromversorgung und Konsorten sind ja schon genannt worden. Eventuell gehst du auf eine ältere Version des Controllers zurück oder probierst mal jsonl oder jarvis.

[ReviewDiePie]

@dr-bakterius

Hi, ich bin schon vor 3 Tagen zurück auf js-controller@3.2.14... dachte auch, dass es daran liegen könnte, kam aber leider wie beschrieben heute morgen trotzdem vor.

was meinst du mit jsonl oder jarvis probieren? Kann mit den Begriffen nichts anfangen, dafür bin ich scheinbar noch nicht tief genug in der Materie versunken Danke!

[Thomas Braun]

@reviewdiepie sagte in ioBroker nicht mehr erreichbar - objects.json "löscht" sich:

Heißt: SD-Karte als Image gezogen und auf eine neue SD-Karte "gebrannt". Die Sache ist, ich mache regelmäßig solche IMG-Backups, falls mal ne SD-Karte abraucht ist das am wenigsten arbeit.

Da sind so viele 'merkwürdige' Meldungen im syslog, dem System würde ich nicht mehr vertrauen.
Sauber NEU aufsetzen, NICHT:

Heißt: SD-Karte als Image gezogen und auf eine neue SD-Karte "gebrannt". Die Sache ist, ich mache regelmäßig solche IMG-Backups, falls mal ne SD-Karte abraucht ist das am wenigsten arbeit.

Dann Backup nur des ioBrokers einspielen.

[UncleSam]

@thomas-braun sagte in ioBroker nicht mehr erreichbar - objects.json "löscht" sich:

Sauber NEU aufsetzen, NICHT:

Meine Worte.

@ReviewDiePie SD Karte kopieren ist kein wirklich sinnvolles Backup. Wenn nämlich im Dateisystem etwas faul ist, dann kopierst du das gleich mit. Backups würde ich nur mit Backitup machen und halt mal ein Shell Skript schreiben, das dir "alles andere" installiert, wenn du noch mehr drauf hast als nur ioBroker. Oder zumindest einfach den Inhalt der "anderen" Ordner irgendwo hin kopieren.

[ReviewDiePie]

@unclesam

ich hab da tatsächlich auch noch ne Homebridge laufen...

Backitup läuft mit und macht jede Nacht n BackUp vom iobroker und zigbee.. Habe ehrlich gesagt ein wenig nen graus vorm neu aufsetzen... wie ist das nochmal mit der Konfiguration sämtlicher Adapter und den Javaskripten? Sind die enthalten wenn ich via backitup restore? Welche Daten von der SD sollte ich sinnvollerweise vorher noch wegsichern um später der neuen sauberen Installation nichts schlechtes damit zu tun?

Ich versteh schon, dass ihr dem IMG-BackUp "misstraut", andererseits lief das ja wie gesagt über Monate hinweg gut und ich habe nicht wirklich was verändert. Selbst wenn, das gebrannte IMG war wie gesagt aus November und von Nov-Januar hatte ich keinerlei Probleme, heißt eigentlic dass der Fehler sich dann erst später eigneschlichen haben kann... aber gut, ist jetzt schwer zu rekonstruieren.

Also neue Installation aufsetzen und dann wie welche Backups einspielen um nicht zu riskieren die Bugs zu importieren? Lässt sich alles sichern ohne dass ich alles neu einstellen/scripten muss? Homebridge?

Sorry für die vielen dummen Fragen, aber diesmal will ichs dann auch alles korrekt machen

Liebe Grüße!

[UncleSam]

@reviewdiepie sagte in ioBroker nicht mehr erreichbar - objects.json "löscht" sich:

Also neue Installation aufsetzen und dann wie welche Backups einspielen um nicht zu riskieren die Bugs zu importieren? Lässt sich alles sichern ohne dass ich alles neu einstellen/scripten muss?

iobroker backup oder der Backitup Adapter erledigen alles für ioBroker. Wenn du noch mehr drauf hast, dann musst du selber schauen.

Homebridge?

Benutz doch den ham Adapter mit dem integrierten Modus (statt "Global"), dann ist die ganze Homebridge Config auch gleich in ioBroker drin.

[Dr. Bakterius]

@reviewdiepie sagte in ioBroker nicht mehr erreichbar - objects.json "löscht" sich:

was meinst du mit jsonl oder jarvis probieren?

Ist eine andere Variante die Daten von ioBroker zu speichern. Und ich meine redis nicht jarvis, sorry. Allerdings würde ich dir auch empfehlen das System plus ioBroker neu aufzusetzen und dann das letzte Backup einspielen. Ist auch nicht viel komplizierter als die Datenverwaltung umzustellen und dann vielleicht vom Regen in die Traufe zu kommen.

[ReviewDiePie]

@unclesam

bzgl HAM, das würd ich gern machen, hab ich aber irgendwie nie hinbekommen. Mehrfach versucht (damals auch auf ner sauberen Neuinstallation aufbauend..) irgendwas wollte da immer nicht so wie ich...

Im iobroker backup sind also auch die javascripts etc enthalten? Gut... dann muss das wohl sein. Homebridge muss ich mal schauen, ob ich das anderweitig gesichert bekomme.

Danke!

Irgendwie würde mich aber dennoch interessieren was da eigentlich schief läuft und wieso... ich warte erstmal obs u.U. mit dem original Pi-Netzteil nicht passiert, dann wäre es auf Stromversorgung zurückzuführen, kann wohl zu den wildesten Problemen führen...

Oder sind da noch irgendwelche komplett unabhängigen Probleme im Log, welche ein Neuaufsetzen quasi unumgänglich machen? @Thomas-Braun

[Thomas Braun]

@reviewdiepie sagte in ioBroker nicht mehr erreichbar - objects.json "löscht" sich:

Das sind so ein paar Meldungen, die ich äußerst verdächtig finde bzw. die ich so auch noch nicht gesehen habe.
Also in einem gesunden System sollten die nicht auftauchen.

[wendy2702]

@reviewdiepie sagte in ioBroker nicht mehr erreichbar - objects.json "löscht" sich:

Ubuntu/Linaro

Und wenn du neu aufsetzt.... nimm ein offizielles Raspi OS.

[Thomas Braun]

@wendy2702 Ist es. Das ist nur das System, auf dem der Kernel gebacken wurde.

[wendy2702]

@thomas-braun Woran siehst du das?

Ich scrolle mir einen Wolf auf dem Smartphone durch das Syslog von oben nach unten und links nach rechts.

[wendy2702]

@reviewdiepie sagte in ioBroker nicht mehr erreichbar - objects.json "löscht" sich:

Use raspi-config

Denke ich habs gefunden.

Oder zumindest einen Hinweis darauf.

[Thomas Braun]

@wendy2702

Cross-compiling.

https://www.raspberry-pi-geek.de/ausgaben/rpg/2015/06/raspberry-pi-programme-per-crosscompiling-auf-dem-pc-bauen/2/

Das System wird natürlich nicht auf einem schwächlichen Pi direkt gebaut sondern per Crosscompiler auf einer 'dicken' Kiste. Das würde ja sonst kein Ende finden.

[wendy2702]

@thomas-braun Danke.

Mal lesen wenn der Bildschirm wieder größer ist.

[UncleSam]

@reviewdiepie sagte in ioBroker nicht mehr erreichbar - objects.json "löscht" sich:

Homebridge muss ich mal schauen, ob ich das anderweitig gesichert bekomme.

Und wenn's nicht geht, sind die Entwickler froh um Feedback! Hier im Forum oder als Issue in GitHub.

Eine neue Version ist schon bald im Anmarsch, allerdings muss unter anderem der schreibende auch noch einiges fixen...