Ping geht mit PRESENCE nach Rereadcfg nicht mehr

[Otto]

Hallo,

ein reload bring PRESENCE zum Stillstand:

Code Auswählen Erweitern

2014.10.11 10:56:40 5: PRESENCE (TV1) - stopping timer
2014.10.11 10:56:40 5: PRESENCE (TV1) - starting blocking call for mode lan-ping
2014.10.11 10:56:40 5: PRESENCE (TV1) - starting ping scan: TV1|192.168.15.40|0|4
2014.10.11 10:56:40 1: HMLAN_Parse: HMLAN1 new condition ok
2014.10.11 10:56:43 5: PRESENCE (TV1) - ping command returned with output:
PING 192.168.15.40 (192.168.15.40) 56(84) bytes of data.
From 192.168.15.150 icmp_seq=1 Destination Host Unreachable
From 192.168.15.150 icmp_seq=2 Destination Host Unreachable
From 192.168.15.150 icmp_seq=3 Destination Host Unreachable
From 192.168.15.150 icmp_seq=4 Destination Host Unreachable

--- 192.168.15.40 ping statistics ---
4 packets transmitted, 0 received, +4 errors, 100% packet loss, time 3008ms
pipe 4
2014.10.11 10:56:43 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 114.
2014.10.11 10:56:43 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
Can't use an undefined value as a symbol reference at FHEM/Blocking.pm line 132.


Danach kommt kein Ping mehr, da hilft nur noch ein restart

Code Auswählen Erweitern

define TV1 PRESENCE lan-ping 192.168.15.40 60
attr TV1 verbose 5

Wo muss ich suchen?

Gruß Otto


edit: Habe das Topic geändert: rereadcfg anstatt reload

[Markus Bloch]

Hallo Otto,

definiere bitte "reload". Meinst du damit ein "reload 73_PRESENCE.pm" in der FHEM Kommandozeile (falls dem so ist, warum musst du einen reload machen?), oder einen Neustart von FHEM mit "shutdown restart"

Bitte ändere den globalen Loglevel (Attribut verbose im global) auf 5 und poste dann bitte nochmal einen Log-Auszug.

Vielen Dank

Gruß
Markus

[Otto]

Hallo Markus,

reload ist Quatsch, keine Ahnung wie ich darauf komme.

Ich meinte rereadcfg.

Also nach einem rereadcfg kommt kein ping.

Code Auswählen Erweitern

2014.10.11 16:33:30 5: Cmd: >rereadcfg<
2014.10.11 16:33:33 5: PRESENCE (TV1) - stopping timer
2014.10.11 16:33:33 5: PRESENCE (TV1) - starting blocking call for mode lan-ping
2014.10.11 16:33:33 5: PRESENCE (TV1) - starting ping scan: TV1|192.168.15.40|0|4
2014.10.11 16:33:34 1: HMLAN_Parse: HMLAN1 new condition ok
2014.10.11 16:33:36 5: PRESENCE (TV1) - ping command returned with output:
PING 192.168.15.40 (192.168.15.40) 56(84) bytes of data.
From 192.168.15.150 icmp_seq=1 Destination Host Unreachable
From 192.168.15.150 icmp_seq=2 Destination Host Unreachable
From 192.168.15.150 icmp_seq=3 Destination Host Unreachable
From 192.168.15.150 icmp_seq=4 Destination Host Unreachable

--- 192.168.15.40 ping statistics ---
4 packets transmitted, 0 received, +4 errors, 100% packet loss, time 3008ms
pipe 4
2014.10.11 16:33:36 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 114.
2014.10.11 16:33:36 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
Can't use an undefined value as a symbol reference at FHEM/Blocking.pm line 132.
2014.10.11 16:41:14 5: Cmd: >define TV1 PRESENCE lan-ping 192.168.15.40 60<
2014.10.11 16:41:14 5: Cmd: >attr TV1 verbose 5<
2014.10.11 16:41:18 5: PRESENCE (TV1) - stopping timer
2014.10.11 16:41:18 5: PRESENCE (TV1) - starting blocking call for mode lan-ping
2014.10.11 16:41:18 4: BlockingCall created child (6607), uses telnetForBlockingFn to connect back
2014.10.11 16:41:18 5: PRESENCE (TV1) - starting ping scan: TV1|192.168.15.40|0|4
2014.10.11 16:41:21 5: PRESENCE (TV1) - ping command returned with output:
PING 192.168.15.40 (192.168.15.40) 56(84) bytes of data.
From 192.168.15.150 icmp_seq=1 Destination Host Unreachable
From 192.168.15.150 icmp_seq=2 Destination Host Unreachable
From 192.168.15.150 icmp_seq=3 Destination Host Unreachable
From 192.168.15.150 icmp_seq=4 Destination Host Unreachable

--- 192.168.15.40 ping statistics ---
4 packets transmitted, 0 received, +4 errors, 100% packet loss, time 3008ms
pipe 4
2014.10.11 16:41:21 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 114.
2014.10.11 16:41:21 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
Can't use an undefined value as a symbol reference at FHEM/Blocking.pm line 132.

Gruß Otto

[Markus Bloch]

Hallo Otto,

ich weis leider immer noch nicht ganz genau, was dein Problem ist. Ist es:

Code Auswählen Erweitern

From 192.168.15.150 icmp_seq=1 Destination Host Unreachable

oder ist es die Tatsache, dass in der FHEM Weboberfläche nichts mehr aktualisiert wird?

Bitte poste mal die Ausgabe von "list telnetForBlockingFn" in der FHEM Kommandozeile.

Danke

Gruß
Markus

[Otto]

Hallo Markus,

das Problem ist: in der FHEM Weboberfläche wird nichts mehr aktualisiert.

Ein list telnetForBlockingFn bringt No device named telnetForBlockingFn found

hier der log nach einem restart

Code Auswählen Erweitern

2014.10.11 17:03:30 5: PRESENCE (TV1) - stopping timer
2014.10.11 17:03:30 5: PRESENCE (TV1) - starting blocking call for mode lan-ping
2014.10.11 17:03:30 5: Loading ./FHEM/98_telnet.pm
2014.10.11 17:03:30 3: telnetForBlockingFn: port 53930 opened
2014.10.11 17:03:30 5: Triggering global (1 changes)
2014.10.11 17:03:30 5: Notify loop for global DEFINED telnetForBlockingFn
2014.10.11 17:03:30 4: BlockingCall created child (6629), uses telnetForBlockingFn to connect back
2014.10.11 17:03:30 5: PRESENCE (TV1) - starting ping scan: TV1|192.168.15.40|0|4
2014.10.11 17:03:33 5: PRESENCE (TV1) - ping command returned with output:
PING 192.168.15.40 (192.168.15.40) 56(84) bytes of data.
From 192.168.15.150 icmp_seq=1 Destination Host Unreachable
From 192.168.15.150 icmp_seq=2 Destination Host Unreachable
From 192.168.15.150 icmp_seq=3 Destination Host Unreachable
From 192.168.15.150 icmp_seq=4 Destination Host Unreachable

--- 192.168.15.40 ping statistics ---
4 packets transmitted, 0 received, +4 errors, 100% packet loss, time 3008ms
pipe 4
2014.10.11 17:03:33 4: Connection accepted from telnet:127.0.0.1:46561
2014.10.11 17:03:33 5: Cmd: >{PRESENCE_ProcessLocalScan('TV1|0|absent')}<
2014.10.11 17:03:33 5: PRESENCE (TV1) - blocking scan result: TV1|0|absent
2014.10.11 17:03:33 5: Triggering TV1 (1 changes)
2014.10.11 17:03:33 5: Notify loop for TV1 absent
2014.10.11 17:03:33 4: PRESENCE (TV1) - rescheduling next check in 60 seconds
2014.10.11 17:04:33 5: PRESENCE (TV1) - stopping timer
2014.10.11 17:04:33 5: PRESENCE (TV1) - starting blocking call for mode lan-ping
2014.10.11 17:04:33 4: BlockingCall created child (6631), uses telnetForBlockingFn to connect back
2014.10.11 17:04:33 5: PRESENCE (TV1) - starting ping scan: TV1|192.168.15.40|0|4


um 17:04:33 kommt auch schön der ping nach 60 sec, wie es sein soll

Gruß Otto

[Markus Bloch]

Hallo Otto,

das Problem ist folgendes. Dieses Phänomen tritt auf, wenn man rereadcfg benutzt und ist auch bekannt. Im Forum wird auch an mehreren Stellen von Rudolf König empfohlen diesen Befehl nicht zu verwenden, um unter anderem dieses Problem zu vermeiden.

Hintergrund, warum dieser Fehler auftritt:

Damit ein Ping-Check mit PRESENCE nicht das gesamte FHEM System lahm legt, wird dieser Check in einem Parrallelprozess durchgeführt und verbindet sich dann via telnet wieder zum Hauptprozess um das Ergebnis dem eigentlichen Hauptprozess (parent-Prozess) mitzuteilen. Nun passiert allerdings folgendes. Bevor ein solcher Parrallelprozess gestartet wird, wird geprüft, ob es eine telnet Instanz gibt, über die man sich zurückverbinden könnte. In deinem Fall existiert allerdings keine, daher wird eine temporäre Telnet Instanz erzeigt, die nur über loopback ansprechbar ist (localhost, bzw. 127.0.0.1). Der Parallelprozess startet nun und fängt an sein Ping-Kommando auszuführen.

Nun wird über die GUI ein rereadcfg ausgeführt. Dabei werden zuerst alle Definitionen gelöscht (auch die temporäre telnet-Definition) und entsprechend dem Konfig-File neu angelegt. Daraus resultiert, das die temporäre Telnet-Instanz nun nicht mehr existiert, da sie ja nicht im Konfig-File steht (was ja auch nicht gedacht war).

Der Parallel-Prozess ist fertig mit seinem Ping und will nun den zuvor temporär erzeugten Telnet-Zugang nutzen um sein Ergebnis an den Hauptprozess zu übertragen. Dazu holt er sich den Port von der telnet-Definition. Allerdings existiert diese Definition nun nicht mehr und somit kann auch der Port nicht mehr ermittelt werden.

Es erscheint die Meldung: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'

Der Hostname "localhost:" ist auch kein gültiger Hostname. Eigentlich müsste es "localhost:7072" heißen, aber da die Definition nicht existiert, kann dieser Port nicht mehr ermittelt werden.

Beim nächsten Check wird dann die temporäre Telnet-Instanz wieder ordnungsgemäß angelegt und alles funktioniert wieder normal.

Was kann man nun dagegen machen?

Es gibt mehrere Möglichkeiten:

• kein rereadcfg mehr benutzen (wird im Forum überall gepredigt) und lieber einen vollständigen "shutdown restart" machen. So wird immer FHEM mit einem sauberen Stand gestartet.
• eine feste telnet-Instanz nur für loopback Verbindungen anlegen. Eine Telnet-Instanz mit der Definition "define <name> telnet <servername>:<portNumber>" ist nur über loopback (localhost/127.0.0.1) ansprechbar und kann nicht von außen angesprochen werden. Details hierzu stehen in der Commandref.

Viele Grüße

Markus