rdmtc / RedMatic

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

Nach einiger Zeit gibt es plötzlich Probleme #520

Open UserRG opened 2 years ago

UserRG commented 2 years ago

Hallo, ich habe das Problem, dass sich nach einiger Zeit die Fehler häufen. Es gibt Neustarts und ich habe das Gefühl, dass manche Dinge nicht mehr korrekt laufen. z.B. erhalte ich Meldungen wie " < BidCos-Wired setValue Error: XML-RPC fault: Failure" etc. Neulich las ich 28 Neustarts seit dem letzten Node-Red-Start. Ich habe zwar immer mal wieder etwas verändert. Vor allem habe ich die Prozesse schlanker gemacht. Habe quasi die "umständliche" Flowgestaltung aus meinen Anfangszeiten verbessert. Gibt es ein Speicherproblem etc.? Ich weiß mir leider keinen Rat. Es sind auch immer wieder andere Konfig-Nodes wie z.B. Alexa betroffen und stehen in den Logs. Aber eigentlich tut Alexa was sie soll... Ich habe bisher NodeRed immer neu installiert und musste dann eben alle Konfig-Nodes etc. nochmal anpassen. Das hat immer geholfen, aber kann ja eigentlich keine Dauerlösung sein. Die flow-Variablen etc. speichere ich alle auf einem USB-Stick an der CCU3. Der hatte sich allerdings auch schonmal verabschiedet, Konnte selbst mit dem PC nichts mehr öffnen. Ob das an zuvielen Zugriffen liegt, kann ich nicht beurteilen. Kann mal jemand über das Log schauen, vielleicht erkennt ihr was!? Danke. redmatic.2021-10-24T12 43 23.263Z.log.txt

djiwondee commented 2 years ago

Hallo @UserRG ,

speichere ich alle auf einem USB-Stick an der CCU3. Der hatte sich allerdings auch schonmal verabschiedet, ...

Ja, das ist leider ein lediges Thema. Wenn man die CCU nicht ordnungsgemäß runterfährt (z. B. Stromausfall), dann gehen ein paar Files auf dem USB-Sticks kaputt. Ggf. auch hier an eine regelmäßigen Backup denken. Auch empfehlenswert sind "Industrie-Klasse" Sticks: https://de.elv.com/apacer-industrie-usb-stick-eh353-16-gb-usb-30-ca-3000-pe-zyklen-251459

Ich habe mal ein bißchen in Dein Log geschaut. Solche Zeilen, wie

Oct 23 20:09:56 TaRoCCU3 daemon.warn node-red[12382]: [alexa-remote-account:30d9a58b.9f0542] failed to load routines: "no body"
Oct 23 20:19:15 TaRoCCU3 daemon.err node-red[12382]: [ccu-connection:localhost]     < BidCos-Wired setValue Error: XML-RPC fault: Failure
Oct 23 20:19:15 TaRoCCU3 daemon.err node-red[12382]: [ccu-connection:localhost] rpc > BidCos-Wired setValue ["HBW0000976:13","LEVEL",{"explicitDouble":0}] < Error: XML-RPC fault: Failure

deuten für mich schon darauf hin, dass Alexa hier ein Problem hat, mit der CCU zu kommunizieren.

Oct 23 00:39:54 TaRoCCU3 daemon.warn node-red[12382]: [alexa-remote-account:30d9a58b.9f0542] failed to load routines: "no body"
Oct 23 01:07:28 TaRoCCU3 daemon.err node-red[12382]: [alexa-remote-smarthome:TV aus] unexpected response layout: "{"controlResponses":[],"errors":[{"entity":{"entityId":"b957dcf7-ffd6-4acd-8d9b-518b219e7fdf","entityType":null},"code":"ENDPOINT_BUSY","message":null,"data":null}]}"
Oct 23 01:09:54 TaRoCCU3 daemon.warn node-red[12382]: [alexa-remote-account:30d9a58b.9f0542] failed to load routines: "no body"

oder auf fehlerhafte Alexa-Node-Konfiguration

Oder auch z. B. hier direkt nach dem automatischen Neustart von Node-red

Oct 23 23:21:23 TaRoCCU3 daemon.err node-red: Node-RED exited with non-zero exit status 1
Oct 23 23:21:23 TaRoCCU3 daemon.warn redmatic: Restarting Node-RED (2/2147483647)
Oct 23 23:21:36 TaRoCCU3 daemon.warn node-red[30550]: Projects disabled : editorTheme.projects.enabled=false
Oct 23 23:21:36 TaRoCCU3 daemon.err node-red: (node:30550) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
Oct 23 23:21:36 TaRoCCU3 daemon.err node-red: (Use `node --trace-deprecation ...` to show where the warning was created)
Oct 23 23:21:42 TaRoCCU3 daemon.err node-red[30550]: [time-inject:2f4b7dd7.a2864a] Day is today not in valid range. [5/1/2022]
Oct 23 23:21:42 TaRoCCU3 daemon.err node-red[30550]: [time-inject:3a5d44a5.a68dd4] Day is today not in valid range. [5/1/2022]
Oct 23 23:21:43 TaRoCCU3 daemon.warn node-red[30550]: [fritzbox-in:FritzBox Alina] Device not ready.
Oct 23 23:21:43 TaRoCCU3 daemon.warn node-red[30550]: [fritzbox-in:FritzBox Chris] Device not ready.
Oct 23 23:21:43 TaRoCCU3 daemon.warn node-red[30550]: [fritzbox-in:FritzBox Roli] Device not ready.
Oct 23 23:21:43 TaRoCCU3 daemon.warn node-red[30550]: [fritzbox-in:FritzBox Tanja] Device not ready.
Oct 23 23:21:52 TaRoCCU3 daemon.warn node-red[30550]: [alexa-remote-account:30d9a58b.9f0542] failed to load routines: "no body"
Oct 23 23:21:54 TaRoCCU3 daemon.warn node-red[30550]: [alexa-remote-account:30d9a58b.9f0542] failed to load routines: "no body"
Oct 23 23:22:01 TaRoCCU3 daemon.err node-red[30550]: [alexa-remote-account:30d9a58b.9f0542] Initialisation was aborted!
Oct 23 23:22:01 TaRoCCU3 daemon.err node-red: Unhandled rejection Error: no response timeout
Oct 23 23:22:01 TaRoCCU3 daemon.err node-red:     at Timeout._onTimeout (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-milight-2/node_modules/node-milight-promise/src/milight-v6-mixin.js:128:26)
Oct 23 23:22:01 TaRoCCU3 daemon.err node-red:     at listOnTimeout (internal/timers.js:554:17)
Oct 23 23:22:01 TaRoCCU3 daemon.err node-red:     at processTimers (internal/timers.js:497:7)
Oct 23 23:22:08 TaRoCCU3 daemon.err node-red: Unhandled rejection Error: no response timeout
Oct 23 23:22:08 TaRoCCU3 daemon.err node-red:     at Timeout._onTimeout (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-milight-2/node_modules/node-milight-promise/src/milight-v6-mixin.js:128:26)
Oct 23 23:22:08 TaRoCCU3 daemon.err node-red:     at listOnTimeout (internal/timers.js:554:17)
Oct 23 23:22:08 TaRoCCU3 daemon.err node-red:     at processTimers (internal/timers.js:497:7)

...gibt es ein Problem mit Alexa.

Ich selber nutze Alex gar nicht und kann folglich nicht wirklich viel weiter helfen. Vielleicht checkst Du mal

der Alexa-Nodes in Node-red und schaust Dir an, ob die Fehler direkt nach dem Neustart von Node-red veschwinden.

UserRG commented 2 years ago

Hi Roland, vielen Dank für Deine Beschreibung. Komischerweise macht Alexa nach wie vor was sie soll, daher fällt mir da nichts auf. Sie ist zwar gefühlt ein bisschen schwerfälliger geworden, aber sie führt alle Befehle aus. Daher ist die Kommunikation scheinbar in Ordnung. Ich habe die Version der Nodes schon gecheckt, bis auf die Fritz-Box waren alle aktuell. Vor allem Alexa.

Ich habe NodeRed nach der Aktualisierung der Fritz-Box-Nodes neu gestartet und erhielt wieder zahlreiche Fehler im Debug-Fenster: z.B. Error: unknown variable SV_Tageshoechsttemperatur Error: overwritten setVariable failed. variables still not known after timeout < BidCos-Wired setValue Error: XML-RPC fault: Failure rpc > BidCos-Wired setValue ["HBW0000XXX:13","LEVEL",{"explicitDouble":0}] < Error: XML-RPC fault: Failure Error: xml in rega response missing at Rega._parseResponse (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-ccu/node_modules/homematic-rega/index.js:60:35) at Request._callback (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-ccu/node_modules/homematic-rega/index.js:111:26) at Request.self.callback (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-ccu/node_modules/request/request.js:185:22) at Request.emit (events.js:315:20) at Request. (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-ccu/node_modules/request/request.js:1154:10) at Request.emit (events.js:315:20) at IncomingMessage. (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-ccu/node_modules/request/request.js:1076:12) at Object.onceWrapper (events.js:421:28) at IncomingMessage.emit (events.js:327:22) at endReadableNT (internal/streams/readable.js:1327:12) at processTicksAndRejections (internal/process...

(Die letzte lange Fehlermeldung kam nach dem letzten Neustart. Die Pfade verweisen allerdings nicht auf den USB-Stick. Da hat es wohl etwas in den Redmatic-Dateien durcheinander gebracht...?

Da wird mir wohl nichts anders als eine Neuinstallation übrig bleiben. Wobei die Daten doch eigentlich auf die interne SD-Karte (?) geschrieben werden. Ich habe einen USB-Stick nur für die Datenspeicherung (z.B. Textdateien für Statistiken, Bilder für Dashboard). Die Daten werden allerdings wohl zu oft beschrieben. z.B. Stromverbrauch, der wird alle 20 Sekunden aktualisiert. Das scheint wohl zu heftig für den USB-Stick. Allerdings sind die Daten noch da. Die Charts werden alle korrekt aufgebaut. Jedenfalls fällt mir dabei nichts auf. Wie kann man das denn "vernünftig" lösen? Wenn das System so anfällig ist, wollte ich genau deshalb einen externen Speicher nutzen. Den kann ich relativ problemlos tauschen. Den USB-Stick werde ich mir mal bestellen. Danke für den Tipp.

Stromausfall hatten wir m.E. nicht. Daran sollte es nicht liegen.

UserRG commented 2 years ago

Update: Habe Redmatic inzwischen deinsgtalliert und neu aufgespielt. Habe auch den USB-Stick getauscht und statt dessen eine SD-Karte mit USB-Adapter verwendet. Aber die Fehlermeldungen sind nach wie vor noch da. Habe den localhost mal auf "Default" und mal auf "File" gestellt. Inzwischen erkennt er einige Variablen wieder. Allerdings ist das System trotz dem Neustart total langsam und generiert immer wieder Fehler:

Error: XML-RPC fault: Failure

Error: xml in rega response missing at Rega._parseResponse (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-ccu/node_modules/homematic-rega/index.js:60:35) at Request._callback (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-ccu/node_modules/homematic-rega/index.js:111:26) at Request.self.callback (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-ccu/node_modules/request/request.js:185:22) at Request.emit (events.js:315:20) at Request. (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-ccu/node_modules/request/request.js:1154:10) at Request.emit (events.js:315:20) at IncomingMessage. (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-ccu/node_modules/request/request.js:1076:12) at Object.onceWrapper (events.js:421:28) at IncomingMessage.emit (events.js:327:22) at endReadableNT (internal/streams/readable.js:1327:12) at processTicksAndRejections (internal/process...

Alles andere scheint zu funktionieren. z.B. Licht schalten per Dashboard bzw. Alexa-Befehl klappt. Allerdings auf Grund des Auslastung manchmal etwas zeitverzögert...

Es scheint ja ein Fehler im Node-Red-CCU-Modul zu geben. Kann es sein, dass ein paar interne Files auf der Platte defekt sind? D.h. Werksreset und komplett neu aufspielen?

djiwondee commented 2 years ago

Hallo @UserRG,

Kann es sein, dass ein paar interne Files auf der Platte defekt sind? D.h. Werksreset und komplett neu aufspielen?

Wenn das wirklich der Fall ist, dann würde ich überlegen, die CCU auszutauschen. Da scheint mir dann dort eher ein Hardware-Problem vorzuliegen.

Fehler im Node-Red-CCU-Modul

Bitte insb. aufpassen, wenn Du Nodes aktualisierst. Bitte nicht einfach Update drücken, sondern unbedingt vorher prüfen, ob die aktualisierbaren Nodes auch mit dem Release-Stand von node-red in Redmatic laufen. Latest Release von Node-red ist.

UserRG commented 2 years ago

Was mir noch aufgefallen ist: Die Fehler verschwinden... d.h. es scheint so, als wenn die CCU "zu langsam" ist, die Informationen zu liefern... Nach einigen Minuten, aktualisieren sich die Systemvariablen auch wieder und werden auch gefunden. Nur die inject-Nodes, die nach dem Neustart losrennen laufen auf Fehler, da die Systemvariablen nicht bekannt sind etc. Ich merke die Verzögerung auch an manchen Befehlen... Ich werde nochmal den BUS-Traffic loggen, evtl. gibts da ein defektes Gerät. Sonst muss ich wohl wirklich mal einen Werksreset machen. Backup habe ich genug... Sieht aktuell jedenfalls nach einem Problem auf der CCU3 aus... Evtl. wirklich ein paar defekte Dateien

djiwondee commented 2 years ago

@UserRG

es scheint so, als wenn die CCU "zu langsam" ist

ha! Guter Punkt. Das erlebe ich auch hin und wieder. Letzte Woche z. B. war die CCU mit Firmwareupdates meiner zahlreichen HmIP-BSM's beschäftigt. Gut möglich, dass hier der ein oder andere Timeout zuschlägt.

UserRG commented 2 years ago

Hallo Zusammen, ich habe inzwischen das Bus-Protokoll von einem Profi bei HausBus.de prüfen lassen. Sie sagen keine Auffälligkeiten. Ich habe inzwischen ein Werksreset gemacht und das Backup neu eingespielt. Problem ist leider noch immer da. Ich habe auch die Haus-Bus Aktoren (weil Systemfremd) mal gelöscht und geschaut was passiert... Aber Problem bleibt. Es gibt jede Menge Fehlermeldungen und dann stabilisiert sich das System irgendwann.

Ich musste nach dem Werksreset auch NodeRed wieder neu installieren (Version 7.2.1). Trotzdem erhalte ich beim Deployen (Voll oder Flows der geänderten Nodes) folgende Fehlermeldung:

Error: xml in rega response missing at Rega._parseResponse (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-ccu/node_modules/homematic-rega/index.js:60:35) at Request._callback (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-ccu/node_modules/homematic-rega/index.js:111:26) at Request.self.callback (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-ccu/node_modules/request/request.js:185:22) at Request.emit (events.js:315:20) at Request. (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-ccu/node_modules/request/request.js:1154:10) at Request.emit (events.js:315:20) at IncomingMessage. (/usr/local/addons/redmatic/var/node_modules/node-red-contrib-ccu/node_modules/request/request.js:1076:12) at Object.onceWrapper (events.js:421:28) at IncomingMessage.emit (events.js:327:22) at endReadableNT (internal/streams/readable.js:1327:12) at processTicksAndRejections (internal/process...

Da passt doch was nicht mit der Node-Red installation. Diese ist aber wie gesagt "nagelneu"... Jemand eine Idee? Ich bin langsam am Ende...

UserRG commented 2 years ago

Hallo Zusammen, ich habe mir jetzt mal die Mühe gemacht und meine ganze Homatic-Installation neu aufzusetzen... Nach ca 20 (!) Stunden hatte ich alles wieder am Laufen - noch ohne Redmatic. Nachdem ich auch Redmatic installiert hatte, kamen die Fehlermeldungen allerdings wieder... Es sieht so aus, als wenn beim Deploy aller Flows die Daten nicht zeitgerecht an Redmatic übermittelt werden. Evtl. habe ich aber noch eine Idee, da ich auch die Homematic-Scripte auf Redmatic laufen lasse, immer dann, wenn sich ein bestimmtes Gewerk (Licht / Fenster) ändert. Ich habe die Befürchtung, dass nach dem Deploy alle Aktoren ihren Status neu melden und daher die Scripte zig mal laufen, die wiederum ja auch alle Stati aller Geräte abfragen. Und das sind bei mir schon ein paar Kanäle... Kann man das irgendwie abfangen? So ähnlich wie beim CCU-Neustart durch eine Variable? (Was leider durch die verspätete Übermittlung der Daten im Moment auch nicht funktioniert). Wenn sich der Datenstau aufgelöst hat, scheint auch alles wieder normal zu funktionieren. Auch alle Variablen sind plötzlich wieder vorhanden. Ergo nur ein Zeitproblem? Startet Redmatic für große Installationen zu früh? Kann ich das selbst hinauszögern?

Sineos commented 2 years ago

Schwer zu sagen. Die Redmatic Benutzer, die ich kenne, haben ihre gesamte Logik in die Redmatic verlagert und verzichten auf Scripte. Scheint hier auch zu komischem Verhalten kommen zu können: https://github.com/jens-maus/RaspberryMatic/issues/1583