HM-CC-TC paired nicht mit vccu

[FilliFairy]

Hallo zusammen,

nachdem die HM Geräte viele Monate stabil liefen kam ich durch einige Änderungen im Haus in die Situation, dass ich einige Geräte resettet habe und nun das pairen nicht mehr funktioniert.

Die Batterien sind frisch gewechselt und die Geräte auf Werkseinstellungen zurückgesetzt.
FHEM habe ich heute aktualisiert.

Ich habe 2 HM-CFG-LAN, die mit einer vccu zusammenfasst sind.
Das Pairing mache ich über set vccu set vccu hmPairForSec 600.
Am HM-CC-TC aktiviere ich das pairing, der Zähler stoppt nach wenigen Sekunden und zeigt NOK im Display.

Leider kann ich die Infos im Log nicht deuten:

Code Auswählen Erweitern



2017.07.02 12:40:53.778 3: CUL_HM set vccu hmPairForSec 600
2017.07.02 12:40:54.854 0: HMLAN_Parse: HMLAN1 R:E19E597   stat:0000 t:122877BC d:FF r:FFCC     m:BB A410 19E597 3D2DD3 06022A00000000
2017.07.02 12:40:54.917 0: HMLAN_Parse: HMLAN2 R:E19E597   stat:0000 t:17BD66B0 d:FF r:FFB1     m:BB A410 19E597 3D2DD3 06022A00000000
2017.07.02 12:40:54.921 0: HMLAN_Parse: HMLAN2 R:E3D2DD3   stat:0000 t:17BD6726 d:FF r:FFB3     m:BB 8002 3D2DD3 19E597 00
2017.07.02 12:40:58.412 0: HMLAN_Send:  HMLAN2 I:K
2017.07.02 12:40:58.453 0: HMLAN_Parse: HMLAN2 V:03C4 sNo:LEQ0383614 d:29A48B O:3D2DD3 t:17BD7797 IDcnt:0013 L:8 %
2017.07.02 12:41:05.454 0: HMLAN_Parse: HMLAN1 R:E20256E   stat:0000 t:1228A253 d:FF r:FFBE     m:3A 8400 20256E 000000 2100394B4551303037393638325800FFFF
2017.07.02 12:41:05.493 0: HMLAN_Send:  HMLAN1 I:+20256E,02,00,00
2017.07.02 12:41:05.502 0: HMLAN_Send:  HMLAN1 S:S02E3BD39 stat:  00 t:00000000 d:01 r:02E3BD39 m:62 A001 3D2DD3 20256E 00050000000000
2017.07.02 12:41:05.522 0: HMLAN_Parse: HMLAN2 R:E20256E   stat:0000 t:17BD9146 d:FF r:FFAE     m:3A 8400 20256E 000000 2100394B4551303037393638325800FFFF
2017.07.02 12:41:06.224 0: HMLAN_Parse: HMLAN1 R:R02E3BD39 stat:0001 t:1228A4F2 d:FF r:FFBD     m:62 8002 20256E 3D2DD3 00
2017.07.02 12:41:06.233 0: HMLAN_Send:  HMLAN1 S:S02E3C015 stat:  00 t:00000000 d:01 r:02E3C015 m:63 A001 3D2DD3 20256E 000802010A3D0B2D0CD3
2017.07.02 12:41:06.233 0: HMLAN_Send:  HMLAN1 I:K
2017.07.02 12:41:06.241 0: HMLAN_Parse: HMLAN2 R:E3D2DD3   stat:0000 t:17BD9361 d:FF r:FFB3     m:62 A001 3D2DD3 20256E 00050000000000
2017.07.02 12:41:06.247 0: HMLAN_Parse: HMLAN2 R:E20256E   stat:0000 t:17BD93E0 d:FF r:FFAF     m:62 8002 20256E 3D2DD3 00
2017.07.02 12:41:07.794 0: HMLAN_Parse: HMLAN1 V:03C4 sNo:IEQ0061733 d:1398A7 O:3D2DD3 t:1228A733 IDcnt:001F L:4 %
2017.07.02 12:41:07.795 0: HMLAN_Parse: HMLAN1 R:R02E3C015 stat:0001 t:1228A7CE d:FF r:FFBD     m:63 8002 20256E 3D2DD3 00
2017.07.02 12:41:07.804 0: HMLAN_Send:  HMLAN1 S:S02E3C638 stat:  00 t:00000000 d:01 r:02E3C638 m:64 A001 3D2DD3 20256E 0006
2017.07.02 12:41:07.811 0: HMLAN_Parse: HMLAN2 R:E3D2DD3   stat:0000 t:17BD9640 d:FF r:FFB3     m:63 A001 3D2DD3 20256E 000802010A3D0B2D0CD3
2017.07.02 12:41:07.816 0: HMLAN_Parse: HMLAN2 R:E20256E   stat:0000 t:17BD96BC d:FF r:FFAE     m:63 8002 20256E 3D2DD3 00
2017.07.02 12:41:08.152 0: HMLAN_Parse: HMLAN2 R:E3D2DD3   stat:0000 t:17BD9C5D d:FF r:FFB3     m:64 A001 3D2DD3 20256E 0006
2017.07.02 12:41:08.158 0: HMLAN_Parse: HMLAN2 R:E3D2DD3   stat:0000 t:17BD9D25 d:FF r:FFB3     m:64 A001 3D2DD3 20256E 0006
2017.07.02 12:41:08.160 4: CUL_HM vccu dupe: dont process
2017.07.02 12:41:10.630 0: HMLAN_Parse: HMLAN1 R:R02E3C638 stat:0008 t:00000000 d:FF r:7FFF     m:64 A001 3D2DD3 20256E 0006
2017.07.02 12:41:10.631 0: HMLAN_Parse: HMLAN1 no ACK from 20256E
2017.07.02 12:41:10.632 0: HMLAN_Parse: HMLAN2 R:E3D2DD3   stat:0000 t:17BD9DED d:FF r:FFB3     m:64 A001 3D2DD3 20256E 0006
2017.07.02 12:41:10.636 4: CUL_HM vccu dupe: dont process

Der HM-CC-TC sieht nach der Aktion so aus:

Code Auswählen Erweitern


Internals:
   CFGFN      ./FHEM/fhemDevice.cfg
   CHANGED
   DEF        20256E
   HMLAN1_MSGCNT 26
   HMLAN1_RAWMSG E20256E,0000,122DE393,FF,FFBC,3C867020256E000000010138
   HMLAN1_RSSI -68
   HMLAN1_TIME 2017-07-02 12:46:52
   HMLAN2_MSGCNT 26
   HMLAN2_RAWMSG E20256E,0000,17C2D28D,FF,FFA1,3C867020256E000000010138
   HMLAN2_RSSI -95
   HMLAN2_TIME 2017-07-02 12:46:52
   IODev      HMLAN1
   LASTInputDev HMLAN2
   MSGCNT     52
   NAME       GG_ElwBad600_B1
   NOTIFYDEV  global
   NR         939
   NTFY_ORDER 50-GG_ElwBad600_B1
   STATE      MISSING ACK
   TYPE       CUL_HM
   channel_01 GG_ElwBad600_B1_Weather
   channel_02 GG_ElwBad600_B1_Climate
   channel_03 GG_ElwBad600_B1_WindowRec
   lastMsg    No:3C - t:70 s:20256E d:000000 010138
   protCmdDel 18
   protLastRcv 2017-07-02 12:46:52
   protResnd  7 last_at:2017-07-02 12:44:51
   protResndFail 2 last_at:2017-07-02 12:46:59
   protSnd    14 last_at:2017-07-02 12:46:52
   protState  CMDs_done_Errors:1
   rssi_at_HMLAN1 avg:-67.19 cnt:25 max:-63 lst:-68 min:-70
   rssi_at_HMLAN2 min:-95 avg:-82.87 cnt:25 max:-78 lst:-95
   Readings:
     2017-07-02 12:41:05   Activity        alive
     2017-07-02 12:41:07   CommandAccepted yes
     2017-07-02 12:41:05   D-firmware      2.1
     2017-07-02 12:41:05   D-serialNr      KEQ0079682
     2017-07-02 12:22:04   R-pairCentral   set_0x3D2DD3
     2017-07-02 12:46:52   humidity        56
     2017-07-02 12:46:52   measured-temp   25.7
     2017-07-02 12:46:59   state           MISSING ACK
     2017-07-02 12:46:59   status          T: 25.70 H: 56 D: 0.0
   Helper:
     HM_CMDNR   61
     cSnd       013D2DD320256E000802010A3D0B2D0CD3,013D2DD320256E0006
     mId        0039
     rxType     140
     supp_Pair_Rep 0
     Expert:
       def        1
       det        0
       raw        1
       tpl        0
     Io:
       newChn     +20256E,00,00,00
       nextSend   1498990303.11757
       rxt        2
       vccu       vccu
       p:
         20256E
         00
         00
         00
     Mrssi:
       mNo        3C
       Io:
         HMLAN1     -66
         HMLAN2     -95
     Prt:
       bErr       0
       sProc      0
     Q:
       qReqConf
       qReqStat
     Role:
       chn        1
       dev        1
     Rssi:
       At_hmlan1:
         avg        -67.2
         cnt        25
         lst        -68
         max        -63
         min        -70
       At_hmlan2:
         avg        -82.88
         cnt        25
         lst        -95
         max        -78
         min        -95
     Shadowreg:
       RegL_00.    02:01 0A:3D 0B:2D 0C:D3
     Tmpl:
Attributes:
   IODev      HMLAN1
   IOgrp      vccu:HMLAN1
   actCycle   000:10
   actStatus  alive
   autoReadReg 3_onChange
   event-min-interval .*:900
   event-on-change-reading status,measured-temp:0.5,humidity:2,actuator:2,desired-temp:0.5,battery,batteryLevel
   expert     2_full
   firmware   2.1
   icon       icoKLIMA
   model      HM-CC-TC
   room       GartenG_ELW
   serialNr   KEQ0079682
   subType    thermostat
   userReadings status {sprintf("T: %.2f H: %.0f D: %.1f", ReadingsVal("GG_ElwBad600_B1","measured-temp",0), ReadingsVal("GG_ElwBad600_B1","humidity",0), ReadingsVal("GG_ElwBad600_B1","dewpoint",0))}

Hat jemand eine Idee, wie dem Problem auf die Spur zu kommen ist?

Gruß

FilliFairy

[frank]

eventuell hast du verzögerungen in deinem system, so dass das timing der kommunikation nicht mehr passt.

nach den timestamps vom hmlan2 (beobachter) vergehen ca 1,5 sek zwischen antwort 63 vom device und dem nächsten befehl mit message nummer 64. die antwort 64 kommt dann auch nicht mehr.

zwischen den logzeiten der entsprechenden messages vom hmlan1 vergehen aber angeblich nur 9 millisek, was dann aber viel zu schnell wäre.

prüfe mal mit apptime/perfmon auf verzögerungen.

edit: ich würde auch mal die neueste fw 0.965 für die hmlan installieren.

[FilliFairy]

Super Frank,

Deine Hinweise waren genau richtig. Gefühlt hatte die Schwupdizität von FHEM in letzter Zeit nachgelassen. Mit apptime konnte ich die Performancefresser identifizieren.

Danach fühlte sich FHEM wieder flüssig an und das pairen ging wieder.

Den Firmware update der HMLANs habe ich zwar auch gemacht - aber mir scheint dir Ursache war eher das Permance Problem.

Vielen Dank.

FillyFairy