ACK Verständnisfrage

Begonnen von KarlHeinz2000, 30 September 2020, 15:16:27

Vorheriges Thema - Nächstes Thema

KarlHeinz2000

Ich habe einen kleinen RS485 Aufbau mit GW und einem Node und teste das ACK, um meine Übertragung zuverlässiger zu machen.
Dabei ist mir aufgefallen, dass im Falle eines fehlenden ACK das heartbeat reading auf NACK gesetzt wird und nicht der state. Soll das so sein?
Heartbeat wird auch nur durch ein gesendetes Heartbeat wieder auf alive gesetzt. Ein erfolgreiches ACK bewirkt das nicht.
Wie wäre der angedachte Ablauf? Ich sende Daten zum Node mit ACK aktiv und warte dann, ob das entsprechende Reading innerhalb einer Zeit auf den neuen Wert geht? Wenn nicht-> nicht zugestellt. Oder wertet man das heartbeat reading bzgl NACK aus? Aber wie?

Beta-User

Also, die story war die, dass heartbeat ursprünglich mal in state stattgefunden hat, weil das (scheinbar) gar nicht genutzt wurde.
Irgendwie war das aber nicht der richtige Ort, daher ist es insgesamt eben in ein eigenes Reading "heartbeat" gewandert, was dann nicht ganz optimal ist, wenn man es mit "state"-settern zu tun hat (also z.B. einem Relay, das man per setCommands nach "state" geschoben hat). Sowas ist aber die ziemliche Ausnahme, was man schon daran sieht, dass du nach Jahren der erste bist, der darüber grübelt ;D ...

Im Prinzip könnte man "dead" etc. ja auch wieder zurücksetzen, wenn "irgendwas" von der Node kommt. Das war mal in der Diskussion, hätte aber eine deutliche Erhöhung der Systemlast zur Folge gehabt, daher hatte ich das damals nicht umgesetzt. Du hat jetzt aber m.E. berechtigt einen "Sonderfall" aufgezeigt, werde mal schauen, wie man Antworten auf "Ack"-Anforderungen an der Stelle anders behandeln kann.

(Btw.: eine heartbeat-Message sollte nach meinem Codeverständnis eigentlich ein NACK nicht zurücksetzen, sondern erst eine zeitgerecht bestätigte (andere) ACK-Anforderung. Wenn wir das aber in der Ack-Verarbeitung berücksichtigen, kann das m.E. auch so bleiben, alles andere wäre unnötiger overhead.
Wobei man von ACK im engeren Sinne eigentlich nur noch bei nRF24 sprechen sollte, im MyS-Node-Code nennt sich das seit einiger Zeit bei anderen Transport-Layern "echo").
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

Beta-User

Mags du mal zum testen diese Routine in 10_MYSENSORS_DEVICE.pm tauschen:

sub onSetMessage {
    my $hash = shift;
    my $msg  = shift // return;
    my $name = $hash->{NAME};
    if (defined $msg->{payload}) {
      eval {
        my ($reading,$value) = rawToMappedReading($hash,$msg->{subType},$msg->{childId},$msg->{payload});
        readingsBeginUpdate($hash);
        readingsBulkUpdate($hash, $reading, $value);
        if ( defined ($hash->{setcommands}->{$value}) && $hash->{setcommands}->{$value}->{var} eq $reading ) { #$msg->{childId}
           if ($hash->{SetExtensionsCommand} && AttrVal($name, "setExtensionsEvent", undef)) {
             readingsBulkUpdate($hash,"state",$hash->{SetExtensionsCommand}) ; 
           } else {
             readingsBulkUpdate($hash,"state","$value");
             SetExtensionsCancel($hash) if !$msg->{ack};
           }
         }
      };
      readingsBulkUpdate($hash,"heartbeat","alive") if $msg->{ack} && ReadingsVal($hash,"heartbeat","dead") eq "NACK" and @{$hash->{IODev}->{messagesForRadioId}->{$hash->{radioId}}->{messages}} == 0;
      readingsEndUpdate( $hash, 1 );
      Log3 ($hash->{NAME}, 4, "MYSENSORS_DEVICE $hash->{NAME}: ignoring C_SET-message ".GP_Catch($@)) if $@;
    } else {
      Log3 ($hash->{NAME}, 5, "MYSENSORS_DEVICE $hash->{NAME}: ignoring C_SET-message without payload");
    }
    return;
}
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

KarlHeinz2000

Alles klar. Mache ich heute Abend.
Danke.

KarlHeinz2000

Habe das kurz getestet. Keine Änderung. :(
Nach einem fehlenden ACK bleibt das heartbeat reading auf NACK. Egal ob die ACKs später wieder kommen. Auch einreboot des Node ändert nichts. Nur ein gesendeter heartbeat setzt das reading auf alive. Der Übergang von dead auf NACK funktioniert.

PS:
das requestAck Attribut lässt sich nur mit deleteattr löschen. Das Ändern über das drop down Feld geht nicht (es wird immer 1 angezeigt)

Beta-User

#5
Grummel, da war ich wohl etwas verpeilt, was das Ziel der ReadingsVal-Abfrage anging...

So sollte der Teil besser sein:
sub onSetMessage {
    my $hash = shift;
    my $msg  = shift // return;
    my $name = $hash->{NAME};
    if (defined $msg->{payload}) {
      eval {
        my ($reading,$value) = rawToMappedReading($hash,$msg->{subType},$msg->{childId},$msg->{payload});
        readingsBeginUpdate($hash);
        readingsBulkUpdate($hash, $reading, $value);
        if ( defined ($hash->{setcommands}->{$value}) && $hash->{setcommands}->{$value}->{var} eq $reading ) { #$msg->{childId}
           if ($hash->{SetExtensionsCommand} && AttrVal($name, "setExtensionsEvent", undef)) {
             readingsBulkUpdate($hash,"state",$hash->{SetExtensionsCommand}) ; 
           } else {
             readingsBulkUpdate($hash,"state","$value");
             SetExtensionsCancel($hash) if !$msg->{ack};
           }
         }
      };
      readingsBulkUpdate($hash,"heartbeat","alive") if $msg->{ack} && ReadingsVal($name,"heartbeat","dead") eq "NACK" and @{$hash->{IODev}->{messagesForRadioId}->{$hash->{radioId}}->{messages}} == 0;
      readingsEndUpdate( $hash, 1 );
      Log3 ($hash, 4, "MYSENSORS_DEVICE $name: ignoring C_SET-message ".GP_Catch($@)) if $@;
    } else {
      Log3 ($hash, 5, "MYSENSORS_DEVICE $name: ignoring C_SET-message without payload");
    }
    return;
}


Dafür finde ich es jetzt ganz und gar nicht mehr einleuchtend, dass eine heartbeat-Message das auf alive setzt, obwohl ggf. noch nicht alles zugestellt ist, was mit ACK-Anforderung versendet wurde (bzw. wiederholt dann auch versendet wird)... Da ist wohl auch noch was ändern ab Zeile 947:
    if ($type == I_HEARTBEAT_RESPONSE) {
        readingsSingleUpdate($hash, "heartbeat", "alive",1) if !ReadingsVal($name,"heartbeat","alive") eq "NACK";


Ad PS:
Das mit dem "Wahr/Falsch"-Attribut ist auch in vielen anderen Fällen so, dass man das nur (auf 1) Setzen oder Löschen kann.
EDIT sagt: Es gibt jedenfalls nach meinem Verständnis sogar komische Ergebnisse, wenn man das via Kommandozeile auf "0" setzt, bitte mal ein list ansehen... (Wie gesagt, mit diesem Verhalten dürfte MYSENSORS_DEVICE kein Einzelfall sein ;) .)
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

KarlHeinz2000

Jetzt funktioniert das ACK in der Art, dass das heartbeat reading nach Ablauf der timeoutAck Zeit auf NACK geht. Sobald die Nachricht zugestellt wurde geht es wieder auf alive. Passt, denke ich.
Allerdings ist das Alive jetzt ohne Funktion. Es gibt kein dead mehr. Das heartbeat reading bleibt immer auf alive. Nur wenn timeoutAlive geändert wird wird dead aktiv.

Beta-User

Hmm, vielleicht sollte man die Abfrage einfacher schreiben:
     readingsSingleUpdate($hash, "heartbeat", "alive",1) if ReadingsVal($name,"heartbeat","alive") ne "NACK";

Danke für's Testen und Mitdenken!
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

KarlHeinz2000

geht immer noch nicht. Das reading wechselt nicht von alive nach dead.

Beta-User

Vermutlich habe ich was noch nicht richtig verstanden. Was genau meinst du mit
Zitat von: KarlHeinz2000 am 01 Oktober 2020, 17:59:06
Allerdings ist das Alive jetzt ohne Funktion. Es gibt kein dead mehr. Das heartbeat reading bleibt immer auf alive. Nur wenn timeoutAlive geändert wird wird dead aktiv.

Grundsätzlich ist "dead" nur erreichbar, wenn timeoutAlive gesetzt ist. Du schreibst aber, dass das timeoutAlive geändert werden müßte. Dann war das gesetzt, allerdings muss der Timer wieder aktiviert werden, daher nochmaliges setzen.
(Dann hat das aber eher was mit der Änderung in onSetMessage() zu tun und nichts mit der  I_HEARTBEAT_RESPONSE-Geschichte? Das Verhalten müsste dann (fast) gleich sein, egal, was dort passiert... Grübel, werde mir das mit den Timern nochmal ansehen müssen, aber eine Klarstellung wäre ggf. hilfreich).
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

KarlHeinz2000

Ich versuche mal das Verhalten zu beschreiben:

1)
requestAck 0
timeoutAlive 3

dead/alive funktioniert. Nach Ablauf timeoutAlive geht reading auf dead
- gesendetes heartbeat vom node: dead -> alive (->dead)
- ändern der timeoutAlive: dead->alive(->dead)

2)
requestAck 1
timeoutAck 2
timeoutAlive 3

RS485 Verbindung händisch unterbrochen.

Senden-> Reading geht auf NACK nach Ablauf der timeoutAck.
Ist die Verbindung wieder hergestellt, kommt nach einigen Sek ein erneuter/automatischer Sendeversuch. Dieser gelingt. Das reading wird von NACK->alive gesetzt (retry von FHEM oder GW?).
Es bleibt dann alive, außer:
- Wenn ein heartbeat vom node kommt, läuft die Zeit erneut ab und dead wird gesetzt.
- Die timeoutAlive Zeit wird geändert
- Übertragung ist gestört ->NACK


Beta-User

OK, dann muss der Timer auch an der Stelle wieder in Gang gesetzt werden. Ergo sollte das hier helfen:

sub onSetMessage {
    my $hash = shift;
    my $msg  = shift // return;
    my $name = $hash->{NAME};
    if (defined $msg->{payload}) {
      readingsBeginUpdate($hash);
      eval {
        my ($reading,$value) = rawToMappedReading($hash,$msg->{subType},$msg->{childId},$msg->{payload});
     
        readingsBulkUpdate($hash, $reading, $value);
        if ( defined ($hash->{setcommands}->{$value}) && $hash->{setcommands}->{$value}->{var} eq $reading ) { #$msg->{childId}
           if ($hash->{SetExtensionsCommand} && AttrVal($name, "setExtensionsEvent", undef)) {
             readingsBulkUpdate($hash,"state",$hash->{SetExtensionsCommand}) ; 
           } else {
             readingsBulkUpdate($hash,"state","$value");
             SetExtensionsCancel($hash) if !$msg->{ack};
           }
         }
      };
      if ($msg->{ack} && ReadingsVal($name,"heartbeat","dead") eq "NACK" and @{$hash->{IODev}->{messagesForRadioId}->{$hash->{radioId}}->{messages}} == 0) {
         readingsBulkUpdate($hash,"heartbeat","alive") ;
         refreshInternalMySTimer($hash,"Alive") if $hash->{timeoutAlive};
      }
      readingsEndUpdate( $hash, 1 );
      Log3 ($hash, 4, "MYSENSORS_DEVICE $name: ignoring C_SET-message ".GP_Catch($@)) if $@;
    } else {
      Log3 ($hash, 5, "MYSENSORS_DEVICE $name: ignoring C_SET-message without payload");
    }
    return;
}
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

KarlHeinz2000

Sieht gut aus!  :)
Soweit ich es testen konnte ist alles ok.

Ein eingehendes heartbeat vom Node generiert allerdings 2 alive events im monitor. Soll das so sein? War evtl auch vorher schon so...

Und jetzt geht es an die Umsetzung der eigentlichen Kommunikation mit ACK. Da habe ich auf FHEM Seite noch keine Idee.
Eine Sub schreiben, in der gesendet wird und gleichzeitig ein Timer läuft und auf das ACK wartet?
Wie kann ich sicherstellen, dass ein empfangenes ACK auch zu meiner gesendeten Nachricht gehört und nicht von einem anderen Node stammt? Fängt da Protokoll das ab?
Es gibt unterschiedliche events:

MYSENSORS_DEVICE MYSENSOR_100 var2 3
MYSENSORS_DEVICE MYSENSOR_100 var2: 3

Einmal mit und ohne ":"
"Ohne" ist das Senden mit angefordertem ACK
"Mit" ist das eingehende ACK
Bei timeout ACK kommt das NACK zwischendrin

2020-10-02 11:57:35 MYSENSORS_DEVICE MYSENSOR_100 var2 3
2020-10-02 11:57:37 MYSENSORS_DEVICE MYSENSOR_100 heartbeat: NACK
2020-10-02 11:57:49 MYSENSORS_DEVICE MYSENSOR_100 var2: 3


Wird ohne requestACK gesendet kommt nur:


MYSENSORS_DEVICE MYSENSOR_100 var2: 3


Macht ein Fifo Sinn, wenn eine Nachricht länger braucht und schon eine die nächste gesendet werden soll. Wo fängt man sowas ab?



Wenn es da Ideen gibt, bitte her damit  ;)

Beta-User

Wg. des 2. Events: Ist vermutlich eine "Nebenwirkung" der Timer-Erneuerung, kommentiere mal in onSetEvent den Reading-Update aus:
if ($msg->{ack} && ReadingsVal($name,"heartbeat","dead") eq "NACK" and @{$hash->{IODev}->{messagesForRadioId}->{$hash->{radioId}}->{messages}} == 0) {
         #readingsBulkUpdate($hash,"heartbeat","alive") ;
         refreshInternalMySTimer($hash,"Alive") if $hash->{timeoutAlive};
      }


Was die "Warteschlange" angeht: die wird vom Modul verwaltet und der Reihe nach abgearbeitet. MAn. no action required. Ob da irgendeine bessere Timing-Verarbeitung erforderlich wäre: keine Ahnung, ein Teil der Nachrichten wird nämlich auch (zusätzlich) vom GW gepuffert, das hat einen buffer, der afaik sowohl eingehende wie ausgehende Messages enthalten kann (dunkel: ~15). Von daher würde ich das "Freischießen der Leitung" nach Möglichkeit auf dem GW belassen. Wer da richtig viel Traffic hat, muss ggf. eine andere MCU einsetzen und den Nachrichtenpuffer dort vergrößern?

Die Events mit und ohne Doppelpunkt dürften normal sein, ist einmal das Setzen vom User/von FHEM aus und einmal die Antwort, ohne Ack wird so getan, als "wäre das so".
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

KarlHeinz2000

Die 2 alive sind immer noch im event monitor. Aber nur wenn das heartbeat vom Node kommt. Wenn ich nur den timeoutAlive ändere, kommt nur 1x alive.

Wie reagiere ich, wenn beim Senden etwas nicht ankommt. z.B: 3 Nachrichten sollen gesendet werden. Bei der 2. gibt es kein ACK. Wie bekomme ich das mit? Wird dann abgebrochen oder noch x-Mal probiert? Geht die 3. Nachricht noch raus?

Beta-User

#15
Puh, dickes Brett, aber m.E. war das mit den Timern der entscheidende Hinweis. Kann zwar sein, dass das jetzt erst mal noch eine Regression gibt, aber im Prinzip sollte es zielführend sein, alles in den Timer-Erneuerungen abzuklären und (im Prinzip) auch nur da die Events zu erzeugen. Da das ganze jetzt auf ein paar Stellen verteilt ist, das ganze Packet anbei.

Was die Queue angeht: Das Modul versucht - in immer größeren Abständen - zuzustellen, solange, bis es eine Bestätigung gibt (oder einen neuen Content, der an das Noce/Child-Paar gehen soll). Erst mit der Bestätigung fliegt das aus der Queue (oder mit einem FHEM-Restart).
Konkret auf dein Beispiel bedeutet es, dass die 2. und 3. Nachricht "ewig" wiederholt wird. Die Größe der Warteschlange insgesamt steht auch irgendwo (aus dem Gedächtnis: beim GW, bitte ggf. in die Internals und lists schauen).

(EDIT: gleich noch eine etwas erweiterte Meta-Unterstützung eingebaut).
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

KarlHeinz2000

Moin,
habe das heute noch mal getestet und es funktioniert.

Beta-User

Danke für die Rückmeldung, dann checke ich das bei Gelegenheit ein :) .
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

KarlHeinz2000

Mir ist noch was aufgefallen. Wenn ich von FHEM aus ohne payload sende, dann wird das vom node kommende ECHO nicht erkannt und zyklisch wiederholt gesendet.
Ich habe eine "0" dann "" dann "0" gesendet
Das ECHO bei "" wurde nicht erkannt und deswegen 3 Mal wiederholt.

2020.11.10 21:36:47 4: MYSENSORS/RAW: /0;255
2020.11.10 21:36:47 4: MYSENSORS/RAW: 0;255/;3;0;9;53010
2020.11.10 21:36:47 4: MYSENSORS/RAW: 0;255;3;0;9;53010/0657
2020.11.10 21:36:47 4: MYSENSORS/RAW: 0;255;3;0;9;530100657 /TSF:SAN:OK

2020.11.10 21:36:47 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530100657 TSF:SAN:OK'

2020.11.10 21:36:47 5: MYSENSORS gateway gateway: 530100657 TSF:SAN:OK
2020.11.10 21:36:49 5: MYSENSORS send: Rx: fr=070 ci=000 c=001(C_SET         ) st=047(V_TEXT          ) ack=1 '0'

2020.11.10 21:36:49 5: SW: 37303b303b313b313b34373b300a
2020.11.10 21:36:49 5: MYSENSOR_70: refreshInternalMySTimer called (Ack)
2020.11.10 21:36:49 5: MYSENSOR_70: Ack timeout timer set at 1605040609.34201
2020.11.10 21:36:49 5: MYSENSOR_70 is not sleeping, sending message!
2020.11.10 21:36:49 5: gateway: getFirmwareTypes - list contains:
2020.11.10 21:36:49 5: MYSENSOR_70: timeoutAck called
2020.11.10 21:36:49 4: MYSENSOR_70: timeoutAck called, outstanding: 1
2020.11.10 21:36:49 5: gateway: getFirmwareTypes - list contains:
2020.11.10 21:36:49 4: MYSENSORS/RAW: /0;255;3;0;9;530102025 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=0,l=1,sg=0,ft=0,st=OK:0
0;255;3;0;9;530102046 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=0,l=1,sg=0:0
0;255;3;0;9;530102066 TSF:MSG:ECHO
70;0;1;1;47;0

2020.11.10 21:36:49 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530102025 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=0,l=1,sg=0,ft=0,st=OK:0'

2020.11.10 21:36:49 5: MYSENSORS gateway gateway: 530102025 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=0,l=1,sg=0,ft=0,st=OK:0
2020.11.10 21:36:49 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530102046 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=0,l=1,sg=0:0'

2020.11.10 21:36:49 5: MYSENSORS gateway gateway: 530102046 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=0,l=1,sg=0:0
2020.11.10 21:36:49 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530102066 TSF:MSG:ECHO'

2020.11.10 21:36:49 5: MYSENSORS gateway gateway: 530102066 TSF:MSG:ECHO
2020.11.10 21:36:49 4: MYSENSORS Read: Rx: fr=070 ci=000 c=001(C_SET         ) st=047(V_TEXT          ) ack=1 '0'

2020.11.10 21:36:49 5: MYSENSOR_70: refreshInternalMySTimer called (Alive)
2020.11.10 21:36:49 5: gateway: getFirmwareTypes - list contains:
2020.11.10 21:36:49 5: MYSENSOR_70: refreshInternalMySTimer called (Ack)
2020.11.10 21:36:49 5: MYSENSOR_70: Ack timeout timer set at 1605040609.55885
2020.11.10 21:36:49 5: MYSENSOR_70: timeoutAck called
2020.11.10 21:36:49 4: MYSENSOR_70: timeoutAck called, no outstanding Acks at all
2020.11.10 21:36:53 5: MYSENSORS send: Rx: fr=070 ci=000 c=001(C_SET         ) st=047(V_TEXT          ) ack=1 ''

2020.11.10 21:36:53 5: SW: 37303b303b313b313b34373b0a
2020.11.10 21:36:53 5: MYSENSOR_70: refreshInternalMySTimer called (Ack)
2020.11.10 21:36:53 5: MYSENSOR_70: Ack timeout timer set at 1605040613.70833
2020.11.10 21:36:53 5: MYSENSOR_70 is not sleeping, sending message!
2020.11.10 21:36:53 5: gateway: getFirmwareTypes - list contains:
2020.11.10 21:36:53 4: MYSENSORS/RAW: /0;255;3;0;9;530106392 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=0,ft=0,st=OK:0
0;255;3;0;9;530106415 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l=1,sg=0:
2020.11.10 21:36:53 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530106392 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=0,ft=0,st=OK:0'

2020.11.10 21:36:53 5: MYSENSORS gateway gateway: 530106392 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=0,ft=0,st=OK:0
2020.11.10 21:36:53 4: MYSENSORS/RAW: 0;255;3;0;9;530106415 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l=1,sg=0:/0
0;255;3;0;9;53
2020.11.10 21:36:53 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530106415 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l=1,sg=0:0'

2020.11.10 21:36:53 5: MYSENSORS gateway gateway: 530106415 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l=1,sg=0:0
2020.11.10 21:36:53 4: MYSENSORS/RAW: 0;255;3;0;9;53/0106434 TSF:MSG:ECHO

2020.11.10 21:36:53 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530106434 TSF:MSG:ECHO'

2020.11.10 21:36:53 5: MYSENSORS gateway gateway: 530106434 TSF:MSG:ECHO
2020.11.10 21:36:53 4: MYSENSORS/RAW: /70;0;1;1;47;0

2020.11.10 21:36:53 4: MYSENSORS Read: Rx: fr=070 ci=000 c=001(C_SET         ) st=047(V_TEXT          ) ack=1 '0'

2020.11.10 21:36:53 4: MYSENSORS Read: unexpected ack Rx: fr=070 ci=000 c=001(C_SET         ) st=047(V_TEXT          ) ack=1 '0'

2020.11.10 21:36:53 5: MYSENSOR_70: refreshInternalMySTimer called (Alive)
2020.11.10 21:36:53 5: gateway: getFirmwareTypes - list contains:
2020.11.10 21:36:53 5: MYSENSOR_70: refreshInternalMySTimer called (Ack)
2020.11.10 21:36:53 5: MYSENSOR_70: Ack timeout timer set at 1605040613.81766
2020.11.10 21:36:53 5: MYSENSOR_70: timeoutAck called
2020.11.10 21:36:53 4: MYSENSOR_70: timeoutAck called, outstanding: 1
2020.11.10 21:36:53 5: gateway: getFirmwareTypes - list contains:
2020.11.10 21:36:55 5: MYSENSORS outstanding ack, re-send: Rx: fr=070 ci=000 c=001(C_SET         ) st=047(V_TEXT          ) ack=1 ''

2020.11.10 21:36:55 5: SW: 37303b303b313b313b34373b0a
2020.11.10 21:36:55 4: MYSENSORS/RAW: /0;25
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;25/5;3;0;
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;/9;530
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530/107787
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107787/ TSF:
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107787 TSF:/MSG:SE
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107787 TSF:MSG:SE/ND,0-
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107787 TSF:MSG:SEND,0-/0-70-7
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107787 TSF:MSG:SEND,0-0-70-7/0,s=0
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107787 TSF:MSG:SEND,0-0-70-70,s=0/,c=1,t
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t/=47,pt
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt/=1,l=
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=/1,sg=0
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=0/,ft=0
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=0,ft=0/,st=OK
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=0,ft=0,st=OK/:0
0
2020.11.10 21:36:55 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530107787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=0,ft=0,st=OK:0'

2020.11.10 21:36:55 5: MYSENSORS gateway gateway: 530107787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=0,ft=0,st=OK:0
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0/;255;3
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3/;0;9;5
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;5/30107
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107/809 TS
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107809 TS/F:MSG
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107809 TSF:MSG/:READ,
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107809 TSF:MSG:READ,/70-70
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107809 TSF:MSG:READ,70-70/-0,s=0
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107809 TSF:MSG:READ,70-70-0,s=0/,c=1,
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107809 TSF:MSG:READ,70-70-0,s=0,c=1,/t=47,p
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107809 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,p/t=1,l=
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107809 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l=/1,sg=
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107809 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l=1,sg=/0:0
0
2020.11.10 21:36:55 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530107809 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l=1,sg=0:0'

2020.11.10 21:36:55 5: MYSENSORS gateway gateway: 530107809 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l=1,sg=0:0
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0/;255;3
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3/;0;9;5
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;5/30107
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107/828 TS
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107828 TS/F:MSG
2020.11.10 21:36:55 4: MYSENSORS/RAW: 0;255;3;0;9;530107828 TSF:MSG/:ECHO

2020.11.10 21:36:55 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530107828 TSF:MSG:ECHO'

2020.11.10 21:36:55 5: MYSENSORS gateway gateway: 530107828 TSF:MSG:ECHO
2020.11.10 21:36:55 4: MYSENSORS/RAW: /70;0
2020.11.10 21:36:55 4: MYSENSORS/RAW: 70;0/;1;1;4
2020.11.10 21:36:55 4: MYSENSORS/RAW: 70;0;1;1;4/7;0

2020.11.10 21:36:55 4: MYSENSORS Read: Rx: fr=070 ci=000 c=001(C_SET         ) st=047(V_TEXT          ) ack=1 '0'

2020.11.10 21:36:55 4: MYSENSORS Read: unexpected ack Rx: fr=070 ci=000 c=001(C_SET         ) st=047(V_TEXT          ) ack=1 '0'

2020.11.10 21:36:55 5: MYSENSOR_70: refreshInternalMySTimer called (Alive)
2020.11.10 21:36:55 5: gateway: getFirmwareTypes - list contains:
2020.11.10 21:36:55 5: MYSENSOR_70: refreshInternalMySTimer called (Ack)
2020.11.10 21:36:55 5: MYSENSOR_70: Ack timeout timer set at 1605040615.18579
2020.11.10 21:36:55 5: MYSENSOR_70: timeoutAck called
2020.11.10 21:36:55 4: MYSENSOR_70: timeoutAck called, outstanding: 1
2020.11.10 21:36:55 5: gateway: getFirmwareTypes - list contains:
2020.11.10 21:36:58 5: MYSENSORS outstanding ack, re-send: Rx: fr=070 ci=000 c=001(C_SET         ) st=047(V_TEXT          ) ack=1 ''

2020.11.10 21:36:58 5: SW: 37303b303b313b313b34373b0a
2020.11.10 21:36:58 4: MYSENSORS/RAW: /0;25
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;25/5;3;0
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0/;9;530
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530/110787
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110787/ TSF:
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110787 TSF:/MSG:SE
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110787 TSF:MSG:SE/ND,0-
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110787 TSF:MSG:SEND,0-/0-70-7
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110787 TSF:MSG:SEND,0-0-70-7/0,s=0
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110787 TSF:MSG:SEND,0-0-70-70,s=0/,c=1,t
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t/=47,p
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,p/t=1,l=
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=/1,sg=
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=/0,ft=0
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=0,ft=0/,st=OK
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=0,ft=0,st=OK/:0
0
2020.11.10 21:36:58 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530110787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=0,ft=0,st=OK:0'

2020.11.10 21:36:58 5: MYSENSORS gateway gateway: 530110787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=0,ft=0,st=OK:0
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0/;255;3
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3/;0;9;
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;/530110
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110/810 T
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110810 T/SF:MSG
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110810 TSF:MSG/:READ,
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110810 TSF:MSG:READ,/70-70
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110810 TSF:MSG:READ,70-70/-0,s=0
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110810 TSF:MSG:READ,70-70-0,s=0/,c=1,
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110810 TSF:MSG:READ,70-70-0,s=0,c=1,/t=47,p
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110810 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,p/t=1,l
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110810 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l/=1,sg=
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110810 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l=1,sg=/0:0
0
2020.11.10 21:36:58 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530110810 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l=1,sg=0:0'

2020.11.10 21:36:58 5: MYSENSORS gateway gateway: 530110810 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l=1,sg=0:0
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0/;255;3
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3/;0;9;
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;/530110
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110/828 TS
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110828 TS/F:MSG
2020.11.10 21:36:58 4: MYSENSORS/RAW: 0;255;3;0;9;530110828 TSF:MSG/:ECHO

2020.11.10 21:36:58 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530110828 TSF:MSG:ECHO'

2020.11.10 21:36:58 5: MYSENSORS gateway gateway: 530110828 TSF:MSG:ECHO
2020.11.10 21:36:58 4: MYSENSORS/RAW: /70;0
2020.11.10 21:36:58 4: MYSENSORS/RAW: 70;0/;1;1;4
2020.11.10 21:36:58 4: MYSENSORS/RAW: 70;0;1;1;4/7;0

2020.11.10 21:36:58 4: MYSENSORS Read: Rx: fr=070 ci=000 c=001(C_SET         ) st=047(V_TEXT          ) ack=1 '0'

2020.11.10 21:36:58 4: MYSENSORS Read: unexpected ack Rx: fr=070 ci=000 c=001(C_SET         ) st=047(V_TEXT          ) ack=1 '0'

2020.11.10 21:36:58 5: MYSENSOR_70: refreshInternalMySTimer called (Alive)
2020.11.10 21:36:58 5: gateway: getFirmwareTypes - list contains:
2020.11.10 21:36:58 5: MYSENSOR_70: refreshInternalMySTimer called (Ack)
2020.11.10 21:36:58 5: MYSENSOR_70: Ack timeout timer set at 1605040618.18538
2020.11.10 21:36:58 5: MYSENSOR_70: timeoutAck called
2020.11.10 21:36:58 4: MYSENSOR_70: timeoutAck called, outstanding: 1
2020.11.10 21:36:58 5: gateway: getFirmwareTypes - list contains:
2020.11.10 21:37:01 5: MYSENSORS outstanding ack, re-send: Rx: fr=070 ci=000 c=001(C_SET         ) st=047(V_TEXT          ) ack=1 ''

2020.11.10 21:37:01 5: SW: 37303b303b313b313b34373b0a
2020.11.10 21:37:01 4: MYSENSORS/RAW: /0;2
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;2/55;3;
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;/0;9;53
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;53/01137
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;5301137/87 TSF
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113787 TSF/:MSG:S
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113787 TSF:MSG:S/END,0
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113787 TSF:MSG:SEND,0/-0-70-
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113787 TSF:MSG:SEND,0-0-70-/70,s=
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113787 TSF:MSG:SEND,0-0-70-70,s=/0,c=1,
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,/t=47,
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,/pt=1,l
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l/=1,sg
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg/=0,ft=
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=0,ft=/0,st=O
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=0,ft=0,st=O/K:0

2020.11.10 21:37:01 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530113787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=0,ft=0,st=OK:0'

2020.11.10 21:37:01 5: MYSENSORS gateway gateway: 530113787 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=1,l=1,sg=0,ft=0,st=OK:0
2020.11.10 21:37:01 4: MYSENSORS/RAW: /0;255
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255/;3;0;
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;/9;5301
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;5301/13810
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113810/ TSF:M
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113810 TSF:M/SG:REA
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113810 TSF:MSG:REA/D,70-
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113810 TSF:MSG:READ,70-/70-0,s
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113810 TSF:MSG:READ,70-70-0,s/=0,c=
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113810 TSF:MSG:READ,70-70-0,s=0,c=/1,t=47
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113810 TSF:MSG:READ,70-70-0,s=0,c=1,t=47/,pt=1
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113810 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1/,l=1,s
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113810 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l=1,s/g=0:0
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113810 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l=1,sg=0:0/
0;25
2020.11.10 21:37:01 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530113810 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l=1,sg=0:0'

2020.11.10 21:37:01 5: MYSENSORS gateway gateway: 530113810 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l=1,sg=0:0
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;25/5;3;0
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0/;9;530
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530/113828
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113828/ TSF:
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113828 TSF:/MSG:EC
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530113828 TSF:MSG:EC/HO
7
2020.11.10 21:37:01 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530113828 TSF:MSG:ECHO'

2020.11.10 21:37:01 5: MYSENSORS gateway gateway: 530113828 TSF:MSG:ECHO
2020.11.10 21:37:01 4: MYSENSORS/RAW: 7/0;0;1;
2020.11.10 21:37:01 4: MYSENSORS/RAW: 70;0;1;/1;47;
2020.11.10 21:37:01 4: MYSENSORS/RAW: 70;0;1;1;47;/0

2020.11.10 21:37:01 4: MYSENSORS Read: Rx: fr=070 ci=000 c=001(C_SET         ) st=047(V_TEXT          ) ack=1 '0'

2020.11.10 21:37:01 4: MYSENSORS Read: unexpected ack Rx: fr=070 ci=000 c=001(C_SET         ) st=047(V_TEXT          ) ack=1 '0'

2020.11.10 21:37:01 5: MYSENSOR_70: refreshInternalMySTimer called (Alive)
2020.11.10 21:37:01 5: gateway: getFirmwareTypes - list contains:
2020.11.10 21:37:01 5: MYSENSOR_70: refreshInternalMySTimer called (Ack)
2020.11.10 21:37:01 5: MYSENSOR_70: Ack timeout timer set at 1605040621.18625
2020.11.10 21:37:01 5: MYSENSOR_70: timeoutAck called
2020.11.10 21:37:01 4: MYSENSOR_70: timeoutAck called, outstanding: 1
2020.11.10 21:37:01 5: gateway: getFirmwareTypes - list contains:
2020.11.10 21:37:01 5: MYSENSORS send: Rx: fr=070 ci=000 c=001(C_SET         ) st=047(V_TEXT          ) ack=1 '0'

2020.11.10 21:37:01 5: SW: 37303b303b313b313b34373b300a
2020.11.10 21:37:01 5: MYSENSOR_70: refreshInternalMySTimer called (Ack)
2020.11.10 21:37:01 5: MYSENSOR_70: Ack timeout timer set at 1605040621.95284
2020.11.10 21:37:01 5: MYSENSOR_70 is not sleeping, sending message!
2020.11.10 21:37:01 5: gateway: getFirmwareTypes - list contains:
2020.11.10 21:37:01 4: MYSENSORS/RAW: /0;255;3;0;9;530114635 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=0,l=1,sg=0,ft=0,st=OK:0
0;255;3;0;9;530114658 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=0,l=1,sg=
2020.11.10 21:37:01 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530114635 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=0,l=1,sg=0,ft=0,st=OK:0'

2020.11.10 21:37:01 5: MYSENSORS gateway gateway: 530114635 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=0,l=1,sg=0,ft=0,st=OK:0
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530114658 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=0,l=1,sg=/0:0
0;255;3;0;9;
2020.11.10 21:37:01 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530114658 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=0,l=1,sg=0:0'

2020.11.10 21:37:01 5: MYSENSORS gateway gateway: 530114658 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=0,l=1,sg=0:0
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;/530114677 TSF:MSG:ECHO
2020.11.10 21:37:01 4: MYSENSORS/RAW: 0;255;3;0;9;530114677 TSF:MSG:ECHO/
70;0
2020.11.10 21:37:01 4: MYSENSORS Read: Rx: fr=000 ci=255 c=003(C_INTERNAL    ) st=009(I_LOG_MESSAGE   ) ack=0 '530114677 TSF:MSG:ECHO'

2020.11.10 21:37:01 5: MYSENSORS gateway gateway: 530114677 TSF:MSG:ECHO
2020.11.10 21:37:01 4: MYSENSORS/RAW: 70;0/;1;1;47;0

2020.11.10 21:37:01 4: MYSENSORS Read: Rx: fr=070 ci=000 c=001(C_SET         ) st=047(V_TEXT          ) ack=1 '0'

2020.11.10 21:37:01 5: MYSENSOR_70: refreshInternalMySTimer called (Alive)
2020.11.10 21:37:01 5: gateway: getFirmwareTypes - list contains:
2020.11.10 21:37:01 5: MYSENSOR_70: refreshInternalMySTimer called (Ack)
2020.11.10 21:37:01 5: MYSENSOR_70: Ack timeout timer set at 1605040622.06195
2020.11.10 21:37:02 5: MYSENSOR_70: timeoutAck called
2020.11.10 21:37:02 4: MYSENSOR_70: timeoutAck called, no outstanding Acks at all

Beta-User

Boa, nicht so einfach, nichts von nichts zu unterscheiden; kann ggf. unerwünschte Nebenwirkungen haben...

Kannst du mal testweise in 00_MYSENSORS folgende Zeile zum Ergänzen der fehlenden payload was reinbasteln:

sub onAcknowledge {
  my ($hash,$msg) = @_;
  my $ack;
  $msg->{payload} = '' if !defined $msg->{payload};
  if (defined (my $outstanding = $hash->{messagesForRadioId}->{$msg->{radioId}}->{messages})) {


Irgendwann muß ich auch das mit den firmware-update-Nachfragen fixen, das ist irgendwie unschön...
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

KarlHeinz2000

Funktioniert leider nicht. Wobei ich mir immer noch nicht im klaren bin, was FHEM bei "" wirklich sendet. Ist das wirklich nichts/leer/... oder doch irgendein Zeichen? NULL? Wie bekommt man da ran? Auf dem RX vom GW mitmessen?

Wenn ich mit FHEM "" sende steht im log vom node


22:45:26.259 -> 816348 TSF:MSG:SEND,70-70-0-0,s=0,c=1,t=47,pt=1,l=1,sg=0,ft=0,st=OK:0
22:45:26.259 -> ID: 0, Data:
22:45:26.259 -> ret is <null>


Parallel mit einem anderen GW am MYSController

11.11.2020 22:45:26 RX 0;255;3;0;9;2103425 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=1,l=1,sg=0:0
11.11.2020 22:45:26 RX 0;255;3;0;9;2103443 TSF:MSG:ACK
11.11.2020 22:45:26 RX 70;0;1;1;47;0


Beides mal wird "0" angezeigt, wobei der Node das als NULL /0 erkennt. Das scheint keine normale 0 zu sein.

Sende ich vom Node "" zu FHEM sieht das so aus

11.11.2020 22:50:00 RX 0;255;3;0;9;2377205 TSF:MSG:READ,70-70-0,s=0,c=1,t=47,pt=0,l=0,sg=0:
11.11.2020 22:50:00 RX 70;0;1;0;47;

Und "" von MYSController zum node
11.11.2020 22:57:07 TX 70;0;1;0;47;
11.11.2020 22:57:07 RX 0;255;3;0;9;2803834 TSF:MSG:SEND,0-0-70-70,s=0,c=1,t=47,pt=0,l=0,sg=0,ft=0,st=OK:


Beides mal richtig leer/kein Zeichen. Auch das ECHO funktioniert zwischen MYSController und Node.
Siehe auch https://forum.mysensors.org/post/108080
Das habe ich mittlerweile auch so selbst testen können.


KarlHeinz2000

Nachgemessen. FHEM und MYSController versenden die gleiche Nachricht zum GW. Payload fehlt. Warum der Node das unterschiedlich darstellt???

Beta-User

Bin grade auch noch am gedanklichen Puzzeln.

Habe mir auch nochmal die Vorgeschichte angesehen...
Es ist jedenfalls ein Problem, wenn was anderes zurückkommt, als versendet wurde, zumindest liegt es dann schon mal nicht an der onAcknowledge().

Aber warum versendet MYSController da auch (zusätzlich...?!?) was mit I_NONCE...?!? (Log Parser Auswertung von dem, was frits gepostet hatte)

Es gibt in jedem Fall auch ein Problem in onSetMessage() in DEVICE: Da wird vorausgesetzt, dass es eine Payload gibt, sonst wird auch das ack nicht richtig verarbeitet. Das muss ich mir wohl in jedem Fall mal anschauen, aber das hat mit deinem Problem erst mal nichts zu tun. Das mit dem I_NONCE muss ich mir wohl auch mal ansehen, bisher hatte ich nicht die leiseste Idee, für was das da sein könnte; aber evtl. geht es da tatsächlich um die Option, Inhalte mit NULL zu belegen? (Falls du eine Quelle dazu findest: her damit...)

Ansonsten bastelt FHEM bei jeder ausgehenden Message eine "Zwangspayload" mit "". Vielleicht wäre hier ein () besser (Zeile 937) (Merker für mich: abgekupfert von https://www.tutorialspoint.com/using-null-values-in-perl-database-operation).
Was anderes fällt mir grade nicht ein...
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

KarlHeinz2000

Entwarnung in gewisser Weise.
Nach einer Menge Testen sieht es für mich so aus, dass der Fehler in der aktuellen MySensor lib liegt.
Wenn das GW mit 2.2.0 läuft ist alles gut. ECHO wird sofort erkannt.
Mit der 2.3.2 auf dem GW gibt es die Probleme, da das GW beim ECHO anstelle "" eine 0 an FHEM sendet.

Beta-User

Hm, ok, dann lege ich das Thema mal auf die Seite.

Ich nehme an, du hast/wirst das als PR bei MySensors einkippen, oder?
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files

Beta-User

Zitat von: Beta-User am 05 Oktober 2020, 09:50:04
Danke für die Rückmeldung, dann checke ich das bei Gelegenheit ein :) .
Done!
Server: HP-elitedesk@Debian 12, aktuelles FHEM@ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn: u.a MySensors, Weekday-&RandomTimer, Twilight,  div. attrTemplate-files