[gelöst] smartSleep friert Fhem ein

[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

Code Auswählen Erweitern

$type == I_PRE_SLEEP_NOTIFICATION)hat

Code Auswählen Erweitern

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

Code Auswählen Erweitern

$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.

Code Auswählen Erweitern

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'
               };


Code Auswählen Erweitern

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;
}


Code Auswählen Erweitern

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.