FHEM2FHEM blockiert wenn Event gesendet wird

Begonnen von Nemo0815, 29 April 2015, 18:59:58

Vorheriges Thema - Nächstes Thema

Nemo0815

Hallo,

folgendes Problem:

Ich habe 2 mal FHEM2FHEM auf dem Raspi und der Fritzbox.

Auf dem Raspi so definiert:

Internals:
   DEF        fritz.box:7072 LOG:Anwesend
   FD         14
   Host       fritz.box:7072
   NAME       Raspi2Fritz
   NR         69
   PARTIAL
   STATE      connected
   TYPE       FHEM2FHEM
   informType LOG
   regexp     Anwesend
Attributes


und auf der Fritzbox so

Internals:
   DEF        raspberrypi:7072 LOG:forwardRemote2
   FD         17
   Host       raspberrypi:7072
   NAME       Fritz2Raspi
   NR         84
   PARTIAL
   STATE      connected
   TYPE       FHEM2FHEM
   informType LOG
   regexp     forwardRemote2
Attributes:


Wenn ich jetzt auf der Fritzbox den Wert für "Anwesend" ändere, dann hängt sich FHEM auf dem Raspi komplett auf. Ich bekomme keinerlei Log Einträge, ausser dem hier:

2015.04.29 18:48:43 3: FHEM2FHEM opening Raspi2Fritz at fritz.box:7072
2015.04.29 18:48:43 3: FHEM2FHEM device opened (Raspi2Fritz)
2015.04.29 18:50:27 0: Server shutdown
2015.04.29 18:50:27 1: CallBlockingFn: Can't connect to localhost:7072: IO::Socket::INET: connect: Verbindungsaufbau abgelehnt
2015.04.29 18:53:22 1: Including fhem.cfg
2015.04.29 18:53:22 3: telnetPort: port 7072 opened


Und manchmal, wenn ich versuche über Telnet FHEM zu stoppen das hier in der Konsole

pi@raspberrypi ~ $ Can't use an undefined value as a symbol reference at FHEM/Blocking.pm line 125.



Mach ich irgendwas falsch? Ich möchte gefiltert nur diese beiden Events übertragen...

Nemo0815

Was ich noch sagen wollte, wenn ich das mache "heilt" sich das System meistens selbst wieder. Das dauert allerdings bis zu 20 Minuten bis FHEM reagiert.

Keiner ne Idee? Im Logfile taucht allerdings nichts weiter auf...

Wernieman

2015.04.29 18:50:27 1: CallBlockingFn: Can't connect to localhost:7072: IO::Socket::INET: connect: Verbindungsaufbau abgelehnt

Wie ist telnet bei Dir definiert?
- Bitte um Input für Output
- When there is a Shell, there is a Way
- Wann war Dein letztes Backup?

Wie man Fragen stellt: https://tty1.net/smart-questions_de.html

Nemo0815

#3
so

Internals:
   CONNECTS   2
   DEF        7072 global
   FD         6
   NAME       telnetPort
   NR         3
   PORT       7072
   STATE      Initialized
   TYPE       telnet
Attributes:


Das passiert übrigens wechselseitig. Je nachdem ob ich auf der Box oder den Raspi ein event "sende" hängt der jeweilige Empfänger. Interessanterweise löst die Box den Zustand aber viel schneller wieder auf

Nemo0815

#4
Ich habe jetzt mal auf der Fritzbox den Regex erweitert:

raspberrypi:7072 LOG:forwardRemote2|RASPI.Watchdog

Der Watchdog wird jede Minute auf dem Raspi geschrieben. Jedesmal wenn das passiert hängt die Fritzbox für genau 1 Minute:

2015-04-30 09:51:39 dummy RASPI.Watchdog 16
2015-04-30 09:52:39 dummy RASPI.Watchdog 17


Erst nach dieser Zeit tauchen die beiden Zeilen oben im Eventlog auf.

Das schreiben des "forwardRemote" funktioniert übrigens ohne eine solche Verzögerung. Nur wenn ich ein Event welches nicht auf der Gegenseite exisitert schreibe kommt es zu diesem Hänger.


Wenn ich mir jetzt noch den Watchdog auf der Fritzbox anschaue (auch ein Counter der jede Minute inkrementiert wird) sehe ich dass FHEM wirklich hängt - für jeweils 11 Sekunden (?) und sich die Timestamps verschieben, solange der FHEM2FHEM den obigen Event empfängt. Lösche ich ihn wieder aus dem Regex, läufts wieder normal durch:

2015-04-30_09:47:28 FRITZBOX.Watchdog 48
2015-04-30_09:48:39 FRITZBOX.Watchdog 49
2015-04-30_09:49:28 FRITZBOX.Watchdog 50
2015-04-30_09:50:39 FRITZBOX.Watchdog 51
2015-04-30_09:51:28 FRITZBOX.Watchdog 52
2015-04-30_09:52:39 FRITZBOX.Watchdog 53
2015-04-30_09:53:28 FRITZBOX.Watchdog 54
2015-04-30_09:54:39 FRITZBOX.Watchdog 55
2015-04-30_09:55:28 FRITZBOX.Watchdog 56
2015-04-30_09:56:39 FRITZBOX.Watchdog 57
2015-04-30_09:57:28 FRITZBOX.Watchdog 58
2015-04-30_09:58:39 FRITZBOX.Watchdog 59
2015-04-30_09:59:28 FRITZBOX.Watchdog 60
2015-04-30_10:00:39 FRITZBOX.Watchdog 0
2015-04-30_10:01:27 FRITZBOX.Watchdog 1


Nachdem er wieder rausgeschlöscht wurde gehts minutengenau weiter:

2015-04-30_10:01:27 FRITZBOX.Watchdog 1
2015-04-30_10:02:27 FRITZBOX.Watchdog 2
2015-04-30_10:03:27 FRITZBOX.Watchdog 3
2015-04-30_10:04:27 FRITZBOX.Watchdog 4


Was mir noch aufgefallen ist, wenn ich FHEM2FHEM ändere (z.b. Regex ändere) bekomme ich im Log:

2015.04.30 10:00:39 1: FHEMWEB SSL/HTTPS error:
2015.04.30 10:00:40 1: FHEMWEB SSL/HTTPS error:
2015.04.30 10:00:52 3: FHEM2FHEM opening Fritz2Raspi at raspberrypi:7072
2015.04.30 10:00:52 3: FHEM2FHEM device opened (Fritz2Raspi)


?

Wernieman

"Mann" sollte Logfiles komplett lesen .... (mea Culpa)

2015.04.29 18:50:27 0: Server shutdown
2015.04.29 18:50:27 1: CallBlockingFn: Can't connect to localhost:7072: IO::Socket::INET: connect: Verbindungsaufbau abgelehnt
2015.04.29 18:53:22 1: Including fhem.cfg
2015.04.29 18:53:22 3: telnetPort: port 7072 opened


Logisch, das er den telnet-Port nicht erreicht, wenn vorher der fhem-Server abgeschaltet wird .... warum er aber vorher fhem runtrfährt (Server shutdown) müsen andere klähren ...
- Bitte um Input für Output
- When there is a Shell, there is a Way
- Wann war Dein letztes Backup?

Wie man Fragen stellt: https://tty1.net/smart-questions_de.html

Nemo0815

Zitat von: Wernieman am 30 April 2015, 10:17:19
"Mann" sollte Logfiles komplett lesen .... (mea Culpa)

2015.04.29 18:50:27 0: Server shutdown
2015.04.29 18:50:27 1: CallBlockingFn: Can't connect to localhost:7072: IO::Socket::INET: connect: Verbindungsaufbau abgelehnt
2015.04.29 18:53:22 1: Including fhem.cfg
2015.04.29 18:53:22 3: telnetPort: port 7072 opened


Logisch, das er den telnet-Port nicht erreicht, wenn vorher der fhem-Server abgeschaltet wird .... warum er aber vorher fhem runtrfährt (Server shutdown) müsen andere klähren ...

Ok, das war dann wohl ich mit dem Manuellem Shutdown über die Konsole. Hat dann wohl nichts mit dem obigen Problem zu tun, sorry...

Nemo0815

Interessanterweise funktionert

LOG:.*

besser als

LOG:forwardRemote.*

Bei ersterem wird die Fritzbox zwar mit allen Events zu geballert, aber hängt nicht, bei letzterem kommt es zu besagtem Hänger. (?)

Nach der Änderung zurück auf LOG:forwardRemote.* ist fhem auf der Fritzbox jetzt komplett tot. Auf dem Raspi bekomme ich nur noch

2015.04.30 13:23:26 1: FRITZBOX FritzBox: Readout_Start.623 Old readout process still running. Killing old process HASH(0x13ede70)
2015.04.30 13:23:38 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:23:38 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:24:05 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:24:05 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:25:08 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:25:08 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:26:11 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:26:11 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:27:14 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:27:14 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:28:17 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:28:17 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:28:26 1: FRITZBOX FritzBox: Readout_Start.623 Old readout process still running. Killing old process HASH(0xaf8ff0)
2015.04.30 13:28:38 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:28:38 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:29:20 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:29:20 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:30:23 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:30:23 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:31:26 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:31:26 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:32:29 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:32:29 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:33:26 1: FRITZBOX FritzBox: Readout_Start.623 Old readout process still running. Killing old process HASH(0x13ea7f0)
2015.04.30 13:33:32 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:33:32 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:33:37 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:33:37 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:34:35 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:34:35 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:35:38 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:35:38 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:36:41 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:36:41 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:37:44 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:37:44 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:38:26 1: FRITZBOX FritzBox: Readout_Start.623 Old readout process still running. Killing old process HASH(0xaf68b0)
2015.04.30 13:38:38 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:38:38 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:38:47 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:38:47 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:39:50 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:39:50 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:40:53 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:40:53 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:41:56 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:41:56 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:42:59 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:42:59 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:43:26 1: FRITZBOX FritzBox: Readout_Start.623 Old readout process still running. Killing old process HASH(0x13ede70)
2015.04.30 13:43:37 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:43:37 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:44:02 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:44:02 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:45:05 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:45:05 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:46:08 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:46:08 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:47:11 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:47:11 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:48:14 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:48:14 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:48:26 1: FRITZBOX FritzBox: Readout_Start.623 Old readout process still running. Killing old process HASH(0x128e938)
2015.04.30 13:48:38 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:48:38 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:49:17 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:49:17 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:50:20 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:50:20 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:51:23 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:51:23 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'
2015.04.30 13:52:26 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at FHEM/Blocking.pm line 107.
2015.04.30 13:52:26 1: CallBlockingFn: Can't connect to localhost:: IO::Socket::INET: Bad hostname 'localhost:'

Nemo0815

Ich glaube ich habe des Rätsels Lösung:

LOG:(forwardRemote)

also in Klammern, scheint zu funktionieren - warum auch immer...