UNSOLVED Zigbee Geräte schalten verzögert

[amg_666]

@fiddle Richtig verstanden

[DirkS]

Gibt es hier vielleicht schon ein paar neue Erkenntnisse?
Ich werde aktuell auch vom verzögerten Schalten geplagt. Es wird aber auch nichts ins Log geschrieben.
Teilweise sind die Verzögerungen bis zu 30 Sekunden. Irgendwie habe ich die Vermutung, dass dies durch "Alexa" ausgelöst werden. Wenn aber durch Alexa nicht geschaltet wird, dann kann ich auch direkt über iobroker nicht schalten.
Nachdem der "Knoten" gelöst ist, werden dann alle bis dahin getätigten Schaltvorgänge abgearbeitet und es ist für einen kurzen Moment Party im Raum.

[Asgothian]

@DirkS Nein. Da ich den Effekt nicht habe kann ich den nicht analysieren.

A.

[DirkS]

@Asgothian
Vielen Dank für die schnelle Antwort.
Seltsam ist es, dass es nicht immer auftritt. Was auch seltsam ist, dass diesmal nichts im Log steht.
Könnte ich denn noch irgendwie zur Lösung des Problem beitragen?

[Asgothian]

@DirkS

Je nach dem wie häufig es auftritt könntest Du den Adapter im Debug laufen lassen, incl. zigbee-herdsman-debug Info, um dann wenn es passiert die vorhandenen Nachrichten aneinander setzen zu können.

Allerdings macht das nur in einem bestimmten Szenario Sinn. Um da genauer schauen zu können benötige ich

• ein Log von einer Schaltsituation die sauber gelaufen ist
• ein Log von einer Verzögerten Schaltsituation.

Wichtig ist dabei das die beiden Situationen soweit wie möglich identisch sein müssen, sprich das die gleichen Leuchtmittel angesprochen werden.

A.

[DirkS]

@Asgothian
Debug Ausgabe hatte ich wohl irgendwann wieder deaktiviert. Nun ist sie wieder aktiv und auch der zigbee-herdman-debug info. Hoffe ich bekomme da eine Diskrepanz raus.

[DirkS]

[Nachtrag]
Debugausgabe ist nun aktiv und füllt die Log Datei extrem.
Es wird kontinuierlich Ausgabe erzeugt. Eventuell ist einfach zu viel Traffic, so dass irgendwann die Queue voll ist. Im Schnitt landen 100-120 Zeilen/Minute im Log. Ping, Status, Werte, etc. obwohl nichts geschaltet wird.
Kann man hier irgendwas einstellen, dass nicht ständig irgendwelche Updates kommen?
Kann es eventuell damit zu tun haben?
Version 1.16.0 overall slow network response
Welche Version arbeitet hier aktuell im "Kern"?
Habe gerade die aktuelle Version vom GitHub genommen.

[Asgothian]

@DirkS Dabei geht es um Effekte im Zigbee2mqtt 1.16 soweit ich das erkennen konnte. Diese setzen wir nicht ein. In wie weit das auf Anpassungen innerhalb des Herdsman zurück fällt konnte ich nicht erkennen.

Ich gehe davon aus das Dein Effekt ein anderer ist. In dem Thread ist von einer generellen "Langsamkeit" die Rede.

A.

[DirkS]

@Asgothian
Okay. Ich habe da mal eine Vermutung. Ich habe gerade etwas im Log beobachtet:
Es tat sich einige Zeit nichts, dann kam folgender Eintrag und danach folgten wieder einiger Einträge:
Error on send command to 0xYYXXZZFFeeGGHHJJ. Error: Error: Command 0xYYXXZZFFeeGGHHJJ/1 genOnOff.off({}, {"timeout":10000,"di...
Hier scheint eine meiner Steckdose nicht erreichbar gewesen zu sein und alles andere wartete darauf.

[arteck]

@DirkS wenn was nicht sofort antwortet wird 10 sec gewartet ..

[Asgothian]

@DirkS
Es sollten nur Schaltbefehle an die eine Steckdose warten. Alles andere sollte parallel weiter laufen.

Das sollte durch interne Queues so abgebildet sein, und ich bin mir 99% sicher das es so bei mir auch funktioniert.

Was hast du bei deinem Adapter in der Config an Einstellungen ?

A.

[DirkS]

@Asgothian
Was meinst du konkret mit "Einstellungen"? Habe eigentlich nichts verändert außer den Schlüssel.
Die Log Level Einstellung erzeugt nun ganz schon viel Traffic. vorher hatte ich ein paar KB nun sind es 100MB Log/Tag.
Was mir aufgefallen ist, dass scheinbar Teile des Netzwerk wohl kurzzeitig ständig nicht erreichbar sind. Ich hatte mir hierzu einmal den "Available" State von verschiednen Zigbee Geräten an unterschiedlichen Standorten protokollieren lassen.
Es gibt wohl auch ein Firmware Update für meine cc2538 Lösung.

[Asgothian]

@DirkS

OK.. hat Sich erledigt.. früher gab es eine Einstellung mit der das command queuing am Zigbee-Adapter umgestellt werden kann. Die Einstellung gibt es nicht mehr.

Kannst du bitte den Folgenden Test machen:

• ein Skript schreiben, das fuer 20 Sekunden jede Sekunde eine Lampe umschaltet (eine die auch da ist)
• Nach 5 Schaltzyklen soll es zusätzlich eine Lampe schalten die du vorher vom Strom getrennt hast (device nicht erreichbar erzwingen)

Diese 20 Sekunden im Log aufzeichnen und mir bitte zukommen lassen, zusammen mit einer Beschreibung wie sich die Lampe verhält, sowie die ieee Adressen der beiden betroffenen Lampen.

A.

[DirkS]

@Asgothian
Werde ich die Tage machen, wenn es etwas ruhiger wird.
Es ist aber schon sehr kurrios. Wenn ich SQL Logging einschaltet, sollte doch der letzte Zustand protokolliert sein? Dieser passt manchmal nicht zum aktuellen Zustand der Erreichbarkeit.
Das nächste ist, dass z.B. von meinen geliebten OSRAM Dingern die Erreichbarkeit als nicht vorhanden angezeigt wird, diese sich aber schalten lassen. Ich vermute, dass es dann den umgekehrten Fall auch gibt?
[Nachtrag]
Vermutlich kein Zusammenhang, habe gerade ein Update-Check gestartet und bekomme nun dies hier ins Log

zigbee.1	2020-12-17 07:39:13.231	error	at Timer.processTimers (timers.js:223:10)
zigbee.1	2020-12-17 07:39:13.231	error	at listOnTimeout (timers.js:263:5)
zigbee.1	2020-12-17 07:39:13.231	error	at tryOnTimeout (timers.js:300:5)
zigbee.1	2020-12-17 07:39:13.231	error	at ontimeout (timers.js:436:11)
zigbee.1	2020-12-17 07:39:13.231	error	at Timeout.waiter.timer.setTimeout [as _onTimeout] (/opt/iobroker/node_modules/iobroker.zigbee/node_modules/zigbee-herdsman/dist/utils/waitress.js:46:35)
zigbee.1	2020-12-17 07:39:13.231	error	(10275) Error: Timeout - 46243 - 1 - null - 25 - 1 after 30000ms
zigbee.1	2020-12-17 07:39:13.231	error	(10275) unhandled promise rejection: Timeout - 46243 - 1 - null - 25 - 1 after 30000ms
Unhandled	2020-12-17 07:39:13.230	error	promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch().

[Asgothian]

@DirkS sagte in Zigbee Geräte schalten verzögert:

Vermutlich kein Zusammenhang, habe gerade ein Update-Check gestartet und bekomme nun dies hier ins Log

Irgendwie scheint dieser Eintrag unvollständig. Der entscheidende Teil fehlt.

@DirkS sagte in Zigbee Geräte schalten verzögert:

Das nächste ist, dass z.B. von meinen geliebten OSRAM Dingern die Erreichbarkeit als nicht vorhanden angezeigt wird, diese sich aber schalten lassen. Ich vermute, dass es dann den umgekehrten Fall auch gibt?

Soweit ich das überblicke gibt es diesen Fall nur bei batteriebetriebenen Geräten, bei denen die Erkennung der Anwesenheit generell problematisch ist, da sie nicht abgefragt werden können. Eine saubere Erkennung basierend auf der letzten erhaltenen Nachricht ist nicht immer Einfach, da sich das Intervall in dem sich die Geräte melden von Gerät zu Gerät extrem unterscheiden kann.

A.

[DirkS]

@Asgothian
Leider ist im Log nicht mehr vorhanden, außer dass es sich mehrfach wiederholt und dann der Adapter irgendwann automatisch neu startet.

Bei der Erreichbarkeit geht es ja nicht um die Batterie betriebenen Geräte. Es ist der OSRAM Led Stripe.

[Asgothian]

@DirkS sagte in Zigbee Geräte schalten verzögert:

Bei der Erreichbarkeit geht es ja nicht um die Batterie betriebenen Geräte. Es ist der OSRAM Led Stripe.

Bei dem sollte der "available" Datenpunkt zumindest in dem 5 Minuten Raster des Abfragen korrekt sein, sprich es gibt ein Zeitfenster von max. 5 Minuten in denen der Strip noch mit "available = wahr" geführt wird, obwohl er bereits aus ist. Danach wird er auf jeden Fall auf falsch gehen da er auf den Ping der ihm geschickt wird nicht reagieren wird.

A.

[DirkS]

@Asgothian
Sicher nicht mehr der richtige Thread.
Habe heute folgende Einträge im Log

zigbee.1	2020-12-18 07:17:11.563	error	at fulfilled (/opt/iobroker/node_modules/iobroker.zigbee/node_modules/zigbee-herdsman/dist/adapter/z-stack/adapter/zStackAdapter.js:24:58)
zigbee.1	2020-12-18 07:17:11.563	error	at Generator.next (<anonymous>)
zigbee.1	2020-12-18 07:17:11.563	error	at ZStackAdapter.<anonymous> (/opt/iobroker/node_modules/iobroker.zigbee/node_modules/zigbee-herdsman/dist/adapter/z-stack/adapter/zStackAdapter.js:339:27)
zigbee.1	2020-12-18 07:17:11.563	error	(29141) Error on send command to 0xXXXXXXXXXXXXXXXX. Error: Error: Command 0xXXXXXXXXXXXXXXXX/1 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultRespon

Der State vom "available" ist aber die ganze Zeit auf true und die Protokollierung zeigte auch seit gestern keine Änderung.
Sollte denn dann zuminest bei so einem Fehler der State nicht auf false gehen?

[Asgothian]

@DirkS

• Stimmt, nicht der richtige Thread
• Das Log ist unvollständig - die entscheidende Information ist (mal wieder) abgeschnitten
• Aktuell ist es so dass ein Router-Device nur dann auf "available=false" gesetzt wird wenn es auf den "ping" nicht reagiert.

A.

[DirkS]

@asgothian
Nachdem ich nun dummerweise beim Flashen der neuen Firmware auch einen Haken bei "Full erase " gesetzt hatten, musste ich danach alle Geräte neu anlernen. Danach lief es bis zum letzten Wochenende echt super. Nun fängt das beschriebene Problem wieder an. Die Geräte schalten wieder etwas verzögert.
Im Log ist im Level Info keine Ausgabe zu den Zeitpunkten. Ich habe habe aber nun auch vermehrt die Hinweise "Failed to Ping" zu mehreren Geräten.