PRESENCE: lan-ping stellt irgendwann den Dienst ein

[kaihs]

Ich lasse mittels PRESENCE per lan-ping ein Gerät überwachen.
Das geht auch einige Zeit gut:

Code Auswählen Erweitern


2014.12.09 21:04:26 4: PRESENCE (pres_mci500h) - rescheduling next check in 30 seconds
2014.12.09 21:04:56 5: PRESENCE (pres_mci500h) - stopping timer
2014.12.09 21:04:56 5: PRESENCE (pres_mci500h) - starting blocking call for mode lan-ping
2014.12.09 21:04:56 5: PRESENCE (pres_mci500h) - starting ping scan: pres_mci500h|192.168.2.205|0|4
2014.12.09 21:04:59 5: PRESENCE (pres_mci500h) - ping command returned with output:
PING 192.168.2.205 (192.168.2.205) 56(84) bytes of data.
64 bytes from 192.168.2.205: icmp_req=1 ttl=64 time=0.937 ms
64 bytes from 192.168.2.205: icmp_req=2 ttl=64 time=0.890 ms
64 bytes from 192.168.2.205: icmp_req=3 ttl=64 time=0.987 ms
64 bytes from 192.168.2.205: icmp_req=4 ttl=64 time=0.992 ms

--- 192.168.2.205 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3004ms
rtt min/avg/max/mdev = 0.890/0.951/0.992/0.051 ms
2014.12.09 21:04:59 5: PRESENCE (pres_mci500h) - blocking scan result: pres_mci500h|0|present
2014.12.09 21:04:59 4: PRESENCE (pres_mci500h) - rescheduling next check in 30 seconds


und dann irgendwann:

Code Auswählen Erweitern


2014.12.09 21:05:43 5: PRESENCE (pres_mci500h) - starting local scan
2014.12.09 21:05:43 5: PRESENCE (pres_mci500h) - starting blocking call for mode lan-ping
2014.12.09 21:05:43 5: PRESENCE (pres_mci500h) - starting ping scan: pres_mci500h|192.168.2.205|1|4
2014.12.09 21:05:56 5: PRESENCE (pres_mci500h) - ping command returned with output:
PING 192.168.2.205 (192.168.2.205) 56(84) bytes of data.

--- 192.168.2.205 ping statistics ---
4 packets transmitted, 0 received, 100% packet loss, time 3005ms

2014.12.09 21:05:56 5: PRESENCE (pres_mci500h) - blocking scan result: pres_mci500h|1|absent


Hier fehlt dann die Ausgabe von "rescheduling next check in 30 seconds", und es erfolgen keine weiteren Checks mehr.

Nach einem expliziten

Code Auswählen Erweitern


set pres_mci500h statusRequest


wird der Check einmal durchgeführt, aber nicht mehr zyklisch.

Hat jemand eine Idee woran das liegen kann?

[kaihs]

Ich habe die Ursache nach Analyse des Codes des Moduls wahrscheinlich gerade selbst gefunden.

Ich starte auf Grund von gewissen Bedingungen selbst einen 'local scan' per set statusRequest um schneller als durch die definierten Timeouts ein Ergebnis zu bekommen.
Durch das set statusReuquest wird anscheinend die zyklische Bearbeitung komplett beendet.

Ist dieses Verhalten so beabsichtigt?

[Markus Bloch]

Deine Annahme ist so nicht ganz richtig.

In deinem ersten Logauszug aus einem regulären PRESENCE Durchlauf findest du folgende Zeilen:

Code Auswählen Erweitern

2014.12.09 21:04:56 5: PRESENCE (pres_mci500h) - stopping timer
Hier wird der Timer zu Beginn gestoppt (das ist so gewollt).

und

Code Auswählen Erweitern

2014.12.09 21:04:59 4: PRESENCE (pres_mci500h) - rescheduling next check in 30 seconds
Hier wird ein neuer Timer gestartet, der den nächsten Check in 30 Sekunden startet.

In deinem zweiten Logauszug findest du diese Zeilen nicht, da es sich dort um einen "local"-Scan handelt, der ja ausserhalb des Timers zusätzlich durchgeführt wird. Dort wird der Timer nicht unterbrochen und auch nicht neu gestartet.

Gib mal bitte einen größeren Logauszug, wo noch automatische Checks laufen und nach einem local scan dannach nicht mehr.

Vielen Dank

Gruß

Markus

[kaihs]

Da habe ich mich wahrscheinlich nicht deutlich genug ausgedrückt.
Nach dem local scan kommen keine PRESENCE Einträge mehr im log.

Code Auswählen Erweitern


2014.12.09 21:04:59 5: PRESENCE (pres_mci500h) - blocking scan result: pres_mci500h|0|present
2014.12.09 21:04:59 4: PRESENCE (pres_mci500h) - rescheduling next check in 30 seconds
2014.12.09 21:05:28 5: Messsage an IO senden Message raw: isF0F0FFF0FFF0420
2014.12.09 21:05:29 5: FHEMduino_PT2262 IODev device didn't answer is command correctly:   raw => isFF0FFF0FFF42
2014.12.09 21:05:29 5: PRESENCE (pres_mci500h) - starting local scan
2014.12.09 21:05:29 5: PRESENCE (pres_mci500h) - starting blocking call for mode lan-ping
2014.12.09 21:05:29 5: PRESENCE (pres_mci500h) - starting ping scan: pres_mci500h|192.168.2.205|1|4
2014.12.09 21:05:30 5: PRESENCE (pres_mci500h) - stopping timer
2014.12.09 21:05:30 5: PRESENCE (pres_mci500h) - starting blocking call for mode lan-ping
2014.12.09 21:05:42 5: PRESENCE (pres_mci500h) - ping command returned with output:
PING 192.168.2.205 (192.168.2.205) 56(84) bytes of data.

--- 192.168.2.205 ping statistics ---
4 packets transmitted, 0 received, 100% packet loss, time 3008ms

2014.12.09 21:05:42 5: PRESENCE (pres_mci500h) - blocking scan result: pres_mci500h|1|absent
2014.12.09 21:05:42 5: Messsage an IO senden Message raw: isF0F0FFF0FFF0420
2014.12.09 21:05:43 5: Answer from fd:   raw => isF0F0FFF0FFF0420
2014.12.09 21:05:43 5: PRESENCE (pres_mci500h) - starting local scan
2014.12.09 21:05:43 5: PRESENCE (pres_mci500h) - starting blocking call for mode lan-ping
2014.12.09 21:05:43 5: Messsage an IO senden Message raw: isF0F0FFF0FF0F420
2014.12.09 21:05:43 5: PRESENCE (pres_mci500h) - starting ping scan: pres_mci500h|192.168.2.205|1|4
2014.12.09 21:05:43 5: FHEMduino_PT2262 IODev device didn't answer is command correctly:   raw => isF0FFFFFFF42
2014.12.09 21:05:56 5: PRESENCE (pres_mci500h) - ping command returned with output:
PING 192.168.2.205 (192.168.2.205) 56(84) bytes of data.

--- 192.168.2.205 ping statistics ---
4 packets transmitted, 0 received, 100% packet loss, time 3005ms

2014.12.09 21:05:56 5: PRESENCE (pres_mci500h) - blocking scan result: pres_mci500h|1|absent
2014.12.09 21:41:34 3: Define: Steckdose_mci500h_real FHEMduino_PT2262 F0F0FFF0FF 420 0F F0
2014.12.09 21:41:34 5: Define hascode: {F0F0FFF0FF}{Steckdose_mci500h_real}
2014.12.09 22:07:27 5: PRESENCE (pres_mci500h) - starting local scan
2014.12.09 22:07:27 5: PRESENCE (pres_mci500h) - starting blocking call for mode lan-ping
2014.12.09 22:07:27 5: PRESENCE (pres_mci500h) - starting ping scan: pres_mci500h|192.168.2.205|1|4
2014.12.09 22:07:30 5: PRESENCE (pres_mci500h) - ping command returned with output:
PING 192.168.2.205 (192.168.2.205) 56(84) bytes of data.
64 bytes from 192.168.2.205: icmp_req=1 ttl=64 time=2.65 ms
64 bytes from 192.168.2.205: icmp_req=2 ttl=64 time=0.889 ms
64 bytes from 192.168.2.205: icmp_req=3 ttl=64 time=0.933 ms
64 bytes from 192.168.2.205: icmp_req=4 ttl=64 time=1.16 ms

--- 192.168.2.205 ping statistics ---
4 packets transmitted, 4 received, 0% packet loss, time 3005ms
rtt min/avg/max/mdev = 0.889/1.411/2.655/0.725 ms
2014.12.09 [b]22:07:30[/b] 5: PRESENCE (pres_mci500h) - blocking scan result: pres_mci500h|1|present
2014.12.09 [b]22:23:00[/b] 1: PERL WARNING: Subroutine myUtils_Initialize redefined at ./FHEM/99_myUtils.pm line 14.


Um 22:23 habe ich die myUtils geändert.
Dort stand bisher

Code Auswählen Erweitern


sub myUtils_mci500h_poweroff()
{
fhem "set IR_Dev irSend ButtonMCI020";
fhem "set IR_Dev irSend ButtonMCI024";
fhem "set pres_mci500h statusRequest";
}


Dadurch wird per IR-Signal ein Gerät das durch Presence überwacht wird ausgeschaltet und anschließend versucht den Status zu aktualisieren.

Dummerweise kann ich das Verhalten aktuell nicht reproduzieren und schon gar nicht in einer Weise die du dann auch reproduzieren kannst.
Ich habe daher Verständnis wenn du da keinen Aufwand rein stecken willst.

Gruß,

Kai

[Markus Bloch]

Hab ein Fix eingechecked und steht ab morgen zur Verfügung.

Viele Grüße

Markus