Node red random restart

I resume this old post because I'm facing the same issue but I cannot solve it following the solution proposed by davidcgu (disabling apt-daily upgrade). NR is running on Raspberry pi 3B + using Stretch.

The flows I'm running on NR have worked with no problems for long time. More or less two months ago I've started having random NR restart (not Raspberry restart) but I sincerely cannot understand why... The only changes I've made in this last months are:

  • modification to my flows files (by adding/modifiying nodes but without installing new palettes).
  • perform an apt-update/apt-upgrade to my system

With NR log level set to "debug" in settings.js, I've checked in /var/log/system file and find what follows

...
May 28 06:05:01 raspberrypi CRON[8328]: (root) CMD (~/duckdns/duck.sh >/dev/null 2>&1)
.....
May 28 06:07:55 raspberrypi systemd[1]: Starting Daily apt upgrade and clean activities...
May 28 06:07:56 raspberrypi systemd[1]: Started Daily apt upgrade and clean activities.
May 28 06:07:56 raspberrypi systemd[1]: apt-daily-upgrade.timer: Adding 40min 2.221355s random time.
May 28 06:07:56 raspberrypi systemd[1]: apt-daily-upgrade.timer: Adding 24min 50.370714s random time.
....
....
May 28 06:09:01 raspberrypi CRON[11568]: (root) CMD (  [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /usr/lib/php/sessionclean; fi)
....
May 28 06:10:01 raspberrypi CRON[12373]: (root) CMD (~/duckdns/duck.sh >/dev/null 2>&1)
.....
May 28 06:15:02 raspberrypi CRON[16365]: (root) CMD (~/duckdns/duck.sh >/dev/null 2>&1)
...
May 28 06:17:01 raspberrypi CRON[17957]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
May 28 06:17:07 raspberrypi systemd[1]: nodered.service: Main process exited, code=killed, status=11/SEGV
May 28 06:17:07 raspberrypi systemd[1]: nodered.service: Unit entered failed state.
May 28 06:17:07 raspberrypi systemd[1]: nodered.service: Failed with result 'signal'.
May 28 06:17:07 raspberrypi systemd[1]: nodered.service: Service hold-off time over, scheduling restart.
May 28 06:17:07 raspberrypi systemd[1]: Stopped Node-RED graphical event wiring tool.
May 28 06:17:07 raspberrypi systemd[1]: Started Node-RED graphical event wiring tool.
May 28 06:17:11 raspberrypi Node-RED[18070]: 28 May 06:17:11 - [info]
May 28 06:17:11 raspberrypi Node-RED[18070]: Welcome to Node-RED
May 28 06:17:11 raspberrypi Node-RED[18070]: ===================
May 28 06:17:11 raspberrypi Node-RED[18070]: 28 May 06:17:11 - [info] Node-RED version: v0.20.7
May 28 06:17:11 raspberrypi Node-RED[18070]: 28 May 06:17:11 - [info] Node.js  version: v8.16.0
May 28 06:17:11 raspberrypi Node-RED[18070]: 28 May 06:17:11 - [info] Linux 4.19.57-v7+ arm LE
May 28 06:17:12 raspberrypi Node-RED[18070]: 28 May 06:17:12 - [info] Loading palette nodes

I've cleaned some additional log entries (where "... " appears) because not of interest.
I've seen that there is a "suspect" CRON entry that happened 6 seconds before the suddenly Node-Red kill signal

May 28 06:17:01 raspberrypi CRON[17957]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)

It seems that "someone" has sent a KILL signal to NR causing it to shut-down. After that - being NR started as a service - it automatically restart.
Is there a way to understand "who" sent the KILL signal to NR and how can I avoid it? And additionally if the restart should be caused by the "suspect" CRON job?

What is in that etc/cron.hourly file ?

cron.hourly is a directory and contains just one file (fake-hwclock)

root@raspberrypi:/etc/cron.hourly# ls
fake-hwclock

below the content of the fake-hwclock file

#!/bin/sh
#
# Simple cron script - save the current clock periodically in case of
# a power failure or other crash

if (command -v fake-hwclock >/dev/null 2>&1) ; then
  fake-hwclock save
fi


So not that then. Maybe do show us the "boring" bits as well

Below the complete syslog file section before the NR restart

May 28 06:00:01 raspberrypi CRON[4328]: (root) CMD (~/duckdns/duck.sh >/dev/null 2>&1)
May 28 06:00:27 raspberrypi Node-RED[393]: 28 May 06:00:27 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:00:58 raspberrypi Node-RED[393]: 28 May 06:00:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:01:28 raspberrypi Node-RED[393]: 28 May 06:01:28 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:01:58 raspberrypi Node-RED[393]: 28 May 06:01:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:02:28 raspberrypi Node-RED[393]: 28 May 06:02:28 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:02:58 raspberrypi Node-RED[393]: 28 May 06:02:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:03:28 raspberrypi Node-RED[393]: 28 May 06:03:28 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:03:31 raspberrypi Node-RED[393]: 28 May 06:03:31 - [info] [exec:d6cd5048.90061] error:Error: Command failed: python3.5 /home/pi/ADC_PI_Analog_Read_1.py
May 28 06:03:31 raspberrypi Node-RED[393]: Traceback (most recent call last):
May 28 06:03:31 raspberrypi Node-RED[393]:   File "/home/pi/ADC_PI_Analog_Read_1.py", line 10, in <module>
May 28 06:03:31 raspberrypi Node-RED[393]:     print("ANALOG 4: ", adc.read_voltage(4))
May 28 06:03:31 raspberrypi Node-RED[393]:   File "/usr/local/lib/python3.5/dist-packages/ADCPi/ADCPi.py", line 137, in read_voltage
May 28 06:03:31 raspberrypi Node-RED[393]:     raw = self.read_raw(channel)
May 28 06:03:31 raspberrypi Node-RED[393]:   File "/usr/local/lib/python3.5/dist-packages/ADCPi/ADCPi.py", line 199, in read_raw
May 28 06:03:31 raspberrypi Node-RED[393]:     raise TimeoutError(msg)
May 28 06:03:31 raspberrypi Node-RED[393]: TimeoutError: read_raw: channel 4 conversion timed out
May 28 06:03:58 raspberrypi Node-RED[393]: 28 May 06:03:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:04:28 raspberrypi Node-RED[393]: 28 May 06:04:28 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:04:58 raspberrypi Node-RED[393]: 28 May 06:04:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:05:01 raspberrypi CRON[8328]: (root) CMD (~/duckdns/duck.sh >/dev/null 2>&1)
May 28 06:05:28 raspberrypi Node-RED[393]: 28 May 06:05:28 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:05:58 raspberrypi Node-RED[393]: 28 May 06:05:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:06:28 raspberrypi Node-RED[393]: 28 May 06:06:28 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:06:58 raspberrypi Node-RED[393]: 28 May 06:06:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:07:28 raspberrypi Node-RED[393]: 28 May 06:07:28 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:07:55 raspberrypi systemd[1]: Starting Daily apt upgrade and clean activities...
May 28 06:07:56 raspberrypi systemd[1]: Started Daily apt upgrade and clean activities.
May 28 06:07:56 raspberrypi systemd[1]: apt-daily-upgrade.timer: Adding 40min 2.221355s random time.
May 28 06:07:56 raspberrypi systemd[1]: apt-daily-upgrade.timer: Adding 24min 50.370714s random time.
May 28 06:07:58 raspberrypi Node-RED[393]: 28 May 06:07:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:08:28 raspberrypi Node-RED[393]: 28 May 06:08:28 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:08:58 raspberrypi Node-RED[393]: 28 May 06:08:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:09:01 raspberrypi CRON[11568]: (root) CMD (  [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /usr/lib/php/sessionclean; fi)
May 28 06:09:28 raspberrypi Node-RED[393]: 28 May 06:09:28 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:09:58 raspberrypi Node-RED[393]: 28 May 06:09:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:10:01 raspberrypi CRON[12373]: (root) CMD (~/duckdns/duck.sh >/dev/null 2>&1)
May 28 06:10:28 raspberrypi Node-RED[393]: 28 May 06:10:28 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:10:58 raspberrypi Node-RED[393]: 28 May 06:10:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:11:28 raspberrypi Node-RED[393]: 28 May 06:11:28 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:11:58 raspberrypi Node-RED[393]: 28 May 06:11:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:12:28 raspberrypi Node-RED[393]: 28 May 06:12:28 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:12:58 raspberrypi Node-RED[393]: 28 May 06:12:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:13:28 raspberrypi Node-RED[393]: 28 May 06:13:28 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:13:58 raspberrypi Node-RED[393]: 28 May 06:13:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:14:28 raspberrypi Node-RED[393]: 28 May 06:14:28 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:14:58 raspberrypi Node-RED[393]: 28 May 06:14:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:15:02 raspberrypi CRON[16365]: (root) CMD (~/duckdns/duck.sh >/dev/null 2>&1)
May 28 06:15:28 raspberrypi Node-RED[393]: 28 May 06:15:28 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:15:58 raspberrypi Node-RED[393]: 28 May 06:15:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:16:28 raspberrypi Node-RED[393]: 28 May 06:16:28 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:16:58 raspberrypi Node-RED[393]: 28 May 06:16:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k
May 28 06:17:01 raspberrypi CRON[17957]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
May 28 06:17:07 raspberrypi systemd[1]: nodered.service: Main process exited, code=killed, status=11/SEGV
May 28 06:17:07 raspberrypi systemd[1]: nodered.service: Unit entered failed state.
May 28 06:17:07 raspberrypi systemd[1]: nodered.service: Failed with result 'signal'.
May 28 06:17:07 raspberrypi systemd[1]: nodered.service: Service hold-off time over, scheduling restart.
May 28 06:17:07 raspberrypi systemd[1]: Stopped Node-RED graphical event wiring tool.
May 28 06:17:07 raspberrypi systemd[1]: Started Node-RED graphical event wiring tool.
May 28 06:17:11 raspberrypi Node-RED[18070]: 28 May 06:17:11 - [info]
May 28 06:17:11 raspberrypi Node-RED[18070]: Welcome to Node-RED
May 28 06:17:11 raspberrypi Node-RED[18070]: ===================
May 28 06:17:11 raspberrypi Node-RED[18070]: 28 May 06:17:11 - [info] Node-RED version: v0.20.7
May 28 06:17:11 raspberrypi Node-RED[18070]: 28 May 06:17:11 - [info] Node.js  version: v8.16.0
May 28 06:17:11 raspberrypi Node-RED[18070]: 28 May 06:17:11 - [info] Linux 4.19.57-v7+ arm LE
May 28 06:17:12 raspberrypi Node-RED[18070]: 28 May 06:17:12 - [info] Loading palette nodes

as a note consider that:

  • all the entries regarding the exec node 96ba9b5a.d097b8 are not interesting because there were also before the NR random restart started to happen (I execute a command from NR in order to reset a serial port that I use for connecting some gas sensors to the Rasp before reading the sensors otherwise sometimes the serial port get stucked)
  • the error coming out from reading the
/home/pi/ADC_PI_Analog_Read_1.py

is a random error and also in this case appeared sometimes also before the NR random restart started to happen

May 28 06:00:58 raspberrypi Node-RED[393]: 28 May 06:00:58 - [info] [exec:96ba9b5a.d097b8] error:Error: Command failed: sudo fuser /dev/ttyFTDI_GAS -k

Is there a way to monitor which program send the KILL signal to NR?

  1. When you say you can't fix it by disabling daily updates do you mean you have done that and it didn't work or there is some other reason you can't do it?
  2. Is there always the cron entry just before it restarts?
  3. Have a look in /var/log/apt/history.log (or older such files) to see if there is anything there around that time.

I've disabled the daily updates but it didn't solve the issue (random NR restars will happened)

Not always

No activities in /var/log/apt/history.log file. The file dated 01/01/2020 is empty

You said the restart is not always immediately after the cron entry, does that mean that it is often just after it (I mean just after it in time, not just after it in the log but with maybe a significant time interval between them).

Another thought, you haven't by any chance got something in the flow that restarts node red under some conditions have you? A watchdog of some sort maybe.

Otherwise that is me pretty much out of ideas.

I've got a CRON for updating duckdns IP that runs every 5 minutes and NR random restart are more or less one per day. I'll try to exlcude the CRON for duckdns update. The other CRON that apperas in the log i posted

May 28 06:17:01 raspberrypi CRON[17957]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)

instead has occured only with this restart (in the previous restarts it didn't occur in a range-time before NR restart) so I think it's just a case...

I've checked and I have an exec node that trigger a NR restart but it's triggered manually by a dashboard button and IƬll try to exclude also this.

I'll try to investigate further and share with you my results.

Thanks anyway for your support Colin.

Thinking about it, if the restart is doing a normal restart invoking the systemd stop and start script then you would see a normal shutdown in the log not a killed message.

However, I have just noticed that the log is showing a SEGV error. That means that node red has somehow generated a memory Segmentation Violation. I have no idea what might cause that I am afraid, a pretty serious bug in something I imagine. Personally I would start by sorting out all the node related errors that you are seeing in the log even if you don't think they are part of the problem. Any time you you have code hitting error conditions you are more likely to be exercising routes through the s/w that may not have been tested as thoroughly as the rest so the possibility of side effects is always there. So sort those out and see if it helps.
Additionally I would upgrade to the latest version of node 8.x (which should be painless) or possibly even better move to 10.x or 12.x, though that is not always straighforward.

2 Likes

I've made some steps forward by recording ad analysing the system core-dump created when node-red crashes.
In details I'd enabled the system core-dump recording (that are disabled by default in Rasp) and analyse the core-dump file produced using gdb (consider that since yesterday I didn't know anything about core-dump, stack, trace, gdb and so on - so sorry if I say something wrong) :laughing:

After invoking gdb with the following command

root@raspberrypi:/var/lib/coredumps# gdb node /var/lib/coredumps/core-node-red-sig11-user1000-group1000-pid17273-time1591792948

I've obtained the following outcome

GNU gdb (Raspbian 7.12-6) 7.12.0.20161007-git
Copyright (C) 2016 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "arm-linux-gnueabihf".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
http://www.gnu.org/software/gdb/bugs/.
Find the GDB manual and other documentation resources online at:
http://www.gnu.org/software/gdb/documentation/.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from node...done.
warning: core file may not match specified executable file.
[New LWP 17273]
[New LWP 17282]
[New LWP 17281]
[New LWP 17283]
[New LWP 17285]
[New LWP 17284]
[New LWP 17288]
[New LWP 17290]
[New LWP 17291]
[New LWP 17289]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/arm-linux-gnueabihf/libthread_db.so.1".
Core was generated by `node-red '.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x009bae10 in v8::internal::LocalEmbedderHeapTracer::RegisterWrappersWithRemoteTracer() ()
[Current thread is 1 (Thread 0x76f35570 (LWP 17273))]

At the end not a lot of additional info. Gdb says that the core-dump was generated by node-red (and I already know it), that the program exited with a SEGV signal (and I already know it). So I'll inspect the gdb back-trace by launching from within the gdb console the bt command. And something interesting at the end came out. Below the result of the bt command

(gdb) bt
#0 0x009bae10 in v8::internal::LocalEmbedderHeapTracer::RegisterWrappersWithRemoteTracer() ()
#1 0x009df484 in v8::internal::Heap::Scavenge() ()
#2 0x009e08b0 in v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) ()
#3 0x025a1af0 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

It seems that the SEGV has been caused by the Scvenge/GarbageCollection process. Is my understanding correct? If so how is it possible that the garbage collection process caused a segmentation fault in Node-Red? Any help to solve this probem will be highly appreciated

Have you upgraded nodejs to at least the latest 8.x as I suggested? Not much point doing more till you have done that.

[Edit]
Also have you got rid of all the other errors in the log that you showed earlier?

Hi Colin,
as per the extract of my syslog file attached some messages above

May 28 06:17:11 raspberrypi Node-RED[18070]: 28 May 06:17:11 - [info] Node-RED version: v0.20.7
May 28 06:17:11 raspberrypi Node-RED[18070]: 28 May 06:17:11 - [info] Node.js version: v8.16.0

The node-js version I'm currently using is the v8.16.0.
I'm trying to clean all the other error messages (even if I cannot understand the relationship between them and the fault in the garbage collector process - but surely I'm missing some points).
I'll keep you updated

I imagine that a crash in the garbage collection could be caused by something corrupting the memory heap. That could be anything in the process and the problem might not be catastrophic till the garbage collection attempts to clean it up.
If I had the problem I would also upgrade to node 10 or 12 as perhaps the defensive programming in the garbage collection has improved so that it doesn't crash.

Can I also check that you have tried a different SD card? You may already have said that but without reading back through the whole thread I don't know. Also are you sure the PSU is good? Though that failure is not typical of PSU problems.

Ok great, I'll soon follow your suggestion and I'll upgrade node.js to the latest stable version ( Latest LTS Version: 12.18.0 that includes npm 6.14.4).

I've also clone the current MicroSD (using the SD Card Copier tool that comes out of the box in the Raspberry GUI) in order to exclude any hw-related problem but the random NR crashes - due to SEGV - still continue to happen.
I've also excluded PSU-related problems because I use a Meanwell PSU - MDR-60-5
outputting 5V DC 10A (and I think its enough :smile:).
In order to upgrade node-js to the lastest version do you suggest me to use npm (so basically after upgrading npm to the latest version with npm install npm@latest -g launch the command to upgrade node with sudo npm cache clean -f sudo npm install -g n sudo n stable) or it will be better to upgrade it by using nvm (after installing it because I don't think it will be alrady installed in my Stretch OS running on my Rasp)? I want to avoid to upgrade Node-Red - in order to update node.js - because in the past I've tried to upgrade my current version of NR from the v 0.20.7 to the latest available at that time but I had to revert back to v 0.20.7 because - without reason - the MQTT client node of the newer version didn't connect anymore to my MQTT broker for unknown reasons).

No, first remove the current version
sudo apt remove nodejs
then upgrade using the recommended script Running on Raspberry Pi : Node-RED which should be how you installed in the first place, but maybe not.

But in this way I also automatically update Node-Red to the latest version, right?

Yes, don't you want to do that? After running it you can downgrade node-red if you want.

Upgrading Node-Red causing problem in my flows (MQTT client node didn't connect to my mqtt broker).

How can I then downgrade Node-Red to the version I'm currently using?

There is no known problem with the mqtt nodes that I am aware of, but to downgrade this should do it
npm install -g --unsafe-perm node-red@0.20.7
However, having upgraded everything I would check whether the mqtt problem still exists before downgrading.
If you installed npm via apt then remove that too before starting, though probably it isn't necessary.