Unplanned Restart / Reboot?

Hi,

it seems that my Node-Red (On Raspi) is rebooting without any trigger or influence.
That makes me unhappy, because it clears all chart data and history :frowning:

Is there kind of a logfile showing such events and possible reasons for it ?

BR
G

There is a log written to stdout, which you can write to file. You can also view it (if you used the pi install script) through node-red-log which tails the output and keeps updating.

It sounds like for some reason node-red crashes, and the service restarts it. If that’s the case you can see the reason why it crashes in the logs like above. Without that information I’m afraid I can’t assist more.

Is the entire Pi rebooting? If so it is probably a power supply problem.

The system log is in /var/log/syslog. That should include node red related messages. Have a look at that around the time of reset and you should be able to see whether just node red restarted or whether the pi rebooted and you may get clues about why.

I found some strange lines in /var/log/syslog between 22:55 and 23:05

the result of this FATAL error was a restart of Node-Red ... unfortunately I do not know if I can fix this issue in any way :frowning:

Feb 10 22:55:45 raspberrypi Node-RED[9119]: 10 Feb 22:55:45 - [info] [pushover api:Pushover Homematic] pushover POST succeeded:
Feb 10 22:55:45 raspberrypi Node-RED[9119]: "{\"status\":1,\"request\":\"7529058a-1c3a-47c3-951b-61aa43206e84\"}"
Feb 10 23:00:01 raspberrypi Node-RED[9119]: <--- Last few GCs --->
Feb 10 23:00:01 raspberrypi Node-RED[9119]: [9119:0x3140620] 224026009 ms: Mark-sweep 244.5 (257.8) -> 243.7 (258.0) MB, 1118.8 / 0.1 ms  (average mu = 0.109, current mu = 0.010) allocation failure scavenge migh$
Feb 10 23:00:01 raspberrypi Node-RED[9119]: [9119:0x3140620] 224026678 ms: Mark-sweep 244.6 (258.0) -> 243.6 (258.0) MB, 658.0 / 0.1 ms  (average mu = 0.074, current mu = 0.015) allocation failure scavenge might$
Feb 10 23:00:01 raspberrypi Node-RED[9119]: <--- JS stacktrace --->
Feb 10 23:00:01 raspberrypi Node-RED[9119]: ==== JS stack trace =========================================
Feb 10 23:00:01 raspberrypi Node-RED[9119]:     0: ExitFrame [pc: 0xe52060]
Feb 10 23:00:01 raspberrypi Node-RED[9119]: Security context: 0x2524e225 <JSObject>
Feb 10 23:00:01 raspberrypi Node-RED[9119]:     1: hasBinary [0x522df2b9] [/home/pi/.node-red/node_modules/has-binary2/index.js:~30] [pc=0x263d9c18](this=0x3f2811c9 <JSGlobal Object>,0xab098bc5 <Object map = 0x2$
Feb 10 23:00:01 raspberrypi Node-RED[9119]:     2: hasBinary [0x522df2b9] [/home/pi/.node-red/node_modules/has-binary2/index.js:~30] [pc=0x263d9b80](this=0x3f2811c9 <JSGlobal Object>,0x58a84e39 <JSArray[1440]>)
Feb 10 23:00:01 raspberrypi Node-RED[9119]:     3: hasBinary [0x522df2...
Feb 10 23:00:01 raspberrypi Node-RED[9119]: FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
Feb 10 23:00:01 raspberrypi Node-RED[9119]: Writing Node.js report to file: report.20200210.230001.9119.0.001.json
Feb 10 23:00:01 raspberrypi Node-RED[9119]: Node.js report completed
Feb 10 23:00:01 raspberrypi systemd[1]: nodered.service: Main process exited, code=killed, status=6/ABRT
Feb 10 23:00:01 raspberrypi systemd[1]: nodered.service: Failed with result 'signal'.
Feb 10 23:00:02 raspberrypi systemd[1]: nodered.service: Service RestartSec=100ms expired, scheduling restart.
Feb 10 23:00:02 raspberrypi systemd[1]: nodered.service: Scheduled restart job, restart counter is at 7.
Feb 10 23:00:02 raspberrypi systemd[1]: Stopped Node-RED graphical event wiring tool.
Feb 10 23:00:02 raspberrypi systemd[1]: Started Node-RED graphical event wiring tool.
Feb 10 23:00:03 raspberrypi Node-RED[5421]: 10 Feb 23:00:03 - [info]
Feb 10 23:00:03 raspberrypi Node-RED[5421]: Willkommen bei Node-RED!
Feb 10 23:00:03 raspberrypi Node-RED[5421]: ===================
Feb 10 23:00:03 raspberrypi Node-RED[5421]: 10 Feb 23:00:03 - [info] Node-RED Version: v1.0.3
Feb 10 23:00:03 raspberrypi Node-RED[5421]: 10 Feb 23:00:03 - [info] Node.js  Version: v12.14.0
Feb 10 23:00:03 raspberrypi Node-RED[5421]: 10 Feb 23:00:03 - [info] Linux 4.19.75-v7l+ arm LE
Feb 10 23:00:04 raspberrypi Node-RED[5421]: 10 Feb 23:00:04 - [info] Paletten-Nodes werden geladen
Feb 10 23:00:09 raspberrypi Node-RED[5421]: 10 Feb 23:00:09 - [info] node-red-contrib-ccu version: 3.1.4
Feb 10 23:00:10 raspberrypi Node-RED[5421]: 10 Feb 23:00:10 - [info] Dashboard version 2.19.3 started at /ui
Feb 10 23:00:10 raspberrypi Node-RED[5421]: 10 Feb 23:00:10 - [info] Einstellungsdatei: /home/pi/.node-red/settings.js
Feb 10 23:00:10 raspberrypi Node-RED[5421]: 10 Feb 23:00:10 - [info] Kontextspeicher: 'default' [ module=memory]
Feb 10 23:00:10 raspberrypi Node-RED[5421]: 10 Feb 23:00:10 - [info] Benutzerverzeichnis: /home/pi/.node-red
Feb 10 23:00:10 raspberrypi Node-RED[5421]: 10 Feb 23:00:10 - [warn] Projekte inaktiviert: editorTheme.projects.enabled=false
Feb 10 23:00:10 raspberrypi Node-RED[5421]: 10 Feb 23:00:10 - [info] Flow-Datei: /home/pi/.node-red/flows_raspberrypi.json
Feb 10 23:00:10 raspberrypi Node-RED[5421]: 10 Feb 23:00:10 - [info] Server wird jetzt auf http://127.0.0.1:1880/ ausgeführt.

It was indeed a fatal error, and take a closer look to see why. What does your flow try to do, that might cause this?

Yes, Node.js is running out of heap memory. It tries to recover some using the garbage collector but can't get enough so it gives up in disgust.

That shouldn't restart your Pi though. As Paul says, that is generally a power issue.

It will cause node-red to restart which will clear the charts.

I am using the original raspberry 3A power supply

Is it possible to clear the memory heap in a "good" way ? or extend the available memory to a higher value ?

That may just be patching over the underlying problem, and might only be a temporary fix. You should try to find where your flows are allocating but not freeing memory. My first instinct would be that it's a function node that's the culprit, although it could be an imported node which isn't clearing up correctly.

1 Like

Tell us the sort of things your flow is doing, we may be able to suggest where to look.
Do you have any delay nodes in Rate Limit mode?
Managing files?
Video?

My flows are mainly managing MQTT messages, triggering pushovers and other MQTT messages to Tasmota Devices

no Delays, no Files, no Video

Power supplies are like houseplants, some flourish for years, others die unexpectedly.
Try a different supply if possible.

1 Like

But do you have any function nodes which might allocate memory, or any not-very-widely-used additional nodes?

Something's eating your memory, and it's worth tracking it down.

I am using nodes for:
Homematic, MQTT, Thingspeak, MSSQL, Pushover, ModBus

I am using ONE Delay Node - to wait for 1 min between two HTTP Requests (turn on device, wait, turn off device)

Can I see or track allocated memory ?

I'm not really familiar with the internals of Node-RED or Node.js (I spend my days in C/C++ land) so it may need input from some of the developers to help in finding the problem.

There are a couple of nodes which seem to be able to check memory usage, such as node-red-contrib-heap-dump or node-red-contrib-nodes-memory. How you interpret the results they produce is another question.

I don't think there is any evidence that it is rebooting, unless @Golonder has not shown us that bit of the log.
@Golonder you can easily check this by running top in a terminal. That will show you how long since the last reboot. That command will also show you how much memory node-red is using. Some prefer htop which is a bit more user friendly. You can also see whether the processor is overloaded.
Might the MQTT messages be coming in faster than the following flows can handle them? If so then an ever increasing queue of messages may build up in node-red.

2 Likes

@Golonder you really should put a closing message on previous problems you have asked for help with saying what the conclusion was, as that may help others finding the thread.

The Raspberry is up since 20 days and 11 hours
The Node-Red service is consuming 20,8% MEM and 2%CPU

I am afraid that is not the issue :frowning:

top - 16:42:16 up 20 days, 11:16,  2 users,  load average: 0,00, 0,03, 0,01
Tasks: 140 total,   1 running, 139 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0,2 us,  0,1 sy,  0,5 ni, 99,2 id,  0,0 wa,  0,0 hi,  0,0 si,  0,0 st
MiB Mem :    924,5 total,    313,3 free,    327,3 used,    283,9 buff/cache
MiB Swap:    100,0 total,     30,0 free,     70,0 used.    543,4 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
 5421 pi        25   5  300428 197476  29448 S   2,0  20,9  22:41.00 node-red
 1185 root      20   0    3176   2000   1808 S   0,3   0,2  89:57.44 cuxd
 1280 root      20   0  276376  67084   4884 S   0,3   7,1 104:54.21 java
28227 pi        20   0    7828   2748   2388 R   0,3   0,3   0:00.23 top
    1 root      20   0   33696   7948   6404 S   0,0   0,8   0:22.23 systemd
    2 root      20   0       0      0      0 S   0,0   0,0   0:00.78 kthreadd
    3 root       0 -20       0      0      0 I   0,0   0,0   0:00.00 rcu_gp

What is not the issue?