93_DbLog - Umstellung Log-Funktion auf non-blocking

Begonnen von DS_Starter, 18 Dezember 2016, 20:03:56

Vorheriges Thema - Nächstes Thema

rudolfkoenig

130*0.0244 = 3.172
Oder habe ich mich verrechnet?

Wenn du mit "in memory caches" NVRAM/FLASH/etc meinst, dann klar.

Sonst habe ich Probleme bei einer Platte mit 5400/min Umdrehungen mehr als 90 Transaktionen pro Sekunde vorzustellen, wenn die Daten nur von einer Quelle seriell kommen. Jede Transaktion muss doch auf die Platte gesynct werden, bevor die DB ein Ack senden darf und zwischen Ack und naechsten insert dreht sich die Platte weiter. Wenn das OS nach jedem Sync den Inode wg. Zeitstempel aktualisiert (wie auf einem "normal" gemounteten FS), dann komme ich auf 45.
Ich kann mich irren, mein Wissen ist 10+ Jahre alt. Lerne aber gerne dazu.

justme1968

#16
nein. die rechnung stimmt. ich habe mich verrechnet. die synology zahlen sind aber nicht unbedingt repräsentativ. da ist noch ein software raid mit einem langsamen prozessor dazwischen. eine reine platte müsste etwas schneller sein.

aber um bei deinem FBDECT beispiel zu bleiben. die 13 events die auf ein mal kommen sollte man z.b. in einer transaktion schreiben. nicht einzeln. das sollte etwa den faktor 13 bringen.

da fällt mir gerade noch eine ziemliche performance bremse bei dblog ein: wenn man DbLogType nicht auf history setzt wird current bei jedem event gelösct und geschrieben. d.h. es werden die dreifachen ios erzeugt. das müsste vor allem bei mysql/mariadb auffallen. sqlite kann diese tabelle komplett im speicher cachen. da ist es dann nicht ganz so schlimm.
hue, tradfri, alexa-fhem, homebridge-fhem, LightScene, readingsGroup, ...

https://github.com/sponsors/justme-1968

JoeALLb

Ich begrüße es sehr, wenn DbLog weiterentwickelt wird. Danke Heiko fürs Einbringen neuer Ideen!
Zu den Änderungen kann ich nicht viel sagen, weil es bei mir selbst auf einem RPI 1 mit MySQL recht performant läuft!

In diesem Zusammenhang möchte ich aber weitere Verbesserungen (für die Zukunft)  mit dem Modul vorschlagen,
mit dem Bewußtsein dass es hier zumindest vorerst um andere Punkte geht:
1: MySql: Erstetzen des separaten insert oder update-Handlings durch ON DUPLICATE KEY UPDATE col1 = 2;
2: SqLite: Erstetzen durch INSERT OR REPLACE INTO history (timestamp, device, ...)   VALUES (xxx, 'yyy', 'zzz');
3. Erweitern des Indexes auf timestamp, device, reading im Unique-Modus:
   Vorteile:
   a) Löschen von Datensätzen dank PK leichter und eindeutig möglich
   b) Vorbeugen von unnützen doppelten Einträgen zur selben Zeit vom selben Device und reading. Das kann weder in Plots noch sonst wo korrekt ausgewertet werden!
4. Bessere Trennung von Einträgen in die Spalten Unit und Value. Hierzu gibts mehrere Einträge im Forum, die Funktion "DbLog_ParseEvent" ist einfach nicht allgemein genug dafür.
5. Besseres Handling wenn der SQL-Server nicht erreichbar ist. (zB lokales Zwischenspeichern).
6. ggf. Bulkinsert nutzen.

Wo ich kann und soll würde ich mich auch einbringen.
:D
FHEM-Server auf IntelAtom+Debian (8.1 Watt), KNX,
RasPi-2 Sonos-FHEM per FHEM2FHEM,RasPi-3 Versuchs-RasPi für WLAN-Tests
Gateways: DuoFern Stick, CUL866 PCA301, CUL HM, HMLan, JeeLink, LaCrosse,VCO2
Synology. Ardurino UNO für 1-Wire Tests, FB7270

DS_Starter

#18
Hallo zusammen, hallo Joe,

ich konnte es nicht lassen und habe eine weitere Testversion gebaut (V2.2 hier angehängt).
Aus meiner ersten Version habe ich alle für gut befundenen Änderungen beibehalten und Blocking wieder rausgeschmissen.

Als ich Rudis Anmerkung zu execute_array gelesen habe konnte ich nicht anders als es mal mit dem DBI-Interface umzusetzen.
D.h. es werden mit dieser Version die gefilterten (NOTIFYDEV) und bewerteten Events über ein Array an die DB übergeben und im Block abgearbeiet.
Der Erfolg kann sich im Vergleich zur originalen DbLog sehen lassen.
Ich komme jetzt mit meiner MySQL bei vollem Logging des SMA-Energymeters (71 events im Block) auf einen max-Wert von ca. 120ms. Der
apptime-average liegt bei 32ms.
Wenn ein Gerät nur ein event schmeisst der geloggt werden soll dann liegt der max-Wert bei 27ms mit einem avarage von 12,5ms.
Das sind alles Werte erst einmal von meiner Testmaschine.

Es sind doch erhebliche Performancegewinne zu verzeichnen. Mit SQlite habe ich es noch nicht ausprobiert.

Geändert habe ich auch, dass nur in die Tabelle "History" eingefügt wird wenn das Attribut DbLogType nicht gesetzt ist. Man muß also explizit
Current/History setzen wenn die Bearbeitung beider Tabellen gewünscht ist.

Zusammengefasst sind die Änderungen nun folgende:

* DbLog Push-Funktion ist umgestellt auf execute_array
* Insert nur in Tabell History wenn Attr DbLogType nicht gesetzt ist
* Umstellung der NotifyFn (DbLog_Log) auf deviceEvents
* Einführung von NOTIFYDEV um nur Events von Devices vom DbLog-Device auswerten zu lassen die auch in der DEF angegeben wurden

Auch wenn es noch nicht non-blocking ist dürfte diese Änderung m.M. nach in sehr vielen Fällen Erleichterung schaffen.

Würde mich wieder über Testergebnisse freuen, aber zu weiteren Arbeiten komme ich nun momentan wirklich nicht mehr.

Grüße
Heiko
ESXi@NUC+Debian+MariaDB, PV: SMA, Victron MPII+Pylontech+CerboGX
Maintainer: SSCam, SSChatBot, SSCal, SSFile, DbLog/DbRep, Log2Syslog, SolarForecast,Watches, Dashboard, PylonLowVoltage
Kaffeekasse: https://www.paypal.me/HMaaz
Contrib: https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter

JoeALLb

#19
Bisher läuft es wunderbar.
Die Statusanzeige zeigt regelmäßig Module an, die doppelte Logeinträge generieren, das muss ich mir noch nächer ansehen, aber das war mit dem alten Modul nicht anders.

Die Reaktion von FHEM ist gestiegen, da ich aber auch andere Änderungen gemacht habe (entfernen von Subroutinen aus Userreadings) muss ich das
nochmals genauer prüfen.
Meine CPU_Auslastung ist jedenfalls von 0.04 auf 0.01 gesunken!
FHEM-Server auf IntelAtom+Debian (8.1 Watt), KNX,
RasPi-2 Sonos-FHEM per FHEM2FHEM,RasPi-3 Versuchs-RasPi für WLAN-Tests
Gateways: DuoFern Stick, CUL866 PCA301, CUL HM, HMLan, JeeLink, LaCrosse,VCO2
Synology. Ardurino UNO für 1-Wire Tests, FB7270

DS_Starter

Morgen Joe,

Was meinst du mit der Statusanzeige von Modulen .... genau ?

Ich habe es jetzt nicht verstanden und vielleicht fällt mir noch etwas dazu ein.

Grüße
Heiko
ESXi@NUC+Debian+MariaDB, PV: SMA, Victron MPII+Pylontech+CerboGX
Maintainer: SSCam, SSChatBot, SSCal, SSFile, DbLog/DbRep, Log2Syslog, SolarForecast,Watches, Dashboard, PylonLowVoltage
Kaffeekasse: https://www.paypal.me/HMaaz
Contrib: https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter

JoeALLb

Im alten Modul zeigte der state vo, DbLog-Device manchmal folgende meldung an
DbLog: Failed to insert new readings into database: DBD::mysql::st execute failed: Duplicate entry 'bad.Rollo-positionCombi-2016-12-21 06:25:22-0' for key 'PRIMARY' at ./FHEM/93_DbLog.pm line 613.

im neuen Modul sieht die Meldung so aus.
DbLog: Failed to insert new readings into database: DBD::mysql::st execute_array failed: Duplicate entry 'bad.Rollo-positionCombi-2016-12-22 09:51:26' for key 'PRIMARY' [err was 1062 now 2000000000]


Eine Ursache dafür ist, dass ich meine Datenbank so eingestellt habe, dass sie doppelte Einträge nicht zulässt.

Ich habe jedoch noch nicht untersucht, warum manche Devices regelmäßig doppelte Einträge produzieren.
Zu den Devicetypen gehören Homematic Dimmer (im state-reading) oder aber auch manche von mir zuwenig
eingeschränkten userReadings.

Aber wie gesagt, ich denke nicht, dass hier Handlungsbedarf besteht, das funktioniert schon alles ganz gut.
Ein Analysetool könnte höchstens (irgendwann mal) diese Module (oder Userreadings) ausfindig machen und dem Benutzer zur Verbesserung melden...
FHEM-Server auf IntelAtom+Debian (8.1 Watt), KNX,
RasPi-2 Sonos-FHEM per FHEM2FHEM,RasPi-3 Versuchs-RasPi für WLAN-Tests
Gateways: DuoFern Stick, CUL866 PCA301, CUL HM, HMLan, JeeLink, LaCrosse,VCO2
Synology. Ardurino UNO für 1-Wire Tests, FB7270

stromer-12

Ich habe es auch mal getestet.

Lief soweit, weniger freezes, aber ich musste aber plotfork deaktivieren, dadurch bei den Grafiken größere freezes.
Und beim Modul 98_lifetracking.pm wurde nichts mehr gelogt.

Habe jetzt wieder zurückgesetzt auf original DbLog.
FHEM (SVN) auf RPi1B mit HMser | ESPLink
FHEM (SVN) virtuell mit HMLAN | HMUSB | CUL

DS_Starter

Hallo stromer-12,
Danke für die Info.
Ich glaube den Fehler gefunden zu haben ...Habe etwas im Code vergessen.
Bei mir auf dem Tablet habe ich es schnell geändert und läuft.
Lade heute Abend eine korrigierte Version zum Test hoch.

Grüße,
Heiko
ESXi@NUC+Debian+MariaDB, PV: SMA, Victron MPII+Pylontech+CerboGX
Maintainer: SSCam, SSChatBot, SSCal, SSFile, DbLog/DbRep, Log2Syslog, SolarForecast,Watches, Dashboard, PylonLowVoltage
Kaffeekasse: https://www.paypal.me/HMaaz
Contrib: https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter

DS_Starter

Hallo zusammen,

hier die korrigierte V2.3. Sie sollte das von stromer-12 gemeldete Problem beseitigen.
Habe auch nochmal speziell mit plotfork=1 auf meinen beiden Systemen gecheckt. Keine Probleme festgestellt.

Grüße
Heiko
ESXi@NUC+Debian+MariaDB, PV: SMA, Victron MPII+Pylontech+CerboGX
Maintainer: SSCam, SSChatBot, SSCal, SSFile, DbLog/DbRep, Log2Syslog, SolarForecast,Watches, Dashboard, PylonLowVoltage
Kaffeekasse: https://www.paypal.me/HMaaz
Contrib: https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter

JoeALLb

Hast Du eine Ahnung, woher dieser Fehler stammen kann?
Dieser kommt vorallem nach dem Neustart
DbLog: Error in inline function: <:>, Error: syntax error at (eval 3222) line 1, near ":"

Ansonsten läuft nun auch bei mir Plotfork! Danke!
FHEM-Server auf IntelAtom+Debian (8.1 Watt), KNX,
RasPi-2 Sonos-FHEM per FHEM2FHEM,RasPi-3 Versuchs-RasPi für WLAN-Tests
Gateways: DuoFern Stick, CUL866 PCA301, CUL HM, HMLan, JeeLink, LaCrosse,VCO2
Synology. Ardurino UNO für 1-Wire Tests, FB7270

DS_Starter

Morgen Joe,

ich habe einen alten Thread gefunden: https://forum.fhem.de/index.php/topic,21440.msg149401.html#msg149401

Dort war die Lösung:

Zitat... Ich habe den Fehler gefunden. Bei einem Plot hatte ich ein ":" zuviel in der Spec eines Wertes....

Könnte mir ähnliches bei dir vorstellen.

Grüße
Heiko
ESXi@NUC+Debian+MariaDB, PV: SMA, Victron MPII+Pylontech+CerboGX
Maintainer: SSCam, SSChatBot, SSCal, SSFile, DbLog/DbRep, Log2Syslog, SolarForecast,Watches, Dashboard, PylonLowVoltage
Kaffeekasse: https://www.paypal.me/HMaaz
Contrib: https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter

JoeALLb

Morgen Heiko,

das wars tatsächlich... sorry, dass ich nicht zuvor selbst gesucht hatte, mir war es gerade eben nur aufgefallen und ich dachte es wäre hilfreich. sorry!

Offtopic:
Manchmal habe ich das Gefühl, die "::" in den Plots vermehren sich von selbst ;-)
FHEM-Server auf IntelAtom+Debian (8.1 Watt), KNX,
RasPi-2 Sonos-FHEM per FHEM2FHEM,RasPi-3 Versuchs-RasPi für WLAN-Tests
Gateways: DuoFern Stick, CUL866 PCA301, CUL HM, HMLan, JeeLink, LaCrosse,VCO2
Synology. Ardurino UNO für 1-Wire Tests, FB7270

DS_Starter

Ist doch Weihnachten  :D

Ich habe das geänderte DbLog inzwischen auch auf meiner Prod-Instanz laufen und bin auch dort mit der Performance schon sehr zufrieden.
Der apptime max-Wert liegt hier so um die 290ms, der average liegt ebenfalls bei 30ms. Es gibt bei mir natürlich Einflüsse durch die Architektur auf dem NAS, die MySQL ist nicht exklusiv für FHEM vorhanden.
ESXi@NUC+Debian+MariaDB, PV: SMA, Victron MPII+Pylontech+CerboGX
Maintainer: SSCam, SSChatBot, SSCal, SSFile, DbLog/DbRep, Log2Syslog, SolarForecast,Watches, Dashboard, PylonLowVoltage
Kaffeekasse: https://www.paypal.me/HMaaz
Contrib: https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter

stromer-12

Ich habe es auch gestern Abend noch mal erneuert. Das mit plotfork klappt jetzt gut.

Nur wurden vom livetracking Modul keine Werte mehr geloggt. mit der originalen Version klappt das aber.
Fehler werden auch keine angezeigt. Ich bin jetzt wieder auf original zurück.
Ich weis jetzt nicht, ob noch wo anders etwas nicht geloggt wird.
FHEM (SVN) auf RPi1B mit HMser | ESPLink
FHEM (SVN) virtuell mit HMLAN | HMUSB | CUL