`ping` node story. Weird happenings

General
1

Ok, I recently posted about the advanced-ping node because the original ping node didn't support a list being sent. (Or something like that.)

I went through and modified the existing flows to use the standard ping node and not the extra one advanced-ping.

I installed the newer/est version of said node and things were working.

Or so I thought!

I went away for 2 weeks - and is why I have been so quiet.

I came back and the system wasn't working.

I looked on one of my machines. It was alive, but NR wouldn't load the dashboad.

Going to the edit screen it was there saying: I am not going to start until the missing node is installed.
(Well, you know what I mean)

So I looked at the palette manager and the ping node wasn't there - at all!

I installed it, and then node-red started working.

So my question is:

What happened?

It was working before I left.
During my absence the machine rebooted - I think, or it is implied with the logs I see - and then NR decided that node wasn't there and just didn't deploy. (Activate?)

It is now working. But for how long?

2

Does it keep working if you do a full power cycle (not just reboot).

3

Oh, not sure about a power cycle.

But why/how would that be different?

I believe I have a watchdog that reboots the machine if it gets overloaded.

4

If it is on something like pi that uses an SD card then if it means that the card has failed. A common mode of failure is that it stops saving data to flash. So any writes to the card are lost on removing power.

5

Yeah, ok.

So given there was no power loss and it just rebooted - by command - how did the node vanish?

6

Have you done a power cycle to see if it is this problem?

7

I shall do it later as this is a main machine and it isn't good just now.

Sorry.

8

Well there is not much point trying to explain it until you have tried.

1 Like
9

Powered down and powering back up.

That opened a whole new can of worms.

I'll get back when things are working.

Ok, it is working. I have another (different) error which I think I have mentioned.

So the SD card is looking good.

10

Today - just now - another machine.

Just went crazy and locked up. :frowning:
Spitting out errors like this:

Error: spawn EIO    at ChildProcess.spawn (internal/child_process.js:313:11)    at exports.spawn (child_process.js:508:9)    at doPing (/home/pi/.node-red/node_modules/node-red-node-ping/88-ping.js:40:14)    at PingNode._inputCallback (/home/pi/.node-red/node_modules/node-red-node-ping/88-ping.js:120:36)    at hooks.trigger (/usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/nodes/Node.js:203:26)    at Object.trigger (/usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/hooks.js:113:9)    at PingNode.Node._emitInput (/usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/nodes/Node.js:195:11)    at PingNode.Node.emit (/usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/nodes/Node.js:179:25)    at PingNode.Node.receive (/usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/nodes/Node.js:476:10)    at Immediate.<anonymous> (/usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/flows/Flow.js:657:52)

About this time another node went belly up too.

node-red-contrib-vcgencmd

and ..... Well, that's a whole other thread.

But it too was spitting out errors.
Had to reboot the machine.

Not happy as the MTBF for reboots is just over 2 weeks.

So: Sticking to this error.

Does it give much in the way of what went wrong?

Sorry, this may be a bigger/better paste of the error:

{"message":"Error: spawn EIO","source":{"id":"286d9c48.9ce52c","type":"ping","name":"TV","count":1},"stack":"Error: spawn EIO\n    at ChildProcess.spawn (internal/child_process.js:313:11)\n    at exports.spawn (child_process.js:508:9)\n    at doPing (/home/pi/.node-red/node_modules/node-red-node-ping/88-ping.js:40:14)\n    at PingNode._inputCallback (/home/pi/.node-red/node_modules/node-red-node-ping/88-ping.js:120:36)\n    at hooks.trigger (/usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/nodes/Node.js:203:26)\n    at Object.trigger (/usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/hooks.js:113:9)\n    at PingNode.Node._emitInput (/usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/nodes/Node.js:195:11)\n    at PingNode.Node.emit (/usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/nodes/Node.js:179:25)\n    at PingNode.Node.receive (/usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/nodes/Node.js:476:10)\n    at Immediate.<anonymous> (/usr/lib/node_modules/node-red/node_modules/@node-red/runtime/lib/flows/Flow.js:657:52)"}
11

Same question as usual when it looks like a system problem, what is in syslog at the time it failed?

12

Yeah.... Sorry. CRAFT disease again.

I'm still learning how to do that search.

Given I posted the error message, what command do I need to search the log?

I know it is the:

zgrep -i --color=always -A 10 -B 10 "Key in object structure" /var/log/syslog* | awk -F: '{if(f!=$1)print "=========="; f=$1; print $0;}'

But that isn't looking for the right thing and I am still not able to work out how / what to put to search.

Sorry.

Ok, what I make of it:
zgrep show colours show 10 lines before and 10 after. Search for "Key in object structure" and where to find it. Then send that to awk and then, I'm stumped.

13

Ok, I did a look in the error file I created and it happened to day at 10:26 local.

When I search the syslog things don't add up.

An extract:

Feb  1 10:17:27 BedPi systemd[606]: Starting Virtual filesystem service - digital camera monitor...
Feb  1 10:17:27 BedPi dbus-daemon[623]: Successfully activated service 'org.gtk.vfs.GPhoto2VolumeMonitor'
Feb  1 10:17:27 BedPi systemd[606]: Started Virtual filesystem service - digital camera monitor.
Feb  1 10:17:27 BedPi dbus-daemon[623]: Activating via systemd: service name='org.gtk.vfs.AfcVolumeMonitor' unit='gvfs-afc-volume-monitor.service'
Feb  1 10:17:27 BedPi Node-RED[341]: 1 Feb 10:17:27 - [info]
Feb  1 10:17:27 BedPi Node-RED[341]: Welcome to Node-RED
Feb  1 10:17:27 BedPi Node-RED[341]: ===================
Feb  1 10:17:27 BedPi systemd[606]: Starting Virtual filesystem service - Apple File Conduit monitor...
Feb  1 10:17:27 BedPi Node-RED[341]: 1 Feb 10:17:27 - [info] Node-RED version: v1.2.6
Feb  1 10:17:27 BedPi Node-RED[341]: 1 Feb 10:17:27 - [info] Node.js  version: v8.17.0
Feb  1 10:17:27 BedPi Node-RED[341]: 1 Feb 10:17:27 - [info] Linux 4.19.66-v7+ arm LE
Feb  1 10:17:27 BedPi gvfs-afc-volume-monitor[813]: Volume monitor alive
Feb  1 10:17:27 BedPi dbus-daemon[623]: Successfully activated service 'org.gtk.vfs.AfcVolumeMonitor'
Feb  1 10:17:27 BedPi systemd[606]: Started Virtual filesystem service - Apple File Conduit monitor.
Feb  1 10:17:28 BedPi kernel: [   34.964045] FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
Feb  1 10:17:28 BedPi udisksd[775]: Mounted /dev/sda1 at /media/pi/06BB-C87D on behalf of uid 1000
Feb  1 10:17:29 BedPi systemd[1]: Started Certbot.
Feb  1 10:17:29 BedPi systemd[1]: certbot.timer: Adding 8h 37min 34.656962s random time.
Feb  1 10:17:29 BedPi systemd[1]: certbot.timer: Adding 7h 23min 16.477861s random time.
Feb  1 10:27:30 BedPi systemd[507]: Time has been changed
Feb  1 10:27:30 BedPi systemd[1]: Time has been changed
Feb  1 10:27:30 BedPi systemd[606]: Time has been changed
Feb  1 10:27:30 BedPi systemd-timesyncd[275]: Synchronized to time server 216.218.254.202:123 (2.debian.pool.ntp.org).
Feb  1 10:27:30 BedPi systemd[1]: certbot.timer: Adding 7h 38min 20.374165s random time.
Feb  1 10:27:30 BedPi systemd[1]: apt-daily.timer: Adding 2h 34min 55.878925s random time.
Feb  1 10:27:30 BedPi systemd[1]: apt-daily-upgrade.timer: Adding 46min 45.158730s random time.
Feb  1 10:27:34 BedPi Node-RED[341]: 1 Feb 10:27:34 - [info] Loading palette nodes
Feb  1 10:27:56 BedPi kernel: [   68.344194] random: crng init done
Feb  1 10:27:56 BedPi kernel: [   68.344212] random: 7 urandom warning(s) missed due to ratelimiting
Feb  1 10:27:56 BedPi vncserver-x11[428,root]: ServerManager: Server started
Feb  1 10:27:57 BedPi vncserver-x11[428,root]: ConsoleDisplay: Found running X server (pid=506, binary=/usr/lib/xorg/Xorg)
Feb  1 10:28:04 BedPi Node-RED[341]: 1 Feb 10:28:04 - [info] Dashboard version 2.26.1 started at /ui

It doesn't have anything logged at 10:26.

It goes from 10:17 to 10:27.

But that is because somewhere around then I power cycled it because it (the machine) was dead.

pi@BedPi:/media/pi/06BB-C87D/logs/reboot $ cat Rebooted\ at\ 2021-02-01\ 102832.db 
2021-02-01 10:26:37
up 2 weeks, 3 days, 13 hours, 44 minutes

So that shows it got shut down about 10:26.

Does that help?

14

(Sorry)

This is a bigger/better extract of the syslog file around that time.

From 10:12 - 10:27 which shows the machine being powered up again.

Ok, a slightly cut down cut down post.

Feb  1 10:17:04 BedPi kernel: [    0.795962] dwc_otg 3f980000.usb: DWC OTG Controller
Feb  1 10:17:04 BedPi kernel: [    0.796014] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
Feb  1 10:17:04 BedPi kernel: [    0.796070] dwc_otg 3f980000.usb: irq 56, io mem 0x00000000
Feb  1 10:17:04 BedPi systemd[1]: Reached target RPC Port Mapper.
Feb  1 10:17:04 BedPi kernel: [    0.796121] Init: Port Power? op_state=1
Feb  1 10:17:04 BedPi kernel: [    0.796128] Init: Power Port (0)
Feb  1 10:17:04 BedPi kernel: [    0.796507] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
Feb  1 10:17:04 BedPi systemd[1]: Started Network Time Synchronization.
Feb  1 10:17:04 BedPi kernel: [    0.796522] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
Feb  1 10:17:04 BedPi kernel: [    0.796533] usb usb1: Product: DWC OTG Controller
Feb  1 10:17:04 BedPi kernel: [    0.796545] usb usb1: Manufacturer: Linux 4.19.66-v7+ dwc_otg_hcd
Feb  1 10:17:04 BedPi systemd[1]: Reached target System Time Synchronized.
Feb  1 10:17:04 BedPi kernel: [    0.796556] usb usb1: SerialNumber: 3f980000.usb
Feb  1 10:17:04 BedPi kernel: [    0.797464] hub 1-0:1.0: USB hub found
Feb  1 10:17:04 BedPi kernel: [    0.797532] hub 1-0:1.0: 1 port detected
Feb  1 10:17:04 BedPi kernel: [    0.798370] dwc_otg: FIQ enabled
Feb  1 10:17:04 BedPi kernel: [    0.798379] dwc_otg: NAK holdoff enabled
Feb  1 10:17:04 BedPi kernel: [    0.798386] dwc_otg: FIQ split-transaction FSM enabled
Feb  1 10:17:04 BedPi kernel: [    0.798405] Module dwc_common_port init
Feb  1 10:17:04 BedPi kernel: [    0.798837] usbcore: registered new interface driver usb-storage
Feb  1 10:17:04 BedPi kernel: [    0.799120] mousedev: PS/2 mouse device common for all mice
Feb  1 10:17:04 BedPi kernel: [    0.800262] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
Feb  1 10:17:04 BedPi kernel: [    0.800584] bcm2835-cpufreq: min=600000 max=900000
Feb  1 10:17:04 BedPi kernel: [    0.801184] sdhci: Secure Digital Host Controller Interface driver
Feb  1 10:17:04 BedPi kernel: [    0.801191] sdhci: Copyright(c) Pierre Ossman
Feb  1 10:17:04 BedPi kernel: [    0.801718] sdhost-bcm2835 3f202000.mmc: could not get clk, deferring probe
Feb  1 10:17:04 BedPi kernel: [    0.801916] sdhci-pltfm: SDHCI platform and OF driver helper
Feb  1 10:17:04 BedPi kernel: [    0.802895] ledtrig-cpu: registered to indicate activity on CPUs
Feb  1 10:17:04 BedPi kernel: [    0.803054] hidraw: raw HID events driver (C) Jiri Kosina
Feb  1 10:17:04 BedPi kernel: [    0.803293] usbcore: registered new interface driver usbhid
Feb  1 10:17:04 BedPi kernel: [    0.803300] usbhid: USB HID core driver
Feb  1 10:17:04 BedPi kernel: [    0.804227] vchiq: vchiq_init_state: slot_zero = (ptrval), is_master = 0
Feb  1 10:17:04 BedPi kernel: [    0.806034] [vc_sm_connected_init]: start
Feb  1 10:17:04 BedPi kernel: [    0.815339] [vc_sm_connected_init]: end - returning 0
Feb  1 10:17:04 BedPi kernel: [    0.816887] Initializing XFRM netlink socket
Feb  1 10:17:04 BedPi kernel: [    0.816929] NET: Registered protocol family 17
Feb  1 10:17:04 BedPi kernel: [    0.817082] Key type dns_resolver registered
Feb  1 10:17:04 BedPi kernel: [    0.817649] Registering SWP/SWPB emulation handler
Feb  1 10:17:04 BedPi kernel: [    0.818687] registered taskstats version 1
Feb  1 10:17:04 BedPi kernel: [    0.818710] Loading compiled-in X.509 certificates
Feb  1 10:17:04 BedPi kernel: [    0.828051] uart-pl011 3f201000.serial: cts_event_workaround enabled
Feb  1 10:17:04 BedPi kernel: [    0.828185] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 81, base_baud = 0) is a PL011 rev2
Feb  1 10:17:04 BedPi kernel: [    0.828263] console [ttyAMA0] enabled
Feb  1 10:17:04 BedPi kernel: [    0.831154] sdhost: log_buf @ (ptrval) (fad13000)
Feb  1 10:17:04 BedPi kernel: [    0.878180] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
Feb  1 10:17:04 BedPi kernel: [    0.879942] of_cfs_init
Feb  1 10:17:04 BedPi kernel: [    0.880199] of_cfs_init: OK
Feb  1 10:17:04 BedPi kernel: [    0.881165] Waiting for root device PARTUUID=b677eeab-02...
Feb  1 10:17:04 BedPi kernel: [    0.937805] mmc0: host does not support reading read-only switch, assuming write-enable
Feb  1 10:17:04 BedPi kernel: [    0.940732] mmc0: new high speed SDXC card at address 1234
Feb  1 10:17:04 BedPi kernel: [    0.942360] mmcblk0: mmc0:1234 SA64G 57.7 GiB
Feb  1 10:17:04 BedPi kernel: [    0.945330]  mmcblk0: p1 p2
Feb  1 10:17:04 BedPi kernel: [    0.968120] EXT4-fs (mmcblk0p2): INFO: recovery required on readonly filesystem
Feb  1 10:17:04 BedPi kernel: [    0.968135] EXT4-fs (mmcblk0p2): write access will be enabled during recovery
Feb  1 10:17:04 BedPi kernel: [    1.012766] Indeed it is in host mode hprt0 = 00021501
Feb  1 10:17:04 BedPi kernel: [    1.093200] random: fast init done
Feb  1 10:17:04 BedPi kernel: [    1.222656] usb 1-1: new high-speed USB device number 2 using dwc_otg
Feb  1 10:17:04 BedPi kernel: [    1.222875] Indeed it is in host mode hprt0 = 00001101
Feb  1 10:17:04 BedPi kernel: [    1.462959] usb 1-1: New USB device found, idVendor=0424, idProduct=9514, bcdDevice= 2.00
Feb  1 10:17:04 BedPi kernel: [    1.462977] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Feb  1 10:17:04 BedPi kernel: [    1.463922] hub 1-1:1.0: USB hub found
Feb  1 10:17:04 BedPi systemd[1]: Reached target System Initialization.
Feb  1 10:17:04 BedPi kernel: [    1.464064] hub 1-1:1.0: 5 ports detected
Feb  1 10:17:04 BedPi kernel: [    1.782590] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
Feb  1 10:17:04 BedPi kernel: [    1.912923] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00, bcdDevice= 2.00
Feb  1 10:17:04 BedPi kernel: [    1.912939] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Feb  1 10:17:04 BedPi kernel: [    1.915782] smsc95xx v1.0.6
Feb  1 10:17:04 BedPi kernel: [    2.007190] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:15:c0:30
Feb  1 10:17:04 BedPi systemd[1]: Started CUPS Scheduler.
Feb  1 10:17:04 BedPi kernel: [    2.102594] usb 1-1.3: new high-speed USB device number 4 using dwc_otg
Feb  1 10:17:04 BedPi kernel: [    2.234908] usb 1-1.3: New USB device found, idVendor=058f, idProduct=6387, bcdDevice= 1.02
Feb  1 10:17:04 BedPi kernel: [    2.234926] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Feb  1 10:17:04 BedPi kernel: [    2.234937] usb 1-1.3: Product: Mass Storage
Feb  1 10:17:04 BedPi kernel: [    2.234949] usb 1-1.3: Manufacturer: Generic
Feb  1 10:17:04 BedPi systemd[1]: Reached target Paths.
Feb  1 10:17:04 BedPi kernel: [    2.234960] usb 1-1.3: SerialNumber: C7705276
Feb  1 10:17:04 BedPi kernel: [    2.235860] usb-storage 1-1.3:1.0: USB Mass Storage device detected
Feb  1 10:17:04 BedPi kernel: [    2.236823] scsi host0: usb-storage 1-1.3:1.0
Feb  1 10:17:04 BedPi systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket.
Feb  1 10:17:04 BedPi kernel: [    3.273827] scsi 0:0:0:0: Direct-Access     Generic  Flash Disk       8.00 PQ: 0 ANSI: 2
Feb  1 10:17:04 BedPi kernel: [    3.275615] sd 0:0:0:0: [sda] 248320 512-byte logical blocks: (127 MB/121 MiB)
Feb  1 10:17:04 BedPi kernel: [    3.275940] sd 0:0:0:0: [sda] Write Protect is off
Feb  1 10:17:04 BedPi kernel: [    3.275956] sd 0:0:0:0: [sda] Mode Sense: 03 00 00 00
Feb  1 10:17:04 BedPi kernel: [    3.276298] sd 0:0:0:0: [sda] No Caching mode page found
Feb  1 10:17:04 BedPi kernel: [    3.281819] sd 0:0:0:0: [sda] Assuming drive cache: write through
Feb  1 10:17:04 BedPi systemd[1]: Listening on D-Bus System Message Bus Socket.
Feb  1 10:17:04 BedPi kernel: [    3.444867]  sda: sda1
Feb  1 10:17:04 BedPi kernel: [    3.447862] sd 0:0:0:0: [sda] Attached SCSI removable disk
Feb  1 10:17:04 BedPi kernel: [    5.084126] EXT4-fs (mmcblk0p2): orphan cleanup on readonly fs
Feb  1 10:17:04 BedPi systemd[1]: Listening on triggerhappy.socket.
Feb  1 10:17:04 BedPi kernel: [    5.084388] EXT4-fs (mmcblk0p2): 1 orphan inode deleted
Feb  1 10:17:04 BedPi kernel: [    5.084401] EXT4-fs (mmcblk0p2): recovery complete
Feb  1 10:17:04 BedPi kernel: [    5.164309] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
Feb  1 10:17:04 BedPi kernel: [    5.164399] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
Feb  1 10:17:04 BedPi kernel: [    5.165537] devtmpfs: mounted
Feb  1 10:17:04 BedPi systemd[1]: Listening on PC/SC Smart Card Daemon Activation Socket.
Feb  1 10:17:04 BedPi kernel: [    5.171332] Freeing unused kernel memory: 1024K
Feb  1 10:17:04 BedPi kernel: [    5.171641] Run /sbin/init as init process
Feb  1 10:17:04 BedPi kernel: [    5.890245] NET: Registered protocol family 10
Feb  1 10:17:04 BedPi systemd[1]: certbot.timer: Adding 8h 1min 48.375493s random time.
Feb  1 10:17:04 BedPi kernel: [    5.892306] Segment Routing with IPv6
Feb  1 10:17:04 BedPi kernel: [    5.939770] random: systemd: uninitialized urandom read (16 bytes read)
Feb  1 10:17:04 BedPi kernel: [    5.952097] random: systemd: uninitialized urandom read (16 bytes read)
Feb  1 10:17:04 BedPi systemd[1]: Started Run certbot twice daily.
Feb  1 10:17:04 BedPi systemd[1]: Started Daily Cleanup of Temporary Directories.
Feb  1 10:17:04 BedPi systemd[1]: Listening on CUPS Scheduler.
Feb  1 10:17:04 BedPi systemd[1]: Reached target Sockets.
Feb  1 10:17:04 BedPi systemd[1]: Reached target Basic System.
Feb  1 10:17:04 BedPi systemd[1]: Starting Login Service...
Feb  1 10:17:04 BedPi systemd[1]: Started Regular background program processing daemon.
Feb  1 10:17:04 BedPi systemd[1]: Starting System Logging Service...
Feb  1 10:17:04 BedPi systemd[1]: Starting Save/Restore Sound Card State...
Feb  1 10:17:04 BedPi systemd[1]: Started CUPS Scheduler.
Feb  1 10:17:04 BedPi systemd[1]: apt-daily.timer: Adding 2h 45min 51.240092s random time.
Feb  1 10:17:04 BedPi systemd[1]: Started Daily apt download activities.
Feb  1 10:17:04 BedPi systemd[1]: Starting Check for v3d driver...
Feb  1 10:17:04 BedPi systemd[1]: Started Clean PHP session files every 30 mins.
Feb  1 10:17:04 BedPi cron[315]: (CRON) INFO (pidfile fd = 3)
Feb  1 10:17:04 BedPi systemd[1]: Started D-Bus System Message Bus.
Feb  1 10:17:04 BedPi cron[315]: (CRON) INFO (Running @reboot jobs)
Feb  1 10:17:04 BedPi liblogging-stdlog:  [origin software="rsyslogd" swVersion="8.24.0" x-pid="316" x-info="http://www.rsyslog.com"] start
Feb  1 10:17:04 BedPi kernel: [    6.048095] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read)
Feb  1 10:17:04 BedPi kernel: [    6.084842] uart-pl011 3f201000.serial: no DMA platform data
Feb  1 10:17:04 BedPi kernel: [    6.925135] i2c /dev entries driver
Feb  1 10:17:04 BedPi kernel: [    7.050771] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
Feb  1 10:17:04 BedPi kernel: [    8.134297] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
Feb  1 10:17:04 BedPi kernel: [    8.846307] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
Feb  1 10:17:04 BedPi kernel: [    8.859666] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
Feb  1 10:17:04 BedPi kernel: [    8.859691] [vc_sm_connected_init]: start
Feb  1 10:17:04 BedPi kernel: [    8.867608] media: Linux media interface: v0.10
Feb  1 10:17:04 BedPi kernel: [    8.869584] [vc_sm_connected_init]: installed successfully
Feb  1 10:17:04 BedPi kernel: [    8.907889] videodev: Linux video capture interface: v2.00
Feb  1 10:17:04 BedPi kernel: [    8.984138] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
Feb  1 10:17:04 BedPi kernel: [    9.021695] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
Feb  1 10:17:04 BedPi kernel: [    9.031438] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
Feb  1 10:17:04 BedPi kernel: [    9.032423] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
Feb  1 10:17:04 BedPi kernel: [    9.048495] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
Feb  1 10:17:04 BedPi kernel: [    9.048516] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
Feb  1 10:17:04 BedPi kernel: [    9.057117] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
Feb  1 10:17:04 BedPi kernel: [    9.057147] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
Feb  1 10:17:04 BedPi kernel: [    9.067270] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
Feb  1 10:17:04 BedPi kernel: [    9.067289] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
Feb  1 10:17:04 BedPi kernel: [    9.068363] bcm2835_audio soc:audio: card created with 8 channels
Feb  1 10:17:04 BedPi kernel: [    9.356692] usbcore: registered new interface driver uas
Feb  1 10:17:04 BedPi kernel: [    9.462338] sd 0:0:0:0: Attached scsi generic sg0 type 0
Feb  1 10:17:05 BedPi CRON[335]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker remote reboot)
Feb  1 10:17:05 BedPi CRON[336]: (root) CMD (/usr/sbin/logrotate /etc/pihole/logrotate)
Feb  1 10:17:05 BedPi dbus[320]: [system] Successfully activated service 'org.freedesktop.systemd1'
Feb  1 10:17:05 BedPi systemd[1]: Starting WPA supplicant...
Feb  1 10:17:05 BedPi systemd[1]: apt-daily-upgrade.timer: Adding 13min 50.116252s random time.
Feb  1 10:17:05 BedPi systemd[1]: Started Daily apt upgrade and clean activities.
Feb  1 10:17:05 BedPi systemd[1]: Reached target Timers.
Feb  1 10:17:05 BedPi systemd[1]: Started Node-RED graphical event wiring tool.
Feb  1 10:17:05 BedPi systemd[1]: Starting Disable WiFi if country not set...
Feb  1 10:17:05 BedPi systemd[1]: Starting dhcpcd on all interfaces...
Feb  1 10:17:05 BedPi systemd[1]: Starting triggerhappy global hotkey daemon...
Feb  1 10:17:05 BedPi systemd[1]: Starting Avahi mDNS/DNS-SD Stack...
Feb  1 10:17:05 BedPi systemd[1]: Started System Logging Service.
Feb  1 10:17:05 BedPi systemd[1]: Started Save/Restore Sound Card State.
Feb  1 10:17:05 BedPi systemd[1]: Started Check for v3d driver.
Feb  1 10:17:05 BedPi systemd[1]: Started Disable WiFi if country not set.
Feb  1 10:17:05 BedPi thd[346]: Found socket passed from systemd
Feb  1 10:17:05 BedPi systemd[1]: Starting Certbot...
Feb  1 10:17:05 BedPi systemd[1]: Started Login Service.
Feb  1 10:17:05 BedPi systemd[1]: Started triggerhappy global hotkey daemon.
Feb  1 10:17:05 BedPi avahi-daemon[350]: Found user 'avahi' (UID 108) and group 'avahi' (GID 112).
Feb  1 10:17:05 BedPi avahi-daemon[350]: Successfully dropped root privileges.
Feb  1 10:17:05 BedPi avahi-daemon[350]: avahi-daemon 0.6.32 starting up.
Feb  1 10:17:05 BedPi dhcpcd[345]: dev: loaded udev
Feb  1 10:17:05 BedPi systemd[1]: Started Avahi mDNS/DNS-SD Stack.
Feb  1 10:17:05 BedPi avahi-daemon[350]: Successfully called chroot().
Feb  1 10:17:05 BedPi avahi-daemon[350]: Successfully dropped remaining capabilities.
Feb  1 10:17:05 BedPi systemd[1]: Received SIGRTMIN+20 from PID 200 (plymouthd).
Feb  1 10:17:05 BedPi avahi-daemon[350]: No service file found in /etc/avahi/services.
Feb  1 10:17:05 BedPi systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
Feb  1 10:17:05 BedPi avahi-daemon[350]: Network interface enumeration completed.
Feb  1 10:17:05 BedPi avahi-daemon[350]: Server startup complete. Host name is BedPi.local. Local service cookie is 815300029.
Feb  1 10:17:05 BedPi kernel: [   11.754668] cfg80211: Loading compiled-in X.509 certificates for regulatory database
Feb  1 10:17:05 BedPi kernel: [   11.824439] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
Feb  1 10:17:05 BedPi dhcpcd[345]: forked to background, child pid 380
Feb  1 10:17:05 BedPi systemd[1]: Started dhcpcd on all interfaces.
Feb  1 10:17:05 BedPi systemd[1]: Started WPA supplicant.
Feb  1 10:17:05 BedPi wpa_supplicant[340]: Successfully initialized wpa_supplicant
Feb  1 10:17:06 BedPi dhcpcd[380]: eth0: waiting for carrier
Feb  1 10:17:06 BedPi dhcpcd[380]: eth0: carrier acquired
Feb  1 10:17:06 BedPi kernel: [   12.215850] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
Feb  1 10:17:06 BedPi dhcpcd[380]: eth0: carrier lost
Feb  1 10:17:07 BedPi kernel: [   13.835950] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xC1E1
Feb  1 10:17:07 BedPi dhcpcd[380]: eth0: carrier acquired
Feb  1 10:17:07 BedPi avahi-daemon[350]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::ba27:ebff:fe15:c030.
Feb  1 10:17:07 BedPi avahi-daemon[350]: New relevant interface eth0.IPv6 for mDNS.
Feb  1 10:17:07 BedPi avahi-daemon[350]: Registering new address record for fe80::ba27:ebff:fe15:c030 on eth0.*.
Feb  1 10:17:07 BedPi ifup[281]: ifup: unknown interface eth0
Feb  1 10:17:08 BedPi dhcpcd[380]: eth0: probing address 192.168.0.83/24
Feb  1 10:17:08 BedPi systemd[1]: networking.service: Main process exited, code=exited, status=1/FAILURE
Feb  1 10:17:08 BedPi systemd[1]: Failed to start Raise network interfaces.
Feb  1 10:17:08 BedPi systemd[1]: networking.service: Unit entered failed state.
Feb  1 10:17:08 BedPi systemd[1]: networking.service: Failed with result 'exit-code'.
Feb  1 10:17:08 BedPi systemd[1]: Reached target Network.
Feb  1 10:17:08 BedPi systemd[1]: Starting OpenBSD Secure Shell server...
Feb  1 10:17:08 BedPi systemd[1]: Starting OpenVPN service...
Feb  1 10:17:08 BedPi systemd[1]: Starting NFS Mount Daemon...
Feb  1 10:17:08 BedPi systemd[1]: Started VNC Server in Service Mode daemon.
Feb  1 10:17:08 BedPi systemd[1]: Starting Lighttpd Daemon...
Feb  1 10:17:08 BedPi systemd[1]: Reached target Network is Online.
Feb  1 10:17:08 BedPi systemd[1]: Starting /etc/rc.local Compatibility...
Feb  1 10:17:08 BedPi systemd[1]: Started OpenVPN service.
Feb  1 10:17:08 BedPi systemd[1]: Started /etc/rc.local Compatibility.
Feb  1 10:17:08 BedPi rpc.mountd[429]: Version 1.3.3 starting
Feb  1 10:17:08 BedPi systemd[1]: Started NFS Mount Daemon.
Feb  1 10:17:08 BedPi systemd[1]: Starting NFS server and services...
Feb  1 10:17:09 BedPi systemd[1]: Started OpenBSD Secure Shell server.
Feb  1 10:17:09 BedPi kernel: [   15.220815] NFSD: starting 90-second grace period (net f00004c1)
Feb  1 10:17:09 BedPi systemd[1]: Started NFS server and services.
Feb  1 10:17:09 BedPi systemd[1]: Reached target Remote File Systems (Pre).
Feb  1 10:17:09 BedPi systemd[1]: Reached target Remote File Systems.
Feb  1 10:17:09 BedPi systemd[1]: Starting LSB: pihole-FTL daemon...
Feb  1 10:17:09 BedPi systemd[1]: Starting LSB: Switch to ondemand cpu governor (unless shift key is pressed)...
Feb  1 10:17:09 BedPi systemd[1]: Starting Permit User Sessions...
Feb  1 10:17:09 BedPi systemd[1]: Started Permit User Sessions.
Feb  1 10:17:09 BedPi systemd[1]: Starting Hold until boot process finishes up...
Feb  1 10:17:09 BedPi systemd[1]: Starting Terminate Plymouth Boot Screen...
Feb  1 10:17:09 BedPi systemd[1]: Starting Light Display Manager...
Feb  1 10:17:09 BedPi systemd[1]: Received SIGRTMIN+21 from PID 200 (plymouthd).
Feb  1 10:17:09 BedPi pihole-FTL[449]: Not running
Feb  1 10:17:09 BedPi systemd[1]: Started Hold until boot process finishes up.
Feb  1 10:17:09 BedPi systemd[1]: Started Terminate Plymouth Boot Screen.
Feb  1 10:17:09 BedPi systemd[1]: Started Serial Getty on ttyAMA0.
Feb  1 10:17:09 BedPi systemd[1]: Started Getty on tty1.
Feb  1 10:17:09 BedPi systemd[1]: Reached target Login Prompts.
Feb  1 10:17:09 BedPi raspi-config[450]: Checking if shift key is held down:Error opening '/dev/input/event*': No such file or directory
Feb  1 10:17:09 BedPi raspi-config[450]:  No. Switching to ondemand scaling governor.
Feb  1 10:17:09 BedPi systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed).
Feb  1 10:17:09 BedPi lightdm[463]: Error getting user list from org.freedesktop.Accounts: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Accounts was not provided by any .service files
Feb  1 10:17:09 BedPi lighttpd[422]: 2021-02-01 10:17:08: (server.c.1295) WARNING: unknown config-key: alias.url (ignored)
Feb  1 10:17:09 BedPi systemd[1]: Started Lighttpd Daemon.
Feb  1 10:17:10 BedPi systemd[1]: Created slice User Slice of pihole.
Feb  1 10:17:10 BedPi systemd[1]: Starting User Manager for UID 999...
Feb  1 10:17:10 BedPi systemd[1]: Started Light Display Manager.
Feb  1 10:17:10 BedPi systemd[1]: Started Session c1 of user pihole.
Feb  1 10:17:10 BedPi systemd[507]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Feb  1 10:17:10 BedPi systemd[507]: Starting D-Bus User Message Bus Socket.
Feb  1 10:17:10 BedPi systemd[507]: Listening on GnuPG cryptographic agent and passphrase cache.
Feb  1 10:17:10 BedPi systemd[507]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Feb  1 10:17:10 BedPi systemd[507]: Reached target Paths.
Feb  1 10:17:10 BedPi systemd[507]: Reached target Timers.
Feb  1 10:17:10 BedPi systemd[507]: Listening on GnuPG cryptographic agent (access for web browsers).
Feb  1 10:17:10 BedPi systemd[507]: Listening on D-Bus User Message Bus Socket.
Feb  1 10:17:10 BedPi systemd[507]: Reached target Sockets.
Feb  1 10:17:10 BedPi systemd[507]: Reached target Basic System.
Feb  1 10:17:10 BedPi systemd[507]: Reached target Default.
Feb  1 10:17:10 BedPi systemd[507]: Startup finished in 322ms.
Feb  1 10:17:10 BedPi systemd[1]: Started User Manager for UID 999.
Feb  1 10:17:11 BedPi pihole-FTL[449]: FTL started!
Feb  1 10:17:11 BedPi systemd[1]: Started LSB: pihole-FTL daemon.
Feb  1 10:17:13 BedPi dhcpcd[380]: eth0: received approval for 192.168.0.83
Feb  1 10:17:13 BedPi dhcpcd[380]: eth0: adding route to 192.168.0.0/24
Feb  1 10:17:13 BedPi dhcpcd[380]: eth0: adding default route via 192.168.0.254
Feb  1 10:17:13 BedPi avahi-daemon[350]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.0.83.
Feb  1 10:17:13 BedPi avahi-daemon[350]: New relevant interface eth0.IPv4 for mDNS.
Feb  1 10:17:13 BedPi avahi-daemon[350]: Registering new address record for 192.168.0.83 on eth0.IPv4.
Feb  1 10:17:13 BedPi lightdm[597]: Error getting user list from org.freedesktop.Accounts: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Accounts was not provided by any .service files
Feb  1 10:17:14 BedPi systemd[1]: Created slice User Slice of pi.
Feb  1 10:17:14 BedPi systemd[1]: Starting User Manager for UID 1000...
Feb  1 10:17:14 BedPi systemd[1]: Started Session c2 of user pi.
Feb  1 10:17:14 BedPi systemd[606]: Starting D-Bus User Message Bus Socket.
Feb  1 10:17:14 BedPi systemd[606]: Reached target Timers.
Feb  1 10:17:14 BedPi systemd[606]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Feb  1 10:17:14 BedPi systemd[606]: Listening on GnuPG cryptographic agent (access for web browsers).
Feb  1 10:17:14 BedPi systemd[606]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Feb  1 10:17:14 BedPi systemd[606]: Reached target Paths.
Feb  1 10:17:14 BedPi systemd[606]: Listening on GnuPG cryptographic agent and passphrase cache.
Feb  1 10:17:14 BedPi systemd[606]: Listening on D-Bus User Message Bus Socket.
Feb  1 10:17:14 BedPi systemd[606]: Reached target Sockets.
Feb  1 10:17:14 BedPi systemd[606]: Reached target Basic System.
Feb  1 10:17:14 BedPi systemd[606]: Reached target Default.
Feb  1 10:17:14 BedPi systemd[606]: Startup finished in 186ms.
Feb  1 10:17:14 BedPi systemd[1]: Started User Manager for UID 1000.
Feb  1 10:17:14 BedPi lightdm[463]: Error opening audit socket: Protocol not supported
Feb  1 10:17:14 BedPi systemd[606]: Started D-Bus User Message Bus.
Feb  1 10:17:14 BedPi systemd[1]: Started Session c3 of user pi.
Feb  1 10:17:24 BedPi dbus-daemon[623]: Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service'
Feb  1 10:17:24 BedPi systemd[606]: Starting Virtual filesystem service...
Feb  1 10:17:24 BedPi dbus-daemon[623]: Successfully activated service 'org.gtk.vfs.Daemon'
Feb  1 10:17:24 BedPi systemd[606]: Started Virtual filesystem service.
Feb  1 10:17:24 BedPi kernel: [   30.976560] fuse init (API version 7.27)
Feb  1 10:17:25 BedPi systemd[1]: Mounting FUSE Control File System...
Feb  1 10:17:25 BedPi systemd[1]: Mounted FUSE Control File System.
Feb  1 10:17:25 BedPi dbus[320]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service'
Feb  1 10:17:25 BedPi systemd[1]: Starting Authorization Manager...
Feb  1 10:17:25 BedPi polkitd[757]: started daemon version 0.105 using authority implementation `local' version `0.105'
Feb  1 10:17:25 BedPi dbus[320]: [system] Successfully activated service 'org.freedesktop.PolicyKit1'
Feb  1 10:17:25 BedPi systemd[1]: Started Authorization Manager.
Feb  1 10:17:26 BedPi dbus-daemon[623]: Activating via systemd: service name='org.gtk.vfs.UDisks2VolumeMonitor' unit='gvfs-udisks2-volume-monitor.service'
Feb  1 10:17:26 BedPi systemd[606]: Starting Virtual filesystem service - disk device monitor...
Feb  1 10:17:26 BedPi dbus[320]: [system] Activating via systemd: service name='org.freedesktop.UDisks2' unit='udisks2.service'
Feb  1 10:17:26 BedPi systemd[1]: Starting Disk Manager...
Feb  1 10:17:26 BedPi udisksd[775]: udisks daemon version 2.1.8 starting
Feb  1 10:17:26 BedPi dbus[320]: [system] Successfully activated service 'org.freedesktop.UDisks2'
Feb  1 10:17:26 BedPi systemd[1]: Started Disk Manager.
Feb  1 10:17:26 BedPi udisksd[775]: Acquired the name org.freedesktop.UDisks2 on the system message bus
Feb  1 10:17:26 BedPi udisksd[775]: Cleaning up mount point /media/pi/06BB-C87D (device 8:1 is not mounted)
Feb  1 10:17:27 BedPi dbus-daemon[623]: Successfully activated service 'org.gtk.vfs.UDisks2VolumeMonitor'
Feb  1 10:17:27 BedPi systemd[606]: Started Virtual filesystem service - disk device monitor.
Feb  1 10:17:27 BedPi dbus-daemon[623]: Activating via systemd: service name='org.gtk.vfs.GoaVolumeMonitor' unit='gvfs-goa-volume-monitor.service'
Feb  1 10:17:27 BedPi systemd[606]: Starting Virtual filesystem service - GNOME Online Accounts monitor...
Feb  1 10:17:27 BedPi dbus-daemon[623]: Successfully activated service 'org.gtk.vfs.GoaVolumeMonitor'
Feb  1 10:17:27 BedPi systemd[606]: Started Virtual filesystem service - GNOME Online Accounts monitor.
Feb  1 10:17:27 BedPi dbus-daemon[623]: Activating via systemd: service name='org.gtk.vfs.MTPVolumeMonitor' unit='gvfs-mtp-volume-monitor.service'
Feb  1 10:17:27 BedPi systemd[606]: Starting Virtual filesystem service - Media Transfer Protocol monitor...
Feb  1 10:17:27 BedPi dbus-daemon[623]: Successfully activated service 'org.gtk.vfs.MTPVolumeMonitor'
Feb  1 10:17:27 BedPi systemd[606]: Started Virtual filesystem service - Media Transfer Protocol monitor.
Feb  1 10:17:27 BedPi dbus-daemon[623]: Activating via systemd: service name='org.gtk.vfs.GPhoto2VolumeMonitor' unit='gvfs-gphoto2-volume-monitor.service'
Feb  1 10:17:27 BedPi systemd[606]: Starting Virtual filesystem service - digital camera monitor...
Feb  1 10:17:27 BedPi dbus-daemon[623]: Successfully activated service 'org.gtk.vfs.GPhoto2VolumeMonitor'
Feb  1 10:17:27 BedPi systemd[606]: Started Virtual filesystem service - digital camera monitor.
Feb  1 10:17:27 BedPi dbus-daemon[623]: Activating via systemd: service name='org.gtk.vfs.AfcVolumeMonitor' unit='gvfs-afc-volume-monitor.service'
Feb  1 10:17:27 BedPi Node-RED[341]: 1 Feb 10:17:27 - [info]
Feb  1 10:17:27 BedPi Node-RED[341]: Welcome to Node-RED
Feb  1 10:17:27 BedPi Node-RED[341]: ===================
Feb  1 10:17:27 BedPi systemd[606]: Starting Virtual filesystem service - Apple File Conduit monitor...
Feb  1 10:17:27 BedPi Node-RED[341]: 1 Feb 10:17:27 - [info] Node-RED version: v1.2.6
Feb  1 10:17:27 BedPi Node-RED[341]: 1 Feb 10:17:27 - [info] Node.js  version: v8.17.0
Feb  1 10:17:27 BedPi Node-RED[341]: 1 Feb 10:17:27 - [info] Linux 4.19.66-v7+ arm LE
Feb  1 10:17:27 BedPi gvfs-afc-volume-monitor[813]: Volume monitor alive
Feb  1 10:17:27 BedPi dbus-daemon[623]: Successfully activated service 'org.gtk.vfs.AfcVolumeMonitor'
Feb  1 10:17:27 BedPi systemd[606]: Started Virtual filesystem service - Apple File Conduit monitor.
Feb  1 10:17:28 BedPi kernel: [   34.964045] FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
Feb  1 10:17:28 BedPi udisksd[775]: Mounted /dev/sda1 at /media/pi/06BB-C87D on behalf of uid 1000
Feb  1 10:17:29 BedPi systemd[1]: Started Certbot.
Feb  1 10:17:29 BedPi systemd[1]: certbot.timer: Adding 8h 37min 34.656962s random time.
Feb  1 10:17:29 BedPi systemd[1]: certbot.timer: Adding 7h 23min 16.477861s random time.
Feb  1 10:27:30 BedPi systemd[507]: Time has been changed
Feb  1 10:27:30 BedPi systemd[1]: Time has been changed
Feb  1 10:27:30 BedPi systemd[606]: Time has been changed
Feb  1 10:27:30 BedPi systemd-timesyncd[275]: Synchronized to time server 216.218.254.202:123 (2.debian.pool.ntp.org).
Feb  1 10:27:30 BedPi systemd[1]: certbot.timer: Adding 7h 38min 20.374165s random time.
Feb  1 10:27:30 BedPi systemd[1]: apt-daily.timer: Adding 2h 34min 55.878925s random time.
Feb  1 10:27:30 BedPi systemd[1]: apt-daily-upgrade.timer: Adding 46min 45.158730s random time.
15

We have been over this before I am sure. That is all after the reboot. The kernel messages with the time in square brackets show you how long it is since boot. The point at which the time changes to 10:27:30 is when the network came up and the clock synchronised. All the times before that from the reboot are not correct. You need to go back a fair way to before the reboot to find where it failed. You will see the times in brackets go down to zero as you go back then there will be a number of startup messages from before the kernel got going, then you should be into pre-boot.

16

Um,
That is 10:17.

The reboot (after the error) is/was 10:27.

So the problem happened around 10:17.
Or: Before 10:27.

As 10:17 is the latest time before the time line goes to 10:27, I am offering the latest stuff.

How can you say the times are incorrect? 10:17 is before 10:27 and ok, 10 minutes to boot is a bit extravagant for a RasPi. But if it totally locked up (which it did seem to do.....)

I'll have another look - but I am not quit getting what you are saying.

Ok, is this better?

Feb  1 09:09:36 BedPi systemd[1]: Starting Clean php session files...
Feb  1 09:09:36 BedPi systemd[1]: Started Clean php session files.
Feb  1 09:10:01 BedPi CRON[16807]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Feb  1 09:17:01 BedPi CRON[17154]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Feb  1 09:20:01 BedPi CRON[17310]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Feb  1 09:30:01 BedPi CRON[17799]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Feb  1 09:39:01 BedPi CRON[18252]: (root) CMD (  [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /usr/lib/php/sessionclean; fi)
Feb  1 09:39:36 BedPi systemd[1]: Starting Clean php session files...
Feb  1 09:39:36 BedPi systemd[1]: Started Clean php session files.
Feb  1 09:40:01 BedPi CRON[18348]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Feb  1 09:50:01 BedPi CRON[18835]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Feb  1 09:53:36 BedPi systemd[1]: Starting Daily apt download activities...
Feb  1 09:53:38 BedPi systemd[1]: Started Daily apt download activities.
Feb  1 09:53:38 BedPi systemd[1]: apt-daily.timer: Adding 5h 32min 13.447499s random time.
Feb  1 09:53:38 BedPi systemd[1]: apt-daily.timer: Adding 6h 15min 23.957947s random time.
Feb  1 10:00:01 BedPi CRON[19373]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Feb  1 10:09:01 BedPi CRON[19822]: (root) CMD (  [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /usr/lib/php/sessionclean; fi)
Feb  1 10:09:36 BedPi systemd[1]: Starting Clean php session files...
Feb  1 10:09:36 BedPi systemd[1]: Started Clean php session files.
Feb  1 10:10:01 BedPi CRON[19916]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
Feb  1 10:17:01 BedPi CRON[20275]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Feb  1 10:17:04 BedPi systemd-modules-load[100]: Inserted module 'i2c_dev'
Feb  1 10:17:04 BedPi kernel: [    0.000000] Booting Linux on physical CPU 0xf00
Feb  1 10:17:04 BedPi kernel: [    0.000000] Linux version 4.19.66-v7+ (dom@buildbot) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1253 SMP Thu Aug 15 11:49:46 BST 2019
Feb  1 10:17:04 BedPi kernel: [    0.000000] CPU: ARMv7 Processor [410fc075] revision 5 (ARMv7), cr=10c5387d
Feb  1 10:17:04 BedPi kernel: [    0.000000] CPU: div instructions available: patching division code
Feb  1 10:17:04 BedPi kernel: [    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
Feb  1 10:17:04 BedPi fake-hwclock[109]: Sun 31 Jan 23:17:01 UTC 2021
Feb  1 10:17:04 BedPi kernel: [    0.000000] OF: fdt: Machine model: Raspberry Pi 2 Model B Rev 1.1
Feb  1 10:17:04 BedPi kernel: [    0.000000] Memory policy: Data cache writealloc
Feb  1 10:17:04 BedPi kernel: [    0.000000] cma: Reserved 8 MiB at 0x3ac00000
Feb  1 10:17:04 BedPi systemd[1]: Started Restore / save the current clock.
Feb  1 10:17:04 BedPi kernel: [    0.000000] On node 0 totalpages: 242688
Feb  1 10:17:04 BedPi kernel: [    0.000000]   Normal zone: 2133 pages used for memmap
Feb  1 10:17:04 BedPi kernel: [    0.000000]   Normal zone: 0 pages reserved
Feb  1 10:17:04 BedPi kernel: [    0.000000]   Normal zone: 242688 pages, LIFO batch:63
Feb  1 10:17:04 BedPi kernel: [    0.000000] random: get_random_bytes called from start_kernel+0xac/0x4b4 with crng_init=0
Feb  1 10:17:04 BedPi systemd[1]: Mounted Configuration File System.
Feb  1 10:17:04 BedPi systemd[1]: Started Apply Kernel Variables.
Feb  1 10:17:04 BedPi systemd[1]: Time has been changed
Feb  1 10:17:04 BedPi kernel: [    0.000000] percpu: Embedded 17 pages/cpu s39488 r8192 d21952 u69632
Feb  1 10:17:04 BedPi kernel: [    0.000000] pcpu-alloc: s39488 r8192 d21952 u69632 alloc=17*4096
Feb  1 10:17:04 BedPi blkmapd[141]: open pipe file /run/rpc_pipefs/nfs/blocklayout failed: No such file or directory
Feb  1 10:17:04 BedPi kernel: [    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
Feb  1 10:17:04 BedPi kernel: [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 240555
Feb  1 10:17:04 BedPi kernel: [    0.000000] Kernel command line: coherent_pool=1M bcm2708_fb.fbwidth=1280 bcm2708_fb.fbheight=768 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  dwc_otg.lpm_enable=0 console=ttyAMA0,115200 console=tty1 root=PARTUUID=b677eeab-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait quiet splash plymouth.ignore-serial-consoles
Feb  1 10:17:04 BedPi kernel: [    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
Feb  1 10:17:04 BedPi systemd[1]: Starting File System Check on Root Device...
Feb  1 10:17:04 BedPi kernel: [    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
Feb  1 10:17:04 BedPi kernel: [    0.000000] Memory: 939092K/970752K available (8192K kernel code, 629K rwdata, 2176K rodata, 1024K init, 821K bss, 23468K reserved, 8192K cma-reserved)
Feb  1 10:17:04 BedPi kernel: [    0.000000] Virtual kernel memory layout:
Feb  1 10:17:04 BedPi systemd[1]: Started pNFS block layout mapping daemon.
Feb  1 10:17:04 BedPi kernel: [    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
Feb  1 10:17:04 BedPi kernel: [    0.000000]     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
Feb  1 10:17:04 BedPi kernel: [    0.000000]     vmalloc : 0xbb800000 - 0xff800000   (1088 MB)
Feb  1 10:17:04 BedPi kernel: [    0.000000]     lowmem  : 0x80000000 - 0xbb400000   ( 948 MB)
Feb  1 10:17:04 BedPi systemd[1]: Started File System Check Daemon to report status.
Feb  1 10:17:04 BedPi kernel: [    0.000000]     modules : 0x7f000000 - 0x80000000   (  16 MB)
Feb  1 10:17:04 BedPi kernel: [    0.000000]       .text : 0x(ptrval) - 0x(ptrval)   (9184 kB)
Feb  1 10:17:04 BedPi kernel: [    0.000000]       .init : 0x(ptrval) - 0x(ptrval)   (1024 kB)
Feb  1 10:17:04 BedPi systemd[1]: Started Create Static Device Nodes in /dev.
Feb  1 10:17:04 BedPi kernel: [    0.000000]       .data : 0x(ptrval) - 0x(ptrval)   ( 630 kB)
Feb  1 10:17:04 BedPi kernel: [    0.000000]        .bss : 0x(ptrval) - 0x(ptrval)   ( 822 kB)
Feb  1 10:17:04 BedPi kernel: [    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
Feb  1 10:17:04 BedPi kernel: [    0.000000] ftrace: allocating 26394 entries in 78 pages
Feb  1 10:17:04 BedPi kernel: [    0.000000] rcu: Hierarchical RCU implementation.
Feb  1 10:17:04 BedPi systemd[1]: Starting udev Kernel Device Manager...
Feb  1 10:17:04 BedPi kernel: [    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
Feb  1 10:17:04 BedPi kernel: [    0.000000] arch_timer: cp15 timer(s) running at 19.20MHz (phys).
Feb  1 10:17:04 BedPi kernel: [    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
Feb  1 10:17:04 BedPi systemd-fsck[142]: e2fsck 1.43.4 (31-Jan-2017)
Feb  1 10:17:04 BedPi kernel: [    0.000010] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
Feb  1 10:17:04 BedPi kernel: [    0.000024] Switching to timer-based delay loop, resolution 52ns
Feb  1 10:17:04 BedPi kernel: [    0.000351] Console: colour dummy device 80x30
Feb  1 10:17:04 BedPi kernel: [    0.000375] console [tty1] enabled
Feb  1 10:17:04 BedPi kernel: [    0.000436] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
Feb  1 10:17:04 BedPi kernel: [    0.000455] pid_max: default: 32768 minimum: 301
Feb  1 10:17:04 BedPi systemd-fsck[142]: /dev/mmcblk0p2: clean, 188287/3710784 files, 1535802/15120896 blocks
Feb  1 10:17:04 BedPi kernel: [    0.000889] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
Feb  1 10:17:04 BedPi kernel: [    0.000913] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
Feb  1 10:17:04 BedPi kernel: [    0.002157] CPU: Testing write buffer coherency: ok
Feb  1 10:17:04 BedPi kernel: [    0.002843] CPU0: update cpu_capacity 1024
Feb  1 10:17:04 BedPi systemd[1]: Started File System Check on Root Device.
Feb  1 10:17:04 BedPi kernel: [    0.002857] CPU0: thread -1, cpu 0, socket 15, mpidr 80000f00
Feb  1 10:17:04 BedPi kernel: [    0.003866] Setting up static identity map for 0x100000 - 0x10003c
Feb  1 10:17:04 BedPi kernel: [    0.004099] rcu: Hierarchical SRCU implementation.
Feb  1 10:17:04 BedPi kernel: [    0.005282] smp: Bringing up secondary CPUs ...
Feb  1 10:17:04 BedPi kernel: [    0.006577] CPU1: update cpu_capacity 1024
Feb  1 10:17:04 BedPi systemd[1]: Starting Remount Root and Kernel File Systems...
Feb  1 10:17:04 BedPi kernel: [    0.006591] CPU1: thread -1, cpu 1, socket 15, mpidr 80000f01
Feb  1 10:17:04 BedPi kernel: [    0.008025] CPU2: update cpu_capacity 1024
Feb  1 10:17:04 BedPi systemd[1]: Started udev Kernel Device Manager.
Feb  1 10:17:04 BedPi kernel: [    0.008036] CPU2: thread -1, cpu 2, socket 15, mpidr 80000f02
Feb  1 10:17:04 BedPi kernel: [    0.009366] CPU3: update cpu_capacity 1024
Feb  1 10:17:04 BedPi kernel: [    0.009378] CPU3: thread -1, cpu 3, socket 15, mpidr 80000f03
Feb  1 10:17:04 BedPi kernel: [    0.009549] smp: Brought up 1 node, 4 CPUs
17

To explain that first.

There is a message timestamped 10:17:29 about certbot. The next message says "Time has been changed" and it is timestamped 10:27:30" and a couple of messages later it explains why the time has been changed, as it synchronised via the internet. There is no significant real time gap between the the 10:17 and 10:27 messages, it is just that the clock was changed.

Looking at the start of the boot I don't see the shutdown log there, but looking back at your comments I see that is because the machine had completely crashed.

So to summarize, your error log show an error associated apparently with ping. Almost immediately thereafter the machine crashed completely with no clue in the log as to what happened. The most obvious conclusion is that you have a hardware problem of some sort, possibly PSU related, but could be SD card or something else. Nothing that node-red can do will cause a complete system crash without anything in the log.

[Edit] The reason your error does not appear in the log before the boot will be because the disc I/O is buffered by the OS. The error will have been written to the log but then the processor stopped before it got round to writing it to the card.

1 Like
18

Well, if the machine did 100% lock up - which I suspected - then I agree there won't be much to see in the log.

Ok.

I shall have to try other things to find out what is happening and why.

The machine is a RasPi 3B is fairly new in the scheme of things and is only ticking over at less than 10% CPU load most of the time.

19

YOu should setup a central Syslog server so that all of these machines write their log files to a central machine that has reliable storage - then as long as all of their times are synched to the Net it will be much easier to troubleshoot these types of issues in the future

Craig

1 Like
20

Good idea.

I'll put that on the list of things to do.