Bug Report (Priorität: niedrig) - MQTT Gateway stoppt - Loxberry 3.0.0.6

[cainam24]

Hallo zusammen,

bevor ich mein Problem schildere, möchte ich mich bei allen, die an diesem Projekt mitwirken, bedanken. Ihr macht einen tollen Job.

Systembeschreibung:
* Ich habe Loxberry in Version 3.0.0.6 in Proxmox aufgesetzt (DietPi v8.18.2).
* Ich habe einen eigenen MQTT Server im Netz und nutze den Mosquitto des Loxberrys nicht.
* Ich habe einige selbstgeschriebene Services in verschiedenen VMs laufen. Ich nutze MQTT, um Daten zwischen den Services auszutauschen.
* Der Loxberry ist ebenfalls mit dem MQTT Server verbunden.

Dies lief nun einige Monate sehr gut - bis vor drei Tagen.
Am Wochenende ist dann das erste Mal das MQTT Gateway ausgefallen. Und seit dem passiert das alle 12 - 36 Stunden.

Im Webfrontend wechselt der Schriftzug: "MQTT Gateway running ([...,]) | Mosquitto not running" zu "MQTT Gateway not running ([...,]) | Mosquitto not running".
Das Gateway lässt problemlos wieder starten und funktioniert dann wieder.

Heute am Morgen ist es wieder ausgefallen und ich habe versucht es einmal zu analysieren bevor ich das Gateway manuell neu gestartet habe.

In den Log-Files (mqttgateway.log, mqttfinder.log) konnte ich keine Fehlermeldungen finden.

Was mir jedoch aufgefallen ist, dass die mqttgateway.log mit folgendem Abschnitt einfach aufhört.

00:18:09.570 <OK> MQTT IN: Inside/Basement/HeatingRoom/AIT/Temperatures: {
"Vorlauf": 19.8,
"Ruecklauf": 19.4,
"RuecklSoll": 20.7,
"Heissgas": 21,
"Aussentemperatur": 8.4,
"Mitteltemperatur": 11.5,
"WarmwasserIst": 56,
"WarmwasserSoll": 52,
"WaermequelleEin": 15.7,
"Vorlaufmax": 60,
"AnsaugVD": 20.5,
"\uFFFD\uFFFDberhitzung": 6.2,
"UeberhitzungSoll": 18.4,
"TFL1": 18.4,
"TFL2": 19.8
}
00:18:09.571 Expanding json message
00:18:09.572 Inside/Basement/HeatingRoom/AIT/Temperatures/Aussentemperatur = 8.4
00:18:09.572 Inside/Basement/HeatingRoom/AIT/Temperatures/UeberhitzungSoll = 18.4
00:18:09.572 Inside/Basement/HeatingRoom/AIT/Temperatures/Mitteltemperatur = 11.5
00:18:09.572 Inside/Basement/HeatingRoom/AIT/Temperatures/Ruecklauf = 19.4
00:18:09.572 Inside/Basement/HeatingRoom/AIT/Temperatures/WaermequelleEin = 15.7
00:18:09.572 Inside/Basement/HeatingRoom/AIT/Temperatures/RuecklSoll = 20.7
00:18:09.573 Inside/Basement/HeatingRoom/AIT/Temperatures/Vorlaufmax = 60
00:18:09.573 Inside/Basement/HeatingRoom/AIT/Temperatures/WarmwasserIst = 56
00:18:09.573 Inside/Basement/HeatingRoom/AIT/Temperatures/TFL2 = 19.8
00:18:09.573 Inside/Basement/HeatingRoom/AIT/Temperatures/WarmwasserSoll = 52
00:18:09.573 Inside/Basement/HeatingRoom/AIT/Temperatures/Vorlauf = 19.8
00:18:09.573 Inside/Basement/HeatingRoom/AIT/Temperatures/AnsaugVD = 20.5
00:18:09.573 Inside/Basement/HeatingRoom/AIT/Temperatures/��berhitzung = 6.2
00:18:09.574 Inside/Basement/HeatingRoom/AIT/Temperatures/Heissgas = 21
00:18:09.574 Inside/Basement/HeatingRoom/AIT/Temperatures/TFL1 = 18.4
00:18:09.574 Inside/Basement/HeatingRoom/AIT/Temperatures/WaermequelleEin is cached
00:18:09.574 Inside/Basement/HeatingRoom/AIT/Temperatures/��berhitzung is cached
00:18:09.574 Inside/Basement/HeatingRoom/AIT/Temperatures/Ruecklauf is cached
00:18:09.575 Inside/Basement/HeatingRoom/AIT/Temperatures/WarmwasserSoll is cached
00:18:09.575 Inside/Basement/HeatingRoom/AIT/Temperatures/AnsaugVD is cached
00:18:09.575 Inside/Basement/HeatingRoom/AIT/Temperatures/Aussentemperatur is cached
00:18:09.575 Inside/Basement/HeatingRoom/AIT/Temperatures/RuecklSoll is cached
00:18:09.575 Inside/Basement/HeatingRoom/AIT/Temperatures/Vorlaufmax is cached
00:18:09.575 Inside/Basement/HeatingRoom/AIT/Temperatures/Mitteltemperatur is cached
00:18:09.575 Inside/Basement/HeatingRoom/AIT/Temperatures/TFL1 is cached
00:18:09.575 Inside/Basement/HeatingRoom/AIT/Temperatures/Heissgas is cached
00:18:09.575 Inside/Basement/HeatingRoom/AIT/Temperatures/Vorlauf is cached
00:18:09.575 Inside/Basement/HeatingRoom/AIT/Temperatures/TFL2 is cached
00:18:09.576 Inside/Basement/HeatingRoom/AIT/Temperatures/UeberhitzungSoll is cached
00:18:09.576 Inside/Basement/HeatingRoom/AIT/Temperatures/WarmwasserIst is cached
00:18:09.576 Inside/# matches Inside/Basement/HeatingRoom/AIT/Temperatures, send to MS 1
00:18:09.576 HTTP: Preparing input Inside_Basement_HeatingRoom_AIT_Temperatures_Heiss gas (using cache): 21
00:18:09.576 HTTP: Preparing input Inside_Basement_HeatingRoom_AIT_Temperatures_TFL1 (using cache): 18.4
00:18:09.576 HTTP: Preparing input Inside_Basement_HeatingRoom_AIT_Temperatures_Warmw asserIst (using cache): 56
00:18:09.576 HTTP: Preparing input Inside_Basement_HeatingRoom_AIT_Temperatures_��ber hitzung (using cache): 6.2
00:18:09.576 HTTP: Preparing input Inside_Basement_HeatingRoom_AIT_Temperatures_Ansau gVD (using cache): 20.5
00:18:09.576 HTTP: Preparing input Inside_Basement_HeatingRoom_AIT_Temperatures_Ausse ntemperatur (using cache): 8.4
00:18:09.577 HTTP: Preparing input Inside_Basement_HeatingRoom_AIT_Temperatures_Warmw asserSoll (using cache): 52
00:18:09.577 HTTP: Preparing input Inside_Basement_HeatingRoom_AIT_Temperatures_TFL2 (using cache): 19.8
00:18:09.577 HTTP: Preparing input Inside_Basement_HeatingRoom_AIT_Temperatures_Ueber hitzungSoll (using cache): 18.4
00:18:09.577 HTTP: Preparing input Inside_Basement_HeatingRoom_AIT_Temperatures_Rueck lSoll (using cache): 20.7
00:18:09.577 HTTP: Preparing input Inside_Basement_HeatingRoom_AIT_Temperatures_Vorla ufmax (using cache): 60
00:18:09.577 HTTP: Preparing input Inside_Basement_HeatingRoom_AIT_Temperatures_Mitte ltemperatur (using cache): 11.5
00:18:09.577 HTTP: Preparing input Inside_Basement_HeatingRoom_AIT_Temperatures_Vorla uf (using cache): 19.8
00:18:09.577 HTTP: Preparing input Inside_Basement_HeatingRoom_AIT_Temperatures_Waerm equelleEin (using cache): 15.7
00:18:09.577 HTTP: Preparing input Inside_Basement_HeatingRoom_AIT_Temperatures_Rueck lauf (using cache): 19.4

Es fällt natürlich sofort auf, dass hier Sonderzeichen vom MQTT-Server kommen ("\uFFFD\uFFFDberhitzung").
In meiner Datenbank, die die MQTT-Nachrichten protokolliert, sehe ich ebenfalls, dass manchmal statt des Parameters "Ueberhitzung" der Parameter "\uFFFD\uFFFDberhitzung" geloggt wird.

Die Daten werden von einem von meinen Services von einer Alpha Innotec Heizung abgerufen, konvertiert und zum MQTT-Server gesendet. Dabei scheint wohl in meinem Service manchmal etwas schief zu laufen und die Sonderzeichen werden zum MQTT publiziert - das ist selbstverständlich ein Problem auf meiner Seite. Die Ursache konnte ich noch nicht finden - da das nur sehr selten passiert.

Ich gehe nun davon aus, dass das MQTT-Gateway vom Loxberry hier zwar nicht der Schuldige ist, aber der Gateway Service sollte nicht kommentarlos sterben.
Würdet ihr bitte schauen, ob die beschriebene Vermutung für Euch einen Sinn ergibt und ob ihr ggf. den Gateway Service hier robuster machen könntet und eine Fehlermeldung ins Log schreiben könntet?

Wie bereits im Titel geschrieben, hat dieses Anliegen eine geringe Priorität, ich muss zunächst den Fehler auf meiner Seite finden und würde bis dahin kein Update einspielen.

Falls es von Eurer Seite Fragen gibt, stehe ich Euch gerne zur Verfügung.

Beste Grüsse und schon einmal Danke im Voraus,

cainam

[Christian Fenzl]

Servus,

kannst du bitte
- Dich mit putty anmelden
- pkill mqttgateway.pl
- Das Gateway sollte jetzt im UI als gestoppt angezeigt werden.
- Jetzt bitte starten
/opt/loxberry/sbin/mqttgateway.pl

Nun sollte es direkt in deiner Shell laufen.

Jetzt wäre es optimal, den Fehler irgendwie zu triggern.
Dann sollte die Exception in der Shell sichtbar werden, wenn das Gateway stirbt. Das was da kommt, gibt mir dann Aufschluss, wo genau die Funktion crashed.

Vom Zeitpunkt des Logs her ist es dann, wenn der Cache geprüft wird, und die http-Übertragung an den MS stattfindet.

lg, Christian

[cainam24]

Guten Morgen Christian,

danke für Deine rasche Antwort.

Ich habe aktuell die Heizung via Regex als Ausnahme konfiguriert bei den Subscriptions, aktuell läuft das Gateway noch (jetzt etwa 24 Stunden).
Gemäss meiner Datenbank wurde seit dem Setzen der Ausnahme (inkl. Neustart des Gateways) und heute morgen 17 mal ein Datum mit Sonderzeichen gesendet.

Ich werde heute am Abend die Ausnahme zurücksetzen und so vorgehen, wie Du vorgeschlagen hast. Ich melde mich, wenn ich mehr weiss.

Danke für Deinen Support.

cainam

[cainam24]

Hallo Christian,

hier nur ein kurzes Update. Der Fehler ist bisher nicht wieder vorgekommen.
Auch in meiner DB sind keine Einträge mit Sonderzeichen mehr zu finden, seit dem ich das Log gestartet habe.
Ich werde in den nächsten Tagen mal versuchen das manuell nachzustellen...

Schönen Sonntag,

cainam

[cainam24]

Hoi Christian,

bitte entschuldige, dass ich mich nicht früher gemeldet habe. Ich hatte keine Zeit, das Problem noch einmal anzuschauen. Das Log lief nun die ganze Woche mit und es gab keine weiteren Fehler.

Ich habe jetzt mal schnell ein Programm geschrieben, dass MQTT-Messages mit Sonderzeichen sowohl im Topic-Namen als auch in der Message zum Loxberry schickt. Das habe ich nun eine Stunde lang laufen lassen (Abstand zwischen den Nachrichten 250ms). Und das Ergebnis ist NICHTS. Alles funktioniert, läuft problemlos, erzeugt keine Fehler/Exceptions im Log, usw.

Da das Problem offenbar nicht reproduzierbar ist, ist ein Debuggen schwierig. Ich starte das Gateway nun wieder aus dem UI. Falls der Fehler wieder auftritt, weiss ich, wie ich vorgehen muss, um Logs zu produzieren.

--> Ticket closed

Danke für Deinen Support und Grüsse aus der Schweiz,

cainam24