Marstek Modbus Suite 1.2 und 1.3: Wenn der Speicher nicht mehr antwortet

Nach 1.1.0 liefen zwei Stränge parallel. Der eine war ein Satz Betas für 1.1.5, der andere eine Reihe von Releases, die auf Debug-Logs einer Venus E v3 (Firmware 150) zurückgehen, darunter ein Log, aus dem 1.2.0 entstand: ein Speicher, der still wurde, und eine Integration, die darauf wartete. Zusammengenommen verändern sie, wie sich die Marstek Modbus Suite bei Verbindungsproblemen verhält.

DEV-Register: Forschung als Schalter

1.1.5-beta.1 bringt eine Option unter Optionen → DEV-Register, standardmäßig aus, die 131 Diagnosesensoren zuschaltet. 51 davon sind Register, deren Bedeutung ungeklärt ist, 80 liegen im Bereich 40000 und haben bei einem Live-Scan auf einen Lesezugriff geantwortet. Die Namen folgen dem Muster DEV <Register> (<Vermutung>?); das Fragezeichen markiert die Vermutung als solche. Bewusst ausgeschlossen sind 41500–41515, der Puffer für WLAN-Zugangsdaten (ein Sensorwert landete sonst in Datenbank, Backups und womöglich Logs), und alle Register, bei denen im Scan die Verbindung abbrach.

Weil dabei der erste Blockzugriff über 30 Register entstand (46501–46544, 44 Register), wurde die Blockgröße vorher am Gerät gemessen: 8, 16, 24, 30, 32, 36, 40 und 44 Register, je dreimal, mit Lebenszeichen-Test nach jedem Versuch. Alle gingen durch, und die Antwortzeit wächst nicht mit der Blockgröße – 44 Register brauchten 7 ms, 8 Register 15 ms. Die Rundlaufzeit dominiert, nicht die Nutzlast. In beta.2 wurde die Option in zwei geteilt, Unbekannt (117) und Duplikate (14), mit Migration des alten Schalters, damit nach dem Update nichts verschwindet.

Ein Jahreszähler, der fällt

beta.3 ging einem Wert von rund 35 Millionen nach, den ein Sensor auf einem Gerät ohne PV zeigte. Es waren zwei Fehler. Ein DEV-Eintrag erbte vom Register-Vorbild den Typ u32 und las damit 37022 und 37023 als ein 32-Bit-Wort; 37023 ist mppt_error. Der Wert war also Register 37022 × 65536 + mppt_error. Der zweite Fehler war die Deutung von pv_year_capacity (37021) als Jahresertrag. Eine Messung über 70 Minuten ohne PV zeigte, dass 37021 konstant 0 bleibt und 37022 sich in beide Richtungen zwischen 535 und 561 bewegt. Ein Jahresertrag kann nicht fallen; als total_increasing hätte er bei jedem Rückgang die Langzeitstatistik beschädigt. Praktisch betroffen war niemand, der Sensor war deaktiviert. Er ist entfernt, beide Register laufen als einfache uint16-Werte in der Gruppe der Unbekannten.

Warum der Start so lange dauerte

Die Betas 4 bis 6 räumten auf, was das Starten und Abfragen zäh machte. Anlass war die Meldung „Setup of select platform marstek_modbus is taking over 10 seconds“, und dahinter standen vier Ursachen:

• Die select-Plattform war die einzige, die ihre Entitäten mit update_before_add=True anlegte. Das löste einen vollständigen Abfragezyklus aus, der das Setup blockierte, und rund zehn Sekunden später noch einen zweiten.
• Die Wartezeit zwischen Nachrichten wurde pro Anfrage doppelt angewendet. Gemessen mit einem Test-Client bei 10 ms Antwortzeit: vorher 173 ms je Anfrage und 957 ms für sechs Lesezugriffe, nachher 92 ms und 471 ms.
• In UI-angelegten Einträgen gab es kein Timeout-Feld, entry.data.get("timeout") war None, und AsyncModbusTcpClient(timeout=None) wartet unbegrenzt. Jetzt gilt ein Standard von 3 s.
• Das Timeout für Blockzugriffe hatte mit dem des Clients nichts zu tun und lag bei 10 bis 22 s; es folgt jetzt dem Client-Timeout.

Außerdem gibt async_setup_entry bei einem kurzzeitig nicht erreichbaren Speicher nicht mehr einfach False zurück, sondern wirft ConfigEntryNotReady; Home Assistant versucht es dann mit Backoff erneut. Die Nebenwirkung: Solange das Gerät nicht erreichbar ist, bleibt der Eintrag im Wiederholungsmodus, statt mit nicht verfügbaren Entitäten zu laden.

beta.5 machte die Wartezeit in den Verbindungseinstellungen einstellbar (0 bis 1000 ms). Das Feld hatte es nie gegeben, ein einmal in entry.data gelandeter Wert war über die Oberfläche nicht änderbar. Auf dem Testgerät standen 300 ms bei einer tatsächlichen Antwortzeit von etwa 10 ms, 97 Prozent jedes Zyklus waren selbst auferlegte Pause: 16,1 s für den ersten Abruf mit 179 Lesezugriffen (bei eingeschalteten DEV-Registern), gegenüber geschätzten 4 bis 5 s bei den 80 ms Standard. Wer eine ältere Installation hat, sollte den Dialog einmal öffnen und nachsehen. beta.6 schließlich gibt den berechneten Sensoren ihre Nachkommastellen zurück: Das Zelldelta zeigte 0 statt 0.000, weil precision nur die Basisklasse der Messwerte las.

1.2.0: Ein stilles Gerät friert nicht mehr minutenlang ein

Das Log, das 1.2.0 auslöste, stammt von einer Venus E v3. Plötzlich kam keine Antwort mehr, ein Abfragezyklus dauerte 356,6 Sekunden, bis „All read attempts failed (0/28)“ einen Reconnect auslöste, nach dem sofort wieder alles ging. Der Speicher war nie kaputt, eine frische Verbindung lieferte nach 316 ms Daten. Der alte Socket war halb offen, und nichts ersetzte ihn.

Die Ursache war eine Verschachtelung zweier Wiederholungsschleifen. Jeder Aufruf steckte in einem asyncio.wait_for mit 10 s, aber pymodbus wiederholt eine Anfrage intern bis zu dreimal, je mit vollem Timeout. Gegen einen Server, der die Verbindung annimmt und nie antwortet, dauerte ein Aufruf bei timeout=3 und den Standardwiederholungen 12,01 s, mit retries=0 3,00 s. Der äußere Wächter schlug also immer zuerst zu und brach Transaktionen mitten im Lauf ab – und eine abgebrochene Transaktion liest ihre Antwort nie, was den Socket genau in den halb offenen Zustand bringt.

Seit 1.2.0 gibt es nur noch eine Wiederholungsebene, die der Integration selbst (PYMODBUS_RETRIES = 0), und der Wächter sitzt oberhalb des Budgets. Der Socket wird dort neu aufgebaut, wo der Timeout passiert, gedrosselt auf einen Reconnect je max(5 s, 2 × Timeout). Der Vergleich gegen ein dauerhaft schweigendes Gerät: vorher bricht der Wächter nach 10,00 s ab und es wurde ein einziger Socket je geöffnet, nachher gibt der Client nach 9,82 s sauber auf und hat dabei zwei Reconnects gemacht. Im Fall aus dem Log dauert das Lesen 3,41 s statt 356 s.

1.2.1 bis 1.3.1: Nachbesserungen aus dem Feld

Das zweite Debug-Log derselben Venus bestätigte 1.2.0: drei Ausfälle in 18 Minuten, jeder nach 1 bis 4 Sekunden vorbei. 1.2.1 betrifft nur noch das Log. Jeder Reconnect brauchte zwei Versuche, weil das Gerät nach dem Schließen nicht sofort eine neue Sitzung vergibt: Bei etwa 0 ms Abstand wurde die Verbindung nach rund 110 ms abgelehnt, bei etwa 210 ms klappte sie. RECONNECT_SETTLE_SEC = 0,3 wartet deshalb zwischen Schließen und Verbinden. Die pymodbus-Fehlerzeile „No response received“ bleibt, weil derselbe Logger auch von Home Assistants eigener Modbus-Integration genutzt wird und ein Filter von hier aus deren Fehler mit stummschalten würde.

1.3.1 behebt eine Regression aus den 1.2-Versionen, die ich nicht verschweigen will. Weil jetzt mehr Aufrufer neu verbanden, kam ein latenter Nebenläufigkeitsfehler zum Vorschein: Wer hinter der Sperre wartete, baute eine inzwischen funktionierende Verbindung noch einmal ab, und der Schreibpfad verband ganz ohne Sperre. Gemeldet wurde ein Speicher, der dauerhaft offline blieb und nur nach einem Neustart von Home Assistant zurückkam. Es gibt jetzt eine eigene Verbindungssperre mit einem Generationszähler; wer eine bereits erneuerte Verbindung vorfindet, übernimmt sie. Sechs gleichzeitige Reconnects ergeben einen Aufbau. Außerdem wurde ein Gerät, das Verbindungen ablehnt, vorher regelrecht bombardiert: 61 Verbindungsversuche in einer Minute, drei Minuten lang. Ein fehlgeschlagener Aufbau sperrt den nächsten Versuch jetzt von 1 s bis höchstens 30 s, 4 Versuche in 12 s statt vorher 15.

Register 42000: kein „RS485-Steuermodus“

1.3.0 führte einen Reparaturhinweis ein: Register 42000 (rs485_control_mode) schaltet sich auf Firmware 150 von selbst ab, drei Logs zeigen es, jeweils im selben Moment wie ein Kommunikationsaussetzer und nie nach einem eigenen Schreibzugriff. Dann laufen die Messwerte weiter, nur Steuerbefehle haben keine Wirkung. Unter Einstellungen → System → Reparaturen erscheint ein Eintrag, dessen Bestätigung den Modus zurückschreibt. Bewusst nicht automatisch, weil es ein Schreibzugriff auf ein Steuerregister ist.

1.3.2 korrigiert die Erklärung. Aus dem dekompilierten Write_Handler der Firmware v150 schreiben 42000 und 43000 dieselbe Variable. Es gibt kein eigenes Steuermodus-Flag, sondern ein einziges Modusbyte, das entweder 0x0A ist (42000 liest dann 0x55AA) oder ein normaler Betriebsmodus. Keine der drei Optionen von 43000 schreibt 0x0A, und in den Logs ändern sich beide Register jeweils in derselben Sekunde. Gemessen auf einer Venus D: Bei einer erzwungenen Entladung mit 605 W fiel die Leistung auf 12 W, sobald das Byte von 0x0A wegsprang. Die Schreibzugriffe auf 42011 und 42020 prüfen nur den Wertebereich und werden weiter bestätigt, während die Steuerlogik sie ignoriert. Deshalb sieht der Fehler nach nichts aus, bis der Speicher nicht mehr tut, was man ihm sagt.

Zwei Dinge sind offen: Beide Bedienelemente stellen einen einzigen Zustand als zwei unabhängige Schalter dar, das Fehlermodell teilt die Integration mit dem Upstream. Und warum das Byte von selbst zurückfällt, ist nicht geklärt; der periodische Reset der Ethernet-Bridge ist es nicht.