@pierre-gilles @cicoub13 kleiner Fortschritt
Zusammenfassung von chatGPT:
Kompletter Freeze von Gladys beim Update eines Zigbee2MQTT-Geräts
Ich stoße auf ein reproduzierbares Problem mit Gladys, wenn ich eine Steckdose namens Station informatique über die Zigbee2MQTT-Schnittstelle aktualisiere.
Ursprünglich wollte ich dieses Gerät einfach aktualisieren, da einige Funktionen im Zusammenhang mit Energie/Verbrauch fehlten.
Symptome
Beim Aktualisieren des Geräts über Gladys:
-
die Anfrage endet mit einem Timeout;
-
die Schnittstelle wird teilweise oder vollständig unbrauchbar;
-
die SQLite-Schreibvorgänge beginnen dann zu scheitern mit:
SequelizeTimeoutError
SQLITE_BUSY: Datenbank ist gesperrt
Zum Beispiel:
Unable to reset failure count of integration ...
SQLITE_BUSY: Datenbank ist gesperrt
Der HTTP-Server selbst antwortet jedoch weiterhin auf Port 8455.
DB-Konfiguration
Die SQLite-Datenbank ist recht groß:
gladys-production.db ~12 GB
gladys-production.db-wal ~1 GB
gladys-production.duckdb ~1,9 GB
SQLite funktioniert im WAL-Modus:
PRAGMA journal_mode;
wal
Ein passiver Checkpoint funktioniert:
PRAGMA wal_checkpoint(PASSIVE);
0|227|227
Einfache Abfragen auf SQLite bleiben schnell:
SELECT COUNT(*) FROM t_device_feature;
446
real 0m0.090s
Und:
SELECT COUNT(*) FROM t_device_feature_state;
0
Die Zustände scheinen also erfolgreich zu DuckDB migriert worden zu sein.
Betroffenes Gerät
Das Gerät ist:
id:
fd928ba6-ca0d-4a0d-8483-5b74cfddce8c
external_id:
zigbee2mqtt:Station informatique
Vor dem Update-Versuch waren seine registrierten Features unter anderem:
Schalter
Verbrauchte Leistung
Verbrauchte Stromstärke
Durchschnittsspannung
Verbrauchte Energie
Signalstärke
Zugriffskontrollmodus
Das Feature « Zugriffskontrollmodus » entspricht:
zigbee2mqtt:Station informatique:access-control:mode:child_lock
Untersuchung in device.create.js
Ich habe instrumentiert:
/src/server/lib/device/device.create.js
um genau zu bestimmen, wo die Transaktion blockiert wird.
Der Beginn des Updates funktioniert normal:
[DEBUG DEVICE CREATE] START zigbee2mqtt:Station informatique
[DEBUG DEVICE CREATE] BEFORE getDeviceInDb zigbee2mqtt:Station informatique
[DEBUG DEVICE CREATE] AFTER getDeviceInDb zigbee2mqtt:Station informatique
[DEBUG DEVICE CREATE] BEFORE device update zigbee2mqtt:Station informatique
[DEBUG DEVICE CREATE] AFTER device update zigbee2mqtt:Station informatique
[DEBUG DEVICE CREATE] BEFORE feature cleanup zigbee2mqtt:Station informatique
Die Blockade tritt also während dieses Teils von device.create.js auf:
await Promise.map(deviceInDb.features, async (existingFeature) => {
if (!matchFeatureInList(existingFeature, features)) {
await existingFeature.destroy({ transaction });
}
});
Ich habe dann jedes Feature instrumentiert.
Ergebnis:
[DEBUG FEATURE CLEANUP] ...:switch:binary:state matched= true
[DEBUG FEATURE CLEANUP] ...:switch:power:power matched= true
[DEBUG FEATURE CLEANUP] ...:switch:current:current matched= true
[DEBUG FEATURE CLEANUP] ...:switch:voltage:voltage matched= true
[DEBUG FEATURE CLEANUP] ...:switch:energy:energy matched= true
Dann:
[DEBUG FEATURE CLEANUP] zigbee2mqtt:Station informatique:access-control:mode:child_lock matched= false
[DEBUG FEATURE DESTROY] BEFORE zigbee2mqtt:Station informatique:access-control:mode:child_lock
Und kein DEBUG FEATURE DESTROY AFTER erscheint.
Das nächste Feature wird noch vom Promise.map inspiziert:
[DEBUG FEATURE CLEANUP] ...:signal:integer:linkquality matched= true
aber das Promise.map beendet sich nie, da das destroy() von child_lock blockiert bleibt.
Was zu passieren scheint
Die neue Definition, die von Zigbee2MQTT hochgeladen wird, enthält nicht mehr das Feature:
access-control:mode:child_lock
Gladys betrachtet daher logischerweise dieses alte Feature als gelöscht und führt aus:
await existingFeature.destroy({ transaction });
Genau dieser Aufruf kehrt nicht zurück.
Die Transaktion device.create() bleibt dann offen.
Kurz darauf versuchen andere Komponenten von Gladys, in SQLite zu schreiben, und beginnen, Folgendes zu produzieren:
SQLITE_BUSY: Datenbank ist gesperrt
Zum Beispiel die Aktualisierungen von t_service:
UPDATE `t_service`
SET `failure_count`=$1,`updated_at`=$2
WHERE `id` = $3
enden mit SequelizeTimeoutError.
Das ergibt also, in diesem Stadium, die folgende Sequenz:
Geräteupdate Z2M
↓
device.create()
↓
deviceInDb.update() OK
↓
Bereinigung der alten Features
↓
child_lock fehlt im neuen Gerät
↓
existingFeature.destroy({transaction})
↓
BLOCKIERUNG
↓
SQLite-Transaktion bleibt offen
↓
andere Schreibvorgänge
↓
SQLITE_BUSY / Datenbank ist gesperrt
Zur Energie
Das Problem trat auf, als ich versuchte, die Energieverbrauchs-Funktionen dieser Steckdose abzurufen, was mich zunächst auf den neuen Energieüberwachungscode lenkte.
Die Spuren zeigen jedoch jetzt, dass die Blockade vor der Erstellung/Aktualisierung der Energie-Features auftritt.
Das vorhandene Feature energy wird übrigens korrekt erkannt:
zigbee2mqtt:Station informatique:switch:energy:energy matched=true
Die Blockade wird durch den Versuch ausgelöst, das alte Feature child_lock zu löschen.
Weitere Beobachtung
Während des Freezes setzt der Energy Monitoring-Service seine Verarbeitung fort und zeigt insbesondere an:
Found 52 energy devices
Found 0 devices with both INDEX and thirty-minutes-consumption features
Dann erscheinen die SQLITE_BUSY in verschiedenen Teilen von Gladys.
Ich habe auch t_job überprüft: Die Jobs für die Migration SQLite → DuckDB und das Löschen von verwaisten DuckDB-Zuständen werden als success angezeigt.
Getesteter Patch ohne Erfolg
Ich hatte auch eine Änderung von device.create.js getestet, um die Bereinigung der Zustände nur auszulösen, wenn keep_history tatsächlich von true auf false wechselt:
const keepHistoryBeforeUpdate = deviceFeature.keep_history;
await deviceFeature.update(featureToUpdate, { transaction });
if (keepHistoryBeforeUpdate !== false && deviceFeature.keep_history === false) {
deviceFeaturesIdsToPurge.push(deviceFeature.id);
}
Dies behebt das Problem nicht: Dank der zusätzlichen Protokolle weiß man jetzt, dass der Freeze früher auftritt, während des destroy() des veralteten Features.
Aktueller Diagnosezustand
Der reproduzierbare Blockadepunkt ist jetzt recht genau identifiziert:
existingFeature.destroy({ transaction })
für:
zigbee2mqtt:Station informatique:access-control:mode:child_lock
)
