Hallo Tobias!
Gemäß diesem Thread (http://forum.fhem.de/index.php/topic,18061.msg119695.html#msg119695) hast du schonmal einen Bugfix eingecheckt in Bezug auf dblog und plotfork. Ich nutze mySQL und habe das Problem leider immer noch. Wenn ich Plots öffne sehe ich dass weitere Datenbankverbindungen geöffnet werden, gelogged wird ab dann überhaupt nicht mehr. Habe vor wenigen Tagen noch ein update gemacht, also habe ich eine relativ aktuelle Version.
Grüße,
Markus
Zu dblog gab es heute wieder ein update, ich hab noch nicht genau nachgesehen, was alles geändert wurde.
Das Plotten selbst hat bei mir mit MySQL aber auch bisher problemlos funktioniert.
DBLog in Verbindung mit MySQL funktioniert bei mir auch absolut Problemlos. Nur sobald ich plotfork aktiviere geht alles den Bach runter. Werde das Update mal ausprobieren!
Grüße,
Markus
Habe gerade geupdated -> Das Problem besteht weiterhin.
Grüße,
Markus
Ich kann das Problem hier bestägigen. DBLog mit MySQL und plotfork=1 führt dazu, dass bei Aufruf eines Raums mit Plots weitere DB-Verbindung(en) geöffnet werden und danach nicht mehr geloggt wird. Im Log taucht dann sowas auf:
DBD::mysql::st execute failed: MySQL server has gone away at ./FHEM/93_DbLog.pm line 835.
DBD::mysql::st execute failed: MySQL server has gone away at ./FHEM/93_DbLog.pm line 835.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
2014.03.24 19:58:36.603 3: Connection to db mysql:database=fhem;host=127.0.0.1;port=3306 established for pid 7256
2014.03.24 19:58:36.594 3: Connecting to database mysql:database=fhem;host=127.0.0.1;port=3306 with user fhemuser
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
2014.03.24 19:55:14.630 3: Connection to db mysql:database=fhem;host=127.0.0.1;port=3306 established for pid 7208
2014.03.24 19:55:14.620 3: Connecting to database mysql:database=fhem;host=127.0.0.1;port=3306 with user fhemuser
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
2014.03.24 19:54:49.459 3: Connection to db mysql:database=fhem;host=127.0.0.1;port=3306 established for pid 7205
2014.03.24 19:54:49.448 3: Connecting to database mysql:database=fhem;host=127.0.0.1;port=3306 with user fhemuser
2014.03.24 19:54:46.627 3: Connection to db mysql:database=fhem;host=127.0.0.1;port=3306 established for pid 7204
2014.03.24 19:54:46.618 3: Connecting to database mysql:database=fhem;host=127.0.0.1;port=3306 with user fhemuser
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
2014.03.24 19:54:25.021 3: Connection to db mysql:database=fhem;host=127.0.0.1;port=3306 established for pid 7200
2014.03.24 19:54:25.010 3: Connecting to database mysql:database=fhem;host=127.0.0.1;port=3306 with user fhemuser
2014.03.24 19:53:59.316 3: Connection to db mysql:database=fhem;host=127.0.0.1;port=3306 established
2014.03.24 19:53:59.313 3: Connection to db mysql:database=fhem;host=127.0.0.1;port=3306 established for pid 14157
2014.03.24 19:53:59.304 3: Connecting to database mysql:database=fhem;host=127.0.0.1;port=3306 with user fhemuser
commit ineffective with AutoCommit enabled at ./FHEM/93_DbLog.pm line 1039.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
2014.03.24 19:52:59.463 3: Connection to db mysql:database=fhem;host=127.0.0.1;port=3306 established for pid 7179
2014.03.24 19:52:59.453 3: Connecting to database mysql:database=fhem;host=127.0.0.1;port=3306 with user fhemuser
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
2014.03.24 19:52:44.203 3: Connection to db mysql:database=fhem;host=127.0.0.1;port=3306 established for pid 7177
2014.03.24 19:52:44.193 3: Connecting to database mysql:database=fhem;host=127.0.0.1;port=3306 with user fhemuser
2014.03.24 19:52:40.725 3: Connection to db mysql:database=fhem;host=127.0.0.1;port=3306 established for pid 7173Zitat# $Id: 93_DbLog.pm 5163 2014-03-08 12:20:51Z tobiasfaust $
Also laut der maintainers.txt ist dieses Forum hier das richtige wenn es um dblog geht. Entweder schaut Tobias hier nie rein oder er ignoriert das Thema. Wenigstens ein 'Das steht auf meiner ToDo-Liste' wäre nett gewesen...
Grüße,
Markus
kann bitte einer von euch der mysql verwendet mal probehalber in zweile 760 das $hash->{DBH}->disconnect(); auskommentieren und schauen ob es damit funktioniert ?
gruss
andre
Ich schau hier nicht immer rein. Das ist die korrekte Antwort. Zur zeit gibt es keine Anforderungen einer Weiterentwicklung. Deshalb konsolidiere ich nur Patches bzgl. Bugfixes.
Gesendet von meinem ALCATEL ONE TOUCH 997D mit Tapatalk
Zeile 760 auskommentiert, DbLog neu geladen, plotfork auf 1 gestellt und nach dem Aufruf eines Raums mit Plot erscheint folgendes im Log
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
Danach wird das Loggen eingestellt wie vor dem Auskommentieren.
Zitat von: marvin78 am 27 März 2014, 16:41:37
Zeile 760 auskommentiert, DbLog neu geladen, plotfork auf 1 gestellt und nach dem Aufruf eines Raums mit Plot erscheint folgendes im Log
DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 403.
Danach wird das Loggen eingestellt. Genau wie vor dem Auskommentieren.
Kannst du bitte mal fhem von der Konsole aus starten . Ich wette das nur auf der Konsole die verursachende Fehlermeldung zu sehen ist.
Gesendet von meinem ALCATEL ONE TOUCH 997D mit Tapatalk
Nimm doch mal die ganze Transaktion heraus, diese wird hier nicht benötigt!
Konsole liefert nur den gleichen Fehler wie oben, immer, wenn versucht wird, etwas zu loggen, im Moment des Ausfalls aber nichts.
Die Fehlermeldung weist darauf hin das die vorherige Transaktion nicht korrekt abgeschlossen wurde, also mit einem Fehler abgebrochen wurde. Und diesen Fehler gilt es zu finden.
Gesendet von meinem ALCATEL ONE TOUCH 997D mit Tapatalk
Oder eben dass eine transaktion schreiben will, während die andere noch schreibt.
Versuch doch mal die Transaktion ganz herauszunehmen und vielleicht auch gleichzeitig nur in die history-tabelle zu loggen.
beim plot anzeigen wird nicht geschrieben sondern nur gelesen. das sollte also eigentlich auch mit den transaktionen keine probleme machen.
selbst wenn einzelne transaktionen fehl schlagen sollte nicht irgendwann alles zusammenbrechen.
das ist eher ein symptom als die ursache.
gruss
andre
ich werde am Wochenende mal eine mysql DB aufsetzen und nachschauen was da passiert. Bei SQLITE tritt der Fehler nicht auf.
Das Problem ist ja warscheinlich das die Letzte Transaktion nicht sauber geschlossen wurde. Mal sehen was Udo rausbekommt.
Gesendet von meinem ALCATEL ONE TOUCH 997D mit Tapatalk
Nein, das Problem ist, dass das gesamte Verbinungsmanagement in DbLog etwas durcheinander ist.
Zum Zeitpunkt des ersten Logeintrags nach dem plotfork besteht für den Log-Prozess selbst keine gültige Datenbankverbindung mehr.
Das Problem tritt bei SQLITE nicht auf, weil dabei DBI intern ein anderes (einfacheres) Verbindungsmanagement verwendet wird.
Folgender Patch sorgt dafür, dass eine neue Verbindung für den Log-Prozess aufgebaut wird, falls beim Loggen festgestellt wird, dass keine Verbindung mehr besteht.
Index: 93_DbLog.pm
===================================================================
--- 93_DbLog.pm (Revision 5370)
+++ 93_DbLog.pm (Arbeitskopie)
@@ -388,8 +388,9 @@
################################################################
sub DbLog_Push(@) {
my ($hash, $DbLogType, $timestamp, $device, $type, $event, $reading, $value, $unit) = @_;
- my $dbh= $hash->{DBH};
-
+ my $name = $hash->{NAME};
+ my $dbh = $hash->{DBH};
+
# Daten auf maximale laenge beschneiden
$device = substr($device,0, $columns{DEVICE});
$type = substr($type,0, $columns{TYPE});
@@ -399,8 +400,15 @@
$unit = substr($unit,0, $columns{UNIT});
$dbh->{RaiseError} = 1;
+ $dbh->{PrintError} = 0;
- $dbh->begin_work();
+ eval { $dbh->begin_work() };
+ if ($@) {
+ Log3 ($name, 4, "DbLog $name reconnect due to lost dbh");
+ DbLog_Connect($hash);
+ $dbh = $hash->{DBH};
+ eval { $dbh->begin_work(); };
+ }
my $sth_ih = $dbh->prepare_cached("INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (?,?,?,?,?,?,?)") if (lc($DbLogType) =~ m(history) );
my $sth_ic = $dbh->prepare_cached("INSERT INTO current (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (?,?,?,?,?,?,?)") if (lc($DbLogType) =~ m(current) );
@@ -433,7 +441,9 @@
}
else {
$dbh->commit();
- $dbh->{RaiseError} = 0;
+ $dbh->{RaiseError} = 0;
+ $dbh->{PrintError} = 1;
+
}
return $dbh->{RaiseError};
Im Anhang die komplette 93_DbLog.pm - es wäre schön, wenn mal ein paar der Betroffenen Leute diese Version testen würden.
Funktioniert bei mir. Danke.
Das Fehlverhalten war übrigens auch die Ursache für meine Problembeschreibung vor einiger Zeit hier:
http://forum.fhem.de/index.php/topic,20345.0.html
Mir war damals nur nicht klar, dass es einen Zusammenhang mit den SVG plots geben könnte.
eigentlich sollte es doch auch mögich sein eine lösung zu finden die das handle zum loggen gar nicht weiter anfasst.
wo genau geht es denn schief bzw. warum hat es nicht gereicht nach dem fork das original handle nicht zu schliessen sondern in ruhe zu lassen.
gruss
andre
Das habe ich noch nicht endgültig rausgefunden - bitte Geduld, da bin ich noch dran.
Ich wollte aber gestern zumindest eine Lösung für das akute Problem anbieten,
da ich versprochen hatte mich am Wochenende darum zu kümmern.
Davon abgesehen: Man sollte in einem so kritischen Modul wie dem Logging eigentlich wo immer möglich den Fehlerfall mit einplanen und abfangen.
Die bereits im Modul vorhandene Fehlerbehandlung innerhalb der push-Funktion ist zwar schön, aber sie kommt u.U. viel zu spät.
Zitat von: betateilchen am 31 März 2014, 09:29:16
Davon abgesehen: Man sollte in einem so kritischen Modul wie dem Logging eigentlich wo immer möglich den Fehlerfall mit einplanen und abfangen.
Sehe ich auch so ;-)
Ich erinnere an den Fehler aus diesem Thread, indem dblog beim start "verschwindet", wenn Mysql zum booten länger benötigt als fhem.
http://forum.fhem.de/index.php/topic,18564.msg123788.html
Vielleicht fällt jemandem für diesen Fall auch noch eine Lösung ein.
Zitat von: JoeALLb am 31 März 2014, 09:38:36
Vielleicht fällt jemandem für diesen Fall auch noch eine Lösung ein.
das ist relativ einfach, den Fehler kannte ich noch nicht :)
Das Problem ist tatsächlich recht nervig. Bei mir kommt es beim Cubieboard II immer mal wieder vor, dass bei einem Neustart des Systems mySQL noch nicht bereit steht (obwohl ich entsprechende Maßnahmen ergriffen habe), wenn FHEM schon eine Verbindung herstellen möchte. Das führt immer dazu, dass das DbLog Device komplett gelöscht wird. Im schlimmsten Fall merkt man das nicht, bis man mal wieder explizit danach sucht. Irgendwo im Forum hat mal jemand geschrieben, dass das ein Feature und kein Bug wäre, ich finde den Beitrag aber gerade auf die Schnelle nicht wieder.
kannst Du das nicht einfach im fhem-Startskript lösen?
# Required-Start: $remote_fs $syslog
Dort einfach mysql hinzufügen. Das nennt sich dependency based boot sequencing und sorgt dafür, dass ein Dienst erst dann gestartet wird, wenn die in Required-Start eingetragenen Dienste verfügbar sind.
Achtung: die # am Anfang der Zeile ist hier KEIN Kommentarzeichen!
Naja. Das habe ich gemacht. Hin- und wieder (es ist sehr selten und ich weiß nicht warum) passiert es trotzdem. Ich hatte aber auch noch keine Zeit, mich näher mit den Gründen zu befassen.
Aber selbst wenn man das im Griff hat, sollte es kein normales Verhalten sein, dass das Device mit allen Attributen einfach gelöscht wird, nur weil keine Verbindung hergestellt werden kann.
Zitat von: betateilchen am 31 März 2014, 14:35:55
kannst Du das nicht einfach im fhem-Startskript lösen?
# Required-Start: $remote_fs $syslog
Dort einfach mysql hinzufügen. Das nennt sich dependency based boot sequencing und sorgt dafür, dass ein Dienst erst dann gestartet wird, wenn die in Required-Start eingetragenen Dienste verfügbar sind.
Achtung: die # am Anfang der Zeile ist hier KEIN Kommentarzeichen!
Das habe ich mit meiner PostGreSql-DB damals auch so gemacht... Seitdem nie wieder gelöschte DbLog-Devices...
Zitat von: marvin78 am 31 März 2014, 14:40:22
Aber selbst wenn man das im Griff hat, sollte es kein normales Verhalten sein, dass das Device mit allen Attributen einfach gelöscht wird, nur weil keine Verbindung hergestellt werden kann.
ja, aber das ist strategisch. Die Sache mit dem Startskript ist taktisch :P
Das Device wird übrigens nicht gelöscht, sondern einfach nicht angelegt. Gelöscht wird es erst beim nächsten "save config" 8)
Mit configDB übrigens kein Problem, weil die Versionierung dafür sorgt, dass Du die vorherige Version wiederherstellen kannst, in der auch das DbLog Device noch vorhanden ist.
Also für mich ist es ohnehin kein Problem (eher was nervendes) weil ich ja configDB nutze (wobei das schon ein Problem sein kann, wenn mySQL noch nicht da ist, wenn fhem startet ;)). Mir geht es um das grundsätzliche Verhalten was, meiner Ansicht nach, nicht korrekt ist.
Es gibt genug Gründe, warum DBLog nicht gelöscht werden sollte, aber dass ein Workaround hilfreich ist, ist natürlich auch logisch.
Beispielsweise wurde bei mir letztens DBLog beim Start gelöscht, als MySQL die Datenbank reindiziert hat und deshalb nicht (schnell genug) geantwortet hat.
Zitat von: JoeALLb am 31 März 2014, 15:35:10
Beispielsweise wurde bei mir letztens DBLog beim Start gelöscht, als MySQL die Datenbank reindiziert hat
jepp, das ist einer der Fälle, in denen das Required-Start nicht weiterhilft, weil der Dienst ja komplett gestartet ist (sonst könnte die Reindexierung nicht laufen)
Zitat von: justme1968 am 31 März 2014, 00:55:39
warum hat es nicht gereicht nach dem fork das original handle nicht zu schliessen sondern in ruhe zu lassen.
Weil es überhaupt keine unterscheidbaren Handles gibt...
Anders gesagt: Völlig egal, ob Du ein disconnect() überhaupt verwendest oder nicht, die Verbindung wird vom fork kontrolliert und nicht von DbLog. Du kannst das Testen, indem Du alle disconnects im Modul auskommentierst - es wird das Fehlerverhalten nicht beeinflussen. Die einzige Chance ist die jetzt eingebaute Fehlerbehandlung.
Ob das Ganze jetzt MySQL spezifisch ist, kann ich noch nicht beurteilen. WIe schon gesagt: SQLITE ist davon nicht betroffen. Und Postgre hab ich nicht im Einsatz.
die erklärung kann aber nicht nicht ganz vollständig sein.
wie kann die lib im parent mit bekommen das es ein fork gab und wie kann etwas das nur im child passiert die connection im parent beeinflussen. und selbst wenn es das über die conenction irgendwie schafft sollte es spätestens dann funktionieren wenn man das disconnect weg lässt. spätestens dann gibt es keinen unterschied mehr zu mehreren connections aus unterschiedlichen prozessen. und das kann sogar mysql.
irgendetwas stimmt da immer noch nicht glaube ich.
Zitat von: justme1968 am 31 März 2014, 20:53:15sollte es spätestens dann funktionieren wenn man das disconnect weg lässt.
Tut es aber nicht - probiers aus, wenn Du es nicht glaubst.
Zitat von: justme1968 am 31 März 2014, 20:53:15spätestens dann gibt es keinen unterschied mehr zu mehreren connections aus unterschiedlichen prozessen.
Theoretisch...
Zitat von: justme1968 am 31 März 2014, 20:53:15und das kann sogar mysql.
Mag sein, dass MySQL das kann.
Die Frage ist aber, ob die DBD / DBI das kann, so weit in die Tiefe bin ich nicht gegangen.
Am DbLog Modul liegt es nach meinen Tests und der daraus gebildeten Meinung nicht.
ich glaube dir :)
das bedeutet aber nicht das ich das verhalten verstehe oder sogar sage das es so korrekt ist :)
Ich habe auch nirgends behauptet, dass das Verhalten korrekt sei. Aber ich habe keine große Lust, perl Module ausserhalb von fhem zu debuggen.
Der vorgeschlagene Patch behebt das Problem recht zuverlässig, den anderen offenen Punkt (DbLog wird nicht gestartet, wenn MySQL wegen Auslastung noch nicht verfügbar) solle man separat betrachten.
Wenn der Patch soweit io ist kann ich ihn einchecken. Sagt Bescheid.
Gesendet von meinem ALCATEL ONE TOUCH 997D mit Tapatalk
Der Patch hängt in meinem Beitrag von Sonntag.
Zitat von: JoeALLb am 31 März 2014, 15:35:10
Es gibt genug Gründe, warum DBLog nicht gelöscht werden sollte, aber dass ein Workaround hilfreich ist, ist natürlich auch logisch.
Beispielsweise wurde bei mir letztens DBLog beim Start gelöscht, als MySQL die Datenbank reindiziert hat und deshalb nicht (schnell genug) geantwortet hat.
Im Developer-Bereich habe ich gerade eine Modulversion gepostet, die auch mit noch nicht existierenden Datenbankverbindungen zurechtkommen sollte.
http://forum.fhem.de/index.php/topic,20847.msg154874.html#msg154874
Hallo,
ich weiß nicht recht ob ich hier richtig bin. Bei Bedarf bitte verschieben.
Mein Problem: DBLog nach Neustart des GANZEN Servers mit MySQL (auf QNAP NAS).
Fehler:
"Error messages while initializing FHEM:
configfile: Can't connect to database."
LogFile:
2014.05.22 00:52:48 3: Connecting to database mysql:database=fhem;host=localhost;port=3306 with user fhem
2014.05.22 00:52:48 3: Connection to db mysql:database=fhem;host=localhost;port=3306 established for pid 5671
2014.05.22 00:52:48 3: Connection to db mysql:database=fhem;host=localhost;port=3306 established
UND:
XML-Verarbeitungsfehler: Kein Element gefunden
Adresse: http://10.255.255.5:8083/fhem/SVG_showLog?dev=PLOT_Kurse&logdev=KurseLOG&gplotfile=PLOT_Kurse&logfile=history&pos=
Zeile Nr. 2, Spalte 1:
Ratlos...
Viele Grüße,
Johannes
Johannes,
ich würde sagen das du den FHEM Start nicht vom DB-Start abhängig gemacht hast. Da fehlen bei dir die Abhängigkeiten im FHEM-Startscript
oder Du hast in deiner Konfiguration die SVG plots vor dem DbLog definiert.
Hallo,
@betateilchen: die Reihenfolge ist korrekt
@Tobias: # Required-Start: xxx
Wo ist diese Abhängigkeit einzustellen?
In meinem Start- Script ist so etwas (noch?) nicht vorhanden.
Zur Erklärung: Alles läuft auf einem QNAP-NAS mit Optware.
Der Fehler tritt auch nur nach einem Reboot des Gesamtsystems auf
(welchen ich einmal in der Woche machen muß, sonst vergißt mein
NAS externe Geräte wie USV etc...)
Mache ich bei laufendem (NAS-) System einen "Shutdown Restart",
werden mir die Grafiken wieder angezeigt.
Es sieht mir so aus, daß fhem bzw. SVG-PLOT beim Start nicht auf mysql wartet.
Im Logfile sehe ich ja den mißlungenen Verbindungsaufbau, aber später steht
da ja "Connection established".
Nur im Frontend bekomme ich keine Grafik. Stoße ich dann einen "Shutdown Restart"
an, klappt es wieder mit der Anzeige.
Habe ich was übersehen bzgl. derStart- Reihenfolge oder sollte mein NAS nach dem Neustart
so sehr mit mysql (oder mysql selbst) beschäftigt sein?
Oder soll ich einen cron- Job einrichten, der dann fhem nochmal neu startet?
Ich meine mich erinnern zu können daß das Anfang April oder so mal reibungslos lief...
Hat wer eine solche Konstellation und eine Lösung?
Viele Grüße,
Johannes
Ich schließe mich hier mal mit an da ich nachdem ich heute auf meinem PI2 auf Plotfork umgestellt habe wegen langsamer Ploterstellung
http://forum.fhem.de/index.php/topic,45296.msg375358.html#msg375358
Seit dem Zeitpunkt der Umstellung wird nichts mehr geloggt, habe dann FHEM neu gestartet und es wurde wie es ausschaut ein Datensatz geloggt und danach dann wieder nichts mehr.
Den Bugfix von hier einzuspielen wird wohl nach über einem Jahr nichts bringen zumal sich die 93_DbLog ja weiterentwickelt hat und ich auch vermute das der Bugfix schon eingearbeitet wurde.
Ich bin jetzt vom PI2 auf einen Intel NUC (4 x 1,6 GHz mit 8 GB RAM und SSD) umgezogen und Plotfork funktioniert auch dort auf dem frisch aufgesetzten Debian (stable) nicht
Plotfork hat bei mir nie richtig funktioniert (MySQL). Ich habe schnell aufgehört, mich damit zu beschäftigen. Das bringt nur Frust. Mit der Maschine (NUC) wirst du das allerdings auch nicht benötigen. Der sollte die Plots so schnell raus hauen, dass du gar nicht so schnell schauen kannst.
Wenn das nicht der Fall sein sollte, loggst du deutlich zu viel und dann würde ich an dieser Stelle ansetzen (event-on-change-reading, DbLogExclude, Regex in der DEF von DbLog etc.)).
29 Readings auf einer Seite mit Werten im Minutentakt (siehe oben) sind ~15 Millionen Datensätze bei der Jahresansicht, wenn ich mich nicht verrechnet habe. Da wird auch einen NUC ins schwitzen kommen ;)
Ich sage ja, dann wird zu viel geloggt bzw. man müsste ausdünnen. Ich frage mich, von welchen Daten man Werte im Minutentakt benötigt und das auch noch über mehr als ein Jahr hinweg!? Plotfork wird nicht die Lösung sein. Der Tag an dem das funktioniert ist noch in keinem Kalender ;)
Zitat von: dev0 am 17 Dezember 2015, 16:04:14
29 Readings auf einer Seite mit Werten im Minutentakt (siehe oben) sind ~15 Millionen Datensätze bei der Jahresansicht, wenn ich mich nicht verrechnet habe. Da wird auch einen NUC ins schwitzen kommen ;)
Man kann auch viel an MySQL drehen ;-) Ich arbeite beispielsweise gerade mit Partitionen und einem anderen Index.
[OFFTOPIC]
Im Gegensatz zum PI gehts jetzt mit dem NUC (um 18:00 Uhr) auch ohne plotfork,
4 Readings in einem SVG im Minutentakt in 2 Sekunden
10 SVGs mit insgesamt
4 x 5 Readings
1 x 2 Readings
3 x 1 Readings
also 25 Readings im Minutenabstand in 15 Sekunden
Load Average beim NUC während der Erstellung der 25 Readings war 0,30
DbLogExclude ist schon drin (sollte aber beim Auslesen der Daten egal sein da darauf ja kein Select gemacht wird)
event-on-change-reading kommt noch rein, muss mich da noch einlesen wie das geht das zumindest im Plot immer der letzte Wert angezeigt wird auch wenn er nicht geloggt wurde
@JoeALLb
welchen Index ? Ich habe einen Index auf TIMESTAMP, DEVICE und READING
ansonsten immer her mit Deinen Infos :)
[/OFFTOPIC]
ansonsten wäre es schön wenn es trotzdem mit plotfork funktionieren würde ^^
Zitat von: Afterburner am 17 Dezember 2015, 18:45:03
DbLogExclude ist schon drin (sollte aber beim Auslesen der Daten egal sein da darauf ja kein Select gemacht wird)
event-on-change-reading kommt noch rein, muss mich da noch einlesen wie das geht das zumindest im Plot immer der letzte Wert angezeigt wird auch wenn er nicht geloggt wurde
Weniger Daten in der DB -> schnellere Plots. Das kann man einsehen, muss man aber nicht. Und hierbei ist es nicht (nur) entscheidend, ob die entsprechenden Daten auch im Log autauchen. Es muss ja die komplette DB (oder der Index) durchsucht werden.
Es kann auch helfen, mehrere DBLog Instanzen (verschiedene DBs) zu verwenden. Ich logge beispielsweise Daten, die ich längerristig benötige (Temperatur, Energie) in eine andere DB als die die ich nach 35 Tagen weg werfen kann, weil sie danach uninteressant werden.
Jedes einzelne Event zu loggen, macht weder Sinn, noch ist es der Performance zuträglich (sowohl beim loggen, als auch beim Anzeigen).
Also beim SELECT stimme ich Dir allgemein gesehen nur bedingt zu
Einfach mal nen Select über 4 Spalten aus der DB meines Forums (3 GB) so das möglichst viele Einträge erscheinen
SELECT * FROM `wbb42_1_post` WHERE `parentPostID` = 0 AND `userID` >= 0 AND `message` != 'sfhsajfhsajfhsahfa' AND `time` >= 0
Zeige Datensätze 0 - 24 (3211818 insgesamt, Die Abfrage dauerte 0.0012 Sekunden.)
Ich glaube die 0.0012 Sekunden sind da zu vernachlässigen, die dann aufzuarbeiten ist natürlich ein anderes Thema genau wie die Größe der DB die mit mehr (unnützen) Daten immer weiter anschwillt aber hier ging es ja nur im den Select
In FHEM (122 MB) sieht es etwas anders aus
SELECT * FROM `history` WHERE `TIMESTAMP` > '2015-12-17 00:00:00' AND `DEVICE` = 'Heizung.Badezimmer' AND `READING` = 'temperature' ORDER BY `TIMESTAMP` DESC
Zeige Datensätze 0 - 24 (984 insgesamt, Die Abfrage dauerte 0.3415 Sekunden.)
Ist da halt schon um einiges langsamer, warum habe ich noch nicht raus gefunden, eine fehlender PRIMARY Key spielt da sicherlich auch irgendwie eine Rolle, auch den TIMESTAMP als unixtimestamp zu speichern könnte meiner Meinung nach die Abfragen ein wenig beschleunigen. (auf jeden Fall wird die Datenbank minimal kleiner :D :D :D )
Dem Device könnte man auch statt dem Namen eine Nummer geben für den DB Einträge, evtl auch dem TYPE sofern darauf eine Abfrage gemacht wird (der hat bei mir nämlich noch keinen Index bekommen)
Heizung.Badezimmer = 12
SELECT * FROM `history` WHERE `TIMESTAMP` > '1450306800' AND `DEVICE` = '12' AND `READING` = 'temperature' ORDER BY `TIMESTAMP` ASC
wäre vermutlich etwas schneller
Das Problem ist das dies mit dem flexiblen Aufbau von FHEM nicht so ganz funktionieren würde, aber wobei wenn ich den Device Namen in der FHEM Config ändere wird die Datenbank ja auch nicht geändert.
Theoretisch könnte man das Ganze auch automatisieren mit einer "Device Config DB" beim Start von FHEM oder beim hinzufügen von Geräten
SELECT device_id from DEVICES WHERE device_name = 'Heizung.Badezimmer'
if ($result['device_id']){
attr Heizung.Badezimmer devid $result['device_id']
}else{
INSERT INTO DEVICES .....
attr Heizung.Badezimmer devid mysql_insert_id();
}
ob es allerdings was bringt ist schwer zu sagen
DbLog ist alles andere als perfekt. Wir könnten jetzt hier über Datenbankstrukturen diskutieren, ändern damit aber nichts daran, dass DbLog so ist, wie es ist. In MySql kann man noch einiges selbst machen (partitionen und ein wenig an den Indizes schrauben kann hier nicht schaden). Es bleibt aber dabei: Es ist sonnlos, jedes Event zu loggen (gerade bei HM-Devices).
Ich habe etwa 300 Devices die Log-Daten produzieren (in verschiedene DBs) und eine meiner DBs hat mehrere Gigabyte an Daten. Es sind jeweils nur die Events darin geloggt, die ich auch benötige. Mein NUC lacht darüber beim anzeigen von 30 Plots auf einer Seite ;)
Aber es ist zumindest interessant sich darüber zu unterhalten ^^
Ich habe gerade mal ein EXPLAIN gemacht auf
EXPLAIN SELECT DATE_FORMAT(TIMESTAMP, '%Y-%m-%d %H:%i:%s'), DEVICE, READING, VALUE FROM history WHERE 1=1 AND DEVICE = 'Heizung.Schlafzimmer' AND READING = 'temperature' AND TIMESTAMP >= STR_TO_DATE('2015-12-15 09:00:00', '%Y-%m-%d %H:%i:%s') AND TIMESTAMP < STR_TO_DATE('2015-12-16 09:00:01', '%Y-%m-%d %H:%i:%s') ORDER BY TIMESTAMP
was wohl das Format der Abfragen in FHEM sein soll
id select_type table type possible_keys key key_len ref rows Extra
1 SIMPLE history index_merge DEVICE,TIMESTAMP,READING READING,DEVICE 34,52 NULL 11353 Using intersect(READING,DEVICE); Using where; Using filesort
was mich jetzt wundert ist das TIMESTAMP nicht genutzt wird obwohl es die größte Kardinalität hat, in dem Fall könnte ich den Index zu TIMESTAMP ja theoretisch wieder löschen
Nun. Eigentlich erscheinen deine Indizes nicht so, wie vorgeschlagen. Es sollte eigentlich einen kombinierten Index "Search_idx" über die 3 Spalten TIMESTAMP, DEVICE und EVENT geben.
Also ich habe bisher nur 3 einzelne Indexe angelegt da das ja aber MySQL 5 wohl egal sein soll oder habe ich da was falsch verstanden ?
Wenn ein Index über 3 dann sollte die Reihenfolge dann nicht
DEVICE_READING_TIMESTAMP
sein ?
Ich habe gerade das Query mal umgedreht und TIMESTAMP an den Anfang direkt hinter WHERE verschoben ?
aber trotzdem nutzt MySQL nur die Indexe READING,DEVICE
Du hast Recht. Ich habe oben nicht die richtige Reihenfolge aufgeschrieben. Mir ging es nur um den kombinierten Index. Ich habe mich auch boß gewundert, es sollte tatsächlich bei MySQl 5 egal sein. Hier kann man mal ein wenig spielen und messen.
Also es scheint in MySQL wohl doch nicht egal zu sein, habe gerade einen Index über die 3 Spalten erstellt und siehe da
Zeige Datensätze 0 - 24 (1288 insgesamt, Die Abfrage dauerte 0.0052 Sekunden.)
Auf jeden Fall eine Steigerung um mehrere 100 Prozent
Also hier die Anleitung wie es geht (in PhpMyAdmin)
1. In die Tabelle "history" gehen
2. dort auf "Struktur" klicken
3. weiter unten auf "+ Indizes" klicken
4. bei Index über: 3 auswählen
5. auf OK klicken
6. Bei Indexname: DEVICE_READING_TIMESTAMP eintragen
7. Bei Indextyp: INDEX auswählen
8. Die Spalten in folgender Reihenfolge auswählen
- DEVICE
- READING
- TIMESTAMP
9. auf OK klicken und sich freuen ^^
Oder von vornherein die Tabellen-Vorlagen verwenden, die dem FHEM Paket beiliegen(SQL-Datei) ;)
Das lag mir gerade auch auf der Zunge ;)
Ich hatte die Tabelle ganz brav nach dem Wikieintrag angelegt
http://www.fhemwiki.de/wiki/DbLog#Beispiel:_Anlegen_und_Nutzung_einer_SQLite-Datenbank
allerdings DEVICE varchar(32) auf DEVICE varchar(50) geändert
war zwar auf SQLite bezogen aber die Struktur ist ja die Selbe
@all
ich lasse mich ja gerne in der Luft zerreißen aber wo habt ihr denn mitgelieferte Tabellen in FHEM her ?
Mehr als Wiki lesen kann ich ja nicht
auch in der
....fhem/docs/commandref.html#DbLog
steht dazu nichts
arg ... man sollte auch mal den Text lesen und nicht nur die Befehle 7 Struktur
Die Vorlagen zur Anlage von Tabellen und Indizes sind für jeden unterstützten Datenbanktyp im Verzeichnis contrib/dblog der FHEM-Installation, oder hier zu finden: Link. Das MySQL-Skript (db_create_mysql.sql) legt eine neue Datenbank, das PostGres-Skript (db_create_postgresql.sql) ein neues Schema mit Namen "fhem" an.
Wikis haben so ihre Vor- und Nachteile. Das hier ist ein Nachteil: Es darf dort jeder schreiben und dabei kann auch mal was fehlen oder es kann auch Fehler geben.
Die SQL Dateien liegen in /contrib/dblog. Das steht in der commandref zu DbLog (was die erste Anlaufstelle für Infos ist).
Also in der commandref finde ich nur das
ZitatDefine
define <name> DbLog <configfilename> <regexp>
Log events to a database. The database connection is defined in <configfilename> (see sample configuration file contrib/dblog/db.conf). The configuration is stored in a separate file to avoid storing the password in the main configuration file and to have it visible in the output of the list command.
was annähernd dazu passen könnte ... aber egal, Problem beseitigt :)
EDIT Doppelpost