[cul_hm] probleme mit wakeup und/oder lazyConfig und/oder A112

[noansi]

Hallo Frank,

dort fehlt in zeile 3716 eine schliessende geschweifte klammer vor dem else.

Danke für den Hinweis, ich hab's in beiden korrigiert. Fällt leider nicht auf, wenn man's nicht testet.

wenn ich es richtig verstehe, sind diese änderungen noch nicht in cul_hm 24158, sondern in deiner version aus beitrag #18. gestern habe ich aber erst martins neueste version 24158 getestet.
demnach kann der wunsch ja nicht die ursache sein.

Doch, das hatte Martin schon mitbekommen und eingearbeitet.

ausserdem gibt es schwierigkeiten bei diesem sensor mit dem timing. entweder das autonome 8102, oder der nachfolgende A001 cmd.

Ich denke, der schläft recht früh wieder ein, sprich reagiert nicht angemessen auf 8102 mit längerer Wachsamkeit.

Kann man natürlich auch so interpretieren, dass CUL_HM zu spät seinen nächsten Request schickt.

Aber dann würde alles "Hallo Wach" Protokoll keinen Sinn machen. Nach 269ms oder 221ms schon wieder schlafen ist zu knapp. Eine der autonomen Wiederholungen sollte er noch mindestens aufschnappen können sollen, denke ich.

Gruß, Ansgar.

[noansi]

Hallo Frank,

ich hab jetzt mal im Anhang die Attribut IODev Ergänzung eingebaut.
Bitte teste mal, ob es was gebracht hat.

Wenn Du das Attribut händisch setzt, dann kommt die Meldung: 'IODev handled'
Das ist kein Fehler, sondern hindert fhem.pl daran, am $hash->{IODev} Änderungen vorzunehmen.
Meist wird damit das IO direkt umgestellt, kann aber auch erst verzögert passieren, je nach Zustand.

Gruß, Ansgar.

[frank]

hallo ansgar,

ich hab jetzt mal im Anhang die Attribut IODev Ergänzung eingebaut.
Bitte teste mal, ob es was gebracht hat.

es hat zumindestens gezeigt, dass die definition meines cul in der fhem.cfg viel zu spät eingebaut war. 
eigentlich dachte ich gehört zu haben, dass die reihenfolge der definitionen nicht mehr so wichtig war.
oder war das vielleicht der grund, weshalb die anpassung des attr IODev irgendwann nicht mehr funktionierte?

alle probleme mit der wakeup-statusrequest-queue sind weiterhin identisch.



io zuweisung

ich hatte 2 neue meldungen nach restart im zusammenhang mit "IODev handled".

Code Auswählen Erweitern

2021.04.08 08:57:04.890 3: SwitchES01: unknown IODev cul868 specified
2021.04.08 08:57:06.387 3: test: unknown IODev cul868 specified

diese meldungen sind nachvollziehbar, da die definitionen der beiden devices vor der cul definition erfolgten und beide den cul als prefered io gesetzt hatten und zumindestens noch vor ein paar tagen der cul auch in attr IODev stand.


einige zeit nach restart sieht die ausgabe von "get vccu listDevice" so aus:

Code Auswählen Erweitern

devices using ccu
current IO / preferred
  cul868 / cul868 HM_196BD8
  cul868 / cul868 SwitchES01
  cul868 / cul868 SwitchPBU07
  cul868 / cul868 SwitchPBU08
  cul868 / cul868 SwitchPBU09
  cul868 / cul868 rssi_hmuart
  cul868 / hmlan1 DimUP01
  cul868 / hmlan1 SwitchUP02
  hmlan1 / hmlan1 DimPBU01
  hmlan1 / hmlan1 Fenster.Bad
  hmlan1 / hmlan1 SD.AZ
  hmlan1 / hmlan1 SD.SZ
  hmlan1 / hmlan1 SD.WZ
  hmlan1 / hmlan1 SDTeam
  hmlan1 / hmlan1 SwitchPBU01
  hmlan1 / hmlan1 SwitchPBU03
  hmlan1 / hmlan1 SwitchPBU04
  hmlan1 / hmlan1 SwitchPBU06
  hmlan1 / hmlan1 SwitchPL01
  hmlan1 / hmlan1 SwitchPL02
  hmlan1 / hmlan1 SwitchUP01
  hmlan1 / hmlan1 Thermostat.Bad
  hmlan1 / hmlan1 Thermostat.Bad.OG
  hmlan1 / hmlan1 Thermostat.Kueche
  hmlan1 / hmlan1 Thermostat.OZ
  hmlan1 / hmlan1 Thermostat.WZ
  hmlan1 / hmlan1 Tuer.WZ.Terrasse
  hmlan1 / hmlan1 VentilControler.AZ.Nord
  hmlan1 / hmlan1 VentilControler.AZ.West
  hmlan1 / hmlan1 VentilControler.Bad
  hmlan1 / hmlan1 VentilControler.Kueche
  hmlan1 / hmlan1 VentilControler.SZ
  hmlan1 / hmlan1 VentilControler.WZ
  hmlan1 / hmlan1 ccu
  hmlan1 / hmlan1 virtAktorAlarmOff
  hmlan1 / hmlan1 virt_vd
  hmuart1 / hmuart1 HM_114B05
  hmuart1 / hmuart1 SwitchPBU02
  hmuart1 / hmuart1 SwitchPBU05
  hmuart1 / hmuart1 Thermostat.AZ
  hmuart1 / hmuart1 Thermostat.GZ
  hmuart1 / hmuart1 Thermostat.Keller
  hmuart1 / hmuart1 Thermostat.SZ
  hmuart1 / hmuart1 Tuer.SZ
  hmuart1 / hmuart1 Ventil.AZ.Nord
  hmuart1 / hmuart1 Ventil.AZ.West
  hmuart1 / hmuart1 Ventil.Bad
  hmuart1 / hmuart1 Ventil.Kueche
  hmuart1 / hmuart1 Ventil.SZ
  hmuart1 / hmuart1 Ventil.WZ
  hmuart1 / hmuart1 Wetter.Nord
  hmuart1 / hmuart1 Wetter.Sued
  hmusb1 / cul868 test


1. in dieser liste sollte man eigentlich keine ignored devices listen.

2. das device test hat jeweils attr ignore und dummy gesetzt.
das nun zugewiesene io hmusb1 hat ebenfalls attr dummy gesetzt.
wie kommt es dazu, dass dieses io gewählt wird, obwohl es nicht operabel ist?

Code Auswählen Erweitern

attr ccu IOList hmlan1,cul868,hmusb1,hmuart1

3. das popup "IODev handled" bei der attribut eingabe ist sehr verwirrend.
es macht den eindruck, dass nichts passiert ist. man kann unendlich oft eine eingabe machen und jedesmal kommt das popup. erst wenn nach der bestätigung des popup die detailseite neu geladen wird, ist der erfolg sichtbar.

zusätzlich werden nach dem editieren und speichern der fhem.cfg über edit files dutzende fehler "IODev handled" angezeigt. ich dachte zuerst, jetzt habe ich die datei zerschossen. war aber alles ok.
also auch einfach nicht beachten und weiter machen.

ausserdem tauchen alle "IODev handled" zeilen auf der startseite nach dem restart auf.
das wird sicher viele aufgeregte support anfragen im forum aufwerfen, oder?

Code Auswählen Erweitern

Messages collected while initializing FHEM:configfile: IODev handled
IODev handled
IODev handled
IODev handled
...

4. wenn in dieser version die option none bei prefferedIO in der vccu funktionieren sollte, was zumindestens den eindruck macht, dann müsste man auch noch hminfo configcheck anpassen, da sonst folgender fehler auftaucht:

Code Auswählen Erweitern


IOgrp: prefered IO undefined
    DimPBU01: ->none
    DimUP01: ->none
    SwitchUP02: ->none

5. schön wäre ein logeintrag, eventuell mit verbose 4 bei der vccu, aus dem ein io-wechsel erkennbar wird.

6. irgendwie starten die automatischen statusrequests beim restart grundsätzlich sehr früh.
bei den ersten requests ist scheinbar nur der cul operabel, wodurch dieser zunächst alle msgs sendet.
der hmlan macht kurze zeit später dann auch mit.
der hmuart braucht noch länger um senden zu können.
damit alle prefferedIO die chance zum senden bekommen können, müsste der start der requests eigentlich um 3-5 sekunden verzögert werden.

mit der option none lässt sich dies zwar auch erreichen, aber dadurch wird der cul dann ja grundsätzlich als backup ausgeschlossen.


gruss frank

[noansi]

Hallo Frank,

alle probleme mit der wakeup-statusrequest-queue sind weiterhin identisch.

D.h.

2. der erste versuch des automatischen statusrequest nach fhem restart wird ohne autonome A112 ausgeführt.

das autonome senden von A112 findet nicht statt, da das io erst nach dem empfang der WAKEMEUP message entsprechend gesetzt wird.

Ist auch so geblieben? Ich hatte auch beim Attribut modelForce noch eine IO Aktualisierung ergänzt und gehofft, dass das noch was bringen könnte. -> OK, war Quatsch, hat aber auch nicht weh getan. Ich hab das wieder raus genommen.

eigentlich dachte ich gehört zu haben, dass die reihenfolge der definitionen nicht mehr so wichtig war.

Nun, nach Initialisierung von FHEM wird bei den devices die Konfiguration nochmal durchgeackert und ggf. ein IO gesetzt. Bis sich das aber alles "normalisiert" hat, können noch Probleme auftreten. Insbesondere, wenn messages vom IO vorher durch fhem verarbeitet werden sollten. Eigentlich sollten danach alle devices passend am IO angemedet sein.

das nun zugewiesene io hmusb1 hat ebenfalls attr dummy gesetzt.
wie kommt es dazu, dass dieses io gewählt wird, obwohl es nicht operabel ist?

Das sehe ich grundsätzlich als Bug im IO Modul, da es dann seinen XmitOpen auf 0 setzen sollte.
Eigentlich wird nur CUL anders behandelt und da würde das Problem auch auftreten. Wäre schön, wenn Rudolf auch XmitOpen einbauen würde.

3. das popup "IODev handled" bei der attribut eingabe ist sehr verwirrend.

Das hatte ich angekündigt. Wenn die attr IODev Behandlung was nützliches bringt, dann wäre es sicherlich möglich Rudolf zur einem Rückgabewert zu überzeugen, der in der fhem.pl schlicht ignoriert wird, oder eine andere Lösung. Dann fiellen die Meldungen weg.
Nur zum Testen geht es nicht anders, da das assignIO auch zu einem anderen IO schalten kann, als das Setzen des Attributes möchte, bei TSCUL z.B., wenn das IO auf dummy gesetzt wäre oder das IO aus anderem Grund nicht operabel anzeigt.
In jedem Fall müßtest Du im Vergleich feststellen, dass das Setzen des Attributes mit IO Wechsel auch meißt direkt zu einer IO Vorbereitung führt, was bisher nicht der Fall war.

5. schön wäre ein logeintrag, eventuell mit verbose 4 bei der vccu, aus dem ein io-wechsel erkennbar wird.

Wenn es mit der IO Zuweisung keine Probleme gibt, dann bin ich stark dafür das Logging weg zu lassen, sprich nur Log, wenn ein Fehler auftritt. Da es vor dem Senden ausgeführt wird, ist es zeitkrisch und der Logging String wird schon zusammen gebaut, bevor festgestellt wird, das der verbose level gar keinen Log Eintrag möchte.

damit alle prefferedIO die chance zum senden bekommen können, müsste der start der requests eigentlich um 3-5 sekunden verzögert werden.

Für meinen Geschmack eher noch deutlich mehr, weil auch andere Module (besonders bei mir ) via Timer noch mit verzögerten Startaktionen rechenzeitfordernd dazwischen funken. Statt Sekunden eher Minuten...

Gruß, Ansgar.

[frank]

hallo ansgar,


automatischer wakeup-statusrequest
das problem ist meiner meinung nach, dass die vorbereitung der aktion ebenfalls auf die WAKEMEUP message wartet.
es findet hier sozusagen keine trennung in "vorbereitung" und "ausführung" statt.

normaler weise wird ein befehl initiiert, indem der cmd einen logeintrag erhält, auf den stack kommt und das io präpariert wird. diese vorbereitung, gekennzeichnet durch cmds_pending, erwartet nun die aulösemessage.

nochmal aktuelles beispiel mit selbem device/IOdev:

Code Auswählen Erweitern

2021.04.08 18:37:31.126 4: CUL_Parse: cul868 A 0C 1B 8670 2064CB 000000 005B3FED -83.5
2021.04.08 18:37:31.130 3: CUL_HM set Thermostat.GZ_Climate statusRequest noArg
2021.04.08 18:37:31.243 0: HMUARTLGW hmuart1 recv: 01 05 00 00 4B msg: 1B 86 70 2064CB 000000 005B3F
2021.04.08 18:37:31.260 0: HMLAN_Parse: hmlan1 R:E2064CB   stat:0000 t:8B368ACB d:FF r:FFA5     m:1B 8670 2064CB 000000 005B3F
2021.04.08 18:37:31.341 0: HMUARTLGW hmuart1 send: 01 02 00 00 00 msg: 1C A0 01 1ACE1F 2064CB 020E
2021.04.08 18:37:31.368 4: CUL_Parse: cul868 A 0B 1C A001 1ACE1F 2064CB 020E67 -22.5
2021.04.08 18:37:31.378 0: HMLAN_Parse: hmlan1 R:E1ACE1F   stat:0000 t:8B368BBD d:FF r:FFCD     m:1C A001 1ACE1F 2064CB 020E
2021.04.08 18:37:31.708 4: CUL_Parse: cul868 A 0B 1C A001 1ACE1F 2064CB 020E67 -22.5
2021.04.08 18:37:31.718 0: HMLAN_Parse: hmlan1 R:E1ACE1F   stat:0000 t:8B368D11 d:FF r:FFCD     m:1C A001 1ACE1F 2064CB 020E
2021.04.08 18:37:32.040 4: CUL_Parse: cul868 A 0B 1C A001 1ACE1F 2064CB 020E67 -22.5
2021.04.08 18:37:32.060 0: HMLAN_Parse: hmlan1 R:E1ACE1F   stat:0000 t:8B368E5B d:FF r:FFCD     m:1C A001 1ACE1F 2064CB 020E
2021.04.08 18:37:32.289 0: HMUARTLGW hmuart1 recv: 01 0404, state 100
2021.04.08 18:37:32.291 0: HMUARTLGW hmuart1 can't send due to unknown problem (no response?)
2021.04.08 18:37:32.292 0: HMUARTLGW hmuart1 send: 01 062064CB000100
2021.04.08 18:37:32.299 0: HMUARTLGW hmuart1 recv: 01 04070101000EFFFFFFFFFFFFFFFF, state 90
2021.04.08 18:37:32.300 0: HMUARTLGW hmuart1 GetSet Ack: 07, state 90
2021.04.08 18:37:32.301 0: HMUARTLGW hmuart1 added peer: 2064CB, aesChannels: FFFFFFFFFFFFFFFF
2021.04.08 18:37:32.304 0: HMUARTLGW hmuart1 send: 01 062064CB000100
2021.04.08 18:37:32.310 0: HMUARTLGW hmuart1 recv: 01 04070101000EFFFFFFFFFFFFFFFF, state 93
2021.04.08 18:37:32.312 0: HMUARTLGW hmuart1 GetSet Ack: 07, state 93
2021.04.08 18:37:32.312 0: HMUARTLGW hmuart1 added peer: 2064CB, aesChannels: FFFFFFFFFFFFFFFF

....

2021.04.08 18:40:14.633 4: CUL_Parse: cul868 A 0C 1C 8670 2064CB 000000 005C3FEC -84
2021.04.08 18:40:14.644 3: CUL_HM set Thermostat.GZ_Climate statusRequest noArg
2021.04.08 18:40:14.770 0: HMUARTLGW hmuart1 send: 01 02 00 00 00 msg: 1D A0 01 1ACE1F 2064CB 020E
2021.04.08 18:40:14.774 0: HMLAN_Parse: hmlan1 R:E2064CB   stat:0000 t:8B390994 d:FF r:FFA5     m:1C 8670 2064CB 000000 005C3F
2021.04.08 18:40:14.777 0: HMLAN_Parse: hmlan1 R:E1ACE1F   stat:0000 t:8B390A0F d:FF r:FFCD     m:3C A112 1ACE1F 2064CB
2021.04.08 18:40:14.782 4: CUL_Parse: cul868 A 09 3C A112 1ACE1F 2064CB 67 -22.5
2021.04.08 18:40:14.788 0: HMUARTLGW hmuart1 recv: 01 0408, state 100
2021.04.08 18:40:14.789 0: HMUARTLGW hmuart1 IO currently busy, trying again in a bit
2021.04.08 18:40:14.842 0: HMUARTLGW hmuart1 send: 01 02 00 00 00 msg: 1D A0 01 1ACE1F 2064CB 020E
2021.04.08 18:40:14.848 0: HMUARTLGW hmuart1 recv: 01 0408, state 100
2021.04.08 18:40:14.849 0: HMUARTLGW hmuart1 IO currently busy, trying again in a bit
2021.04.08 18:40:14.884 4: CUL_Parse: cul868 A 0A 3C 8002 2064CB 1ACE1F 00EE -83
2021.04.08 18:40:14.891 0: HMUARTLGW hmuart1 recv: 01 05 10 00 4B msg: 1C 86 70 2064CB 000000 005C3F
2021.04.08 18:40:14.898 0: HMLAN_Parse: hmlan1 R:E2064CB   stat:0000 t:8B390A92 d:FF r:FFA4     m:3C 8002 2064CB 1ACE1F 00
2021.04.08 18:40:14.986 0: HMUARTLGW hmuart1 send: 01 02 00 00 00 msg: 1D A0 01 1ACE1F 2064CB 020E
2021.04.08 18:40:15.025 4: CUL_Parse: cul868 A 0B 1D A001 1ACE1F 2064CB 020E67 -22.5
2021.04.08 18:40:15.037 0: HMLAN_Parse: hmlan1 R:E1ACE1F   stat:0000 t:8B390B1E d:FF r:FFCD     m:1D A001 1ACE1F 2064CB 020E
2021.04.08 18:40:15.157 4: CUL_Parse: cul868 A 0E 1D 8002 2064CB 1ACE1F 01020C004FED -83.5
2021.04.08 18:40:15.176 0: HMLAN_Parse: hmlan1 R:E2064CB   stat:0000 t:8B390BA2 d:FF r:FFA4     m:1D 8002 2064CB 1ACE1F 01020C004F
2021.04.08 18:40:15.182 0: HMUARTLGW hmuart1 recv: 01 04 03 00 4B msg: 1D 80 02 2064CB 1ACE1F 01020C004F
2021.04.08 18:40:15.278 0: HMUARTLGW hmuart1 send: 01 02 00 00 00 msg: 1E A0 01 1ACE1F 2064CB 020E
2021.04.08 18:40:15.306 4: CUL_Parse: cul868 A 0B 1E A001 1ACE1F 2064CB 020E67 -22.5
2021.04.08 18:40:15.315 0: HMLAN_Parse: hmlan1 R:E1ACE1F   stat:0000 t:8B390C37 d:FF r:FFCD     m:1E A001 1ACE1F 2064CB 020E
2021.04.08 18:40:15.438 4: CUL_Parse: cul868 A 0E 1E 8002 2064CB 1ACE1F 01020C0050EE -83
2021.04.08 18:40:15.533 0: HMLAN_Parse: hmlan1 R:E2064CB   stat:0000 t:8B390CBC d:FF r:FFA4     m:1E 8002 2064CB 1ACE1F 01020C0050
2021.04.08 18:40:15.537 0: HMUARTLGW hmuart1 recv: 01 04 03 00 4B msg: 1E 80 02 2064CB 1ACE1F 01020C0050
2021.04.08 18:40:15.540 0: HMUARTLGW hmuart1 send: 01 062064CB000000
2021.04.08 18:40:15.696 0: HMUARTLGW hmuart1 recv: 01 04070101000EFFFFFFFFFFFFFFFF, state 90
2021.04.08 18:40:15.697 0: HMUARTLGW hmuart1 GetSet Ack: 07, state 90
2021.04.08 18:40:15.698 0: HMUARTLGW hmuart1 added peer: 2064CB, aesChannels: FFFFFFFFFFFFFFFF
2021.04.08 18:40:15.701 0: HMUARTLGW hmuart1 send: 01 062064CB000000
2021.04.08 18:40:15.714 0: HMUARTLGW hmuart1 recv: 01 04070101000EFFFFFFFFFFFFFFFF, state 93
2021.04.08 18:40:15.715 0: HMUARTLGW hmuart1 GetSet Ack: 07, state 93
2021.04.08 18:40:15.716 0: HMUARTLGW hmuart1 added peer: 2064CB, aesChannels: FFFFFFFFFFFFFFFF


Das sehe ich grundsätzlich als Bug im IO Modul, da es dann seinen XmitOpen auf 0 setzen sollte.
Eigentlich wird nur CUL anders behandelt und da würde das Problem auch auftreten. Wäre schön, wenn Rudolf auch XmitOpen einbauen würde.

der hmusb hat xmitopen=0

Code Auswählen Erweitern

Internals:
   DEF        fritz.box:1234
   DeviceName fritz.box:1234
   FUUID      5c4ce2e7-f33f-09c4-37e6-608fb13c49ee601e
   NAME       hmusb1
   NR         28
   NTFY_ORDER 50-hmusb1
   STATE      disconnected
   TYPE       HMLAN
   XmitOpen   0
   assignedIDsCnt 0
   msgKeepAlive
   msgLoadCurrent 0
   owner     
   owner_CCU  ccu
   .attraggr:
   .attreocr:
     .*
   .attreour:
     prot_ERROR-Overload
     prot_Warning-HighLoad
     prot_disconnected
     prot_init
     prot_keepAlive
     prot_ok
     prot_timeout
   .attrminint:
   READINGS:
     2017-02-02 16:15:41   D-HMIdAssigned  1ACE1F
     2017-02-02 16:15:41   D-HMIdOriginal  263408
     2017-02-02 16:15:41   D-firmware      0.967
     2017-02-02 16:15:41   D-serialNr      KEQ1111271
     2021-04-09 23:17:18   Xmit-Events     dummy:1 disconnected:1
     2021-04-09 23:17:18   cond            dummy
     2017-02-06 11:11:46   loadLvl         low
     2021-04-09 23:17:18   prot_disconnected last
     2021-04-09 23:17:18   prot_dummy      last
     2017-02-06 23:17:13   prot_init       last
     2017-02-06 11:12:16   prot_keepAlive  last
     2017-02-02 16:15:41   prot_ok         last
     2017-02-02 09:47:45   prot_timeout    last
     2021-04-09 23:17:18   state           disconnected
   helper:
     assIdCnt   0
     assIdRep   0
     cnd:
       251        1
       253        1
     k:
       BufMin     30
       DlyMax     0
       Start      0
     loadLvl:
       bl         40
       a:
         99
         90
         40
         0
       h:
         0          low
         40         batchLevel
         90         high
         99         suspended
     log:
       all        0
       sys        0
       ids:
         20DFE1
     q:
       HMcndN     251
       answerPend 0
       hmLanQlen  1
       loadLastMax 0
       loadNo     0
       scnt       0
       ald:
         0
         0
         0
         0
         0
         0
         0
         0
         0
         0
         0
         0
       apIDs:
Attributes:
   dummy      1
   event-on-change-reading .*
   event-on-update-reading prot_ERROR-Overload,prot_Warning-HighLoad,prot_disconnected,prot_init,prot_keepAlive,prot_ok,prot_timeout
   group      IO-Devices
   hmId       1ACE1F
   hmLanQlen  1_min
   loadLevel  0:low,40:batchLevel,90:high,99:suspended
   logIDs     Thermostat.OZ
   room       90_Technik
   wdTimer    25

Das hatte ich angekündigt.

ich komme damit klar und es funktioniert auch gut, soweit es zu erkennen ist.

[noansi]

Hallo Frank,

das problem ist meiner meinung nach, dass die vorbereitung der aktion ebenfalls auf die WAKEMEUP message wartet.
es findet hier sozusagen keine trennung in "vorbereitung" und "ausführung" statt.

Du hast das Problem nur nach fhem restart, so habe ich es verstanden.
Beim nächsten ausgelösten statusRequest passiert es nicht mehr, richtig?

Mit dem push auf den leeren cmdstack wird das IO präpariert, allerdings nur, wenn die Information dazu vorliegen, dass das device es benötigt und es nicht bereits so vorbereitet ist. (so sagt es mir der code, glaube ich)

Code Auswählen Erweitern

sub CUL_HM_protState($$){
  my ($hash,$state) = @_;
  my $name = $hash->{NAME};

  my $sProcIn = $hash->{helper}{prt}{sProc};
  $sProcIn = 0 if(!defined $sProcIn);
...
  Log3 $name,5,"CUL_HM $name protEvent:$state".
            ($hash->{cmdStack}?" pending:".scalar @{$hash->{cmdStack}}:"");
  CUL_HM_hmInitMsgUpdt($hash) if (  $hash->{helper}{prt}{sProc} != $sProcIn
                                  && (   $hash->{helper}{prt}{sProc} < 2
                                      ||($hash->{helper}{prt}{sProc} == 2 && $sProcIn == 0 )));
}

Ich habe das Logging mal etwas erweitert (Anhang):

Code Auswählen Erweitern

  Log3 $name,5,"CUL_HM $name protEvent:$state".
            ($hash->{cmdStack}?" pending:".scalar @{$hash->{cmdStack}}:"")
            .", $sProcIn -> $hash->{helper}{prt}{sProc}, $hash->{helper}{io}{newChn}, $hash->{helper}{io}{rxt}";


der hmusb hat xmitopen=0

Wenn dummy nach der IO Zuweisung gesetzt wird, dann würde auch ein daraus resultierends XmitOpen=0 nicht helfen bis zum nächsten assignIO. Fällt mir zunächst dazu ein.
Ich habe zumindest noch einen Zusatzcheck für Wahl nach Attribut IODev eingebaut.

IODev Meldungen/Log habe ich zumindest ewas verringert.

Gruß, Ansgar.

Edit1: angepasst an 24214
Edit2: nun auch mit patch für unreachable letzter channel

[frank]

hallo ansgar,

Du hast das Problem nur nach fhem restart, so habe ich es verstanden.
Beim nächsten ausgelösten statusRequest passiert es nicht mehr, richtig?

wie in antwort #25 beschrieben, gibt es mindestens 3 probleme mit statusrequest.

nr2 kommt nur beim ersten versuch nach restart. hier wird der cmd zu "spät", nach dem empfang der WAKEMEUP msg, auf den leeren stack gepusht. dadurch wird natürlich kein A112 mehr gesendet.
man könnte auch sagen, dass das senden hier zu früh passiert, da das io ja gerade erst präpariert wurde.
präparieren des io und gleichzeitiges senden ist jedenfalls verkehrt.


hier ein sniff vom automatischen statusrequest nach restart.
der hat jetzt aus "versehen" funktioniert, ohne A112.

Code Auswählen Erweitern

2021.04.11 11:06:18.120 4: CUL_Parse: cul868 A 0C 14 8670 2064CB 000000 006C40EA -85
2021.04.11 11:06:18.123 3: CUL_HM set Thermostat.GZ_Climate statusRequest noArg
2021.04.11 11:06:18.124 5: CUL_HM Thermostat.GZ protEvent:CMDs_pending pending:1, 0 -> 2, +2064CB,00,00,00, 2
2021.04.11 11:06:18.124 0: HMUARTLGW hmuart1 send: 01 062064CB000100
2021.04.11 11:06:18.130 5: CUL_HM Thermostat.GZ protEvent:CMDs_processing... pending:0, 2 -> 1, +2064CB,02,00,00, 2
2021.04.11 11:06:18.158 5: CUL_HM set Thermostat.GZ ?
2021.04.11 11:06:18.162 5: CUL_HM set Thermostat.GZ ?
2021.04.11 11:06:18.165 0: HMLAN_Parse: hmlan1 R:E2064CB   stat:0000 t:990CFD9F d:FF r:FF9F     m:14 8670 2064CB 000000 006C40
2021.04.11 11:06:18.167 4: CUL_HM Thermostat.GZ dupe: dont process
2021.04.11 11:06:18.169 0: HMUARTLGW hmuart1 recv: 01 05 00 00 4B msg: 14 86 70 2064CB 000000 006C40
2021.04.11 11:06:18.170 4: CUL_HM Thermostat.GZ dupe: dont process
2021.04.11 11:06:18.172 0: HMUARTLGW hmuart1 recv: 01 04070101000EFFFFFFFFFFFFFFFF, state 90
2021.04.11 11:06:18.173 0: HMUARTLGW hmuart1 GetSet Ack: 07, state 90
2021.04.11 11:06:18.173 0: HMUARTLGW hmuart1 added peer: 2064CB, aesChannels: FFFFFFFFFFFFFFFF
2021.04.11 11:06:18.176 0: HMUARTLGW hmuart1 send: 01 062064CB000100
2021.04.11 11:06:18.182 0: HMUARTLGW hmuart1 recv: 01 04070101000EFFFFFFFFFFFFFFFF, state 93
2021.04.11 11:06:18.183 0: HMUARTLGW hmuart1 GetSet Ack: 07, state 93
2021.04.11 11:06:18.184 0: HMUARTLGW hmuart1 added peer: 2064CB, aesChannels: FFFFFFFFFFFFFFFF
2021.04.11 11:06:18.267 0: HMUARTLGW hmuart1 send: 01 02 00 00 00 msg: 15 A0 01 1ACE1F 2064CB 020E
2021.04.11 11:06:18.292 4: CUL_Parse: cul868 A 0B 15 A001 1ACE1F 2064CB 020E67 -22.5
2021.04.11 11:06:18.303 0: HMLAN_Parse: hmlan1 R:E1ACE1F   stat:0000 t:990CFE4B d:FF r:FFCF     m:15 A001 1ACE1F 2064CB 020E
2021.04.11 11:06:18.425 4: CUL_Parse: cul868 A 0E 15 8002 2064CB 1ACE1F 01020C004FEA -85
2021.04.11 11:06:18.430 5: CUL_HM Thermostat.GZ protEvent:CMDs_done, 1 -> 0, +2064CB,02,00,00, 2
2021.04.11 11:06:18.453 5: CUL_HM set Thermostat.GZ ?
2021.04.11 11:06:18.457 5: CUL_HM set Thermostat.GZ ?
2021.04.11 11:06:18.460 0: HMLAN_Parse: hmlan1 R:E2064CB   stat:0000 t:990CFED0 d:FF r:FFA3     m:15 8002 2064CB 1ACE1F 01020C004F
2021.04.11 11:06:18.462 4: CUL_HM Thermostat.GZ dupe: dont process
2021.04.11 11:06:18.465 0: HMUARTLGW hmuart1 recv: 01 04 03 00 4B msg: 15 80 02 2064CB 1ACE1F 01020C004F
2021.04.11 11:06:18.466 4: CUL_HM Thermostat.GZ dupe: dont process
2021.04.11 11:06:18.468 0: HMUARTLGW hmuart1 send: 01 062064CB000000
2021.04.11 11:06:18.474 0: HMUARTLGW hmuart1 recv: 01 04070101000EFFFFFFFFFFFFFFFF, state 90
2021.04.11 11:06:18.475 0: HMUARTLGW hmuart1 GetSet Ack: 07, state 90
2021.04.11 11:06:18.476 0: HMUARTLGW hmuart1 added peer: 2064CB, aesChannels: FFFFFFFFFFFFFFFF
2021.04.11 11:06:18.478 0: HMUARTLGW hmuart1 send: 01 062064CB000000
2021.04.11 11:06:18.485 0: HMUARTLGW hmuart1 recv: 01 04070101000EFFFFFFFFFFFFFFFF, state 93
2021.04.11 11:06:18.486 0: HMUARTLGW hmuart1 GetSet Ack: 07, state 93
2021.04.11 11:06:18.486 0: HMUARTLGW hmuart1 added peer: 2064CB, aesChannels: FFFFFFFFFFFFFFFF



zum vergleich ein manueller statusrequest, der immer funktioniert.
in beitrag #25 beispiel nr1: es werden immer 2 cmds ausgeführt (ebenfalls beim restart):

Code Auswählen Erweitern

2021.04.11 11:03:27.536 3: CUL_HM set Thermostat.GZ_Climate statusRequest noArg
2021.04.11 11:03:27.561 5: CUL_HM set Thermostat.GZ ?
2021.04.11 11:03:27.584 5: CUL_HM set Thermostat.GZ ?
2021.04.11 11:03:27.586 5: CUL_HM Thermostat.GZ protEvent:CMDs_pending pending:1, 0 -> 2, +2064CB,00,00,00, 2
2021.04.11 11:03:27.588 0: HMUARTLGW hmuart1 send: 01 062064CB000100
2021.04.11 11:03:27.594 0: HMUARTLGW hmuart1 recv: 01 04070101000EFFFFFFFFFFFFFFFF, state 90
2021.04.11 11:03:27.596 0: HMUARTLGW hmuart1 GetSet Ack: 07, state 90
2021.04.11 11:03:27.596 0: HMUARTLGW hmuart1 added peer: 2064CB, aesChannels: FFFFFFFFFFFFFFFF
2021.04.11 11:03:27.599 0: HMUARTLGW hmuart1 send: 01 062064CB000100
2021.04.11 11:03:27.726 0: HMUARTLGW hmuart1 recv: 01 04070101000EFFFFFFFFFFFFFFFF, state 93
2021.04.11 11:03:27.727 0: HMUARTLGW hmuart1 GetSet Ack: 07, state 93
2021.04.11 11:03:27.727 0: HMUARTLGW hmuart1 added peer: 2064CB, aesChannels: FFFFFFFFFFFFFFFF
2021.04.11 11:03:28.127 5: CUL_HM set Thermostat.GZ ?
2021.04.11 11:03:28.155 5: CUL_HM set Thermostat.GZ ?
2021.04.11 11:03:28.882 0: HMUARTLGW hmuart1 send: 00 08
2021.04.11 11:03:28.886 0: HMUARTLGW hmuart1 recv: 00 040207, state 98
2021.04.11 11:03:28.888 0: HMUARTLGW hmuart1 GetSet Ack: 02, state 98
2021.04.11 11:03:28.888 0: HMUARTLGW hmuart1 roundtrip delay: 0.0034
2021.04.11 11:03:29.438 5: CUL_HM set Thermostat.GZ ?
2021.04.11 11:03:29.919 4: CUL_Parse: cul868 A 14 8D 805E 266EA5 1ACE1F 000000000000000000000025 -55.5
2021.04.11 11:03:29.928 0: HMLAN_Parse: hmlan1 R:E266EA5   stat:0000 t:990A6C7F d:FF r:FFCC     m:8D 805E 266EA5 1ACE1F 0000000000000000000000
2021.04.11 11:03:29.933 0: HMUARTLGW hmuart1 recv: 01 05 00 00 32 msg: 8D 80 5E 266EA5 1ACE1F 0000000000000000000000
2021.04.11 11:03:34.523 4: CUL_Parse: cul868 A 0C 68 8670 206278 000000 80A238EF -82.5
2021.04.11 11:03:34.710 0: HMUARTLGW hmuart1 recv: 01 05 00 00 4E msg: 68 86 70 206278 000000 80A238
2021.04.11 11:03:34.714 0: HMLAN_Parse: hmlan1 R:E206278   stat:0000 t:990A7E7B d:FF r:FFBB     m:68 8670 206278 000000 80A238
2021.04.11 11:03:39.997 4: CUL_Parse: cul868 A 0C B9 8670 206487 000000 006945F4 -80
2021.04.11 11:03:40.007 0: HMLAN_Parse: hmlan1 R:E206487   stat:0000 t:990A93DE d:FF r:FFB1     m:B9 8670 206487 000000 006945
2021.04.11 11:03:40.011 0: HMUARTLGW hmuart1 recv: 01 05 00 00 4B msg: B9 86 70 206487 000000 006945
2021.04.11 11:03:43.887 0: HMUARTLGW hmuart1 send: 00 08
2021.04.11 11:03:43.892 0: HMUARTLGW hmuart1 recv: 00 040207, state 98
2021.04.11 11:03:43.893 0: HMUARTLGW hmuart1 GetSet Ack: 02, state 98
2021.04.11 11:03:43.893 0: HMUARTLGW hmuart1 roundtrip delay: 0.0034
2021.04.11 11:03:44.090 0: HMLAN_Send:  hmlan1 I:K
2021.04.11 11:03:44.094 0: HMLAN_Parse: hmlan1 V:03C5 sNo:JEQ0315335 d:1C671E O:1ACE1F t:990AA3E1 IDcnt:0013 L:1 %
2021.04.11 11:03:47.117 4: CUL_Parse: cul868 A 0C 13 8670 2064CB 000000 006C40EB -84.5
2021.04.11 11:03:47.122 5: CUL_HM Thermostat.GZ protEvent:CMDs_processing... pending:0, 2 -> 1, +2064CB,02,00,00, 2
2021.04.11 11:03:47.146 5: CUL_HM set Thermostat.GZ ?
2021.04.11 11:03:47.150 5: CUL_HM set Thermostat.GZ ?
2021.04.11 11:03:47.153 0: HMLAN_Parse: hmlan1 R:E2064CB   stat:0000 t:990AAFAF d:FF r:FFA0     m:13 8670 2064CB 000000 006C40
2021.04.11 11:03:47.155 4: CUL_HM Thermostat.GZ dupe: dont process
2021.04.11 11:03:47.219 0: HMUARTLGW hmuart1 send: 01 02 00 00 00 msg: 14 A0 01 1ACE1F 2064CB 020E
2021.04.11 11:03:47.225 0: HMUARTLGW hmuart1 recv: 01 0408, state 100
2021.04.11 11:03:47.226 0: HMUARTLGW hmuart1 IO currently busy, trying again in a bit
2021.04.11 11:03:47.239 4: CUL_Parse: cul868 A 09 2B A112 1ACE1F 2064CB 67 -22.5
2021.04.11 11:03:47.250 0: HMLAN_Parse: hmlan1 R:E1ACE1F   stat:0000 t:990AB02A d:FF r:FFCF     m:2B A112 1ACE1F 2064CB
2021.04.11 11:03:47.279 0: HMUARTLGW hmuart1 send: 01 02 00 00 00 msg: 14 A0 01 1ACE1F 2064CB 020E
2021.04.11 11:03:47.285 0: HMUARTLGW hmuart1 recv: 01 0408, state 100
2021.04.11 11:03:47.286 0: HMUARTLGW hmuart1 IO currently busy, trying again in a bit
2021.04.11 11:03:47.338 0: HMUARTLGW hmuart1 send: 01 02 00 00 00 msg: 14 A0 01 1ACE1F 2064CB 020E
2021.04.11 11:03:47.344 0: HMUARTLGW hmuart1 recv: 01 0408, state 100
2021.04.11 11:03:47.346 0: HMUARTLGW hmuart1 IO currently busy, trying again in a bit
2021.04.11 11:03:47.370 4: CUL_Parse: cul868 A 0A 2B 8002 2064CB 1ACE1F 00EB -84.5
2021.04.11 11:03:47.376 0: HMUARTLGW hmuart1 recv: 01 05 10 00 4B msg: 13 86 70 2064CB 000000 006C40
2021.04.11 11:03:47.473 0: HMUARTLGW hmuart1 send: 01 02 00 00 00 msg: 14 A0 01 1ACE1F 2064CB 020E
2021.04.11 11:03:47.511 4: CUL_Parse: cul868 A 0B 14 A001 1ACE1F 2064CB 020E67 -22.5
2021.04.11 11:03:47.521 0: HMLAN_Parse: hmlan1 R:E1ACE1F   stat:0000 t:990AB139 d:FF r:FFCF     m:14 A001 1ACE1F 2064CB 020E
2021.04.11 11:03:47.643 4: CUL_Parse: cul868 A 0E 14 8002 2064CB 1ACE1F 01020C004FEC -84
2021.04.11 11:03:47.648 5: CUL_HM Thermostat.GZ protEvent:CMDs_done, 1 -> 0, +2064CB,02,00,00, 2
2021.04.11 11:03:47.672 5: CUL_HM set Thermostat.GZ ?
2021.04.11 11:03:47.675 5: CUL_HM set Thermostat.GZ ?
2021.04.11 11:03:47.680 0: HMUARTLGW hmuart1 recv: 01 04 03 00 4B msg: 14 80 02 2064CB 1ACE1F 01020C004F
2021.04.11 11:03:47.682 4: CUL_HM Thermostat.GZ dupe: dont process
2021.04.11 11:03:47.683 0: HMUARTLGW hmuart1 send: 01 062064CB000000
2021.04.11 11:03:47.690 0: HMUARTLGW hmuart1 recv: 01 04070101000EFFFFFFFFFFFFFFFF, state 90
2021.04.11 11:03:47.691 0: HMUARTLGW hmuart1 GetSet Ack: 07, state 90
2021.04.11 11:03:47.691 0: HMUARTLGW hmuart1 added peer: 2064CB, aesChannels: FFFFFFFFFFFFFFFF
2021.04.11 11:03:47.694 0: HMUARTLGW hmuart1 send: 01 062064CB000000
2021.04.11 11:03:47.700 0: HMUARTLGW hmuart1 recv: 01 04070101000EFFFFFFFFFFFFFFFF, state 93
2021.04.11 11:03:47.701 0: HMUARTLGW hmuart1 GetSet Ack: 07, state 93
2021.04.11 11:03:47.702 0: HMUARTLGW hmuart1 added peer: 2064CB, aesChannels: FFFFFFFFFFFFFFFF


[noansi]

Hallo Frank,

mit dem erweiterten Logging sieht man besser, was zu passieren scheint.

Code Auswählen Erweitern

2021.04.11 11:06:18.120 4: CUL_Parse: cul868 A 0C 14 8670 2064CB 000000 006C40EA -85
CUL empfängt die Nachricht. Damit hat der HMUARTLGW diese auch schon empfangen.

Code Auswählen Erweitern

2021.04.11 11:06:18.123 3: CUL_HM set Thermostat.GZ_Climate statusRequest noArg
Hier wird ein statusRequest abgesetzt, da es gequeued wurde. Das pusht eine message auf den cmdstack. Davor gab es aber noch keinen statusRequest.
In der derzeit implementierten Logik hätte es einen geben müssen, damit das IO im Vorfeld vorbereitet wird (das wäre der erste der 2 statusRequest, die Dich beim manuellen statusRequest stören).

Code Auswählen Erweitern

2021.04.11 11:06:18.124 0: HMUARTLGW hmuart1 send: 01 062064CB000100
2021.04.11 11:06:18.130 5: CUL_HM Thermostat.GZ protEvent:CMDs_processing... pending:0, 2 -> 1, +2064CB,02,00,00, 2

HMUARTLGW wird vorbereitet (durch die message), hat auch alle Informationen dazu. Macht natürlich keinen Sinn mehr, weil er die Nachricht schon empfangen hat.

Damit ist für mich schon mal als wichtiger Punkt geklärt, dass alle Infos für das Vorbereiten des IOs bereit stehen, wenn der automatische statusRequest anläuft.
Der Rest wird komplizierter.

Warum ist der statusRequest gequeued ist die Frage? Ich denke die Antwort liegt im Delayed Status read.

Gruß, Ansgar.

[frank]

und martin hat vorhin auch ein neues update gemacht.

[noansi]

Hallo Frank,

ja, betrifft aber nicht dieses Problem hier.

Dafür die verbleibenden von #18 https://forum.fhem.de/index.php/topic,119853.msg1145485.html#msg1145485.

Auch IOgrp und "none".
Dein Hinweis zu HMInfo und "none" in IOgrp ist dabei noch nicht eingeschlossen gewesen. https://forum.fhem.de/index.php/topic,119853.msg1147382/topicseen.html#msg1147382 Punkt 4.
@Martin: kanst Du bitte mal da schauen.

Gruß, Ansgar.

[frank]

hi ansgar,

gerade entdeckt:
hmlan sendet autonomes ack plus diese "mir suspekte" ackinfo message.

Code Auswählen Erweitern

2021.04.27 09:13:06.728 4: CUL_Parse: cul868 A 0C EC A441 1DF7C6 1ACE1F 01CBC842 -41
2021.04.27 09:13:06.829 0: HMLAN_Send:  hmlan1 S:S122CA825 stat:  00 t:00000000 d:01 r:122CA825 m:EC 8002 1ACE1F 1DF7C6 0101C800
2021.04.27 09:13:06.857 0: HMUARTLGW hmuart1 recv: 01 05 00 00 32 msg: EC A4 41 1DF7C6 1ACE1F 01CBC8
2021.04.27 09:13:06.860 0: HMUARTLGW hmuart1 recv: 01 05 00 00 30 msg: EC 80 02 1ACE1F 1DF7C6 00
2021.04.27 09:13:06.864 4: CUL_Parse: cul868 A 0A EC 8002 1ACE1F 1DF7C6 003F -42.5
2021.04.27 09:13:06.866 0: HMLAN_Parse: hmlan1 R:E1DF7C6   stat:0000 t:09E86652 d:FF r:FFD9     m:EC A441 1DF7C6 1ACE1F 01CBC8
2021.04.27 09:13:07.124 4: CUL_Parse: cul868 A 0D EC 8002 1ACE1F 1DF7C6 0101C8003F -42.5
2021.04.27 09:13:07.129 0: HMUARTLGW hmuart1 recv: 01 05 00 00 30 msg: EC 80 02 1ACE1F 1DF7C6 0101C800
2021.04.27 09:13:07.132 0: HMLAN_Parse: hmlan1 R:R122CA825 stat:0002 t:00000000 d:FF r:7FFF     m:EC 8002 1ACE1F 1DF7C6 0101C800


Code Auswählen Erweitern

Internals:
   DEF        1DF7C6
   FUUID      5c4ce2e9-f33f-09c4-8f44-bd6e15f82bf6976c
   IODev      hmlan1
   LASTInputDev hmlan1
   MSGCNT     207
   NAME       Tuer.WZ.Terrasse
   NOTIFYDEV  global
   NR         296
   NTFY_ORDER 50-Tuer.WZ.Terrasse
   STATE      Tuer:open (to ccu), Status:open, Sabotage:sabotageError, Bat:ok
   TYPE       CUL_HM
   chanNo     01
   cul868_MSGCNT 69
   cul868_RAWMSG A0CECA4411DF7C61ACE1F01CBC8::-41:cul868
   cul868_RSSI -41
   cul868_TIME 2021-04-27 09:13:06
   hmlan1_MSGCNT 69
   hmlan1_RAWMSG E1DF7C6,0000,09E86652,FF,FFD9,ECA4411DF7C61ACE1F01CBC8
   hmlan1_RSSI -39
   hmlan1_TIME 2021-04-27 09:13:06
   hmuart1_MSGCNT 69
   hmuart1_RAWMSG 05000032ECA4411DF7C61ACE1F01CBC8
   hmuart1_RSSI -50
   hmuart1_TIME 2021-04-27 09:13:06
   lastMsg    No:EC - t:41 s:1DF7C6 d:1ACE1F 01CBC8
   protLastRcv 2021-04-27 09:13:06
   protRcv    69 last_at:2021-04-27 09:13:06
   protSnd    69 last_at:2021-04-27 09:13:06
   protState  CMDs_done
   rssi_at_cul868 cnt:69 min:-45.5 max:-40 avg:-41.55 lst:-41
   rssi_at_hmlan1 cnt:69 min:-43 max:-37 avg:-39.62 lst:-39
   rssi_at_hmuart1 cnt:69 min:-59 max:-46 avg:-50.99 lst:-50
   .attraggr:
   .attreocr:
     .*
   .attrminint:
   .attrtocr:
     .*
   CL:
     Authenticated 0
     BUF       
     FD         82
     FW_ID      43149
     LASTACCESS 1619507888
     NAME       WEB_192.168.1.31_49681
     NR         43149
     PEER       192.168.1.31
     PORT       49681
     SNAME      WEB
     SSL       
     STATE      Connected
     TEMPORARY  1
     TYPE       FHEMWEB
     canAsyncOutput 1
     .attraggr:
     .attrminint:
     READINGS:
       2021-04-27 09:16:46   state           Connected
   READINGS:
     from archivexx        .D-devInfo      810101
     from archivexx        .D-stc          80
     2021-04-25 10:18:13   .associatedWith Tuer.WZ.Terrasse,Tuer.WZ.Terrasse
     2021-04-27 09:13:06   .protLastRcv    20210427091306
     2021-03-23 19:19:08   Activity        alive
     from archivexx        D-firmware      2.0
     from archivexx        D-serialNr      JEQ0602486
     2021-04-23 11:24:30   R-cyclicInfoMsg on
     2021-04-23 11:24:30   R-eventDlyTime  2 s
     2021-04-23 11:24:30   R-ledOnTime     0.5 s
     2021-04-23 11:24:30   R-msgScPosA     closed
     2021-04-23 11:24:30   R-msgScPosB     open
     2021-04-23 11:24:30   R-pairCentral   0x1ACE1F
     2021-04-23 11:24:30   R-sabotageMsg   on
     2021-04-23 11:24:30   R-sign          off
     2021-04-23 11:24:30   R-transmDevTryMax 6
     2021-04-23 11:24:30   R-transmitTryMax 6
     2017-01-04 12:43:01   RegL_00.        02:01 09:01 0A:1A 0B:CE 0C:1F 10:01 14:06 00:00
     2017-01-04 12:43:01   RegL_01.        08:00 20:60 21:02 22:64 30:06 00:00
     2021-03-23 19:18:32   battery         ok
     2021-03-23 13:04:18   cfgState        ok
     2021-03-23 19:18:32   commState       CMDs_done
     2021-04-27 09:13:06   contact         open (to ccu)
     2021-04-27 09:13:06   state           open
     2021-04-27 09:13:06   trigger_cnt     203
   helper:
     HM_CMDNR   236
     mId        002F
     peerFriend peerAct,peerVirt
     peerIDsState complete
     peerOpt    4:threeStateSensor
     regLst     0,1,4p
     rxType     28
     supp_Pair_Rep 0
     tmplChg    0
     ack:
     cmds:
       TmplKey    :1619338699.76635:1619338699.78172
       TmplTs     1619338699.78172
       cmdKey     1:1:0::Tuer.WZ.Terrasse:002F:01:
       cmdLst:
         assignHmKey noArg
         clear      [(readings|trigger|register|oldRegs|rssi|msgEvents|{msgErrors}|attack|all)]
         deviceRename -newName-
         fwUpdate   -filename- [-bootTime-]
         getConfig  noArg
         getDevInfo noArg
         getRegRaw  (List0|List1|List2|List3|List4|List5|List6|List7) [-peerChn-]
         peerBulk   -peer1,peer2,...- [({set}|unset)]
         peerChan   -btnNumber- -actChn- [({single})] [({set}|unset)] [actor|remote|both]
         peerSmart  -peerOpt-
         raw        -data- [...]
         regBulk    -list-.-peerChn- -addr1:data1- -addr2:data2-...
         regSet     [(prep|{exec})] -regName- -value- [-peerChn-]
         reset      noArg
         sign       [(on|{off})]
         tplDel     -tplDel-
         tplSet_0   -tplChan-
         trgEventL  -peer- -condition-
         trgEventS  -peer- -condition-
         trgPressL  [(-peer-|{all})]
         trgPressS  [(-peer-|{all})]
         unpair     noArg
       lst:
         condition  closed,open,tilted
         peer       
         peerOpt    DimPBU01_Dim,DimPBU01_Dim_V_01,DimPBU01_Dim_V_02,DimUP01,SDTeam_Btn1,SwitchES01_Sw,SwitchPBU01_Sw_01,SwitchPBU01_Sw_02,SwitchPBU02_Sw_01,SwitchPBU02_Sw_02,SwitchPBU03,SwitchPBU05,SwitchPBU06,SwitchUP01,SwitchUP02,VentilControler.AZ.Nord_Btn1,VentilControler.AZ.West_Btn1,VentilControler.Bad_Btn1,VentilControler.Kueche_Btn1,VentilControler.SZ_Btn1,VentilControler.WZ_Btn1,ccu_Btn1,ccu_Btn2,ccu_Btn3,ccu_Btn4,ccu_Btn5,rssi_hmuart_Btn1,virtAktorAlarmOff_Btn1
         tplChan    single-chn-sensor-device
         tplDel     
         tplPeer   
       rtrvLst:
         cmdList    [({short}|long)]
         deviceInfo [({short}|long)]
         list       [({normal}|full)]
         param      -param-
         reg        -addr- -list- [-peerChn-]
         regList    noArg
         regTable   noArg
         regVal     -addr- -list- [-peerChn-]
         saveConfig [-filename-]
         tplInfo    noArg
     expert:
       def        1
       det        1
       raw        1
       tpl        1
     io:
       flgs       0
       newChn     +1DF7C6,00,00,00
       nextSend   1619507587.14787
       rxt        2
       vccu       ccu
       p:
         1DF7C6
         00
         00
         00
       prefIO:
         hmlan1
     mRssi:
       mNo        EC
       io:
         cul868:
           -41
           -41
         hmlan1:
           -31
           -31
         hmuart1:
           -50
           -50
         hmusb1:
     peerIDsH:
       00000000   broadcast
     prt:
       bErr       0
       sProc      0
       sleeping   1
       rspWait:
     q:
       qReqConf   
       qReqStat   
     role:
       chn        1
       dev        1
     rpt:
       IO         cul868
       flg        A
       ts         1619507586.73025
       ack:
         HASH(0x40eae50)
         EC80021ACE1F1DF7C60101C800
     rssi:
       at_cul868:
         avg        -41.5579710144928
         cnt        69
         lst        -41
         max        -40
         min        -45.5
       at_hmlan1:
         avg        -39.6231884057971
         cnt        69
         lst        -39
         max        -37
         min        -43
       at_hmuart1:
         avg        -51
         cnt        69
         lst        -50
         max        -46
         min        -59
     shadowReg:
     tmpl:
Attributes:
   .mId       002F
   IODev      hmlan1
   IOgrp      ccu:hmlan1
   actCycle   028:00
   actStatus  alive
   autoReadReg 0_off
   comment    Lueftung
   event-on-change-reading .*
   expert     defReg,allReg,rawReg,templ
   firmware   2.0
   group      Alarmmelder
   model      HM-SEC-SC
   peerIDs    00000000
   room       01_ALARM,10_WZ
   serialNr   JEQ0602486
   stateFormat Tuer:contact, Status:state, Sabotage:sabotageError, Bat:battery
   subType    threeStateSensor
   timestamp-on-change-reading .*

[noansi]

Hallo Frank,

hmlan sendet autonomes ack plus diese "mir suspekte" ackinfo message.

Ja, wird von CUL_HM generiert und dieser Kommentar erklärt es:

Code Auswählen Erweitern

# SCs - depending on FW version - do not accept ACK only. Especially if peered

Weh tut es aber nicht.

Gruß, Ansgar.

[frank]

hallo ansgar,

Weh tut es aber nicht.

da habe ich ja nur drauf gewartet. 


bei expliziten, zusätzlichen statusrequests, die "nur" bei restart kämen und wahrscheinlich "nur" bei mehr-kanal-aktoren, die unerreichbar in der schublade liegen, warst du noch ganz anderer ansicht:

Code Auswählen Erweitern

besser wäre natürlich, alle channel werden wirklich abgefragt.
Da msgRepeat zur Anwendung kommt, würdest Du ein mehrfaches an Funklast erzeugen/credits verschwenden, für das gleiche Ergebnis.

sagen wir mal:
3 zimmer, küche, bad, balkon => vielleicht 8 kontakte.
bei wenig nutzung vielleicht jeweils 3x täglich öffnen/schliessen => 3x2x8=48 "unnötige" msgs täglich.
auf diesen wert komme ich alleine schon durch meine katze an der terrassentür.
corona-konformes lüften (alle 20min?) ist auch noch nciht eingerechnet.

wieviele definierte, stromlose mehr-kanal-aktoren liegen durchschnittlich in der schublade?
ich sage mal: maximal ein 4-chn-aktor,
der dann zb zusätzlich: 3 (chn) x 4 (normal+resend) = 12 "unnötige" msgs pro restart erzeugt. 
sogar bei fragwürdigen, täglichen restarts wären das nur ein viertel der msgs im vergleich zum sc.

Code Auswählen Erweitern

# SCs - depending on FW version - do not accept ACK only. Especially if peered
da bei eq3 grundsätzlich die ACKs der zentrale von den io autonom erzeugt werden, würde ich wetten, dass eine ccu niemals zusätzlich ein ackinfo sendet.
und gepeerte thermostate machen sicherlich auch keine unterschiede im ACK verhalten.

wenn überhaupt, kann das ja nur ein fw bug in einigen sc sein.
ich kann mich noch dunkel an probleme bei den ersten sc2 erinnern.
meine sc1 mit fw 2.4 haben von anfang an, egal ob gepeert oder nicht, auf "normale" ACK mit grüner led reagiert.

Weh tut es aber nicht.

hoffentlich sind diese ackinfos nicht an den häufigen sc problemen schuld (pairing verlust, freeze, ..).
zumal ja die enthaltene info im ackinfo auch nicht stimmt.


gruss frank

[noansi]

Hallo Frank,

wenn überhaupt, kann das ja nur ein fw bug in einigen sc sein.

schöne überzeugende Rechnung. 
Das behebt aber leider noch nicht das Problem des Kommentars, dessen Urheber ich nicht bin und zu der ich nicht mal eine Firmwareversion kenne, die betroffen wäre, noch weiß, was passiert, wenn der state ack nicht gesendet wird, noch warum er so ausschaut.
Sonst wäre ich auch grundsätzlich direkt dabei.

So lautet die komplette Zeile mit dem Kommentar.

Code Auswählen Erweitern

      if ($mh{md} =~ m/^(HM-SEC-SC.*|ROTO_ZEL-STG-RM-FFK)$/){# SCs - depending on FW version - do not accept ACK only. Especially if peered

Du kannst Dir den Code in dem Bereich ja mal auf nur Ack umbauen und schauen, ob es bei Dir problemlos klappt.
Da beim threeStateSensor für CUL schon ein ACK gepushed wird und die anderen IOs auto Ack senden sollten, dürfte es reichen, die Zeile danach einfach auszukommentieren.

Meine HM-SEC-SC-2 Firmware 2.4 sind mit einem einzelnen Ack mit oder ohne AES anscheinend glücklich.
Sie wiederholen nicht, wenn die Status Message nicht gesendet wird. Stromaufnahme habe ich auch gemessen, was bestätigt, dass sie auch brav sofort wieder einschlafen.

Code Auswählen Erweitern

2021.04.28 19:16:08.909 4: TSCUL_Parse: SCC_HM868  08067900 A F001 10967448 00 0C 03 A641 5B3F13 F11034 010300 -55.5dB
2021.04.28 19:16:09.104 4: TSCUL_Parse: SCC_HM868  08068097 A F001 10967580 00 0A 03 8002 F11034 5B3F13 00 -46dB
2021.04.28 19:16:12.156 4: TSCUL_Parse: SCC_HM868  08071148 A F001 10970684 00 0C 04 A641 5B3F13 F11034 0104C8 -54.5dB
2021.04.28 19:16:12.266 4: TSCUL_Parse: SCC_HM868  08071259 A F001 10970804 00 0A 04 8002 F11034 5B3F13 00 -46.5dB
2021.04.28 19:16:15.414 4: TSCUL_Parse: SCC_HM868  08074403 A F001 10973920 00 0C 05 A641 5B3F13 F11034 010500 -56dB
2021.04.28 19:16:15.531 4: TSCUL_Parse: SCC_HM868  08074523 A F001 10974036 00 0A 05 8002 F11034 5B3F13 00 -46dB
2021.04.28 19:16:17.665 4: TSCUL_Parse: SCC_HM868  08076656 A F001 10976160 00 0C 06 A641 5B3F13 F11034 0106C8 -53.5dB
2021.04.28 19:16:17.791 4: TSCUL_Parse: SCC_HM868  08076782 A F001 10976280 00 0A 06 8002 F11034 5B3F13 00 -46.5dB
2021.04.28 19:16:20.435 4: TSCUL_Parse: SCC_HM868  08079427 A F001 10978896 00 0C 07 A641 5B3F13 F11034 010700 -55.5dB
2021.04.28 19:16:20.554 4: TSCUL_Parse: SCC_HM868  08079546 A F001 10979016 00 0A 07 8002 F11034 5B3F13 00 -46dB
2021.04.28 19:16:21.899 4: TSCUL_Parse: SCC_HM868  08080890 A F001 10980388 00 0C 08 A641 5B3F13 F11034 0108C8 -53.5dB
2021.04.28 19:16:22.067 4: TSCUL_Parse: SCC_HM868  08081060 A F001 10980508 00 0A 08 8002 F11034 5B3F13 00 -46.5dB


Das wird Martin aber vermutlich nicht reichen, um auf der Basis eine Änderung einzubauen.
Vermutlich werden deswegen Patches zum HM-LC-DIM1TPBU-FM und HM-MOD-RE-8 auch nicht vollständig übernommen, weil der Test mit allen älteren Hard-/Firmwareversionen für mich nicht durchführbar ist, um die FW Bugs ggf. versionsgerecht bedienen zu können.

hoffentlich sind diese ackinfos nicht an den häufigen sc problemen schuld (pairing verlust, freeze, ..).

Kann man natürlich nicht ausschließen, ohne der Firmwarecode untersuchen zu können.
Ein reproduzierbares Logging würde Überzugungskraft leisten können, so denn die Versionsfrage zu obigem Kommentar ebenfalls zu klären wäre.

Gruß, Ansgar.

PS: Meine letzten Probleme mit einem HM-SEC-SC-2 ließen sich übrigens mit Nachlöten der Stromversorgungsverkabelung lösen (obwohl die Lötungen nicht so schlecht aussahen). Fast leere Knopfzellen oder schlechter Batteriekontakt sind ebenso wahrscheinlich als Problemursache.

[frank]

hi ansgar,

hier sind eigentlich alle infos (sc1,sc2,roto) zu finden: https://forum.fhem.de/index.php/topic,22688.msg162781.html#msg162781.


zusammenfassung des led verhaltens (inkl meines sc/fw2.4):

Code Auswählen Erweitern

model   fw   unpeered/Ack   unpeered/AckInfo   peered/Ack   peered/AckInfo
---------------------------------------------------------------------------
roto    2.0      rot             grün             rot            grün
sc      2.1      rot             grün             rot            grün
sc      2.4      grün            grün             grün           grün
sc-2    2.2      rot             grün             rot            rot
sc-2    2.4      grün            grün             grün           grün


daraus folgt:
alle fensterkontakte mit fw >= 2.4 können mit Ack und AckInfo umgehen => für diese reicht ein Ack.
alle fensterkontakte mit fw < 2.4 können nur mit AckInfo umgehen. => für diese reicht ein AckInfo.

zusätzlich hat der sc-2 mit fw 2.2 ein problem, wenn er mit einem rt gepeert ist. ich vermute, dass er auch vom peer ein AckInfo erwartet. im sniff sind allerdings keine wiederholungen zu sehen.



ohne AckInfo, wenn ich die "push AckInfo" zeile auskommentiere:
jeweils open/close mit einem gepeerten (io=hmuart) und einem ungepeerten (io=hmlan) sc/fw 2.4

Code Auswählen Erweitern

2021.04.29 14:57:48.728 4: CUL_Parse: cul868 A 0C B5 A441 1DE620 1ACE1F 01B2C81D -59.5
2021.04.29 14:57:48.763 0: HMUARTLGW hmuart1 recv: 01 05 01 00 4B msg: B5 A4 41 1DE620 1ACE1F 01B2C8
2021.04.29 14:57:48.766 0: HMLAN_Parse: hmlan1 R:E1DE620   stat:0000 t:157117D6 d:FF r:FFCE     m:B5 A441 1DE620 1ACE1F 01B2C8
2021.04.29 14:57:48.851 4: CUL_Parse: cul868 A 0A B5 8002 1ACE1F 1DE620 0067 -22.5
2021.04.29 14:57:48.861 0: HMLAN_Parse: hmlan1 R:E1ACE1F   stat:0000 t:15711850 d:FF r:FFD0     m:B5 8002 1ACE1F 1DE620 00
2021.04.29 14:57:48.979 4: CUL_Parse: cul868 A 0C B6 A041 1DE620 1A164B 01B2C81E -59
2021.04.29 14:57:49.026 0: HMUARTLGW hmuart1 recv: 01 05 00 00 44 msg: B6 A0 41 1DE620 1A164B 01B2C8
2021.04.29 14:57:49.030 0: HMLAN_Parse: hmlan1 R:E1DE620   stat:0000 t:157118D0 d:FF r:FFCE     m:B6 A041 1DE620 1A164B 01B2C8
2021.04.29 14:57:49.105 4: CUL_Parse: cul868 A 0E B6 8002 1A164B 1DE620 0101C8402E1A -61
2021.04.29 14:57:49.137 0: HMUARTLGW hmuart1 recv: 01 05 00 00 40 msg: B6 80 02 1A164B 1DE620 0101C8402E
2021.04.29 14:57:49.140 0: HMLAN_Parse: hmlan1 R:E1A164B   stat:0000 t:1571194E d:FF r:FFC7     m:B6 8002 1A164B 1DE620 0101C8402E

2021.04.29 14:57:53.729 4: CUL_Parse: cul868 A 0C B7 A441 1DE620 1ACE1F 01B3001A -61
2021.04.29 14:57:53.762 0: HMLAN_Parse: hmlan1 R:E1DE620   stat:0000 t:15712B5F d:FF r:FFD3     m:B7 A441 1DE620 1ACE1F 01B300
2021.04.29 14:57:53.766 0: HMUARTLGW hmuart1 recv: 01 05 01 00 3C msg: B7 A4 41 1DE620 1ACE1F 01B300
2021.04.29 14:57:53.852 4: CUL_Parse: cul868 A 0A B7 8002 1ACE1F 1DE620 0067 -22.5
2021.04.29 14:57:53.861 0: HMLAN_Parse: hmlan1 R:E1ACE1F   stat:0000 t:15712BD9 d:FF r:FFD0     m:B7 8002 1ACE1F 1DE620 00
2021.04.29 14:57:53.979 4: CUL_Parse: cul868 A 0C B8 A041 1DE620 1A164B 01B3001B -60.5
2021.04.29 14:57:54.026 0: HMLAN_Parse: hmlan1 R:E1DE620   stat:0000 t:15712C59 d:FF r:FFD3     m:B8 A041 1DE620 1A164B 01B300
2021.04.29 14:57:54.030 0: HMUARTLGW hmuart1 recv: 01 05 00 00 3C msg: B8 A0 41 1DE620 1A164B 01B300
2021.04.29 14:57:54.106 4: CUL_Parse: cul868 A 0E B8 8002 1A164B 1DE620 010100003419 -61.5
2021.04.29 14:57:54.146 0: HMLAN_Parse: hmlan1 R:E1A164B   stat:0000 t:15712CD7 d:FF r:FFC7     m:B8 8002 1A164B 1DE620 0101000034
2021.04.29 14:57:54.158 0: HMUARTLGW hmuart1 recv: 01 05 00 00 40 msg: B8 80 02 1A164B 1DE620 0101000034

2021.04.29 15:01:16.430 4: CUL_Parse: cul868 A 0C 2E A441 1DF7C6 1ACE1F 010DC841 -41.5
2021.04.29 15:01:16.464 0: HMUARTLGW hmuart1 recv: 01 05 00 00 32 msg: 2E A4 41 1DF7C6 1ACE1F 010DC8
2021.04.29 15:01:16.467 0: HMLAN_Parse: hmlan1 R:E1DF7C6   stat:0000 t:15744346 d:FF r:FFD9     m:2E A441 1DF7C6 1ACE1F 010DC8
2021.04.29 15:01:16.552 4: CUL_Parse: cul868 A 0A 2E 8002 1ACE1F 1DF7C6 0040 -42
2021.04.29 15:01:16.557 0: HMUARTLGW hmuart1 recv: 01 05 00 00 2C msg: 2E 80 02 1ACE1F 1DF7C6 00

2021.04.29 15:01:21.429 4: CUL_Parse: cul868 A 0C 2F A441 1DF7C6 1ACE1F 010E0040 -42
2021.04.29 15:01:21.495 0: HMUARTLGW hmuart1 recv: 01 05 00 00 31 msg: 2F A4 41 1DF7C6 1ACE1F 010E00
2021.04.29 15:01:21.506 0: HMLAN_Parse: hmlan1 R:E1DF7C6   stat:0000 t:157456CE d:FF r:FFD8     m:2F A441 1DF7C6 1ACE1F 010E00
2021.04.29 15:01:21.552 4: CUL_Parse: cul868 A 0A 2F 8002 1ACE1F 1DF7C6 0040 -42
2021.04.29 15:01:21.560 0: HMUARTLGW hmuart1 recv: 01 05 00 00 2C msg: 2F 80 02 1ACE1F 1DF7C6 00

zum vergleich mit AckInfo (hierbei zeigt hmlan probleme, da häufig msgs im log fehlen):
jeweils open/close mit einem gepeerten (io=hmuart) und einem ungepeerten (io=hmlan) sc/fw 2.4

Code Auswählen Erweitern

2021.04.29 12:36:38.697 4: CUL_Parse: cul868 A 0C A5 A441 1DE620 1ACE1F 01AAC80A -69
2021.04.29 12:36:38.745 0: HMUARTLGW hmuart1 recv: 01 05 01 00 34 msg: A5 A4 41 1DE620 1ACE1F 01AAC8
2021.04.29 12:36:38.749 0: HMLAN_Parse: hmlan1 R:E1DE620   stat:0000 t:14EFD563 d:FF r:FFCD     m:A5 A441 1DE620 1ACE1F 01AAC8
2021.04.29 12:36:38.800 0: HMUARTLGW hmuart1 send: 01 02 00 00 00 msg: A5 80 02 1ACE1F 1DE620 0101C800
2021.04.29 12:36:38.806 0: HMUARTLGW hmuart1 recv: 01 0408, state 101
2021.04.29 12:36:38.807 0: HMUARTLGW hmuart1 IO currently busy, trying again in a bit
2021.04.29 12:36:38.819 4: CUL_Parse: cul868 A 0A A5 8002 1ACE1F 1DE620 0067 -22.5
2021.04.29 12:36:38.830 0: HMLAN_Parse: hmlan1 R:E1ACE1F   stat:0000 t:14EFD5DE d:FF r:FFD0     m:A5 8002 1ACE1F 1DE620 00
2021.04.29 12:36:38.860 0: HMUARTLGW hmuart1 send: 01 02 00 00 00 msg: A5 80 02 1ACE1F 1DE620 0101C800
2021.04.29 12:36:38.948 4: CUL_Parse: cul868 A 0C A6 A041 1DE620 1A164B 01AAC811 -65.5
2021.04.29 12:36:38.998 0: HMUARTLGW hmuart1 recv: 01 05 00 00 34 msg: A6 A0 41 1DE620 1A164B 01AAC8
2021.04.29 12:36:39.000 4: CUL_Parse: cul868 A 0D A5 8002 1ACE1F 1DE620 0101C80067 -22.5
2021.04.29 12:36:39.005 0: HMLAN_Parse: hmlan1 R:E1ACE1F   stat:0000 t:14EFD676 d:FF r:FFD0     m:A5 8002 1ACE1F 1DE620 0101C800
2021.04.29 12:36:39.074 4: CUL_Parse: cul868 A 0E A6 8002 1A164B 1DE620 0101C8403119 -61.5
2021.04.29 12:36:39.110 0: HMUARTLGW hmuart1 recv: 01 05 00 00 41 msg: A6 80 02 1A164B 1DE620 0101C84031
2021.04.29 12:36:39.114 0: HMLAN_Parse: hmlan1 R:E1A164B   stat:0000 t:14EFD6DD d:FF r:FFC7     m:A6 8002 1A164B 1DE620 0101C84031

2021.04.29 12:36:44.450 4: CUL_Parse: cul868 A 0C A7 A441 1DE620 1ACE1F 01AB00F8 -78
2021.04.29 12:36:44.489 0: HMUARTLGW hmuart1 recv: 01 05 01 00 35 msg: A7 A4 41 1DE620 1ACE1F 01AB00
2021.04.29 12:36:44.493 0: HMLAN_Parse: hmlan1 R:E1DE620   stat:0000 t:14EFEBDC d:FF r:FFCF     m:A7 A441 1DE620 1ACE1F 01AB00
2021.04.29 12:36:44.553 0: HMUARTLGW hmuart1 send: 01 02 00 00 00 msg: A7 80 02 1ACE1F 1DE620 0101C800
2021.04.29 12:36:44.559 0: HMUARTLGW hmuart1 recv: 01 0408, state 101
2021.04.29 12:36:44.560 0: HMUARTLGW hmuart1 IO currently busy, trying again in a bit
2021.04.29 12:36:44.572 4: CUL_Parse: cul868 A 0A A7 8002 1ACE1F 1DE620 0067 -22.5
2021.04.29 12:36:44.582 0: HMLAN_Parse: hmlan1 R:E1ACE1F   stat:0000 t:14EFEC57 d:FF r:FFD0     m:A7 8002 1ACE1F 1DE620 00
2021.04.29 12:36:44.613 0: HMUARTLGW hmuart1 send: 01 02 00 00 00 msg: A7 80 02 1ACE1F 1DE620 0101C800
2021.04.29 12:36:44.699 4: CUL_Parse: cul868 A 0C A8 A041 1DE620 1A164B 01AB00FA -77
2021.04.29 12:36:44.747 4: CUL_Parse: cul868 A 0D A7 8002 1ACE1F 1DE620 0101C80067 -22.5
2021.04.29 12:36:44.752 0: HMUARTLGW hmuart1 recv: 01 05 00 00 34 msg: A8 A0 41 1DE620 1A164B 01AB00
2021.04.29 12:36:44.755 0: HMLAN_Parse: hmlan1 R:E1DE620   stat:0000 t:14EFECD6 d:FF r:FFD0     m:A8 A041 1DE620 1A164B 01AB00
2021.04.29 12:36:44.825 4: CUL_Parse: cul868 A 0E A8 8002 1A164B 1DE620 010100002F19 -61.5
2021.04.29 12:36:44.859 0: HMUARTLGW hmuart1 recv: 01 05 00 00 42 msg: A8 80 02 1A164B 1DE620 010100002F
2021.04.29 12:36:44.867 0: HMLAN_Parse: hmlan1 R:E1A164B   stat:0000 t:14EFED54 d:FF r:FFC6     m:A8 8002 1A164B 1DE620 010100002F

2021.04.29 06:30:46.049 4: CUL_Parse: cul868 A 0C 2C A441 1DF7C6 1ACE1F 010BC83F -42.5
2021.04.29 06:30:46.150 0: HMLAN_Send:  hmlan1 S:S1BE4BE9E stat:  00 t:00000000 d:01 r:1BE4BE9E m:2C 8002 1ACE1F 1DF7C6 0101C800
2021.04.29 06:30:46.181 0: HMLAN_Parse: hmlan1 R:E1DF7C6   stat:0000 t:13A0D16A d:FF r:FFD6     m:2C A441 1DF7C6 1ACE1F 010BC8
2021.04.29 06:30:46.185 0: HMUARTLGW hmuart1 recv: 01 05 00 00 33 msg: 2C A4 41 1DF7C6 1ACE1F 010BC8
2021.04.29 06:30:46.188 0: HMUARTLGW hmuart1 recv: 01 05 00 00 2C msg: 2C 80 02 1ACE1F 1DF7C6 00
2021.04.29 06:30:46.192 4: CUL_Parse: cul868 A 0A 2C 8002 1ACE1F 1DF7C6 0040 -42
2021.04.29 06:30:46.444 4: CUL_Parse: cul868 A 0D 2C 8002 1ACE1F 1DF7C6 0101C80040 -42
2021.04.29 06:30:46.449 0: HMLAN_Parse: hmlan1 R:R1BE4BE9E stat:0002 t:00000000 d:FF r:7FFF     m:2C 8002 1ACE1F 1DF7C6 0101C800
2021.04.29 06:30:46.451 0: HMUARTLGW hmuart1 recv: 01 05 00 00 2C msg: 2C 80 02 1ACE1F 1DF7C6 0101C800

2021.04.29 08:12:47.479 4: CUL_Parse: cul868 A 0C 2D A441 1DF7C6 1ACE1F 010C0040 -42
2021.04.29 08:12:47.581 0: HMLAN_Send:  hmlan1 S:S1C422679 stat:  00 t:00000000 d:01 r:1C422679 m:2D 8002 1ACE1F 1DF7C6 0101C800
2021.04.29 08:12:47.631 0: HMLAN_Parse: hmlan1 R:E1DF7C6   stat:0000 t:13FE3C67 d:FF r:FFD8     m:2D A441 1DF7C6 1ACE1F 010C00
2021.04.29 08:12:47.634 4: CUL_Parse: cul868 A 0A 2D 8002 1ACE1F 1DF7C6 0040 -42
2021.04.29 08:12:47.640 0: HMUARTLGW hmuart1 recv: 01 05 00 00 30 msg: 2D A4 41 1DF7C6 1ACE1F 010C00
2021.04.29 08:12:47.643 0: HMUARTLGW hmuart1 recv: 01 05 00 00 2C msg: 2D 80 02 1ACE1F 1DF7C6 00
2021.04.29 08:12:47.871 4: CUL_Parse: cul868 A 0D 2D 8002 1ACE1F 1DF7C6 0101C80041 -41.5
2021.04.29 08:12:47.876 0: HMLAN_Parse: hmlan1 R:R1C422679 stat:0002 t:00000000 d:FF r:7FFF     m:2D 8002 1ACE1F 1DF7C6 0101C800
2021.04.29 08:12:47.878 0: HMUARTLGW hmuart1 recv: 01 05 00 00 2C msg: 2D 80 02 1ACE1F 1DF7C6 0101C800



jetzt verstehe ich endlich, warum überhaupt auch AckInfo funktioniert:
der gepeerte aktor (sw1pbu-fm) antwortet ebenfalls mit AckInfo.
da vermute ich mal, dass der "zickige" sc-2 mit fw 2.2 mit diesem switch gepeert, ebenfalls grün zeigen würde.

noch zur info:
dieser sc-2/fw2.2 hat übrigens im verlinkten thread mit A241 die trigger gesendet, kann also auch lazyConfig.