Node red stops right after reboot and node-red "auto-start"

henkkas · 23 December 2022 10:57

I am trying to make a clean install of node red on a raspberry pi 3B+.
Almost looks to turn out very well. Only I have a weird behavior.

When I reboot the device. Then directly after node red has started it stops. When I restart node red again, everything seems well. I only have some minor flows on my project, incl. a serial node.

The startup after boot looks like this:

~ $ node-red-log


23 Dec 11:42:45 - [info] Loading palette nodes
23 Dec 11:42:49 - [info] Dashboard version 3.2.3 started at /ui
23 Dec 11:42:50 - [info] Settings file  : /home/pi/.node-red/settings.js
23 Dec 11:42:50 - [info] Context store  : 'default' [module=localfilesystem]
23 Dec 11:42:50 - [info] User directory : /home/pi/.node-red
23 Dec 11:42:50 - [warn] Projects disabled : editorTheme.projects.enabled=false
23 Dec 11:42:50 - [info] Flows file     : /home/pi/.node-red/flows.json
23 Dec 11:42:50 - [warn] Using unencrypted credentials
23 Dec 11:42:50 - [info] Server now running at http://127.0.0.1:18181/
23 Dec 11:42:50 - [info] Starting flows
23 Dec 11:42:50 - [info] Started flows
23 Dec 11:42:50 - [info] [serialconfig:05bfa2b9058c9fb6] serial port /dev/ttyUSB0 opened at 115200 baud 8N1
      pi : PWD=/home/pi ; USER=root ; COMMAND=/usr/bin/smem -c pss -P node-red -k -t
pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
pam_unix(sudo:session): session closed for user root
      pi : PWD=/home/pi ; USER=root ; COMMAND=/usr/bin/smem -c pss -P influx -k -t
pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
pam_unix(sudo:session): session closed for user root
Stopping Node-RED graphical event wiring tool...
23 Dec 11:53:28 - [info] Stopping flows
23 Dec 11:53:28 - [info] serial port /dev/ttyUSB0 closed
23 Dec 11:53:28 - [info] Stopped flows
nodered.service: Succeeded.
Stopped Node-RED graphical event wiring tool.
nodered.service: Consumed 1min 25.100s CPU time.

after I start node red again, everything looks well, and the log looks like this:

Starting as a systemd service.
23 Dec 11:59:34 - [info]
Welcome to Node-RED
===================
23 Dec 11:59:34 - [info] Node-RED version: v3.0.2
23 Dec 11:59:34 - [info] Node.js  version: v16.19.0
23 Dec 11:59:34 - [info] Linux 5.15.76-v7+ arm LE
23 Dec 11:59:36 - [info] Loading palette nodes
23 Dec 11:59:41 - [info] Dashboard version 3.2.3 started at /ui
23 Dec 11:59:41 - [info] Settings file  : /home/pi/.node-red/settings.js
23 Dec 11:59:42 - [info] Context store  : 'default' [module=localfilesystem]
23 Dec 11:59:42 - [info] User directory : /home/pi/.node-red
23 Dec 11:59:42 - [warn] Projects disabled : editorTheme.projects.enabled=false
23 Dec 11:59:42 - [info] Flows file     : /home/pi/.node-red/flows.json
23 Dec 11:59:42 - [warn] Using unencrypted credentials
23 Dec 11:59:42 - [info] Server now running at http://127.0.0.1:18181/
23 Dec 11:59:42 - [info] Starting flows
23 Dec 11:59:42 - [info] Started flows
23 Dec 11:59:42 - [info] [serialconfig:05bfa2b9058c9fb6] serial port /dev/ttyUSB0 opened at 115200 baud 8N1
      pi : PWD=/home/pi ; USER=root ; COMMAND=/usr/bin/smem -c pss -P node-red -k -t
pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
pam_unix(sudo:session): session closed for user root
      pi : PWD=/home/pi ; USER=root ; COMMAND=/usr/bin/smem -c pss -P influx -k -t
pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
pam_unix(sudo:session): session closed for user root

Anybody has any idea, what causes this?

ghayne · 23 December 2022 11:04

How did you install node-red?

dceejay · 23 December 2022 11:19

looks like at some point you have used sudo by mistake.

henkkas · 23 December 2022 11:21

@ghayne

First:

sudo apt install build-essential git

then

bash <(curl -sL https://raw.githubusercontent.com/node-red/linux-installers/master/deb/update-nodejs-and-nodered)

and then

sudo systemctl enable nodered.service

henkkas · 23 December 2022 12:02

@dceejay Yes I see that. I don't know how that happened.

But if I look in my running project, I see the same thing. But that project is running fine, without any problems.

Colin · 23 December 2022 22:08

Do you have any logic in your flows that intentionally stops or restarts node-red? It appears to be being stopped rather than failing. If it failed then it would auto-restart.

Do you mean that when it automatically starts on boot that it stops again 11 minutes later, but if you then restart it again it runs indefinitely? Is the 11 minutes consistent?

Have a look in /var/log/syslog at around 11:53 to see if there are any clues as to what stopped node-red.

henkkas · 24 December 2022 06:51

@Colin I

No

No, I don't have. Not intentionally, at least.

Yes, to your first sentence. The second I am not sure.

Hereby part of my syslog, I don't see anything that I can connect with the stopping of Node red,

ec 24 07:33:05 EBS10 bthelper[1064]: Changing power off succeeded
Dec 24 07:33:05 EBS10 bthelper[1064]: [#001#033[0;93m#002CHG#001#033[0m#002] Controller B8:27:EB:DD:80:46 Powered: no
Dec 24 07:33:05 EBS10 bthelper[1064]: [#001#033[0;93m#002CHG#001#033[0m#002] Controller B8:27:EB:DD:80:46 Discovering: no
Dec 24 07:33:05 EBS10 bthelper[1064]: [#001#033[0;93m#002CHG#001#033[0m#002] Controller B8:27:EB:DD:80:46 Class: 0x00000000
Dec 24 07:33:05 EBS10 bthelper[818]: [#001#033[0;93m#002CHG#001#033[0m#002] Controller B8:27:EB:DD:80:46 Class: 0x002c0000
Dec 24 07:33:05 EBS10 bthelper[818]: Changing power on succeeded
Dec 24 07:33:06 EBS10 dbus-daemon[334]: [system] Activating via systemd: service name='org.freedesktop.PackageKit' unit='packagekit.service' requested by ':1.36' (uid=1000 pid=881 comm="lxpanel --profile LXDE-pi ")
Dec 24 07:33:06 EBS10 systemd[1]: Starting PackageKit Daemon...
Dec 24 07:33:06 EBS10 PackageKit: daemon start
Dec 24 07:33:06 EBS10 dhcpcd[436]: eth0: DHCPv6 REPLY: No Addresses Available
Dec 24 07:33:06 EBS10 dbus-daemon[334]: [system] Successfully activated service 'org.freedesktop.PackageKit'
Dec 24 07:33:06 EBS10 systemd[1]: Started PackageKit Daemon.
Dec 24 07:33:08 EBS10 vncserver-x11[545,root]: Connections: connected: 192.168.0.190::1961 (TCP)
Dec 24 07:33:08 EBS10 vncserver-x11[545,root]: Connections: authenticated: 192.168.0.190::1961 (TCP), as pi (d permissions)
Dec 24 07:33:08 EBS10 dbus-daemon[334]: [system] Activating via systemd: service name='org.freedesktop.ColorManager' unit='colord.service' requested by ':1.10' (uid=0 pid=475 comm="/usr/sbin/cupsd -l ")
Dec 24 07:33:08 EBS10 systemd[1]: Starting Manage, Install and Generate Color Profiles...
Dec 24 07:33:08 EBS10 dbus-daemon[334]: [system] Successfully activated service 'org.freedesktop.ColorManager'
Dec 24 07:33:08 EBS10 systemd[1]: Started Manage, Install and Generate Color Profiles.
Dec 24 07:33:11 EBS10 packagekitd[1167]: https://repos.influxddata.com/debian bullseye InRelease is not (yet) available (Could not resolve 'repos.influxddata.com')
Dec 24 07:33:11 EBS10 PackageKit: refresh-cache transaction /19_aaedaaee from uid 1000 finished with failed after 4322ms
Dec 24 07:33:12 EBS10 kernel: [   33.130160] cam-dummy-reg: disabling
Dec 24 07:33:15 EBS10 dbus-daemon[645]: [session uid=1000 pid=645] Activating via systemd: service name='org.gtk.vfs.Metadata' unit='gvfs-metadata.service' requested by ':1.10' (uid=1000 pid=882 comm="pcmanfm --desktop --profile LXDE-pi ")
Dec 24 07:33:15 EBS10 systemd[616]: Starting Virtual filesystem metadata service...
Dec 24 07:33:15 EBS10 dbus-daemon[645]: [session uid=1000 pid=645] Successfully activated service 'org.gtk.vfs.Metadata'
Dec 24 07:33:15 EBS10 systemd[616]: Started Virtual filesystem metadata service.
Dec 24 07:33:18 EBS10 systemd[1]: systemd-fsckd.service: Succeeded.
Dec 24 07:33:31 EBS10 systemd-timesyncd[282]: Initial synchronization to time server 195.13.1.153:123 (2.debian.pool.ntp.org).
Dec 24 07:33:33 EBS10 dhcpcd[436]: eth0: DHCPv6 REPLY: No Addresses Available
Dec 24 07:33:42 EBS10 systemd[1]: systemd-hostnamed.service: Succeeded.
Dec 24 07:34:04 EBS10 dhcpcd[436]: eth0: DHCPv6 REPLY: No Addresses Available
Dec 24 07:35:06 EBS10 dhcpcd[436]: eth0: DHCPv6 REPLY: No Addresses Available
Dec 24 07:36:58 EBS10 dhcpcd[436]: eth0: Router Advertisement from fe80::de2c:6eff:fea9:d576
Dec 24 07:37:05 EBS10 dhcpcd[436]: eth0: DHCPv6 REPLY: No Addresses Available

Colin · 24 December 2022 07:12

The restart was at 11:53, so I am not sure why you have posted that section of syslog.

henkkas · 24 December 2022 07:32

@Colin That was yesterday. I rebooted just an hour ago again. To see the same behavior.

See the node-log here. The syslog is too big to show here.

 sudo reboot
login as: pi
pi@192.168.0.41's password:
Linux EBS10 5.15.76-v7+ #1597 SMP Fri Nov 4 12:13:17 GMT 2022 armv7l

The programs included with the Debian GNU/Linux system are free software;
the exact distribution terms for each program are described in the
individual files in /usr/share/doc/*/copyright.

Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
Last login: Sat Dec 24 09:04:12 2022

Wi-Fi is currently blocked by rfkill.
Use raspi-config to set the country before use.

pi@EBS10:~ $ node-red-log


24 Dec 08:03:48 - [info]
Welcome to Node-RED
===================
24 Dec 08:03:48 - [info] Node-RED version: v3.0.2
24 Dec 08:03:48 - [info] Node.js  version: v16.19.0
24 Dec 08:03:48 - [info] Linux 5.15.76-v7+ arm LE
24 Dec 08:03:50 - [info] Loading palette nodes
24 Dec 08:03:55 - [info] Dashboard version 3.2.3 started at /ui
24 Dec 08:03:55 - [info] Settings file  : /home/pi/.node-red/settings.js
24 Dec 08:03:55 - [info] Context store  : 'default' [module=localfilesystem]
24 Dec 08:03:55 - [info] User directory : /home/pi/.node-red
24 Dec 08:03:55 - [warn] Projects disabled : editorTheme.projects.enabled=false
24 Dec 08:03:55 - [info] Flows file     : /home/pi/.node-red/flows.json
24 Dec 08:03:55 - [warn] Using unencrypted credentials
24 Dec 08:03:56 - [info] Server now running at http://127.0.0.1:18181/
24 Dec 08:03:56 - [info] Starting flows
24 Dec 08:03:56 - [info] Started flows
24 Dec 08:03:56 - [info] [serialconfig:05bfa2b9058c9fb6] serial port /dev/ttyUSB  0 opened at 115200 baud 8N1
24 Dec 09:04:00 - [info] Stopping flows
Stopping Node-RED graphical event wiring tool...
24 Dec 09:04:00 - [info] serial port /dev/ttyUSB0 closed
24 Dec 09:04:00 - [info] Stopped flows
nodered.service: Succeeded.
Stopped Node-RED graphical event wiring tool.
nodered.service: Consumed 7min 18.120s CPU time.
^C
pi@EBS10:~ $ node-red-stop
Stop Node-RED

Use   node-red-start   to start Node-RED again

pi@EBS10:~ $ node-red-start

Start Node-RED

Once Node-RED has started, point a browser at http://192.168.0.41:1880
On Pi Node-RED works better with the Firefox or Chrome browser

Use   node-red-stop                          to stop Node-RED
Use   node-red-start                         to start Node-RED again
Use   node-red-log                           to view the recent log output
Use   sudo systemctl enable nodered.service  to autostart Node-RED at every boot
Use   sudo systemctl disable nodered.service to disable autostart on boot

To find more nodes and example flows - go to http://flows.nodered.org

Starting as a systemd service.
24 Dec 09:05:33 - [info]
Welcome to Node-RED
===================
24 Dec 09:05:33 - [info] Node-RED version: v3.0.2
24 Dec 09:05:33 - [info] Node.js  version: v16.19.0
24 Dec 09:05:33 - [info] Linux 5.15.76-v7+ arm LE
24 Dec 09:05:36 - [info] Loading palette nodes
24 Dec 09:05:40 - [info] Dashboard version 3.2.3 started at /ui
24 Dec 09:05:41 - [info] Settings file  : /home/pi/.node-red/settings.js
24 Dec 09:05:41 - [info] Context store  : 'default' [module=localfilesystem]
24 Dec 09:05:41 - [info] User directory : /home/pi/.node-red
24 Dec 09:05:41 - [warn] Projects disabled : editorTheme.projects.enabled=false
24 Dec 09:05:41 - [info] Flows file     : /home/pi/.node-red/flows.json
24 Dec 09:05:41 - [warn] Using unencrypted credentials
24 Dec 09:05:41 - [info] Server now running at http://127.0.0.1:18181/
24 Dec 09:05:41 - [info] Starting flows
24 Dec 09:05:41 - [info] Started flows
24 Dec 09:05:42 - [info] [serialconfig:05bfa2b9058c9fb6] serial port /dev/ttyUSB  0 opened at 115200 baud 8N1

Colin · 24 December 2022 09:03

We don't need the whole of syslog. Just the part around 09:04. You should see that same Stopping flows message, the interesting bit is what happened in the few tens of seconds before that.

henkkas · 24 December 2022 10:37

@Colin There is no mention of stopping flows.
At

That minute I have over 800 entries in the syslog. I show you the first part here.

Dec 24 09:03:56 EBS10 influxd[477]: [httpd] 127.0.0.1 - root [24/Dec/2022:09:03:56 +0100] "POST /write?db=EBS_ST&p=%5BREDACTED%5D&precision=s&rp=&u=root HTTP/1.1" 204 0 "-" "-" 83fb5bcb-8361-11ed-838a-000000000000 19647
Dec 24 09:04:00 EBS10 systemd[1]: Stopping Session 1 of user pi.
Dec 24 09:04:00 EBS10 systemd[1]: Stopping Session 3 of user pi.
Dec 24 09:04:00 EBS10 systemd[1]: Stopping Session 4 of user pi.
Dec 24 09:04:00 EBS10 systemd[1]: Removed slice system-modprobe.slice.
Dec 24 09:04:00 EBS10 systemd[1]: Stopped target Bluetooth.
Dec 24 09:04:00 EBS10 systemd[1]: Stopped target Graphical Interface.
Dec 24 09:04:00 EBS10 systemd[1]: Stopped target Multi-User System.
Dec 24 09:04:00 EBS10 systemd[1]: Stopped target Login Prompts.
Dec 24 09:04:00 EBS10 systemd[1]: Stopped target Sound Card.
Dec 24 09:04:00 EBS10 systemd[1]: Stopped target Timers.
Dec 24 09:04:00 EBS10 systemd[1]: apt-daily-upgrade.timer: Succeeded.
Dec 24 09:04:00 EBS10 systemd[1]: Stopped Daily apt upgrade and clean activities.
Dec 24 09:04:00 EBS10 systemd[1]: apt-daily.timer: Succeeded.
Dec 24 09:04:00 EBS10 systemd[1]: Stopped Daily apt download activities.
Dec 24 09:04:00 EBS10 systemd[1]: e2scrub_all.timer: Succeeded.
Dec 24 09:04:00 EBS10 systemd[1]: Stopped Periodic ext4 Online Metadata Check for All Filesystems.
Dec 24 09:04:00 EBS10 systemd[1]: fstrim.timer: Succeeded.
Dec 24 09:04:00 EBS10 systemd[1]: Stopped Discard unused blocks once a week.
Dec 24 09:04:00 EBS10 systemd[1]: logrotate.timer: Succeeded.
Dec 24 09:04:00 EBS10 systemd[1]: Stopped Daily rotation of log files.
Dec 24 09:04:00 EBS10 systemd[1]: man-db.timer: Succeeded.
Dec 24 09:04:00 EBS10 systemd[1]: Stopped Daily man-db regeneration.
Dec 24 09:04:00 EBS10 systemd[1]: systemd-tmpfiles-clean.timer: Succeeded.
Dec 24 09:04:00 EBS10 systemd[1]: Stopped Daily Cleanup of Temporary Directories.
Dec 24 09:04:00 EBS10 systemd[1]: Stopped target System Time Synchronized.
Dec 24 09:04:00 EBS10 systemd[1]: Stopped target System Time Set.
Dec 24 09:04:00 EBS10 systemd[1]: systemd-rfkill.socket: Succeeded.
Dec 24 09:04:00 EBS10 systemd[1]: Closed Load/Save RF Kill Switch Status /dev/rfkill Watch.
Dec 24 09:04:00 EBS10 systemd[1]: Unmounting RPC Pipe File System...
Dec 24 09:04:00 EBS10 ModemManager[475]: <info>  caught signal, shutting down...
Dec 24 09:04:00 EBS10 systemd[1]: Stopping Modem Manager...
Dec 24 09:04:00 EBS10 bluetoothd[758]: Terminating
Dec 24 09:04:00 EBS10 systemd[1]: Stopping Save/Restore Sound Card State...
Dec 24 09:04:00 EBS10 bluetoothd[758]: Endpoint unregistered: sender=:1.26 path=/MediaEndpoint/A2DPSink/sbc
Dec 24 09:04:00 EBS10 systemd[1]: Stopping Bluetooth service...
Dec 24 09:04:00 EBS10 bluetoothd[758]: Endpoint unregistered: sender=:1.26 path=/MediaEndpoint/A2DPSource/sbc
Dec 24 09:04:00 EBS10 influxd[477]: ts=2022-12-24T08:04:00.147119Z lvl=info msg="Signal received, initializing clean shutdown..." log_id=0exjX8Rl000
Dec 24 09:04:00 EBS10 influxd[477]: ts=2022-12-24T08:04:00.147241Z lvl=info msg="Waiting for clean shutdown..." log_id=0exjX8Rl000
Dec 24 09:04:00 EBS10 influxd[477]: ts=2022-12-24T08:04:00.147551Z lvl=info msg="Shutting down monitor service" log_id=0exjX8Rl000 service=monitor
Dec 24 09:04:00 EBS10 influxd[477]: ts=2022-12-24T08:04:00.147732Z lvl=info msg="Terminating storage of statistics" log_id=0exjX8Rl000 service=monitor
Dec 24 09:04:00 EBS10 influxd[477]: ts=2022-12-24T08:04:00.147802Z lvl=info msg="Terminating precreation service" log_id=0exjX8Rl000 service=shard-precreation
Dec 24 09:04:00 EBS10 influxd[477]: ts=2022-12-24T08:04:00.147589Z lvl=info msg="Listener closed" log_id=0exjX8Rl000 service=snapshot
Dec 24 09:04:00 EBS10 influxd[477]: ts=2022-12-24T08:04:00.147887Z lvl=info msg="Terminating continuous query service" log_id=0exjX8Rl000 service=continuous_querier
Dec 24 09:04:00 EBS10 influxd[477]: ts=2022-12-24T08:04:00.148120Z lvl=info msg="Closing retention policy enforcement service" log_id=0exjX8Rl000 service=retention
Dec 24 09:04:00 EBS10 systemd[1]: Stopping Manage, Install and Generate Color Profiles...
Dec 24 09:04:00 EBS10 pulseaudio[690]: X connection to :0 broken (explicit kill or server shutdown).
Dec 24 09:04:00 EBS10 influxd[477]: ts=2022-12-24T08:04:00.150172Z lvl=info msg="Closed service" log_id=0exjX8Rl000 service=subscriber
Dec 24 09:04:00 EBS10 influxd[477]: ts=2022-12-24T08:04:00.159146Z lvl=info msg="Server shutdown completed" log_id=0exjX8Rl000
Dec 24 09:04:00 EBS10 vncserver-x11-serviced[591]: X connection to :0 broken (explicit kill or server shutdown).
Dec 24 09:04:00 EBS10 systemd[1]: Stopping Regular background program processing daemon...
Dec 24 09:04:00 EBS10 systemd[1]: Stopping Make remote CUPS printers available locally...
Dec 24 09:04:05 EBS10 systemd-modules-load[131]: Failed to find module 'lp'
Dec 24 09:04:05 EBS10 systemd-modules-load[131]: Failed to find module 'ppdev'
Dec 24 09:04:05 EBS10 systemd-modules-load[131]: Failed to find module 'parport_pc'
Dec 24 09:04:05 EBS10 systemd-modules-load[131]: Inserted module 'i2c_dev'
Dec 24 09:04:05 EBS10 systemd-sysctl[147]: Couldn't write '1' to 'kernel/unprivileged_userns_clone', ignoring: No such file or directory
Dec 24 09:04:05 EBS10 fake-hwclock[134]: Sat 24 Dec 08:04:01 UTC 2022
Dec 24 09:04:05 EBS10 systemd-fsck[148]: e2fsck 1.46.2 (28-Feb-2021)
Dec 24 09:04:05 EBS10 systemd-fsck[148]: rootfs: clean, 145151/1918208 files, 1224153/7725184 blocks
Dec 24 09:04:05 EBS10 systemd[1]: Finished Remount Root and Kernel File Systems.
Dec 24 09:04:05 EBS10 systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
Dec 24 09:04:05 EBS10 systemd[1]: Starting Flush Journal to Persistent Storage...
Dec 24 09:04:05 EBS10 systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped.
Dec 24 09:04:05 EBS10 systemd[1]: Starting Load/Save Random Seed...
Dec 24 09:04:05 EBS10 systemd[1]: Starting Create System Users...
Dec 24 09:04:05 EBS10 systemd[1]: Finished Coldplug All udev Devices.
Dec 24 09:04:05 EBS10 systemd[1]: Starting Helper to synchronize boot up for ifupdown...
Dec 24 09:04:05 EBS10 systemd[1]: Finished Helper to synchronize boot up for ifupdown.
Dec 24 09:04:05 EBS10 systemd[1]: Finished Create System Users.
Dec 24 09:04:05 EBS10 systemd[1]: Starting Create Static Device Nodes in /dev...
Dec 24 09:04:05 EBS10 systemd[1]: Finished Load/Save Random Seed.
Dec 24 09:04:05 EBS10 systemd[1]: Condition check resulted in First Boot Complete being skipped.
Dec 24 09:04:05 EBS10 systemd[1]: Finished Set the console keyboard layout.
Dec 24 09:04:05 EBS10 systemd[1]: Finished Create Static Device Nodes in /dev.
Dec 24 09:04:05 EBS10 systemd[1]: Reached target Local File Systems (Pre).
Dec 24 09:04:05 EBS10 systemd[1]: Starting Rule-based Manager for Device Events and Files...
Dec 24 09:04:05 EBS10 systemd[1]: Finished Flush Journal to Persistent Storage.
Dec 24 09:04:05 EBS10 systemd[1]: Started Rule-based Manager for Device Events and Files.
Dec 24 09:04:05 EBS10 systemd[1]: Starting Show Plymouth Boot Screen...
Dec 24 09:04:05 EBS10 systemd[1]: Received SIGRTMIN+20 from PID 173 (plymouthd).
Dec 24 09:04:05 EBS10 systemd[1]: Started Show Plymouth Boot Screen.
Dec 24 09:04:05 EBS10 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped.
Dec 24 09:04:05 EBS10 systemd[1]: Started Forward Password Requests to Plymouth Directory Watch.
Dec 24 09:04:05 EBS10 systemd[1]: Reached target Local Encrypted Volumes.
Dec 24 09:04:05 EBS10 systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped.
Dec 24 09:04:05 EBS10 systemd[1]: Condition check resulted in Huge Pages File System being skipped.
Dec 24 09:04:05 EBS10 systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
Dec 24 09:04:05 EBS10 systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
Dec 24 09:04:05 EBS10 systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped.
Dec 24 09:04:05 EBS10 systemd[1]: Found device /dev/disk/by-partuuid/b55a00c3-01.
Dec 24 09:04:05 EBS10 systemd[1]: Starting File System Check on /dev/disk/by-partuuid/b55a00c3-01...
Dec 24 09:04:05 EBS10 systemd-fsck[215]: fsck.fat 4.2 (2021-01-31)
Dec 24 09:04:05 EBS10 systemd-fsck[215]: /dev/mmcblk0p1: 326 files, 25491/130554 clusters
Dec 24 09:04:05 EBS10 systemd[1]: Finished File System Check on /dev/disk/by-partuuid/b55a00c3-01.
Dec 24 09:04:05 EBS10 systemd[1]: Mounting /boot...
Dec 24 09:04:05 EBS10 systemd[1]: Mounted /boot.
Dec 24 09:04:05 EBS10 systemd[1]: Reached target Local File Systems.
Dec 24 09:04:05 EBS10 systemd[1]: Starting Set console font and keymap...
Dec 24 09:04:05 EBS10 systemd[1]: Starting Raise network interfaces...
Dec 24 09:04:05 EBS10 systemd[1]: Starting Preprocess NFS configuration...
Dec 24 09:04:05 EBS10 systemd[1]: Starting Tell Plymouth To Write Out Runtime Data...
Dec 24 09:04:05 EBS10 systemd[1]: Condition check resulted in Store a System Token in an EFI Variable being skipped.
Dec 24 09:04:05 EBS10 systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped.
Dec 24 09:04:05 EBS10 systemd[1]: Starting Create Volatile Files and Directories...
Dec 24 09:04:05 EBS10 systemd[1]: Finished Set console font and keymap.
Dec 24 09:04:05 EBS10 systemd[1]: nfs-config.service: Succeeded.
Dec 24 09:04:05 EBS10 systemd[1]: Finished Preprocess NFS configuration.
Dec 24 09:04:05 EBS10 systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped.
Dec 24 09:04:05 EBS10 systemd[1]: Condition check resulted in RPC security service for NFS server being skipped.
Dec 24 09:04:05 EBS10 systemd[1]: Reached target NFS client services.
Dec 24 09:04:05 EBS10 systemd[1]: Reached target Remote File Systems (Pre).
Dec 24 09:04:05 EBS10 systemd[1]: Reached target Remote File Systems.
Dec 24 09:04:05 EBS10 mtp-probe: checking bus 1, device 4: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1/1-1.1.3"
Dec 24 09:04:05 EBS10 mtp-probe: checking bus 1, device 5: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1/1-1.1.1"
Dec 24 09:04:05 EBS10 mtp-probe: bus: 1, device: 4 was not an MTP device
Dec 24 09:04:05 EBS10 mtp-probe: bus: 1, device: 5 was not an MTP device
Dec 24 09:04:05 EBS10 systemd[1]: Finished Create Volatile Files and Directories.
Dec 24 09:04:05 EBS10 systemd[1]: Starting Network Time Synchronization...
Dec 24 09:04:05 EBS10 systemd[1]: Starting Update UTMP about System Boot/Shutdown...
Dec 24 09:04:05 EBS10 systemd-udevd[162]: Using default interface naming scheme 'v247'.
Dec 24 09:04:05 EBS10 systemd[1]: Finished Update UTMP about System Boot/Shutdown.
Dec 24 09:04:05 EBS10 systemd[1]: Finished Raise network interfaces.
Dec 24 09:04:05 EBS10 systemd[1]: Started Network Time Synchronization.
Dec 24 09:04:05 EBS10 systemd[1]: Reached target System Time Set.
Dec 24 09:04:05 EBS10 systemd[1]: Reached target System Time Synchronized.
Dec 24 09:04:05 EBS10 systemd[1]: Received SIGRTMIN+20 from PID 173 (plymouthd).
Dec 24 09:04:05 EBS10 systemd[1]: Finished Tell Plymouth To Write Out Runtime Data.
Dec 24 09:04:05 EBS10 systemd[1]: Reached target System Initialization.
Dec 24 09:04:05 EBS10 systemd[1]: Started CUPS Scheduler.
Dec 24 09:04:05 EBS10 systemd[1]: Started Daily apt download activities.
Dec 24 09:04:05 EBS10 systemd[1]: Started Daily apt upgrade and clean activities.
Dec 24 09:04:05 EBS10 systemd[1]: Started Periodic ext4 Online Metadata Check for All Filesystems.
Dec 24 09:04:05 EBS10 systemd[1]: Started Discard unused blocks once a week.
Dec 24 09:04:05 EBS10 systemd[1]: Started Daily rotation of log files.
Dec 24 09:04:05 EBS10 systemd[1]: Started Daily man-db regeneration.
Dec 24 09:04:05 EBS10 systemd[1]: Started Daily Cleanup of Temporary Directories.
Dec 24 09:04:05 EBS10 systemd[1]: Reached target Paths.
Dec 24 09:04:05 EBS10 systemd[1]: Reached target Timers.
Dec 24 09:04:05 EBS10 systemd[1]: Listening on Avahi mDNS/DNS-SD Stack Activation Socket.
Dec 24 09:04:05 EBS10 systemd[1]: Listening on CUPS Scheduler.
Dec 24 09:04:05 EBS10 systemd[1]: Listening on D-Bus System Message Bus Socket.
Dec 24 09:04:05 EBS10 systemd[1]: Listening on triggerhappy.socket.
Dec 24 09:04:05 EBS10 systemd[1]: Reached target Sockets.
Dec 24 09:04:05 EBS10 systemd[1]: Reached target Basic System.
Dec 24 09:04:05 EBS10 systemd[1]: Starting Avahi mDNS/DNS-SD Stack...
Dec 24 09:04:05 EBS10 systemd[1]: Started Regular background program processing daemon.
Dec 24 09:04:05 EBS10 systemd[1]: Started D-Bus System Message Bus.
Dec 24 09:04:05 EBS10 cron[329]: (CRON) INFO (pidfile fd = 3)
Dec 24 09:04:05 EBS10 systemd[1]: Starting dphys-swapfile - set up, mount/unmount, and delete a swap file...
Dec 24 09:04:05 EBS10 cron[329]: (CRON) INFO (Running @reboot jobs)
Dec 24 09:04:05 EBS10 systemd[1]: Starting Remove Stale Online ext4 Metadata Check Snapshots...
Dec 24 09:04:05 EBS10 systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped.
Dec 24 09:04:05 EBS10 systemd[1]: Starting Check for glamor...
Dec 24 09:04:05 EBS10 avahi-daemon[328]: Found user 'avahi' (UID 108) and group 'avahi' (GID 113).
Dec 24 09:04:05 EBS10 systemd[1]: Starting Check for v3d driver...
Dec 24 09:04:05 EBS10 avahi-daemon[328]: Successfully dropped root privileges.
Dec 24 09:04:05 EBS10 avahi-daemon[328]: avahi-daemon 0.8 starting up.
Dec 24 09:04:05 EBS10 systemd[1]: Starting Configure Bluetooth Modems connected by UART...
Dec 24 09:04:05 EBS10 systemd[1]: Starting Authorization Manager...
Dec 24 09:04:05 EBS10 systemd[1]: Condition check resulted in Copy user wpa_supplicant.conf being skipped.
Dec 24 09:04:05 EBS10 systemd[1]: Starting DHCP Client Daemon...
Dec 24 09:04:05 EBS10 systemd[1]: Starting LSB: Switch to ondemand cpu governor (unless shift key is pressed)...
Dec 24 09:04:05 EBS10 systemd[1]: Starting LSB: rng-tools (Debian variant)...
Dec 24 09:04:05 EBS10 systemd[1]: Starting Check for Raspberry Pi EEPROM updates...
Dec 24 09:04:05 EBS10 systemd[1]: Starting System Logging Service...
Dec 24 09:04:05 EBS10 dhcpcd[343]: dev: loaded udev
Dec 24 09:04:05 EBS10 systemd[1]: Condition check resulted in Turn on SSH if /boot/ssh is present being skipped.
Dec 24 09:04:05 EBS10 dbus-daemon[330]: dbus[330]: Unknown username "geoclue" in message bus configuration file
Dec 24 09:04:05 EBS10 rpi-eeprom-update[350]: This tool only works with a Raspberry Pi 4
Dec 24 09:04:05 EBS10 systemd[1]: Starting User Login Management...
Dec 24 09:04:05 EBS10 systemd[1]: Starting triggerhappy global hotkey daemon...
Dec 24 09:04:05 EBS10 systemd[1]: Starting Disk Manager...
Dec 24 09:04:05 EBS10 systemd[1]: Starting WPA supplicant...
Dec 24 09:04:05 EBS10 dhcpcd[343]: forked to background, child pid 406
Dec 24 09:04:05 EBS10 systemd[1]: Finished Check for Raspberry Pi EEPROM updates.
Dec 24 09:04:05 EBS10 systemd[1]: Started DHCP Client Daemon.
Dec 24 09:04:05 EBS10 thd[399]: Found socket passed from systemd
Dec 24 09:04:05 EBS10 dphys-swapfile[331]: want /var/swap=100MByte, checking existing: keeping it
Dec 24 09:04:05 EBS10 systemd[1]: Started triggerhappy global hotkey daemon.
Dec 24 09:04:05 EBS10 systemd[1]: e2scrub_reap.service: Succeeded.
Dec 24 09:04:05 EBS10 systemd[1]: Finished Remove Stale Online ext4 Metadata Check Snapshots.
Dec 24 09:04:05 EBS10 kernel: [    0.000000] Booting Linux on physical CPU 0x0
Dec 24 09:04:05 EBS10 kernel: [    0.000000] Linux version 5.15.76-v7+ (dom@buildbot) (arm-linux-gnueabihf-gcc-8 (Ubuntu/Linaro 8.4.0-3ubuntu1) 8.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #1597 SMP Fri Nov 4 12:13:17 GMT 2022
Dec 24 09:04:05 EBS10 kernel: [    0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d
Dec 24 09:04:05 EBS10 kernel: [    0.000000] CPU: div instructions available: patching division code
Dec 24 09:04:05 EBS10 kernel: [    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
Dec 24 09:04:05 EBS10 kernel: [    0.000000] OF: fdt: Machine model: Raspberry Pi 3 Model B Plus Rev 1.3
Dec 24 09:04:05 EBS10 kernel: [    0.000000] random: crng init done
Dec 24 09:04:05 EBS10 kernel: [    0.000000] Memory policy: Data cache writealloc
Dec 24 09:04:05 EBS10 kernel: [    0.000000] Reserved memory: created CMA memory pool at 0x1ec00000, size 256 MiB
Dec 24 09:04:05 EBS10 kernel: [    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
Dec 24 09:04:05 EBS10 kernel: [    0.000000] Zone ranges:
Dec 24 09:04:05 EBS10 kernel: [    0.000000]   DMA      [mem 0x0000000000000000-0x000000003b3fffff]
Dec 24 09:04:05 EBS10 kernel: [    0.000000]   Normal   empty
Dec 24 09:04:05 EBS10 kernel: [    0.000000] Movable zone start for each node
Dec 24 09:04:05 EBS10 kernel: [    0.000000] Early memory node ranges
Dec 24 09:04:05 EBS10 kernel: [    0.000000]   node   0: [mem 0x0000000000000000-0x000000003b3fffff]
Dec 24 09:04:05 EBS10 kernel: [    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x000000003b3fffff]
Dec 24 09:04:05 EBS10 kernel: [    0.000000] percpu: Embedded 16 pages/cpu s35724 r8192 d21620 u65536
Dec 24 09:04:05 EBS10 kernel: [    0.000000] pcpu-alloc: s35724 r8192 d21620 u65536 alloc=16*4096
Dec 24 09:04:05 EBS10 kernel: [    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
Dec 24 09:04:05 EBS10 kernel: [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 240555
Dec 24 09:04:05 EBS10 kernel: [    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 video=Composite-1:720x480@60i vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  console=tty1 root=PARTUUID=b55a00c3-02 rootfstype=ext4 fsck.repair=yes rootwait quiet splash plymouth.ignore-serial-consoles
Dec 24 09:04:05 EBS10 kernel: [    0.000000] Unknown kernel command line parameters "splash", will be passed to user space.
Dec 24 09:04:05 EBS10 kernel: [    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
Dec 24 09:04:05 EBS10 kernel: [    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
Dec 24 09:04:05 EBS10 kernel: [    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
Dec 24 09:04:05 EBS10 kernel: [    0.000000] Memory: 681100K/970752K available (10240K kernel code, 1337K rwdata, 3080K rodata, 1024K init, 569K bss, 27508K reserved, 262144K cma-reserved)
Dec 24 09:04:05 EBS10 kernel: [    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
Dec 24 09:04:05 EBS10 kernel: [    0.000000] ftrace: allocating 33307 entries in 98 pages
Dec 24 09:04:05 EBS10 kernel: [    0.000000] ftrace: allocated 98 pages with 3 groups
Dec 24 09:04:05 EBS10 kernel: [    0.000000] trace event string verifier disabled
Dec 24 09:04:05 EBS10 kernel: [    0.000000] rcu: Hierarchical RCU implementation.

Colin · 24 December 2022 13:30

That is a reboot.

Edit: So for some reason your computer rebooted at 09:04, which is why node red stops.

henkkas · 24 December 2022 13:52

@Colin Yes, I did it intentionally to recreate the situation. So after reboot Node Red starts again, but after startup node-red almost immediately stops. Then I stop node-red and start it again, after that point node-red keeps on functioning normally.

It is every time for sure that Node-Red stops after reboot. After new start, it keeps on running.

Colin · 24 December 2022 14:32

You don't appear to have shown us the log of it stopping and restarting.

henkkas · 24 December 2022 14:35

I can send you that log by mail, because it is too big to show here.

Colin · 24 December 2022 15:10

Just the bit immediately before node-red stops.
Search for "Stopping Node-RED graphical event wiring tool..." and post the section up to that.

henkkas · 24 December 2022 16:49

@Colin Ok, I have been playing around for a while with this problem.

Latest I did was:

Stop node-red
Delete the syslog
sudo reboot

So according to CLI node-red started, followed with a crash.
I left it there a looked at the syslog.

This log is just over a 1000 lines long. But nowhere any mention about node-red.

I think something must be terribly wrong......

node-red-log


24 Dec 18:20:08 - [info]
Welcome to Node-RED
===================
24 Dec 18:20:08 - [info] Node-RED version: v3.0.2
24 Dec 18:20:08 - [info] Node.js  version: v16.19.0
24 Dec 18:20:08 - [info] Linux 5.15.76-v7+ arm LE
24 Dec 18:20:11 - [info] Loading palette nodes
24 Dec 18:20:15 - [info] Dashboard version 3.2.3 started at /ui
24 Dec 18:20:16 - [info] Settings file  : /home/pi/.node-red/settings.js
24 Dec 18:20:16 - [info] Context store  : 'default' [module=localfilesystem]
24 Dec 18:20:16 - [info] User directory : /home/pi/.node-red
24 Dec 18:20:16 - [warn] Projects disabled : editorTheme.projects.enabled=false
24 Dec 18:20:16 - [info] Flows file     : /home/pi/.node-red/flows.json
24 Dec 18:20:16 - [warn] Using unencrypted credentials
24 Dec 18:20:16 - [info] Server now running at http://127.0.0.1:18181/
24 Dec 18:20:16 - [info] Starting flows
24 Dec 18:20:17 - [info] Started flows
24 Dec 18:20:17 - [info] [serialconfig:05bfa2b9058c9fb6] serial port /dev/ttyUSB0 opened at 115200 baud 8N1
Stopping Node-RED graphical event wiring tool...
24 Dec 18:20:30 - [info] Stopping flows
24 Dec 18:20:30 - [info] serial port /dev/ttyUSB0 closed
24 Dec 18:20:30 - [info] Stopped flows
nodered.service: Succeeded.
Stopped Node-RED graphical event wiring tool.
nodered.service: Consumed 14.900s CPU time.

Dec 24 18:20:08 EBS10 Node-RED[1404]: Welcome to Node-RED
Dec 24 18:20:08 EBS10 Node-RED[1404]: ===================
Dec 24 18:20:08 EBS10 Node-RED[1404]: 24 Dec 18:20:08 - [info] Node-RED version: v3.0.2
Dec 24 18:20:08 EBS10 Node-RED[1404]: 24 Dec 18:20:08 - [info] Node.js  version: v16.19.0
Dec 24 18:20:08 EBS10 Node-RED[1404]: 24 Dec 18:20:08 - [info] Linux 5.15.76-v7+ arm LE
Dec 24 18:20:11 EBS10 Node-RED[1404]: 24 Dec 18:20:11 - [info] Loading palette nodes
Dec 24 18:20:15 EBS10 Node-RED[1404]: 24 Dec 18:20:15 - [info] Dashboard version 3.2.3 started at /ui
Dec 24 18:20:16 EBS10 Node-RED[1404]: 24 Dec 18:20:16 - [info] Settings file  : /home/pi/.node-red/settings.js
Dec 24 18:20:16 EBS10 Node-RED[1404]: 24 Dec 18:20:16 - [info] Context store  : 'default' [module=localfilesystem]
Dec 24 18:20:16 EBS10 Node-RED[1404]: 24 Dec 18:20:16 - [info] User directory : /home/pi/.node-red
Dec 24 18:20:16 EBS10 Node-RED[1404]: 24 Dec 18:20:16 - [warn] Projects disabled : editorTheme.projects.enabled=false
Dec 24 18:20:16 EBS10 Node-RED[1404]: 24 Dec 18:20:16 - [info] Flows file     : /home/pi/.node-red/flows.json
Dec 24 18:20:16 EBS10 Node-RED[1404]: 24 Dec 18:20:16 - [warn] Using unencrypted credentials
Dec 24 18:20:16 EBS10 Node-RED[1404]: 24 Dec 18:20:16 - [info] Server now running at http://127.0.0.1:18181/
Dec 24 18:20:16 EBS10 Node-RED[1404]: 24 Dec 18:20:16 - [info] Starting flows
Dec 24 18:20:17 EBS10 Node-RED[1404]: 24 Dec 18:20:17 - [info] Started flows
Dec 24 18:20:17 EBS10 Node-RED[1404]: 24 Dec 18:20:17 - [info] [serialconfig:05bfa2b9058c9fb6] serial port /dev/ttyUSB0 opened at 115200 baud 8N1
Dec 24 18:20:19 EBS10 influxd[465]: ts=2022-12-24T17:20:19.107175Z lvl=info msg="Executing query" log_id=0eyI9ErG000 service=query query="SELECT mean(voltL1), mean(voltL2), mean(voltL3) FROM EBS_ST.autogen.smartmeter WHERE time >= '2022-12-24T09:20:19.000Z' AND time <= '2022-12-24T17:20:19.000Z' GROUP BY time(2m) fill(none)"
Dec 24 18:20:19 EBS10 influxd[465]: ts=2022-12-24T17:20:19.107696Z lvl=info msg="Executing query" log_id=0eyI9ErG000 service=query query="SELECT mean(voltL1), mean(voltL2), mean(voltL3) FROM EBS_ST.autogen.smartmeter WHERE time >= '2022-12-24T09:20:19.000Z' AND time <= '2022-12-24T17:20:19.000Z' GROUP BY time(2m) fill(none)"
Dec 24 18:20:19 EBS10 influxd[465]: ts=2022-12-24T17:20:19.108545Z lvl=info msg="Executing query" log_id=0eyI9ErG000 service=query query="SELECT mean(voltL1), mean(voltL2), mean(voltL3) FROM EBS_ST.autogen.smartmeter WHERE time >= '2022-12-24T09:20:19.000Z' AND time <= '2022-12-24T17:20:19.000Z' GROUP BY time(2m) fill(none)"
Dec 24 18:20:19 EBS10 influxd[465]: ts=2022-12-24T17:20:19.110124Z lvl=info msg="Executing query" log_id=0eyI9ErG000 service=query query="SELECT mean(voltL1), mean(voltL2), mean(voltL3) FROM EBS_ST.autogen.smartmeter WHERE time >= '2022-12-24T09:20:19.000Z' AND time <= '2022-12-24T17:20:19.000Z' GROUP BY time(2m) fill(none)"
Dec 24 18:20:19 EBS10 influxd[465]: ts=2022-12-24T17:20:19.120644Z lvl=info msg="Executing query" log_id=0eyI9ErG000 service=query query="SELECT mean(memory), mean(temp), mean(usage) FROM EBS_ST.autogen.cpu WHERE time >= '2022-12-24T16:20:19.000Z' AND time <= '2022-12-24T17:20:19.000Z' GROUP BY time(10s) fill(none)"
Dec 24 18:20:19 EBS10 influxd[465]: [httpd] 127.0.0.1 - root [24/Dec/2022:18:20:19 +0100] "GET /query?db=EBS_ST&epoch=&p=%5BREDACTED%5D&params=&q=SELECT+MEAN%28memory%29%2C+MEAN%28temp%29%2C+MEAN%28usage%29+FROM+cpu+WHERE+time+%3E%3D+%272022-12-24T16%3A20%3A19.000Z%27+AND+time+%3C%3D+%272022-12-24T17%3A20%3A19.000Z%27+GROUP+BY+time%2810s%29+fill%28none%29&rp=&u=root HTTP/1.1" 200 5104 "-" "-" 3d698cde-83af-11ed-8005-000000000000 15582
Dec 24 18:20:19 EBS10 influxd[465]: [httpd] 127.0.0.1 - root [24/Dec/2022:18:20:19 +0100] "GET /query?db=EBS_ST&epoch=&p=%5BREDACTED%5D&params=&q=SELECT+MEAN%28voltL1%29%2CMEAN%28voltL2%29%2CMEAN%28voltL3%29+FROM+smartmeter+WHERE+time+%3E%3D+%272022-12-24T09%3A20%3A19.000Z%27+AND+time+%3C%3D+%272022-12-24T17%3A20%3A19.000Z%27+GROUP+BY+time%282m%29+fill%28none%29&rp=&u=root HTTP/1.1" 200 12186 "-" "-" 3d66feb7-83af-11ed-8004-000000000000 49663
Dec 24 18:20:19 EBS10 influxd[465]: [httpd] 127.0.0.1 - root [24/Dec/2022:18:20:19 +0100] "GET /query?db=EBS_ST&epoch=&p=%5BREDACTED%5D&params=&q=SELECT+MEAN%28voltL1%29%2CMEAN%28voltL2%29%2CMEAN%28voltL3%29+FROM+smartmeter+WHERE+time+%3E%3D+%272022-12-24T09%3A20%3A19.000Z%27+AND+time+%3C%3D+%272022-12-24T17%3A20%3A19.000Z%27+GROUP+BY+time%282m%29+fill%28none%29&rp=&u=root HTTP/1.1" 200 12186 "-" "-" 3d668f79-83af-11ed-8001-000000000000 75823
Dec 24 18:20:19 EBS10 influxd[465]: [httpd] 127.0.0.1 - root [24/Dec/2022:18:20:19 +0100] "GET /query?db=EBS_ST&epoch=&p=%5BREDACTED%5D&params=&q=SELECT+MEAN%28voltL1%29%2CMEAN%28voltL2%29%2CMEAN%28voltL3%29+FROM+smartmeter+WHERE+time+%3E%3D+%272022-12-24T09%3A20%3A19.000Z%27+AND+time+%3C%3D+%272022-12-24T17%3A20%3A19.000Z%27+GROUP+BY+time%282m%29+fill%28none%29&rp=&u=root HTTP/1.1" 200 12186 "-" "-" 3d66be17-83af-11ed-8002-000000000000 76466
Dec 24 18:20:19 EBS10 influxd[465]: [httpd] 127.0.0.1 - root [24/Dec/2022:18:20:19 +0100] "GET /query?db=EBS_ST&epoch=&p=%5BREDACTED%5D&params=&q=SELECT+MEAN%28voltL1%29%2CMEAN%28voltL2%29%2CMEAN%28voltL3%29+FROM+smartmeter+WHERE+time+%3E%3D+%272022-12-24T09%3A20%3A19.000Z%27+AND+time+%3C%3D+%272022-12-24T17%3A20%3A19.000Z%27+GROUP+BY+time%282m%29+fill%28none%29&rp=&u=root HTTP/1.1" 200 12186 "-" "-" 3d66db0a-83af-11ed-8003-000000000000 81038
Dec 24 18:20:19 EBS10 influxd[465]: ts=2022-12-24T17:20:19.905205Z lvl=info msg="Executing query" log_id=0eyI9ErG000 service=query query="SELECT mean(impTotaal), mean(expTotaal) FROM EBS_ST.autogen.smartmeter WHERE time >= '2022-12-24T16:20:19.000Z' AND time <= '2022-12-24T17:20:19.000Z' GROUP BY time(1m) fill(none)"
Dec 24 18:20:19 EBS10 influxd[465]: [httpd] 127.0.0.1 - root [24/Dec/2022:18:20:19 +0100] "GET /query?db=EBS_ST&epoch=&p=%5BREDACTED%5D&params=&q=SELECT+MEAN%28impTotaal%29%2CMEAN%28expTotaal%29+FROM+smartmeter+WHERE+time+%3E%3D+%272022-12-24T16%3A20%3A19.000Z%27+AND+time+%3C%3D+%272022-12-24T17%3A20%3A19.000Z%27+GROUP+BY+time%281m%29+fill%28none%29&rp=&u=root HTTP/1.1" 200 789 "-" "-" 3de10859-83af-11ed-8006-000000000000 8707
Dec 24 18:20:21 EBS10 influxd[465]: ts=2022-12-24T17:20:21.854796Z lvl=info msg="Executing query" log_id=0eyI9ErG000 service=query query="SHOW RETENTION POLICIES ON EBS_RT"
Dec 24 18:20:21 EBS10 influxd[465]: [httpd] 127.0.0.1 - root [24/Dec/2022:18:20:21 +0100] "GET /query?db=EBS_RT&epoch=&p=%5BREDACTED%5D&params=&q=SHOW+RETENTION+POLICIES+ON+EBS_RT&rp=&u=root HTTP/1.1" 200 167 "-" "-" 3f0ac845-83af-11ed-8007-000000000000 1334
Dec 24 18:20:21 EBS10 influxd[465]: ts=2022-12-24T17:20:21.855787Z lvl=info msg="Executing query" log_id=0eyI9ErG000 service=query query="SHOW RETENTION POLICIES ON EBS_ST"
Dec 24 18:20:21 EBS10 influxd[465]: [httpd] 127.0.0.1 - root [24/Dec/2022:18:20:21 +0100] "GET /query?db=EBS_ST&epoch=&p=%5BREDACTED%5D&params=&q=SHOW+RETENTION+POLICIES+ON+EBS_ST&rp=&u=root HTTP/1.1" 200 169 "-" "-" 3f0aeea1-83af-11ed-8008-000000000000 1328
Dec 24 18:20:21 EBS10 influxd[465]: ts=2022-12-24T17:20:21.856663Z lvl=info msg="Executing query" log_id=0eyI9ErG000 service=query query="SHOW RETENTION POLICIES ON EBS_HT"
Dec 24 18:20:21 EBS10 influxd[465]: [httpd] 127.0.0.1 - root [24/Dec/2022:18:20:21 +0100] "GET /query?db=EBS_HT&epoch=&p=%5BREDACTED%5D&params=&q=SHOW+RETENTION+POLICIES+ON+EBS_HT&rp=&u=root HTTP/1.1" 200 171 "-" "-" 3f0b0e11-83af-11ed-8009-000000000000 1421
Dec 24 18:20:21 EBS10 influxd[465]: ts=2022-12-24T17:20:21.859386Z lvl=info msg="Executing query" log_id=0eyI9ErG000 service=query query="SHOW RETENTION POLICIES ON EBS_LT"
Dec 24 18:20:21 EBS10 influxd[465]: [httpd] 127.0.0.1 - root [24/Dec/2022:18:20:21 +0100] "GET /query?db=EBS_LT&epoch=&p=%5BREDACTED%5D&params=&q=SHOW+RETENTION+POLICIES+ON+EBS_LT&rp=&u=root HTTP/1.1" 200 172 "-" "-" 3f0b759c-83af-11ed-800a-000000000000 1859
Dec 24 18:20:21 EBS10 influxd[465]: ts=2022-12-24T17:20:21.997343Z lvl=info msg="Executing query" log_id=0eyI9ErG000 service=query query="SELECT mean(memory), mean(temp), mean(usage) FROM EBS_ST.autogen.cpu WHERE time >= '2022-12-24T16:20:21.000Z' AND time <= '2022-12-24T17:20:21.000Z' GROUP BY time(10s) fill(none)"
Dec 24 18:20:22 EBS10 influxd[465]: [httpd] 127.0.0.1 - root [24/Dec/2022:18:20:21 +0100] "GET /query?db=EBS_ST&epoch=&p=%5BREDACTED%5D&params=&q=SELECT+MEAN%28memory%29%2C+MEAN%28temp%29%2C+MEAN%28usage%29+FROM+cpu+WHERE+time+%3E%3D+%272022-12-24T16%3A20%3A21.000Z%27+AND+time+%3C%3D+%272022-12-24T17%3A20%3A21.000Z%27+GROUP+BY+time%2810s%29+fill%28none%29&rp=&u=root HTTP/1.1" 200 5104 "-" "-" 3f207c4c-83af-11ed-800b-000000000000 14175
Dec 24 18:20:26 EBS10 influxd[465]: [httpd] 127.0.0.1 - root [24/Dec/2022:18:20:26 +0100] "POST /write?db=EBS_ST&p=%5BREDACTED%5D&precision=s&rp=&u=root HTTP/1.1" 204 0 "-" "-" 4201c740-83af-11ed-800c-000000000000 6579
Dec 24 18:20:30 EBS10 systemd[1]: Stopping Session 1 of user pi.
Dec 24 18:20:30 EBS10 systemd[1]: Stopping Session 3 of user pi.
Dec 24 18:20:30 EBS10 systemd[1]: Stopping Session 4 of user pi.
Dec 24 18:20:30 EBS10 systemd[1]: Removed slice system-modprobe.slice.
Dec 24 18:20:30 EBS10 systemd[1]: Stopped target Bluetooth.
Dec 24 18:20:30 EBS10 systemd[1]: Stopped target Graphical Interface.
Dec 24 18:20:30 EBS10 systemd[1]: Stopped target Multi-User System.
Dec 24 18:20:30 EBS10 systemd[1]: Stopped target Login Prompts.
Dec 24 18:20:30 EBS10 systemd[1]: Stopped target Sound Card.
Dec 24 18:20:30 EBS10 systemd[1]: Stopped target Timers.
Dec 24 18:20:30 EBS10 systemd[1]: apt-daily-upgrade.timer: Succeeded.
Dec 24 18:20:30 EBS10 systemd[1]: Stopped Daily apt upgrade and clean activities.
Dec 24 18:20:30 EBS10 systemd[1]: apt-daily.timer: Succeeded.
Dec 24 18:20:30 EBS10 systemd[1]: Stopped Daily apt download activities.
Dec 24 18:20:30 EBS10 systemd[1]: e2scrub_all.timer: Succeeded.
Dec 24 18:20:30 EBS10 systemd[1]: Stopped Periodic ext4 Online Metadata Check for All Filesystems.
Dec 24 18:20:30 EBS10 systemd[1]: fstrim.timer: Succeeded.

Colin · 24 December 2022 17:35

What are those two logs that you have posted? They are for the same times but contain different information. It is no use posting stuff without explaining what it is.

henkkas · 26 December 2022 10:46

@Colin So I tried some more stuff. Removed flow file of node-red and also removing settings file at the end.
Node-red started again with new settings file and clean and empty flow file.

After reboot same result again. Now I decided it was time to make a clean install on my rpi 3b+ again.
So I followed the procedure again. And make clean install of debian bullseye followed by influxDB (1.6.7~rc0) and node red, and some other small stuff.

After that with standard install and no changes whatsoever to Node-red. I rebooted and Node-red started
WITH SAME RESULT AGAIN!!! Here is the log I got in CLI

 sudo reboot
login as: pi
pi@192.168.0.41's password:
Linux EBStest 5.15.76-v7+ #1597 SMP Fri Nov 4 12:13:17 GMT 2022 armv7l

The programs included with the Debian GNU/Linux system are free software;
the exact distribution terms for each program are described in the
individual files in /usr/share/doc/*/copyright.

Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
Last login: Mon Dec 26 11:11:36 2022

Wi-Fi is currently blocked by rfkill.
Use raspi-config to set the country before use.

pi@EBStest:~ $ node-red-log


If the system-generated key is lost for any reason, your credentials
file will not be recoverable, you will have to delete it and re-enter
your credentials.
You should set your own key using the 'credentialSecret' option in
your settings file. Node-RED will then re-encrypt your credentials
file using your chosen key the next time you deploy a change.
---------------------------------------------------------------------
26 Dec 11:10:59 - [info] Server now running at http://127.0.0.1:1880/
26 Dec 11:10:59 - [warn] Encrypted credentials not found
26 Dec 11:10:59 - [info] Starting flows
26 Dec 11:10:59 - [info] Started flows
26 Dec 11:11:23 - [info] Stopping flows
26 Dec 11:11:23 - [info] Stopped flows
Stopping Node-RED graphical event wiring tool...
nodered.service: Succeeded.
Stopped Node-RED graphical event wiring tool.
nodered.service: Consumed 8.825s CPU time.
Started Node-RED graphical event wiring tool.
26 Dec 11:11:41 - [info]
Welcome to Node-RED
===================
26 Dec 11:11:41 - [info] Node-RED version: v3.0.2
26 Dec 11:11:41 - [info] Node.js  version: v16.19.0
26 Dec 11:11:41 - [info] Linux 5.15.76-v7+ arm LE
26 Dec 11:11:45 - [info] Loading palette nodes
26 Dec 11:11:53 - [info] Settings file  : /home/pi/.node-red/settings.js
26 Dec 11:11:53 - [info] Context store  : 'default' [module=memory]
26 Dec 11:11:53 - [info] User directory : /home/pi/.node-red
26 Dec 11:11:53 - [warn] Projects disabled : editorTheme.projects.enabled=false
26 Dec 11:11:53 - [info] Flows file     : /home/pi/.node-red/flows.json
26 Dec 11:11:53 - [info] Creating new flow file
26 Dec 11:11:53 - [warn]
---------------------------------------------------------------------
Your flow credentials file is encrypted using a system-generated key.
If the system-generated key is lost for any reason, your credentials
file will not be recoverable, you will have to delete it and re-enter
your credentials.
You should set your own key using the 'credentialSecret' option in
your settings file. Node-RED will then re-encrypt your credentials
file using your chosen key the next time you deploy a change.
---------------------------------------------------------------------
26 Dec 11:11:53 - [warn] Encrypted credentials not found
26 Dec 11:11:53 - [info] Starting flows
26 Dec 11:11:53 - [info] Started flows
26 Dec 11:11:53 - [info] Server now running at http://127.0.0.1:1880/

So my conclusion is that something is wrong with my install procedure.
Hereby a summary of the install procedure that I did,

1. With raspberry PI Imager make image on sd card (Debian 11 (bullseye) with desktop xsfc
2. After startup with putty: 
sudo apt-get update -y && sudo apt-get upgrade -y && sudo apt-get autoremove -y && sudo apt-get autoclean -y
3. With raspi-config,
  •	System options Audio  Headphone
  •	System options Hostname
  •	Interface options  SSH Enable
  •	Interface options  VNC Enable
  •	Advanced  options  Expand filesystem
4. Activation usb drive possibility with
sudo apt-get install ntfs-3g
5. Installing standard influxDB (1.6.7):
        sudo apt-get install influxdb
        sudo apt install influxdb-client
Adjust influxDB settings file:
         /etc/influxdb/influxdb.conf

        [HTTP]
       HTTP: enabled = true
       bind-address = ":8086"
       [monitor]  
       store-enabled = false 
6. sudo reboot
7. Activate Influxdb service 
       sudo systemctl unmask influxdb
       sudo systemctl enable influxdb
       sudo systemctl start influxdb
10. Install samba,
      sudo apt update
      sudo apt install samba samba-common-bin smbclient
   
     Edit  /etc/samba/smb.conf
11. sudo apt update && sudo apt install smem
12. Install NODE RED:
        sudo apt install build-essential git
        bash <(curl -sL https://raw.githubusercontent.com/node-red/linux-installers/master/deb/update-nodejs-and-nodered) 
        sudo systemctl enable nodered.service
13, sudo reboot
14. node-red-log

This was the procedure that I followed with the result, I showed you before.

The nodered-install.log didn't show any abnormalities also to my mind.

I also check the syslog and saw something familiar in the first 3 lines that I saw before also, namely failed to find modules lp/ppdev/parport_pc, I don't now if it means anything ????

Hereby the first few lines.

Sep 22 02:34:53 EBStest systemd-modules-load[130]: Failed to find module 'lp'
Sep 22 02:34:53 EBStest systemd-modules-load[130]: Failed to find module 'ppdev'
Sep 22 02:34:53 EBStest systemd-modules-load[130]: Failed to find module 'parport_pc'
Sep 22 02:34:53 EBStest systemd-modules-load[130]: Inserted module 'i2c_dev'
Sep 22 02:34:53 EBStest systemd-sysctl[147]: Couldn't write '1' to 'kernel/unprivileged_userns_clone', ignoring: No such file or directory
Sep 22 02:34:53 EBStest fake-hwclock[134]: Thu 22 Sep 00:34:48 UTC 2022
Sep 22 02:34:53 EBStest systemd-fsck[148]: e2fsck 1.46.2 (28-Feb-2021)
Sep 22 02:34:53 EBStest systemd-fsck[148]: rootfs: clean, 121433/1918208 files, 934128/7725184 blocks
Sep 22 02:34:53 EBStest systemd[1]: Finished Remount Root and Kernel File Systems.
Sep 22 02:34:53 EBStest systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
Sep 22 02:34:53 EBStest systemd[1]: Starting Flush Journal to Persistent Storage...
Sep 22 02:34:53 EBStest systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped.
Sep 22 02:34:53 EBStest systemd[1]: Starting Load/Save Random Seed...
Sep 22 02:34:53 EBStest systemd[1]: Starting Create System Users...
Sep 22 02:34:53 EBStest systemd[1]: Finished Coldplug All udev Devices.
Sep 22 02:34:53 EBStest systemd[1]: Starting Helper to synchronize boot up for ifupdown...
Sep 22 02:34:53 EBStest systemd[1]: Finished Helper to synchronize boot up for ifupdown.
Sep 22 02:34:53 EBStest systemd[1]: Finished Load/Save Random Seed.
Sep 22 02:34:53 EBStest systemd[1]: Condition check resulted in First Boot Complete being skipped.
Sep 22 02:34:53 EBStest systemd[1]: Finished Create System Users.
Sep 22 02:34:53 EBStest systemd[1]: Starting Create Static Device Nodes in /dev...
Sep 22 02:34:53 EBStest systemd[1]: Finished Set the console keyboard layout.
Sep 22 02:34:53 EBStest systemd[1]: Finished Flush Journal to Persistent Storage.
Sep 22 02:34:53 EBStest systemd[1]: Finished Create Static Device Nodes in /dev.
Sep 22 02:34:53 EBStest systemd[1]: Reached target Local File Systems (Pre).
Sep 22 02:34:53 EBStest systemd[1]: Starting Rule-based Manager for Device Events and Files...
Sep 22 02:34:53 EBStest systemd[1]: Started Rule-based Manager for Device Events and Files.
Sep 22 02:34:53 EBStest systemd[1]: Starting Show Plymouth Boot Screen...
Sep 22 02:34:53 EBStest systemd[1]: Received SIGRTMIN+20 from PID 173 (plymouthd).
Sep 22 02:34:53 EBStest systemd[1]: Started Show Plymouth Boot Screen.
Sep 22 02:34:53 EBStest systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped.
Sep 22 02:34:53 EBStest systemd[1]: Started Forward Password Requests to Plymouth Directory Watch.
Sep 22 02:34:53 EBStest systemd[1]: Reached target Local Encrypted Volumes.
Sep 22 02:34:53 EBStest systemd[1]: Condition check resulted in Dispatch Password Requests to Console Directory Watch being skipped.
Sep 22 02:34:53 EBStest systemd[1]: Condition check resulted in Huge Pages File System being skipped.
Sep 22 02:34:53 EBStest systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
Sep 22 02:34:53 EBStest systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
Sep 22 02:34:53 EBStest systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped.
Sep 22 02:34:53 EBStest systemd[1]: Found device /dev/disk/by-partuuid/a47cfc53-01.
Sep 22 02:34:53 EBStest systemd[1]: Starting File System Check on /dev/disk/by-partuuid/a47cfc53-01...
Sep 22 02:34:53 EBStest systemd-fsck[214]: fsck.fat 4.2 (2021-01-31)
Sep 22 02:34:53 EBStest systemd-fsck[214]: /dev/mmcblk0p1: 321 files, 25467/130554 clusters
Sep 22 02:34:53 EBStest systemd[1]: Finished File System Check on /dev/disk/by-partuuid/a47cfc53-01.
Sep 22 02:34:53 EBStest systemd[1]: Mounting /boot...
Sep 22 02:34:53 EBStest systemd[1]: Mounted /boot.
Sep 22 02:34:53 EBStest systemd[1]: Reached target Local File Systems.
Sep 22 02:34:53 EBStest systemd[1]: Starting Set console font and keymap...
Sep 22 02:34:53 EBStest systemd[1]: Starting Raise network interfaces...

I am really puzzled now...... Any idea's on this?

Also @TotallyInformation or @dceejay maybe you guys have any idea what I did wrong in my installation procedure?

Colin · 26 December 2022 12:13

Exactly what time did you issue the reboot? To within 10 seconds please. If you don't know then do it again. Make sure you read the time from the system clock. If you watch the clock then issue the reboot exactly on the minute that would be the best thing. That will allow you to relate the node-red log to exactly the point at which you rebooted.

Topic		Replies	Views
Flows restart after restart of Node Red but not after a reboot of the pi General	24	2361	25 May 2021
Node-RED must be restarted to enable upgraded modules General	23	7271	14 October 2020
Raspberry 4 reboots just after starting node-red General	8	119	5 March 2024
Cant start after reboot General	3	332	20 April 2021
Node red Not starting Look at log idk General	8	620	14 December 2021

Node red stops right after reboot and node-red "auto-start"

Related Topics