DbLog beendet Verbindung nach fork

[vbs]

Ich habe mir mal das DbLog eingerichtet und das funktioniert eigentlich sehr gut. Jedoch habe ich sporadisch Situationen, in denen einfach nichts mehr geloggt wird.

Nachdem ich in DbLog_Push diese Variable gesetzt habe, konnte ich zumindest im Log eine Fehlermeldung sehen:

Code Auswählen Erweitern


  $dbh->{RaiseError} = 0;
  $dbh->{PrintError} = 1; 


Code Auswählen Erweitern


DBD::mysql::st execute failed: MySQL server has gone away at ./FHEM/93_DbLog.pm line 450.
DBD::mysql::st execute failed: MySQL server has gone away at ./FHEM/93_DbLog.pm line 455.
Use of uninitialized value $rv_uc in numeric eq (==) at ./FHEM/93_DbLog.pm line 456.
DBD::mysql::st execute failed: MySQL server has gone away at ./FHEM/93_DbLog.pm line 457.
commit ineffective with AutoCommit enabled at ./FHEM/93_DbLog.pm line 471.


Außerdem seh ich auf dem MySQL-Server, dass die fhem-Verbindung direkt nach dem Verbinden wieder verschwindet.

Ich habe den starken Verdacht, dass das wieder mit dem Forken anderer Module zu tun hat. Ich benutze die fork-Option in XBMC und in STV. Wenn ich bei den beiden "fork" auf disable setze, dann tritt das Problem nicht auf. Ich hab ja gelernt, dass geforkte Prozesse gerne Schweinkram mit den Filedeskriptoren treiben, wenn sie sich beenden.

In beiden Modulen (XBMC und STV) ist jedoch eigentlich dieser Code drin, der in den geforkten Prozessen korrekt die Handles schließen sollte:

Code Auswählen Erweitern

        return if($hash->{CHILDPID} = fork);
        my $ppid = getppid();
   
        ### Copied from Blocking.pm
        foreach my $d (sort keys %defs) {   # Close all kind of FD
          my $h = $defs{$d};
          TcpServer_Close($h) if($h->{SERVERSOCKET});
          if($h->{DeviceName}) {
            require "$attr{global}{modpath}/FHEM/DevIo.pm";
            DevIo_CloseDev($h,1);
          }
        }
        ### End of copied from Blocking.pm
Das scheint jedoch im Fall von DbLog nicht ausreichend zu sein? Hat jemand evtl. eine Idee? Danke!

[betateilchen]

welche Version des DbLog Moduls hast Du im Einsatz? Das Problem in DbLog ist eigentlich schon seit mehreren Wochen behoben.

Aktuell ist die Version 5782

[vbs]

Habe gerade nochmal mit der aktuellen r5782 im trunk verglichen und das ist genau die, die ich auch laufen habe 

So spontan habe ich gerade in dem Commit übrigens nichts gesehen, was aussah, als würde es in Richtung Handling von File-Deskriptoren o.ä. gehen. Kann aber an mir liegen, hab es nur überflogen und kenne DbLog nicht näher...

[betateilchen]

DbLog arbeitet nicht mit Filedeskriptoren.

Das Problem mit dem verlorengegangenen db-handle in DbLog trat immer im Zusammenhang mit plotfork auf und wurde gelöst. Für andere Prozesse ist das forken der Datenbankverbindung in DbLog meines Wissens nicht implementiert.

[vbs]

Hm, was ist denn das Problem bei fork? Der geforkte Prozess schafft es irgendwie die DB-Verbindung des Hauptprozesses zu beenden?

Was kann man denn da machen? Ein Weg wäre sicherlich, fork nicht zu verwenden. Das würde halt auf ein generelles fork-Verbot hinauslaufen. 

Spricht etwas dagegen, dass DbLog vor jedem DB-Zugriff prüft, ob die Verbindung noch steht und ggf. neu aufbaut? Das passiert ja momentan noch nicht scheinbar. Wie verhält sich denn DbLog im Moment, falls der DB-Daemon oder gar der DB-Server mal neu startet?

[betateilchen]

Spricht etwas dagegen, dass DbLog vor jedem DB-Zugriff prüft, ob die Verbindung noch steht und ggf. neu aufbaut? Das passiert ja momentan noch nicht scheinbar. Wie verhält sich denn DbLog im Moment, falls der DB-Daemon oder gar der DB-Server mal neu startet?

Diese Fälle sind in DbLog inzwischen alle abgefangen.

Was Probleme macht, ist der von Dir beschriebene Fall, dass ein ANDERES Modul forkt, denn davon bekommt DbLog nichts mit (mit Ausnahme der Plotgenerierung bei plotfork). Theoretisch bräuchte jeder geforkte Prozess ein eigenes Datenbankhandle.

Das Ganze ist einfach eine historisch gewachsene Unzulänglichkeit bei der Verbindungsverwaltung von DbLog. Prinzipiell müsste das gesamte Verbindungsmanagement in DbLog komplett neu programmiert werden, um den inzwischen gewachsenen Anforderungen von fhem an das LoggingModul gerecht zu werden.

[vbs]

Was hälst du denn von dem Ansatz, dass man in jeder Funktion in DbLog, die auf die Datenbank zugreift einmal fragt "Steht Verbindung noch?", wenn nein -> Verbindung neu aufbauen?

[betateilchen]

Was hälst du denn von dem Ansatz, dass man in jeder Funktion in DbLog, die auf die Datenbank zugreift einmal fragt "Steht Verbindung noch?", wenn nein -> Verbindung neu aufbauen?

Das geht nicht so einfach, wie Du Dir das vorstellst. Innerhalb des DbLog Moduls selbst wird das schon so gehandhabt. Probleme sind aber die anderen Module, die Prozesse forken und dann noch Daten loggen wollen. Davon bekommt DbLog einfach nichts mit.

[vbs]

Das geht nicht so einfach, wie Du Dir das vorstellst. Innerhalb des DbLog Moduls selbst wird das schon so gehandhabt.

Also in meinem Fall kommen Events bei DbLog per NotifyFn an und dann werden die Daten in DbLog_Push an die Datenbank geschickt, richtig? In dem Moment ist bei mir die DB-Verbindung aber schon weg und innerhalb von DbLog_Push wird nicht versucht, diese neu aufzubauen. Es schlägt dann einfach fehl.

Probleme sind aber die anderen Module, die Prozesse forken und dann noch Daten loggen wollen. Davon bekommt DbLog einfach nichts mit.

Auf welche Art und Weise können denn Module selbst ohne Wissen von DbLog in die Datenkbank loggen? Ich dachte, dass alle Datenbank-Logs in Form von Events an der NotifyFn von DbLog vorbei kommen.

Sorry für die Fragerei, aber ich würde das wirklich gerne verstehen 

[betateilchen]

in DbLog wird zumindest beim Fehlschlag des Loggings erkannt, dass die Datenbankverbindung neu aufgebaut werden muss, was dann auch erfolgt. Der fehlgeschlagene Event wird dabei allerdings nicht noch einmal geloggt.

Würde man an dieser Stelle eine Wiederholung einbauen, müsste man auch noch eine Maximalzahl an Fehlversuchen definieren, um nicht in eine Endlosschleife zu geraten.

Eine Verbindungsprüfung VOR dem Loggen jedes Events wäre eine böse Perfomancefalle.

[Wuppi68]

mal ne blöde Frage

Kann dblog nicht automatisch beim Fork eine neue DB COnnecton aufmachen?

[betateilchen]

Ich hab keine Lust, hier gegen Windmühlen anzukämpfen und den Papageien zu spielen, der zehnmal hintereinander das gleiche antwortet.

[Wuppi68]

hallo betateilchen,

mein Denkansatz ist ein wenig anders. Kein dbopen und close für jeden log, sondern nur bei einem Fork ...

bei meiner Installation sehe ich normalerweise nur einen FHEM Prozess. Bei einen asynchronen Update vom System bekomme ich einen weiteren FHEM Prozess angezeigt. Ergo gehe ich bis dato davon aus, dass ein Fork ein Sonderfall im System ist und demnach auch kein Performanceproblem bedeuten SOLLTE ...

Irgendwo habe ich mal am Rande mitbekommen, das sqllite in Pearl nur eine DB Verbindung zuläßt - das wäre dann mit Sicherheit ein Showstopper

[vbs]

Kann vielleicht jemand kurz umreißen, was überhaupt das zugrunde liegende Problem ist, wegen dem nach einem fork der Hauptprozess sein DB-Handle verliert?

[vbs]

Yay! Hab das jetzt funktionierend am Laufen mit forkendem XBMC und STV. Ich benutze jetzt folgenden Code im Child nach dem Fork:

Code Auswählen Erweitern

        foreach my $d (sort keys %defs) {   # Close all kind of FD
          my $h = $defs{$d};
          $h->{DBH}->{InactiveDestroy} = 1 if ($h->{TYPE} eq 'DbLog');
          TcpServer_Close($h) if($h->{SERVERSOCKET});
          if($h->{DeviceName}) {
            require "$attr{global}{modpath}/FHEM/DevIo.pm";
            DevIo_CloseDev($h,1);
          }
        }

Neu ist die Zeile:

Code Auswählen Erweitern

$h->{DBH}->{InactiveDestroy} = 1 if ($h->{TYPE} eq 'DbLog');

Damit überlebt der DB-Handle im Hauptprozess den Fork und es wird auch weiterhin erfolgreich 'dbgeloggt' nachdem XBMC oder STV geforkt haben.

EDIT:

in DbLog wird zumindest beim Fehlschlag des Loggings erkannt, dass die Datenbankverbindung neu aufgebaut werden muss, was dann auch erfolgt. Der fehlgeschlagene Event wird dabei allerdings nicht noch einmal geloggt.

Das ist übrigens nicht so (zumindest nicht bei MySQL). Wenn ich den MySQL-Server neu starte, dann komme keine Loggings mehr und DbLog verbindet sich auch nicht neu. Er kommt dann bei mir nicht über diese Zeile hinaus:

Code Auswählen Erweitern

  $dbh->begin_work();