ioBroker / ioBroker.knx

connect KNX via eibd
http://www.iobroker.org
Other
50 stars 32 forks source link

Unzverlässige Empfang von Status-Telegrammen vom KNX-Bus #292

Closed TheBigS1981 closed 11 months ago

TheBigS1981 commented 11 months ago

Hallo alle zusammen und insb. hallo @chefkoch009,

seit einigen Versionen kämpfe ich mit einem Problem bzgl. der Zuverlässigkeit vom knx Adapter. Grundsätzlich funktioniert alles wie es soll, nur manchmal eben nicht zuverlässig. Ich habe einige Wochen/Monate das "hingenommen", aber jetzt in den letzten Wochen hat mich der Status zunehmend mehr gestört. Das Problem wurde auch schon im KNX Forum addressiert, aber auch nicht gelöst. Ich kann auch definitiv ausschließen, dass es etwas mit der (KNX-)Hardware zu tun hat. Alles was ich getestet hat, funktioniert innerhalb des KNX-Systems fehlerfrei.

Ich versuch jetzt nachfolgend die Problematik an einem Beispiel (Rolladen) zu erklären. Grundsätzlich betrifft es aber auch Lichter und wahrscheinlich auch noch weitere Funktionen innerhalb von KNX. Dort fällt es aber eben am meisten auf. Gerne helfe ich bei der Fehlersuche.

Ist-Zustand

knx.0.EG_Esszimmer.Rolladen_Wintergarten_bestimmte_Position = GA, die die Position eines Rolladen festlegt (writeable) knx.0.EG_Esszimmer.Rolladen_Wintergarten_bestimmte_Position_Status = GA, die den Status des Rolladen darstellt (writeable und readable)

Die Zuordnung wurde vom Adapter selbst durch einen Import gemacht und stimmt meiner Meinung nach. Kann man im GA-Tool auch schön sehen.

Problem Wenn ich mit einem Script, einem KNX-Taster oder direkt über die Objekte im ioBroker den Rolladen auf eine bestimmte Position setze kann es passieren (leider nicht immer), dass die Aktion ausgeführt wird, aber der Status nicht sauber zurückkommt. Hier schön zu sehen:

grafik

Im Log (alles) steht dann dazu leider nur folgendes:

_2023-07-21 17:30:57.527 - ^[[32minfo^[[39m: knx.0 (2834634) main.js : tGA.write on Statechange : 7/1/0 P-08D5-0_GA-26 typeof val: number 100 DPT5.001 2023-07-21 17:30:57.528 - ^[[32minfo^[[39m: knx.0 (2834634) easy-knx.js groupValueWrite value: 100 dpt : DPT5.001{"type":"Buffer","data":[6,16,4,32,0,22,4,126,0,0,17,0,188,224,0,1,57,0,2,0,128,255]} 2023-07-21 17:30:57.528 - ^[[32minfo^[[39m: knx.0 (2834634) ( 1 ) Sending : GroupValueWrite : 06 10 04 20 00 16 04 7e 00 00 11 00 bc e0 00 01 39 00 02 00 80 ff sent to 192.168.1.58:3671 ChID: 126 SeqCntIN : 2 SeqCntOUT : 0 GA : 7/1/0 conCheck.conected : true 2023-07-21 17:30:57.528 - ^[[32minfo^[[39m: knx.0 (2834634) easy-knx: task.data : 06 10 04 20 00 16 04 7e 00 00 11 00 bc e0 00 01 39 00 02 00 80 ff byteLen : 22 2023-07-21 17:30:57.529 - ^[[32minfo^[[39m: knx.0 (2834634) ( 2 ) Received TUNNELACK : 06 10 04 21 00 0a 04 7e 00 00 from 192.168.1.58:3671 SeqCntIN : 2 SeqCntOUT : 1 GA : 0/0/0 2023-07-21 17:30:57.529 - ^[[32minfo^[[39m: knx.0 (2834634) ==> successful acknowledged previous package... processing next of 0 2023-07-21 17:30:57.529 - ^[[32minfo^[[39m: knx.0 (2834634) ==> easy-knx.js: signal runtime : 0s 1.481658ms

Der Diagnosemonitor von der ETS hingegen sagt das hier: grafik

Im ioBroker-Log um ~ 17:31:18 (Zeitpunkt als im KNX-Bus der Status aktualisiert wurde) ist schön zu sehen, dass der Status nicht zurück kommt.

_2023-07-21 17:31:10.239 - ^[[32minfo^[[39m: knx.0 (2834634) Send : UDP Connection State Request : 06 10 02 07 00 10 7e 00 08 01 00 00 00 00 9a 35 sent from Port: to 192.168.1.58:3671 2023-07-21 17:31:10.239 - ^[[32minfo^[[39m: knx.0 (2834634) Received CONNECTIONSTATE_RESPONSE : 06 10 02 08 00 08 7e 00 192.168.1.58:3671 ChID : 126 SeqCntIN : 2 SeqCntOUT : 1 msgCode : [object Object] 2023-07-21 17:31:12.232 - ^[[32minfo^[[39m: knx.0 (2834634) checkConnectionState 192.168.1.58 State : true 2023-07-21 17:31:12.232 - ^[[32minfo^[[39m: knx.0 (2834634) Send : conCheck Connection State Request : 06 10 02 07 00 10 7e 00 08 01 00 00 00 00 9a 35 sent to 192.168.1.58:3671 2023-07-21 17:31:12.233 - ^[[32minfo^[[39m: knx.0 (2834634) Received CONNECTIONSTATE_RESPONSE : 06 10 02 08 00 08 7e 00 192.168.1.58:3671 ChID : 126 SeqCntIN : 2 SeqCntOUT : 1 msgCode : [object Object] 2023-07-21 17:31:14.234 - ^[[32minfo^[[39m: knx.0 (2834634) Send : UDP Connection State Request : 06 10 02 07 00 10 7e 00 08 01 00 00 00 00 9a 35 sent from Port: to 192.168.1.58:3671 2023-07-21 17:31:14.234 - ^[[32minfo^[[39m: knx.0 (2834634) Received CONNECTIONSTATE_RESPONSE : 06 10 02 08 00 08 7e 00 192.168.1.58:3671 ChID : 126 SeqCntIN : 2 SeqCntOUT : 1 msgCode : [object Object] 2023-07-21 17:31:16.236 - ^[[32minfo^[[39m: knx.0 (2834634) Send : UDP Connection State Request : 06 10 02 07 00 10 7e 00 08 01 00 00 00 00 9a 35 sent from Port: to 192.168.1.58:3671 2023-07-21 17:31:16.236 - ^[[32minfo^[[39m: knx.0 (2834634) Received CONNECTIONSTATE_RESPONSE : 06 10 02 08 00 08 7e 00 192.168.1.58:3671 ChID : 126 SeqCntIN : 2 SeqCntOUT : 1 msgCode : [object Object] 2023-07-21 17:31:18.238 - ^[[32minfo^[[39m: knx.0 (2834634) Send : UDP Connection State Request : 06 10 02 07 00 10 7e 00 08 01 00 00 00 00 9a 35 sent from Port: to 192.168.1.58:3671 2023-07-21 17:31:18.238 - ^[[32minfo^[[39m: knx.0 (2834634) Received CONNECTIONSTATE_RESPONSE : 06 10 02 08 00 08 7e 00 192.168.1.58:3671 ChID : 126 SeqCntIN : 2 SeqCntOUT : 1 msgCode : [object Object] 2023-07-21 17:31:20.239 - ^[[32minfo^[[39m: knx.0 (2834634) Send : UDP Connection State Request : 06 10 02 07 00 10 7e 00 08 01 00 00 00 00 9a 35 sent from Port: to 192.168.1.58:3671 2023-07-21 17:31:20.240 - ^[[32minfo^[[39m: knx.0 (2834634) Received CONNECTIONSTATE_RESPONSE : 06 10 02 08 00 08 7e 00 192.168.1.58:3671 ChID : 126 SeqCntIN : 2 SeqCntOUT : 1 msgCode : [object Object] 2023-07-21 17:31:22.232 - ^[[32minfo^[[39m: knx.0 (2834634) checkConnectionState 192.168.1.58 State : true 2023-07-21 17:31:22.232 - ^[[32minfo^[[39m: knx.0 (2834634) Send : conCheck Connection State Request : 06 10 02 07 00 10 7e 00 08 01 00 00 00 00 9a 35 sent to 192.168.1.58:3671 2023-07-21 17:31:22.233 - ^[[32minfo^[[39m: knx.0 (2834634) Received CONNECTIONSTATE_RESPONSE : 06 10 02 08 00 08 7e 00 192.168.1.58:3671 ChID : 126 SeqCntIN : 2 SeqCntOUT : 1 msgCode : [object Object] 2023-07-21 17:31:24.233 - ^[[32minfo^[[39m: knx.0 (2834634) Send : UDP Connection State Request : 06 10 02 07 00 10 7e 00 08 01 00 00 00 00 9a 35 sent from Port: to 192.168.1.58:3671 2023-07-21 17:31:24.233 - ^[[32minfo^[[39m: knx.0 (2834634) Received CONNECTIONSTATERESPONSE : 06 10 02 08 00 08 7e 00 192.168.1.58:3671 ChID : 126 SeqCntIN : 2 SeqCntOUT : 1 msgCode : [object Object]

Ich habe extra mal den Zeitraum davor/danach auch mitkopiert.

Es sieht jetzt für mich so aus, als ob im KNX-Bus der Status sauber übermittelt wird, aber der ioBroker-KNX-Adapater ihn nicht empfängt. Wo/wie kann ich jetzt mehr herausfinden und forschen? Das einzige was mir noch einfällt, wäre ein TCPDUMP, aber das macht dann weniger Spaß den zu lesen oder zu interpretieren.

Leider muss ich auch noch ergänzen, dass ich manchmal das Problem beim "schreiben" einer GA habe. Das möchte ich jetzt aber bewusst draußen lassen, damit wir uns erstmal um das korrekte Empfangen des "Status" kümmern können. Vielleicht löst sich das Problem dann auch von selbst.

chefkoch009 commented 11 months ago

Hallo, Hast du mehrere Linien? Warum arbeitest Du mit 0.0.1 und 1.1.x? Welche Versionen haben: der js-Controller, node, Admin und knx-Adapter? Im log stehen conState Requests....wie viele Geräte inkl. ETS greifen auf dein LAN-GW zu?

VG chefkoch009

TheBigS1981 commented 11 months ago

Hallo, Hast du mehrere Linien? Warum arbeitest Du mit 0.0.1 und 1.1.x? Welche Versionen haben: der js-Controller, node, Admin und knx-Adapter? Im log stehen conState Requests....wie viele Geräte inkl. ETS greifen auf dein LAN-GW zu?

VG chefkoch009

Hallo und danke für Deine schnelle Meldung. Zu Deinen Fragen:

Versionsübersicht

js-controller: 5.0.8 admin: 6.6.1 Node.js: 18.17.0 NPM: 9.6.7 knx-Adapter: 2.0.22

Ist meines erachtens alles ok und auf dem neusten Beta-Stand.

Aufgrund Deiner Fragen habe ich mir mal wieder Webinterface vom MDT LAN-GW angeschaut und hab gesehen, dass dieses den ioBroker mit seiner IP auf die Tunnelig Adresse 0. 0. 4 gemappt hat. Ich werde das mal anpassen und alle in den 1.x.x Bereich schieben. Wobei das nach meinem KNX-Verständnis doch eigentlich keine Auswirkung haben dürfte.

TheBigS1981 commented 11 months ago

@chefkoch009 ich habe wie vorhin erwähnt, die physikalische Adresse vom ioBroker auf die gesetzt, die mir das LAN-GW angezeigt hat. Seit der Änderung, habe ich die ganze Zeit alles durchgetestet. Ich befürchte, dass das tatsächlich die Ursache war. Aktuell funktioniert alles tadellos.

Ich werde das jetzt natürlich weiter beobachten und auch gerne darüber berichten. Übers Wochenende werde ich definitiv herausfinden, ob alles jetzt wieder sauber läuft.

Allerdings ist mir völlig unklar, wieso das die letzten fünf Jahre gut funktioniert hat,

Danke für den Denkanstoß.

chefkoch009 commented 11 months ago

Wenn 2 Geräte die gleiche physikalische Adresse haben, dann antwortet immer der schnellere. Wenn dieser nun aber nix gemacht hat oder nix zum antworten hat, dann kommt genau nichts. Der knx adapter MUSS eine FREIE Adresse von dem netzsegment bekommen. Ist aber schön das es nun bei Dir läuft. Bei anderen Auffälligkeiten gern wieder melden.

TheBigS1981 commented 11 months ago

Wenn 2 Geräte die gleiche physikalische Adresse haben, dann antwortet immer der schnellere. Wenn dieser nun aber nix gemacht hat oder nix zum antworten hat, dann kommt genau nichts. Der knx adapter MUSS eine FREIE Adresse von dem netzsegment bekommen. Ist aber schön das es nun bei Dir läuft. Bei anderen Auffälligkeiten gern wieder melden.

Leider war meine Vorfreude falsch. Das Problem besteht leider weiterhin. Es tritt nach wie vor bei Rollläden und Lichtern auf. Deshalb habe ich mir die Sache jetzt doch mal mit TCPDUMP und Wireshark genauer angeschaut. Daher vorab hier noch eine Erklärung dazu:

Der KNX-Adapter frägt ja beim Neustart den Status aller bekannten Adressen ab. Daher habe ich jetzt auf meinem ioBroker Server TCPDUMP laufen lassen, gleichzeitig das KNX-Adapter-Log auf "alles" gestellt, meine ETS-Diagnose laufen lassen und anschließend den ioBroker KNX-Adapter neu gestartet. Das ganze begrenze ich jetzt auf das Schlafzimmer-Licht, da laut ioBroker dieses schon die ganze Nacht an ist ;). Es ist dort also nicht der Status "aus" beim ioBroker Adapter angekommen. Durch den Neustart und die erneute Abfrage des Status, sollte sich das ja jetzt korrigieren.

knx.0.DG_Schlafzimmer.Beleuchtung_Decke.DG_Schlafzimmer_Beleuchtung_Decke_An-Aus Gruppenadresse: 15/4/0

knx.0.DG_Schlafzimmer.Beleuchtung_Decke.DG_Schlafzimmer_Beleuchtung_Decke_An-Aus_Status Gruppenadresse: 15/4/1

Hier die Ergebnisse:

KNX-Adapter-Log

2023-07-23 12:49:20.882 - info: knx.0 (2327482) DPP erstellt für : 15/4/0 DG Schlafzimmer Beleuchtung Decke An-Ausmit DPT1.001 2023-07-23 12:49:20.882 - info: knx.0 (2327482) DPP erstellt für : 15/4/2 DG Schlafzimmer Beleuchtung Decke Dimmen absolutmit DPT5.001 2023-07-23 12:49:24.634 - info: knx.0 (2327482) ( 1 ) Sending : GroupValueRead : 06 10 04 20 00 15 04 0d 21 00 11 00 bc e0 11 02 7c 01 01 00 00 sent to 192.168.1.58:3671 ChID: 13 SeqCntIN : 65 SeqCntOUT : 33 GA : 15/4/1 conCheck.conected : true 2023-07-23 12:49:24.758 - info: knx.0 (2327482) ( 1 ) Sending : GroupValueRead : 06 10 04 20 00 15 04 0d 22 00 11 00 bc e0 11 02 7c 03 01 00 00 sent to 192.168.1.58:3671 ChID: 13 SeqCntIN : 65 SeqCntOUT : 34 GA : 15/4/3 conCheck.conected : true

Man kann schön sehen, dass er den Status von 15/4/1 abfragt.

ETS-Diagnose

image

Wireshark

image

Die Uhrzeiten werden in Wireshark im UTC-Format angezeigt. Sind also zwei Stunden hinterher. Man kann aber bei Wireshark sehen, dass ganz offensichtlich das UDP-Paket raus geht und gleich darauf ein "OK" kommt. Ich bin jetzt nicht der mega Wiresharkexperte, aber es sieht für mich "ok" aus. Die Frage ist jetzt, warum der Status, welcher definitiv im KNX-Bus zu sehen ist, beim ioBroker-KNX-Adapter nicht ankommt.

Hast Du vielleicht noch eine Idee, wo/wie ich das eingrenzen kann? Es muss ein Problem sein, was etwas mit Zufall zu tun hat. Übrigens, die Busverkehrs-Last ist während des Neustarts vom Adapter bei ca. 25 %. Ist also eigentlich auch weit weg von "zu viel". Ohne Neustart, ist die Last bei max. 5 %.

Zu den physikalischen Adressen: Es war zu keinem Zeitpunkt so, dass die physikalische Adresse des ioBroker KNX-Adapters doppelt vergeben war. Das einzige was mir komisch vorkam, war die Anzeige im Webinterface des MDT-LAN-Gateways. Dort wurde für den ioBroker eine andere "erkannte" physikalische Adresse angezeigt. Das ist jetzt aber ausgeschlossen und kann jetzt auch kein Grund mehr sein.

chefkoch009 commented 11 months ago

Hast du auf dem iobroker host eine Firewall laufen? Ist das Problem auf spezielle GA oder zeitlich eingrenzbar? Wie viele Geräte greifen auf den GW zu?

TheBigS1981 commented 11 months ago

Hast du auf dem iobroker host eine Firewall laufen? Ist das Problem auf spezielle GA oder zeitlich eingrenzbar? Wie viele Geräte greifen auf den GW zu?

Ich habe ioBroker in einem LXC-Container virtualisiert. Mein PVE-Host ist jetzt nicht mega ausgestattet, weshalb der Container ab und zu eine Load von mehr als 1 hat. Ich halte es eigentlich für ausgeschlossen, aber meinst Du es könnte damit zusammenhängen? Immerhin geht es um UDP-Pakete. Hat easy-knx.js selbst noch mehr Log- oder Debug-Möglichkeiten?

TheBigS1981 commented 11 months ago

Hallo @chefkoch009 ,

ich habe gute Neuigkeiten. Nach meinem letzten Post am Sonntag, habe ich nach Updates vom MDT-IP-Gateway geschaut. Mein letztes war schon eine weile her. Ich hab dann auch eines gefunden und es installiert. Laut Changelog waren zwar keine Änderungen dabei, die auf mein Fehlerbild hindeuten, aber ich denke durch den Neustart des Gateways haben sich meine Probleme erledigt. Seit dem, kommen alle Status sauber zum ioBroker-KNX-Adapter und die darauf aufbauenden Funktionen/Automatisierungen funktionieren wieder richtig. Ich denke damit kann man das Issue schließen.

Trotzdem Danke :)

chefkoch009 commented 11 months ago

Danke für die Rückmeldung und vorallem die Beschreibung der Ursache und deren Behebung.