PRESENCE function(xxx) Zombies on Timeout - brauche Tip

[erwin]

Hi all,
Folgende Situation:
ich schreibe eine Funktion, die zuerst einen Daemon startet (falls dieser nicht bereits läuft), der anschließend mit der Funktion daten austauscht.
Funktioniert alles Bestens.
Was mir allerdings aufgefallen ist, dass die PRESENCE function(xxx) beim ersten mal starten nicht rechtzeitig fertig wird und in den Timeout exit läuft. Warum? Weiß ich noch nicht, der Daemon wird richtig gestartet, nimmt die daten und gibt auch Antwort....
Aber: nach diesen LogMessages:

Code Auswählen Erweitern

2014.02.18 21:34:51 1: Timeout for PRESENCE_DoLocalFunctionScan reached, terminated process 13094
2014.02.18 21:34:51 2: PRESENCE: Erwin_PRESENCE could not be checked (retrying in 10 seconds)
2014.02.18 21:34:56 1: Timeout for PRESENCE_DoLocalFunctionScan reached, terminated process 13099
2014.02.18 21:34:56 2: PRESENCE: Margit_PRESENCE could not be checked (retrying in 10 seconds)
2014.02.18 21:35:02 2: PRESENCE: Erwin_PRESENCE returned a valid result after 1 unsuccesful retry
2014.02.18 21:35:06 2: PRESENCE: Margit_PRESENCE returned a valid result after 1 unsuccesful retry
entstehen zwei zombies mit exact den beiden PID's:

Code Auswählen Erweitern

fhem     13091     1  9 21:33 pts/1    00:01:01 perl fhem.pl fhem.cfg
fhem     13094 13091  0 21:33 pts/1    00:00:00 [perl] <defunct>
fhem     13097     1  0 21:33 pts/1    00:00:02 /usr/bin/perl ./FHEM/RFritzBoxScan.pl ./credentials.cfg
fhem     13099 13091  0 21:33 pts/1    00:00:00 [perl] <defunct>
Alle folgenden PRESENCE funktion(xxx) laufen problemlos. Das passiert nur unmittelbar beim start von FHEM und es sind exakt immer 2 zombies, obwohl es 8 solche "PRESENCE devices" gibt.

Ich brauch eine Idee???
l.g. erwin

[Markus Bloch]

Poste doch mal bitte die Funktion die du da verwendest.

Wenn die Funktion innerhalb von 60 Sekunden kein Resultat liefert, wird der Check vorzeitig abgebrochen, so wie bei dir.


Gruß
Markus

[erwin]

Hallo Markus,
das ist mal die Funktion .... ein paar variablen werden "global" (in der 99_RFritzBox.pm) initialisiert

Code Auswählen Erweitern


### query Remote FB via telnet interface
sub RemoteFritzBox($) {
   my ($devname) = @_;

   ### check if my server is running
   my ($serverstatus) = qx(pidof -x $serverbin);
   if (defined ($serverstatus)) {
      chomp $serverstatus;
      Log3 "RemoteFritzBox", 5,"RemoteFritzBox Server-running with pid $serverstatus";
   } else {
     ### trying to start the server
     Log3 "RemoteFritzBox", 2, "RemoteFritzBox Server-Task $serverbin starting";
     my $alloutput = "> /dev/null 2>&1";
     system("$fullserverbin $alloutput &");
     select(undef, undef, undef, 2.0); # give daemon time to start before connecting
     my ($serverstatus) = qx(pidof -x $serverbin);
     if (defined ($serverstatus)) {
        chomp $serverstatus;
        Log3 "RemoteFritzBox", 5,"RemoteFritzBox Server-running with pid $serverstatus";
     } else {
        Log3 "RemoteFritzBox", 1,"RemoteFritzBox Server could not be started";
     }
   }

   ### auto-flush on socket
   $| = 1;

   ### create a connecting socket
   my $socket = new IO::Socket::INET (
     PeerHost => $serverhost,
     PeerPort => $serverport,
     Proto => 'tcp',
   );
   unless ($socket) {
      Log3 "RemoteFritzBox", 1, "RemoteFritzBox cannot connect to Server $!";
      return "RemoteFritzBox cannot connect to Fritzbox $!\n"; #  unless $socket;
   }
   my $sockport = $socket->sockport();
   Log3 "RemoteFritzBox", 5, "RemoteFritzBox connected: $serverhost:$serverport on socket $sockport";
   my $size = $socket->send($devname);
   Log3 "RemoteFritzBox", 5, "RemoteFritzBox sending request: $devname for socket $sockport";
   ### notify server that request has been sent
   shutdown($socket, 1);

   ### receive a response of up to 1024 characters from server
   my $response = "";
   $socket->recv($response, 1024);
   Log3 "RemoteFritzBox", 5, "RemoteFritzBox receiving response: $response for socket $sockport";
   $socket->close();
   return "$response";
}

Wobei es egal ist, ob zum FHEM start der Daemon bereits läuft oder erst hier gestartet wird.
Und wie schon beschrieben, abgesehen davon läuft ja alles bestens.
Die Frage ist: selbst wenn die Funktion nicht fertig werden sollte (aus welchem Grund aus immer), warum bleiben da zombies über?

Danke erwin

[Markus Bloch]

Die Frage ist: selbst wenn die Funktion nicht fertig werden sollte (aus welchem Grund aus immer), warum bleiben da zombies über?

Weil die Funktion nachwievor noch läuft und irgendwo innerhalb der Funktion hängt (ich tippe auf den Empfangsbefehl des Socket). Und der Prozess kann aufgrund dieser Blockade nicht beendet werden und ist deswegen nun ein Zombie.

Zu deiner Funktion kann ich nicht viel zu sagen, da ich sie selber nicht benutze.

[erwin]

Hallo Markus,
dein Hinweis war sehr gut, ich habe nun alles möglich probiert und komme zu dem Schluss, daß es ein Timingproblem beim start von FHEM ist....
Wie komm ich auf die Idee?
ich hab ganz am Anfang meiner Funktion ein

Code Auswählen Erweitern

    select(undef, undef, undef, 20.0); eingefügt, und auf einmal geht es vom start weg....
Das ist natürlich für produktives Environment nicht praktikabel, aber ich denke ich weiß worans liegt.
Im socket read liegts jedenfalls nicht, da hab ich zusätzlich Timeout eingebaut,
ich vermute fast, dass fhem noch nicht fertig ist - das Modul schon läuft und irgendwas aufruft was es noch nicht gibt und damit crashed das Modul unkontrolliert. - Ist aber nur eine gewagte Theorie! Z.B. fehlen mir Log-einträge die zu dem PID passen....und die PID Nummer des/der zombies war nur um 10 höher als von fhem... (mit dem delay bekomm ich eine pid nummer, die um 100+ höher ist?
ideen dazu ?
l.g erwin

[erwin]

Hallo Markus,
Fehler gefunden!!! ...nach etlichen Versuchen.....
Problem war, dass ich bei zwei PRESENCE device's attr disable 0 hatte, und die zünden sofort beim einlesen des state files... und da ist etliches offensichtlich noch nicht fertig, was ich brauche.

Herausgekommen bei der ganzen fehlersuche ist ist ein diff, bitte schau's dir mal an!
l.g erwin

[Markus Bloch]

Hallo erwin,

versteh mich bitte nicht falsch, aber ist das nicht eine Sache, die in deiner Funktion berücksichtigt werden sollte? Normalerweise ist ja eine Anwesenheitserkennung von anderen FHEM Definitionen unabhängig und muss nicht auf die abgeschlossene Initialisierung aller Definitionen warten.

Setz doch einfach in deiner Funktion den gesamten Code in ein if($init_done) { ...... } hinein. Dann wird deine Funktion direkt beim Start natürlich kein Ergebnis liefern, aber dann beim nächsten Aufruf währe ja dann $init_done auf 1 und deine Funktion würde in Aktion treten.

Viele Grüße

Markus

[erwin]

Hab ich soeben ausprobiert,

meine Funktion schaut soo aus:

Code Auswählen Erweitern


package main;

use strict;
use warnings;
use POSIX;
use IO::Socket::INET; ## only for Telnet Access
use FritzBoxUtils; ## only for web access

### query Remote FB via telnet interface
sub RemoteFritzBox($) {
   my ($devname) = @_;

   return "fhem init phase query not executed" if (! ($init_done)); ### patch against zombies during fhem start
   return "normal return";

1;

und das gibt einen zombie für jedes PRESENCE device, dass attr disable 0 gesetzt hat.
Ich hab jetzt ja kein Problem damit,  da ich die Ursache kenne kann ich sie leicht vermeiden. - delete attr disable
Allerdings erschließt sich mir der Grund nicht, warum im set - während des einlesens des state-files - process_local_scan aufgerufen wird.
Mit etwas Pech wird zuerst im set der process_local_scan getriggert, dann während des define nochmal (oder umgekehrt), wenn sich das vom timing schlecht ausgeht, ist der 1.Timer unterwegs und das ding wird nocheinmal  gestartet!
l.g. erwin

[Markus Bloch]

Allerdings erschließt sich mir der Grund nicht, warum im set - während des einlesens des state-files - process_local_scan aufgerufen wird.
Mit etwas Pech wird zuerst im set der process_local_scan getriggert, dann während des define nochmal (oder umgekehrt), wenn sich das vom timing schlecht ausgeht, ist der 1.Timer unterwegs und das ding wird nocheinmal  gestartet!
l.g. erwin

Was genau meinst du? Wenn das fhem-state File eingelesen wird, wird ein ProcessLocalScan() ausgeführt? Das kann eigentlich nicht sein, da innerhalb des FHEM-Hauptprozesses diese Funktion nicht aufgerufen wird. Sie wird lediglich per telnet von den Unterprozessen ausgeführt. Ist also möglich, dass beim Start von FHEM noch ein Unterprozess der vorherigen Instanz lief und versucht das Ergebnis am (nun neugestarteten) Hauptprozess abzuladen.

Währe interessant, wenn du mal einen Logauszug mit verbose 5 bei deiner PRESENCE Instanz postest.

Vielen Dank

Gruß
Markus

[erwin]

Hi Markus,

Was genau meinst du? Wenn das fhem-state File eingelesen wird, wird ein ProcessLocalScan() ausgeführt?

richtig, das meine ich und zwar in sub PRESENCE_Attr(@) (ganz am schluss) wenn ein Attribut disable auf 0 steht (im save file) und das passiert offensichtlich sehr sehr früh....
Das ist so früh, dass z.B. die Log3 funktion noch nicht funktioniert (zumindest kommt im log file nix an, print statements nach STDOUT gehen aber immer 

Wie gesagt, wenn ich das attribut lösche, gibts keine Probleme...
l.g. erwin

[Markus Bloch]

Hallo erwin,

In der Attr-Funktion wird kein ProcessLocalScan aufgerufen, sondern ein StartLocalScan, welches einen Check in Gang setzt, sobald man entweder das disable Attribut gelöscht, oder es auf 0 gesetzt ist. Das ist auch nicht schlimm, da immer nur ein Check zur gleichen Zeit laufen darf. Wenn also beim Start ein Check aufgrund von disable 0 gestartet wird, so ist das nicht schlimm. Der eigentliche Start durch die Define-Funktion wird dann auch getriggert, aber da bereits ein Check läuft wird kein neuer Check gestartet.

Ich würde aber ein Check in der Attr-Funktion einbauen, der prüft, ob die relevanten Daten durch die Define-Funktion bereits in $hash eingetragen worden. So wird verhindert, das die Attr-Funktion noch vor der Define-Funktion tätig wird.

Viele Grüße

Markus

[erwin]

Hallo Markus,

So wird verhindert, das die Attr-Funktion noch vor der Define-Funktion tätig wird

Danke das ist die Lösung!!!
Bei mir dauert offensichtlich der startup so lange, daß der startlocalscan (getriggert in der Attr - Funktion)   bereits den Blockingcall ausgelöst hatte und im define dann nochmals.
Wenn du also in det Attr-Funktion das einbauen kannst, ist alles super !!!

herzlichen dank für deine Hilfe
erwin
PS: ich setze auf gelöst.

[Markus Bloch]

eingecheckt.