rdmtc / RedMatic

Node-RED packaged as Addon for the Homematic CCU3 and RaspberryMatic 🤹‍♂️
Apache License 2.0
535 stars 47 forks source link

[FRAGE] /var/log/messages und tail-node verursacht node-red crash #496

Open djiwondee opened 3 years ago

djiwondee commented 3 years ago

Hallo,

in meinem Redmatic-Setup habe ich aus dem redmatic WIKI diesen Flow für die Fehlerüberwachung der CCU implementiert. Seit neuestem beobachte ich Abstürze von Node-red, verursacht durch den darin verwendeten node-red-node-tail. Dazu habe ich hierzu schon ein Issue aufgemacht, da der node-red-node-tail hier wohl den Fehler beim Datei-Zugriff auf /var/log/messages nicht abfängt.

Apr 13 11:55:30 {{HOSTNAME}} node-red[16624]: [tail:e84c1031.b43f2] size check for /var/log/messages failed: Error: ENOENT: no such file or directory, stat '/var/log/messages'
Apr 13 11:55:30 {{HOSTNAME}} node-red: 13 Apr 11:55:30 - [red] Uncaught Exception:
Apr 13 11:55:30 {{HOSTNAME}} node-red: 13 Apr 11:55:30 - Error: ENOENT: no such file or directory, stat '/var/log/messages'
Apr 13 11:55:30 {{HOSTNAME}} node-red:     at Object.statSync (fs.js:1086:3)
Apr 13 11:55:30 {{HOSTNAME}} node-red:     at Tail.latestPosition (/usr/local/addons/redmatic/var/node_modules/node-red-node-tail/node_modules/tail/lib/tail.js:81:23)
Apr 13 11:55:30 {{HOSTNAME}} node-red:     at Tail.change (/usr/local/addons/redmatic/var/node_modules/node-red-node-tail/node_modules/tail/lib/tail.js:125:22)
Apr 13 11:55:30 {{HOSTNAME}} node-red:     at Tail.watchEvent (/usr/local/addons/redmatic/var/node_modules/node-red-node-tail/node_modules/tail/lib/tail.js:188:18)
Apr 13 11:55:30 {{HOSTNAME}} node-red:     at FSWatcher.<anonymous> (/usr/local/addons/redmatic/var/node_modules/node-red-node-tail/node_modules/tail/lib/tail.js:149:97)
Apr 13 11:55:30 {{HOSTNAME}} node-red:     at FSWatcher.emit (events.js:315:20)
Apr 13 11:55:30 {{HOSTNAME}} node-red:     at FSEvent.FSWatcher._handle.onchange (internal/fs/watchers.js:186:12)
Apr 13 11:55:31 {{HOSTNAME}} node-red: Node-RED exited with non-zero exit status 1
Apr 13 11:55:31 {{HOSTNAME}} redmatic: Restarting Node-RED (½)

Ist so das Problem schon mal von jemanden beobachtet worden? Irgendwelche Ideen, ob es hier zu einem simultanen Zugriff zwischen redmatic logging und node-red kommt, was mir beim Feedback an @dceeyay helfen könnte? Kann es ein Problem auf unterster Dateisystem-Ebene sein? Wann macht redmatic ein log-rotation von /var/log/messages ?

Vielen Dank im Voraus!

Sineos commented 3 years ago

Komisch, ich benutzte diesen Flow schon seit 2 Jahren und ja, die tail-node wirft beim Logrotate einen Fehler, aber mir ist deswegen noch nie NR abgeschmiert.

Bei mir sieht es aber seit neuestem so aus, dass die tail-node nach diesem Fehler in einen performanten Error Modus geht und sich daraus auch nicht selbst erholt. Muss ich aber noch verifizieren.

panotwinjuergen commented 3 years ago

Hallo,

Ist so das Problem schon mal von jemanden beobachtet worden?

Ja, gerade heute Nacht habe ich das ebenfalls beobachtet:

Apr 16 02:37:21 {{HOSTNAME}} daemon.err node-red[22190]: [tail:f81692a9.586f08] size check for /var/log/messages failed: Error: ENOENT: no such file or directory, stat '/var/log/messages'
Apr 16 02:37:21 {{HOSTNAME}} daemon.err node-red: 16 Apr 02:37:21 - [red] Uncaught Exception:
Apr 16 02:37:21 {{HOSTNAME}} daemon.err node-red: 16 Apr 02:37:21 - Error: ENOENT: no such file or directory, stat '/var/log/messages'
Apr 16 02:37:21 {{HOSTNAME}} daemon.err node-red:     at Object.statSync (fs.js:1086:3)
Apr 16 02:37:21 {{HOSTNAME}} daemon.err node-red:     at Tail.latestPosition (/usr/local/addons/redmatic/lib/node_modules/node-red/node_modules/tail/lib/tail.js:74:23)
Apr 16 02:37:21 {{HOSTNAME}} daemon.err node-red:     at Tail.change (/usr/local/addons/redmatic/lib/node_modules/node-red/node_modules/tail/lib/tail.js:118:22)
Apr 16 02:37:21 {{HOSTNAME}} daemon.err node-red:     at Tail.watchEvent (/usr/local/addons/redmatic/lib/node_modules/node-red/node_modules/tail/lib/tail.js:183:18)
Apr 16 02:37:21 {{HOSTNAME}} daemon.err node-red:     at FSWatcher.<anonymous> (/usr/local/addons/redmatic/lib/node_modules/node-red/node_modules/tail/lib/tail.js:143:101)
Apr 16 02:37:21 {{HOSTNAME}} daemon.err node-red:     at FSWatcher.emit (events.js:315:20)
Apr 16 02:37:21 {{HOSTNAME}} daemon.err node-red:     at FSEvent.FSWatcher._handle.onchange (internal/fs/watchers.js:186:12)
Apr 16 02:37:21 {{HOSTNAME}} daemon.err node-red: Node-RED exited with non-zero exit status 1

Anfang der Woche war mir RedMatic schon mal abgeschmiert, da bin ich dem Thema aber noch nicht nachgegangen. Ich hatte jetzt gerade letztes Wochenende die Version 7.2.1 installiert. Davor war ich über ein halbes Jahr stabil auf einer älteren Version.

djiwondee commented 3 years ago

Habe die tail-node seit einer Woche abgeklemmt und habe seit dem wieder Ruhe damit. Funktioniert halt das Dashlog so nicht mehr.

Ich schicke die CCU-Meldungen auch an einen separat laufenden Raspi (syslog-server) und werde da mal zur Verifikation das CCU-log mit der tail-node anzapfen. Mal sehen, ob sowas dann hier auch passiert.

Sineos commented 3 years ago

Ich hab bei festgestellt, dass ich noch eine "alte" Version (0.1.0) der tail-node am Laufen habe. Die crasht bei mir nicht.

djiwondee commented 3 years ago

Nach eine weiteren gute Woche Test mit der tail-node und deren Zugriff auf einen separat laufenden Raspi, der per syslog-server ein CCU-log schreibt, kann ich sagen, dass es hier keine Abstürze gab. Hat die CCU vielleicht betriebssystemseitig ein Problem mit dem File und dem tail darauf?

djiwondee commented 2 years ago

Ich betreibe den auf Version 0.1.1 downgraded tail-node seit ein paar Wochen im oben erwähnten Szenario/node-red-flow. Das Problem ist bis jetzt nicht mehr aufgetreten.

Habe mal bei dem issue angefragt, worin der Unterschied zwischen Version 0.1.1 und 0.3.1 in Bezug auf dieses Problem bestehen könnte.

Auf dem unter dem vom 26. Apr. angefügten Kommentar (s. o.) läuft nach wie vor die 0.3.1 tail-node, jedoch bisher auch ohne Crash dadurch verursacht. So ganz zusammenhanglos zum CCU Access zu `/var/log/messages´ ist das Problem wohl eher nicht.