#fehlerloggen

Im vorherigen Beitrag habe ich dir gezeigt, wie du Fehler und Statusänderungen in Node-RED mit einer Catch- beziehungsweise Status-Node erkennst und anschließend über eine Debug-Node ausgibst.

Doch was passiert, wenn ein Flow unbeaufsichtigt läuft und du einen Fehler erst Stunden oder Tage später bemerkst? In diesem Fall reicht die Ausgabe im Debug-Bereich nicht aus. Damit sich die Ursache im Nachhinein nachvollziehen lässt, sollten wichtige Meldungen dauerhaft in einer Logdatei gespeichert werden.

https://youtu.be/U-w314Y3hc0

In diesem Beitrag zeige ich dir deshalb, wie du Fehler mit den Bordmitteln von Node-RED in eine Logdatei schreibst. Anschließend stelle ich dir eine eigene Logger-Node vor, die dir viele wiederkehrende Arbeitsschritte abnimmt. Sie lässt sich flexibel konfigurieren und sorgt dafür, dass deine Logeinträge einheitlich und übersichtlich gespeichert werden.

Praxisbeispiel: Ausfälle des MQTT-Brokers protokollieren

Als Beispiel verwenden wir erneut die Überwachung eines MQTT-Brokers. Dieser Anwendungsfall ist besonders praxisnah, da ein Broker in vielen IoT- und Smart-Home-Projekten eine zentrale Rolle übernimmt.

Der Node-RED Flow erkennt Statusänderungen der MQTT-Out-Node und unterscheidet zwischen einer unterbrochenen und einer wiederhergestellten Verbindung. Node-RED Flow zum Importieren }, { "id": "7d1c53815cc56777", "type": "inject", "z": "8c105c2e4a45c10e", "name": "", "props": , "repeat": "", "crontab": "", "once": false, "onceDelay": 0.1, "topic": "", "payload": "", "payloadType": "date", "x": 120, "y": 120, "wires": ] }, { "id": "2e69599beb37b62d", "type": "mqtt out", "z": "8c105c2e4a45c10e", "name": "", "topic": "/beispiel/text", "qos": "", "retain": "", "respTopic": "", "contentType": "", "userProps": "", "correl": "", "expiry": "", "broker": "2dc0a4b70d96ebb5", "x": 270, "y": 120, "wires": }, { "id": "7113958f4b37c1cb", "type": "status", "z": "8c105c2e4a45c10e", "name": "", "scope": , "x": 100, "y": 260, "wires": ] }, { "id": "5edda4976ee422cb", "type": "debug", "z": "8c105c2e4a45c10e", "name": "Ausgabe der Statusänderung", "active": true, "tosidebar": true, "console": false, "tostatus": false, "complete": "true", "targetType": "full", "statusVal": "", "statusType": "auto", "x": 880, "y": 260, "wires": }, { "id": "99ee96e58880f9fd", "type": "function", "z": "8c105c2e4a45c10e", "name": "Statusmeldung für "nicht verbunden" erstellen", "func": "msg.payload = "Die Verbindung zum MQTT Broker ist unterbrochen!";nreturn msg;", "outputs": 1, "timeout": 0, "noerr": 0, "initialize": "", "finalize": "", "libs": , "x": 540, "y": 220, "wires": ] }, { "id": "895156e15c61ffb6", "type": "switch", "z": "8c105c2e4a45c10e", "name": "", "property": "status.text", "propertyType": "msg", "rules": , "checkall": "false", "repair": false, "outputs": 2, "x": 250, "y": 260, "wires": , ] }, { "id": "03e0329660e4c26b", "type": "function", "z": "8c105c2e4a45c10e", "name": "Statusmeldung für "verbunden" erstellen", "func": "msg.payload = "Die Verbindung zum MQTT Broker wurde hergestellt!";nreturn msg;", "outputs": 1, "timeout": 0, "noerr": 0, "initialize": "", "finalize": "", "libs": , "x": 540, "y": 300, "wires": ] }, { "id": "0ffb9997f320e647", "type": "debug", "z": "8c105c2e4a45c10e", "name": "debug 1", "active": true, "tosidebar": true, "console": false, "tostatus": false, "complete": "true", "targetType": "full", "statusVal": "", "statusType": "auto", "x": 240, "y": 360, "wires": }, { "id": "2dc0a4b70d96ebb5", "type": "mqtt-broker", "name": "", "broker": "mosquitto", "port": 1883, "clientid": "", "autoConnect": true, "usetls": false, "protocolVersion": 4, "keepalive": 60, "cleansession": true, "autoUnsubscribe": true, "birthTopic": "", "birthQos": "0", "birthRetain": "false", "birthPayload": "", "birthMsg": {}, "closeTopic": "", "closeQos": "0", "closeRetain": "false", "closePayload": "", "closeMsg": {}, "willTopic": "", "willQos": "0", "willRetain": "false", "willPayload": "", "willMsg": {}, "userProps": "", "sessionExpiry": "" } ]

Fällt der MQTT-Broker aus, können angeschlossene Geräte und Anwendungen keine Nachrichten mehr austauschen. Läuft der Node-RED-Flow unbeaufsichtigt, bemerken wir die Unterbrechung möglicherweise erst deutlich später. Eine dauerhaft gespeicherte Logdatei hilft uns dabei, nachzuvollziehen, wann die Verbindung unterbrochen und zu welchem Zeitpunkt sie wiederhergestellt wurde.

Der Ausgangspunkt ist der Flow aus dem vorherigen Beitrag. Eine Status-Node überwacht den Verbindungszustand der MQTT-Out-Node. Die nachfolgende Switch-Node unterscheidet zwischen den beiden Statuswerten „verbunden“ und „nicht verbunden“.

Abhängig vom erkannten Zustand erzeugen zwei Function-Nodes eine verständliche Meldung:

Die Verbindung zum MQTT-Broker ist unterbrochen!

beziehungsweise:

Die Verbindung zum MQTT-Broker wurde hergestellt!

Bisher werden diese Meldungen lediglich über eine Debug-Node ausgegeben. Im nächsten Schritt erweitern wir den Flow so, dass jede Statusänderung zusätzlich mit einem Zeitstempel in einer Logdatei gespeichert wird.

Damit können wir später beispielsweise folgende Fragen beantworten:

- Wann ist der MQTT-Broker ausgefallen? - Wie lange war die Verbindung unterbrochen? - Wann konnte Node-RED die Verbindung wiederherstellen? - Tritt der Fehler regelmäßig zu einer bestimmten Uhrzeit auf?

Gerade bei einem dauerhaft laufenden Node-RED-System ist diese Protokollierung deutlich hilfreicher als eine reine Ausgabe im Debug-Bereich.

MQTT-Status mit Node-RED-Bordmitteln protokollieren

Für die erste Lösung verwenden wir ausschließlich Nodes, die bereits in Node-RED enthalten sind. Zusätzliche Erweiterungen müssen dafür nicht installiert werden.

Node-RED Flow zum Importieren }, { "id": "7d1c53815cc56777", "type": "inject", "z": "8c105c2e4a45c10e", "name": "", "props": , "repeat": "", "crontab": "", "once": false, "onceDelay": 0.1, "topic": "", "payload": "", "payloadType": "date", "x": 120, "y": 40, "wires": ] }, { "id": "2e69599beb37b62d", "type": "mqtt out", "z": "8c105c2e4a45c10e", "name": "", "topic": "/beispiel/text", "qos": "", "retain": "", "respTopic": "", "contentType": "", "userProps": "", "correl": "", "expiry": "", "broker": "2dc0a4b70d96ebb5", "x": 270, "y": 40, "wires": }, { "id": "7113958f4b37c1cb", "type": "status", "z": "8c105c2e4a45c10e", "name": "", "scope": , "x": 100, "y": 140, "wires": ] }, { "id": "5edda4976ee422cb", "type": "debug", "z": "8c105c2e4a45c10e", "name": "Ausgabe der Statusänderung", "active": true, "tosidebar": true, "console": false, "tostatus": false, "complete": "true", "targetType": "full", "statusVal": "", "statusType": "auto", "x": 1260, "y": 120, "wires": }, { "id": "99ee96e58880f9fd", "type": "function", "z": "8c105c2e4a45c10e", "name": "Statusmeldung für "nicht verbunden" erstellen", "func": "msg.payload = "Die Verbindung zum MQTT Broker ist unterbrochen!";nmsg.logLevel = "ERROR";nreturn msg;", "outputs": 1, "timeout": 0, "noerr": 0, "initialize": "", "finalize": "", "libs": , "x": 540, "y": 100, "wires": ] }, { "id": "895156e15c61ffb6", "type": "switch", "z": "8c105c2e4a45c10e", "name": "", "property": "status.text", "propertyType": "msg", "rules": , "checkall": "false", "repair": false, "outputs": 3, "x": 250, "y": 140, "wires": , , ] }, { "id": "03e0329660e4c26b", "type": "function", "z": "8c105c2e4a45c10e", "name": "Statusmeldung für "verbunden" erstellen", "func": "msg.payload = "Die Verbindung zum MQTT Broker wurde hergestellt!";nmsg.logLevel = "INFO";nreturn msg;", "outputs": 1, "timeout": 0, "noerr": 0, "initialize": "", "finalize": "", "libs": , "x": 540, "y": 220, "wires": ] }, { "id": "ae0e3cd59331728d", "type": "function", "z": "8c105c2e4a45c10e", "name": "LogMessage erstellen", "func": "function createGermanTimestamp() {n const now = new Date();nn const day = String(now.getDate()).padStart(2, "0");n const month = String(now.getMonth() + 1).padStart(2, "0");n const year = now.getFullYear();nn const hours = String(now.getHours()).padStart(2, "0");n const minutes = String(now.getMinutes()).padStart(2, "0");n const seconds = String(now.getSeconds()).padStart(2, "0");n const milliseconds = String(now.getMilliseconds()).padStart(3, "0");nn return `${day}.${month}.${year} ${hours}:${minutes}:${seconds}.${milliseconds}`;n}nnlet timestamp = createGermanTimestamp();nmsg.payload = timestamp + " " + msg.payload;nreturn msg;", "outputs": 1, "timeout": 0, "noerr": 0, "initialize": "", "finalize": "", "libs": , "x": 980, "y": 160, "wires": ] }, { "id": "e42770381c324907", "type": "file", "z": "8c105c2e4a45c10e", "name": "", "filename": "/data/sample.log", "filenameType": "str", "appendNewline": true, "createDir": false, "overwriteFile": "false", "encoding": "none", "x": 1220, "y": 180, "wires": ] }, { "id": "da8de8fd48fad8c1", "type": "function", "z": "8c105c2e4a45c10e", "name": "Statusmeldung für "Verbindung wird hergestellt" erstellen", "func": "msg.payload = "Die Verbindung zum MQTT Broker wird hergestellt!";nmsg.logLevel = "INFO";nreturn msg;", "outputs": 1, "timeout": 0, "noerr": 0, "initialize": "", "finalize": "", "libs": , "x": 590, "y": 160, "wires": ] }, { "id": "2dc0a4b70d96ebb5", "type": "mqtt-broker", "name": "", "broker": "mosquitto", "port": 1883, "clientid": "", "autoConnect": true, "usetls": false, "protocolVersion": 4, "keepalive": 60, "cleansession": true, "autoUnsubscribe": true, "birthTopic": "", "birthQos": "0", "birthRetain": "false", "birthPayload": "", "birthMsg": {}, "closeTopic": "", "closeQos": "0", "closeRetain": "false", "closePayload": "", "closeMsg": {}, "willTopic": "", "willQos": "0", "willRetain": "false", "willPayload": "", "willMsg": {}, "userProps": "", "sessionExpiry": "" } ]

Die Status-Node überwacht den Verbindungszustand der MQTT-Out-Node. Sobald sich der Status ändert, wird eine Nachricht an die Switch-Node übergeben. Diese unterscheidet in unserem Beispiel zwischen drei möglichen Zuständen:

- Verbindung unterbrochen - Verbindung wird hergestellt - Verbindung hergestellt

Für jeden Zustand wird eine eigene Function-Node verwendet. Dort erzeugen wir eine verständliche Meldung und ergänzen zusätzlich ein Log-Level.

Bei einer unterbrochenen Verbindung verwenden wir das Log-Level ERROR:

msg.payload = "Die Verbindung zum MQTT-Broker ist unterbrochen!"; msg.logLevel = "ERROR"; return msg;

Während Node-RED versucht, die Verbindung erneut herzustellen, verwenden wir das Log-Level INFO:

msg.payload = "Die Verbindung zum MQTT-Broker wird hergestellt!"; msg.logLevel = "INFO"; return msg;

Auch die erfolgreich wiederhergestellte Verbindung wird als Information protokolliert:

msg.payload = "Die Verbindung zum MQTT-Broker wurde hergestellt!"; msg.logLevel = "INFO"; return msg;

Alle drei Nachrichten werden anschließend an dieselbe Function-Node weitergeleitet. Diese ergänzt einen Zeitstempel mit Millisekunden und erzeugt daraus einen einheitlichen Logeintrag.

function createGermanTimestamp() { const now = new Date(); const day = String(now.getDate()).padStart(2, "0"); const month = String(now.getMonth() + 1).padStart(2, "0"); const year = now.getFullYear(); const hours = String(now.getHours()).padStart(2, "0"); const minutes = String(now.getMinutes()).padStart(2, "0"); const seconds = String(now.getSeconds()).padStart(2, "0"); const milliseconds = String(now.getMilliseconds()).padStart(3, "0"); return `${day}.${month}.${year} ${hours}:${minutes}:${seconds}.${milliseconds}`; } const timestamp = createGermanTimestamp(); msg.payload = `${timestamp} ${msg.payload}`; return msg;

Die fertige Meldung wird anschließend gleichzeitig an eine Debug-Node und eine File-Node übergeben. Die Debug-Node hilft uns während der Entwicklung, während die File-Node den Eintrag dauerhaft in der Datei /data/sample.log speichert.

In der Write-File-Node geben wir den vollständigen Pfad an, unter dem die Logdatei gespeichert werden soll. Dieser setzt sich aus dem Zielverzeichnis und dem Dateinamen zusammen.

Da ich Node-RED in einem Docker-Container betreibe, verwende ich das Verzeichnis /data/. Als Dateinamen wähle ich für dieses Beispiel zunächst sample.log.

Der vollständige Pfad lautet damit: /data/sample.log

Das Verzeichnis /data/ wird bei einer typischen Node-RED-Docker-Installation für persistente Daten verwendet. Voraussetzung ist, dass es als Volume eingebunden wurde. Dadurch bleibt die Logdatei auch erhalten, wenn der Container neu gestartet oder neu erstellt wird.

Die Option zum Anhängen an eine bestehende Datei muss aktiviert sein. Andernfalls würde die Logdatei bei jeder neuen Meldung überschrieben werden. Außerdem sollte nach jedem Eintrag automatisch ein Zeilenumbruch ergänzt werden.

Logdateien automatisch nach Datum aufteilen

Bisher werden alle Meldungen in dieselbe Datei geschrieben: /data/sample.log

Bei einem dauerhaft laufenden Node-RED-System kann diese Datei mit der Zeit jedoch sehr groß und unübersichtlich werden. Außerdem ist es schwieriger, gezielt nach Ereignissen eines bestimmten Tages zu suchen.