Nach Update von 10_CUL_HM.pm keine AES-signierte Kommunikation mehr möglich

[@tango]

Hallo *,

ich habe mit meiner "alten" funktionsfähigen FHEM Version ohne das update von CUL_HM noch experimentiert.
Versuchsweise habe ich mal statt restart einen rereadcfg durchgeführt.
Dann ergeben sich bereits danach die gleichen fehlerhaften AES Effekte wie mit der neuen CUL_HM!!!
Ein restart behebt den Fehler wieder.
Ich bilde mir ein, dass ich dass schon beim Inbetriebnehmen meines HMUARTs Mitte letzten Jahres beobachtet habe und rereadcg seit dem vermieden habe.

Vielleicht hilft es ja weiter.

[Beta-User]

Ist das Problem im laufenden System weg, wenn du IOList in der VCCU änderst? Kann ein Leerzeichen am Ende  sein.

[@tango]

In meinem noch funktionsfähigen System ist IOList bisher Leerzeichen frei.
Wenn ich welche mittels attr ..... anhänge sind sie auch anschließend nicht vorhanden.
In der WEBUI zeigt "Save config" kein ?.
Dann hat sich wohl nichts getan.

Ein rereadcfg zeigt anschließend wieder aesCommToDev=fail bei den Jalousieschaltern am HMUART.
Am HMLAN scheint alles OK.

restart hats wieder gerichtet.

Scheint der gleiche Effekt zu sein wie nach CUL_HM update.

[frank]

wie gesagt, meine ich, dass die nun fehlenden attribute IODev das verhalten hervorbringt.

[@tango]

Da hab ich meine Zweifel.
Den Effekt über rereadcfg hatte ich nach meiner Erinnerung schon vor einem Jahr.
Da waren an den Jal.Schaltern noch überall IODevs angebracht.
Die habe ich jetzt erst entfernt.

[Beta-User]

...so war das mit dem Leerzeichen nicht gemein...
Mein Verdacht: die interne Datenstruktur mit den vorhandenen IO's wird nicht in allen Fällen richtig initialisiert. Die aktuellen svn-Version (einschl. der von heute morgen) habe das z.B. beim Startup, dass helper-io-ioList NICHT gefüllt ist.

Wenn alles richtig läuft, sollte das m.E. in etwa so aussehen:

Code: [Auswählen]

Internals:
[...]
   TYPE       CUL_HM
   assignedIOs CUL_0,HmUART_Maple,mapleCUN1,myHmUART
[...]
   READINGS:
     2021-01-15 08:09:06   .associatedWith VCCU,VCCU_Btn1,VCCU_Btn2,VCCU_Btn3,VCCU_Btn4,VCCU_Btn5,VCCU_Btn6,VCCU
     2021-09-12 18:15:06   .protLastRcv    20210912181506
[...]
   helper:
[...]
     io:
       nextSend   1631463306.35471
       vccu       VCCU
       ioList:
         CUL_0
         HmUART_Maple
         mapleCUN1
         myHmUART
       prefIO:
     mRssi:
       io:
Vergrößert:

       vccu       VCCU
       ioList:
         CUL_0

Ändert man was Relevantes, wird dieses Array gefüllt.

"Was Relevantes" kann z.B. vielleicht der aes-Key sein, oder eben schlicht die IOList. Mein Vorschlag war, einfach das "anzufassen", indem du ein Leerzeichen anfügst (das wird ignoriert, dazwischen ist Käse). Was auch geht, ist z.B. ein IO da zu löschen und hinterher wieder zu ergänzen. Ganz egal, einfach irgendwie (akzeptabel) ändern.

Dann schauen, ob die IO's aaO gelistet sind und die Kommunikation anschließend wieder klappt.

(Falls das der Fall ist, bitte meine Version aus dem Nebenthread testen, da ist (u.A.) dann die Initialisierung der VCCU's beim Starten (und rereadcfg) geändert. "rereadcfg gehört verboten", hat einer, der es besser weiß wie ich schon vor längerem geäußert. Also einfach vergessen, dass es das je gab und shutdown+restart verwenden...)

[@tango]

Rereadcfg benutze ich schon lange nicht mehr. Seit halt der Fehler auftrat. Stattdessen eben restart.
Wird sich schon jemand was bei gedacht haben.
rereadcfg war jetzt nur ein Experiment.

list VCCU wenns funktioniert.

Code: [Auswählen]

Internals:
   CFGFN      ./FHEM/MyLanInterface.cfg
   DEF        2576CB
   FUUID      5c44eb3c-f33f-9dc6-955e-3b26dd5c810a4994
   IODev      XX_LANInterface
   LASTInputDev XX_HMUART
   MSGCNT     58
   NAME       XX_VCCU
   NOTIFYDEV  global
   NR         445
   NTFY_ORDER 50-XX_VCCU
   STATE      XX_LANInterface:ok,XX_HMUART:ok
   TYPE       CUL_HM
   XX_HMUART_MSGCNT 15
   XX_HMUART_RAWMSG 050001369981122576CB000000
   XX_HMUART_RSSI -54
   XX_HMUART_TIME 2021-09-12 18:41:39
   XX_LANInterface_MSGCNT 43
   XX_LANInterface_RAWMSG E2576CB,0000,000FF7E2,FF,FFC6,C780022576CB6041B30101C800
   XX_LANInterface_RSSI -58
   XX_LANInterface_TIME 2021-09-12 18:35:22
   assignedIOs XX_HMUART,XX_LANInterface
   ...
   lastMsg    No:99 - t:12 s:2576CB d:000000
   protLastRcv 2021-09-12 18:41:39
   protRcv    58 last_at:2021-09-12 18:41:39
   protRcvB   1 last_at:2021-09-12 18:14:58
   rssi_at_XX_HMUART cnt:15 min:-54 max:-52 avg:-53.06 lst:-54
   rssi_at_XX_LANInterface cnt:43 min:-58 max:-56 avg:-57.11 lst:-58
   READINGS:
     2021-09-12 18:35:21   CommandAccepted yes
     2021-09-12 18:09:43   IODev           XX_LANInterface
     2021-09-12 18:41:39   IOopen          2
     2021-09-12 18:35:21   aesKeyNbr       02
     2021-09-12 13:31:01   aesReqTo        JA_WZT_Jal
     2021-09-11 23:07:23   cfgState        ok
     2020-07-17 11:27:30   commState       CMDs_done
     2021-09-12 18:41:39   state           XX_LANInterface:ok,XX_HMUART:ok
     2021-09-10 08:21:18   unknown_2437B9  received
   helper:
     HM_CMDNR   153
     mId        FFF0
     peerFriend -
     peerOpt    -:virtual
     regLst     
     rxType     1
     supp_Pair_Rep 0
     ack:
     cmds:
       TmplKey    :no:1631462984.8173
       TmplTs     1631462984.8173
       cmdKey     0:1:1::XX_VCCU:FFF0:00:
       cmdLst:
         assignIO   -IO- [({set}|unset)]
         clear      [(readings|rssi|msgEvents|attack|{msgErrors}|unknownDev)]
         defIgnUnknown noArg
         hmPairForSec [-sec-]
         hmPairSerial -serial-
         update     noArg
         virtual    [(1..50;1|{1})]
       lst:
         condition  slider,0,1,255
         peer       
         peerOpt   
         tplChan   
         tplDel     
         tplPeer   
       rtrvLst:
         cmdList    [({short}|long)]
         deviceInfo [({short}|long)]
         list       [({normal}|full)]
         listDevice noArg
         param      -param-
     expert:
       def        1
       det        0
       raw        0
       tpl        0
     io:
       nextSend   1631464899.53466
       prefIO     
       vccu       XX_VCCU
       ioList:
         XX_LANInterface
         XX_HMUART
     mRssi:
       mNo        99
       io:
         XX_HMUART:
           -54
           -54
         XX_LANInterface:
           -52
     peerIDsH:
     prt:
       bErr       0
       sProc      0
       rspWait:
     q:
       qReqConf   
       qReqStat   
     role:
       dev        1
       vrt        1
     rssi:
       at_XX_HMUART:
         avg        -53.0666666666667
         cnt        15
         lst        -54
         max        -52
         min        -54
       at_XX_LANInterface:
         avg        -57.1162790697674
         cnt        43
         lst        -58
         max        -56
         min        -58
     tmpl:
Attributes:
   IODev      XX_LANInterface
   IOList     XX_LANInterface,XX_HMUART
   IOgrp      XX_VCCU
   alias      VCCU
   group      Homematic
..
   model      CCU-FHEM
   room       Server
   subType    virtual
   webCmd     virtual:update

Nach rereadcfg wenn AES nicht funktioniert, mir fällt
aesKeyNbr       00
auf

Code: [Auswählen]

Internals:
   CFGFN      ./FHEM/MyLanInterface.cfg
   DEF        2576CB
   FUUID      5c44eb3c-f33f-9dc6-955e-3b26dd5c810a4994
   IODev      XX_LANInterface
   LASTInputDev XX_LANInterface
   MSGCNT     47
   NAME       XX_VCCU
   NOTIFYDEV  global
   NR         445
   STATE      XX_LANInterface:ok,XX_HMUART:ok
   TYPE       CUL_HM
   XX_HMUART_MSGCNT 10
   XX_HMUART_RAWMSG 050000361180022576CB6119DA0091EA1CC2
   XX_HMUART_RSSI -54
   XX_HMUART_TIME 2021-09-12 18:48:19
   XX_LANInterface_MSGCNT 37
   XX_LANInterface_RAWMSG E2576CB,0000,00099547,FF,FFC7,70A0022576CB5C83510457320000320C00
   XX_LANInterface_RSSI -57
   XX_LANInterface_TIME 2021-09-12 18:51:08
   assignedIOs XX_HMUART,XX_LANInterface
   ...
   lastMsg    No:70 - t:02 s:2576CB d:5C8351 0457320000320C00
   protLastRcv 2021-09-12 18:51:08
   protRcv    47 last_at:2021-09-12 18:51:08
   rssi_at_XX_HMUART cnt:10 min:-54 max:-54 avg:-54 lst:-54
   rssi_at_XX_LANInterface cnt:37 min:-58 max:-57 avg:-57.43 lst:-57
   READINGS:
     2021-09-12 18:48:18   CommandAccepted yes
     2021-09-12 18:47:43   IODev           XX_LANInterface
     2021-09-12 18:48:04   IOopen          2
     2021-09-12 18:51:08   aesKeyNbr       00
     2021-09-12 13:31:01   aesReqTo        JA_WZT_Jal
     2021-09-11 23:07:23   cfgState        ok
     2020-07-17 11:27:30   commState       CMDs_done
     2021-09-12 18:48:04   state           XX_LANInterface:ok,XX_HMUART:ok
     2021-09-10 08:21:18   unknown_2437B9  received
   helper:
     HM_CMDNR   112
     mId        FFF0
     peerFriend -
     peerOpt    -:virtual
     regLst     
     rxType     1
     supp_Pair_Rep 0
     ack:
     cmds:
       TmplKey    :no:1631465275.25671
       TmplTs     1631465275.25671
       cmdKey     0:1:1::XX_VCCU:FFF0:01:
       cmdLst:
         assignIO   -IO- [({set}|unset)]
         clear      [(readings|rssi|msgEvents|attack|{msgErrors}|unknownDev)]
         defIgnUnknown noArg
         hmPairForSec [-sec-]
         hmPairSerial -serial-
         tplSet_0   -tplChan-
         update     noArg
         virtual    [(1..50;1|{1})]
       lst:
         condition  slider,0,1,255
         peer       
         peerOpt   
         tplChan   
         tplDel     
         tplPeer   
       rtrvLst:
         cmdList    [({short}|long)]
         deviceInfo [({short}|long)]
         list       [({normal}|full)]
         listDevice noArg
         param      -param-
     expert:
       def        1
       det        0
       raw        0
       tpl        0
     io:
       nextSend   1631465468.26954
       prefIO     
       vccu       XX_VCCU
       ioList:
         XX_LANInterface
         XX_HMUART
     mRssi:
       mNo        70
       io:
         XX_HMUART:
         XX_LANInterface:
           -51
           -51
     peerIDsH:
     prt:
       bErr       0
       sProc      0
       rspWait:
     q:
       qReqConf   
       qReqStat   
     role:
       dev        1
       vrt        1
     rssi:
       at_XX_HMUART:
         avg        -54
         cnt        10
         lst        -54
         max        -54
         min        -54
       at_XX_LANInterface:
         avg        -57.4324324324324
         cnt        37
         lst        -57
         max        -57
         min        -58
     tmpl:
Attributes:
   IODev      XX_LANInterface
   IOList     XX_LANInterface,XX_HMUART
   IOgrp      XX_VCCU
   alias      VCCU
   group      Homematic
..
   model      CCU-FHEM
   room       Server
   subType    virtual
   webCmd     virtual:update


Jetzt die beiden IOs in der IOList vertauscht, in meiner Version geht das ja noch.
Fehler weiterhin vorhanden.

Code: [Auswählen]

Internals:
   CFGFN      ./FHEM/MyLanInterface.cfg
   DEF        2576CB
   FUUID      5c44eb3c-f33f-9dc6-955e-3b26dd5c810a4994
   IODev      XX_LANInterface
   LASTInputDev XX_LANInterface
   MSGCNT     48
   NAME       XX_VCCU
   NOTIFYDEV  global
   NR         445
   STATE      XX_HMUART:ok,XX_LANInterface:ok
   TYPE       CUL_HM
   XX_HMUART_MSGCNT 10
   XX_HMUART_RAWMSG 050000361180022576CB6119DA0091EA1CC2
   XX_HMUART_RSSI -54
   XX_HMUART_TIME 2021-09-12 18:48:19
   XX_LANInterface_MSGCNT 38
   XX_LANInterface_RAWMSG E2576CB,0000,000B5606,FF,FFC6,82943F2576CB000000020428D0ECEE
   XX_LANInterface_RSSI -58
   XX_LANInterface_TIME 2021-09-12 18:53:03
   assignedIOs XX_HMUART,XX_LANInterface
   ....
   lastMsg    No:82 - t:3F s:2576CB d:000000 020428D0ECEE
   protLastRcv 2021-09-12 18:53:03
   protRcv    48 last_at:2021-09-12 18:53:03
   protRcvB   1 last_at:2021-09-12 18:53:03
   rssi_at_XX_HMUART cnt:10 min:-54 max:-54 avg:-54 lst:-54
   rssi_at_XX_LANInterface cnt:38 min:-58 max:-57 avg:-57.44 lst:-58
   READINGS:
     2021-09-12 18:48:18   CommandAccepted yes
     2021-09-12 18:47:43   IODev           XX_LANInterface
     2021-09-12 18:56:04   IOopen          2
     2021-09-12 18:51:08   aesKeyNbr       00
     2021-09-12 13:31:01   aesReqTo        JA_WZT_Jal
     2021-09-11 23:07:23   cfgState        ok
     2020-07-17 11:27:30   commState       CMDs_done
     2021-09-12 18:56:04   state           XX_HMUART:ok,XX_LANInterface:ok
     2021-09-10 08:21:18   unknown_2437B9  received
   helper:
     HM_CMDNR   130
     mId        FFF0
     peerFriend -
     peerOpt    -:virtual
     regLst     
     rxType     1
     supp_Pair_Rep 0
     ack:
     cmds:
       TmplKey    :no:1631465275.25671
       TmplTs     1631465275.25671
       cmdKey     0:1:1::XX_VCCU:FFF0:01:
       cmdLst:
         assignIO   -IO- [({set}|unset)]
         clear      [(readings|rssi|msgEvents|attack|{msgErrors}|unknownDev)]
         defIgnUnknown noArg
         hmPairForSec [-sec-]
         hmPairSerial -serial-
         update     noArg
         virtual    [(1..50;1|{1})]
       lst:
         condition  slider,0,1,255
         peer       
         peerOpt   
         tplChan   
         tplDel     
         tplPeer   
       rtrvLst:
         cmdList    [({short}|long)]
         deviceInfo [({short}|long)]
         list       [({normal}|full)]
         listDevice noArg
         param      -param-
     expert:
       def        1
       det        0
       raw        0
       tpl        0
     io:
       nextSend   1631465583.13224
       prefIO     
       vccu       XX_VCCU
       ioList:
         XX_HMUART
         XX_LANInterface
     mRssi:
       mNo        82
       io:
         XX_HMUART:
         XX_LANInterface:
           -52
           -52
     peerIDsH:
     prt:
       bErr       0
       sProc      0
       rspWait:
     q:
       qReqConf   
       qReqStat   
     role:
       dev        1
       vrt        1
     rssi:
       at_XX_HMUART:
         avg        -54
         cnt        10
         lst        -54
         max        -54
         min        -54
       at_XX_LANInterface:
         avg        -57.4473684210526
         cnt        38
         lst        -58
         max        -57
         min        -58
     tmpl:
Attributes:
   IODev      XX_LANInterface
   IOList     XX_HMUART,XX_LANInterface
   IOgrp      XX_VCCU
   alias      VCCU
   group      Homematic
..
   model      CCU-FHEM
   room       Server
   subType    virtual
   webCmd     virtual:update

ioList scheint mir jedesmal passend.

[Beta-User]

Hmm, ok, dann scheint es das nicht gewesen zu sein.

Du bist jetzt grade wieder zurück auf

Ich bin bis SVN-Revision 24374 schrittweise zurück gegangen, das ist die letzte funktionierende.

Oder aktueller?

Mit der obigen Version hatte Martin das startup-Verhalten geändert und einige Plausibilitätstest eingeführt, die u.A. dazu geführt hatten, dass das tempListTmpl-Attribut nicht mehr gesetzt werden konnte. Das ist deswegen interessant, weil aus irgendeinem Grund die dazu passende Voraussetzung zum Prüfungszeitpunkt noch nicht gegeben war.
Bzgl. des genannten Attributs ist das mit der 24961 (von heute aus dem svn) nicht mehr so, (der Zusammenhang zwischen der Änderung und dem Effekt ist jedenfalls mir auf die Schnelle nicht einleuchtend gewesen).

Vielleicht könntest du die mal testen und es gibt  da einen Zusammenhang/ähnlichen Effekt?

[@tango]

Woran erkenne ich das genau?

In meiner funktionierenden 10_CUL_HM.pm steht im header jedenfalls:

Code: [Auswählen]

# $Id: 10_CUL_HM.pm 24449 2021-05-16 09:03:48Z martinp876 $

Wie kann ich konkret die 24961 runterladen? ich kenne mich da nicht sehr aus.
Oder reicht ein normaler update?

[Beta-User]

Seit kurz vor 8:00 Uhr ist die svn-Version per regulärem update verfügbar, ich hatte gestern nur auf svn verwiesen, weil das da noch nicht geklappt hätte.

In meiner funktionierenden 10_CUL_HM.pm steht im header jedenfalls:

Code: [Auswählen]

# $Id: 10_CUL_HM.pm 24449 2021-05-16 09:03:48Z martinp876 $


Demnach kam das Problem nicht von 24374 nach 24449, sondern erst in der Folgeversion...? Das erhöht die Chancen, dass es jetzt wieder besser ist, denn meine Anmerkung von gestern abend trifft eigentlich deutlich besser auf den Wechsel in 24834 zu .

Bitte melden, falls das nichts hilft, dann könnte es noch an der VCCU-Initialisierung hängen (siehe anderen Thread).

[@tango]

Update ausgeführt, neue CUL_HM ist dabei, restart.

AES Fehler weiter vorhanden.

 

Reicht es wenn ich nur die CUL_HM restore und nicht den gesamten update?

Ich würde gerne mit den restlichen Moduln auf einen aktuellen Stand kommen.

[Beta-User]

Bitte noch den Test mit der Version von nebenan machen, die pegatchte Datei sollte mit

Code: [Auswählen]

"wget https://raw.githubusercontent.com/rejoe2/FHEM/master/10_CUL_HM.pm -O ./FHEM/10_CUL_HM.pm"(FHEM-kommando, einschl. der Anführungszeichen) zu bekommen sein.

Sonst kannst du das (zusammen mit HMinfo und HMConfig.pm!) auch aus dem Backup isoliert holen, im Moment sehe ich auf die Schnelle nichts, das aus dem sonstigen FHEM-Kontext Probleme machen sollte.

[@tango]

Gepatchte CUL_HM geladen. Restart ausgeführt.

Sieht gut aus!!!!

Nach restart scheint der AES Fehler behoben zu sein.
Jedenfalls nach einigen Stichproben.

Ich muss noch in Ruhe alles durchsehen.

Gratulation 

[Beta-User]

 
Danke für die Rückmeldung.

Das müßte dann übrigens auch "rereadcfg-fest" sein ...

[@tango]

Ich bin nicht scharf auf rereadcfg.
Mir fehlt die Information, was Vor- und Nachteile von rereadcfg und restart sind.
Die Empfehlung, nicht mit fhem.cfg zu arbeiten kenne ich auch (warum nicht!)
Meine ist ziemlich stark mit includes strukturiert, da ich seit langem mit eigenen (Jalousie-) Templates implementiert mit shell-scripten arbeite und diverse includes pro Jalousie generiere.
Funktioniert bestens.
Ich habe mal gelernt: "never change a running program".
Der  Rest läuft über die WEBUI. Geht schneller.
Aber aufwendige Analysen sind mit Linux Kommandos grep, etc. besser möglich bzw. fallen mir leichter.

Wie gehts weiter?
Kann ich verhindern, dass der Patch beim nächsten update überschrieben wird?
Bzw. wie sehe ich, dass er offiziell wird?

Jedenfalls noch mal besten Dank für die Hilfe.