[Behoben] Schwer zu lokalisierender Fehler in FHEM / vermutlich DbLog+plotfork

tobox · 17 April 2019, 16:46:13

Hallo liebe FHEM-User,

ich betreue mehrere FHEM-Instanzen und habe aktuell ein Problem, bei dem ich einfach nicht weiter komme. Bei einer FHEM-Installation lassen sich die Webseiten von 2 Räumen nicht aufrufen, da irgendwas bei der Erstellung der SVG-Logs abstürzt. Das Problem ist reproduzierbar, die Seiten gehen nie (alle anderen Räume und Grafiken funktionieren).

Im Kernel-Log der FHEM-Servers findet man bei jedem fehlgeschlagenen Zugriff eine der folgenden Zeilen (die Zahlen variieren):

Code Auswählen

perl[30313]: segfault at a8 ip 00007f8f81aa3cc2 sp 00007ffc38285730 error 4 in libmariadb.so.3[7f8f81a97000+21000]

perl[487]: segfault at 55a41928df60 ip 000055a41928df60 sp 00007ffc055e8a18 error 15

perl[24795]: segfault at 7fb511f01dd0 ip 00007fb511f01dd0 sp 00007ffc6e485618 error 15 in libc-2.28.so[7fb511f01000+2000]

traps: perl[25520] general protection ip:7fb51160bcba sp:7ffc6e485620 error:0 in libmariadb.so.3[7fb5115ff000+21000]

Ich habe dann mal ein Trace mit folgendem Aufruf erzeugt (FHEM ist dann unbedienbar langsam, und es entstehen innerhalb von Minuten 100MB Logfiles):

Code Auswählen

perl -d:Trace fhem.pl fhem.cfg

So richtig schlau bin ich aus dem Logfile nicht geworden, ich kann es gerne irgendwo bereitstellen. Die letzten Zeilen aus DbLog.pm sind übrigens folgende:

Code Auswählen

>> /opt/fhem/FHEM/93_DbLog.pm:2622:   Log3 $name, 4, "DbLog $name -> ################################################################";
>> /opt/fhem/FHEM/93_DbLog.pm:2623:   Log3 $name, 4, "DbLog $name -> ###                  new get data for SVG                    ###";
>> /opt/fhem/FHEM/93_DbLog.pm:2624:   Log3 $name, 4, "DbLog $name -> ################################################################";
>> /opt/fhem/FHEM/93_DbLog.pm:2625:   Log3($name, 4, "DbLog $name -> main PID: $hash->{PID}, secondary PID: $$");
>> /opt/fhem/FHEM/93_DbLog.pm:2627:   $dbh = $hash->{DBHP};
>> /opt/fhem/FHEM/93_DbLog.pm:2628:   if ( !$dbh || not $dbh->ping ) {

Kann da irgendjemand was schlaues zu sagen?

Serverinfos:

Debian Testing, aktuell.

FHEM ist gerade geupdatet, also aktuell, Fehler ist aber schon seit mehreren Monaten da.

Code Auswählen


perl           5.28.1-6 

ii  libmariadb3:amd64          1:10.3.13-2  amd64        MariaDB database client library
ii  mariadb-client-10.3        1:10.3.13-2  amd64        MariaDB database client binaries
ii  mariadb-client-core-10.3   1:10.3.13-2  amd64        MariaDB database core client binaries
ii  mariadb-common             1:10.3.13-2  all          MariaDB common metapackage
ii  mariadb-server             1:10.3.13-2  all          MariaDB database server (metapackage depending on the latest version)
ii  mariadb-server-10.3        1:10.3.13-2  amd64        MariaDB database server binaries
ii  mariadb-server-core-10.3   1:10.3.13-2  amd64        MariaDB database core server files

Bin über jeden Hinweis dankbar.

DS_Starter · 17 April 2019, 21:24:19

Hallo tobox,

ich habe die Meldung jetzt längere Zeit angeschaut und etwas gegoogelt.
Für mich sieht es momentan danach aus, dass es wohl einen Fehler in der libmariadb.so.3 Library gibt die DbLOg natürlich verwendet. Soviel ich gelesen habe, tritt das Problem in einer reconnect-Situation zu Tage.
Allerdings habe ich noch keinen Hinweis gelesen der exakt dein verwendetes Library-Release erwähnt, aber das würde auch zur Absturzstelle

Zitat
>> /opt/fhem/FHEM/93_DbLog.pm:2627: $dbh = $hash->{DBHP};
>> /opt/fhem/FHEM/93_DbLog.pm:2628: if ( !$dbh || not $dbh->ping ) {

passen, sofern es das letzte ist du von DbLog im Log siehst.
Also lösen kann ich das Problem nicht, ich denke es wird mit einem update der Perl Datenbank-Treiber verschwinden.

Was ich allerdings versuchen kann, ist den Reconnect an dieser Stelle für MariaDB anders zu gestalten und so evtl. einen Workaround zu erstellen. Käme auf einen Versuch an.
Melde mich wieder.

Grüße,
Heiko

tobox · 17 April 2019, 21:30:02

Hallo Heiko,

vielen Dank schonmal für die Antwort. Ich habe natürlich auch schon viel gegoogelt, aber konkret zu den libmariadb-segfaults war auch nichts passendes zu finden. Ich werde mal weiter debuggen, und Teile mit dem Funktionierenden Instanzen tauschen und schauen, wann der Fehler mitwandert.

LG
Thomas

DS_Starter · 17 April 2019, 23:06:10

Ich habe dir eine Testversion in meinem contrib bereitgestellt.

https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter (Downloadbutton benutzen)

In der Version sind auch die Änderungen drin die du hier lesen kannst:
https://forum.fhem.de/index.php/topic,65860.msg930539.html#msg930539

Versuche mal dein Glück.

Grüße,
Heiko

DS_Starter · 18 April 2019, 00:10:15

Jetzt fällt mir noch etwas auf

Zitat
Serverinfos:

Debian Testing, aktuell.

Setzt du tatsächlich die Debian Development Version ein ?
Würde ich nicht machen und nur auf "stable" setzen.

LG

tobox · 18 April 2019, 07:59:49

So, mein Debugging letzte Nacht war erfolgreich. Nachdem ich die gesamte Datenbank auf einen anderen Server übertragen und die Plots dort in FHEM eingebunden hatte, war der Fehler verschwunden. Dann habe ich das ganze Setup umgezogen: Fehler wieder da.

Im Endeffekt ließ es sich darauf eingrenzen, dass folgendes gesetzt war:

Code Auswählen

attr WEB_Main plotfork 1

Jetzt wo ich danach suche, scheinen solche Probleme auch schon andere gehabt zu haben. Wenn das Problem bekannt ist und man DbLog nicht zusammen mit Plotfork benutzen darf, dann sollte FHEM das vielleicht erkennen und eine Warnung/Fehlermeldung bringen. Denn diesen Fehler zu debuggen ist für normaluser praktisch unmöglich.

Trotzdem danke fürs mithelfen!

DS_Starter · 18 April 2019, 08:28:24

Guten Morgen,

plotfork für sich genommen kann nicht das Problem sein.
Ich verwende auf allen Instanzen mit den verschiedenen Datenbanken Plotfork und da gibt es kein Problem.
Wohl aber wird dadurch ein reconnect forciert, was wiederum den lt. meinen Recherchen dem verwendeten Treiber zuzuschreibenden Problem förderlich ist.
Also diese Schlussfolgerung kann man so allein nicht stehen lassen.
Hast du denn mal die Testversion mal verwendet ?

Grüsse,
Heiko

tobox · 18 April 2019, 10:24:19

Hallo Heiko,

Zitat von: DS_Starter am 18 April 2019, 08:28:24
Hast du denn mal die Testversion mal verwendet ?

habe eben Plotfork wieder reingemacht: Fehler wieder da (hätte mich sonst auch gewundert).

Dann Deine Testversion eingespiel: Fehler weg.

Du bist mein Held

Deine Kaffeekasse klingelt

Danke für's fixen!

DS_Starter · 18 April 2019, 10:33:56

Ich freue mich

... über beides !
Ich lasse die Testversion noch eine Weile im contrib zum Test.
Möchte gern noch Rückmeldungen von anderen Testern wegen eventueller Nebeneffekte haben.
Du kannst auch gerne mal auf den bulkInsert umschalten und deine Erfahrung damit teilen.
Hat jetzt nichts mit dem Problem zu tun sondern der allgemeinen Weiterentwicklung.

Danke nochmal und schöne Ostern !
Heiko