Node Red restarts

General
1

Hi@all,

since some days Node Red restarts randomly after 5 minutes, 30 minutes, 5 hours or something else.

I haven't changed anything in the flows nor updated the container.

I have the docker version installed.

Th log shows the following:

0 info it worked if it ends with ok
1 verbose cli [
1 verbose cli   '/usr/local/bin/node',
1 verbose cli   '/usr/local/bin/npm',
1 verbose cli   '--no-update-notifier',
1 verbose cli   '--no-fund',
1 verbose cli   'start',
1 verbose cli   '--cache',
1 verbose cli   '/data/.npm',
1 verbose cli   '--',
1 verbose cli   '--userDir',
1 verbose cli   '/data'
1 verbose cli ]
2 info using npm@6.14.15
3 info using node@v14.18.1
4 verbose config Skipping project config: /usr/src/node-red/.npmrc. (matches userconfig)
5 verbose run-script [ 'prestart', 'start', 'poststart' ]
6 info lifecycle node-red-docker@2.1.3~prestart: node-red-docker@2.1.3
7 info lifecycle node-red-docker@2.1.3~start: node-red-docker@2.1.3
8 verbose lifecycle node-red-docker@2.1.3~start: unsafe-perm in lifecycle true
9 verbose lifecycle node-red-docker@2.1.3~start: PATH: /usr/local/lib/node_modules/npm/node_modules/npm-lifecycle/node-gyp-bin:/usr/src/node-red/node_modules/.bin:/usr/src/node-red/node_modules/.bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
10 verbose lifecycle node-red-docker@2.1.3~start: CWD: /usr/src/node-red
11 silly lifecycle node-red-docker@2.1.3~start: Args: [
11 silly lifecycle   '-c',
11 silly lifecycle   'node $NODE_OPTIONS node_modules/node-red/red.js $FLOWS "--userDir" "/data"'
11 silly lifecycle ]
12 silly lifecycle node-red-docker@2.1.3~start: Returned: code: 1  signal: null
13 info lifecycle node-red-docker@2.1.3~start: Failed to exec start script
14 verbose stack Error: node-red-docker@2.1.3 start: `node $NODE_OPTIONS node_modules/node-red/red.js $FLOWS "--userDir" "/data"`
14 verbose stack Exit status 1
14 verbose stack     at EventEmitter.<anonymous> (/usr/local/lib/node_modules/npm/node_modules/npm-lifecycle/index.js:332:16)
14 verbose stack     at EventEmitter.emit (events.js:400:28)
14 verbose stack     at ChildProcess.<anonymous> (/usr/local/lib/node_modules/npm/node_modules/npm-lifecycle/lib/spawn.js:55:14)
14 verbose stack     at ChildProcess.emit (events.js:400:28)
14 verbose stack     at maybeClose (internal/child_process.js:1058:16)
14 verbose stack     at Process.ChildProcess._handle.onexit (internal/child_process.js:293:5)
15 verbose pkgid node-red-docker@2.1.3
16 verbose cwd /usr/src/node-red
17 verbose Linux 4.18.0-305.3.1.el8.x86_64
18 verbose argv "/usr/local/bin/node" "/usr/local/bin/npm" "--no-update-notifier" "--no-fund" "start" "--cache" "/data/.npm" "--" "--userDir" "/data"
19 verbose node v14.18.1
20 verbose npm  v6.14.15
21 error code ELIFECYCLE
22 error errno 1
23 error node-red-docker@2.1.3 start: `node $NODE_OPTIONS node_modules/node-red/red.js $FLOWS "--userDir" "/data"`
23 error Exit status 1
24 error Failed at the node-red-docker@2.1.3 start script.
24 error This is probably not a problem with npm. There is likely additional logging output above.
25 verbose exit [ 1, true ]

Does anyone have an idea what causes this?

BR
Jarod

2

Where did those logs come?

They look like docker logs, not the output from the actual Node-RED process, which should give some indication of why the process exited.

3

Log is taken from inside the container.

E.g. "bash-5.0$ cat /data/.npm/_logs/2021-11-14T20_41_01_525Z-debug.log"

Logging tag from settings.js:

    logging: {
        console: {errors
            level: "info",
            metrics: false,
            audit: false
        }
    },
4

the console: {errors isn't valid javascript, so that can not be accurate as Node-RED wouldn't start at all if that is truly what is in the running settings.js

You would need to remove the errors to make is correct.

And with the default logging configuration there should be a lot more information in the logs from the startup.

What happens if you use docker logs [containername] to show the actual container logs?

5

Oh sorry,

I stripped the comments and looks like I made a mistake.

Looks like this:

    logging: {
        // Only console logging is currently supported
        console: {
            // Level of logging to be recorded. Options are:
            // fatal - only those errors which make the application unusable should be recorded
            // error - record errors which are deemed fatal for a particular request + fatal errors
            // warn - record problems which are non fatal + errors + fatal errors
            // info - record information about the general running of the application + warn + error + fatal errors
            // debug - record information which is more verbose than info + info + warn + error + fatal errors
            // trace - record very detailed logging + debug + info + warn + error + fatal errors
            // off - turn off all logging (doesn't affect metrics or audit)
            level: "debug",
            // Whether or not to include metric events in the log output
            metrics: false,
            // Whether or not to include audit events in the log output
            audit: false
        }
    },

For the docker logs I will wait for the next restart.

As for now it contains sth like this:

14 Nov 23:12:12 - [info] [zigbee2mqtt-out:6b3a43eb.d2edec] Published to mqtt topic: zigbee2mqtt/Lampe_Vorraum/set : {"state":"OFF","transition":0}
14 Nov 23:15:10 - [info] [zigbee2mqtt-out:44a55c33.fa36e4] Published to mqtt topic: zigbee2mqtt/Lampe_Flur_EG_1/set : {"state":"OFF","transition":0}
6

OK,

it's me again.

Node-Red restarted again.

The following is in the logs rigth before and right after restarting:

14 Nov 23:37:55 - [info] [zigbee2mqtt-out:6b3a43eb.d2edec] Published to mqtt topic: zigbee2mqtt/Lampe_Vorraum/set : {"state":"OFF","transition":0}
14 Nov 23:43:05 - [info] [zigbee2mqtt-out:6b3a43eb.d2edec] Published to mqtt topic: zigbee2mqtt/Lampe_Vorraum/set : {"state":"OFF","transition":0}
14 Nov 23:43:37 - [info] [zigbee2mqtt-out:44a55c33.fa36e4] Published to mqtt topic: zigbee2mqtt/Lampe_Flur_EG_1/set : {"state":"OFF","transition":0}
14 Nov 23:46:12 - [info] [zigbee2mqtt-out:44a55c33.fa36e4] Published to mqtt topic: zigbee2mqtt/Lampe_Flur_EG_1/set : {"state":"OFF","transition":0}
14 Nov 23:46:29 - [info] [zigbee2mqtt-out:d22f84de.9897f8] Published to mqtt topic: zigbee2mqtt/Lampe_Flur_OG_3/set : {"battery":100,"linkquality":90,"occupancy":false,"voltage":3025,"transition":0}
14 Nov 23:46:29 - [info] [zigbee2mqtt-out:b176be8d.25674] Published to mqtt topic: zigbee2mqtt/Lampe_Flur_OG_3/set : {"state":"OFF","transition":0}
14 Nov 23:49:23 - [info] [zigbee2mqtt-out:858c1ce4.a855e] Published to mqtt topic: zigbee2mqtt/Lampe_Kueche_EG/set : {"state":"OFF","transition":0}
14 Nov 23:53:46 - [info] [zigbee2mqtt-out:858c1ce4.a855e] Published to mqtt topic: zigbee2mqtt/Lampe_Kueche_EG/set : {"state":"ON","brightness":30,"transition":0}
14 Nov 23:53:58 - [info] [zigbee2mqtt-out:6b3a43eb.d2edec] Published to mqtt topic: zigbee2mqtt/Lampe_Vorraum/set : {"state":"ON","brightness":30,"transition":0}
14 Nov 23:54:01 - [info] [zigbee2mqtt-out:44a55c33.fa36e4] Published to mqtt topic: zigbee2mqtt/Lampe_Flur_EG_1/set : {"state":"OFF","transition":0}
14 Nov 23:54:18 - [info] [zigbee2mqtt-out:858c1ce4.a855e] Published to mqtt topic: zigbee2mqtt/Lampe_Kueche_EG/set : {"state":"OFF","transition":0}
14 Nov 23:54:22 - [info] [zigbee2mqtt-out:6b3a43eb.d2edec] Published to mqtt topic: zigbee2mqtt/Lampe_Vorraum/set : {"state":"OFF","transition":0}
14 Nov 23:54:27 - [info] [zigbee2mqtt-out:6b3a43eb.d2edec] Published to mqtt topic: zigbee2mqtt/Lampe_Vorraum/set : {"state":"ON","brightness":30,"transition":0}
14 Nov 23:56:02 - [red] Uncaught Exception:
14 Nov 23:56:02 - [error] Error: read ECONNRESET
    at TLSWrap.onStreamRead (internal/stream_base_commons.js:209:20)

> node-red-docker@2.1.3 start /usr/src/node-red
> node $NODE_OPTIONS node_modules/node-red/red.js $FLOWS "--userDir" "/data"

14 Nov 23:56:03 - [info] 

Welcome to Node-RED
===================

14 Nov 23:56:03 - [info] Node-RED version: v2.1.3
14 Nov 23:56:03 - [info] Node.js  version: v14.18.1
14 Nov 23:56:03 - [info] Linux 4.18.0-305.3.1.el8.x86_64 x64 LE
14 Nov 23:56:03 - [info] Loading palette nodes
14 Nov 23:56:03 - [info] node-red-contrib-ccu version: 3.4.2
14 Nov 23:56:04 - [warn] ------------------------------------------------------
14 Nov 23:56:04 - [warn] [node-red-node-rbe/rbe] 'rbe' already registered by module node-red
14 Nov 23:56:04 - [warn] ------------------------------------------------------
14 Nov 23:56:04 - [info] Settings file  : /data/settings.js
14 Nov 23:56:04 - [info] Context store  : 'default' [module=localfilesystem]
14 Nov 23:56:04 - [info] User directory : /data
14 Nov 23:56:04 - [warn] Projects disabled : editorTheme.projects.enabled=false
14 Nov 23:56:04 - [info] Flows file     : /data/flows.json
14 Nov 23:56:04 - [info] Server now running at http://127.0.0.1:1880/
14 Nov 23:56:04 - [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.
---------------------------------------------------------------------

14 Nov 23:56:04 - [info] Starting flows
14 Nov 23:56:04 - [info] [ccu-connection:homematic-raspi] paramsets loaded from /data/paramsets.json
7

So the problem is a node not handling a TCP connection reset on a TLS connection.

But that is all we can say as that's the extent of the stack trace.

You will have to look at what nodes you are using to see it you can work out which it is.

If you can't work it out then using tcpdump to try and catch the reset packet might help. E.g.

8

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.