FHEM Forum

FHEM - Hausautomations-Systeme => Homematic => Thema gestartet von: vbs am 09 April 2015, 09:18:12

Titel: Verzögerung bei mehreren Befehle in Folge an HM-TC Wandthermostat
Beitrag von: vbs am 09 April 2015, 09:18:12
Hi Martin,

mir ist da ein komisches Verhalten aufgefallen, wenn ich mehrere Befehle zum Setzen der Soll-Temperatur eines HM-TC-Climate in Folge absetze. Und zwar vergehen immer mehrere Sekunden zwischen der Verarbeitung der Befehle im HMLAN-Modul. Also ich setze direkt 4 Befehle ab und dann dauert es ca. 10 Sekunden bis diese verarbeitet worden sind, was ich erstmal für unnormal halte.

Meiner Meinung nach, wird nur der erste Befehl mit ACK beantwortet und bei den weiteren Befehlen fehlt es, obwohl jedoch eine Antwort zu kommen scheint. Und ich denke, dass HMLAN wegen dem "no ACK" dann immer eine Pause eingelegt hat, um auf ACK zu warten, so dass zwischen zwei Sends dann ca. 3 Sekunden vergehen. Das sieht dann so aus im Log:
015.04.09 09:09:55.273 3: CUL_HM set wz_hmTcClimate desired-temp 15.5
2015.04.09 09:09:55.274 5: HMLAN_Send:  HMLAN0 S:S9D038416 stat:  00 t:00000000 d:01 r:9D038416 m:39 B011 F15544 261725 86041F
2015.04.09 09:09:55.275 3: CUL_HM set wz_hmTcClimate desired-temp 15.0
2015.04.09 09:09:55.275 3: CUL_HM set wz_hmTcClimate desired-temp 14.5
2015.04.09 09:09:55.276 3: CUL_HM set wz_hmTcClimate desired-temp 14.0
2015.04.09 09:09:55.813 5: HMLAN/RAW: /R9D038416,0001,8F35709E,FF,FFC4,398002261725F1554401021F203440

2015.04.09 09:09:55.814 5: HMLAN_Parse: HMLAN0 R:R9D038416 stat:0001 t:8F35709E d:FF r:FFC4     m:39 8002 261725 F15544 01021F203440
2015.04.09 09:09:55.814 5: HMLAN0 dispatch A0F398002261725F1554401021F203440::-60:HMLAN0
2015.04.09 09:09:55.878 5: HMLAN_Send:  HMLAN0 S:S9D038633 stat:  00 t:00000000 d:01 r:9D038633 m:3A A011 F15544 261725 86041E
2015.04.09 09:09:56.517 5: HMLAN/RAW: /R9D038633,0008,00000000,FF,7FFF,3AA011F1554426172586041E

2015.04.09 09:09:56.517 5: HMLAN_Parse: HMLAN0 R:R9D038633 stat:0008 t:00000000 d:FF r:7FFF     m:3A A011 F15544 261725 86041E
2015.04.09 09:09:56.518 5: HMLAN_Parse: HMLAN0 no ACK from 261725
2015.04.09 09:09:59.548 5: HMLAN_Send:  HMLAN0 S:S9D0394C8 stat:  00 t:00000000 d:01 r:9D0394C8 m:3A B011 F15544 261725 86041E
2015.04.09 09:10:00.101 5: HMLAN/RAW: /R9D0394C8,0001,8F35815E,FF,FFC3,3A8002261725F1554401021E203440

2015.04.09 09:10:00.102 5: HMLAN_Parse: HMLAN0 R:R9D0394C8 stat:0001 t:8F35815E d:FF r:FFC3     m:3A 8002 261725 F15544 01021E203440
2015.04.09 09:10:00.102 5: HMLAN0 dispatch A0F3A8002261725F1554401021E203440::-61:HMLAN0
2015.04.09 09:10:00.165 5: HMLAN_Send:  HMLAN0 S:S9D0396F3 stat:  00 t:00000000 d:01 r:9D0396F3 m:3B A011 F15544 261725 86041D
2015.04.09 09:10:00.805 5: HMLAN/RAW: /R9D0396F3,0008,00000000,FF,7FFF,3BA011F1554426172586041D

2015.04.09 09:10:00.805 5: HMLAN_Parse: HMLAN0 R:R9D0396F3 stat:0008 t:00000000 d:FF r:7FFF     m:3B A011 F15544 261725 86041D
2015.04.09 09:10:00.806 5: HMLAN_Parse: HMLAN0 no ACK from 261725
2015.04.09 09:10:02.920 5: HMLAN_Send:  HMLAN0 S:S9D03A1F4 stat:  00 t:00000000 d:01 r:9D03A1F4 m:3B B011 F15544 261725 86041D
2015.04.09 09:10:03.461 5: HMLAN/RAW: /R9D03A1F4,0001,8F358E7E,FF,FFC3,3B8002261725F1554401021D203440

2015.04.09 09:10:03.462 5: HMLAN_Parse: HMLAN0 R:R9D03A1F4 stat:0001 t:8F358E7E d:FF r:FFC3     m:3B 8002 261725 F15544 01021D203440
2015.04.09 09:10:03.462 5: HMLAN0 dispatch A0F3B8002261725F1554401021D203440::-61:HMLAN0
2015.04.09 09:10:03.527 5: HMLAN_Send:  HMLAN0 S:S9D03A413 stat:  00 t:00000000 d:01 r:9D03A413 m:3C A011 F15544 261725 86041C
2015.04.09 09:10:04.165 5: HMLAN/RAW: /R9D03A413,0008,00000000,FF,7FFF,3CA011F1554426172586041C

2015.04.09 09:10:04.166 5: HMLAN_Parse: HMLAN0 R:R9D03A413 stat:0008 t:00000000 d:FF r:7FFF     m:3C A011 F15544 261725 86041C
2015.04.09 09:10:04.166 5: HMLAN_Parse: HMLAN0 no ACK from 261725
2015.04.09 09:10:05.289 5: HMLAN_Send:  HMLAN0 S:S9D03AB35 stat:  00 t:00000000 d:01 r:9D03AB35 m:3C B011 F15544 261725 86041C
2015.04.09 09:10:05.290 4: HMLAN_ack: timeout - clear queue
2015.04.09 09:10:05.829 5: HMLAN/RAW: /R9D03AB35,0001,8F3597BE,FF,FFC4,3C8002261725F1554401021C203440

2015.04.09 09:10:05.830 5: HMLAN_Parse: HMLAN0 R:R9D03AB35 stat:0001 t:8F3597BE d:FF r:FFC4     m:3C 8002 261725 F15544 01021C203440
2015.04.09 09:10:05.830 5: HMLAN0 dispatch A0F3C8002261725F1554401021C203440::-60:HMLAN0
2015.04.09 09:10:05.881 4: HMLAN_ack: timeout - clear queue
2015.04.09 09:10:09.550 4: HMLAN_ack: timeout - clear queue
2015.04.09 09:10:10.169 4: HMLAN_ack: timeout - clear queue
2015.04.09 09:10:11.570 5: HMLAN_Send:  HMLAN0 I:K
2015.04.09 09:10:11.589 5: HMLAN/RAW: /HHM-LAN-IF,03C7,LEQ0659500,2CC53A,F15544,8F35AE3D,0018

2015.04.09 09:10:11.589 5: HMLAN_Parse: HMLAN0 V:03C7 sNo:LEQ0659500 d:2CC53A O:F15544 t:8F35AE3D IDcnt:0018
2015.04.09 09:10:12.924 4: HMLAN_ack: timeout - clear queue
2015.04.09 09:10:13.530 4: HMLAN_ack: timeout - clear queue
2015.04.09 09:10:15.291 4: HMLAN_ack: timeout - clear queue


Wenn ich das gleiche Spielchen mit einem Dimmer treibe, dann klappt das besser und es werden auch alle ACKs richtig erkannt (IMHO). Scheint für mich also irgendwie mit dem HM-TC zu tun haben.
2015.04.09 09:06:16.965 3: CUL_HM set wz_lightRed 30
2015.04.09 09:06:16.965 5: HMLAN_Send:  HMLAN0 S:S9D002F51 stat:  00 t:00000000 d:01 r:9D002F51 m:34 A011 F15544 2072A5 02013C0320FFFF
2015.04.09 09:06:16.967 3: CUL_HM set wz_lightRed 40
2015.04.09 09:06:16.969 3: CUL_HM set wz_lightRed 50
2015.04.09 09:06:16.971 3: CUL_HM set wz_lightRed 70
2015.04.09 09:06:17.159 5: HMLAN/RAW: /R9D002F51,0001,8F321A7B,FF,FFCC,3480022072A5F155440101011032

2015.04.09 09:06:17.159 5: HMLAN_Parse: HMLAN0 R:R9D002F51 stat:0001 t:8F321A7B d:FF r:FFCC     m:34 8002 2072A5 F15544 0101011032
2015.04.09 09:06:17.160 5: HMLAN0 dispatch A0E3480022072A5F155440101011032::-52:HMLAN0
2015.04.09 09:06:17.234 5: HMLAN_Send:  HMLAN0 S:S9D003015 stat:  00 t:00000000 d:01 r:9D003015 m:35 A011 F15544 2072A5 0201500320FFFF
2015.04.09 09:06:17.415 5: HMLAN/RAW: /R9D003015,0001,8F321B7A,FF,FFCC,3580022072A5F155440101091032

2015.04.09 09:06:17.415 5: HMLAN_Parse: HMLAN0 R:R9D003015 stat:0001 t:8F321B7A d:FF r:FFCC     m:35 8002 2072A5 F15544 0101091032
2015.04.09 09:06:17.416 5: HMLAN0 dispatch A0E3580022072A5F155440101091032::-52:HMLAN0
2015.04.09 09:06:17.484 5: HMLAN_Send:  HMLAN0 S:S9D003114 stat:  00 t:00000000 d:01 r:9D003114 m:36 A011 F15544 2072A5 0201640320FFFF
2015.04.09 09:06:17.671 5: HMLAN/RAW: /R9D003114,0001,8F321C7B,FF,FFCC,3680022072A5F155440101111031

2015.04.09 09:06:17.671 5: HMLAN_Parse: HMLAN0 R:R9D003114 stat:0001 t:8F321C7B d:FF r:FFCC     m:36 8002 2072A5 F15544 0101111031
2015.04.09 09:06:17.672 5: HMLAN0 dispatch A0E3680022072A5F155440101111031::-52:HMLAN0
2015.04.09 09:06:17.734 5: HMLAN_Send:  HMLAN0 S:S9D003215 stat:  00 t:00000000 d:01 r:9D003215 m:37 A011 F15544 2072A5 02018C0320FFFF
2015.04.09 09:06:17.927 5: HMLAN/RAW: /R9D003215,0001,8F321D7B,FF,FFCC,3780022072A5F1554401011B1032

2015.04.09 09:06:17.927 5: HMLAN_Parse: HMLAN0 R:R9D003215 stat:0001 t:8F321D7B d:FF r:FFCC     m:37 8002 2072A5 F15544 01011B1032
2015.04.09 09:06:17.928 5: HMLAN0 dispatch A0E3780022072A5F1554401011B1032::-52:HMLAN0
2015.04.09 09:06:22.791 5: HMLAN/RAW: /E2072A5,0000,8F32307F,FF,FFCB,38A4102072A5F1554406018C00

2015.04.09 09:06:22.791 5: HMLAN_Parse: HMLAN0 R:E2072A5   stat:0000 t:8F32307F d:FF r:FFCB     m:38 A410 2072A5 F15544 06018C00
2015.04.09 09:06:22.792 5: HMLAN0 dispatch A0D38A4102072A5F1554406018C00::-53:HMLAN0
2015.04.09 09:06:22.793 5: HMLAN: Skip ACK
2015.04.09 09:06:24.423 5: HMLAN/RAW: /E2DD2C6,0000,8F3236DA,FF,FFC6,F086102DD2C60000000A80B50E0040

2015.04.09 09:06:24.423 5: HMLAN_Parse: HMLAN0 R:E2DD2C6   stat:0000 t:8F3236DA d:FF r:FFC6     m:F0 8610 2DD2C6 000000 0A80B50E0040
2015.04.09 09:06:24.424 5: HMLAN0 dispatch A0FF086102DD2C60000000A80B50E0040::-58:HMLAN0
2015.04.09 09:06:24.711 5: HMLAN/RAW: /E0B69DC,0000,8F3237E6,FF,FFBE,A4A2700B69DCF1554400585327CB00065F040A28

2015.04.09 09:06:24.711 5: HMLAN_Parse: HMLAN0 R:E0B69DC   stat:0000 t:8F3237E6 d:FF r:FFBE     m:A4 A270 0B69DC F15544 00585327CB00065F040A28
2015.04.09 09:06:24.712 5: HMLAN0 dispatch A14A4A2700B69DCF1554400585327CB00065F040A28::-66:HMLAN0
2015.04.09 09:06:24.713 5: HMLAN: Skip ACK
2015.04.09 09:06:26.486 5: HMLAN_Send:  HMLAN0 I:K
2015.04.09 09:06:26.535 5: HMLAN/RAW: /HHM-LAN-IF,03C7,LEQ0659500,2CC53A,F15544,8F323F21,0018

2015.04.09 09:06:26.535 5: HMLAN_Parse: HMLAN0 V:03C7 sNo:LEQ0659500 d:2CC53A O:F15544 t:8F323F21 IDcnt:0018
2015.04.09 09:06:26.970 4: HMLAN_ack: timeout - clear queue
2015.04.09 09:06:27.236 4: HMLAN_ack: timeout - clear queue
2015.04.09 09:06:27.486 4: HMLAN_ack: timeout - clear queue
2015.04.09 09:06:27.736 4: HMLAN_ack: timeout - clear queue


EDIT:
Also diese Pause finde ich seltsam:
2015.04.09 09:09:56.518 5: HMLAN_Parse: HMLAN0 no ACK from 261725
2015.04.09 09:09:59.548 5: HMLAN_Send:  HMLAN0 S:S9D0394C8 stat:  00 t:00000000 d:01 r:9D0394C8 m:3A B011 F15544 261725 86041E

Da wird die Antwort der vorherigen Nachricht empfangen, aber dann dauert es ca. 3 Sekunden, bis die nächste Nachricht verschickt wird.
Titel: Antw:Verzögerung bei mehreren Befehle in Folge an HM-TC Wandthermostat
Beitrag von: vbs am 09 April 2015, 18:21:24
Achso, vergessen zu erwähnen:
Den ersten Test mit HM-TC hab ich dem Befehl gemacht:
set sz_hmTcClimate desired-temp 15.0;set sz_hmTcClimate desired-temp 15.5;set sz_hmTcClimate desired-temp 16.0

Und das mit den Dimmern so:
set wz_lightRed 30;set wz_lightRed 40;set wz_lightRed 50;set wz_lightRed 70
Titel: Antw:Verzögerung bei mehreren Befehle in Folge an HM-TC Wandthermostat
Beitrag von: martinp876 am 11 April 2015, 08:13:16
der dimmer hat klar kein Problem. Es ist das burst handling.
ich habe es modifiziert - sollte jetzt besser laufen
Titel: Antw:Verzögerung bei mehreren Befehle in Folge an HM-TC Wandthermostat
Beitrag von: vbs am 11 April 2015, 10:43:11
Danke dir Martin, klappt super! Die drei Befehle werden jetzt in ca. 500 ms verarbeitet:
2015-04-11 10:42:30.247 CUL_HM sz_hmTcClimate desired-temp: 15.0
2015-04-11 10:42:30.544 CUL_HM sz_hmTcClimate desired-temp: 15.5
2015-04-11 10:42:30.752 CUL_HM sz_hmTcClimate desired-temp: 16.0