#debuggen

Nächtliches Remote-Debugging am Telefon

Das Riesenmaschine-Blog ist wenige Wochen alt. (Zum Aufschreibezeitpunkt dieses Beitrags, 2022, heißt es schon lange “der Blog”, aber in der hier nachträglich dokumentierten Vergangenheit war das noch nicht so.) Ich habe die Blogsoftware selbst geschrieben, weil wir zu mehreren daran arbeiten wollen und es entweder keine fertige Software für gemeinsames Bloggen gibt oder ich sie nicht finde. Zu diesem Zweck habe ich meinen schon vorhandenen Code für eine News-Seite der “Zentralen Intelligenz Agentur” umgebaut.

Während ich mit meinen Eltern unterwegs zu einer sehr alten und sehr entfernten Verwandten in der Slowakei bin, geht die Riesenmaschine kaputt. Auf welchem Weg ich davon erfahre, ist nicht mehr zu rekonstrieren, vermutlich per SMS. Die anderen Beteiligten können keine neuen Beiträge mehr schreiben. Das ist blöd, weil ich noch mehrere Tage unterwegs sein werde, keinen Laptop dabei habe, und selbst wenn ich einen hätte, gäbe es in der Pension in Niederösterreich, in der ich gerade in einem Zimmer mit Schnitzkruzifix-Deko im Bett liege, kein Internet.

Ich rufe Jan Bölsche an und gebe ihm meine FTP-Zugangsdaten zum Server (die ich auswendig weiß, weil mein Passwort eher nicht so gut ist). Ich beschreibe ihm, welche Dateien ungefähr wo liegen und in welchen davon der Fehler möglicherweise stecken könnte. Wie lange wir telefonieren und wie schwer es ist, den Fehler zu finden und zu beheben, weiß ich 2022 nicht mehr. (Ich besitze noch alle Telefonrechnungen seit immer und werde die Gesprächsdauer eines Tages nachreichen.) Jan sagt am Ende des Telefonats großzügig, der Code sei gar nicht SO schlecht gewesen und zumindest einigermaßen übersichtlich. 

Er war aber schon ziemlich schlecht, denn die Riesenmaschine ist nur kaputtgegangen, weil nicht mehr Juli ist. Die Blogbeiträge stecken nicht wie anderswo üblich in einer Datenbank, sondern in Textdateien. Und mein Blog-Code erwartet in einem neuen Monat, dass es zu diesem Monat ein neues Verzeichnis für diese Dateien gibt, das in diesem Fall “08” heißen müsste. Das Verzeichnis wird aber nicht automatisch angelegt. In den ersten beiden Monaten der Blog-Existenz war das egal, weil ich der Maschine bei der Arbeit zugesehen und alle Probleme gleich am laufenden System behoben habe.

Jan brauchte also nur eine Datei namens “08” am richtigen Ort anzulegen, damit alles wieder funktionierte. Irgendwann später habe ich dieses Problem sogar grundsätzlich behoben, aber nur für die Monate. Das Verzeichnis für ein neues Jahr musste ich in der Riesenmaschine viele Jahre lang von Hand anlegen. Vielleicht ist es sogar heute immer noch so.

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.

Kleine Facebook-Hilfe: Linktexte nachträglich ändern – Link-Debugger

Das ist sicherlich vielen schon passiert: Sie haben auf Facebook einen Link aus Ihrem Blog oder Ihrer Webseite gepostet und haben im Nachhinein die Überschrift des Textes oder das Bild in Ihrem Blog geändert. Nun hat sich aber Facebook mit dem ersten Post die Informationen bereits im Zwischenspeicher abgelegt und zieht beim erneuten Teilen immer wieder diese ursprünglichen Informationen zur…