93_DbLog - Umstellung Log-Funktion auf non-blocking

[DS_Starter]

Wenn Fragen auftauchen oder z.B. Einheiten fehlen, bitte bevorzugt hier im Thread öffentlich darüber diskutieren, damit alle was davon haben. PM ist sonst so eine Einzelgeschichte

Machen wir so .... danke für die Erläuterungen. 

schönen Abend,
Heiko

[Pyromane]

Version 2.4 läuft seit einer Wocher unter Postgresql und auch Sqlite ohne Auffälligkeiten.

[DS_Starter]

Hallo miteinander,

kurz Rückmeldung auch bei mir.
Die letzte Version 2.5 läuft nun bereits etliche Tage problemlos auf meinen beiden MariaDB/MySQL-Instanzen.

Momentan habe ich eine weitere Version im Test.
Ausgehend von der V2.5 habe ich DbLog um eine asynchrone Loggingmöglichkeit erweitert.

Was heißt das ?
Die neue Version kann zunächst unverändert zur V2.5 genutzt werden, d.h. die Events werden synchron als Bulkinsert in die DB geschrieben.
Mit einem neuen Attribut "asyncMode=1" kann auf den asynchronen Modus umgeschaltet bzw. zwischen beiden Modi geswitcht werden.

Die Merkmale des asynchronen Modus sind folgende:

* Die auftretenden und bewerteten Events werden nicht mehr direkt in die DB geschrieben, sondern zunächst im Speicher gecacht.
  Die gecachten Events können mit dem neuen Befehl "set ... listCache" angezeigt werden.
  Es wird ein Reading "CacheUsage" mit der Anzahl der augenblicklich im Speicher gehaltenen Events erzeugt.
  D.h. die Notify-Funktion DbLog_Log ist sehr schnell und wird nicht mehr durch die DB-Zugriffszeit beeinflußt.
 
* Abhängig vom Attribut "syncInterval" werden die im Speicher gecachten Events in die DB wiederum als Bulkinsert weggeschrieben.
  Ist die DB nicht erreichbar, verbleiben die Events im Cache und werden im nächsten Zyklus gespeichert sofern die DB dann
  erreichbar ist. Das Default-Syncinterval ist 30 Sekunden.
  Es wird das Reading "NextSync" mit dem Zeitpunkt des nächsten Synclaufes erzeugt.
  Für diese Technik verwende ich wieder BlockingCall, der sich m.M. nach nun gut entgegen dem ersten Anlauf
  verwenden lässt da der Aufruf in dem Kontext relativ selten erfolgt, der DB-Zugrif als Bulkinsert passiert und nur ein
  Insertprozess gleichzeitig läuft was den Restriktionen von SQLite Rechnung trägt.
 
* wird vom asynchronen Modus in den synchronen Modus geswitcht, werden die im Cache gehaltenen Events sofort in die DB weggeschrieben.

* Wenn FHEM mit "shutdown ..." heruntergefahren bzw. restartet wird, werden die noch im Cache gehalteten Events in die DB weggeschrieben.
  Es gibt im DBLog schon immer das Attribut "shutdownWait" was eine Wartezeit beim shutdown zum Zweck einer ordnungsgemäßen Beendigung
  der DB-Verbindung bweirkt. Dieses Attr sollte gesetzt sein. Ich habe gute Erfahrungen mit einem Wert von 2s gemacht. Damit wurden
  bisher alle gecachten Events problemlos noch in die DB geschrieben bevor FHEM endete.
 
Das ist der momentane Entwicklungsstand bei mir. Er befindet sich zur Zeit in der Testphase und es sieht richtig gut aus .
Sobald es bei mir fehlerfrei läuft, stelle ich die neue Version hier wieder zur Verfügung. Es dürfte diese Woche noch soweit sein.

Wenn die eben beschriebene Version gut getestet ist, sehe ich folgende weiteren Schritte:

Es werden die Events bei Nichtverfügbarkeit der DB zunächst aus dem Cache asynchron non-blocking in eine File-basierende DB geschreiben um
einerseits bei längerem DB-Ausfall den Memory nicht zu sehr zu belasten und andererseits die Events bei einem FHEM-Absturz
nicht zu verlieren (sofern es sich um einen längeren DB-Ausfall handelt). Wird die DB irgendwann wieder verfügbar sein, werden die
Events aus der File-DB in die richtige DB übertragen und im File gelöscht.
Desweiteren wäre es noch möglich das eingangs erwähnte SubProcess.pm statt Blocking zu verwenden bzw. Rudis Hinweis aus #1 umzusetzen.

Allen ein gutes neues Jahr !

viele Grüße
Heiko

[JoeALLb]

* Die auftretenden und bewerteten Events werden nicht mehr direkt in die DB geschrieben, sondern zunächst im Speicher gecacht.
  Die gecachten Events können mit dem neuen Befehl "set ... listCache" angezeigt werden.
  Es wird ein Reading "CacheUsage" mit der Anzahl der augenblicklich im Speicher gehaltenen Events erzeugt.
  D.h. die Notify-Funktion DbLog_Log ist sehr schnell und wird nicht mehr durch die DB-Zugriffszeit beeinflußt.

[...] 
en die Events bei Nichtverfügbarkeit der DB zunächst aus dem Cache asynchron non-blocking in eine File-basierende DB geschreiben um
einerseits bei längerem DB-Ausfall den Memory nicht zu sehr zu belasten und andererseits die Events bei einem FHEM-Absturz
nicht zu verlieren (sofern es sich um einen längeren DB-Ausfall handelt). Wird die DB irgendwann wieder verfügbar sein, werden die
Events aus der File-DB in die richtige DB übertragen und im File gelöscht.

Ein Traum wird wahr!! Vielen Dank dafür! Damit kann ich auch die Speicherkarte am RPI, die nicht so viele Speicherzugriffe abbekommen sollte, endlich noch besser entlasten!

[Tobias]

Heiko, ich bin beeindruckt

[justme1968]

das klingt klasse !

gruss
  andre

[PatrickR]

Großartig!


Von unterwegs gesendet.

[Wuppi68]

WoW

[DS_Starter]

Hallo miteinander,

Nun habe ich die neue Version V2.8.1 auf meinen MariaDB/MySQL Instanzen und auch auf einer SQLite getestet. Läuft bei mir tadellos.
Sie ist hier zum Test angehängt.

Wenn ihr die neue Version einspielt und FHEM restartet ! ist die Arbeitsweise zunächst unverändert zur letzten Version V2.5, d.h. die
Events werden synchron mit Bulk-Insert in die DB geschrieben.

Mit einem neuen Attribut "asyncMode=1" kann nun auf den asynchronen Modus umgeschaltet bzw. zwischen synchronen/asynchronen Modus geswitcht werden.

Die Merkmale des asynchronen Modus und weiteren Änderungen hier nochmal zusammengefasst:

* Die auftretenden und bewerteten Events werden nicht mehr direkt in die DB geschrieben, sondern zunächst im Speicher gecacht.
  Die gecachten Events können mit dem neuen Befehl "set ... listCache" angezeigt werden.
  Es wird ein Reading "CacheUsage" mit der Anzahl der augenblicklich im Speicher gehaltenen Events erzeugt.
  D.h. die Notify-Funktion DbLog_Log ist sehr schnell und wird nicht mehr durch die DB-Zugriffszeit beeinflußt.

* Abhängig vom Attribut "syncInterval" werden die im Speicher gecachten Events in die DB wiederum als Bulkinsert weggeschrieben.
  Ist die DB nicht erreichbar, verbleiben die Events im Cache und werden im nächsten Zyklus gespeichert sofern die DB dann
  erreichbar ist. Das Default-Syncinterval ist 30 Sekunden.
  Es wird das Reading "NextSync" mit dem Zeitpunkt des nächsten Synclaufes erzeugt.
  Für diese Technik verwende ich wieder BlockingCall, der sich m.M. nach nun gut entgegen dem ersten Anlauf
  verwenden lässt da der Aufruf in dem Kontext relativ selten erfolgt, der DB-Zugrif als Bulkinsert passiert und nur ein
  Insertprozess gleichzeitig läuft was den Restriktionen von SQLite Rechnung trägt.

* wird vom asynchronen Modus in den synchronen Modus geswitcht, werden die im Cache gehaltenen Events sofort in die DB weggeschrieben.

* Wenn FHEM mit "shutdown ..." heruntergefahren bzw. restartet wird, werden die noch im Cache gehalteten Events in die DB weggeschrieben.
  Es gibt im DBLog schon immer das Attribut "shutdownWait" was eine Wartezeit beim shutdown zum Zweck einer ordnungsgemäßen Beendigung
  der DB-Verbindung bweirkt. Dieses Attr sollte gesetzt sein. Ich habe gute Erfahrungen mit einem Wert von 2s gemacht. Damit wurden
  bisher alle gecachten Events problemlos noch in die DB geschrieben bevor FHEM endete.
 
* Beim Wechsel in den "disabled"-Modus werden im Cache befindliche Events in die DB geschrieben und danach das Modul disabled sofern
  der asynchrone Modus eingeschaltet ist.
 
* neue Internals MODE bzw. VERSION

* im asynchronen Mode kann mit dem Attr "showproctime" die Verabeitungszeit des Hintergrundprozess ausgegeben werden. In dem Fall
  werden die Readings "background_processing_time" (gesamte Zeit im BlockingCall) und "sql_processing_time" (verbrauchte Zeit für
  SQL-Statements) erzeugt.

Bei mir habe ich mit dem Attr "syncInterval" den Schreibzyklus auf 70s eingestellt damit man die Gelegenheit hat den Aufbau
des Caches zu verfolgen und sich mit "listCache" auch mal anzuzeigen bevor er in die DB weggeschrieben wird.
Nach dem Umschalten in den asyncMode einmal den Browser aktualisieren damit ihr die neuen Readings seht.

Wenn die Version bei euch ebenfalls getestet ist und sauber läuft, würde ich die Commandref überarbeiten und mich dann auch mit der
Möglichkeit einer optionalen File-basierenden DB beschäftigen um einerseits bei längerem DB-Ausfall den Memory nicht zu sehr zu belasten
und andererseits die Events bei einem FHEM-Absturz nicht zu verlieren (sofern es sich um einen längeren DB-Ausfall handelt).
Wird die DB irgendwann wieder verfügbar sein, sollen die Events aus der File-DB in die richtige DB übertragen und im File gelöscht werden.
So der Plan ...

Damit befasse ich mich aber erst wenn der jetzige Entwicklungsstand hinreichend auch bei euch getestet ist.
Also viel Spaß beim Test und gerne wieder Rückmeldungen bzgl. den Ergebnissen.

EDIT: Version 2.8.2 mit überarbeiteter Commandref angehängt

Grüße
Heiko

[Loredo]

Hi Heiko,


könntest du auch noch einbauen, dass DbLog_splitFn nicht nur in $modules{ $defs{$name}{TYPE} }{DbLog_splitFn} gesucht wird, sondern auch in $defs{$name}{'.DbLog_splitFn'}?
$defs{$name}{'.DbLog_splitFn'} sollte dabei dann Vorrang haben.

Damit ließe sich dann das ganze auch pro Device-Instanz nochmals überschreiben. Wir könnten das beispielsweise beim 98_powerMap Modul brauchen.

Vielleicht auch nachgelagert der Vollständigkeit halber noch auf ein vorhandenes userattr "DbLog_splitFn" prüfen und verwenden, sofern die darin benannte Funktion existiert?



Gruß
Julian

[JoeALLb]

Vielleicht auch für die Zukunft:

Könnte man bei einem

Code Auswählen Erweitern

get myDbLog - all 2017-01-05 2017-01-06 KS300:temperature
auch die Daten des caches mit zurück geben? Dann könnte ich eine relativ lange
Cachezeit (ca. 5 Minuten) nutzen, um die SD-Karte des RPI so weit als möglich zu entlasten
(und die Plots würden trotzdem vollständig gezeichnet).

[DS_Starter]

Hi Julian und Joe,

ja sehe ich mal mit vor. Ich habe mich erstmal auf das Logging als Solches konzentriert. Aber ist eine super Idee ...

@Joe, sowas ließe sich bestimmt machen. Habe mir die Get-Funktion von DbLog bisher noch nciht so genau angeschaut (stand bisher nicht im Fokus meiner Bemühungen), aber das wäre sicherlich auch eine ganz tolle Sache.

Grüße
Heiko

[ChrisW]

Danke scheint zu laufen
CacheUsage 86

[stromer-12]

Bei mir will die 2.8 nicht cache auf 800 und nichts in die Datenbank geschrieben.
Bin wieder zurück auf 2.5

[Newbie]

Hallo Heiko,

hab die aktuelle Version mal angetestet,

wenn ich Attribut "asyncMode=1" einstelle geht die Verbindung zur SQLite-DB verloren (entspricht der eingestellten Zeit vom Attribut syncInterval).

state geht dann auf -

state old BlockingCall is running - resync at NextSync     2017-01-05 22:40:13

vg Jens