HMUARTLGW Can't send ACK not originating from my hmId...

automatisierer · 16 November 2017, 07:08:28

Zur Info,
ich habe keine Probleme. Kann Temperaturen direkt an den HM-CC-RT-DN schicken. Die HT's sind mit HM-TC-IT-WM-W-EU gepeert.

IOs: HM-LGW und HM-LAN

khk123 · 16 November 2017, 13:20:11

Gleiche Probleme seit dem letzten Update auch bei meinen HM-CC-RT-DN. Version 15422 (# $Id: 10_CUL_HM.pm 15422 2017-11-11 16:43:17Z martinp876 $) liefert MISSING ACK. Restore der Version 15170 (# $Id: 10_CUL_HM.pm 15170 2017-10-02 08:11:26Z martinp876 $) und alles funktioniert wieder ohne Probleme.

CUL (V 1.67 CUL868 ) HM-CC-RT-DN D-firmware 1.4

Viele Grüße
Karlheinz

Jamo · 16 November 2017, 17:40:45

Die Fehlermeldung

Code Auswählen


HMUARTLGW hmuartwlangw: Can't send ACK not originating from my hmId (firmware bug), please use a VCCU virtual device!

kann daher kommen, das seperate virtuelle Devices angelegt sind, etwa durch (hier als Beispiel)

Code Auswählen

define virtueller_Aktor CUL_HM 123456
set LichtFlur1 peerChan 0 virtueller_Aktor_Btn1 single set

oder wie hier im Absatz "Mit virtuellem Aktor verbinden" beschrieben. https://wiki.fhem.de/wiki/HM-PB-2-WM55_2fach-Funk-Wandtaster#Mit_virtuellem_Aktor_verbinden

Die Lösung ist, falls Ihr eine VCCU habt, die Verknüpfung zu den virtuellen Devices aufzuheben (anstatt 'set' ein 'unset' machen),also

Code Auswählen

set LichtFlur1 peerChan 0 virtueller_Aktor_Btn1 single unset

Dann in der VCCU neue virtuelle devices definieren (z.B. mit set VCCU virtual 5, man bekommt vccu_Btn1 ... vccu_Btn5 als neue devices).

Danach wieder eine Verknüpfung, aber diesmal mit dem Virtuellen Aktor der VCCU

Code Auswählen

set LichtFlur1 peerChan 0 vccu_Btn1 single set

Damist ist die Fehlermeldung dann verschwunden.

mgernoth · 17 November 2017, 08:49:14

Hallo,

Zitat von: inoma am 16 November 2017, 17:40:45
Die Fehlermeldung
Code Auswählen Erweitern
HMUARTLGW hmuartwlangw: Can't send ACK not originating from my hmId (firmware bug), please use a VCCU virtual device!
kann daher kommen, das seperate virtuelle Devices angelegt sind..

Ja, kann sie. Aber in diesem Fall ist war es ein Bug in CUL_HM.

Anscheinend gibt es auch noch weitere Bugs in CUL_HM zur Zeit.

An die Leute mit den nicht steuerbaren Heizkörperthermostaten: Was passiert, wenn ihr den additional CUL ACK aus der aktuellen CUL_HM rausschmeisst (Zeilen 2749 bis 2752)? Geht es dann?

Viele Grüße
Michael

uland2012 · 17 November 2017, 11:09:07

Hallo noansi und mdino,

meine HM-CC-RT-DN haben die FW 1.3
der USB CUL am RASPI hat die VERSION V 1.61 CUL868
der HM-SEC-SC-2 und HM-SEC-RHS beide die V2.4

Aktuell fahre ich wieder mit der CUL_HM V15170

Da bekomme ich saubere Rückmeldungen der HM-SEC-SC-2 und HM-SEC-RHS
(soll heißen die Aktionen werden mit grün und zügig bestätigt)

Die HM-CC-RT-DN antworten hiermit auch schnell und zügig.

Einzig die automatisierte Änderung des Registers mit

Code Auswählen

set *HM-CC_RT_DN* regset decalcWeekday *TAG*
wird nicht sauber verarbeitet. (MISSING ACK oder RESPONSE TIMEOUT:RegisterRead)

Das Register ändere ich seit 3 Jahren 2x pro Woche, dann aber nur in der Heizperiode, um die Entkalkungsfahrt zu umgehen.
Ich habe das Problem, dass die Entkalkungsfahrt grundsätzlich dazu führt, dass die RT's nicht mehr ordnungsgemäß passen,
und ich dann jedes mal neu adaptieren musste.

Aber scheinbar wird das Schreiben in den Register nicht ordentlich erkannt , oder zurückgemeldet.

VG
Uwe

noansi · 17 November 2017, 21:21:49

Hallo Zusammen,

ich habe nun auch einen HM-SEC-SC-2 mit Firmware 2.4.
Den habe ich mit mit FHEM gepairt (ich nutze eine VCCU), ein SCC ist dabei HM IODev, also bezüglich IO auch nur mit 38400 seriell angebunden.
Außerdem habe ich den HM-SEC-SC-2 mit einem HM-CC-RT-DN mit Firmware 1.4 auf dem WindowRec Channel 3 gepeert.

Ich nutze die TSCUL Firmware VTS 0.19 mitsamt Modulen https://forum.fhem.de/index.php/topic,24436.msg714173.html#msg714173, was jetzt nicht als Eigenwerbung gedacht sein soll.

Die Kommunikation in alle Richtungen klappt ohne Probleme. Alle Stati werden gesetzt, wie sie sollen. Auch das Setzen von decalcWeekday.

@Michael und @Martin hier ein Schaltbeispiel mit Öffnen und Schließen des Fensters:

Code Auswählen

2017.11.17 20:31:58.762 4: TSCUL_Parse: SCC_HM868  482959 A F101 16138740 00 0C 3C B441 559003 519E1F 0120C8 _bst -63.5dB -63.5
2017.11.17 20:31:58.901 4: TSCUL_Parse: SCC_HM868  483093 A F101 16138872 00 11 3C A002 519E1F 559003 0435461CA652AE02 -52.5dB -52.5
2017.11.17 20:31:59.039 4: TSCUL_Parse: SCC_HM868  483223 A F101 16139004 00 19 3C A003 559003 519E1F 3984930B437251E7B7F56A4015B5D441 -59.5dB -59.5
2017.11.17 20:31:59.146 4: TSCUL_Parse: SCC_HM868  483342 A F101 16139124 00 0E 3C 8002 519E1F 559003 00DB2ADCB5 -50.5dB -50.5
2017.11.17 20:31:59.265 4: TSCUL_Parse: SCC_HM868  483463 A F10C 16139244 00 0C 3D A241 559003 F11034 0120C8 -61dB _AEScommReq -61
2017.11.17 20:31:59.403 4: TSCUL_Parse: SCC_HM868  483595 A F103 16139344 01 11 3D A002 F11034 559003 04C8CAD5FD1FAD02 _CCAdly:4 _dhmSt:100
2017.11.17 20:31:59.540 4: TSCUL_Parse: SCC_HM868  483724 A F10E 16139504 00 19 3D A203 559003 F11034 7F58A5B573891D1E4A5D6E4D5EDAC2BD -60dB _AESauth -60
2017.11.17 20:31:59.555 4: TSCUL_Parse: SCC_HM868  483752 A F101 16139504 00 0C 3D A241 559003 F11034 0120C8 -61dB -61
2017.11.17 20:31:59.577 4: TSCUL_send:  SCC_HM868  483801                 As 11 3D 8002 F11034 559003 0101C8002FBAC234
2017.11.17 20:31:59.657 4: TSCUL_Parse: SCC_HM868  483852 A F103 16139604 01 0E 3D 8002 F11034 559003 002FBAC234 _CCAdly:4 _dhmSt:100
2017.11.17 20:31:59.772 4: TSCUL_Parse: SCC_HM868  483964 A F103 16139712 01 11 3D 8002 F11034 559003 0101C8002FBAC234 _CCAdly:4 _dhmSt:208
2017.11.17 20:32:06.511 4: TSCUL_Parse: SCC_HM868  490708 A F101 16146456 00 0C 3E B441 559003 519E1F 012100 _bst -64.5dB -64.5
2017.11.17 20:32:06.649 4: TSCUL_Parse: SCC_HM868  490841 A F101 16146588 00 11 3E A002 519E1F 559003 043C161CD122D902 -54.5dB -54.5
2017.11.17 20:32:06.787 4: TSCUL_Parse: SCC_HM868  490971 A F101 16146716 00 19 3E A003 559003 519E1F 4794EF16F3D1E6510FB296805928BC29 -64dB -64
2017.11.17 20:32:06.898 4: TSCUL_Parse: SCC_HM868  491094 A F101 16146836 00 0E 3E 8002 519E1F 559003 00AE397C30 -54.5dB -54.5
2017.11.17 20:32:07.015 4: TSCUL_Parse: SCC_HM868  491212 A F10C 16146956 00 0C 3F A241 559003 F11034 012100 -61.5dB _AEScommReq -61.5
2017.11.17 20:32:07.151 4: TSCUL_Parse: SCC_HM868  491343 A F103 16147056 01 11 3F A002 F11034 559003 04CC06006570A802 _CCAdly:4 _dhmSt:100
2017.11.17 20:32:07.288 4: TSCUL_Parse: SCC_HM868  491472 A F10E 16147216 00 19 3F A203 559003 F11034 0827CEF7F3C9C465160E8AC1D46AEF97 -61.5dB _AESauth -61.5
2017.11.17 20:32:07.305 4: TSCUL_Parse: SCC_HM868  491502 A F101 16147216 00 0C 3F A241 559003 F11034 012100 -61.5dB -61.5
2017.11.17 20:32:07.323 4: TSCUL_send:  SCC_HM868  491548                 As 11 3F 8002 F11034 559003 0101C800EA7E0444
2017.11.17 20:32:07.408 4: TSCUL_Parse: SCC_HM868  491603 A F103 16147316 01 0E 3F 8002 F11034 559003 00EA7E0444 _CCAdly:4 _dhmSt:100
2017.11.17 20:32:07.520 4: TSCUL_Parse: SCC_HM868  491713 A F103 16147424 01 11 3F 8002 F11034 559003 0101C800EA7E0444 _CCAdly:4 _dhmSt:208

Das zusätzliche ACK, welches für den HM-SEC-SC-2 gedacht ist, wird problemlos verarbeitet, keine rote LED beim HM-SEC-SC-2.

Was nun bei CUL mit V1.6x Firmware noch interessant wäre, wäre ein Rohdatenlog vom CUL, um zu schauen, ob die Messagenummer auch für beide ACKs die gleiche ist, ob die Authbytes auch bei beiden ACKs dran hängen und ob es ggf. Timing Probleme gibt. Kann jemand der Betroffenen das Rohdatenlog mal beisteuern?

Mit CUL V1.6x kommt es beim HM-CC-RT-DN vermutlich einfach nur zu Timing Problemen. Mit den Änderungen sehe ich keinen logischen Zusammenhang, dazu müsste schon das model -oder subType-Attribut nicht korrekt gesetzt sein (ergänzt um weitere Buchstaben, Tabs, Leerzeichen, etc.), da die Matches modifiziert wurden, um die etwas zu beschleunigen. (Oder ich habe Tomaten auf den Augen)
Eventuell Timing Probleme durch die zusätzliche IODev Zuweisung in CUL_HM_Parse, was halt etwas mehr Zeit kostet? Wenn der RT zu spät funktechnisch bedient wird, schläft er halt wieder ein.
Auch hier wäre ein Rohdatenlog wohl hilfreich.

Gruß, Ansgar.

noansi · 19 November 2017, 19:25:12

Hallo,

könnt Ihr bitte mal per shell mit

Code Auswählen

perl -v
Eure perl Version checken und mitteilen.

Nicht auszuschließen, dass das den Unterschied macht.

Gruß, Ansgar.

mgernoth · 19 November 2017, 20:17:30

Hallo,

koennten die Betroffenen bitte einmal diese 10_CUL_HM.pm testen:
https://rmdir.de/~michael/10_CUL_HM.pm

Das ist die aktuelle 10_CUL_HM jedoch mit der assignIO-Logik aus der alten Version.

Danke & Viele Gruesse
Michael

mdino · 20 November 2017, 07:04:39

Guten Morgen Michael,

ich habe gerade die geänderte Version von 10_CUL_HM.pm eingespielt. Nach den ersten Tests sieht es so aus, als wenn es damit funktioniert.

Vielen Dank!

@Ansgar: Meine Perl-Version: This is perl 5, version 20, subversion 2 (v5.20.2) built for arm-linux-gnueabihf-thread-multi-64int

Grüße

Matthias

Zitat von: mgernoth am 19 November 2017, 20:17:30
Hallo,

koennten die Betroffenen bitte einmal diese 10_CUL_HM.pm testen:
https://rmdir.de/~michael/10_CUL_HM.pm

Das ist die aktuelle 10_CUL_HM jedoch mit der assignIO-Logik aus der alten Version.

Danke & Viele Gruesse
Michael

arthur_dent_2015 · 29 Dezember 2017, 16:46:09

Hallo Michael,
bei mir taucht die Meldung immer noch auf.

Code Auswählen


2017.12.29 15:12:58 3: Events from device EP_DIS_Btn1:cmd_nr: 2,cmd: 2,cmd_event: EP_Btn1,cmd_2
2017.12.29 15:12:58 3: Events from device EP_Btn1:on
2017.12.29 15:12:58 3: Events from device EP_Disp_Btn1:cmd_nr: 1,cmd: 1,cmd_event: EP_Display_Btn1,cmd_1
2017.12.29 15:12:58 3: Events from device EP_Display_Btn1:Long 1_15 (to VAktor)
2017.12.29 15:12:58 3: EP_Display_Btn1 Long 1_15 (to VAktor)
2017.12.29 15:12:58 1: Perfmon: possible freeze starting at 15:12:57, delay is 1.782
2017.12.29 15:12:58 3: Events from device EP_Display_Btn1:Long 2_15 (to VAktor)
2017.12.29 15:12:59 3: EP_Display_Btn1 Long 2_15 (to VAktor)
2017.12.29 15:12:59 3: Events from device EP_Display_Btn1:Long 3_15 (to VAktor)
2017.12.29 15:12:59 3: EP_Display_Btn1 Long 3_15 (to VAktor)
2017.12.29 15:12:59 0: HMUARTLGW WLAN_CUL_HM: Can't send ACK not originating from my hmId (firmware bug), please use a VCCU virtual device!

und zwar immer im Zusammenhang mit meinem HM-Dis-EP-WM55.

Code Auswählen


Internals:
   CFGFN      
   DEF        4BD4C9
   IODev      hmusb
   LASTInputDev nanoCUL1
   MSGCNT     85
   NAME       HM_4BD4C9
   NOTIFYDEV  global
   NR         880
   NTFY_ORDER 50-HM_4BD4C9
   STATE      CMDs_done
   TYPE       CUL_HM
   WLAN_CUL_HM_MSGCNT 27
   WLAN_CUL_HM_RAWMSG 0501004E7780024BD4C9F1000200
   WLAN_CUL_HM_RSSI -78
   WLAN_CUL_HM_TIME 2017-12-29 15:59:42
   channel_01 EP_Display_Btn1
   channel_02 EP_Display_Btn2
   channel_03 EP_Display_Dis
   channel_04 EP_Display_Key1
   channel_05 EP_Display_Key2
   channel_06 EP_Display_Key3
   channel_07 EP_Display_Key4
   channel_08 EP_Display_Key5
   hmusb_MSGCNT 28
   hmusb_RAWMSG E4BD4C9,0000,0292CA7A,FF,FFBD,7780024BD4C9F1000200
   hmusb_RSSI -67
   hmusb_TIME 2017-12-29 15:59:42
   lastMsg    No:77 - t:02 s:4BD4C9 d:F10002 00
   nanoCUL1_MSGCNT 30
   nanoCUL1_RAWMSG A0A7780024BD4C9F1000200::-51.5:nanoCUL1
   nanoCUL1_RSSI -51.5
   nanoCUL1_TIME 2017-12-29 15:59:42
   protLastRcv 2017-12-29 15:59:42
   protResnd  3 last_at:2017-12-29 13:30:12
   protSnd    12 last_at:2017-12-29 15:59:42
   protState  CMDs_done
   rssi_at_WLAN_CUL_HM avg:-64.33 lst:-78 min:-78 max:-57 cnt:27 
   rssi_at_hmusb avg:-70.14 cnt:28 max:-67 min:-77 lst:-67 
   rssi_at_nanoCUL1 min:-57 max:-46.5 cnt:30 lst:-51.5 avg:-51.01 
   Helper:
     DBLOG:
       battery:
         fhemlogDB:
           TIME       1514559134.75121
           VALUE      ok
       state:
         fhemlogDB:
           TIME       1514559582.62711
           VALUE      CMDs_done
   READINGS:
     2017-12-29 15:59:42   CommandAccepted yes
     2017-09-22 18:17:55   D-firmware      1.1
     2017-12-21 15:41:02   D-serialNr      NEQ0711788
     2017-12-21 15:41:16   PairedTo        0xF10002
     2017-09-22 18:20:30   R-pairCentral   0xF10002
     2017-09-22 18:20:30   R-powerSupply   bat
     2017-12-21 15:41:16   RegL_00.        02:01 05:80 08:01 0A:F1 0B:00 0C:02 14:03 21:07  00:00
     2017-09-22 18:21:57   aesKeyNbr       00
     2017-12-29 15:52:14   battery         ok
     2017-12-21 15:41:11   powerOn         2017-12-21 15:41:11
     2017-12-29 15:59:42   state           CMDs_done
   helper:
     HM_CMDNR   119
     cSnd       11F100024BD4C98003830A125A75686175736513840A12,11F100024BD4C98003300A14C01CD01DE016F003
     mId        00FB
     regLst     ,0,1
     rxType     6
     supp_Pair_Rep 0
     ack:
       VAktor     EP_Display_Btn1:74
     bm:
       CUL_HM_Get:
         cnt        1
         mAr        
         max        0
         tot        0
       CUL_HM_Set:
         cnt        55
         mAr        HASH(0x58fc2e8); HM_4BD4C9; ?
         max        3
         tot        53
     expert:
       def        1
       det        0
       raw        1
       tpl        0
     io:
       newChn     +4BD4C9,00,00,00
       nextSend   1514559582.74365
       rxt        0
       vccu       VCCU
       p:
         4BD4C9
         00
         00
         00
     mRssi:
       mNo        77
       io:
         WLAN_CUL_HM -78
         hmusb      -67
         nanoCUL1   -51.5
     prt:
       bErr       0
       sProc      0
       rspWait:
     q:
       qReqConf   
       qReqStat   
     role:
       dev        1
     rssi:
       at_WLAN_CUL_HM:
         avg        -64.3333333333333
         cnt        27
         lst        -78
         max        -57
         min        -78
       at_hmusb:
         avg        -70.1428571428571
         cnt        28
         lst        -67
         max        -67
         min        -77
       at_nanoCUL1:
         avg        -51.0166666666667
         cnt        30
         lst        -51.5
         max        -46.5
         min        -57
     tmpl:
Attributes:
   IODev      hmusb
   IOgrp      VCCU
   autoReadReg 4_reqStatus
   expert     2_raw
   firmware   1.1
   model      HM-Dis-EP-WM55
   msgRepeat  3
   room       CUL_HM
   serialNr   NEQ0711788
   subType    display
   webCmd     getConfig:clear msgEvents

Bei mir läuft die Version

Code Auswählen


10_CUL_HM.pm 15686 2017-12-25 12:23:45Z martinp876

Peering mit virtuellem Aktor ist vorhanden:

Code Auswählen


Internals:
   CFGFN      
   DEF        4BD4C901
   NAME       EP_Display_Btn1
   NOTIFYDEV  global
   NR         881
   NTFY_ORDER 50-EP_Display_Btn1
   STATE      Long 18_17 (to VAktor)
   TYPE       CUL_HM
   chanNo     01
   device     HM_4BD4C9
   peerList   VAktor_Btn11,
   Helper:
     DBLOG:
       state:
         fhemlogDB:
           TIME       1514559134.72352
           VALUE      Long 18_17 (to VAktor)
   READINGS:
     2017-10-08 13:28:32   R-VAktor_Btn11-expectAES off
     2017-10-08 13:28:32   R-VAktor_Btn11-peerNeedsBurst off
     2017-09-22 18:21:01   R-sign          off
     2017-12-21 15:41:17   RegL_01.        08:00 30:03 36:48 37:4D 38:2D 39:44 3A:69 3B:73  3C:2D 3D:45 3E:50 3F:00 40:00 41:00 42:00 46:4B  47:41 48:4E 49:41 4A:4C 4B:20 4C:31 4D:00 4E:00  4F:00 50:00 51:00 00:00
     2017-12-21 15:41:26   RegL_04.VAktor_Btn11 01:00 00:00
     2017-12-29 04:00:39   peerList        VAktor_Btn11,
     2017-12-21 15:41:11   recentStateType info
     2017-12-29 15:52:14   state           Long 18_17 (to VAktor)
     2017-12-21 15:41:17   text1           HM-Dis-EP
     2017-12-21 15:41:17   text2           KANAL 1
     2017-12-29 15:52:14   trigger         Long_17
     2017-12-29 15:52:14   triggerTo_VAktor Long_17
     2017-12-29 15:52:14   trigger_cnt     17
   helper:
     BNO        17
     BNOCNT     18
     regLst     ,1,4p
     bm:
       CUL_HM_Get:
         cnt        3
         mAr        
         max        0
         tot        0
       CUL_HM_Set:
         cnt        42
         mAr        HASH(0x58fd5e0); EP_Display_Btn1; ?
         max        2
         tot        27
     expert:
       def        1
       det        0
       raw        1
       tpl        0
     role:
       chn        1
     tmpl:
Attributes:
   event-on-change-reading state
   model      HM-Dis-EP-WM55
   peerIDs    00000000,1234560B,
   room       CUL_HM

Perl ist Version:

Code Auswählen


pi@raspberrypi3:~ $ perl -v

This is perl 5, version 20, subversion 2 (v5.20.2) built for arm-linux-gnueabihf-thread-multi-64int

Ich hoffe Du kannst damit was anfangen...

Gruß
Arthur

arthur_dent_2015 · 29 Januar 2018, 10:01:36

keine Lösung in Sicht?

noansi · 29 Januar 2018, 20:10:04

Hallo Arthur,

hast Du diesen Hinweis oben https://forum.fhem.de/index.php/topic,79145.msg716708.html#msg716708 mal beachtet?
Dein virtueller Aktor hat die HMID 123456 wohingegen Deine VCCU und damit auch Dein WLAN_CUL_HM die HMID F10002 hat. Deswegen klappt es wohl nicht.

Alternativ kannst Du wohl noch versuchen mit dem Atrribut

Code Auswählen

attr HM_4BD4C9 IOgrp VCCU:hmusb,nanoCUL1
den WLAN_CUL_HM durch setzen eines VorzugsIOs zu meiden. Wenn der hmusb das gleiche Problem hat, dann nur den nanoCUL1 nehmen (ggf. dann Timing Probleme).

Gruß, Ansgar.