[gelöst] smartSleep friert Fhem ein

Begonnen von alru, 26 Januar 2019, 14:23:09

Vorheriges Thema - Nächstes Thema

alru

Moin,

da nach dem Update (https://forum.fhem.de/index.php/topic,95298.0.html) i.S. "alive" action required ist, wollte ich das heute mal testen.

So wie ich das verstanden habe, gibt es zwei Möglichkeiten ein alive zu generieren:

  • sendHeartbeat() oder
  • smartSleep(<ms>)

Die erste Variante mit sendHeartbeat() funktioniert wie erwartet. Die readings für heartbeat und state werden entsprechend aktualisiert.

Beim Einsatz von smartSleep erscheint nach dem Start des Nodes oder nach dem Reset häufig (nicht immer, aber man kann es provozieren) im state "received presentation".
Danach ist Fhem sofort komplett eingefroren (im Log ist dazu nichts zu finden). Auf der Konsole wird beim Prozess 100% CPU Auslastung angezeigt. Ein Stop/Start von Fhem ist nicht möglich, der Prozess muss gekilled werden.
So lange asleep, alive oder dead im state erscheint, funktioniert alles.

Getestet hab ich das mit einem quasi "leeren" Sketch, auf einem Uno:
void loop()
{
// so geht es:
     sendHeartbeat();
     sleep(5000);

// und so nicht:
//   smartSleep(5000);
}


Meine Konfigurationen:
fhem.pl                                        18317 2019-01-18
10_MYSENSORS_DEVICE.pm 18211 2019-01-11
Mysensors API                           2.2.0
Arduino IDE                                1.8.5

Wenn ich die Wahl hätte, wäre smartSleep mein Favorit, da dort auch der Status "asleep" zu sehen ist.
Gruß,

Stefan
(Raspi 3B / HM-LGW / HomeMatic / MySensors)

Beta-User

Hallo alru,
Danke für's reporten.

Leider habe ich im Moment noch keine durchgreifende Idee, was das auslöst, aber die Funktionalität sollte so sein wie vor dir beschrieben.

Kannst du mal den Abschnitt ab Zeile 767 gegen das hier tauschen und dann nochmal versuchen, den Fehler zu provozieren:
    $type == I_SKETCH_NAME and do {
        #$hash->{$typeStr} = $msg->{payload};
        readingsSingleUpdate($hash, "state", "received presentation", 1) unless ($hash->{STATE} eq "received presentation");
        readingsSingleUpdate($hash, "SKETCH_NAME", $msg->{payload}, 1);
        Log3 $name, 3, "Sketch Name updated";
        #undef $hash->{FW_DATA}; # enable this to free memory?
        delete $hash->{FW_DATA} if (defined $hash->{FW_DATA});
        Log3 $name, 3, "FW_data successfully deleted";
        if (defined $hash->{getCommentReadings}){
          if ($hash->{getCommentReadings} eq "1") {
            $hash->{getCommentReadings} = 2 ;
            Log3 $name, 3, "getCommentReadings set to 2";
          }elsif ($hash->{getCommentReadings} eq "2") {
            Log3 $name, 3, "deleting getCommentReadings";
            delete $hash->{getCommentReadings};
          }
        }
        Log3 $name, 3, "leaving Sketch Name update";
        last;
    };

Dann wäre noch gut zu wissen, wie die Node konfiguriert ist und ob du versucht hast, was an die zu versenden. Bzw. wie du den Absturz provozieren kannst.

Tendenziell würde ich smartSleep aber eher für nodes nutzen, die zwar schlafen, aber Infos erhalten sollen oder OTA-fähig sein (und bei denen man schlecht an den Knopf für einen Reboot kommt). Bei smartSleep wird nämlich der Prozessor samt Transceiver nicht gleich schlafen gelegt, das kostet also ggf. Batterielebensdauer.

(Aber das Problem sollten wir natürlich fixen).
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

alru

Moin,

ich hab mal die Zeile gegen ausgetauscht. Danach ging leider gar nix mehr mit den Mysensor Nodes, aber reichlich Text im Log:
2019.01.26 16:19:25 1: PERL WARNING: Subroutine MYSENSORS_DEVICE_Initialize redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 30.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine Define redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 215.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine UnDefine redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 235.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine Set redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 244.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine Get redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 325.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine onStreamMessage redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 369.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine Attr redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 444.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine onGatewayStarted redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 585.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine onPresentationMessage redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 590.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine onSetMessage redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 671.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine onRequestMessage redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 686.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine onInternalMessage redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 701.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine sendClientMessage redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 922.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine rawToMappedReading redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 954.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine mappedReadingToRaw redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 964.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine short2Hex redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 983.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine hex2Short redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 989.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine flashFirmware redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 994.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine refreshInternalMySTimer redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 1081.
2019.01.26 16:19:25 1: PERL WARNING: Subroutine timeoutMySTimer redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 1107.
2019.01.26 16:20:58 3: Sketch Name updated
2019.01.26 16:20:58 3: FW_data successfully deleted
2019.01.26 16:20:58 3: leaving Sketch Name update
2019.01.26 16:22:35 1: PERL WARNING: Subroutine sendClientMessage redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 917.
2019.01.26 16:22:35 1: PERL WARNING: Subroutine rawToMappedReading redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 949.
2019.01.26 16:22:35 1: PERL WARNING: Subroutine mappedReadingToRaw redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 959.
2019.01.26 16:22:35 1: PERL WARNING: Subroutine short2Hex redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 978.
2019.01.26 16:22:35 1: PERL WARNING: Subroutine hex2Short redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 984.
2019.01.26 16:22:35 1: PERL WARNING: Subroutine flashFirmware redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 989.
2019.01.26 16:22:35 1: PERL WARNING: Subroutine refreshInternalMySTimer redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 1076.
2019.01.26 16:22:35 1: PERL WARNING: Subroutine timeoutMySTimer redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 1102.


Zur Konfiguration des Node, hier das List:
Internals:
   CFGFN     
   DEF        199
   FUUID      5c4c7d1e-f33f-f58a-7cf3-6a7db27a73ed95f1
   IODev      MSG1
   NAME       MYSENSOR_199
   NR         1211
   STATE      alive
   TYPE       MYSENSORS_DEVICE
   ack        0
   radioId    199
   repeater   0
   timeoutAlive 10
   version    2.2.0
   READINGS:
     2019-01-26 16:34:04   heartbeat       last
     2019-01-26 16:34:04   state           alive

Attributes:
   IODev      MSG1
   mode       node
   room       Test
   timeoutAlive 10


Und hier der komplette Sketch:
// Test Sktech um "Heartbeat" zu prüfen

// Enable debug prints to serial monitor
#define MY_DEBUG

// Enable and select radio type attached
#define MY_RADIO_NRF24
// MSG1 (Frequenz 2496 MHz)
#define MY_RF24_CHANNEL 96

// Optional: Define Node ID
#define MY_NODE_ID 199
#define MY_PARENT_NODE_ID 0
#define MY_PARENT_NODE_IS_STATIC

#include <MySensors.h>

void before()
{
}

void setup()
{
}

void presentation()
{
  // Send the sketch version information to the gateway and Controller
  sendSketchInfo("uno_test_heartbeat", "0.2");
}

void loop()
{
sendHeartbeat();
sleep(5000);
// smartSleep(5000);
}


Provoziert hab ich den Absturz einfach mit der Reset Taste auf dem Uno. Gesendet hab ich aus Fhem nichts
Gruß,

Stefan
(Raspi 3B / HM-LGW / HomeMatic / MySensors)

Beta-User

Hmm,
ok, Danke, passiert auch bei mir "zuverlässig", wenn ich die schlafende Node reboote...

Mache grade ein paar Tests mit mehr logausgaben, ich denke, ich kann den Fehler soweit eingrenzen, dass das bald gefixt sein wird.
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

So, Fehler hoffentlich identifiziert und behoben, update ist im svn.

Die log-Ausgaben können wieder raus, nach "$hash->{FW_DATA} if (defined $hash->{FW_DATA});"
sollte folgendes rein:
$hash->{nowSleeping} = 0 if $hash->{nowSleeping};

Wenn es danach noch Probleme gibt, bitte melden.
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

alru

Das ging ja fix....

Ich hab noch ein paar Warnings im Log gefunden:
2019.01.26 18:11:44 1: PERL WARNING: Subroutine sendClientMessage redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 916.
2019.01.26 18:11:44 1: PERL WARNING: Subroutine rawToMappedReading redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 948.
2019.01.26 18:11:44 1: PERL WARNING: Subroutine mappedReadingToRaw redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 958.
2019.01.26 18:11:44 1: PERL WARNING: Subroutine short2Hex redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 977.
2019.01.26 18:11:44 1: PERL WARNING: Subroutine hex2Short redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 983.
2019.01.26 18:11:44 1: PERL WARNING: Subroutine flashFirmware redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 988.
2019.01.26 18:11:44 1: PERL WARNING: Subroutine refreshInternalMySTimer redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 1075.
2019.01.26 18:11:44 1: PERL WARNING: Subroutine timeoutMySTimer redefined at ./FHEM/10_MYSENSORS_DEVICE.pm line 1101.
2019.01.26 18:12:26 3: leaving Sketch Name update


Besonders die letzte Zeile "leaving Sketch Name update" wird nach jedem Reset geschrieben, aber ...
...die smartSleep Funktion ist jetzt gegeben. Mein Kurztest hat keine Abbrüche mehr feststellen können.

Sieht also gut aus. Ich lasse die Tests noch weiter laufen. Aber soweit erst mal Danke!

Noch eine Frage zur Nutzung der beiden Funktionen:
Ich bin mir jetzt echt unsicher welche der Varianten ich nutzen soll. "Wartet" smartSleep denn entscheidend lange, so dass der Batteriebetrieb wirklich merklich belastet wird?
Gruß,

Stefan
(Raspi 3B / HM-LGW / HomeMatic / MySensors)

alru

Moin,

ich hab noch ein paar Tests durchgeführt, aber keine weiteren Fehler gefunden.
Es bleibt nur bei der für mich nicht nachvollziehbaren Meldung im Log, die nach jedem Neustart des Nodes dort zu finden ist. Und zwar für beide alive-Varianten (heartbeat oder smartSleep):
2019.01.27 14:34:15 3: leaving Sketch Name update
Ein evtl. Update des Sketch Names wird natürlich trotzdem ausgeführt.
Gruß,

Stefan
(Raspi 3B / HM-LGW / HomeMatic / MySensors)

Beta-User

Moin,
hast du ein update gemacht oder alle log-Zeilen von der gestrigen Erweiterung wieder rausgeworfen?
Dann sollte das weg sein.

Die übrigen "redefined"-Zeilen kamen übrigens vom reload des Moduls, das ist immer so, wenn man (irgend-) ein Modul manuell neu lädt.

Ergänzend noch zur Frage, was da sinnvoll ist: Es gibt auch noch eine Timer-Erneuerung bei Sendung eines battery-internals. Ansonsten nimmt smartSleep per dafault 500UL, also bei einer 1MHz-Node 500ms (was ein sinnvoller Wert ist).

Will man nicht zwingend was senden (oder kommt an die Node nicht für OTA ran), finde ich die battery-Variante eigentlich am besten (reicht ja ggf. nur alle paar Sendungen). Das mit dem state "asleep" ist zwar nett, aber m.E. reicht es, wenn man weiß, dass die Node regelmäßig sendet.
Muß aber natürlich jeder selber wissen, aus meiner Warte war das vor allem dazu da, um die Funktionsfähigkeit voll auszutesten... Bei "kitzeligen" Funkverbindungen kann das m.E. sogar kontraproduktiv sein (wenn die "gehe-jetzt-Schlafen"-Info unterwegs verloren geht).
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

alru

Moin,
ich hab gestern das Modul aus dem SVN installiert. Danach kamen dann nur noch die Meldung mit "leaving Sketch Name update" im Log, keine weiteren Meldungen.
Also waren die anderen Meldungen tatsächlich vom Reload des Moduls.

Danke für die Erklärung zu den Unterschieden. Ich werde jetzt erst mal die sendHeartbeat() Variante benutzen. Der Sketch der jetzt damit ausgestattet wird darf ohnehin kein sleep benutzen, das hab ich jetzt beim Blick in den Code erst wieder gesehen.
Gruß,

Stefan
(Raspi 3B / HM-LGW / HomeMatic / MySensors)

Beta-User

Thx, da hatte ich beim update noch einen Level übersehen. update ist eingecheckt.
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

alru

Zitat von: Beta-User am 27 Januar 2019, 15:37:36
... update ist eingecheckt.
? Ich sehe im SVN nur die Version von gestern...
Gruß,

Stefan
(Raspi 3B / HM-LGW / HomeMatic / MySensors)

achim771

Hallo,

leider hängt mein FHEM auch fest. Seit Anfang des Monats steht der FHEM-Prozess
mit nahezu 100%. Mit 'service fhem stop' und viel Wartezeit bekomme ich den Server
gestoppt. Im Moment läuft der Server nur, wenn ich die MYSENSORS_DEVICE.pm vom 24.10.2018
downgrade.

Habe heute mal ein nagelneuen FHEM-Server mit Serial-Gateway und den gleichen Nodes aufgesetzt.
Gleiches Ergebniss :(

Die meisten meiner Nodes sind Sleep-Nodes mit smartSleep().
( RPi3+, Signalduino, Homematic, MySensors )

Beta-User

Hallo zusammen,
@achim771: bitte um Rückmeldung, ob das mit version 18432 auch noch passiert (von gestern nachmittag 14:37:06 UTC). Wenn ja: steht was im log? Bzw. kannst du auf dem testsystem mal den verbose-level der Node, die du neu startest auf 5 stellen (dann recht schnell stoppen, bei mir war es mit der alten Version auch unendlich dieselbe Fehlermeldung)...?

@alru: K.A., warum die gestern nicht direkt verfügbar war, hat evtl. ein paar Minuten gedauert, bis das sichtbar war...


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

achim771

#13
@Beta-User: ja, ist die Version 18432. Hab mal ein Testnode(100) zusätzlich eingebunden.
Ausgelöst hat es allerdings ein getriggerter Bewegungsmelder(107)

2019.01.28 18:07:57 5: MYSENSOR_100: refreshInternalMySTimer called (Asleep)
2019.01.28 18:07:57 5: MYSENSOR_100: Awake timeout timer set at 1548695277.86823
2019.01.28 18:07:57 5: MYSENSOR_100: timeoutMySTimer called (timeoutAwake)
2019.01.28 18:08:03 5: MYSENSOR_100: refreshInternalMySTimer called (Asleep)
2019.01.28 18:08:03 5: MYSENSOR_100: Awake timeout timer set at 1548695283.70622
2019.01.28 18:08:03 5: MYSENSOR_100: timeoutMySTimer called (timeoutAwake)
2019.01.28 18:08:09 5: MYSENSOR_100: refreshInternalMySTimer called (Asleep)
2019.01.28 18:08:09 5: MYSENSOR_100: Awake timeout timer set at 1548695289.54492
2019.01.28 18:08:09 5: MYSENSOR_100: timeoutMySTimer called (timeoutAwake)
2019.01.28 18:08:12 5: MYSENSOR_107 is sleeping, enqueueing message!
2019.01.28 18:08:12 5: MYSENSOR_107 is sleeping, enqueueing message!
2019.01.28 18:08:13 4: MYSENSORS_DEVICE MYSENSOR_107: batteryPercent 71
2019.01.28 18:08:14 5: MYSENSOR_107: refreshInternalMySTimer called (Asleep)
2019.01.28 18:08:14 5: MYSENSOR_107: Awake timeout timer set at 1548695294.45189
2019.01.28 18:08:14 5: MYSENSOR_107 is sleeping, enqueueing message!
2019.01.28 18:08:14 5: MYSENSOR_107 is sleeping, enqueueing message!
2019.01.28 18:08:14 5: MYSENSOR_107 is sleeping, enqueueing message!
2019.01.28 18:08:14 5: MYSENSOR_107 is sleeping, enqueueing message!
2019.01.28 18:08:14 5: MYSENSOR_107 is sleeping, enqueueing message!
2019.01.28 18:08:14 5: MYSENSOR_107 is sleeping, enqueueing message!
2019.01.28 18:08:14 5: MYSENSOR_107 is sleeping, enqueueing message!


PS: es hängen noch Gateways am Pi (RPI-HM-MOD, Signalduino, BT LE) die allerdings nicht im FHEM registriert sind!
( RPi3+, Signalduino, Homematic, MySensors )

alru

Moin,

ich hab jetzt auch die Version 18432 kurz getestet.
Bei mir sieht jetzt alles OK aus. Die Meldungen im Log sind auch weg. Der Fhem Prozess zeigt eine unauffällige CPU Last.
Gruß,

Stefan
(Raspi 3B / HM-LGW / HomeMatic / MySensors)

achim771

Ich werde mal testweise einen RPI2 anstelle des RPI3+ testen...
( RPi3+, Signalduino, Homematic, MySensors )

Beta-User

Hmm, ich glaube eigentlich nicht, dass es an der Serverhardware hängt oder an der Zahl der Interfaces.

Im Moment würde ich noch tippen, dass die timer sich irgendwie in die Quere kommen; da hatte ich eh' längerfristig noch einen Umbau im Hinterkopf.

@achim771: Hat die Node 107 irgendwas, was speziell ist?
Könnte es sein, dass die Funkverbindung grenzwertig ist?

@alru: hast du mehrere schlafende Nodes im Einsatz oder nur die eine, mit der du das zuerst festgestellt hast? Wenn nur eine: Kannst du mal testen, ob es bei einer zweiten auch solche Nebenwirkungen hat? (Ich müßte erst wieder Hardware stöpseln, das dauert vermutlich insgesamt zu lange).
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

achim771

@Beta-User: Node 107 ist eine PIR-Sensor mit LDR (Sensebender Micro-Board im Eigenbau), Nach PIR-Trigger sendet das Node ein LDR-Wert, das Motion-Signal, und fragt 2 Werte vom Controller ab.
Räumlich liegt der Controller mittig in der Wohnung. Reichweite scheint daher i.O. zu sein. Mit der 2018er-Version läuft es auch ohne Probleme.
Das MYS-Gateway ist mit INT-Leitung, ein Nano und nRF24L01+PA+LNA-Modul.

Zur Hardware: mein Gedanke lag an der etwas merkwürdigen Serial/BT-Konstruktion des 3+, würde dann aber auch nur das HM-Modul direkt betreffen.

Leider fehlen mir die Perl-Programmierkenntisse.
( RPi3+, Signalduino, Homematic, MySensors )

alru

Moin,

das ursprüngliche Problem habe ich nur mit einem Node (mein Testgerät, ein UNO) getestet
Ich kann das gerne noch an einem anderen testen, wird aber vermutlich bis morgen dauern...

Der Test soll dann mit der 18211 Version laufen, das war ja der ursprüngliche, der bei mir die Probleme bereitet hat, richtig?
(Ich komm hier langsam mit den Versionen durcheinander ....)
Gruß,

Stefan
(Raspi 3B / HM-LGW / HomeMatic / MySensors)

Beta-User

Kein Streß, der Hinweis, dass die Node was wissen will, hat mich hoffentlich auf die richtige Spur gebracht.
Habe eben ein update hochgeladen, das wird mit dem heutigen update dann bereits verteilt.

@achim771: Dass es mit der 2018-er Version aus dem svn klappt, ist eigentlich klar. Da hat FHEM noch gar nichts davon mitbekommen, wenn eine Node in den smartSleep gegangen ist und daher alles, was zu versenden war, auch direkt rausgeschickt. Jetzt muß die Node dahingehend verwaltet werden, dass dieser Zustand überwacht wird. Leider schien die implementierte Methode, das nur über die POST_SLEEP_NOTIFICATION zu machen, (nicht nur im von alru festgestellten Fall, dass die Node neu gestartet wird) fehleranfällig zu sein: Geht die Notification - aus welchem Grund auch immer - verloren, wurde alles in die Warteschlange gesteckt, auch z.B. Zeit-Anfragen usw., die seitens der Node eine direkte Rückmeldung erwarten, weshalb diese die dann immer wieder schickt und damit eine Art Schleife auszulösen scheint.
Jetzt habe ich daher die Sperre für solche direkt zu versendenden Anfragen ausgebaut bzw. mehr eingehende Messages werden ähnlich wie eine POST_SLEEP_NOTIFICATION behandelt.

Rückmeldung ist erbeten, ich bin nicht ganz sicher, dass das update alle Fälle abdeckt.
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

achim771

super :)

kam heute spät von der Arbeit, aber seit ca 8h läuft der Server ohne Probleme mit dem letzten Update durch. Das war wohl das fehlende Puzzlestück.
Eine Sache ist mir allerdings noch aufgefallen:
.Einige Internals haben sich geändert, z.B. 'protocol' in 'version'
.Ein Repeater-Node, der alle 60sek ein heartbeat sendet hat im "state" nach wie vor "received presentation" (diese Node hat nur die Repeater-Funktion)
lässt sich daran etwas machen? alle anderen zeigen den awake, asleep, dead-state an

Super, Klasse Arbeit :)



( RPi3+, Signalduino, Homematic, MySensors )

Beta-User

 :) Danke für die Rückmeldung, hier läuft auch alles soweit durch.

Was den Repeater angeht, nehme ich an, dass der immer läuft, oder? Anders als bei smartSleep-Nodes muß man da ein extra Attribut setzen. Ist  das gesetzt?
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

achim771

Ja, der Repeater läuft natürlich hellwach durch. Das Heartbeat-Flag in den Internals wird auch gesetzt.
Welches Attribut sollte gesetzt werden? Ist das Timeout-Attribut gemeint? Da muss ich heute abend nachschauen.
( RPi3+, Signalduino, Homematic, MySensors )

alru

Moin,

ich habe auch einen Node, der als Aktor und Repeater arbeitet. Dort ist keine heartbeat oder smartSleep implementiert. In den Readings (@achim771: bei dir in den Internals ??) tauchte dann (verm. nach dem dem Fhem/Mysensor Update) irgendwann das heartbeat auf. Ein get heartbeat funktioniert auch.

Wie kann man diesen Nodes beibringen, regelmäßig ein heartbeat zu senden?
Mir fallen 2 Möglichkeiten ein:

  • In die Loop vom Node einen Zähler einbauen, der nach x Loops einen heartbeat sendet
  • Über ein at in Fhem den heartbeat abfragen.
Das von dir erwähnte Attribut kenne ich auch nicht, hört sich aber nach der von mir gesuchten eleganteren Lösung an.
Gruß,

Stefan
(Raspi 3B / HM-LGW / HomeMatic / MySensors)

Beta-User

Zitat von: achim771 am 30 Januar 2019, 09:23:46
Welches Attribut sollte gesetzt werden? Ist das Timeout-Attribut gemeint? Da muss ich heute abend nachschauen.
Ja, timeoutAlive ist zu setzen; wenn es Verbesserungsvorschläge für die cref gibt: her damit...

Zitat von: achim771 am 29 Januar 2019, 22:44:19
Einige Internals haben sich geändert, z.B. 'protocol' in 'version'
Hmm, da muß ich zugeben, dass ich die Mechanismen in der alten Version irgendwie auch nicht so recht verstanden habe, also was das im einzelnen sollte... Es hat mich ziemlich genervt, dass ich jedesmal nach dem FHEM-Start ein "rotes Fragezeichen" hatte, sobald ich mehrere GW's mit unterschiedlichen MySensors-lib-Ständen hatte. Ursache war, dass das Modul das Attribut "Version" (doppelt) geändert hatte. Da nach der allg. Definition Attribute eigentlich dem User gehören, habe ich das erst mal deaktiviert, bis dato war das keinem aufgefallen ;) , es scheint also eigentlich keinen wirklichen Nutzen zu haben (jedenfalls als Attribut).
Wenn jemand dazu sachdienliche Vorschläge hat, was da wie erforderlich ist, können wir das gerne aufgreifen, im Moment hat das aber m.E. keine hohe Prio.

@alru
Würde statt des Zählers millis nehmen (siehe z.B. das Beispiel hier), aber im Prinzip gibt es diese beiden Varianten (Node machen lassen oder FHEM regelmäßig anfragen lassen, z.B. mit einem at).
Und wie gesagt: auch eine battery-Message resettet den internen Timer für alive/dead.

Das ist aber eigentlich eine Frage, die ggf. hier besser aufgehoben wäre.

Kannst du bei Gelegenheit dann das Thema als "gelöst" kennzeichnen, wenn die kommenden Tage keine Probleme mehr auftauchen?
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

alru

Zitat von: Beta-User am 30 Januar 2019, 09:59:04
Würde statt des Zählers millis nehmen ...

Die Nodes sollen bei mir die Aufgabe bekommen sich rechtzeitig zu melden (Push an Fhem). Dann spare ich mir die at Befehle in Fhem.
Den millis() habe ich noch nicht eingesetzt. Sieht dafür aber sehr gut aus. Danke für den Tipp.

Zitat von: Beta-User am 30 Januar 2019, 09:59:04
Kannst du bei Gelegenheit dann das Thema als "gelöst" kennzeichnen, wenn die kommenden Tage keine Probleme mehr auftauchen?

Ja, mach ich zeitnah.
Gruß,

Stefan
(Raspi 3B / HM-LGW / HomeMatic / MySensors)

achim771

Das mit dem Attribut wars, dann klappt ja doch alles ;)
Ich komm schon durcheinander bei dem ganzen Testen :)
( RPi3+, Signalduino, Homematic, MySensors )

Pseudex

hi.
das Thema ist schon älter aber ich habe  letztens auch Probleme gehabt mit einem Sensor der smartsleep verwendet. Hier schien FHEM in eine Endlosschleife zu geraten und nur mit SIG-KILL konnte ich den FHEM Prozess beenden. Wann genau das passiert ist kann ich nicht sagen. Ich meine, wenn ich zwei oder mehrere male das Senden aus FHEM angestoßen habe.

Mein Server ist ein Asus-PN51 mit 5700U CPU und 64GB RAM. Ressourcen sollten hier nicht das Problem sein.

Ich habe mir den Code 10_MYSENSORS_DEVICE.pm angeschaut und bin mir an zwei Stellen nicht sicher, ob das so gewollt ist.

sub sendRetainedMessages {
    my $hash = shift // return;
    my $retainedMsg;
    while (ref ($retainedMsg = shift @{$hash->{retainedMessagesForRadioId}->{messages}}) eq 'HASH') {
       sendClientMessage($hash,%$retainedMsg);
    }
    return;
}


Hier hatte ich die Befürchtung, dass die WHILE Schleife nicht beendet wird. Aber der Vergleich auf "HASH" sollte wahrscheinlich sicher sein. Hier wäre wahrscheinlich noch ein limiter (max 10 Durchläufe oder so ähnlich) als Absicherung vorteilhaft.


sub sendClientMessage {
    my ($hash,%msg) = @_;
    $msg{radioId} = $hash->{radioId};
    my $name = $hash->{NAME};
    $msg{ack} = $hash->{ack} if !defined $msg{ack};
    my $messages = $hash->{retainedMessagesForRadioId}->{messages};
    if (!$hash->{nowSleeping}) {
      sendMessage($hash->{IODev},%msg);
      refreshInternalMySTimer($hash,"Ack") if (($msg{ack} or $hash->{IODev}->{ack}) and $hash->{timeoutAck});
      Log3 ($name,5,"$name is not sleeping, sending message!");
      if ($hash->{nowSleeping}) {
        $hash->{nowSleeping} = 0 ;
        sendRetainedMessages($hash);
      }
      $hash->{retainedMessages}=scalar(@$messages) if (defined $hash->{retainedMessages});
    } else {
      Log3 ($name,5,"$name is sleeping, enqueing message! ");
      #write to queue if node is asleep
      if (!defined $hash->{retainedMessages}) {
        $messages = {messages => [%msg]};
        $hash->{retainedMessages}=1;
        Log3 ($name,5,"$name: No array yet for enqueued messages, building it!");
      } else {
         @$messages = grep {
           $_->{childId} != $msg{childId}
           or $_->{cmd}     != $msg{cmd}
           or $_->{subType} != $msg{subType}
         } @$messages;
         push @$messages,\%msg;
         eval { $hash->{retainedMessages} = scalar(@$messages) }; #might be critical!
      }
    }
    return;
}



sendClientMessage wird von der sub-routine sendRetainedMessages aufgerufen.
In dieser sub-routine kann aber wieder sendClientMessage aufgerufen werden, was zu einer Rekursion führen kann.


define MYSENSOR_124 MYSENSORS_DEVICE 124
attr MYSENSOR_124 DbLogInclude pv_.*:300:force,batt_.*:300:force,device_.*:300:force,load_.*:300:force
attr MYSENSOR_124 IODev MySensorGw
attr MYSENSOR_124 alias EPEVER Solar
attr MYSENSOR_124 icon sani_solar
attr MYSENSOR_124 mapReading_batt_current 2 current
attr MYSENSOR_124 mapReading_batt_level 2 percentage
attr MYSENSOR_124 mapReading_batt_power 2 power
attr MYSENSOR_124 mapReading_batt_temperature 2 temperature
attr MYSENSOR_124 mapReading_batt_voltage 2 voltage
attr MYSENSOR_124 mapReading_device_load 4 status
attr MYSENSOR_124 mapReading_device_temperature 4 temperature
attr MYSENSOR_124 mapReading_load_current 3 current
attr MYSENSOR_124 mapReading_load_energy 3 energy
attr MYSENSOR_124 mapReading_load_power 3 power
attr MYSENSOR_124 mapReading_load_voltage 3 voltage
attr MYSENSOR_124 mapReading_pv_current 1 current
attr MYSENSOR_124 mapReading_pv_energy 1 energy
attr MYSENSOR_124 mapReading_pv_power 1 power
attr MYSENSOR_124 mapReading_pv_voltage 1 voltage
attr MYSENSOR_124 mode node
attr MYSENSOR_124 room MySensors
attr MYSENSOR_124 setCommands on:device_load:on off:device_load:off
attr MYSENSOR_124 setReading_device_load on,off
attr MYSENSOR_124 stateFormat batt_level
#   DEF        124
#   FUUID      639efa62-f33f-a1b0-14d8-8f1931e14d9fd8c5
#   FVERSION   10_MYSENSORS_DEVICE.pm:0.266690/2022-11-06
#   IODev      MySensorGw
#   NAME       MYSENSOR_124
#   NR         315
#   STATE      67
#   TYPE       MYSENSORS_DEVICE
#   ack        0
#   eventCount 163
#   nowSleeping 1
#   outstandingAck 0
#   preSleep   2500
#   radioId    124
#   repeater   0
#   Helper:
#     DBLOG:
#       batt_current:
#         myDbLog:
#           TIME       1673261427.54225
#           VALUE      0.11
#       batt_level:
#         myDbLog:
#           TIME       1673260862.83766
#           VALUE      67
#       batt_voltage:
#         myDbLog:
#           TIME       1673261119.11482
#           VALUE      25.81
#       pv_current:
#         myDbLog:
#           TIME       1673258928.01454
#           VALUE      0.12
#       pv_power:
#         myDbLog:
#           TIME       1673261225.70554
#           VALUE      4.64
#       pv_voltage:
#         myDbLog:
#           TIME       1673259675.6915
#           VALUE      55.33
#   READINGS:
#     2023-01-09 10:57:14   IODev           MySensorGw
#     2023-01-07 23:29:33   SKETCH_NAME     Solar Charger EPEVER
#     2023-01-07 23:29:33   SKETCH_VERSION  1.1
#     2023-01-09 11:50:27   batt_current    0.11
#     2023-01-09 11:41:02   batt_level      67
#     2023-01-07 23:29:38   batt_temperature 25.00
#     2023-01-09 11:49:27   batt_voltage    25.81
#     2023-01-09 10:47:03   device_load     off
#     2023-01-09 10:45:46   device_temperature 25.52
#     2023-01-08 12:40:38   load_current    0.04
#     2023-01-08 12:31:22   load_energy     1.25
#     2023-01-09 10:45:46   load_power      0.00
#     2023-01-09 10:45:46   load_voltage    0.00
#     2023-01-07 23:29:33   parentId        0
#     2023-01-09 11:08:48   pv_current      0.12
#     2023-01-09 10:23:51   pv_energy       1.66
#     2023-01-09 11:51:13   pv_power        3.09
#     2023-01-09 11:23:18   pv_voltage      27.78
#     2023-01-09 11:51:34   sleepState      asleep
#     2023-01-09 10:47:03   state           off
#   gets:
#   messagesForRadioId:
#   readingMappings:
#     1:
#       17:
#         name       pv_power
#       18:
#         name       pv_energy
#       38:
#         name       pv_voltage
#       39:
#         name       pv_current
#     2:
#       0:
#         name       batt_temperature
#       17:
#         name       batt_power
#       3:
#         name       batt_level
#       38:
#         name       batt_voltage
#       39:
#         name       batt_current
#     3:
#       17:
#         name       load_power
#       18:
#         name       load_energy
#       38:
#         name       load_voltage
#       39:
#         name       load_current
#     4:
#       0:
#         name       device_temperature
#       2:
#         name       device_load
#   retainedMessagesForRadioId:
#     messages:
#   setcommands:
#     off:
#       val        off
#       var        device_load
#     on:
#       val        on
#       var        device_load
#   sets:
#     clear      noArg
#     device_load on,off
#     flash      noArg
#     fwType     
#     off       
#     on         
#     reboot     noArg
#     time       noArg
#
setstate MYSENSOR_124 67
setstate MYSENSOR_124 2023-01-09 10:57:14 IODev MySensorGw
setstate MYSENSOR_124 2023-01-07 23:29:33 SKETCH_NAME Solar Charger EPEVER
setstate MYSENSOR_124 2023-01-07 23:29:33 SKETCH_VERSION 1.1
setstate MYSENSOR_124 2023-01-09 11:50:27 batt_current 0.11
setstate MYSENSOR_124 2023-01-09 11:41:02 batt_level 67
setstate MYSENSOR_124 2023-01-07 23:29:38 batt_temperature 25.00
setstate MYSENSOR_124 2023-01-09 11:49:27 batt_voltage 25.81
setstate MYSENSOR_124 2023-01-09 10:47:03 device_load off
setstate MYSENSOR_124 2023-01-09 10:45:46 device_temperature 25.52
setstate MYSENSOR_124 2023-01-08 12:40:38 load_current 0.04
setstate MYSENSOR_124 2023-01-08 12:31:22 load_energy 1.25
setstate MYSENSOR_124 2023-01-09 10:45:46 load_power 0.00
setstate MYSENSOR_124 2023-01-09 10:45:46 load_voltage 0.00
setstate MYSENSOR_124 2023-01-07 23:29:33 parentId 0
setstate MYSENSOR_124 2023-01-09 11:08:48 pv_current 0.12
setstate MYSENSOR_124 2023-01-09 10:23:51 pv_energy 1.66
setstate MYSENSOR_124 2023-01-09 11:51:13 pv_power 3.09
setstate MYSENSOR_124 2023-01-09 11:23:18 pv_voltage 27.78
setstate MYSENSOR_124 2023-01-09 11:51:34 sleepState asleep
setstate MYSENSOR_124 2023-01-09 10:47:03 state off


das ist die definition vom device


hier ist der Quellcode von meinem Sensor: https://gitea.kaiserflur.de/pseudex/epeversolar/src/commit/71ff4a132b6a4f7563a9158fc5d3c7e9ebb9c2ee/src/main.cpp


Beta-User

Hmmm,

ich rätsle jetzt schon eine Weile rum, wann und wieso es zu dem von dir beobachteten Verhalten kommt, und warum das anscheinend nur bei dir so ist - dieser Code ist ja ca. 3 Jahre alt.

Du hast dahingehend recht, dass der wechselseitige Aufruf tendenziell "loop-Gefahr" bedeutet. ABER: Irgendwie werde ich schon aus dem Code nicht schlau, der von dir zitierte Aufruf von sendRetainedMessages() befindet sich an einer Code-Stelle, die m.E. nie angefahren werden kann, weil sendMessage() an dem Internal "nowSleeping" nichts ändert und von daher diese Bedingung nie wahr sein sollte?!? Das eigentliche Problem müßte demnach woanders zu suchen sein.

Vorschlag: Deaktiviere erst mal diese komische if-Konstruktion
      #if ($hash->{nowSleeping}) {
      #  $hash->{nowSleeping} = 0 ;
      #  sendRetainedMessages($hash);
      #}


Danach sollte der Fehler weiter vorhanden sein (vielleicht machst du ein "save", bevor du FHEM in abschussfähigen Zustand versertzt?)...

Einen Limiter einzubauen widerstrebt mir, weil es an sich sinnvoll ist, die Liste schnellstmöglich abzuarbeiten. Eventuell wäre ein timer-basierter Selbstaufruf sinnvoll, um zum einen das GW nicht zu überfrachten und zum anderen FHEM zu erlauben, zwischendurch was anderes zu machen?

Zum anderen sollte das mit "nowSleeping" eigentlich als "Kennung" ausreichen, um solche Rekursions-Probleme zu vermeiden.
Ansonsten wäre ggf. noch interessant, wie sich die Array-Größe innerhalb der "while"-Schleife entwickelt. Wenn deine These stimmt, dass da was rekursiv passiert, dürfte die nicht abnehmen. Könnte man loggen.
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

tmandel

Moin,

bei mir kommt das Problem auch immer Mal wieder vor.
Ich habe mal ein paar zusätzliche Log Ausgaben eingebaut und konnte zumindest sehen, dass eine Endlosschleife in sendRetainedMessages den ganzen FHEM Prozess zum stehen bringt.

Trotzdem konnte ich das Problem noch nicht mit 100% Sicherheit reproduzieren.

@Pseudex: Besteht das Problem bei dir noch?

Was mir sonst noch so aufgefallen ist.  Du verwendet im Sketch
#define MY_SMART_SLEEP_WAIT_DURATION_MS 2500Ich habe auch etwas längere Zeiten bei mir dafür vorgesehen. Im FHEM werden die Timer anscheinend mit einer nicht ganz syncronen Formel gesetzt
my $postsleeptime=($hash->{preSleep} - 200)/1000;

Da im Code zwischendurch
$hash->{nowSleeping} abgefragt wird, aber mittels Timer zur Laufzeit überschrieben wird, könnte hier die Ursache sein, dass das Problem so schlecht reproduzierbar ist.


tmandel

Jetzt gibts etwas logging zum Problem.

05:45:00 -> LichterAnLichterketten
Der Node wurde als nicht schlafend (sleep: 0) erkannt, obwohl der Node definitiv noch im Schlafmodus war.
Der Befehl ('cmd' => 1) wurde also ins Nirvana gesendet.
Vermutlich ist das aber erstmal nicht relevant.

06:00:59 -> LichterAusLichterketten
Der Node wurde korrekt als schlafend (sleep: 1) erkannt (is sleeping, enqueing message)

06:01:07 -> I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 1
I_PRE_SLEEP_NOTIFICATION wurde korrekt erkannt, aber der Status, dass der Node noch schläft war trotzdem gesetzt (nowSleeping: 1)

Schlussfolgerung

$type == I_PRE_SLEEP_NOTIFICATION)hat sendRetainedMessages aufgerufen und der Status von nowSleeping war 1.
Diese Konstellation führt zu einer Endlosschleife

Als nächstes werde ich im Bereich I_PRE_SLEEP_NOTIFICATION $hash->{nowSleeping} = 0 setzen
Im Logging sieht man auch, dass der Status von nowSleeping: immer mal 0 oder 1 ist, obwohl der Node wegen I_PRE_SLEEP_NOTIFICATION eigentlich wach sein sollte.

Mich wundert, warum  $hash->{timeoutAlive} im logging leer ist.

Anbei das Log und die relevanten Code-Bestandteile von 10_MYSENSORS_DEVICE.pm damit der Logtext besser zugeordnet werden kann.



2023.07.27 05:24:50 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:24:50 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:26:32 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:26:32 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:26:32 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:28:14 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:28:14 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:28:48 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:29:22 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:29:22 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:30:30 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:30:30 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:31:04 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 1
2023.07.27 05:31:04 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:33:20 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:36:10 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:36:10 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:37:52 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:37:52 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:39:34 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 1
2023.07.27 05:39:34 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:40:08 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:42:24 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:42:24 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:42:58 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 1
2023.07.27 05:42:58 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:44:06 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:44:06 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:45:00 1: LichterAnLichterketten
2023.07.27 05:45:00 1: MYSENSOR_110 sendClientMessage sleep: 0 Msg: $messages = [];
 retainedMessages: 0 retainedMessagesForRadioId: $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:45:00 1: MYSENSOR_110 sendClientMessage retainedMessages aus Scalar: 0
2023.07.27 05:45:15 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:45:15 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:45:48 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:45:49 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:46:23 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 1
2023.07.27 05:46:23 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:46:56 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:46:57 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:46:57 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:47:31 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:47:31 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:48:05 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 1
2023.07.27 05:48:05 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:50:55 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:50:55 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:51:29 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:51:29 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:53:11 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:53:11 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:53:45 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:53:45 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:55:27 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 1
2023.07.27 05:55:27 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:57:09 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:57:09 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:58:17 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:58:17 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 05:59:25 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 05:59:25 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 06:00:33 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 0
2023.07.27 06:00:33 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 06:00:59 1: LichterAusLichterketten
2023.07.27 06:00:59 1: MYSENSOR_110 sendClientMessage sleep: 1 Msg: $messages = [];
 retainedMessages: 0 retainedMessagesForRadioId: $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 06:00:59 1: MYSENSOR_110 is sleeping, enqueing message!
2023.07.27 06:01:07 1: MYSENSOR_110: I_PRE_SLEEP_NOTIFICATION preSleep: 1000 timeoutAlive:  nowSleeping: 1
2023.07.27 06:01:07 1: MYSENSOR_110: sendRetainedMessages called $hash->{retainedMessagesForRadioId}->{messages} = [
                                                    {
                                                      'childId' => '51',
                                                      'payload' => '0',
                                                      'ack' => 1,
                                                      'subType' => '2',
                                                      'cmd' => 1,
                                                      'radioId' => 110
                                                    }
                                                  ];

2023.07.27 06:01:07 1: MYSENSOR_110: sendRetainedMessages: call sendClientMessage retainedMsg: $retainedMsg = {
                 'childId' => '51',
                 'payload' => '0',
                 'ack' => 1,
                 'subType' => '2',
                 'cmd' => 1,
                 'radioId' => 110
               };

2023.07.27 06:01:07 1: MYSENSOR_110 sendClientMessage sleep: 1 Msg: $messages = [];
 retainedMessages: 1 retainedMessagesForRadioId: $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 06:01:07 1: MYSENSOR_110 is sleeping, enqueing message!
2023.07.27 06:01:07 1: MYSENSOR_110: sendRetainedMessages: call sendClientMessage retainedMsg: $retainedMsg = {
                 'childId' => '51',
                 'payload' => '0',
                 'ack' => 1,
                 'subType' => '2',
                 'cmd' => 1,
                 'radioId' => 110
               };

2023.07.27 06:01:07 1: MYSENSOR_110 sendClientMessage sleep: 1 Msg: $messages = [];
 retainedMessages: 1 retainedMessagesForRadioId: $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 06:01:07 1: MYSENSOR_110 is sleeping, enqueing message!
2023.07.27 06:01:07 1: MYSENSOR_110: sendRetainedMessages: call sendClientMessage retainedMsg: $retainedMsg = {
                 'childId' => '51',
                 'ack' => 1,
                 'payload' => '0',
                 'subType' => '2',
                 'radioId' => 110,
                 'cmd' => 1
               };

2023.07.27 06:01:07 1: MYSENSOR_110 sendClientMessage sleep: 1 Msg: $messages = [];
 retainedMessages: 1 retainedMessagesForRadioId: $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 06:01:07 1: MYSENSOR_110 is sleeping, enqueing message!
2023.07.27 06:01:07 1: MYSENSOR_110: sendRetainedMessages: call sendClientMessage retainedMsg: $retainedMsg = {
                 'childId' => '51',
                 'ack' => 1,
                 'payload' => '0',
                 'subType' => '2',
                 'cmd' => 1,
                 'radioId' => 110
               };

2023.07.27 06:01:07 1: MYSENSOR_110 sendClientMessage sleep: 1 Msg: $messages = [];
 retainedMessages: 1 retainedMessagesForRadioId: $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 06:01:07 1: MYSENSOR_110 is sleeping, enqueing message!
2023.07.27 06:01:07 1: MYSENSOR_110: sendRetainedMessages: call sendClientMessage retainedMsg: $retainedMsg = {
                 'childId' => '51',
                 'payload' => '0',
                 'ack' => 1,
                 'radioId' => 110,
                 'cmd' => 1,
                 'subType' => '2'
               };

2023.07.27 06:01:07 1: MYSENSOR_110 sendClientMessage sleep: 1 Msg: $messages = [];
 retainedMessages: 1 retainedMessagesForRadioId: $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 06:01:07 1: MYSENSOR_110 is sleeping, enqueing message!
2023.07.27 06:01:07 1: MYSENSOR_110: sendRetainedMessages: call sendClientMessage retainedMsg: $retainedMsg = {
                 'payload' => '0',
                 'ack' => 1,
                 'childId' => '51',
                 'subType' => '2',
                 'cmd' => 1,
                 'radioId' => 110
               };

2023.07.27 06:01:07 1: MYSENSOR_110 sendClientMessage sleep: 1 Msg: $messages = [];
 retainedMessages: 1 retainedMessagesForRadioId: $hash->{retainedMessagesForRadioId}->{messages} = [];

2023.07.27 06:01:07 1: MYSENSOR_110 is sleeping, enqueing message!
2023.07.27 06:01:07 1: MYSENSOR_110: sendRetainedMessages: call sendClientMessage retainedMsg: $retainedMsg = {
                 'payload' => '0',
                 'ack' => 1,
                 'childId' => '51',
                 'radioId' => 110,
                 'cmd' => 1,
                 'subType' => '2'
               };


sub sendClientMessage {
    my ($hash,%msg) = @_;
    $msg{radioId} = $hash->{radioId};
    my $name = $hash->{NAME};
    $msg{ack} = $hash->{ack} if !defined $msg{ack};
    my $messages = $hash->{retainedMessagesForRadioId}->{messages};


# Log3 ($name,1,"$name".Dumper($hash));
    Log3 ($name,1,"$name sendClientMessage sleep: $hash->{nowSleeping} Msg: ".Dumper($messages)." retainedMessages: $hash->{retainedMessages} retainedMessagesForRadioId: ".Dumper($hash->{retainedMessagesForRadioId}->{messages}));

    if (!$hash->{nowSleeping}) {
sendMessage($hash->{IODev},%msg);
refreshInternalMySTimer($hash,"Ack") if (($msg{ack} or $hash->{IODev}->{ack}) and $hash->{timeoutAck});
Log3 ($name,5,"$name is not sleeping, sending message!");
     
     
### wird nicht erreicht
if ($hash->{nowSleeping}) {
Log3 ($name,1,"$name sendClientMessage:nowSleeping MsgAck: $msg{ack} Msg: $messages");
$hash->{nowSleeping} = 0 ;
sendRetainedMessages($hash);
}

if (defined $hash->{retainedMessages})
{
$hash->{retainedMessages}=scalar(@$messages);
Log3 ($name,1,"$name sendClientMessage retainedMessages aus Scalar: $hash->{retainedMessages}");
}
     
 
 
 
 
    }
else
{
Log3 ($name,1,"$name is sleeping, enqueing message! ");
#write to queue if node is asleep
if (!defined $hash->{retainedMessages})
{
$messages = {messages => [%msg]};

$hash->{retainedMessages}=1;
Log3 ($name,1,"$name: No array yet for enqueued messages, building it! messages: $messages");
}
else
{
@$messages = grep {
$_->{childId} != $msg{childId}
or $_->{cmd}     != $msg{cmd}
or $_->{subType} != $msg{subType}
} @$messages;
push @$messages,\%msg;

eval { $hash->{retainedMessages} = scalar(@$messages) }; #might be critical!
}
    }
    return;
}



sub sendRetainedMessages {
    my $hash = shift // return;
    if (defined($hash->{retainedMessagesForRadioId}->{messages}))
    {
      Log3($hash->{NAME}, 1, "$hash->{NAME}: sendRetainedMessages called ".Dumper($hash->{retainedMessagesForRadioId}->{messages}));
    }
    else
    {
      Log3($hash->{NAME}, 1, "$hash->{NAME}: sendRetainedMessages called messages: empty"); # kommt nur direkt nach fhem neustart, weil der Zweig im Hash noch nicht existiert
    }
    my $retainedMsg;
    while (ref ($retainedMsg = shift @{$hash->{retainedMessagesForRadioId}->{messages}}) eq 'HASH') {
    Log3 $hash->{NAME}, 1, "$hash->{NAME}: sendRetainedMessages: call sendClientMessage retainedMsg: ".Dumper($retainedMsg);
    $hash->{nowSleeping} = 0;
sendClientMessage($hash,%$retainedMsg);
    }
    return;
}

Beta-User

Gutes finding, das Setzen des korrekten sleep-Status macht in diesem Code-Bereich auf alle Fälle Sinn!

Fix ist im svn, hoffen wir mal, dass das "alles" war.
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