Ankündigung

**Art Mooney** · 28.11.2021, 20:53

Fortsetzung:

Man sieht oben, dass die Items zwar im Log von SHNG die richtigen Werte haben, diese aber nicht immer auf den Bus gesendet werden. Die Zeiten stimmen in den Sekunden nicht ganz überein. Die ETS läuft nicht auf demselben Rechner wie SHNG, daher gibt es einen Versatz bei den genauen Uhrzeiten.

Beispiel: Um 19:32 schickt SHNG für beide Sperr-Items, 1/6/131 und 1/6/132, einen Wert, nämlich soll die helle Beleuchtung gesperrt sein (1/6/131 = 1) und die gedimmte Beleuchtung freigegeben (1/6/132 = 0). In SHNG ist das richtig. Auf dem Bus kommt aber nur an 1/6/132 = 0. Der Wert 1 für die 1/6/131 kommt nicht auf den Bus. Daher das Fehlerbild = helle Beleuchtung wird geschaltet, obwohl nur gedimmtes Licht brennen soll.

Man sieht hier auch: um ca. 19:41 habe ich am Tastsensor das Nachtobjekt O4.NIGH auf True gesetzt, woraufhin beide Kanäle gesperrt wurden. Das kommt auch auf dem Bus an. Drei Sekunden danach setzte ich das Nachtobjekt wieder auf False und direkt im Anschluss liefert SHNG die richtigen Werte für die Sperrobjekte, die diesmal auch den Bus erreichen. Die richtigen Leuchten brannten.

Ich fühle mich erinnert an ein anderes Problem, das ich vor einiger Zeit hatte (Link). Dort wurde auch ein Item nicht auf den Bus gesendet, obwohl in der Logik kein Fehler feststellbar war. Das Problem habe ich mit einem Workaround gelöst, ohne zur Ursache des Problems vorzudringen.

Die Logik für die Sperren wird übrigens immer gestartet, wenn das Item TIME.PLAYTIME oder O4.NIGH gesendet wird.

Noch ein paar Details zu meinem System:

SHNG-Version 1.8.2
KNX-Version 1.7.7
Plugins-Version 1.8.2

Ich freue mich auf Eure Tipps.

**bmx** · 01.12.2021, 18:58

Du hast hier extrem viel geschrieben aber sich da reinzudenken ist recht aufwendig. Zum Einen stimmen die Zeiten nicht genau überein (warum eigentlich nicht?) so das keine exakte Prüfung erfolgen kann. Zum anderen hast Du viel weggelassen aber unnötiges nicht entfernt. Beispiel die Spalte mit den Flags ist leer, also kann die auch weggelassen werden.

Aus der ETS Tabelle geht IMHO eine hohe Buslast hervor, das kann aber nicht überprüft werden, weil nicht genügend Daten gepostet wurden.

Ich bin mir recht sicher das SHNG die Daten korrekt aufbereitet und auch an den knxd schickt. Wenn auf dem Weg Telegramme verloren gehen kann das durch Überlastung der Schnittstelle vom knxd liegen bzw. an der Übergabe der Schnittstelle auf den Bus.

Du kannst versuchen das Problem isoliert nachzustellen und dann stückweise zu testen.

**Art Mooney** · 01.12.2021, 22:39

Ich habe viel geschrieben, damit mögliche Fehler auffallen. Leider hatte ich keine Ahnung, wo das Problem liegen kann.

Danke für den Hinweis mit der überlasteten Schnittstelle. Das könnte das Problem sein, denn es wird eines der beiden Telegramme, die in der Logik gleichzeitig ausgegeben werden, nicht auf den Bus geschrieben. Vielleicht gehen einfach nicht beide gleichzeitig durch. Ich habe jetzt einmal ein "time.sleep(5)" zwischen die beiden Ausgaben gesetzt und schaue, ob das etwas ändert.

Zudem werde ich die Buslast reduzieren. Das hatte ich mir sowieso vorgenommen.

Die unterschiedlichen Zeiten ergeben sich daraus, dass ich die ETS auf einem PC mit Internetverbindung und Kontakt zum Zeitserver ausführe. SHNG läuft auf einem Rechner, der keinen Zugang zum Internet hat und daher eine leicht abweichende Zeit hat.

**bmx** · 02.12.2021, 06:24

Schau doch auch mal ob das Problem exakt reproduzierbar ist, also auch zu unterschiedlichen Zeiten, oder ob das immer nur sporadisch auftritt

**Art Mooney** · 03.12.2021, 20:52

Das Problem trat zumindest häufig auf, wenn das zeitabhängige Item TIME.PLAYTIME von SHNG gesendet wurde. Wenn das vom KNX-Bus gesendete Item O4.NIGH die Logik auslöste, wurden die richtigen Werte auf den Bus gesendet.

Zur Klarstellung: die Logik hat die ganze Zeit richtig funktioniert. Nur das Ergebnis der Logik, also die beiden Items
O4.LICH.SPER1 und O4.LICH.SPER2 wurden nicht auf den Bus gesendet.

Die Buslast habe ich nun deutlich reduziert. Ich probiere gerade aus, ob es funktioniert, wenn ich das Zeititem TIME.PLAYTIME vom Bus senden lasse. In meinem oben verlinkten anderen Fall, hatte das auch das Problem gelöst, wobei ich dort ja auch nicht herausgefunden hatte, woran es genau lag.

**Art Mooney** · 07.12.2021, 21:17

So, nachdem es auch mit einem Zeit-Item direkt vom Bus nicht zuverlässig funktioniert, habe ich die Situation einfach nochmal mit frischen Items nachgestellt wie folgt:

Code:

TEST1:
    ITEM1:
        type: bool
        knx_dpt: 1
        knx_send: 0/2/100
        knx_listen:
        enforce_updates: True
        database: True
        cache: yes
        visu_acl: rw    
    ITEM2:
        type: bool
        knx_dpt: 1
        knx_send: 0/2/101
        enforce_updates: True
        database: True
        cache: yes
        visu_acl: rw      
    NIGH:   #Test-Nachtobjekt
        type: bool
        knx_dpt: 1
        knx_listen: 0/2/103
        knx_send: 0/2/103
        database: True
        cache: yes
        enforce_updates: True
        visu_acl: rw        
TEST2:
    TIME: #ein Zeitobjekt
        type: bool
        knx_dpt: 1
        knx_send: 0/2/102
        eval: 1 if sh.TIME.DAYTIME() < datetime.time(5, 30) or sh.TIME.DAYTIME() > datetime.time(20, 0) else 0
        cycle: 5m
        enforce_updates: True
        cache: yes
        visu_acl: rw

Und einer Logik wie folgt:

Code:

#!/usr/bin/env python3
# atest.py
if sh.TEST1.NIGH() == True:
    sh.TEST1.ITEM1(True)
    time.sleep(1)
    sh.TEST1.ITEM2(True)
elif sh.TEST1.NIGH() == False:
    if sh.TEST2.TIME() == True:  #Während der Testzeit
        sh.TEST1.ITEM1(False)
        time.sleep(1)
        sh.TEST1.ITEM2(True)
    elif sh.TEST2.TIME() == False:   #außerhalb der Testzeit
        sh.TEST1.ITEM2(False)
        time.sleep(1)
        sh.TEST1.ITEM1(True)

Ich habe die Logik so eingestellt, dass immer wenn TEST2.TIME gesendet wird, die Logik abgearbeitet wird. Jetzt ist es nach 20 Uhr. Also sollte alle 5 Minuten ein TEST1.ITEM1 mit Wert 0 und ein TEST1.ITEM2 mit Wert 1 auf den Bus gesendet werden, denn TEST1.NIGH ist False.

**Art Mooney** · 07.12.2021, 21:50

Mmh, jetzt kommen die Test-Telegramme wie erwartet auf den Bus. Es fehlt nicht eines davon, jedenfalls in den letzten 20 Minuten.

Wo liegt denn das Limit für die Belastung von SHNG? Mein smarthome-details Log-File hat seit heute 0:00 Uhr schon fast 600.000 Einträge. Kann das ein Problem sein?

**Art Mooney** · 09.12.2021, 20:36

Ich habe nun noch ein weiteres Telegramm entdeckt, das nicht auf den Bus gesendet worden ist, obwohl es im Log von SHNG auftaucht. Hier das Item, das detaillierte Log von SHNG und ein Auszug aus dem Log meines Wiregates:

Item:

Code:

TIME:
    DAYO: #Tagobjekt
        type: bool
        knx_dpt: 1
        knx_send: 0/0/222
        eval: 1 if sh.TIME.DAYTIME() > datetime.time(7, 0) and sh.TIME.DAYTIME() < datetime.time(19, 30) else 0
        cycle: 5m
        cache: yes
        visu_acl: rw

Man sieht im folgenden SHGN-Log, dass in derselben Sekunde viele weitere Telegramme im Log stehen, darunter das mit der Adresse 0/0/227. Dieses Item 0/0/227 sowie das 3/1/221 davor werden auf den Bus geschrieben, das 0/0/222 aber nicht.

SHNG-Log:

Code:

2021-12-09 19:29:59 CET DEBUG    __init__          logics.ventilation_auto groupwrite telegram for: 3/1/221 - Value: True sent.  --  (__init__.py:groupwrite:227)
2021-12-09 19:29:59 CET DEBUG    __init__          TIME.DAYO-eval groupwrite telegram for: 0/0/222 - Value: False sent.  --  (__init__.py:groupwrite:227)
2021-12-09 19:29:59 CET DEBUG    __init__          TIME.EEVEN-eval groupwrite telegram for: 0/0/227 - Value: False sent.  --  (__init__.py:groupwrite:227)
2021-12-09 19:29:59 CET INFO     __init__          plugins.knx.TCP_Client BM': 1.0.162 set 1/6/44 to 01  --  (__init__.py:parse_telegram:425)
2021-12-09 19:29:59 CET INFO     __init__          plugins.knx.TCP_Client BM': 1.0.162 set 1/6/43 to 00  --  (__init__.py:parse_telegram:425)
2021-12-09 19:29:59 CET INFO     __init__          plugins.knx.TCP_Client BM': 1.0.161 set 1/6/42 to 01  --  (__init__.py:parse_telegram:425)
2021-12-09 19:29:59 CET INFO     __init__          plugins.knx.TCP_Client BM': 1.0.222 set 3/0/216 to False  --  (__init__.py:parse_telegram:434)
2021-12-09 19:29:59 CET DEBUG    __init__          plugins.knx.TCP_Client write request from 1.0.222 to 3/0/216 with '00' and DPT 1  --  (__init__.py:parse_telegram:447)
2021-12-09 19:29:59 CET DEBUG    __init__          plugins.knx.TCP_Client Set Item 'D1.FAN.STAT.ERR' to value 'False' caller='knx', source='1.0.222', dest='3/0/216'  --  (__init__.py:parse_telegram:454)

Hier ein Auszug aus dem eib.log von meinem Wiregate:

Code:

2021-12-09 19:29:39.401,A_GroupValue_Write,1.0.252,8/4/216,00,,,,0,low,5,T_DATA_XXX_REQ,0
2021-12-09 19:29:39.469,A_GroupValue_Write,1.0.252,8/4/218,01,,,,0,low,5,T_DATA_XXX_REQ,0
2021-12-09 19:29:39.561,A_GroupValue_Write,1.0.222,3/3/224,74 07,,,,0,low,6,T_DATA_XXX_REQ,0
2021-12-09 19:29:39.583,A_GroupValue_Write,1.0.180,8/5/101,00 5A,,,,0,low,6,T_DATA_XXX_REQ,0
2021-12-09 19:29:41.285,A_GroupValue_Write,1.0.252,3/1/221,01,,,,0,low,5,T_DATA_XXX_REQ,0
2021-12-09 19:29:41.301,A_GroupValue_Write,1.0.252,0/0/227,00,,,,0,low,5,T_DATA_XXX_REQ,0
2021-12-09 19:29:41.341,A_GroupValue_Write,1.0.162,1/6/44,01,,,,0,low,6,T_DATA_XXX_REQ,0
2021-12-09 19:29:41.368,A_GroupValue_Write,1.0.162,1/6/43,00,,,,0,low,6,T_DATA_XXX_REQ,0
2021-12-09 19:29:41.381,A_GroupValue_Write,1.0.161,1/6/42,01,,,,0,low,6,T_DATA_XXX_REQ,0
2021-12-09 19:29:41.536,A_GroupValue_Write,1.0.222,3/0/216,00,,,,0,alarm,6,T_DATA_XXX_REQ,0
2021-12-09 19:29:41.995,A_GroupValue_Write,0.0.0,8/1/18,07 9E,19.5,DPT_Value_Temp,9.001,0,low,7,T_DATA_XXX_RE Q,0
2021-12-09 19:29:42.277,A_GroupValue_Write,1.0.180,8/5/101,00 28,,,,0,low,6,T_DATA_XXX_REQ,0
2021-12-09 19:29:42.326,A_GroupValue_Write,0.0.0,8/1/17,07 85,19.25,DPT_Value_Temp,9.001,0,low,7,T_DATA_XXX_R EQ,0
2021-12-09 19:29:42.663,A_GroupValue_Write,0.0.0,8/1/123,0C C9,24.5,DPT_Value_Temp,9.001,0,low,7,T_DATA_XXX_RE Q,0
2021-12-09 19:29:42.927,A_GroupValue_Write,1.0.186,8/4/151,01,,,,0,low,6,T_DATA_XXX_REQ,0
2021-12-09 19:29:42.944,A_GroupValue_Write,1.0.252,8/4/217,01,,,,0,low,5,T_DATA_XXX_REQ,0
2021-12-09 19:29:43.014,A_GroupValue_Write,1.0.252,8/4/218,01,,,,0,low,5,T_DATA_XXX_REQ,0
2021-12-09 19:29:43.105,A_GroupValue_Write,1.0.22,9/3/39,00 00 00 00,,,,0,low,6,T_DATA_XXX_REQ,0
2021-12-09 19:29:43.164,A_GroupValue_Write,1.0.182,8/4/121,00,,,,0,low,6,T_DATA_XXX_REQ,0

**Art Mooney** · 09.12.2021, 20:39

Damit scheint es naheliegend, dass ich entweder SHNG, den knxd oder die IP-Schnittstelle überfordere. Auch die oben angegebenen Testitems kommen nicht immer vollständig auf den KNX-Bus.

Wie sollte ich weiter vorgehen? Irgendwie die Arbeit von SHNG reduzieren?

**bmx** · 10.12.2021, 06:58

Also ich würde einfach mal im Webinterface vom knx Plugin im SHNG die Statistiken anschauen. Dort stehen die einzelnen GA bzw. PA mit der Anzahl der gesendeten oder empfangenen Telegramme. Da bekommst Du schon mal einen Eindruck was da viel Lärm macht und was eher unspektakulär ist.

Du kannst mal beim knxd schauen ob Du dort eine Telegrammratenbegrenzung hast oder nicht. Wenn nicht, könntest Du ggf. eine einstellen. Aber da der Bus nur eine endliche Last an Telegramme tragen kann musst Du die dauerhafte Belastung vermutlich reduzieren.

**Art Mooney** · 12.12.2021, 21:04

Danke für den Tipp mit den Statistiken des knx Plugin. Zum Verständnis: beziehen sich die Statistiken auf einen Tag? Also seit 0 Uhr?

**bmx** · 12.12.2021, 21:05

Nein, die beziehen sich auf den Start von SHNG

Es gibt eine (undokumentierte) Funktion um die Statistiken zurückzusetzen: clear_stats()
In einer Logik kann die per sh.knx.clear_stats() aufgerufen werden wenn Dein knx Plugin als knx registriert ist in der Plugin.yaml

**Art Mooney** · 13.12.2021, 22:04

OK, danke. Ich bin dabei die Anzahl der Items zu reduzieren. Hier wird allerhand zyklisch gesendet, was nicht nötig ist. Mal schauen, was das bringt.

**Art Mooney** · 09.01.2022, 20:33

So, nun habe ich einiges unternommen, um meine Buslast und die Arbeit von SHNG zu reduzieren. Die Anzahl der Einträge im Log ist um etwa 70% reduziert. Die Buslast auf dem KNX-Bus habe ich in ähnlichem Maße eingeschränkt. Meine Spannungsversorgung zeigt mir eine durchschnittliche Buslast von 4% an. Das Thema Last sollte jetzt also behoben sein.

Leider ist mein Problem jetzt immer noch nicht weg. Am einfachsten sieht man es wohl an den Test-items, die ich oben im Post #7 beschrieben habe. Auf dem Bus kommt folgendes an:

#

Zeit

Dienst

Quelladresse

Quellname

Zieladresse

Zielname

DPT

Info

19125

09.01.2022 17:29:33,019

vom Bus

1.0.251

IP-Tunnel 1

0/2/102

TEST2.TIME

1.001 Schalten

$00 | Aus

19127

09.01.2022 17:29:33,057

vom Bus

1.0.251

IP-Tunnel 1

0/2/101

TEST1.ITEM2

1.001 Schalten

$00 | Aus

19135

09.01.2022 17:29:33,988

vom Bus

1.0.251

IP-Tunnel 1

0/2/100

TEST1.ITEM1

1.001 Schalten

$01 | Ein

19616

09.01.2022 17:34:32,791

vom Bus

1.0.251

IP-Tunnel 1

0/2/102

TEST2.TIME

1.001 Schalten

$00 | Aus

19617

09.01.2022 17:34:32,806

vom Bus

1.0.251

IP-Tunnel 1

0/2/101

TEST1.ITEM2

1.001 Schalten

$00 | Aus

19618

09.01.2022 17:34:33,799

vom Bus

1.0.251

IP-Tunnel 1

0/2/100

TEST1.ITEM1

1.001 Schalten

$01 | Ein

20098

09.01.2022 17:39:33,089

vom Bus

1.0.251

IP-Tunnel 1

0/2/102

TEST2.TIME

1.001 Schalten

$00 | Aus

20100

09.01.2022 17:39:33,149

vom Bus

1.0.251

IP-Tunnel 1

0/2/101

TEST1.ITEM2

1.001 Schalten

$00 | Aus

20103

09.01.2022 17:39:34,097

vom Bus

1.0.251

IP-Tunnel 1

0/2/100

TEST1.ITEM1

1.001 Schalten

$01 | Ein

20499

09.01.2022 17:44:32,927

vom Bus

1.0.251

IP-Tunnel 1

0/2/102

TEST2.TIME

1.001 Schalten

$00 | Aus

20501

09.01.2022 17:44:32,965

vom Bus

1.0.251

IP-Tunnel 1

0/2/101

TEST1.ITEM2

1.001 Schalten

$00 | Aus

20502

09.01.2022 17:44:33,894

vom Bus

1.0.251

IP-Tunnel 1

0/2/100

TEST1.ITEM1

1.001 Schalten

$01 | Ein

20921

09.01.2022 17:49:32,701

vom Bus

1.0.251

IP-Tunnel 1

0/2/101

TEST1.ITEM2

1.001 Schalten

$00 | Aus

20924

09.01.2022 17:49:33,696

vom Bus

1.0.251

IP-Tunnel 1

0/2/100

TEST1.ITEM1

1.001 Schalten

$01 | Ein

21306

09.01.2022 17:54:32,979

vom Bus

1.0.251

IP-Tunnel 1

0/2/102

TEST2.TIME

1.001 Schalten

$00 | Aus

21309

09.01.2022 17:54:33,039

vom Bus

1.0.251

IP-Tunnel 1

0/2/101

TEST1.ITEM2

1.001 Schalten

$00 | Aus

21312

09.01.2022 17:54:33,988

vom Bus

1.0.251

IP-Tunnel 1

0/2/100

TEST1.ITEM1

1.001 Schalten

$01 | Ein

21662

09.01.2022 17:59:32,838

vom Bus

1.0.251

IP-Tunnel 1

0/2/102

TEST2.TIME

1.001 Schalten

$00 | Aus

21664

09.01.2022 17:59:32,882

vom Bus

1.0.251

IP-Tunnel 1

0/2/101

TEST1.ITEM2

1.001 Schalten

$00 | Aus

21666

09.01.2022 17:59:33,809

vom Bus

1.0.251

IP-Tunnel 1

0/2/100

TEST1.ITEM1

1.001 Schalten

$01 | Ein

Wie man sieht, funktioniert es meistens, aber nicht zum Beispiel um 17:49. Dort kommen zwar die beiden Items TEST1.ITEM2 und TEST1.ITEM1 auf den Bus, aber nicht TEST2.TIME. Im Log steht das ITEM richtig drin und die Logik liefert ja auch das richtige Ergebnis. Nur das Item landet nicht auf dem Bus.

Ankündigung

Item wird nicht auf den KNX-Bus gesendet

Item wird nicht auf den KNX-Bus gesendet

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar

Kommentar