93_DbLog - Überlegungen zur Optimierung (RPI und andere Systeme)

abc2006 · 07 Dezember 2017, 09:30:58

ZitatEs gibt einen Satz von Attribute, die mit "col..." anfangen. Damit kann man die Zeichenbreite im Modul der tatsächlichen Feldbeite in der DB anpassen.
Man kann sie aber auch benutzen um z.B. das Schreiben des Feldes Event zu verhindert indem man das Attribut colEvent = 0 setzt.

Das war mir bereits bewusst. Und nachdem ich jetzt weiss, dass leere Felder keine performance-killer sind, hab ich die current-Tabelle wieder richtig angelegt, und colEvent hab ich ja schon länger auf 0 (siehe checkConfig).

Hab heute Nacht die Live-Tabelle auf Vordermann gebracht, die Test-Tabelle ist jetzt so, wie Live vorher war.
Mal sehen, ob es jetzt stabiler läuft, damit ich weiter optimieren kann.

Danke für die Hilfe!
Grüße,
Stephan

DS_Starter · 07 Dezember 2017, 10:12:41

Ich habe in #535 noch die 3.3.0 hinterlegt. Damit ist ein "list device" nicht mehr hinderlich wenn der cache im Fehlerfall sehr groß ist.

Grüße
Heiko

abc2006 · 07 Dezember 2017, 19:27:58

Rudi hat hier
https://forum.fhem.de/index.php/topic,73490.0.html

den Befehl "blockinginfo" erwähnt.
Wenn ich diesen Ausführe, bekomme ich logdb mit kompletter Ausgabe, gleiche Symptome wie beim list Device mit vollem Cache.
Kennst du diesen Befehl?
Hast du eine Idee, ob der aus gleichem Grund blockiert?

Hoffe, es ist klar geworden, was ich meine ..

Grüße,
Stephan

DS_Starter · 07 Dezember 2017, 21:26:16

ZitatKennst du diesen Befehl?

Ja, der wird quasi nachimplementiert wenn du ein Device/Modul nutzt welches Blocking.pm nutzt.
Dann siehst du den Befehl auch mit "help" in der Kommandozeile.

Der Befehl zeigt nur etwas an wenn ein BlockingCall aktuell läuft. Normalerweise wird dir nur:

Code Auswählen

No BlockingCall processes running currently

zeigen weil der Moment der Ausführung (zumindest bzgl. DbLog) verhältnismäßig kurz ist.
Anders verhält es sich wenn der gestartete BlockingCall im Hintergrund auf irgendetwas wartet.

Erstens wirst du im Device state sehen:

Code Auswählen

Commit already running - resync at NextSync

Und zweitens, wenn du den Befehl blockinginfo ausführst, wird er dir alle Info zu dem laufenden Prozess mit allen seinen Argumenten ausgeben.
Und das können eben im Fehlerfall (oder deinem Fall) sehr sehr viele Daten sein , mit deren Anzeige dein Browsersession überlastet wird.

Der Cache wird mit "list Device" ab der V3.3.0 nicht mehr ausgegeben, das habe ich abgeändert.

Grüße
Heiko

SusisStrolch · 07 Dezember 2017, 22:24:42

Hmm, bei mir schlägt der SqlDump nahezu komplett fehl.
Lediglich current wird gesichert.

Code Auswählen

2017.12.07 22:16:37.104 3: DbRep DbBackUp - ################################################################
2017.12.07 22:16:37.105 3: DbRep DbBackUp - ###             New database clientSide dump                 ###
2017.12.07 22:16:37.106 3: DbRep DbBackUp - ################################################################
2017.12.07 22:16:37.107 4: DbRep DbBackUp - execute command before dump: 'set logdb commitCache' 
2017.12.07 22:16:37.136 4: DbRep DbBackUp -> Start BlockingCall mysql_DoDumpClientSide
2017.12.07 22:16:37.138 3: DbRep DbBackUp - Starting dump of database 'fhem'
2017.12.07 22:16:37.143 3: DbRep DbBackUp - Characterset of collection and backup file set to utf8. 
2017.12.07 22:16:37.144 3: DbRep DbBackUp - Searching for tables inside database fhem....
2017.12.07 22:16:37.150 3: DbRep DbBackUp - Found 3 tables with 273561697 records.
2017.12.07 22:16:37.151 3: DbRep DbBackUp - Dumping table current (Type Aria):
2017.12.07 22:16:37.197 3: DbRep DbBackUp - 1025 records inserted (size of backupfile: 199.83 KB)
2017.12.07 22:16:37.198 3: DbRep DbBackUp - Dumping table history (Type Aria):
2017.12.07 22:16:59.065 3: ESPEasy: set Teich.ModusTag raw event,setTemp=7.1
2017.12.07 22:17:01.633 2: ESPEasy ESPbridge: httpReq failed:  192.168.254.80 pondctrl_Environ 'raw event,setTemp=7.1' 
2017.12.07 22:17:01.664 2: ESPEasy Teich.ModusTag: WARNING: http://192.168.254.80:80/control?cmd=event,setTemp=7.1: empty answer received
2017.12.07 22:17:07.256 1: DbRep DbBackUp - BlockingCall mysql_DoDumpClientSide Process died prematurely
2017.12.07 22:17:07.338 2: DbRep DbBackUp - Database dump aborted by "Process died prematurely" 
2017.12.07 22:17:28.047 2: ESPEasy Teich.ModusTag: RESOLVED: http://192.168.254.80:80/control?cmd=event,setTemp=7.1: empty answer received
2017.12.07 22:17:46.321 1: miniCUL433: answer: miniCUL433 uptime => 0 00:33:41
2017.12.07 22:17:48.977 3: ESPEasy: set Teich.ModusTag raw event,setTemp=7.1

Wie kann ich dem "Process died prematurely" auf die Schliche kommen?

SusisStrolch · 07 Dezember 2017, 22:28:13

Nachtrag:

Code Auswählen

defmod DbBackUp DbRep logdb
attr DbBackUp DbLogExclude .*
attr DbBackUp DbLogInclude DumpRowsHistory
attr DbBackUp dumpFilesKeep 6
attr DbBackUp dumpMemlimit 500000000
attr DbBackUp dumpSpeed 50000000
attr DbBackUp event-on-update-reading state,DumpRowsHistory
attr DbBackUp executeBeforeDump set logdb commitCache
attr DbBackUp room DbLog
attr DbBackUp timeout 7200
attr DbBackUp verbose 4

setstate DbBackUp Process died prematurely
setstate DbBackUp 2017-12-07 22:17:07 state Process died prematurely

DS_Starter · 07 Dezember 2017, 22:36:52

Das ist der falsche Thread

Aber ich hatte das auch vor Kurzem. Ich glaube ich hatte zuviel Ressourcen zugewiesen, Attribute

dumpMemlimit
dumpSpeed

reduzieren.

Grüße
Heiko

abc2006 · 07 Dezember 2017, 22:43:58

ZitatDer Cache wird mit "list Device" ab der V3.3.0 nicht mehr ausgegeben, das habe ich abgeändert.

Ich hab ja das TEST-Device noch mit der verhunzten Datenbank laufen - als test.
2100 Rows in Cache

und beim list DEVEL_logdb kommt der Browser immer noch genauso ins Schwitzen... oder hab ich deinen Satz falsch verstanden?

Grüße,
Stephan

DS_Starter · 07 Dezember 2017, 22:51:44

Nein, hast du nicht falsch verstanden.
Das ist ja blöd ... der Cache wird zwar nicht mehr ausgegeben, aber die Argumente der RUNNING_PID. Das siehst du ja sehr gut auf deinem Screenshot.
Das ist auch nur der Fall wenn ein BlockingCall gerade läuft. Und das ist, normalerweise, nur kurz der Fall.

Muss ich mal schauen ob ich das auch noch unterdrücken kann, aber heute nicht mehr ...

Grüße
Heiko

abc2006 · 07 Dezember 2017, 23:15:10

ZitatUnd das ist, normalerweise, nur kurz der Fall.

Und in dem Fall interessierts ja auch meist nicht

Zitatheute nicht mehr ...

Bin am Wochenende sowieso nicht da

also, kein Stress.

Danke,
Stephan

DS_Starter · 10 Dezember 2017, 18:13:14

Hallo Stephan,

die V3.3.0 ist eingecheckt.
Hier habe ich die V3.4.0 zum Test angehängt. Nun sollten aber tatsächlich keine cache-Bestandteile mehr beim "list" mit angezeigt werden, d.h. auch die BLOCKING_PID nebst ihren Argumenten (cache) wird beim list unterdrückt.

Grüße
Heiko

abc2006 · 11 Dezember 2017, 05:15:19

Hi Heiko,

nachdem ich gestern abend die 3.4.0 aktiviert habe, ist heute morgen FHEM wieder abgestürzt. Leider sind keine Meldungen im Log, weshalb ich lediglich neu gestartet und attr logdb verbose 5 gesetzt habe.

Was ich mir wünschen würde, wäre eine Option, mit der man den Namen des Logfiles definieren kann.
Extrem geil wäre eine Option wie bei FileLog, die direkt erkennt, wann rotiert werden muss (%y-%m-%d täglich; %w wöchentlich usw), aber allein Tagesfiles wäre schon hilfreich.

Wenn ich ein Doif mache, welches auf (bsp) CacheUsage > 2000 reagiert, löst das ja quasi bei *jedem* Datensatz aus
(ja, ich weiss, kann ich zeitlich oder Threshold-mäßig einschränken);
aber alles in einer Datei wäre schon praktischer ..

Grüße,
Stephan

DS_Starter · 11 Dezember 2017, 07:45:03

Hallo Stephan,

Zitatnachdem ich gestern abend die 3.4.0 aktiviert habe, ist heute morgen FHEM wieder abgestürzt. Leider sind keine Meldungen im Log, weshalb ich lediglich neu gestartet und attr logdb verbose 5 gesetzt habe.

Die Version unterdrückt lediglich die Ausgabe der BLOCKING_PID beim "list". Hast du mal gecheckt ob das so ist ?
Wie läuft denn inzwischen deine Prod-DB. Die hast du doch inzwischen ordentlich hergerichtet ?

ZitatWas ich mir wünschen würde, wäre eine Option, mit der man den Namen des Logfiles definieren kann.

Logfiles ? Du meinst sicherlich die Namen der Files vom exportCache.
Die Namensgebung der Files ist absichtlich restriktiv. Dadurch habe ich die Chance, diese Files mit vertretbarem Aufwand für den Befehl "importCacheFile" im System zu identifizieren und dem Nutzer per Drop-Down bereitzustellen.
Das einzigste, worüber ich nachdenken könnte, wäre eine Option ein bestehendes File weiterzuschreiben anstatt bei jedem exportCache ein neues zu beginnen. Macht aber nur Sinn in Verbindung mit "purge" weil man ansonsten alle Daten mehrfach in einem File hat.

Grüße,
Heiko

JoeALLb · 11 Dezember 2017, 07:55:27

Zitat von: abc2006 am 11 Dezember 2017, 05:15:19
Wenn ich ein Doif mache, welches auf (bsp) CacheUsage > 2000 reagiert, löst das ja quasi bei *jedem* Datensatz aus
(ja, ich weiss, kann ich zeitlich oder Threshold-mäßig einschränken);

Meinst Du damit, dass das Doif jedesmal die Werte auswerten muss? Gehts Dir dabei um eine mögliche Ressourcenverschwendung?
Das lässt sich doch mit normalen DOIF-Boardmitteln lösen, ohne dass es gleich neue "Features" benötigt.
Prüfe doch einfach auf "NextSync" (das ändert sich nur alle "syncInterval") und nimm die CacheUsage nur als nicht triggernde Abfrage (durch das ?) mit dazu.

Code Auswählen


([SQL:NextSync] && [?SQL:CacheUsage] > 2000 )

sG
Joe
Achtung, Code nicht getestet aus dem Kopf, bin unterwegs und kanns nicht prüfen.

abc2006 · 11 Dezember 2017, 08:18:53

Hi,

ZitatHast du mal gecheckt ob das so ist ?

Nein. Habe gestern beim einspielen nicht daran gedacht, und heute morgen um 4:30 nur kurz FHEM restartet, bevor ich dann eilig auf Arbeit musste. Check ich später, wenn ich daheim bin.

ZitatDie hast du doch inzwischen ordentlich hergerichtet ?

Ja, hab ich. Die TEST-DB ist grade auch disabled. D.h. der Fehler heute morgen ist mit der prod-DB aufgetreten.

ZitatDu meinst sicherlich die Namen der Files vom exportCache.

Ja, die meine ich.
Okay, war heute morgen vllt etwas früh.
Angenommen, ich habe ein doif, welches auf Events von logdb:cacheUsage triggert.
Weiterhin angenommen, ich führe bei jedem Event ein exportCache (nopurge) durch. Dann habe ich pro Logeintrag eine neue Datei, die entweder alle im Cache befindlichen Daten enthält (also einen Datensatz mehr als die vorherige Datei)
Alternativ führe ich einen exportCache purgeCache durch, dann enthält jede neue Datei lediglich einen Datensatz. Hab ich das so richtig verstanden?

Dadurch entstehen ziemlich schnell ziemlich viele Dateien ( 3600 pro Stunde, wahrscheinlich mehr).
-> Manchmal komm ich erst auf die Ideen, wenn ich mal drüber gesprochen hab. Ich würde ggf. ein expimpdir anlegen, dann wärs mir ja fast egal, wieviele Dateien da drin sind. In Zusammenhang mit purgeCache wärs dann ja sogar konsistent. Solange die Import-Funktion mit so vielen Dateien klar kommt.

Trotzdem könnte ich mir vorstellen, dass es einfacher handhabbar ist, nur eine (wenige) Dateien zu haben ...

Zitat([SQL:NextSync] && [?SQL:CacheUsage] > 2000 )

Klasse Idee, werd ich direkt so umsetzen, wenn ich daheim bin. Habs im Moment mit ([+60] && [?SQL:CacheUsage] > 2000 ) etwas eingeschränkt. Dazu kann ich dann direkt noch einen purgeCache machen, dann könnte das schon fast so sein, wie ich mir das gedacht hatte...

(eingebildeter) Nachteil: wenn fhem zwischendurch dann ganz abstürzt (ich weiss ja noch nicht warum, und ich sähe das (also das eintreten unvorhergesehener Ereignisse, die dazu führen, dass FHEM/DbLog nicht mehr richtig arbeitet) als Hauptanwendungsgrund von exportCache) wären die Daten seit dem letzten SyncInterval weg.

Hoffe das war jetzt verständlicher,
Grüße,
Stephan