FHEM Forum

Hallo zusammen,

in meinem contrib (siehe Fußtext) habe ich eine Testversion DbLog 5.0.0 zur Verfügung gestellt.

Für den asynchronen Betrieb habe ich nun anstelle des sich wiederholenden BlockingCall das SubProcess-Verfahren implementiert.
Das Verhalten ist wie bisher mit asyncMode = 1.

Wenn alles klappt wie ich es beabsichtige, werde ich auch das nicht-asynchrone Verfahren auf SubProcess umstellen und dadurch das Logging
generell non-blocking zur Verfügung stellen.

Das Ganze ist noch nicht fertig, läuft bei mir aber schon soweit reibungslos.

Ich würde mich freuen wenn sich ein paar Tester finden würden.
Denkt aber bitte daran, dass durchaus noch Fehler auftreten können und ihr solltet diesbezüglich eine gewisse Toleranz mitbringen.  ;)

LG,
Heiko

Moin Heiko,

2022.11.29 13:13:52.252 2: DbLog MYSQL - Subprocess "1643166" initialized ... ready for non-blocking operation

ich beobachte. Start schon mal ohne Auffälligkeiten.

Gruss
  Enno

Wow , du bist ja fix  :)

Moin Heiko,

solche Test würde ich nicht bei allen Modulen hier wagen. Da gibt es einige reguläre Module, die ich vom Update ausgeschlossen habe und erst mal ein paar Tage im Forum beobachte bevor ich die aktuellen Versionen einspiele, weil sie immer wieder mit kleinen Tippfehlern oder nicht angekündigten Änderungen aufschlagen.

Deine Testversion läuft bei mir ohne irgendwelche Probleme. Ich kann als User keine Unterschiede zu der normalen Version erkennen. So hatte ich es erwartet ;) Bin gespannt wie es weiter geht.

Gruss
  Enno

Hallo Heiko,

auch bei mir sieht es bis jetzt gut aus und ich werde weiter beobachten.

list DbLog
[...]
   FVERSION   93_DbLog.pm:v1.1.1-s26750/2022-11-26

Gruss Helmut

Danke auch dir Helmut.
Die Version wird richtig nach einem FHEM Restart angezeigt:


FVERSION  93_DbLog.pm:v5.0.0-s26750/2022-11-26


Ein reload reicht da nicht.

Hallo Heiko,

Du hast recht. Aber jetzt:

   FVERSION   93_DbLog.pm:v5.0.0-s26750/2022-11-26

Gruss Helmut

Habs auch am laufen, bisher unauffällig. Aus dem Log:
DbLog myDbLog - Subprocess "31088" initialized ... ready for non-blocking operation

Die Attribute, und die FVERSION
attr myDbLog DbLogType Current/History
attr myDbLog asyncMode 1
attr myDbLog bulkInsert 1
attr myDbLog syncInterval 120
...
#   FVERSION   93_DbLog.pm:v5.0.0-s26750/2022-11-26
#   MODE       asynchronous
#   MODEL      SQLITE
#   NAME       myDbLog
...


läuft!
2022.11.30 08:09:13.590 2: DbLog myDbLog - Subprocess "22837" initialized ... ready for non-blocking operation
2022.11.30 08:09:13.889 3: DbLog myDbLog - Creating Push-Handle to database mysql:database=fhem;host=192.168.5.245;port=3306 with user fhemuser
2022.11.30 08:09:13.913 3: DbLog myDbLog - Push-Handle to db mysql:database=fhem;host=192.168.5.245;port=3306 created
2022.11.30 08:09:13.914 3: DbLog myDbLog - UTF8 support enabled
2022.11.30 08:09:13.946 2: DbLog CL_DbLog - Subprocess "22839" initialized ... ready for non-blocking operation
2022.11.30 08:09:13.974 3: DbLog CL_DbLog - Creating Push-Handle to database mysql:database=fhem;host=192.168.5.13;port=3306 with user fhemuser
2022.11.30 08:09:13.983 3: DbLog CL_DbLog - Push-Handle to db mysql:database=fhem;host=192.168.5.13;port=3306 created
2022.11.30 08:09:13.984 3: DbLog CL_DbLog - UTF8 support enabled


   FVERSION   93_DbLog.pm:v5.0.0-s26750/2022-11-26
   MODE       asynchronous
   MODEL      MYSQL
....
Attributes:
   DbLogSelectionMode Include
   DbLogType  History
   asyncMode  1
   bulkInsert 1
   cacheEvents 2
   colEvent   0
   excludeDevs myDbLog
   room       Global
   showproctime 1
   syncInterval 120
   timeout    86400

Was mir allerdings auffällt, ist das die geforkten Prozesse beinahe soviel CPU % brauchen - wie der main prozess.
...Ich habe 2 DbLog-defs auf diesem Test-system! - ist allerdings ein RPI-2!
22837 fhem      20   0  117552  84908   7404 S   9.2  9.0   2:10.21 perl
22839 fhem      20   0  117536  81480   3940 S   9.2  8.6   2:09.57 perl
22726 fhem      20   0  121136  93420  12312 S   8.9  9.9   4:44.90 perl

Danke für die Weiterentwicklung dieses wesentlichen Moduls!
l.g. erwin
Danke

Moin erwin,

danke für die Info.


  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
  713 fhem      20   0  430360 357900  22584 S   7,3  17,5   1:07.97 perl
  702 fhem      20   0  793016  83532  34832 S   2,3   4,1   0:04.31 homebridge
1697 fhem      20   0  401684 309404   1328 S   2,3  15,2   0:02.32 perl
1688 fhem      20   0  401368 309068   1328 S   2,0  15,1   0:02.56 perl
1693 fhem      20   0  401652 309288   1328 R   2,0  15,1   0:02.32 perl
1695 fhem      20   0  401652 309340   1328 S   1,7  15,2   0:02.35 perl
1698 fhem      20   0  401836 309484   1328 R   1,7  15,2   0:02.32 perl
1689 fhem      20   0  403044 313692   4332 S   1,3  15,4   0:02.39 perl
1690 fhem      20   0  401520 309136   1328 S   1,3  15,1   0:02.20 perl
1696 fhem      20   0  401652 309340   1328 S   1,3  15,2   0:02.31 perl


Habe gleich mal bei mir geschaut. Auf meinem Testsystem laufen 8 DbLog Instanzen.
Sie brauchen deutlich weniger CPU als der Hauptprozess. Ist allerdings ein Intel NUC mit VMWare + VM's.
Aber ich beobachte das mal.

LG

Guten Morgen,

habe gerade die Version 5 auf einem meiner (Test)systeme eingebaut, das lief problemlos.

ZitatFVERSION   93_DbLog.pm:v5.0.0-s26750/2022-11-26
   MODE       asynchronous
   ...
   DbLogType  History
   asyncMode  1
   bulkInsert 1
   colEvent   0
...

es gibt hier aber nicht viele Devices, die Daten in die DB schreiben. Ich werde vermutlich keinen Unterschied in der Performance "spüren"

ein htop zeigt mir 4 zusätzliche instanzen von fhem, nur die Hautinstanz braucht ein paar %, die andern mehr oder weniger bei 0% (Raspi4).

Falls Du irgendwas getestet haben möchtest: einfach schreiben....

Gruß

Sany

Rein von der Bedienung und der "User Experiance" her sollte sich kein Unterschied zur offiziellen Version ergeben.

Das forken durch BlockingCall fällt weg und dadurch sollte ich ein stabiler RAM-Verbauch abzeichnen. Es gibt natürlich noch mehr Module die BlockingCall verwenden (zB. DbRep).
Das muss man bisschen berücksichtigen bei den Beobachtungen.

Ansonsten soll die Version ganz normal werkeln.

Ich habe gerade ein Update des Moduls ins contrib geladen.
Beim Shutdown werden die SubProzesse in der entsprechenden Funktion beendet und das auch mit verbose 2 im Logfile protokolliert.

Ich arbeite weiter an der Code-Überarbeitung, achte aber sehr darauf dass sich keine Inkompatibilitäten einschleichen.
Aber dafür testen wir ja zusammen ...  8)

Ok, die neue version hab ich noch nicht,
aber einen Kommentar:
ein set ... reopen sollte den child prozess ebenfalls terminieren und neu starten, damit könnte man sich eine "dynamische" Übergabe von Parametern (cachelimit, syncinterval,...) evtl. ersparen.
l.g. erwin

Zitatein set ... reopen sollte den child prozess ebenfalls terminieren und neu starten ...

Guter Hinweis, sehe ich mit vor.

ich bin noch dabei.  :) 93_DbLog.pm:v5.0.0-s26750/2022-11-29 ich habe FHEM gestoppt und als keiner zugeschaut hat direkt in der fhem.cfg die Definition von DbLog hinter Global gespeichert. War bei mir vorher ca. im letzten Drittel. Top sagt aber zu Speicherverbrauch fast das Gleiche wie gestern:
559 fhem      20   0  338128 269904  18992 R  14,3   6,9   1:46.89 perl                                       
575 fhem      20   0  306820 228564   7340 R   8,3   5,9   0:37.08 perl

Ich bin auf einem NUC mit Proxmox CT und aktuellen Debian (Bullseye) unterwegs.

Gruss
  Enno

Du hast bestimmt hier (https://forum.fhem.de/index.php/topic,107150.msg1248574.html#msg1248574) gespickelt  :)
Ich muß noch den Start des Subprocesses in die DefFn vorziehen. Dann wäre das erfüllt was Rudi in dem Thread ausgeführt hatte. Das mache ich heute noch.

Gerade eben habe ich das Modul im contrib upgedated.

Der SubProzess wird nun gleich beim Define inititialisiert.
Bei "set ... reopen" erfolgt ebenfalls ein Schließen und Neustart des SubProzesses. Dadurch ist dann aber der Vorteil des zeitigen
Start im Define zunichte gemacht, aber das ist dann nicht zu ändern.

das sieht doch schon gut aus :)

93_DbLog.pm:v5.0.0-s26750/2022-11-30

7717 fhem      20   0  336156 267256  18572 S  14,6   6,8   1:16.70 perl     
7718 fhem      20   0   69940  60116   6900 S   8,6   1,5   0:14.04 perl

Auch hier bisher keine Auffälligkeiten (Laufzeit aber auch erst knapp über eine Stunde).

So, hab die Version jetzt auch mal auf Zwei Instanzen laufen. bis jetzt keine Auffälligkeiten.

So, ich hab jetzt mal eine DbLog def in der cfg nach "vorne" geschoben, bringt definitiv was für mem use!
  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
30337 fhem      20   0   44144  31368   1620 S   8.9  3.3   0:20.71 perl # dblog NR= 20
30343 fhem      20   0   83064  54696   1584 S   8.9  5.8   0:19.74 perl # dblog NR= 92
30330 fhem      20   0  118080  90284  12268 S   1.7  9.5   3:08.15 perl # main
Ein Versuch, $hash->{NR} automatisiert auf einen freien wert < 20 zu setzen, ist allerdings schiefgegangen....
l.g. erwin

Zitat von: erwin am 01 Dezember 2022, 11:24:55
Ein Versuch, $hash->{NR} automatisiert auf einen freien wert < 20 zu setzen, ist allerdings schiefgegangen....
l.g. erwin

Da $devcount bei jedem define erhöht wird, funktioniert das "ganzzahltig" vermutlich nie. Ein workaround könnte sein, das für alle DbLog-Instanzen auf 1.{random} zu setzen, wenn deren automatisch vergebene NR größer ist wie (sagen wir) 10 - count TYPE=DbLog. Ist aber ziemlich "dreckig"...

EDIT: Zu "dreckig". Beim Speichern wird eine ganzzahlige ID erwartet...

Unter dem Gesichtspunkt des Speicher sparens ist meine jetzige Implementierung dass ein "reopen" den Subprozess beendet und dann neu startet sehr kontraproduktiv.
Dann macht man sich den Vorteil, den man sich über die Reihenfolge beim Start verschafft hat, wieder kaputt.

Ich werde es anders machen und nur die DB-Verbindung innerhalb des SP abbauen bzw. wieder aufbauen (passiert aktuell ohnehin im asynchronen Betrieb). Aber da bin ich noch dran.
Sollte der SP mal sterben wird er automatisch neu erstellt, was dann aber zwangsläufig ohne den "Speichervorteil" passiert.
Ist aber wegen der Betriebssicherheit nötig.

Wegen der Sortierung  $hash->{NR} könnten wir uns ja eine sichere! programmtechnische Routine erdenken. Mal schauen.

Zitat von: DS_Starter am 01 Dezember 2022, 12:40:10
Wegen der Sortierung  $hash->{NR} könnten wir uns ja eine sichere! programmtechnische Routine erdenken. Mal schauen.

Na ja. Das ist ein Internal. Man bräuchte ja "nur" eine Schleife von aktueller Position bis 2 rückwärts durchfahren und alle um eins erhöhen. Am Ende dann die DbLog-Instanz neu unter 2 einsortieren, done... Vielleicht noch bedingt dadurch, dass die aktuelle Position nicht sowieso schon klein ist (was auch immer das heißen mag). Sonst kommt es ggf. zu einer Dauer-Umsortierung, v.a., wenn das dann jemand nachmacht ;) .
Wirkt dann halt erst nach dem nächsten "save" (+restart).

EDIT: Es wäre besser, man könnte eine Art "high prio"-Flag setzen, anhand dem dann fhem.pl diese Devices dann automatisch beim save nach vorne sortiert, also erstes Sortierkriterium die mit flag (NR nur Hilfskriterium), danach der Rest wie sich das aus der NR ergibt. Würde halt Änderungen dieser einen Schleife beim wegspeichern bedingen, aber das wäre es dann schon gewesen und man wäre m.E. die Konflikte los...

ZitatWegen der Sortierung  $hash->{NR} könnten wir uns ja eine sichere! programmtechnische Routine erdenken. Mal schauen.

Naja, das habe ich versucht:
- eine NR herausfinden, die 1) nicht belegt ist UND 2) < 20 ist.
- diese NR dann $hash->{NR} = .. setzten.

Das hat grundsätzlich funktioniert, INTERNAL NR war dann "richtig" gesetzt.
Allerdings: Nach einem save-shutdown-restart war das DbLog device dann nicht defined!!!

Interessant ist auch, dass ein nach vorne schieben in der cfg ein NR von 20 ergibt, obwohl zw. 1 und 19 noch etliche NICHT belegt sind...
Meine used NR's =< 20:

used NR: 5 WEB
used NR: 7 WEBphone
used NR: 9 WEBtablet
used NR: 14 autocreate
used NR: 16 eventTypes
used NR: 1 global
used NR: 19 initialUsbCheck
used NR: 20 myDbLog
used NR: 3 telnetPort

Witzig.

Auf dem Testsystem liefert
list NR~.|1. NR
in der Tat Lücken.

Lasse ich das auf mein Hauptstem los, sind lückenlos alle Nummern belegt. Unterschied: Das läuft auf configDB.

Unter den nicht genutzten Nummern scheint sich fhem.pl die Leerzeilen (und Kommentare etc.) zu merken.
(EDIT: ja, "$h = $comments{$i};" nach einer entsprechenden Abfrage.)

Die Luecken koennen auch wegen temporaeren at, FHEMWEB/MQTT Verbindungen, usw. entstehen.

Guten Abend zusammen,

soeben habe ich ein Update des Moduls in mein contrib geladen.

Die gesamte Steuerung bezüglich des SubProzess ist überarbeitet/ausgebaut. Das betrifft vor allem das Connect-Management zur DB, Management bei User/Passwort Änderungen bzw. Änderungen von Attributen die sich auf Connect-Paramter beziehen.

Weiterhin werden Änderungen durch das Online-Einlesen der Konfigdatei mit rereadcfg bzw. das Connect Management mit reopen im SubProzess gesteuert.
Der SubProzess selbst wird nicht mehr beendet (außer wenn der Prozess durch einen Fehler stirbt) um den Speichervorteil beim Start nicht zu verlieren.

Man kann aber mit dem neuen Setter "stopSubProcess" den SubProzess manuell beenden wenn man es braucht.

Das Attr "traceHandles" habe ich entfernt. Es war nur für mich für den Support vorhanden und nicht für den User bestimmt.
In der neuen Architektur hat es nun keinen Mehrwert mehr.

Die Ausgaben in state geben nun auch mehr Information an den User über den aktuellen Zustand des Devices in Verbindung mit SubProcess.

Es sind recht umfangreiche Weiterentwicklungen in der Logik und dem Code. Ich habe alles soweit getestet. Dennoch kann es natürlich das eine oder andere Problemchen geben.
Also mutig updaten und vor allem danach restarten.  :)

LG

93_DbLog.pm:v5.0.0-s26750/2022-12-02 keine Fehler im Log und alles Andere wie immer ohne erkennbare Unterschiede ausser, das der Subprocess kleiner ist als bei der Version von gestern.
121358 fhem      20   0  343028 272084  18512 S  10,6   7,0   2:15.57 perl     
121359 fhem      20   0   70136  48032   6952 R   9,0   1,2   0:59.35 perl   

Das ist schonmal sehr gut.  :)

Du kannst auch gerne mal verbose erhöhen und dir bei restart / reopen diverse Meldungen im Log anschauen die sich auf den
SubProzess beziehen.

Zitat
... ausser, das der Subprocess kleiner ist als bei der Version von gestern....

Die Umnumerierung die wir oben andiskutiert haben, ist noch nicht berücksichtigt.
Aber der SubProcess wird gleich beim Define gestartet. Wenn du DbLog "manuell" in der fhem.cfg weit vorn einsortiert hast, spielt sich die RAM-Ersparnis wie beabsichtigt aus.

... läuft unauffällig,

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
15083 fhem      20   0   53348  35096   5128 S   8.9  3.7   7:46.51 perl # "vorgeschummelte" instanz
15088 fhem      20   0   92544  58624   5216 S   8.9  6.2   7:44.97 perl # instanz NR=92
15082 fhem      20   0  121136  93440  12268 S   3.3  9.9   7:58.75 perl # main

ich denke, damit sind die Möglichkeiten einer "abwärtskompatiblen" Lösung ausgereizt.... ;D
in apptime sehe ich noch relativ lange Zeiten (im main thread) für:  tmr-DbLog_execmemcache, ich denke speziell das eval (in DbLog_Log) schlägt hier zu....
das zu transformieren ohne die Kompatibilität zu verlieren kann ich mir nicht wirklich vorstellen!
Danke nochmals für deine Energie!
l.g. erwin   

Moin erwin,

Zitat
Danke nochmals für deine Energie!

Gerne  :)

Wenn tmr-DbLog_execmemcache rel. hohe Zeiten in apptime anzeigt liegt es meiner Meinung nach vermutlich an einer entsprechend hohen Anzahl von zu verarbeitenden Datensätzen im Memory Cache. In der Funktion, die unabhängig von der (Notify) Log-Funktion arbeitet, werden die gecachten Daten seriell verpackt und  an den Child Prozess gesendet.

Die Zeit, die in der Notify-Funktion (DbLog_Log) für einen Zyklus verbraucht wird,  kann man sich mit dem Attr showNotifyTime = 1 reporten lassen -> Reading notify_processing_time.

Inzwischen bin ich soweit auch den synchronen Log-Vorgang non-blocking über den SubProcess abwickeln zu können.
Ich teste diese Weiterentwicklung noch. Wenn ich soweit bin stelle ich euch die Version wieder im contrib zur Verfügung und beschreibe in der Hilfe auch genauer die jeweiligen Vorteile/Nachteile der jweilige asyncMode-Einstellungen.
Vermutlich sollte ich das Attr  asyncMode nun besser in operationMode umbenennen. Das kann ich ja für den User unschädlich im Code vornehmen.


Zum Thema {NR} Sortierung ...
Möglicherweise hat Rudi Lust und auch eine Idee die Nutzung von SubProcess global in der fhem.pl mit einer entsprechenden Sortierung zu unterstützen.  ;)
Beta-User hatte weiter vorn eine Art "high prio"-Flag ins Spiel gebracht.
Die Idee gefällt mir gut, weil es ja auch weitere Module gibt die SubProcess nutzen und im Prinzip vor der gleichen Problematik stehen sofern sie den SP nicht ständig starten und beenden.
Dadurch geht zwar ein bisschen die "Exklusivität" für DbLog verloren, aber das wäre vermutlich die sauberste weil zentrale Lösung für diese Sache.

LG,
Heiko

ZitatMöglicherweise hat Rudi Lust und auch eine Idee die Nutzung von SubProcess global in der fhem.pl mit einer entsprechenden Sortierung zu unterstützen.  ;)

Ich habe schon zwei Versuche hinter mir, beide waren problematisch.
Haken an dem high Prio Flag ist, dass configDB auch angepasst werden muss.
Haken an der Umnummerierung ist, dass NR von einigen Modulen verwendet wird, d.h. das ist nur mit anschliessenden save+restart machbar.

Danke Rudi schonmal für das Aufgreifen eines solchen Ansatzes !  8)

Ich weiß nicht wie groß eine etwaige Anpassung in configDB wäre und wie betateilchen dazu steht.
Aber ich könnte mir vorstellen dass ein genereller Support für SubProcess unter den behandelten Gesichtspunkten
sinnvoll ist.
Es geht ja nicht nur um den jetzigen Einsatzfall.
Es gibt ja weitere Module, die SubProcess einsetzen und vllt. werden es ja noch mehr.

Idee zum Thema HiPrio-Flag...

Nachdem ja "Lücken" in den NR's grundsätzlich erlaubt sind..., folgende idee:
Während CommandDefine einen niederen Bereich NR's für "spezielle" - explizit definerte Module freilassen - und alle übrigen Module z.B. ab 30 numerieren.
Das würde für bestehende defs beim nächsten start schlagend werden, für neue defs zur runtime!
Es braucht dann kein neues Flag, und alle bisherigen Module bleiben unberührt....
l.g. erwin

Na ja, wahrscheinlich bräuchte man gar nicht so viele Nummern, wenn man das beschränkt auf die Zeit nach $init_done (für bestehende Installationen dann: defmod, und die Instanz wandert nach vorne?).
Den Prio-Flag könnte man  direkt in "Initialize" setzen => nicht für den User sichtbar, aber zur define-Time schon bekannt?.

Beim Speichern/Neustart wird dann die nach vorne geholte Instanz "NR 31", und es wäre wieder Platz "vorne".

In meinem contrib liegt die V 5.1.0.
Nun ist das Logging im synchronen Mode ebenfalls non-blocking über den SubProcess realisiert.

Ich habe die Hilfe zum Attr asyncMode ausgebaut. Der User sollte damit nun genau einschätzen können welcher Modus für seinen Einsatzzweck der richtige ist. Hier ein Auszug. Wenn ihr noch Ergänzung haben solltet nehme ich sie gerne entgegen.

asyncMode

    attr <device> asyncMode [0|1]

    Dieses Attribut stellt den Verarbeitungsprozess ein nach dessen Verfahren das DbLog Device die Daten in die Datenbank schreibt.
    DbLog verwendet zum Schreiben der Log-Daten in die Datenbank einen SubProzess.
    Dadurch erfolgt der Schreibprozess in die Datenbank generell nicht blockierend und FHEM wird im dem Fall,
    dass die Datenbank nicht performant arbeitet oder nicht verfügbar ist (Wartung, Fehlerzustand), nicht beeinträchtigt.
    (default: 0)

        0 -    Synchroner Log-Modus. Die zu loggenden Daten werden sofort nach dem Empfang in die Datenbank geschrieben.
           Vorteile:
           Die Daten stehen im Prinzip sofort in der Datenbank zur Verfügung.
           Bei einem Absturz von FHEM gehen sehr wenige bis keine Daten verloren.
           Nachteile:
           Die Daten werden nicht zwischengespeichert und gehen verloren wenn die Datenbank nicht verfügbar ist
           oder fehlerhaft arbeitet. Eine alternative Speicherung im Filesystem wird nicht unterstützt.
           
           
        1 -    Asynchroner Log-Modus. Die zu loggenden Daten werden zunächst in einem Memory Cache zwischengespeichert
           und abhängig von einem Zeitintervall bzw. Füllgrad des Caches in die Datenbank geschrieben.
           Vorteile:
           Die Daten werden zwischengespeichert und gehen nicht verloren wenn die Datenbank nicht verfügbar ist
           oder fehlerhaft arbeitet. Die alternative Speicherung im Filesystem wird unterstützt.
           Nachteile:
           Die Daten stehen zeitlich verzögert in der Datenbank zur Verfügung.
           Bei einem Absturz von FHEM gehen alle im Memory zwischengespeicherten Daten verloren.


LG

ZitatWährend CommandDefine einen niederen Bereich NR's für "spezielle" - explizit definerte Module freilassen - und alle übrigen Module z.B. ab 30 numerieren.

Das habe ich jetzt implementiert und eingecheckt.
D.h. global kriegt weiterhin NR=1, alle anderen ab 30, es sei denn, InitilizeFn setzt im Modul-Hash prioSave=1.
Diese Definitionen kriegen die Nummer 2 bis 29.

Danke Rudi.

Bin grad unterwegs. Wenn ich wieder zu Hause bin, werde ich das Feature ins Modul einbauen und testen.

@Rudi:
Danke, das funktioniert bestens!
@Heiko:
das reading CacheUsage benimmt sich komisch:- eventmonitor:

2022-12-04 13:26:16.132 DbLog myDbLog CacheUsage: 60
2022-12-04 13:26:16.132 DbLog myDbLog CacheUsage: 0
2022-12-04 13:26:16.162 DbLog myDbLog CacheOverflowLastNum: 0
2022-12-04 13:26:16.162 DbLog myDbLog CacheUsage: 0
2022-12-04 13:26:16.302 DbLog myDbLog background_processing_time: 0.1021
2022-12-04 13:26:16.302 DbLog myDbLog sql_processing_time: 0.0814
2022-12-04 13:26:16.302 DbLog myDbLog CacheUsage: 0
Damit sieht das für den User so aus, als ob nichts geloggt wird...

.. ich hab Rudi's Implementation probehalber im DbLog_Init eingebaut... nach einem save - shutdown - restart sind bede DbLog Instanzen ganz vorne!

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
6719 fhem      20   0   46912  29052   5152 S   9.2  3.1   1:54.50 perl
6720 fhem      20   0   46912  29004   5152 S   9.2  3.1   1:54.07 perl
6718 fhem      20   0  118844  91328  12484 S   6.9  9.6   4:14.75 perl


Hallo zusammen,

habe das Prio Flag jetzt in DbLog eingebaut und getestet ... funktioniert auch bei mir bestens.

Neben dieser Änderung sind noch einige mehr Code-Änderungen eingeflossen  und ich habe auch begonnen Teile der CommandRef
auf die neue Architektur anzupassen.

Ich habe auch begonnen die SetFn umzubauen und muss nun noch schauen wie kompatibel die übrigen Kommandos (importCachefile,
reduceLog, etc.) sind bzw. sie kompatibel machen.

Neue Version liegt im contrib.

LG

Hallo Heiko,

ein kleines Problem ist aufgetaucht:
PERL WARNING: Use of uninitialized value $memcount in numeric ge (>=) at ./FHEM/93_DbLog.pm line 1632.
kommt ständig, offensichtlich dann, wenn es nichts zu loggen gibt. (war auch in der gestrigen version so, hab das gestern schon gepatcht gleichzeitig mit prioflag - und dann vergessen zu erwähnen...)
fix: im attachment.
Das prio-Flag funkt bestens, das hab ich gestern schon geschrieben.
Das Problem mit cacheUsage ist noch da!
ich verwende attr cacheEvents 2
l.g.erwin

Moin erwin,

$memcount hatte ich auch gesehen und die Warnung kommt bei mir aktuell nicht mehr.

Bzgl. cacheUsage  schaue ich nochmal.

Weil ich inzwischen noch etwas weitergemacht hatte ... kannst du bitte nochmal aus dem contrib laden ?
Sonst komme ich mit den Zeilennummern im Patch nicht mehr klar...

kurze Rückmeldung. 5.2 läuft jetzt auch bei mir auf Zwei Instanzen. Nach dem ersten Reboot alles weiterhin Problemlos.
Hab das define noch dazu ganz nach vorne geholt in der cfg.

Welches sind denn die Rahmenbedingungen für die 5.x Version?
Umgebung:
  FHEM Update am 5.12.2022 durchgeführt
  fhem.pl:26635/2022-11-01

Mein logdb Device:
Internals:
   COLUMNS    field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32
   CONFIGURATION ./contrib/dblog/MariaDB10.conf
   DEF        ./contrib/dblog/MariaDB10.conf .*:.*
   FUUID      5e0e63f1-f33f-6054-f97a-82f8e05ae3c5c61b
   FVERSION   93_DbLog.pm:v4.13.3-s26750/2022-11-26
   MODE       asynchronous
   MODEL      MYSQL
   NAME       logdb
   NR         6
   NTFY_ORDER 50-logdb
   PID        18098
   REGEXP     .*:.*
   STATE      connected
   TYPE       DbLog
   UTF8       1
   dbconn     mysql:database=fhem;host=192.168.254.20;port=3307
   dbuser     fhem
   eventCount 26
   HELPER:
     COLSET     1
     DEVICECOL  64
     EVENTCOL   512
     OLDSTATE   connected
     PACKAGE    main
     READINGCOL 64
     TC         current
     TH         history
     TYPECOL    64
     UNITCOL    32
     VALUECOL   128
     VERSION    4.13.3
   READINGS:
     2022-12-05 11:55:16   CacheOverflowLastNum 0
     2022-12-03 15:42:58   CacheOverflowLastState normal
     2022-12-05 11:55:23   CacheUsage      7
     2022-12-05 11:55:16   NextSync        2022-12-05 11:55:46 or if CacheUsage 500 reached
     2022-12-05 11:55:17   background_processing_time 0.5536
     2022-12-04 15:59:56   lastCachefile   ./log/cache_logdb_2022-12-02_07-20-22 import successful
     2022-12-05 11:55:23   notify_processing_time 0.0022
     2022-12-05 11:55:17   sql_processing_time 0.4971
     2022-12-05 11:55:17   state           connected
Attributes:
   DbLogExclude .*
   DbLogSelectionMode Exclude/Include
   DbLogType  Current/History
   asyncMode  1
   bulkInsert 0
   cacheEvents 2
   cacheOverflowThreshold 750
   colEvent   512
   colReading 64
   colValue   128
   disable    0
   event-on-change-reading CacheUsage,background_processing_time
   icon       security
   room       DbLog
   showNotifyTime 1
   showproctime 1
   timeout    86400
   verbose    3

• FHEM via "systemctl stop fhem.service" gestoppt
• FHEM/93_DbLog.pm gesicher
• FHEM/93_DbLog.pm durch den Download ersetzt
• FHEM via "systemctl start fhem.service" gestartet

Im FHEM-Log finde ich dann folgende Fehlermeldungen:
2022.12.05 11:32:50.070 1: PERL WARNING: Use of uninitialized value $memcount in numeric ge (>=) at ./FHEM/93_DbLog.pm line 1653.
2022.12.05 11:32:50.070 1: stacktrace:
2022.12.05 11:32:50.071 1:     main::__ANON__                      called by ./FHEM/93_DbLog.pm (1653)
2022.12.05 11:32:50.071 1:     main::DbLog_Log                     called by fhem.pl (3972)
2022.12.05 11:32:50.071 1:     main::CallFn                        called by fhem.pl (3884)
2022.12.05 11:32:50.071 1:     main::DoTrigger                     called by fhem.pl (4269)
2022.12.05 11:32:50.072 1:     main::Dispatch                      called by ./FHEM/00_MQTT2_SERVER.pm (580)
2022.12.05 11:32:50.072 1:     main::MQTT2_SERVER_doPublish        called by ./FHEM/00_MQTT2_SERVER.pm (460)
2022.12.05 11:32:50.072 1:     main::MQTT2_SERVER_Read             called by fhem.pl (3972)
2022.12.05 11:32:50.072 1:     main::CallFn                        called by fhem.pl (782)


Any ideas?

Zitat
Any ideas?

Ja, ist nur eine Warnung und ist schon im Fokus ... siehe Beitrag drüber ...

Ansonsten keine besonderen Voraussetzungen, Version ist funktionskompatibel zur offiziellen Version.

Die $memcount  Warnung sollte nun beseitigt sein.
Update im contrib.

re: patch/Zeilennummern...
der patch besteht aus einer Zeile, in DbLog_Log:
  if(AttrVal ($name, 'verbose', 3) == 4) {
      if($log4rel) {
          Log3 ($name, 4, "DbLog $name - ################################################################");
          Log3 ($name, 4, "DbLog $name - ###              start of new Logcycle                       ###");
          Log3 ($name, 4, "DbLog $name - ################################################################");
          Log3 ($name, 4, "DbLog $name - number of events received: $max of device: $dev_name");
      }
  }

  my ($event,$reading,$value,$unit,$memcount);
  $memcount = 0;  #<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
  my $err;

Vorschlag zu cacheUsage:
dass passt m.M. auch besser zum wording in der cmd-ref.
gestestet allerdings nur mit cacheEvents 2!

Zitat von: erwin am 05 Dezember 2022, 12:14:34
re: patch/Zeilennummern...
der patch besteht aus einer Zeile, in DbLog_Log:

Danke. Dann kann ich mal mein UTF-8 Problemchen testen...

Danke erwin,

fast getroffen denke ich  ;)
Habe es etwas verändert übernommen.
Gerne wieder aus contrib laden und gegenchecken.

Hallo Heiko,

Ja, das passt!
...auch wenn das readingsupdate ohne EVENT mir nicht ganz verständlich ist...
Aber aus Kompatibilitätsgründen macht das Sinn.

Zitat
...auch wenn das readingsupdate ohne EVENT mir nicht ganz verständlich ist...

Naja, lt. ComRef und wie es von mir auch gedacht war liegt der Schwerpunkt  auf der Erzeugung von entsprechenden Events dieses Readings. Ursprünglich war die Verwendung den Füllgrad des Caches durch den User loggen/überwachen zu können.
Upgedated werden sollte es unabhängig von der Eventerstellung.

Folgende Warnung habe ich im Log: 2022.12.05 21:41:14.371 1: PERL WARNING: Use of uninitialized value $v2[0] in regexp compilation at ./FHEM/93_DbLog.pm line 1516.

93_DbLog.pm:v5.2.0-s26750/2022-12-05 Sonst alles unauffällig.

Hallo enno,

ich denke das kommt von einem DbLogInclude Attr bei dem das Reading fehlt/nicht mitkommt.
Das ist eine Stelle die im offiziellen Modul auch so definiert ist.
Ich weiß nicht wie oft die Warnung bei dir kommt, man bekommt es mit einem verbose 5 raus.

verbose 5 schmeißt aber viele Daten. Wenn du keine Idee hast, mache ich für dich eine Version um herauszubekommen
was genau bei dir diese Warnung erzeugt.

Ich glaube das lohnt nicht. Ich habe die Meldung das erste Mal gesehen. Wenn das öfter passiert, drehe ich am Verbose. Ich bebachte weiter.

Edit: Ich habe in der SQL-Datenbank um genaue die Uhrzeit zwei Einträge meiner Heizung. Der Fehler kam von meiner Heizung "km200". Das Modul hatte ich heute morgen nach langen Zögern doch aktualisiert. Nun habe ich plötzlich einen ganzen Sack mehr Readings dort. Beim Hinzufügen zum Attr DbLogInclude hat sich das System wohl kurz "verschluckt".

Möglicherweise hilft dir auch das globale stacktrace einzuschalten.

SQL-Error Handling
Habe extra mal 'nen fehlerhaften Event via "importCache" eingespielt (Fragment im Anhang) und bewusst auf DbLogValueFN verzichtet.
Sobald MariaDB einen Fehler meldet wird der zu Grunde liegende MemCache verworfen und nicht in ein Cache-File gesichert.
Unangenehm wenn man aus Performance-Gründen auf Einzeltransaktionen verzichten muß/will.
2022.12.05 15:34:37.310 4: DbLog logdb - 40 of 40 events inserted into table history
2022.12.05 15:34:37.998 2: DbLog logdb - Error table history - DBD::mysql::st execute_array failed: executing 33 generated 1 errors at ./FHEM/93_DbLog.pm line 2428.

2022.12.05 15:34:38.319 4: DbLog logdb - commit inserted data table history
2022.12.05 15:34:38.323 4: DbLog logdb - begin transaction
2022.12.05 15:34:38.881 4: DbLog logdb - insert history rolled back
2022.12.05 15:34:38.924 5: DbLog logdb - DbLog_Push Returncode: DBD::mysql::st execute_array failed: executing 33 generated 1 errors at ./FHEM/93_DbLog.pm line 2428.



Der Vollständigkeit halber hier das DbLog Device:
defmod logdb DbLog ./contrib/dblog/MariaDB10.conf .*:.*
attr logdb DbLogExclude .*
attr logdb DbLogSelectionMode Exclude/Include
attr logdb DbLogType Current/History
attr logdb asyncMode 1
attr logdb bulkInsert 0
attr logdb cacheEvents 2
attr logdb cacheOverflowThreshold 750
attr logdb colEvent 512
attr logdb colReading 64
attr logdb colValue 128
attr logdb disable 0
attr logdb event-on-change-reading CacheUsage,background_processing_time
attr logdb icon security
attr logdb room DbLog
attr logdb showNotifyTime 1
attr logdb showproctime 1
attr logdb timeout 86400
attr logdb verbose 5

Moin,

im asynch Mode und mit Transaktion (default) wird der übergebene Datenstack wieder an den Cache zurück gegeben.
Das sollte klappen.

Ich habe gerade eben die nächste V ins contrib geladen. Mit verbose 5 sieht man die zurück gegebenen Daten im Log:

  Log3 ($name, 5, "DbLog $name - rowlback to Cache: $key -> ".$rowlback->{$key});

Weiterhin habe ich noch den CPU-Verbrauch der/des SubProcesses deutlich reduzieren können.
Probiers mal aus.

Hmm, hat nicht so geklappt wie ich das erwartet habe.
Vorgehensweise:
Cache-File (1000 Zeilen) mit dem UTF-8 Fehler importiert.
Commit wurde abgebrochen. Ich hätte jetzt erwartet das die Cachegröße > 1000 ist und die Daten weiterhin im Cache stehen. Dies ist jedoch nicht der Fall.
defmod logdb DbLog ./contrib/dblog/MariaDB10.conf .*:.*
attr logdb DbLogExclude .*
attr logdb DbLogSelectionMode Exclude/Include
attr logdb DbLogType Current/History
attr logdb asyncMode 1
attr logdb bulkInsert 0
attr logdb cacheEvents 2
attr logdb cacheOverflowThreshold 750
attr logdb colEvent 512
attr logdb colReading 64
attr logdb colValue 128
attr logdb disable 0
attr logdb event-on-change-reading CacheUsage,background_processing_time
attr logdb icon security
attr logdb room DbLog
attr logdb showNotifyTime 1
attr logdb showproctime 1
attr logdb timeout 86400
attr logdb verbose 5

setstate logdb connected
setstate logdb 2022-12-06 10:36:44 CacheOverflowLastNum 0
setstate logdb 2022-12-03 15:42:58 CacheOverflowLastState normal
setstate logdb 2022-12-06 10:36:44 CacheUsage 19
setstate logdb 2022-12-06 10:36:44 NextSync 2022-12-06 10:37:14 or when CacheUsage 500 is reached
setstate logdb 2022-12-06 10:36:45 background_processing_time 0.2823
setstate logdb 2022-12-06 10:28:14 lastCachefile ./log/cache_logdb_2022-12-02-n1000 - Error - Resource temporarily unavailable
setstate logdb 2022-12-06 10:36:53 notify_processing_time 0.0048
setstate logdb 2022-12-06 10:36:45 sql_processing_time 0.2688
setstate logdb 2022-12-06 10:36:45 state connected



Im Filesystem ist auch keine neue Datei aufgetaucht, obwohl cacheOverflowThreshold auf 750 gesetzt ist.
Ich habe den entsprechenden Logfile-Auszug angehängt...

Das hätte ich jetzt auch so nicht erwartet.
Ich glaube einen Fehler im Ablauf gefunden zu haben, korrigiert und ins contrib geladen.
Teste mal bitte mit verbose 5.

Hmm...
# $Id: 93_DbLog.pm 26750 2022-12-06 16:38:54Z DS_Starter $

Aber das Repo zeigt Rev. 26793... von 10:20:32
Und das Modul sagt mir
93_DbLog.pm:v5.3.0-s26750/2022-12-06

anyway... hier das Log (verbose 5):
2022.12.06 13:06:03.559 5: DbLog logdb - DbLogExclude of "WZ.LCG.Environment": .*
2022.12.06 13:06:03.559 5: DbLog logdb - DbLogInclude of "WZ.LCG.Environment": humidity,pressure,temperature
2022.12.06 13:06:03.560 4: DbLog logdb - added event - Timestamp: 2022-12-06 13:06:03, Device: WZ.LCG.Environment, Type: LACROSSE, Event: pressure: 1018, Reading: pressure, Value: 1018, Unit:
2022.12.06 13:06:03.633 4: DbLog logdb - ################################################################
2022.12.06 13:06:03.634 4: DbLog logdb - ###         New database processing cycle - synchronous      ###
2022.12.06 13:06:03.634 4: DbLog logdb - ################################################################
2022.12.06 13:06:03.634 4: DbLog logdb - DbLogType is: Current/History
2022.12.06 13:06:03.634 4: DbLog logdb - AutoCommit mode: ON, Transaction mode: ON
2022.12.06 13:06:03.635 4: DbLog logdb - Insert mode: Array
2022.12.06 13:06:03.641 4: DbLog logdb - Primary Key used in history: none
2022.12.06 13:06:03.641 4: DbLog logdb - Primary Key used in current: DEVICE,READING
2022.12.06 13:06:03.642 4: DbLog logdb - processing event Timestamp: 2022-12-02 00:00:00, Device: Hauptzaehler, Type: ESPEASY, Event: Glitches: 657110016, Reading: Glitches, Value: 657110016, Unit:
...
2022.12.06 13:06:03.918 4: DbLog logdb - processing event Timestamp: 2022-12-02 00:13:49, Device: Teich.ModusTag, Type: ESPEASY, Event: Dusk: 61811, Reading: Dusk, Value: 61811, Unit:

2022.12.06 13:06:03.918 4: DbLog logdb - processing event Timestamp: 2022-12-02 00:13:49, Device: Teich.ModusTag, Type: ESPEASY, Event: Temp: 7.0, Reading: Temp, Value: 7.0, Unit:

2022.12.06 13:06:08.985 2: DbLog logdb - Error table history - DBD::mysql::st execute_array failed: executing 1000 generated 1 errors at ./FHEM/93_DbLog.pm line 2543.

2022.12.06 13:06:09.200 4: DbLog logdb - insert history rolled back
2022.12.06 13:06:09.860 5: DbLog logdb - DbLog_Push Returncode: DBD::mysql::st execute_array failed: executing 1000 generated 1 errors at ./FHEM/93_DbLog.pm line 2543.

2022.12.06 13:06:09.881 4: DbLog logdb - check Device: Verbrauch.Homeoffice , Event: power: 204.029879190957
2022.12.06 13:06:09.881 5: DbLog logdb - parsed Event: Verbrauch.Homeoffice , Event: power: 204.029879190957
2022.12.06 13:06:09.881 5: DbLog logdb - DbLogInclude of "Verbrauch.Homeoffice": .*
2022.12.06 13:06:09.882 4: DbLog logdb - added event - Timestamp: 2022-12-06 13:06:09, Device: Verbrauch.Homeoffice, Type: EC3000, Event: power: 204.029879190957, Reading: power, Value: 204.029879190957, Unit:


Für uns zählt erstmal nur was das Modul sagt, die Repo Versionsangabe ist jetzt nebensächlich.
Trotzdem macht mich die Ausgabe stutzig.

Ich habe die Logausgabe besser identifizierbar editiert und sie sieht jetzt so aus für den synchronen Fall verbose 5:


2022.12.06 13:41:04.751 4: DbLog LogDB1 - ################################################################
2022.12.06 13:41:04.752 4: DbLog LogDB1 - ###      New database processing cycle - SBP synchronous     ###
2022.12.06 13:41:04.753 4: DbLog LogDB1 - ################################################################
2022.12.06 13:41:04.754 5: DbLog LogDB1 - Store contains: 22731 -> 2022-12-06 13:41:04|Dum.Energy|DUMMY||T|374.1|
2022.12.06 13:41:04.755 5: DbLog LogDB1 - Store contains: 22732 -> 2022-12-06 13:41:04|Dum.Energy|DUMMY||T|374.1|
2022.12.06 13:41:04.755 5: DbLog LogDB1 - Store contains: 22733 -> 2022-12-06 13:41:04|MySTP_5000|SMAINVERTER||etotal|50162.077|
2022.12.06 13:41:04.756 5: DbLog LogDB1 - Store contains: 22734 -> 2022-12-06 13:41:04|MySTP_5000|SMAINVERTER||etoday|0.36|
2022.12.06 13:41:04.757 5: DbLog LogDB1 - Store contains: 22735 -> 2022-12-06 13:41:04|MySTP_5000|SMAINVERTER||total_pac|0.047|
2022.12.06 13:41:04.758 5: DbLog LogDB1 - Store contains: 22736 -> 2022-12-06 13:41:04|MySTP_5000|SMAINVERTER||state|0.047|
2022.12.06 13:41:05.030 5: DbLog LogDB1 - DbLogType is: Current/History
2022.12.06 13:41:05.030 4: DbLog LogDB1 - AutoCommit mode: ON, Transaction mode: ON
2022.12.06 13:41:05.030 4: DbLog LogDB1 - Insert mode: Bulk
2022.12.06 13:41:05.032 4: DbLog LogDB1 - Primary Key used in fhemtest1.history: TIMESTAMP,DEVICE,READING
2022.12.06 13:41:05.032 4: DbLog LogDB1 - Primary Key used in fhemtest1.current: DEVICE,READING
2022.12.06 13:41:05.032 5: DbLog LogDB1 - processing 22731 -> TS: 2022-12-06 13:41:04, Dev: Dum.Energy, Type: DUMMY, Event: , Reading: T, Val: 374.1, Unit:
2022.12.06 13:41:05.032 5: DbLog LogDB1 - processing 22732 -> TS: 2022-12-06 13:41:04, Dev: Dum.Energy, Type: DUMMY, Event: , Reading: T, Val: 374.1, Unit:
2022.12.06 13:41:05.032 5: DbLog LogDB1 - processing 22733 -> TS: 2022-12-06 13:41:04, Dev: MySTP_5000, Type: SMAINVERTER, Event: , Reading: etotal, Val: 50162.077, Unit:
2022.12.06 13:41:05.032 5: DbLog LogDB1 - processing 22734 -> TS: 2022-12-06 13:41:04, Dev: MySTP_5000, Type: SMAINVERTER, Event: , Reading: etoday, Val: 0.36, Unit:
2022.12.06 13:41:05.032 5: DbLog LogDB1 - processing 22735 -> TS: 2022-12-06 13:41:04, Dev: MySTP_5000, Type: SMAINVERTER, Event: , Reading: total_pac, Val: 0.047, Unit:
2022.12.06 13:41:05.032 5: DbLog LogDB1 - processing 22736 -> TS: 2022-12-06 13:41:04, Dev: MySTP_5000, Type: SMAINVERTER, Event: , Reading: state, Val: 0.047, Unit:
2022.12.06 13:41:05.032 4: DbLog LogDB1 - begin transaction
2022.12.06 13:41:05.034 4: DbLog LogDB1 - commit inserted data table fhemtest1.history
2022.12.06 13:41:05.034 3: DbLog LogDB1 - INFO - 5 of 6 events inserted into table fhemtest1.history due to PK on columns TIMESTAMP,DEVICE,READING
2022.12.06 13:41:05.034 4: DbLog LogDB1 - begin transaction
2022.12.06 13:41:05.036 4: DbLog LogDB1 - 6 of 6 events updated in table fhemtest1.current using PK on columns DEVICE,READING
2022.12.06 13:41:05.037 4: DbLog LogDB1 - commit inserted data table fhemtest1.current


Im Kopf sieht man es ist der SBP = SubProcess.
Bitte nochmal aus dem contrib ziehen und vor allem restarten. reload reicht nicht.

Die set Funktionen "count" und "countNbl" sind nun ebenfalls auf SubProcess umgestellt.
countNbl ist mit count identisch und wird nicht mehr benötigt, bleibt zunächst aber wegen der Abwärtskompatibilität erhalten.

count ist dadurch per se non-blocking.

Update liegt im contrib.

Eben die neue Version eingspielt:
2022.12.06 16:00:44.266 1: PERL WARNING: "my" variable $name masks earlier declaration in same scope at ./FHEM/93_DbLog.pm line 2837, <$fh> line 32.
2022.12.06 16:00:45.324 2: DbLog MYSQL - Subprocess >326123< initialized ... ready for non-blocking operation

Danke enno ... korrigiert.

Die set Funktionen "deleteOldDays" und "deleteOldDaysNbl" sind nun ebenfalls auf SubProcess umgestellt.
deleteOldDaysNbl ist mit deleteOldDays identisch und wird nicht mehr benötigt, bleibt zunächst aber wegen der Abwärtskompatibilität erhalten.

Update liegt im contrib.

userCommand ist nun auch noch auf SubProcess umgestellt.

ZitatFür uns zählt erstmal nur was das Modul sagt, die Repo Versionsangabe ist jetzt nebensächlich.
Trotzdem macht mich die Ausgabe stutzig.

Da ich trotz eines neuen Downloads aus dem Repo und einem FHEM-Restart immer noch keine Fehlerbehandlung sehe:
root@fhem:/opt/fhem/FHEM# md5sum 93_DbLog.pm
9c5463f1697c386e2b6020ce49fbb979  93_DbLog.pm


Auch sehe ich im Log:
[code2022.12.07 09:50:53.758 4: DbLog logdb - ################################################################
2022.12.07 09:50:53.758 4: DbLog logdb - ###         New database processing cycle - synchronous      ###
2022.12.07 09:50:53.758 4: DbLog logdb - ################################################################
2022.12.07 09:50:53.759 4: DbLog logdb - DbLogType is: Current/History
2022.12.07 09:50:53.759 4: DbLog logdb - AutoCommit mode: ON, Transaction mode: ON
2022.12.07 09:50:53.759 4: DbLog logdb - Insert mode: Array
2022.12.07 09:50:53.783 4: DbLog logdb - Primary Key used in history: none
2022.12.07 09:50:53.783 4: DbLog logdb - Primary Key used in current: DEVICE,READING
][/code]
wobei mein Setting auf asynchron steht.
Habe ich da noch ein Attribut übersehen?

Hängt es daran das der "importCache" synchron ausgeführt wird?

Zitat
Hängt es daran das der "importCache" synchron ausgeführt wird?

Ja, importCacheFile stelle ich gerade erst um. Hab ich auch nicht dran gedacht.  :(
Melde mich wieder wenn das erledigt ist.

Habe gerade die V 5.4.0 ins contrib geladen.

Jetzt sind auch die Befehle userCommand, exportCache und importCacheFile auf die neue Architektur angepasst.

Nun fehlt im Prinzip nur noch reduceLog bzw. reduceLogNbl ... kommt demnächst.

Guten Morgen,

im contrib liegt die V 5.5.0.

Es sind nun auch  reduceLog bzw. reduceLogNbl auf SubProcess umgestellt.
Die ComRef ist angepasst.

Edit: auch das Attr timeout ist auf die neue Struktur umgesetzt.

Moin,

Habe die 5.5 eingespielt, die Lage ist jedoch unverändert.

Ablauf:
  importCache "Cache-Datei mit UTF-8 Fehler" um Fehler auf der mysql-Seite zu provizieren.

Erwartungshaltung:   

• Daten des MemCache (bzw. für diesen Commit verwendeten Buffers) werden in ein Cache-File geschrieben
• der fehlerhafte MemCache wird weggeworfen

Hier der entsprechende Level 5 Trace:
2022.12.09 12:02:23.089 3: DbLog logdb - 33 rows read from ./log/cache_logdb_2022-12-02_00:10:05 into temporary Memory store
2022.12.09 12:02:23.090 5: DbLog logdb - DbLogType is: history
2022.12.09 12:02:23.091 4: DbLog logdb - AutoCommit mode: OFF, Transaction mode: OFF
2022.12.09 12:02:23.092 4: DbLog logdb - Insert mode: Array
2022.12.09 12:02:23.100 4: DbLog logdb - Primary Key used in history: none
2022.12.09 12:02:23.101 4: DbLog logdb - Primary Key used in current: DEVICE,READING
2022.12.09 12:02:23.101 4: DbLog logdb - add stored data: 0 -> 2022-12-02 00:10:05|Umwaelzung|ESPEASY|Pumpe: 0.0|Pumpe|0.0|
2022.12.09 12:02:23.101 4: DbLog logdb - add stored data: 1 -> 2022-12-02 00:10:05|Umwaelzung|ESPEASY|Ruecklauf: 15.2|Ruecklauf|15.2|
2022.12.09 12:02:23.102 4: DbLog logdb - add stored data: 2 -> 2022-12-02 00:10:05|Umwaelzung|ESPEASY|state: Pumpe: 0.0 Rueck: 15.2 Vorla: 33.3 delta: 0.0|state|Pumpe: 0.0 Rueck: 15.2 Vorla: 33.3 delta: 0.0|
2022.12.09 12:02:23.102 4: DbLog logdb - add stored data: 3 -> 2022-12-02 00:10:05|Umwaelzung|ESPEASY|Vorlauf: 33.3|Vorlauf|33.3|
2022.12.09 12:02:23.102 4: DbLog logdb - add stored data: 4 -> 2022-12-02 00:10:05|Verbrauch.Warmwasser|EC3000|power: 0.779215177016016|power|0.779215177016016|
2022.12.09 12:02:23.103 4: DbLog logdb - add stored data: 5 -> 2022-12-02 00:10:06|EMS_Boiler|MQTT2_DEVICE|serviceCode: 0�|serviceCode|0�|
2022.12.09 12:02:23.120 5: DbLog logdb - processing 32 -> TS: 2022-12-02 00:10:27, Dev: Hof.3erDose, Type: MQTT2_DEVICE, Event: Wifi_SSId: SusiconStrolch, Reading: Wifi_SSId, Val: SusiconStrolch, Unit:

2022.12.09 12:02:23.143 2: DbLog logdb - Error table history - DBD::mysql::st execute_array failed: executing 33 generated 1 errors at ./FHEM/93_DbLog.pm line 2908.

2022.12.09 12:02:23.160 4: DbLog logdb - ################################################################
2022.12.09 12:02:23.161 4: DbLog logdb - ###              start of new Logcycle                       ###
2022.12.09 12:02:23.161 4: DbLog logdb - ################################################################
2022.12.09 12:02:23.161 4: DbLog logdb - number of events received: 1 of device: logdb


Ergebnis:   

• Daten des MemCache werden nicht geschrieben
• der fehlerhafte MemCache wird weggeworfen

 

An der Stelle hatte ich noch nichts gemacht.
Aber jetzt V 5.5.1 im contrib. Restart erforderlich !

Im Array-Modus (default) und abgeschalteter Transaktion werden die fehlerhaften Daten nicht in die DB geschrieben (die anderen commited) und mit verbose 4 protokolliert, aber nicht an den Cache zurück gegeben.

Habe noch etwas gefeilt....

Und nicht mehr benötigten Code entfernt / aufgeräumt -> V 5.5.2

 V 5.5.3 -> mehr Code rework und minor fixing

Zitat
Zitat
Da ich ja eh mit einer blanken Datenbank starten möchte, bietet sich ja die die neue DbLog Version 5.X geradezu zum Test an :-)

was muss ich dazu machen?
Wenn Fragen dazu sind, am Besten in dem anderen Thread.
Du lädst die Version aus meinem contrib  (siehe Fußtext)  mit dem Downloadbutton herunter und startest danach FHEM neu.

bin zu doof...
habe nun die 93_DbLog.pm auf'm PC .. mit FTP auf den RASPI ins FHEM Verzeichnis ?

Ich habe dir mal einen Screenshot gemacht.
Wenn du auf den Link im Fußtext drückst bekommst du das dargestellte Bild.
Dann rechts neben DbLog auf den Downloadbutton drücken und in Verz. FHEM speichern.
Dann FHEM restarten.

Gehe jetzt mal auf den Weihnachtsmarkt  ;)

Zitat von: DS_Starter am 11 Dezember 2022, 13:33:59
Dann rechts neben DbLog auf den Downloadbutton drücken und in Verz. FHEM speichern.

oder die Datei auf dem Rechner lokal speichern, dann mit einem Editor öffnen und alles markieren "Strg+A" und in die Zwischenablage "Strg+C" kopieren. In FHEM "Edit files" und dort irgend eine Datei öffnen. Diese leeren und über die Zwischenablage "Strg+V" alles einfügen. Jetzt beim Speichern aufpassen, dass du "Save as" mit dem Namen "93_DbLog.pm" speicherst. Dann FHEM shutdown restart
Auf diese Weise ist die Datei im richtigen Verzeichnis mit den richtigen Rechten.

Gruss
  Enno

PS: Falls du unter Windows unterwegs bist, aufpassen, dass du dir keine Steuerzeichen (Zeilenumbrüche) mit reinbaust. Also am besten kein Textverarbeitungsprogramm nutzen.

Oder noch einfacher


"wget -qO ./FHEM/93_DbLog.pm https://svn.fhem.de/fhem/trunk/fhem/contrib/DS_Starter/93_DbLog.pm"


in der FHEMWEB Kommandozeile und restarten.
Bin jetzt wirklich weg ...  ;)

Zitat von: DS_Starter am 11 Dezember 2022, 13:48:24
Bin jetzt wirklich weg ...  ;)

Ah, Du gehst Popcorn holen?

Hi Heiko!
das ist ja ein mächtiger Umbau!
bis jetzt keine Probleme auf dem Testsystem! DANKE!
Ich werde in den nächsten Tagen das mal auf's Produktiv-system kopieren und mal ein paar Tage laufen lassen...
l.g. erwin 

Grade mal die 5.5.3 probiert - die zeigt noch immer das gleiche Verhalten bei einem mysql-Fehler.
2022.12.11 14:44:14.212 4: DbLog logdb - ################################################################
2022.12.11 14:44:14.213 4: DbLog logdb - ###              start of new Logcycle                       ###
2022.12.11 14:44:14.213 4: DbLog logdb - ################################################################
2022.12.11 14:44:14.213 4: DbLog logdb - number of events received: 2 of device: EMS_Boiler
2022.12.11 14:44:14.214 4: DbLog logdb - check Device: EMS_Boiler , Event: flameCurr: 52.4
2022.12.11 14:44:14.215 5: DbLog logdb - parsed Event: EMS_Boiler , Event: flameCurr: 52.4
2022.12.11 14:44:14.215 5: DbLog logdb - DbLogExclude of "EMS_Boiler": .*,wW.*,tapwaterActive,sysPress,selFlowTemp,selBurnPow,retTemp,pump.*,lastCode,json.*
2022.12.11 14:44:14.215 5: DbLog logdb - DbLogInclude of "EMS_Boiler": burnWorkMin,flameCurr,boilTemp,exhaustTemp,outdoorTemp,serviceCode,serviceCodeNumber
2022.12.11 14:44:14.216 4: DbLog logdb - added event - Timestamp: 2022-12-11 14:44:14, Device: EMS_Boiler, Type: MQTT2_DEVICE, Event: flameCurr: 52.4, Reading: flameCurr, Value: 52.4, Unit:
2022.12.11 14:44:14.217 4: DbLog logdb - check Device: EMS_Boiler , Event: curFlowTemp: 66.5
2022.12.11 14:44:14.217 5: DbLog logdb - parsed Event: EMS_Boiler , Event: curFlowTemp: 66.5
2022.12.11 14:44:14.217 5: DbLog logdb - DbLogExclude of "EMS_Boiler": .*,wW.*,tapwaterActive,sysPress,selFlowTemp,selBurnPow,retTemp,pump.*,lastCode,json.*
2022.12.11 14:44:14.218 5: DbLog logdb - DbLogInclude of "EMS_Boiler": burnWorkMin,flameCurr,boilTemp,exhaustTemp,outdoorTemp,serviceCode,serviceCodeNumber
2022.12.11 14:44:14.540 3: DbLog logdb - 33 rows read from ./log/cache_logdb_2022-12-02_00:10:05 into temporary Memory store
2022.12.11 14:44:14.541 5: DbLog logdb - DbLogType is: history
2022.12.11 14:44:14.541 4: DbLog logdb - AutoCommit mode: OFF, Transaction mode: OFF
2022.12.11 14:44:14.541 4: DbLog logdb - Insert mode: Array
2022.12.11 14:44:14.548 4: DbLog logdb - Primary Key used in history: none
2022.12.11 14:44:14.548 4: DbLog logdb - Primary Key used in current: DEVICE,READING
2022.12.11 14:44:14.549 4: DbLog logdb - add stored data: 0 -> 2022-12-02 00:10:05|Umwaelzung|ESPEASY|Pumpe: 0.0|Pumpe|0.0|
2022.12.11 14:44:14.549 4: DbLog logdb - add stored data: 1 -> 2022-12-02 00:10:05|Umwaelzung|ESPEASY|Ruecklauf: 15.2|Ruecklauf|15.2|
...
2022.12.11 14:44:14.558 4: DbLog logdb - add stored data: 32 -> 2022-12-02 00:10:27|Hof.3erDose|MQTT2_DEVICE|Wifi_SSId: SusiconStrolch|Wifi_SSId|SusiconStrolch|
2022.12.11 14:44:14.558 4: DbLog logdb - logstore deleted - 33 stored datasets added for processing
2022.12.11 14:44:14.559 5: DbLog logdb - processing 0 -> TS: 2022-12-02 00:10:05, Dev: Umwaelzung, Type: ESPEASY, Event: Pumpe: 0.0, Reading: Pumpe, Val: 0.0, Unit:
2022.12.11 14:44:14.559 5: DbLog logdb - processing 1 -> TS: 2022-12-02 00:10:05, Dev: Umwaelzung, Type: ESPEASY, Event: Ruecklauf: 15.2, Reading: Ruecklauf, Val: 15.2, Unit:
...
2022.12.11 14:44:14.626 2: DbLog logdb - Error table history - DBD::mysql::st execute_array failed: executing 33 generated 1 errors at ./FHEM/93_DbLog.pm line 2903.
2022.12.11 14:44:14.773 4: DbLog logdb - commit inserted data table history


Zitat von: DS_Starter am 09 Dezember 2022, 13:08:33
Im Array-Modus (default) und abgeschalteter Transaktion werden die fehlerhaften Daten nicht in die DB geschrieben (die anderen commited) und mit verbose 4 protokolliert, aber nicht an den Cache zurück gegeben.

Obwohl 2022.12.11 14:44:14.541 4: DbLog logdb - AutoCommit mode: OFF, Transaction mode: OFF
2022.12.11 14:44:14.541 4: DbLog logdb - Insert mode: Array
wurden die Daten aus dem importCache nicht  weggeschrieben, einen Error-Dump gab es ebenfalls nicht.


Noch ne Kleinigkeit...
Beim FHEM Restart (sei es via "systemctl" oder "shutdown restart") verfällt FHEM erst einmal in eine "Schweigeminute".
Der Restart dauert knapp 2Min...
2022.12.11 14:40:14.313 4: DbLog logdb - ################################################################
2022.12.11 14:40:14.314 4: DbLog logdb - ###              start of new Logcycle                       ###
2022.12.11 14:40:14.315 4: DbLog logdb - ################################################################
2022.12.11 14:40:14.315 4: DbLog logdb - number of events received: 1 of device: global
2022.12.11 14:40:14.316 4: DbLog logdb - check Device: global , Event: SHUTDOWN
2022.12.11 14:40:14.318 5: DbLog logdb - parsed Event: global , Event: SHUTDOWN
2022.12.11 14:40:14.319 4: DbLog logdb - added event - Timestamp: 2022-12-11 14:40:14, Device: global, Type: GLOBAL, Event: SHUTDOWN, Reading: state, Value: SHUTDOWN, Unit:
2022.12.11 14:40:14.328 0: Server shutdown
2022.12.11 14:40:14.332 4: ESPEasy Hauptzaehler: Shutdown requested
2022.12.11 14:41:55.765 1: Verbrauch.Multimedia: no I/O device
2022.12.11 14:41:55.772 1: Verbrauch.Warmwasser: no I/O device
2022.12.11 14:41:55.780 1: Verbrauch.Waschmaschine: no I/O device


sodele
nun läuft wohl die neue pm :-)
nternals
COLUMNS
field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32
CONFIGURATION
./configDB.conf
DEF
./configDB.conf .*:(temperature|humidity).*
FD
15
FUUID
6395a74c-f33f-fd5f-bf68-e3ca20a9e2cee3df
FVERSION
93_DbLog.pm:v5.5.3-s26750/2022-12-10
MODE
asynchronous
MODEL
MYSQL
NAME
dblog_THB
NR
2
NTFY_ORDER
50-dblog_THB
PID
18023
REGEXP
.*:(temperature|humidity).*
SBP_PID
18030
SBP_STATE
running
STATE
DBD::mysql::st execute_array failed: MySQL server has gone away [err was 2006 now 2000000000]
executing 42 generated 42 errors at ./FHEM/93_DbLog.pm line 2903.
TYPE
DbLog
UTF8
0
dbconn
mysql:database=fhem;host=localhost;port=3306
dbuser
fhemuser
eventCount
1
Readings
CacheOverflowLastNum
0
2022-12-11 16:13:43
CacheOverflowLastState
normal
2022-12-11 12:26:51
CacheUsage
2
2022-12-11 16:12:14
NextSync
2022-12-11 16:12:43 or when CacheUsage 500 is reached
2022-12-11 16:12:13
state
DBD::mysql::st execute_array failed: MySQL server has gone away [err was 2006 now 2000000000]
executing 42 generated 42 errors at ./FHEM/93_DbLog.pm line 2903.
2022-12-11 16:12:13
dblog_THB
room
xDBLog
Attributes
DbLogType
History,frontend
deleteattr
alias
dblog_THB
deleteattr
asyncMode
1
deleteattr
bulkInsert
0
deleteattr
cacheLimit
500
deleteattr
commitMode
ac:on_ta:off
deleteattr
event-min-interval
state:600
deleteattr
room
xDBLog
deleteattr
syncInterval
30
deleteattr
useCharfilter
1
deleteattr
verbose
2
deleteattr
Probably associated with
DbLog_THB_ZeilenHistorie
initialized
SVG
DbLog_reduce (DbLog_reducelog 1 1:40)
Next: 01:40:00
at
DbLog_reopen
Next: 01:30:00
at
Rep_MAX
connected » ProcTime: 0.0077 sec
DbRep
ReportDbLog_THB (Rep.Energy)
initialized
DbRep
SVG_MAX_ASTR_F1 (SVG_MAX_ASTR_F1 Kontakt Abstellraum heute)
initialized
SVG
SVG_MAX_BAD_F2 (SVG_MAX_BAD_F2 Kontakt Badtüre heute)
initialized
SVG
SVG_MAX_BAD_HT (MAX_Bad_HT 10 Tage)
initialized
SVG
SVG_MAX_BAD_WT (SVG_MAX_BAD_WT 10 Tage)
initialized
SVG
SVG_MAX_DIELE_F1 (SVG_MAX_DIELE_F1 Kontakt Haustüre heute)
initialized
SVG
SVG_MAX_DIELE_HT (SVG_MAX_DIELE_HT 10 Tage)
initialized
SVG
SVG_MAX_HWR_F1 (SVG_MAX_HWR_F1 Kontakt Aussentüre HWR heute)
initialized
SVG
SVG_MAX_HWR_F2 (SVG_MAX_HWR_F2 Kontakt Zimmertüre HWR heute)
initialized
SVG
SVG_MAX_HWR_HT
initialized
SVG
SVG_MAX_KCH_HT (SVG_Küche_HT 10 Tage)
initialized
SVG
SVG_MAX_PETRA_F4 (SVG_MAX_DIELE_F1 Kontakt Zimmertüre PETRA heute)
initialized
SVG
SVG_MAX_PETRA_O
initialized
SVG
SVG_MAX_PETRA_S1
initialized
SVG
SVG_MAX_PETRA_S2
initialized
SVG
SVG_MAX_PETRA_WT
initialized
SVG
SVG_MAX_Schlafzimmer_HT (SVG_SCHLAFEN)
initialized
SVG
SVG_MAX_Schlafzimmer_WT
initialized
SVG
SVG_MAX_THOMAS_F1 (SVG_MAX_THOMAS_F1 Kontakt Terrassentüre heute)
initialized
SVG
SVG_MAX_THOMAS_F2 (SVG_MAX_THOMAS_F2 Kontakt Thomas Zimmertüre heute)
initialized
SVG
SVG_MAX_THOMAS_HT1
initialized
SVG
SVG_MAX_THOMAS_HT2
initialized
SVG
SVG_MAX_THOMAS_WT
initialized
SVG
SVG_MAX_Toilette_HT (SVG_MAX_Toilette)
initialized
SVG
SVG_MAX_Treppenhaus_HT (SVG_MAX_Treppenhaus HT)
initialized
SVG
SVG_MAX_Treppenhaus_WT (SVG_MAX_Treppenhaus WT)
initialized
SVG
SVG_MAX_Wohnzimmer_O
initialized
SVG
SVG_MAX_Wohnzimmer_SO
initialized
SVG
SVG_MAX_Wohnzimmer_SW
initialized
SVG
SVG_MAX_Wohnzimmer_WT
initialized
SVG
SVG_OilFox (SVG OilFox 90 Tage)
initialized
SVG
SVG_OilFox2 (SVG OilFox2 90 Tage full)
initialized
SVG
SVG_PowerFox_d (PowerFox Stromverbrauch gesamt - heute)
initialized
SVG
SVG_PowerFox_m (PowerFox Stromverbrauch gesamt - 30 Tage)
initialized
SVG
SVG_TX25IT_13 (SVG_TX29 Garagenkeller (13) heute)
initialized
SVG
SVG_TX25IT_13m (SVG_TX29 Garagenkeller (13) 30 Tage)
initialized
SVG
SVG_TX29DTH_01 (SVG_TX29 Wohnzimmer (01) heute)
initialized
SVG
SVG_TX29DTH_01m (SVG_TX29 Wohnzimmer (01) 30 Tage)
initialized
SVG
SVG_TX29DTH_02 (SVG_TX29 Wohnzimmer (02) heute)
initialized
SVG
SVG_TX29DTH_02m (SVG_TX29 Wohnzimmer (02) 30 Tage)
initialized
SVG
SVG_TX29DTH_03 (SVG_TX29 Bad (03) heute)
initialized
SVG
SVG_TX29DTH_03m (SVG_TX29 Bad (03) 30 Tage)
initialized
SVG
SVG_TX29DTH_04 (SVG_TX29 Thomas (04) heute)
initialized
SVG
SVG_TX29DTH_04m (SVG_TX29 Thomas (04) 30 Tage)
initialized
SVG
SVG_TX29DTH_05 (SVG_TX29 Aussen Nord (5) heute)
initialized
SVG
SVG_TX29DTH_05m (SVG_TX29 Aussen Nord (5) 30 Tage)
initialized
SVG
SVG_TX29DTH_06 (SVG_TX29 Aussen Balkon (6) heute)
initialized
SVG
SVG_TX29DTH_06m (SVG_TX29 Aussen Balkon (6) 30 Tage)
initialized
SVG
SVG_TX29DTH_07 (SVG_TX29 Petra (07) heute)
initialized
SVG
SVG_TX29DTH_07m (SVG_TX29 Petra (07) 30Tage)
initialized
SVG
SVG_TX29DTH_08 (SVG_TX29 Schlafzimmer (08) heute)
initialized
SVG
SVG_TX29DTH_08m (SVG_TX29 Schlafzimmer (08) 30 Tage)
initialized
SVG
SVG_TX29DTH_09 (SVG_TX29 Treppenhaus (09) heute)
initialized
SVG
SVG_TX29DTH_09m (SVG_TX29 Treppenhaus (09) 30 Tage)
initialized
SVG
SVG_TX29DTH_10 (SVG_TX29 Aussen Terrasse (10) heute)
initialized
SVG
SVG_TX29DTH_10m (SVG_TX29 Aussen Terrasse (10) 30 Tage)
initialized
SVG
SVG_TX29DTH_11 (SVG_TX29 Abstellraum (11) heute)
initialized
SVG
SVG_TX29DTH_11m (SVG_TX29 Abstellraum (11) 30 Tage)
initialized
SVG
SVG_TX29DTH_12 (SVG_TX29 Hauswirtschaftsraum (12) heute)
initialized
SVG
SVG_TX29DTH_12m (SVG_TX29 Hauswirtschaftsraum (12) 30 Tage)
initialized
SVG
SVG_TX29DTH_14 (SVG_TX29 Garage (14) heute)
initialized
SVG
SVG_TX29DTH_14m (SVG_TX29 Garage (14) 30 Tage)
initialized
SVG
SVG_TX29DTH_15 (SVG_TX29 Bühne (15) heute)
initialized
SVG
SVG_TX29DTH_15m (SVG_TX29 Bühne (15) 30 Tage)
initialized
SVG
SVG_TX29DTH_16 (SVG_TX29 Heizraum (16) heute)
initialized
SVG
SVG_TX29DTH_16m (SVG_TX29 Heizraum (16) 30 Tage)
initialized
SVG
SVG_TX29DTH_17 (SVG_TX29 Aussen Süd OG (17) heute)
initialized
SVG
SVG_TX29DTH_17m (SVG_TX29 Aussen Süd OG (17) 30 Tage)
initialized
SVG
SVG_TX29DTH_18 (SVG_TX29 zbV HWR Problem (18) heute)
initialized
SVG
SVG_TX29DTH_18m (SVG_TX29 zbV HWR Problem (18) 30 Tage)
initialized
SVG
SVG_TX29DTH_19 (SVG_TX29 Tiefkühlfach Küche (19) heute)
initialized
SVG
SVG_TX29DTH_19m (SVG_TX29 Tiefkühlfach Küche (19) 30 Tage)
initialized
SVG
SVG_TX29DTH_20 (SVG_TX29 Tiefkühlfach HWR (20) heute)
initialized
SVG
SVG_TX29DTH_20m (SVG_TX29 Tiefkühlfach HWR (20) 30 Tage)
initialized
SVG
SVG_TX29_00 (SVG_TX29 Aussen Terrasse TFA (00) heute)
initialized
SVG
SVG_TX29_00m (SVG_TX29 Aussen Terrasse TFA (00) 30 Tage)
initialized
SVG
SVG_Temp1 (Temp1 Aussen Terrasse Tuya heute)
initialized
SVG
SVG_Temp2 (Temp2 Petra heute)
initialized
SVG
SVG_Temp3 (Temp1 Aussen Terrasse Tuya heute)
initialized
SVG
SVG_WU_IPLIEZ_1_S
initialized
SVG
SVG_WU_IPLIEZ_3_R (SVG WU_IPLIEZ_3R)
initialized
SVG
SVG_WU_IPLIEZ_3_Rday (SVG WU_IPLIEZ_3Rday)
initialized
SVG
SVG_WU_IPLIEZ_3_T (SVG WU_IPLIEZ_3T)
initialized
SVG
SVG_WU_IPLIEZ_3_Tday (SVG WU_IPLIEZ_3Tday)
initialized
SVG
SVG_WU_IPLIEZ_3_W (SVG WU_IPLIEZ_3W)
initialized
SVG
SVG_WU_IPLIEZ_3_Wday (SVG WU_IPLIEZ_3Wday)
initialized
SVG
SVG_dblog_THB_1
initialized
SVG


aber es knallt wieder mit der ja unveränderten Datenbank.

Wie kann ich diese löschen und neu anlegen ?
In FHEM oder über MYSQL?
Welche DB-User brauche ich außer "root"?

Eben erst sehe ich über PHPmyadmin wohr das ProbleM

History
Zeige Datensätze 0 - 24 (22416208 insgesamt, Die Abfrage dauerte 0.0019 Sekunden.)

kein Wunder..
TRUNKATE ging nicht
DELETE ja
habe also heine history mehr

wie kriege ich history wieder?


CREATE TABLE `fhem`.`history` (TIMESTAMP TIMESTAMP NOT NULL DEFAULT CURRENT_TIMESTAMP, DEVICE varchar(64), TYPE varchar(64), EVENT varchar(512), READING varchar(64), VALUE varchar(128), UNIT varchar(32));
CREATE TABLE `fhem`.`current` (TIMESTAMP TIMESTAMP, DEVICE varchar(64), TYPE varchar(64), EVENT varchar(512), READING varchar(64), VALUE varchar(128), UNIT varchar(32));
GRANT SELECT, INSERT, DELETE, UPDATE ON `fhem`.* TO 'fhemuser'@'%';
CREATE INDEX Search_Idx ON `fhem`.`history` (DEVICE, READING, TIMESTAMP) USING BTREE;


hat die history nun angelegt
und ICH HABE CONNECT :-) juhu

was muss ich nun wegen Version 5 noch anpassen ?
SVGs?

In die DatenBank wird also wohl geschrieben (132 Einträge schon wieder) :-)

in den Gplots kommt jedoch nichts..

was mache ich falsch?

Zitat von: thburkhart am 11 Dezember 2022, 16:46:41
was muss ich nun wegen Version 5 noch anpassen ?

eigentlich nur aufpassen, das beim nächsten Update von FHEM nicht die normale Version wieder eingespielt wird. Oder attr global exclude_from_update 93_DbLog.pm

und meine GPLOTs?

die gplot.cfgs habe ich mit einenem Namen versehen...
# Created by FHEM/98_SVG.pm, 2015-02-05 17:43:13
# THB 2016-06-12
# THB 2020-03-30


set terminal png transparent size <SIZE> crop
set output '<OUT>.png'
set xdata time
set timefmt "%Y-%m-%d_%H:%M:%S"
set xlabel " "
set title '<TL> - <L1> '
set ytics
set y2tics
set grid ytics y2tics
set ylabel "Humidity (%)"
set y2label "Temperature in C"


set yrange [0:100]
# set y2range [-10:40]


#FileLog 4:temperature:10:
#FileLog 6:humidity:50:

#DbLog <SPEC1>:temperature:10:
#DbLog <SPEC1>:humidity:50:


plot "<IN>" using 1:2 axes x1y2 title 'Temperature' ls l0fill lw 1 with lines,\
     "<IN>" using 1:2 axes x1y1 title 'Humidity' ls l2 lw 1 with lines

https://wiki.fhem.de/wiki/SVG-Plots_von_FileLog_auf_DbLog_umstellen

auf was steht dein DbLog ? bei mir ist das attr DbLogType Current/History und in den Plots LOGFILE HISTORY

bingo das wars :-)

danke sehr !!!!!

seltsamerweise lief das mit der alten db prima

andere Frage:
auf dem Android SmartPhone  will sich die App mit denselben Zugangsdaten nicht mit der FHEM Datenbank verbinden.
Database FHEM
User fhemuser

woran könnte das liegen ?

Zitat von: thburkhart am 11 Dezember 2022, 17:11:42

Code Auswählen Erweitern


#FileLog 4:temperature:10:
#FileLog 6:humidity:50:

#DbLog <SPEC1>:temperature:10:
#DbLog <SPEC1>:humidity:50:


Die Zeilen mit #FileLog am Anfang solltest Du entfernen, wenn alle Werte aus der Datenbank kommen.

In den gplot Dateien selbst zu editieren, sollte man nur tun, wenn man wirklich weiß und verstanden hat, WAS man da tut.

Zitat von: thburkhart am 11 Dezember 2022, 17:33:25
woran könnte das liegen ?

Vielleicht daran, dass die Datenbank nur von localhost aus erreichbar ist?

Zitat von: betateilchen am 11 Dezember 2022, 18:18:38
Vielleicht daran, dass die Datenbank nur von localhost aus erreichbar ist?

das Smartphone ist doch wie mein Laptop im selben heimischen Netz ..  ?

@SusisStrolch

Zitat
Noch ne Kleinigkeit...
Beim FHEM Restart (sei es via "systemctl" oder "shutdown restart") verfällt FHEM erst einmal in eine "Schweigeminute".

Es gibt für Module die das benötigen die Möglichkeit den Shutdown zu verzögern (https://wiki.fhem.de/wiki/DevelopmentModuleIntro#X_DelayedShutdown).
DbLog ist eines davon um den Abschluß der letzten DB-Aktivitäten abzuwarten. Siehe auch das globale Attr maxShutdownDelay.
Im Logfile sieht man welche Devices den Shutdown verzögern, z.B.:


2022.12.11 20:59:41.870 1: Server shutdown delayed due to SynCalTasks,SSCam.Keller,SynCal3,SynCal1,CamTER,SDS1,CamHE1,SynCal2,SSCam.Terrasse,SSCam.Hauseingang,CalHaus,SSCam.Carport,LogSQLITE1,SynCal.Abfall,SynCal,LogDB,SSCam.GiebelWest for max 10 sec
2022.12.11 20:59:41.886 2: DbLog LogSQLITE1 - Last database write cycle done
2022.12.11 20:59:41.887 2: DbLog LogSQLITE1 - stopping Subprocess >8567< ...
2022.12.11 20:59:41.890 2: DbLog LogSQLITE1 - Subprocess >8567< stopped
2022.12.11 20:59:41.907 2: DbLog LogDB - Last database write cycle done
2022.12.11 20:59:41.908 2: DbLog LogDB - stopping Subprocess >8564< ...
2022.12.11 20:59:41.911 2: DbLog LogDB - Subprocess >8564< stopped


Ich habe den Prozess im Modul jetzt noch etwas angepasst und ins contrib geladen.

Zitat
Grade mal die 5.5.3 probiert - die zeigt noch immer das gleiche Verhalten bei einem mysql-Fehler.

Ich glaube mit der Fehlerbehandlung komme ich langsam an den Rand des Möglichen. "Pferdefuß" ist wie das DBI den Fehler zurückgibt.
In der V5.5.4 im contrib ist die Ausgabe in das Logfile im Fehlerfall erweitert.
So richtig gefällt mir das nicht und ich denke noch darüber nach die Behandlung doch noch in unserem Sinne abzuändern.

Trotzdem die V5.5.4 bitte mal testen wegen den beiden Änderungen.

@SusisStrolch,

für dein Testszenario habe ich dir eine V  93_DbLog_V5.5.5_Test ins contrib geladen.
Bitte teste sie mit deinen fehlerhaften Events. Umbenennen natürlich.

Interessant wäre das Verhalten mit Attr commitMode = ac:on_ta:off sowie dem Standard basic_ta:on.

LG

Ich habe die Serialisierung von JSON auf Storable umgestellt.

Das hat m.M. nach zwei wesentliche Vorteile.
JSON muss installiert werden. Es ist zwar davon auszugehen dass es bei den allermeisten Usern der Fall ist, sicher ist es wahrscheinlich nicht.
Storable ist bei aktuellem Perl 5 built-In.

Storable ist bei encode/decode signifikant schneller als JSON::(XS) -> https://github.com/trizen/perl-scripts/blob/master/Benchmarks/json_vs_storable.pl
Das sollte sich beim serialisieren/deserialisieren von größeren Datenmengen ausspielen.

Ist im contrib upgedated.

@SusisStrolch ... gibt es noch irgendwelche Testergebnisse mit deinem Szenario ?

Ansonsten wäre die aktuell im contrib liegende Version soweit fertig um damit life gehen zu können falls mir nicht noch etwas auf/einfällt.

auch bei Euerm LaienJungspunt-Tester läuft alles prima :-)

nach dem Startschuss nehme ich die Zeile
attr global exclude_from_update 93_DbLog.pm

wieder raus ?

Zitat
nach dem Startschuss nehme ich die Zeile

attr global exclude_from_update 93_DbLog.pm

wieder raus ?

Ja, aber ich schreibe vorher wenn ich die neue V offiziell einchecke.
Paar Tage geben wir uns noch damit die User, die so mutig waren mitzumachen, nochmal ihre Meinung oder Hinweise abgeben können.

Kurzes Feedback:
habe die 5er Version auf einem Testsystem installiert, fast alle Versionen, die Du bereitgestellt hast. Lief jedesmal völlig ohne Probleme, keinerlei Fehlermeldungen im Log. Vor 3 Tagen habe ich dann die neueste Version (5.5.6) auf mein "Produktiv"-system losgelassen, auch hier keinerlei Fehler im Log, die DB arbeitet korrekt (Daigramme haben die aktuellen daten etc.)
Da ich immer noch nicht dazu kam, mich in DBrep reinzufuchsen bin ich momentan eher Typ Sammler, die DB ist bereits 10,5GB groß geworden. Performancemäßig kann ich nichts sagen, flutscht alles mindestens so gut wie vorher.
Attribute sind so gesetzt:

ZitatDbLogType History
asyncMode 1
bulkInsert 1
colEvent 0
event-on-change-reading state
useCharfilter 1

Ich denke das wäre so richtig für alles im Sub-prozess.
Tolle Arbeit für einen geschmeidigen Übergang zur neuesten Version. Vielen Dank dafür!


Gruß


Sany

Gestern alle Instanzen auf die neue Version hochgezogen.
keine negativen Beobachtungen. alles läuft wie gewohnt.

Zitat von: DS_Starter am 14 Dezember 2022, 19:24:14
@SusisStrolch ... gibt es noch irgendwelche Testergebnisse mit deinem Szenario ?

Ansonsten wäre die aktuell im contrib liegende Version soweit fertig um damit life gehen zu können falls mir nicht noch etwas auf/einfällt.

Nein - leider nicht. Hatte ein wenig Vorweihnachtstress (Releasegang 9.1. in der Firma) und deshalb keine Zeit meine Fehler zu testen.
Die Spezialversion lief nicht - da hat FHEM beim Start einen Fehler geworfen und das Modul direkt gelöscht.
Deshalb bin ich noch auf der 5.5.3 - denke aber, dass ich morgen zu einem Test mit der .6 komme.

@Sany, Frank_Huber ... danke für euer Feedback !

@SusisStrolch weißt du noch den Fehler ?

Nun, ich weiß zumindest wie das Problem zustande kam.
Ich hatte die .pm nach FHEM kopiert und danach ein "shutdown restart" ausgeführt.
2022.12.14 08:27:31.435 4: DbLog logdb - added event - Timestamp: 2022-12-14 08:27:31, Device: global, Type: GLOBAL, Event: SHUTDOWN, Reading: state, Value:
SHUTDOWN, Unit:
2022.12.14 08:27:31.439 0: Server shutdown
2022.12.14 08:27:31.441 4: ESPEasy Hauptzaehler: Shutdown requested
2022.12.14 08:27:36.078 4: DbLog logdb - ################################################################
2022.12.14 08:27:36.078 4: DbLog logdb - ###              start of new Logcycle                       ###
2022.12.14 08:27:36.079 4: DbLog logdb - ################################################################
...
2022.12.14 08:27:36.531 4: DbLog logdb - ################################################################
2022.12.14 08:27:36.531 4: DbLog logdb - ###              start of new Logcycle                       ###
2022.12.14 08:27:36.531 4: DbLog logdb - ################################################################
2022.12.14 08:27:36.532 4: DbLog logdb - number of events received: 1 of device: EMS_Boiler
2022.12.14 08:27:36.532 4: DbLog logdb - check Device: EMS_Boiler , Event: curFlowTemp: 64.2


Da keine Rückmeldung im Log kam habe ich in meiner grenzenlosen Geduld nach 2min einen "systemctl restart" ausgeführt.
Dec 14 08:29:22 fhem systemd[1]: Stopped FHEM Home Automation.
Dec 14 08:29:22 fhem systemd[1]: Starting FHEM Home Automation...
Dec 14 08:29:24 fhem systemd[1]: Started FHEM Home Automation.


welcher dann zu diesem Logeintrag führte:

2022.12.14 08:29:26.063 1: reload: Error:Modul 93_DbLog deactivated:

2022.12.14 08:29:28.653 1: Verbrauch.Multimedia: no I/O device
2022.12.14 08:29:28.659 1: Verbrauch.Warmwasser: no I/O device
2022.12.14 08:29:28.667 1: Verbrauch.Waschmaschine: no I/O device
2022.12.14 08:29:41.390 1: define Rep.logdb.fhem DbRep logdb: The specified DbLog-Device "logdb" doesn't exist.
2022.12.14 08:29:41.522 1: define Rep.logdb.knowhere DbRep logdb: The specified DbLog-Device "logdb" doesn't exist.

Danach war das Modul gelöscht...

Zitat
2022.12.14 08:29:26.063 1: reload: Error:Modul 93_DbLog deactivated:
 

Sieht so aus, als hätte danach ein Fehler ausgegeben werden sollen der allerdings nur "leer" war.

Vllt. war der Download des Moduls nicht ok.
Naja, wahrscheinlich müssig jetzt noch darüber nachzudenken.

Zitat
Danach war das Modul gelöscht...

Ich habe deswegen im global Device das Attr autosave = 0 gesetzt.
Normalerweise deaktiviert fhem nach einem Fehler beim Start die autosave Funktion selbständig.
Vllt. klappt das manchmal nicht so wie es soll, z.B. wenn wie oben der Fehler "leer" ist.
D.h. wenn du nach einem fehlerhaften Start _nicht_ "save" drückst, bleiben die Device Konfigurationen erhalten.
Den Fehler beseitigen und fhem neu starten bringt deine Konfiguration wieder zurück.

Mit autosave = 0 habe ich die Kontrolle über mein System, geht eben ein bisschen auf Kosten des Komforts.

Und wie sieht es bei dir eigentlich mit der V 5.5.6 aus ?

Hi,
ich hab jetzt auch die aktuelle version auf dem produktiv-system - bisher alles Bestens!
Danke!
erwin

etwas offtopic:

ich habe irgendwann mal folgendes zum Datenbank-Backup definiert

[code]define at_dblog_THBDump at *04:00:00 set Report_DumpsRows dumpMySQL clientSide
attr at_dblog_THBDump alias THBDUMP 4:00
attr at_dblog_THBDump room DBLog,xTimer
#   COMMAND    set Report_DumpsRows dumpMySQL clientSide
#   DEF        *04:00:00 set Report_DumpsRows dumpMySQL clientSide
#   FUUID      61daea6a-f33f-21fb-b2e6-a7e04cc6a8d5bed2
#   NAME       at_dblog_THBDump
#   NR         46
#   PERIODIC   yes
#   RELATIVE   no
#   REP        -1
#   STATE      Next: 04:00:00
#   TIMESPEC   04:00:00
#   TRIGGERTIME 1671418800
#   TRIGGERTIME_FMT 2022-12-19 04:00:00
#   TYPE       at
#   READINGS:
#     2022-12-18 20:32:48   state           Next: 04:00:00
#
setstate at_dblog_THBDump Next: 04:00:00
setstate at_dblog_THBDump 2022-12-18 20:32:48 state Next: 04:00:00

[/code]


ist das soweit korrekt ? auch das unspezifische "clientside"

Fehlermeldung bekomme ich nicht direkt; weiß aber auch nicht, wohin das backup geschrieben wird.

bitte um Hilfe

lg

Thomas

Hallo Thomas,

das ist ein DbRep-Thema und passt nicht hierher.
Der Aufruf ist erstmal ok, aber mehr ist dazu nicht zu sagen zumal das DbRep-Device nicht dargestellt ist.

Das können wir uns gerne anschauen, aber bitte nicht hier in diesem Thread, sondern in "Sonstiges".
Dort gibt es auch einen DbRep-Thread, oder ein neues Thema öffnen.

LG,
Heiko

Zitat von: DS_Starter am 18 Dezember 2022, 14:58:01
Und wie sieht es bei dir eigentlich mit der V 5.5.6 aus ?

Bin ich leider noch nicht dazu gekommen. Aber ich denke das ich bis morgen etwas dazu sagen kann.

Edit: Ich hatte die 5.5.6 doch schon anscheinend am 17. eingespielt - wußte ich nicht mehr... :(

So - Zwischenstand 5.5.6
Meine Synology führt Sa/So einen Hyperbackup aus. Dabei wird MariaDB heruntergefahren.
Als Ergebnis hatte ich einige Cache-Files erhalten. Super!
Was mir sonst so auffiel:
- das importierte Cache-File wird nicht (mehr) umbenannt
- mysql Fehler führen noch immer zum Verlust des MemCache
  Hierbei sind es nicht nur die falschen UTF-8, sondern auch so Dinge wie "cache buffer overflow" auf der DB-Seite
  (der default so um die 16MB groß ist und relativ leicht überschritten werden kann
   wenn es aus techn. Gründen (Backup) mal etwas größere Cache-Files gibt)
- werden zwei Imports (oder zwei aufeinanderfolgende Transaktionen) ausgelöst ohne das die Erste beendet ist
  so werden keine Transaktionen mehr an die DB gesendet - anscheinend wird dann das Ende der ersten Transaktion nicht erkannt.
  Zumindest findet sich im Log wiederkehrend der Eintrag
4: DbLog logdb - xx of xx events inserted into table history
4: DbLog logdb - commit inserted data table history
4: DbLog logdb - begin transaction

  Cache-Files werden jedoch nach Überschreiten des Limits geschrieben.

Zitat von: SusisStrolch am 19 Dezember 2022, 19:47:26
So - Zwischenstand 5.5.6

Nachtrag: im Falle der blockierten Transaktion helfen weder "reopen" noch "exportCache purgeCache".
Der Cache und derMemoryCache werden zwar anscheinend gepurged,
2022.12.19 19:51:13.716 4: DbLog logdb - MemCache contains 45 entries to process
2022.12.19 19:51:13.716 4: DbLog logdb - DbLogType is: Current/History
2022.12.19 19:51:13.717 5: DbLog logdb - MemCache contains:  1 -> 2022-12-19 19:50:45|ESPEasy_pondctrl_Wasser|ESPEASY|Temperature: 0.7|Temperature|0.7|
2022.12.19 19:51:13.717 5: DbLog logdb - MemCache contains:  2 -> 2022-12-19 19:50:49|EZ.Fenster2|MQTT2_DEVICE|Wifi_Channel: 7|Wifi_Channel|7|
...
2022.12.19 19:51:13.728 5: DbLog logdb - MemCache contains:  45 -> 2022-12-19 19:51:11|EMS_Boiler|MQTT2_DEVICE|outdoorTemp: 8.8|outdoorTemp|8.8|
2022.12.19 19:51:13.869 5: DbLog logdb - DbLogType is: Current/History
2022.12.19 19:51:13.870 4: DbLog logdb - AutoCommit mode: OFF, Transaction mode: ON
2022.12.19 19:51:13.871 4: DbLog logdb - Insert mode: Array
2022.12.19 19:51:13.881 4: DbLog logdb - Primary Key used in history: none
2022.12.19 19:51:13.881 4: DbLog logdb - Primary Key used in current: DEVICE,READING
2022.12.19 19:51:13.882 5: DbLog logdb - processing 1 -> TS: 2022-12-19 19:50:45, Dev: ESPEasy_pondctrl_Wasser, Type: ESPEASY, Event: Temperature: 0.7, Reading: Temperature, Val: 0.7, Unit:
2022.12.19 19:51:13.882 5: DbLog logdb - processing 2 -> TS: 2022-12-19 19:50:49, Dev: EZ.Fenster2, Type: MQTT2_DEVICE, Event: Wifi_Channel: 7, Reading: Wifi_Channel, Val: 7, Unit:
...
2022.12.19 19:51:13.894 5: DbLog logdb - processing 44 -> TS: 2022-12-19 19:51:09, Dev: Verbrauch.Warmwasser, Type: EC3000, Event: power: 318.323207283562, Reading: power, Val: 318.323207283562, Unit:
2022.12.19 19:51:13.894 5: DbLog logdb - processing 45 -> TS: 2022-12-19 19:51:11, Dev: EMS_Boiler, Type: MQTT2_DEVICE, Event: outdoorTemp: 8.8, Reading: outdoorTemp, Val: 8.8, Unit:
2022.12.19 19:51:13.932 4: DbLog logdb - 45 of 45 events inserted into table history
2022.12.19 19:51:14.072 4: DbLog logdb - commit inserted data table history
2022.12.19 19:51:14.076 4: DbLog logdb - begin transaction
2022.12.19 19:51:14.119 4: DbLog logdb - ################################################################
2022.12.19 19:51:14.120 4: DbLog logdb - ###              start of new Logcycle                       ###
2022.12.19 19:51:14.120 4: DbLog logdb - ################################################################


jedoch fährt die nächste Transaktion an die Wand (MemCache war doch nicht leer / commit ist nicht erfolgt):
2022.12.19 19:51:43.721 4: DbLog logdb - ################################################################
2022.12.19 19:51:43.722 4: DbLog logdb - ###      New database processing cycle - SBP asynchronous    ###
2022.12.19 19:51:43.722 4: DbLog logdb - ################################################################
2022.12.19 19:51:43.724 4: DbLog logdb - MemCache contains 21 entries to process
2022.12.19 19:51:43.724 4: DbLog logdb - DbLogType is: Current/History
2022.12.19 19:51:43.725 5: DbLog logdb - MemCache contains:  46 -> 2022-12-19 19:51:14|WZ.LCG.Environment|LACROSSE|temperature: 19.5|temperature|19.5|
2022.12.19 19:51:43.725 5: DbLog logdb - MemCache contains:  47 -> 2022-12-19 19:51:14|WZ.LCG.Environment|LACROSSE|humidity: 38.100344866095|humidity|38.100344866095|%
...
2022.12.19 19:51:43.730 5: DbLog logdb - MemCache contains:  66 -> 2022-12-19 19:51:39|EMS_Boiler|MQTT2_DEVICE|outdoorTemp: 8.8|outdoorTemp|8.8|
2022.12.19 19:51:43.957 5: DbLog logdb - DbLogType is: Current/History
2022.12.19 19:51:43.958 4: DbLog logdb - AutoCommit mode: OFF, Transaction mode: ON
2022.12.19 19:51:43.958 4: DbLog logdb - Insert mode: Array
2022.12.19 19:51:43.968 4: DbLog logdb - Primary Key used in history: none
2022.12.19 19:51:43.968 4: DbLog logdb - Primary Key used in current: DEVICE,READING
2022.12.19 19:51:43.969 5: DbLog logdb - processing 46 -> TS: 2022-12-19 19:51:14, Dev: WZ.LCG.Environment, Type: LACROSSE, Event: temperature: 19.5, Reading: temperature, Val: 19.5, Unit:
...
2022.12.19 19:51:43.974 5: DbLog logdb - processing 66 -> TS: 2022-12-19 19:51:39, Dev: EMS_Boiler, Type: MQTT2_DEVICE, Event: outdoorTemp: 8.8, Reading: outdoorTemp, Val: 8.8, Unit:
2022.12.19 19:51:43.987 4: DbLog logdb - 21 of 21 events inserted into table history
2022.12.19 19:51:45.344 4: DbLog logdb - commit inserted data table history
2022.12.19 19:51:45.347 4: DbLog logdb - begin transaction

Einzig "shutdown restart" hilft an der Stelle...

Zitat
Was mir sonst so auffiel:
- das importierte Cache-File wird nicht (mehr) umbenannt

Das hatte ich doch tatsächlich vergessen zu implementieren.
Ist jetzt nachgeholt.

Zitat
- mysql Fehler führen noch immer zum Verlust des MemCache

Das habe ich nochmal intensiv geprüft und die Fehlerbehandlung verbessert.
Im SQL Fehlerfall werden die Daten an den Cache zurück gegeben wenn ta_on ist (default).
Ausschnitt log:


2022.12.19 23:22:28.245 4: DbLog LogDB1 - ################################################################
2022.12.19 23:22:28.246 4: DbLog LogDB1 - ###      New database processing cycle - SBP asynchronous    ###
2022.12.19 23:22:28.246 4: DbLog LogDB1 - ################################################################
2022.12.19 23:22:28.247 4: DbLog LogDB1 - MemCache contains 379 entries to process
2022.12.19 23:22:28.247 4: DbLog LogDB1 - DbLogType is: Current/History
2022.12.19 23:22:28.264 4: DbLog LogDB1 - Operation: log_asynch
2022.12.19 23:22:28.265 4: DbLog LogDB1 - AutoCommit: ON, Transaction: ON
2022.12.19 23:22:28.265 4: DbLog LogDB1 - Insert mode: Array
2022.12.19 23:22:28.270 4: DbLog LogDB1 - begin transaction
2022.12.19 23:22:28.335 2: DbLog LogDB1 - Error table fhemtest1.history - DBD::mysql::st execute_array failed: executing 379 generated 37 errors at ./FHEM/93_DbLog.pm line 2932.

2022.12.19 23:22:28.343 4: DbLog LogDB1 - transaction rollback table fhemtest1.history
2022.12.19 23:22:28.344 4: DbLog LogDB1 - Transaction is switched on. Transferred data is returned to the cache.
2022.12.19 23:22:28.344 2: DbLog LogDB1 - WARNING - only 0 of 379 events inserted into table fhemtest1.history
2022.12.19 23:22:28.347 4: DbLog LogDB1 - begin transaction
2022.12.19 23:22:28.421 4: DbLog LogDB1 - 379 of 379 events updated in table fhemtest1.current
2022.12.19 23:22:28.424 4: DbLog LogDB1 - commit inserted data table fhemtest1.current


Zitat
- werden zwei Imports (oder zwei aufeinanderfolgende Transaktionen) ausgelöst ohne das die Erste beendet ist
  so werden keine Transaktionen mehr an die DB gesendet - anscheinend wird dann das Ende der ersten Transaktion nicht erkannt.

Das konnte nur in einem Fehlerfall vorkommen, habe ich korrigiert.

Zitat
Nachtrag: im Falle der blockierten Transaktion helfen weder "reopen" noch "exportCache purgeCache".

set ... stopSubProcess  hätte geholfen.
Aber das sollte sich erledigt haben.

Version 5.6.7 liegt im contrib.

LG

Wow!
Super - werde ich im Laufe des Tages direkt testen!

Edit: ich werde mal versuchen den "set ... stopSubProcess" in meine fhem.service zu dübeln...

Zitat
Edit: ich werde mal versuchen den "set ... stopSubProcess" in meine fhem.service zu dübeln...

Denke daran dass du den Vorteil des geringen Speicherverbrauchs verlierst wenn du "im Betrieb" den SubProcess neu
startest. Das sollte man nur machen wenn es sein muß (was normalerweise nicht der Fall sein wird).
Deswegen realisieren wir ja den zeitigen fork bei FHEM Start bevor alles fertig geladen ist.

Im Bulk-Insert Mode bringt das Modul im Fehlerfall jetzt detaillierte Informationen des SQL-Problems.
Hier ein Beispiel für "Duplicate entry" wenn ein primary Key gesetzt ist, aber durch das Attr noSupportPK=1 der Support deaktiviert wurde:


2022.12.20 14:47:40.561 2: DbLog LogDB1 - Error table fhemtest1.history - DBD::mysql::st execute failed: Duplicate entry '2022-12-20 14:47:40-Dum.Energy-T' for key 'PRIMARY' [for Statement "INSERT INTO fhemtest1.history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES ('2022-12-20 14:47:40','Dum.Energy','DUMMY','','T','578.8',''),('2022-12-20 14:47:40','Dum.Energy','DUMMY','','T','578.8',''),('2022-12-20 14:47:40','MySTP_5000','SMAINVERTER','','etotal','50244.169',''),('2022-12-20 14:47:40','MySTP_5000','SMAINVERTER','','etoday','0.865',''),('2022-12-20 14:47:40','MySTP_5000','SMAINVERTER','','total_pac','0.071',''),('2022-12-20 14:47:40','MySTP_5000','SMAINVERTER','','state','0.071','')"] at ./FHEM/93_DbLog.pm line 2741.

2022.12.20 14:47:40.562 2: DbLog LogDB1 - Transaction is switched off. Transferred data is lost.


Transaction: OFF -> Transaction is switched off. Transferred data is lost.

Im Array Insert Modus werden nun auch die Datensätze ausgeschrieben die wegen irgendwelchen Problemen nicht gespeichert werden konnten.
Leider ist das vom Treiber abhängig was zurück kommt und klappt nicht bei jeder DB gleich.
Hier ein Beispiel mit SQLite, MariaDB bringt es nicht so schön raus.


2022.12.20 15:57:37.408 4: DbLog LogSQLITE1 - ################################################################
2022.12.20 15:57:37.408 4: DbLog LogSQLITE1 - ###      New database processing cycle - SBP asynchronous    ###
2022.12.20 15:57:37.409 4: DbLog LogSQLITE1 - ################################################################
2022.12.20 15:57:37.409 4: DbLog LogSQLITE1 - MemCache contains 70 entries to process
2022.12.20 15:57:37.410 4: DbLog LogSQLITE1 - DbLogType is: Current/History
2022.12.20 15:57:37.670 3: DbLog LogSQLITE1 - DB connection parameters are stored in SubProcess
2022.12.20 15:57:37.684 3: DbLog LogSQLITE1 - SubProcess connected to /opt/fhem1.db
2022.12.20 15:57:37.685 4: DbLog LogSQLITE1 - Operation: log_asynch
2022.12.20 15:57:37.686 4: DbLog LogSQLITE1 - AutoCommit: ON, Transaction: ON
2022.12.20 15:57:37.686 4: DbLog LogSQLITE1 - Insert mode: Array
2022.12.20 15:57:37.690 4: DbLog LogSQLITE1 - begin Transaction
2022.12.20 15:57:37.697 4: DbLog LogSQLITE1 - commit inserted data table history
2022.12.20 15:57:37.698 4: DbLog LogSQLITE1 - Insert into history rejected - TS: 2022-12-20 15:55:44, Device: Dum.Energy, Reading: T
2022.12.20 15:57:37.698 4: DbLog LogSQLITE1 - Insert into history rejected - TS: 2022-12-20 15:55:44, Device: Dum.Energy, Reading: T
2022.12.20 15:57:37.699 4: DbLog LogSQLITE1 - Insert into history rejected - TS: 2022-12-20 15:55:44, Device: Dum.Energy, Reading: T
2022.12.20 15:57:37.699 4: DbLog LogSQLITE1 - Insert into history rejected - TS: 2022-12-20 15:55:44, Device: Dum.Energy, Reading: T
2022.12.20 15:57:37.700 4: DbLog LogSQLITE1 - Insert into history rejected - TS: 2022-12-20 15:55:44, Device: Dum.Energy, Reading: T
2022.12.20 15:57:37.700 4: DbLog LogSQLITE1 - Insert into history rejected - TS: 2022-12-20 15:56:45, Device: Dum.Energy, Reading: T
2022.12.20 15:57:37.700 4: DbLog LogSQLITE1 - Insert into history rejected - TS: 2022-12-20 15:56:45, Device: Dum.Energy, Reading: T
2022.12.20 15:57:37.701 4: DbLog LogSQLITE1 - Insert into history rejected - TS: 2022-12-20 15:56:45, Device: Dum.Energy, Reading: T
2022.12.20 15:57:37.701 4: DbLog LogSQLITE1 - Insert into history rejected - TS: 2022-12-20 15:56:45, Device: Dum.Energy, Reading: T
2022.12.20 15:57:37.702 4: DbLog LogSQLITE1 - Insert into history rejected - TS: 2022-12-20 15:56:45, Device: Dum.Energy, Reading: T
2022.12.20 15:57:37.702 2: DbLog LogSQLITE1 - WARNING - only 60 of 70 events inserted into table history
2022.12.20 15:57:37.702 2: DbLog LogSQLITE1 - The following data was not saved due to problems that may have been displayed previously:
2022.12.20 15:57:37.703 2: DbLog LogSQLITE1 -  1 -> 2022-12-20 15:55:44|Dum.Energy|DUMMY|T: 650.4|T|650.4|
2022.12.20 15:57:37.703 2: DbLog LogSQLITE1 -  2 -> 2022-12-20 15:55:44|Dum.Energy|DUMMY|T: 650.4|T|650.4|
2022.12.20 15:57:37.704 2: DbLog LogSQLITE1 -  3 -> 2022-12-20 15:55:44|Dum.Energy|DUMMY|T: 892.7|T|892.7|
2022.12.20 15:57:37.704 2: DbLog LogSQLITE1 -  4 -> 2022-12-20 15:55:44|Dum.Energy|DUMMY|T: 892.7|T|892.7|
2022.12.20 15:57:37.704 2: DbLog LogSQLITE1 -  5 -> 2022-12-20 15:55:44|Dum.Energy|DUMMY|T: 892.7|T|892.7|
2022.12.20 15:57:37.705 2: DbLog LogSQLITE1 -  6 -> 2022-12-20 15:56:45|Dum.Energy|DUMMY|T: 892.7|T|892.7|
2022.12.20 15:57:37.705 2: DbLog LogSQLITE1 -  7 -> 2022-12-20 15:56:45|Dum.Energy|DUMMY|T: 892.7|T|892.7|
2022.12.20 15:57:37.705 2: DbLog LogSQLITE1 -  8 -> 2022-12-20 15:56:45|Dum.Energy|DUMMY|T: 716.3|T|716.3|
2022.12.20 15:57:37.706 2: DbLog LogSQLITE1 -  9 -> 2022-12-20 15:56:45|Dum.Energy|DUMMY|T: 716.3|T|716.3|
2022.12.20 15:57:37.706 2: DbLog LogSQLITE1 -  10 -> 2022-12-20 15:56:45|Dum.Energy|DUMMY|T: 716.3|T|716.3|
2022.12.20 15:57:37.707 4: DbLog LogSQLITE1 - begin Transaction
2022.12.20 15:57:37.728 4: DbLog LogSQLITE1 - 70 of 70 events updated in table current
2022.12.20 15:57:37.729 4: DbLog LogSQLITE1 - commit inserted data table current


jetzt weiß ich nicht, ob das ein DbLog-Problem ist oder das Problem vor meinem Pc sitzt..

das ist mein dblog DEF:

define dblog_THB DbLog ./configDB.conf .*:(\
temperature|power|humidity|\
va_temperature|va_humidity|humidity_value|\
desiredTemperature|valveposition|\
/heatSources/systemPressure|\
/heatSources/applianceSupplyTemperature|\
/system/sensors/temperatures/outdoor_t1|\
/system/sensors/temperatures/supply_t1|\
/system/sensors/temperatures/supply_t1_setpoint|\
/dhwCircuits/dhw1/actualTemp|\
/dhwCircuits/dhw1/currentSetpoint|\
/heatSources/systemPressure|\
oilfox_metering_liters).*
attr dblog_THB DbLogType Current/History
attr dblog_THB alias dblog_THB
attr dblog_THB asyncMode 1
attr dblog_THB bulkInsert 0
attr dblog_THB cacheLimit 5000
attr dblog_THB commitMode ac:on_ta:off
attr dblog_THB event-min-interval state:600
attr dblog_THB room DBLog
attr dblog_THB syncInterval 30
attr dblog_THB useCharfilter 1
attr dblog_THB verbose 2
#   COLUMNS    field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32
#   CONFIGURATION ./configDB.conf
#   DEF        ./configDB.conf .*:(
#temperature|power|humidity|
#va_temperature|va_humidity|humidity_value|
#desiredTemperature|valveposition|
#/heatSources/systemPressure|
#/heatSources/applianceSupplyTemperature|
#/system/sensors/temperatures/outdoor_t1|
#/system/sensors/temperatures/supply_t1|
#/system/sensors/temperatures/supply_t1_setpoint|
#/dhwCircuits/dhw1/actualTemp|
#/dhwCircuits/dhw1/currentSetpoint|
#/heatSources/systemPressure|
#oilfox_metering_liters).*
#   FD         5
#   FUUID      6395a74c-f33f-fd5f-bf68-e3ca20a9e2cee3df
#   FVERSION   93_DbLog.pm:v5.5.3-s26750/2022-12-10
#   MODE       asynchronous
#   MODEL      MYSQL
#   NAME       dblog_THB
#   NR         2
#   NTFY_ORDER 50-dblog_THB
#   PID        18037
#   REGEXP     .*:(
#temperature|power|humidity|
#va_temperature|va_humidity|humidity_value|
#desiredTemperature|valveposition|
#/heatSources/systemPressure|
#/heatSources/applianceSupplyTemperature|
#/system/sensors/temperatures/outdoor_t1|
#/system/sensors/temperatures/supply_t1|
#/system/sensors/temperatures/supply_t1_setpoint|
#/dhwCircuits/dhw1/actualTemp|
#/dhwCircuits/dhw1/currentSetpoint|
#/heatSources/systemPressure|
#oilfox_metering_liters).*
#   SBP_PID    18038
#   SBP_STATE  running
#   STATE      connected
#   TYPE       DbLog
#   UTF8       0
#   dbconn     mysql:database=fhem;host=localhost;port=3306
#   dbuser     fhemuser
#   eventCount 713
#   HELPER:
#     COLSET     1
#     DEVICECOL  64
#     EVENTCOL   512
#     OLDSTATE   connected
#     PACKAGE    main
#     READINGCOL 64
#     TC         current
#     TH         history
#     TYPECOL    64
#     UNITCOL    32
#     VALUECOL   128
#     VERSION    5.5.3
#   OLDREADINGS:
#   READINGS:
#     2022-12-20 17:57:41   CacheOverflowLastNum 0
#     2022-12-20 10:17:18   CacheOverflowLastState normal
#     2022-12-20 17:57:42   CacheUsage      1
#     2022-12-20 17:57:41   NextSync        2022-12-20 17:58:11 or when CacheUsage 5000 is reached
#     2022-12-20 17:57:41   state           connected
#
setstate dblog_THB connected
setstate dblog_THB 2022-12-20 17:57:41 CacheOverflowLastNum 0
setstate dblog_THB 2022-12-20 10:17:18 CacheOverflowLastState normal
setstate dblog_THB 2022-12-20 17:57:42 CacheUsage 1
setstate dblog_THB 2022-12-20 17:57:41 NextSync 2022-12-20 17:58:11 or when CacheUsage 5000 is reached
setstate dblog_THB 2022-12-20 17:57:41 state connected

dabei werden alle reading in die Datenbank geschrieben bis auf die km200 / Buderus readings:
#/heatSources/systemPressure|
#/heatSources/applianceSupplyTemperature|
#/system/sensors/temperatures/outdoor_t1|
#/system/sensors/temperatures/supply_t1|
#/system/sensors/temperatures/supply_t1_setpoint|
#/dhwCircuits/dhw1/actualTemp|
#/dhwCircuits/dhw1/currentSetpoint|
#/heatSources/systemPressure|

Hallo Thomas,

kannst du deinen Beitrag bitte nochmal editieren (code Tags) .... man kann das nicht wirklich gescheit lesen.
Danke.

Beim Überfliegen bin ich der Ansicht, dass du die Slash der Buderus Readings (ungünstige Gestaltung für das Logging) escapen musst, d.h. "\/heatSources" statt "/heatSources" schreiben. Es wird als regulärer Ausdruck ausgewertet.

habe mal entsprechend umgestellt und auch die backslashes zur Zeilentrennung herausgenommen ...

[code]define dblog_THB DbLog ./configDB.conf .*:(temperature|power|humidity|va_temperature|va_humidity|humidity_value|desiredTemperature|valveposition|\/heatSources/systemPressure|\/heatSources/applianceSupplyTemperature|\/system/sensors/temperatures/outdoor_t1|\/system/sensors/temperatures/supply_t1|\/system/sensors/temperatures/supply_t1_setpoint|\
\/dhwCircuits/dhw1/actualTemp|\
\/dhwCircuits/dhw1/currentSetpoint|\
oilfox_metering_liters).*
attr dblog_THB DbLogType Current/History
attr dblog_THB alias dblog_THB
attr dblog_THB asyncMode 1
attr dblog_THB bulkInsert 0
attr dblog_THB cacheLimit 5000
attr dblog_THB commitMode ac:on_ta:off
attr dblog_THB event-min-interval state:600
attr dblog_THB room DBLog
attr dblog_THB syncInterval 30
attr dblog_THB useCharfilter 1
attr dblog_THB verbose 2
#   COLUMNS    field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32
#   CONFIGURATION ./configDB.conf
#   DEF        ./configDB.conf .*:(temperature|power|humidity|va_temperature|va_humidity|humidity_value|desiredTemperature|valveposition|\/heatSources/systemPressure|\/heatSources/applianceSupplyTemperature|\/system/sensors/temperatures/outdoor_t1|\/system/sensors/temperatures/supply_t1|\/system/sensors/temperatures/supply_t1_setpoint|
#\/dhwCircuits/dhw1/actualTemp|
#\/dhwCircuits/dhw1/currentSetpoint|
#oilfox_metering_liters).*
#   FD         5
#   FUUID      6395a74c-f33f-fd5f-bf68-e3ca20a9e2cee3df
#   FVERSION   93_DbLog.pm:v5.5.3-s26750/2022-12-10
#   MODE       synchronous
#   MODEL      MYSQL
#   NAME       dblog_THB
#   NR         2
#   NTFY_ORDER 50-dblog_THB
#   PID        18037
#   REGEXP     .*:(temperature|power|humidity|va_temperature|va_humidity|humidity_value|desiredTemperature|valveposition|\/heatSources/systemPressure|\/heatSources/applianceSupplyTemperature|\/system/sensors/temperatures/outdoor_t1|\/system/sensors/temperatures/supply_t1|\/system/sensors/temperatures/supply_t1_setpoint|
#\/dhwCircuits/dhw1/actualTemp|
#\/dhwCircuits/dhw1/currentSetpoint|
#oilfox_metering_liters).*
#   SBP_PID    18038
#   SBP_STATE  running
#   STATE      connected
#   TYPE       DbLog
#   UTF8       0
#   dbconn     mysql:database=fhem;host=localhost;port=3306
#   dbuser     fhemuser
#   eventCount 1031
#   HELPER:
#     COLSET     1
#     DEVICECOL  64
#     EVENTCOL   512
#     OLDSTATE   connected
#     PACKAGE    main
#     READINGCOL 64
#     TC         current
#     TH         history
#     TYPECOL    64
#     UNITCOL    32
#     VALUECOL   128
#     VERSION    5.5.3
#   OLDREADINGS:
#   READINGS:
#     2022-12-20 20:35:58   CacheOverflowLastNum 0
#     2022-12-20 10:17:18   CacheOverflowLastState normal
#     2022-12-20 20:36:23   CacheUsage      9
#     2022-12-20 20:35:58   NextSync        2022-12-20 20:36:28 or when CacheUsage 5000 is reached
#     2022-12-20 20:35:58   state           connected
#
setstate dblog_THB connected
setstate dblog_THB 2022-12-20 20:35:58 CacheOverflowLastNum 0
setstate dblog_THB 2022-12-20 10:17:18 CacheOverflowLastState normal
setstate dblog_THB 2022-12-20 20:36:23 CacheUsage 9
setstate dblog_THB 2022-12-20 20:35:58 NextSync 2022-12-20 20:36:28 or when CacheUsage 5000 is reached
setstate dblog_THB 2022-12-20 20:35:58 state connected

[/code]

will aber immer noch nicht schreiben

früher hatte ich einfach alles geloggt und nun auf explizite Angabe umgestellt

was mache ich falsch?

Zum Beispiel dieses

\/system/sensors/temperatures/outdoor_t1

wäre mit Slash Escapes

  \/system\/sensors\/temperatures\/outdoor_t1

Aber eigentlich reicht es doch aus , wenn du nur

   outdoor_t1

verwenden würdest. Dann matcht das Reading ja auch.
Es gibt Regextester wie z.B. https://regex101.com. Dort kannst du deine Regexmuster gegen einen auszuwertenden String testen und damit deine Kombination zusammenstellen.

!!!!!

in die db wird geschrieben :-)

aber in den GPLOTS kommts nicht an...

# Created by FHEM/98_SVG.pm, 2021-05-01 21:46:15
set terminal png transparent size <SIZE> crop
set output '<OUT>.png'
set xdata time
set timefmt "%Y-%m-%d_%H:%M:%S"
set xlabel " "
set title '<TL> <L1>'
set ytics
set y2tics
set grid y2tics
set ylabel "Temperatur in °C / Modulation in %"
set y2label "Aussen-Temperatur in °C"
set yrange [20:105]
set y2range [-20:40]

#dblog_THB <SPEC1>:/system/sensors/temperatures/outdoor_t1::
#dblog_THB <SPEC1>:/system/sensors/temperatures/supply_t1::
#dblog_THB <SPEC1>:/system/sensors/temperatures/supply_t1_setpoint::
#dblog_THB <SPEC1>:/dhwCircuits/dhw1/actualTemp::
#dblog_THB <SPEC1>:/dhwCircuits/dhw1/currentSetpoint::

plot "<IN>" using 1:2 axes x1y2 title 'Aussentemperatur' ls l3 lw 2 with lines,\
     "<IN>" using 1:2 axes x1y1 title 'Vorlauftemperatur' ls l0 lw 1 with lines,\
     "<IN>" using 1:2 axes x1y1 title 'Vorlauftemperatur Set' ls l1 lw 1 with lines,\
     "<IN>" using 1:2 axes x1y1 title 'Warmwasser' ls l2fill lw 1 with lines,\
     "<IN>" using 1:2 axes x1y1 title 'Warmwasser Set' ls l6 lw 1 with lines



wie muss ich hier anpassen ?

Am Besten das Thema in einem SVG Forum vertiefen.
Wir müssen mal ein bisschen die Thread-Hygiene beachten, sonst ufert es aus, kommen vom 100sten ins 1000ste und hier geht es um die DbLog-Umstellung auf V5.  ;)

stimmt ;-)

vielen, vielen Dank!

nun komme ich doch noch mal wegen der Db-selbst:

ich hatte ja deinem Hinweis folgend den Def so geschrieben:

define dblog_THB DbLog ./configDB.conf .*:(temperature|power|humidity|va_temperature|va_humidity|humidity_value|desiredTemperature|valveposition|systemPressure|CHpumpModulation|actualDHWPower|actualCHPower|flameStatus|applianceSupplyTemperature|actualSupplyTemperature|supplyTemperatureSetpoint|outdoor_t1|supply_t1|supply_t1_setpoint|actualTemp|currentSetpoint|charge|chargeDuration|setpoint|singleChargeSetpoint|workingTime|oilfox_metering_liters).*


dann hat das System auch schön die readings supplyTemperatureSetpoint|outdoor_t1|supply_t1|supply_t1_setpoint|actualTemp|currentSetpoint|charge|chargeDuration in die Datenbank geschrieben und dann aber aufgehört
usw.

2022-12-20 20:43:26
Buderus
KM200
/heatSources/applianceSupplyTemperature: 55.1
/heatSources/applianceSupplyTemperature
55.1
C
2022-12-20 21:15:25
Buderus
KM200
/heatSources/applianceSupplyTemperature: 55.4
/heatSources/applianceSupplyTemperature
55.4
C
2022-12-20 21:06:08
Buderus
KM200
/heatSources/applianceSupplyTemperature: 55.7
/heatSources/applianceSupplyTemperature
55.7
C
2022-12-20 21:13:15
Buderus
KM200
/heatSources/applianceSupplyTemperature: 57.4
/heatSources/applianceSupplyTemperature
57.4
C
2022-12-20 20:41:18
Buderus
KM200
/heatSources/applianceSupplyTemperature: 57.7
/heatSources/applianceSupplyTemperature
57.7
C
2022-12-20 20:37:23
Buderus
KM200
/heatSources/applianceSupplyTemperature: 58.5
/heatSources/applianceSupplyTemperature
58.5
C
2022-12-20 21:11:55
Buderus
KM200
/heatSources/applianceSupplyTemperature: 58.9
/heatSources/applianceSupplyTemperature
58.9
C
2022-12-20 21:07:59
Buderus
KM200
/heatSources/applianceSupplyTemperature: 59.7
/heatSources/applianceSupplyTemperature
59.7
C
2022-12-20 20:39:17
Buderus
KM200
/heatSources/applianceSupplyTemperature: 60.4
/heatSources/applianceSupplyTemperature
60.4
C
2022-12-20 21:09:50
Buderus
KM200
/heatSources/applianceSupplyTemperature: 61.4
/heatSources/applianceSupplyTemperature
61.4
C
2022-12-20 20:33:25
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 20:35:35
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 20:37:27
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 20:39:21
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 20:41:22
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 20:44:35
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 20:46:38
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 20:48:31
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 20:50:45
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 20:52:36
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 20:54:28
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 20:56:25
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 20:58:16
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 21:00:38
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 21:02:30
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 21:04:21
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 21:06:12
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 21:08:03
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 21:09:55
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 21:11:59
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 21:13:33
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 21:15:29
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 21:17:23
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
2022-12-20 21:19:14
Buderus
KM200
/heatSources/systemPressure: 25.5
/heatSources/systemPressure
25.5
bar
die zugehörige DbLog DEF sieht so aus:
[code]define dblog_THB DbLog ./configDB.conf .*:(temperature|power|humidity|va_temperature|va_humidity|humidity_value|desiredTemperature|valveposition|systemPressure|CHpumpModulation|actualDHWPower|actualCHPower|flameStatus|applianceSupplyTemperature|actualSupplyTemperature|supplyTemperatureSetpoint|outdoor_t1|supply_t1|supply_t1_setpoint|actualTemp|currentSetpoint|charge|chargeDuration|setpoint|singleChargeSetpoint|workingTime|oilfox_metering_liters).*
attr dblog_THB DbLogExclude state
attr dblog_THB DbLogType Current/History
attr dblog_THB alias dblog_THB
attr dblog_THB asyncMode 1
attr dblog_THB bulkInsert 1
attr dblog_THB cacheLimit 5000
attr dblog_THB commitMode ac:on_ta:off
attr dblog_THB event-min-interval state:600
attr dblog_THB room DBLog
attr dblog_THB syncInterval 30
attr dblog_THB useCharfilter 1
attr dblog_THB verbose 2
#   COLUMNS    field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32
#   CONFIGURATION ./configDB.conf
#   DEF        ./configDB.conf .*:(temperature|power|humidity|va_temperature|va_humidity|humidity_value|desiredTemperature|valveposition|systemPressure|CHpumpModulation|actualDHWPower|actualCHPower|flameStatus|applianceSupplyTemperature|actualSupplyTemperature|supplyTemperatureSetpoint|outdoor_t1|supply_t1|supply_t1_setpoint|actualTemp|currentSetpoint|charge|chargeDuration|setpoint|singleChargeSetpoint|workingTime|oilfox_metering_liters).*
#   FD         5
#   FUUID      63a33b3f-f33f-fd5f-7f81-5787629cdd49cde5
#   FVERSION   93_DbLog.pm:v5.5.3-s26750/2022-12-10
#   MODE       asynchronous
#   MODEL      MYSQL
#   NAME       dblog_THB
#   NR         2
#   NTFY_ORDER 50-dblog_THB
#   PID        9571
#   REGEXP     .*:(temperature|power|humidity|va_temperature|va_humidity|humidity_value|desiredTemperature|valveposition|systemPressure|CHpumpModulation|actualDHWPower|actualCHPower|flameStatus|applianceSupplyTemperature|actualSupplyTemperature|supplyTemperatureSetpoint|outdoor_t1|supply_t1|supply_t1_setpoint|actualTemp|currentSetpoint|charge|chargeDuration|setpoint|singleChargeSetpoint|workingTime|oilfox_metering_liters).*
#   SBP_PID    9572
#   SBP_STATE  running
#   STATE      connected
#   TYPE       DbLog
#   UTF8       0
#   dbconn     mysql:database=fhem;host=localhost;port=3306
#   dbuser     fhemuser
#   eventCount 57
#   HELPER:
#     COLSET     1
#     DEVICECOL  64
#     EVENTCOL   512
#     OLDSTATE   connected
#     PACKAGE    main
#     READINGCOL 64
#     TC         current
#     TH         history
#     TYPECOL    64
#     UNITCOL    32
#     VALUECOL   128
#     VERSION    5.5.3
#   OLDREADINGS:
#   READINGS:
#     2022-12-21 18:27:17   CacheOverflowLastNum 0
#     2022-12-20 10:17:18   CacheOverflowLastState normal
#     2022-12-21 18:27:35   CacheUsage      6
#     2022-12-21 18:27:17   NextSync        2022-12-21 18:27:47 or when CacheUsage 5000 is reached
#     2022-12-21 18:27:18   state           connected
#
setstate dblog_THB connected
setstate dblog_THB 2022-12-21 18:27:17 CacheOverflowLastNum 0
setstate dblog_THB 2022-12-20 10:17:18 CacheOverflowLastState normal
setstate dblog_THB 2022-12-21 18:27:35 CacheUsage 6
setstate dblog_THB 2022-12-21 18:27:17 NextSync 2022-12-21 18:27:47 or when CacheUsage 5000 is reached
setstate dblog_THB 2022-12-21 18:27:18 state connected

[/code]
was läuft da schief?

habe ich etwa im Device  km200 etwas excluded?
es gibt jedenfalls kein diesbezügliches attr:

Attributes
IntervalDynVal
90
deleteattr
PollingTimeout
200
deleteattr
event-min-interval
/heatSources/systemPressure:7200,/system/sensors/temperatures/supply_t1:6000,/system/sensors/temperatures/supply_t1_setpoint:6000
deleteattr
event-on-update-reading
/heatSources/systemPressure,/system/sensors/temperatures/supply_t1
deleteattr
loglevel
1
deleteattr
room
BUDERUS
deleteattr
Probably associated with

Hallo Thomas,

wenn alles funktioniert hat und "plötzlich aufhört" wurde sicherlich etwas geändert .. ?

Geloggt wurden die Readings

Zitat
supplyTemperatureSetpoint|outdoor_t1|supply_t1|supply_t1_setpoint|actualTemp|currentSetpoint|charge|chargeDuration

Aber du erzeugst nur Events von:


/heatSources/systemPressure,/system/sensors/temperatures/supply_t1

bzw.

/system/sensors/temperatures/supply_t1_setpoint:6000


Mich stören wieder die Slashes in den Readings da die Angaben als regulärer Ausdruck gewertet werden.
Möglicherweise werden keine Events generiert. Entweder die Slashes escapen "\/" wie schon mal geschrieben, oder einfach nur so schreiben:


event-on-update-reading = .*systemPressure,.*supply_t1


bzw.


event-min-interval = .*systemPressure:7200,.*supply_t1:6000,.*supply_t1_setpoint:6000


Der Eventmonitor zeigt dir ob und wie Events generiert werden.

Ist aber alles auch wieder ein allgemeines Thema und hat mit der Umstellung auf DbLog V 5 nichts zu tun.  ;)

@SusisStrolch, hattest du gestern die V nochmal mit deinem Szenario gecheckt ?

Zitat von: DS_Starter am 21 Dezember 2022, 21:56:30
Hallo Thomas,

wenn alles funktioniert hat und "plötzlich aufhört" wurde sicherlich etwas geändert .. ?

Geloggt wurden die Readings

Aber du erzeugst nur Events von:

Code Auswählen Erweitern


/heatSources/systemPressure,/system/sensors/temperatures/supply_t1

bzw.

/system/sensors/temperatures/supply_t1_setpoint:6000


Mich stören wieder die Slashes in den Readings da die Angaben als regulärer Ausdruck gewertet werden.
Möglicherweise werden keine Events generiert. Entweder die Slashes escapen "\/" wie schon mal geschrieben, oder einfach nur so schreiben:

Code Auswählen Erweitern


event-on-update-reading = .*systemPressure,.*supply_t1


bzw.

Code Auswählen Erweitern


event-min-interval = .*systemPressure:7200,.*supply_t1:6000,.*supply_t1_setpoint:6000


Der Eventmonitor zeigt dir ob und wie Events generiert werden.

Ist aber alles auch wieder ein allgemeines Thema und hat mit der Umstellung auf DbLog V 5 nichts zu tun.  ;)

hmm

hmm ich logge nun einfach alles. Die Plots funktionieren auch wieder :-)

Jedoch meldet die DB:

2022.12.22 11:23:51 3: dblog_THB_notify_1 return value: HASH(0x3d977a8)
2022.12.22 11:24:21 3: dblog_THB_notify_1 return value: HASH(0x52f1bb8)
2022.12.22 11:24:51 3: dblog_THB_notify_1 return value: HASH(0x4e7e480)
2022.12.22 11:25:21 3: dblog_THB_notify_1 return value: HASH(0x470e188)
2022.12.22 11:25:51 3: dblog_THB_notify_1 return value: HASH(0x517b358)
2022.12.22 11:26:21 3: dblog_THB_notify_1 return value: HASH(0x507c280)
2022.12.22 11:26:51 3: dblog_THB_notify_1 return value: HASH(0x50bd328)

und
2022.12.22 11:30:41 2: DbLog dblog_THB - Error: DBI connect('database=fhem;host=db;port=3306','root',...) failed: Unknown MySQL server host 'db' (-2) at ./FHEM/93_DbLog.pm line 2487.

2022.12.22 11:30:41 2: DbLog dblog_THB - Error: DBI connect('database=fhem;host=db;port=3306','root',...) failed: Unknown MySQL server host 'db' (-2) at ./FHEM/93_DbLog.pm line 2487.

das ist doch die db

wie kriege ich deine neueste distri? mit welchem FHEM Befehl?

Zitat von: thburkhart am 21 Dezember 2022, 18:28:50
wie kriege ich deine neueste distri? mit welchem FHEM Befehl?

https://forum.fhem.de/index.php/topic,130588.msg1250729.html#msg1250729

Zitat von: Frank_Huber am 22 Dezember 2022, 11:49:12
https://forum.fhem.de/index.php/topic,130588.msg1250729.html#msg1250729

habe damit
93_DbLog.pm:v5.5.3-s26750/2022-12-10
waren wir nicht schon bei 5.5.5?

Zitatwaren wir nicht schon bei 5.5.5?

Shutdown / restart gemacht?
https://forum.fhem.de/index.php/topic,130588.msg1250729.html#msg1250729, also
wget -qO ./FHEM/93_DbLog.pm https://svn.fhem.de/fhem/trunk/fhem/contrib/DS_Starter/93_DbLog.pmliefert 5.5.7
kannst die Seite "https://svn.fhem.de/fhem/trunk/fhem/contrib/DS_Starter/" ja mal manuell ansurfen, und den File manuell runterladen, dann im Editor öffnen, und schauen was da für eine Versionsnummer steht.
Sollte nicht so schwer sein.

Zitat von: DS_Starter am 21 Dezember 2022, 23:05:30
@SusisStrolch, hattest du gestern die V nochmal mit deinem Szenario gecheckt ?

Ich hatte am 21. die 5.5.7 installiert.
Prompt auch ein kaputtes Paket empfangen. Ein Cache-File wurde angelegt - anscheinend hat meine valueFn nicht gegriffen.
Hatte aber bisher keine Zeit zur Analyse.

Zitat von: SusisStrolch am 22 Dezember 2022, 19:06:05
... - anscheinend hat meine valueFn nicht gegriffen.

Ist meine DbLogValueFn syntaktisch korrekt (C&P aus raw definition)?
attr logdb DbLogValueFn {    my $flags = Encode::FB_CROAK | Encode::LEAVE_SRC;;\
    my $void = eval {\
        Encode::decode( 'utf-8', $EVENT, $flags );;\
    } || $IGNORE=1\
}

Guten Morgen,

ich habe es ein wenig umgeschrieben. Probiers mal aus.


attr logdb DbLogValueFn
{   
   my $flags = Encode::FB_CROAK | Encode::LEAVE_SRC;
   eval {
        Encode::decode( 'utf-8', $EVENT, $flags );
        1;
    }
    or do {$IGNORE=1;
          };
}

Ansonsten sieht die Reaktion des Devices auf die fehlerhaften Daten soweit gut aus.
Die Daten werden an den Cache zurück gegeben und bei Überlauf des cacheOverflowThreshold wird der Cache in ein File geleert.

@thburkhart,

Zitat
Jedoch meldet die DB:

2022.12.22 11:23:51 3: dblog_THB_notify_1 return value: HASH(0x3d977a8)
2022.12.22 11:24:21 3: dblog_THB_notify_1 return value: HASH(0x52f1bb8)
2022.12.22 11:24:51 3: dblog_THB_notify_1 return value: HASH(0x4e7e480)

Das ist keine Meldung der DB sondern die eines Notify. Was im Notify ausgeführt wird wissen wir nicht, ist aber eine einfache Rückmeldung. verbose 2 hilft hier wenn klar ist dass das Notify richtig arbeitet.

Aber

Zitat
2022.12.22 11:30:41 2: DbLog dblog_THB - Error: DBI connect('database=fhem;host=db;port=3306','root',...) failed: Unknown MySQL server host 'db' (-2) at ./FHEM/93_DbLog.pm line 2487.

lohnt sich mal genauer zu lesen.  Du siehst doch hier steht " failed: Unknown MySQL server host 'db' ". D.h. der übergebene Name des MySQL Rechners ist "db" den das System nicht kennt bzw. nicht auflösen kann.
Du solltest deswegen mal deine Konfigurationsdatei (./configDB.conf) prüfen ob nicht bei dir host=db angegeben ist. Hier ist der Name des Hosts oder dessen IP Adresse anzugeben:

     connection => "mysql:database=fhemtest1;host=192.168.2.44;port=3306",

EDIT: hatte mich verschrieben

Ok, hab mal die geänderte Version eingebaut.
K
Mal schaun wann sich der Fehlerteufel wieder meldet.

Vielen Dank und Frohe Weihnachten!

Ich wünsche allen schöne Festtage !

@SusisStrolch, mir ist noch etwas aufgefallen.

Das Attr DbLogValueFn setzt du in den Quellendevices, nicht im DbLog-Device. Zum Setzen einer Value-Funktion im DbLog-Device benutzt du das Attr valueFn.

Ich verbessere die commandref damit der Zusammenhang klarer wird.

Ah... das erklärt Einiges!

Vielen Dank für den Hinweis.

Wie sieht es bis jetzt aus ?
Ich erwäge nach Weihnachten das Roll-Out vorzunehmen.

Bei mir läuft alles stabil ohne Probleme - Daumen hoch!
Danke für die gute Arbeit!!

 :)  Danke.

Ich habe auch keine Probleme. Sehr schön! Super Arbeit!

Gruss
  Enno

Alles bestens.
Go for it!

Und Danke für die Arbeit die diu da reinsteckst!

Hallo zusammen,

vielen Dank für eure Rückmeldungen und für eure Mitarbeit in den Tests bzw. Unterstützung.
Danke an Rudi für die Unterstützung der SubProcess-Verwendung in der fhem.pl (Start Prio).

Ich habe jetzt die neue V eingecheckt und sie wird morgen früh im Update verteilt.
Eine Zusammenfassung der Änderungen für den User habe ich hier hinterlegt: https://forum.fhem.de/index.php/topic,130743.msg1253560.html#msg1253560

Es gibt zwar noch einges zu tun im DbLog, zum Beispiel die Erweiterung des SVG Editors.

Jetzt liegt der Fokus aber erstmal auf den Rollout der Version und die Abarbeitung möglicher Probleme die evtl. doch noch bei
den Usern auftreten.
Ich bin aber dank euch optimistisch.  :)

LG,
Heiko

Die Statusanzeige des DbLog in einer Raumübersicht sprengt bei mir den kompletten Bildschirm, wenn die Anzeige von "Connected" auf irgendwas mit "Another process... bla..." (das geht so schnell, dass ich die Meldung nicht lesen kann) wechselt.

Außerdem wäre es "schön", wenn diese Meldung

connection params saved into SubProcess. Connection to DB is established when it is needed

zweizeilig ausgegeben würde.

Guten Morgen,

Die Meldung die du kurz siehst ist:

Another operation is in progress - data is stored temporarily (check with listCache)


Die Meldung kommt wenn neue Daten zum Schreiben an den Childprozess gesendet werden sollen, der vorherige Lauf
aber noch nicht abgeschlossen ist.
Wenn es nur sehr kurz präsent ist, dann ist es gerade so eine Grenzsituation denn normalerwiese kommt bei hinreichend schneller DB im Verhältnis zur Schreibfrequenz der Daten im synchronen Modus keine Meldung.

Ich kürze es etwas ein und gebe die Meldung auch zweizeilig aus wie auch dein Vorschlag bzgl. der anderen Meldung.
Ist eine gute Idee. Ich schaue nach ob ich noch mehr längere Meldungen habe, die setze ich auch gleich auf zweizeilig um.

Habe die V 5.5.8 eingecheckt:

* lange (planmäßige) Meldungen werden im state zweizeilig ausgegeben

* die Meldung "Another operation is in progress. Data is stored temporarily." (zweizeilig) wird im synchronen Modus erst dann ausgegeben wenn
   die vorangegangene Operation sich mit der neuen Anforderung mehr als ein zeitlicher Schwellenwert (aktuell 0.8 s) überschneidet.
   Das wird die Häufigkeit der Meldung reduzieren und nur "markantere" Fälle dem User im state mitteilen.

Hi,

ich habe ggf. einen Fehler in der neuen Version entdeckt.
Update auf die 5.x lief gestern problemlos durch.
Als ich heute aber meine regexp innerhalb des define angepasst habe, wird mir direkt nach dem "save"
eine Fehlermeldung angezeigt:

2022-12-28 18:50:09 DbLog myDbLog DBD::Pg::st execute failed: ERROR:  relation "history" does not exist LINE 1: INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING...                     ^ [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES ('2022-12-28 18:50:09','myDbLog','DBLOG','state: waiting for connection','state','waiting for connection',''),('2022-12-28 18:50:00','tankenPreis','JSONMOD','preis: 1.819','preis','1.819','')"] at ./FHEM/93_DbLog.pm line 2757.

Ab diesem Moment wird auch nichts mehr in die "history" Tabelle geschrieben und das Logfile mit diesen Fehlern geflutet.
Wenn ich fhem danach restarte, funktioniert wieder alles problemlos.


Aktuelle config:

defmod myDbLog DbLog /opt/fhem/config/db.conf (?i).*(temperature|humidity|preis|state):.*
attr myDbLog DbLogType Current/History
attr myDbLog asyncMode 1
attr myDbLog bulkInsert 1
attr myDbLog dbSchema fhem
attr myDbLog showproctime 1

FVERSION   93_DbLog.pm:v5.5.8-s26907/2022-12-27

Habe leider meine beiden FHEM Installationen schon auf die neue Version hochgezogen und kann daher nicht prüfen, ob das Problem schon vorher bestand. Allerdings habe ich vor einiger Zeit problemlos meine regexp "on-the-fly" anpassen können.

 :)Danke für das Update.

@DS_Starter

* Update:Scheint ähnlich wie nog76 seine Meldung zu sein.
   Allerdings ist die Fehlermeldung eine andere..

Bitte schau einmal kurz in diesem Thread, ob da ein Zusammenhang mit den aktualisierten Modul sein kann.
Wir können gerne auch hier weiterschreiben..

https://forum.fhem.de/index.php?topic=25540.msg1254042#msg1254042

@cortmen, nein ist kein Zusammenhang. Habe dir die Lösung geschrieben.

@nog76, deine Meldung ist ein Fehler der direkt von der Datenbank gemeldet wird:


DBD::Pg::st execute failed: ERROR:  relation "history" does not exist


Da muss ich erstmal googeln was das konkret bei Postgre bedeuten soll. Sieht mir auf den ersten Blick so aus als ob die
Verbindung zur DB verloren gegangen war.
Das Modul bringt jetzt mehr detaillierte Meldungen bei Fehlern raus. Kann sein dass sowas früher nicht aufgefallen war.
Einen direkten Zusammenhang mit dem drücken von "save" schließe ich aus. Habe gerade bei mir mit MariaDB gecheckt -> kein Problem.
Kannst mal schauen ob du den Fehler nochmal bewußt reproduzieren kannst.

@nog76, zeig mir bitte ein list von deinem DbLog-Device.

Hi, hier erstmal ein list vom device

Internals:
   COLUMNS    field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32
   CONFIGURATION /opt/fhem/config/db.conf
   DEF        /opt/fhem/config/db.conf .*(temperature|humidity|preis|state):.*
   FD         4
   FUUID      624de2e1-f33f-1758-5c38-6b56f60aeffc8515
   FVERSION   93_DbLog.pm:v5.5.8-s26907/2022-12-27
   MODE       asynchronous
   MODEL      POSTGRESQL
   NAME       myDbLog
   NR         2
   NTFY_ORDER 50-myDbLog
   PID        313435
   REGEXP     .*(temperature|humidity|preis|state):.*
   SBP_PID    313442
   SBP_STATE  running
    STATE      connected
   TYPE       DbLog
   dbconn     Pg:database=fhemlog;host=localhost
   dbuser     qqfhemlog
   eventCount 6
   HELPER:
     COLSET     1
     DEVICECOL  64
     EVENTCOL   512
     OLDSTATE   connected
     PACKAGE    main
     READINGCOL 64
     TC         fhem.current
     TH         fhem.history
     TYPECOL    64
     UNITCOL    32
     VALUECOL   128
     VERSION    5.5.8
   OLDREADINGS:
   READINGS:
     2022-12-28 19:54:13   CacheOverflowLastNum 0
     2022-04-06 20:58:41   CacheOverflowLastState normal
     2022-12-28 19:54:43   CacheUsage      0
     2022-12-28 19:54:43   NextSync        2022-12-28 19:55:13 or when CacheUsage 500 is reached
     2022-12-28 19:54:13   background_processing_time 0.0159
     2022-12-28 19:54:13   sql_processing_time 0.0123
     2022-12-28 19:54:43   state           connected
Attributes:
   DbLogType  Current/History
   asyncMode  1
   bulkInsert 1
   dbSchema   fhem
   showproctime 1
   verbose    5

Versuche gerade das Verhalten nochmal mit verbose=5 zu reproduzieren.

und hier nochmal ein Log:

2022.12.28 19:59:18 4 : DbLog myDbLog - ################################################################
2022.12.28 19:59:18 4 : DbLog myDbLog - ###              start of new Logcycle                       ###
2022.12.28 19:59:18 4 : DbLog myDbLog - ################################################################
2022.12.28 19:59:18 4 : DbLog myDbLog - number of events received: 1 of device: myDbLog
2022.12.28 19:59:18 4 : DbLog myDbLog - check Device: myDbLog , Event: state: DBD::Pg::st execute failed: ERROR:  relation "history" does not exist
LINE 1: INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING...
                    ^ [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES ('2022-12-28 19:59:18','myDbLog','DBLOG','state: waiting for connection','state','waiting for connection','')"] at ./FHEM/93_DbLog.pm line 2757.
2022-12-28 19:59:18 DbLog myDbLog waiting for connection
2022-12-28 19:59:18 DbLog myDbLog CacheUsage: 1
2022-12-28 19:59:18 DbLog myDbLog CacheOverflowLastNum: 0
2022-12-28 19:59:18 Global global MODIFIED myDbLog
2022-12-28 19:59:18 DbLog myDbLog <html>Connection parameters saved into SubProcess. <br>Connection to DB is established when it is needed.</html>
2022-12-28 19:59:18 DbLog myDbLog CacheUsage: 1
2022-12-28 19:59:18 DbLog myDbLog DBD::Pg::st execute failed: ERROR:  relation "history" does not exist LINE 1: INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING...                     ^ [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES ('2022-12-28 19:59:18','myDbLog','DBLOG','state: waiting for connection','state','waiting for connection','')"] at ./FHEM/93_DbLog.pm line 2757.

Für mich sieht es so aus, als würde nach der Änderung das Attribut "scheme" nicht mehr genutzt zu werden - in Postgres verwende ich fhem.history (also schema.tabelle).

Zitat
Für mich sieht es so aus, als würde nach der Änderung das Attribut "scheme" nicht mehr genutzt zu werden - in Postgres verwende ich fhem.history (also schema.tabelle).

Den Verdacht hatte ich jetz auch, deswegen die Frage bzgl. List.
Ich prüfe das gerade.

Lass bitte verbose = 5 eingestellt und führe ein "set ... stopSubProcess" aus.
In dem Log wird es viele Meldungen geben.
Interessant ist dann dieser Teil:


2022.12.28 20:15:52.711 3: DbLog LogDB1 - DB connection parameters are stored in SubProcess
2022.12.28 20:15:52.713 5: DbLog LogDB1 -  current -> current
2022.12.28 20:15:52.714 5: DbLog LogDB1 -  dbuser -> fhemtest1
2022.12.28 20:15:52.714 5: DbLog LogDB1 -  utf8 -> 1
2022.12.28 20:15:52.715 5: DbLog LogDB1 -  cm -> basic_ta:off
2022.12.28 20:15:52.715 5: DbLog LogDB1 -  model -> MYSQL
2022.12.28 20:15:52.716 5: DbLog LogDB1 -  dbconn -> mysql:database=fhemtest1;host=192.168.2.44;port=3306
2022.12.28 20:15:52.717 5: DbLog LogDB1 -  dbpassword -> xxxxxxxxx
2022.12.28 20:15:52.717 5: DbLog LogDB1 -  dbname -> fhemtest1
2022.12.28 20:15:52.718 5: DbLog LogDB1 -  dbstorepars -> 1
2022.12.28 20:15:52.718 5: DbLog LogDB1 -  history -> history


Am einfachsten ist es im Log nach "DB connection parameters are stored in SubProcess" zu suchen.

Hier der Logauszug nach stopSubProcess:

2022.12.28 20:23:49 5: DbLog myDbLog - MemCache contains:  39 -> 2022-12-28 20:23:23|myDbLog|DBLOG|state: SubProcess stopped and will be automatically restarted if needed|state|SubProcess stopped and will be automatically restarted if needed|
2022.12.28 20:23:50 3: DbLog myDbLog - DB connection parameters are stored in SubProcess
2022.12.28 20:23:50 5: DbLog myDbLog -  history -> history
2022.12.28 20:23:50 5: DbLog myDbLog -  model -> POSTGRESQL
2022.12.28 20:23:50 5: DbLog myDbLog -  dbpassword -> *********
2022.12.28 20:23:50 5: DbLog myDbLog -  dbconn -> Pg:database=fhemlog;host=localhost
2022.12.28 20:23:50 5: DbLog myDbLog -  current -> current
2022.12.28 20:23:50 5: DbLog myDbLog -  cm -> basic_ta:on
2022.12.28 20:23:50 5: DbLog myDbLog -  utf8 -> 0
2022.12.28 20:23:50 5: DbLog myDbLog -  dbuser -> qqfhemlog
2022.12.28 20:23:50 5: DbLog myDbLog -  dbstorepars -> 1
2022.12.28 20:23:50 5: DbLog myDbLog -  dbname -> fhemlog

Danke. Problem erkannt:

Zitat
2022.12.28 20:23:50 5: DbLog myDbLog -  history -> history
2022.12.28 20:23:50 5: DbLog myDbLog -  model -> POSTGRESQL
2022.12.28 20:23:50 5: DbLog myDbLog -  dbpassword -> *********
2022.12.28 20:23:50 5: DbLog myDbLog -  dbconn -> Pg:database=fhemlog;host=localhost
2022.12.28 20:23:50 5: DbLog myDbLog -  current -> current

Jetzt schaue ich nach der Lösung.

Super.
Nach dem Restart wird das Schema auch korrekt gelogged:

2022.12.28 20:31:10 5: DbLog myDbLog -  history -> fhem.history
...
2022.12.28 20:31:10 5: DbLog myDbLog -  current -> fhem.current

So, denke Problem beseitigt.
Kannst du bitte die Testversion aus meinem contrib laden und restarten ?
Danach mal testen ob das Problem beseitigt ist.

In der Brower Kommandozeile:

"wget -qO ./FHEM/93_DbLog.pm https://svn.fhem.de/fhem/trunk/fhem/contrib/DS_Starter/93_DbLog.pm"


oder aus dem Link im Footer.

Hi,

Danke - habe die neue Version eingespielt und der Fehler scheint behoben zu sein.
Ich lasse es mal weiter über Nacht in meinem Testsystem laufen und probiere morgen das gleiche in PROD.

Danke für den schnellen Bugfix :-)

Guten Morgen,

über Nacht lief alles problemlos auf dem Testsystem durch.
Habe daher auch mein PROD-System mit der Bugfix-Version versehen - auch hier kann ich den Bug nicht mehr nachstellen.
Damit ist der Fehler aus meiner Sicht behoben (und wird ja auch schon per Update ausgespielt).

Allerdings habe ich noch ein weiteres Finding:
Bei mir steht das Attribut asyncMode auf 1 - und daher wird in den Internals bei MODE=asynchronous angezeigt.

Internals:

   FVERSION   93_DbLog.pm:v5.5.9-s26907/2022-12-27
   MODE       asynchronous

Wenn ich jedoch eine Änderung wieder in der regex vornehme, wechselt die Anzeige auf MODE=synchronous

Internals:
   FVERSION   93_DbLog.pm:v5.5.9-s26907/2022-12-27
   MODE       synchronous

Wenn ich das Attribut nochmal manuell setze, wechselt die Anzeige auch wieder auf asynchronous.

Zitat
Allerdings habe ich noch ein weiteres Finding:
Bei mir steht das Attribut asyncMode auf 1 - und daher wird in den Internals bei MODE=asynchronous angezeigt.

Danke, Ist gefixt im contrib.
Ich habe die Lösung von gestern auch nochmal abgeändert. So richtig gefallen hat es mir nicht.
Deswegen die Version nochmal aus dem contrib ziehen und beide Fixes testen.

LG

Habe die neueste Version jetzt getestet:
Beide Probleme sind damit behoben :-)

Sehr schön.
Ich checke die neue V ein. Sie ist dann morgen früh im Update enthalten.

Guten Neues wünsche ich allen!

eben stelle ich fest, dass mein FHEM sich nicht mehr updated:
Result of version check
Used Perl version: 5.32.1
Used DBI (Database independent interface) version: 1.643
Used DBD (Database driver) version Undefined
Used DbLog version: 5.5.3.
A new DbLog version is available (creation time: 2022-12-30_07:45:03, size: 469411 bytes)
Recommendation: You should update FHEM to get the recent DbLog version from repository !

habe mehrfach update gefahren; dennoch

Downloading https://fhem.de/fhemupdate/controls_fhem.txt

fhem
List of new / modified files since last update:
UPD ./CHANGED
UPD FHEM/00_KNXIO.pm
UPD FHEM/00_MQTT2_CLIENT.pm
UPD FHEM/00_MQTT2_SERVER.pm
UPD FHEM/01_FHEMWEB.pm
UPD FHEM/10_CUL_HM.pm
UPD FHEM/10_KNX.pm
UPD FHEM/36_ShellyMonitor.pm
UPD FHEM/70_ESCVP21net.pm
UPD FHEM/70_SVDRP.pm
UPD FHEM/93_DbLog.pm
UPD FHEM/93_DbRep.pm
UPD FHEM/93_FHEM2FHEM.pm
UPD FHEM/98_DOIF.pm
UPD FHEM/98_HMinfo.pm
UPD FHEM/98_monitoring.pm
UPD FHEM/HttpUtils.pm
UPD FHEM/lib/AttrTemplate/mqtt2.template
UPD docs/commandref_frame.html
UPD docs/commandref_frame_DE.html
UPD lib/FHEM/SynoModules/SMUtils.pm
UPD www/images/fhemSVG/automower.svg
Downloading https://raw.githubusercontent.com/dominikkarall/fhempy/master/controls_pythonbinding.txt

pythonbinding
nothing to do...

im Log steht:

2023.01.02 12:10:52 1 : open ./FHEM/93_DbLog.pm failed: Permission denied, trying to restore the previous version and aborting the update

liegt es daran? und was tun?

vielen Dank

Thomas

Hallo Thomas,

die gleichen Wünsche von mir!

Du gehst auf Betriebssystemnebene und machst das File beschreibbar:


   sudo chown fhem:dialout /opt/fhem/FHEM/93_DbLog.pm
   sudo chmod 775 /opt/fhem/FHEM/93_DbLog.pm


Das Update sollte dann wieder laufen.

LG

oh danke

update lief wieder ..

ich habe immer noch den Fehler:

2023.01.02 16:03:02 3: dblog_THB_notify_1 return value: HASH(0x5351fd0)
2023.01.02 16:03:32 3: dblog_THB_notify_1 return value: HASH(0x543fff0)
2023.01.02 16:04:02 3: dblog_THB_notify_1 return value: HASH(0x5439c60)
2023.01.02 16:04:32 3: dblog_THB_notify_1 return value: HASH(0x524e098)
2023.01.02 16:05:02 3: dblog_THB_notify_1 return value: HASH(0x4b673b8)
2023.01.02 16:05:32 3: dblog_THB_notify_1 return value: HASH(0x51db9f8)
2023.01.02 16:06:02 3: dblog_THB_notify_1 return value: HASH(0x4b51e68)

Zitatich habe immer noch den Fehler:

Das ist imho kein Fehler, sondern nur eine Rückmeldung des Notify dblog_THB_notify_1 (wie schon geschrieben).
Wenn das notify tut, was es soll, setzt  du in dem notify verbose=2.

Kannst uns ja mal ein List des Notify zeigen.

Zitat von: DS_Starter am 02 Januar 2023, 16:16:19

Kannst uns ja mal ein List des Notify zeigen.

gerne:
[code]define dblog_THB_notify_1 notify dblog_THB:CacheOverflowLastNum:.0 {}
#   DEF        dblog_THB:CacheOverflowLastNum:.0 {}
#   FUUID      63a190a0-f33f-fd5f-0099-c04e18177b54e33b
#   NAME       dblog_THB_notify_1
#   NOTIFYDEV  dblog_THB
#   NR         44
#   NTFY_ORDER 50-dblog_THB_notify_1
#   REGEXP     dblog_THB:CacheOverflowLastNum:.0
#   STATE      2023-01-02 16:40:33
#   TRIGGERTIME 1672674033.07242
#   TYPE       notify
#   READINGS:
#     2023-01-02 16:01:10   state           active
#     2023-01-02 16:40:33   triggeredByDev  dblog_THB
#     2023-01-02 16:40:33   triggeredByEvent CacheOverflowLastNum: 0
#
setstate dblog_THB_notify_1 2023-01-02 16:40:33
setstate dblog_THB_notify_1 2023-01-02 16:01:10 state active
setstate dblog_THB_notify_1 2023-01-02 16:40:33 triggeredByDev dblog_THB
setstate dblog_THB_notify_1 2023-01-02 16:40:33 triggeredByEvent CacheOverflowLastNum: 0

[/code]

habe ja null Ahnung was das überhaupt mach oder machen soll

Zitat
habe ja null Ahnung was das überhaupt mach oder machen soll

Und warum hast du es dann angelegt ?  :)

Also das kannst du löschen, tut sowieso nichts:

  DEF        dblog_THB:CacheOverflowLastNum:.0 {}

Ich möchte gerne mitmachen zum testn.

Ich empfinde seit etwa 27-12-2022 auch selber ein Problem mit Dblog das ich nur lösen könnte durch ein altere Version (dd 22-12-2022) zu benutzen. Als ich das Insert das hier gezeigt wird selber mit phpmyadmin ins DB eintrage gibt es kein Problem, ebenso mit der altere 4.x.x Version.

2023.01.04 15:17:47 2: DbLog EnergieDB - Error table history - DBD::mysql::st execute failed: Incorrect string value: '\x94\x06' for column `fhem`.`history`.`EVENT` at row 1 [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES ('2023-01-04 15:17:46','Energiemeter','SMARTMETERHANS','ElectricityProducedNormalTariff: 0.000 kWh▒','ElectricityProducedNormalTariff','0.000 kWh▒','')"] at ./FHEM/93_DbLog.pm line 2755.

2023.01.04 15:17:51 4: ZoneMinder (MijnZM) SimpleGet calling http://192.168.1.9/zm/api/host/getLoad.json with callback CODE(0x37e7fa8)
2023.01.04 15:18:17 2: DbLog EnergieDB - Error table history - DBD::mysql::st execute failed: Incorrect string value: '\x94\x06' for column `fhem`.`history`.`EVENT` at row 1 [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES ('2023-01-04 15:17:46','Energiemeter','SMARTMETERHANS','ElectricityProducedNormalTariff: 0.000 kWh▒','ElectricityProducedNormalTariff','0.000 kWh▒','')"] at ./FHEM/93_DbLog.pm line 2755.

2023.01.04 15:18:41 3: Nmap (Harijn3) - starting network scan
2023.01.04 15:18:47 2: DbLog EnergieDB - Error table history - DBD::mysql::st execute failed: Incorrect string value: '\x94\x06' for column `fhem`.`history`.`EVENT` at row 1 [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES ('2023-01-04 15:17:46','Energiemeter','SMARTMETERHANS','ElectricityProducedNormalTariff: 0.000 kWh▒','ElectricityProducedNormalTariff','0.000 kWh▒','')"] at ./FHEM/93_DbLog.pm line 2755.

2023.01.04 15:18:48 3: Nmap (Harijn3) - network scan done
2023.01.04 15:18:51 4: ZoneMinder (MijnZM) SimpleGet calling http://192.168.1.9/zm/api/host/getLoad.json with callback CODE(0x37e7fa8)
2023.01.04 15:19:17 2: DbLog EnergieDB - Error table history - DBD::mysql::st execute failed: Incorrect string value: '\x94\x06' for column `fhem`.`history`.`EVENT` at row 1 [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES ('2023-01-04 15:17:46','Energiemeter','SMARTMETERHANS','ElectricityProducedNormalTariff: 0.000 kWh▒','ElectricityProducedNormalTariff','0.000 kWh▒','')"] at ./FHEM/93_DbLog.pm line 2755.

2023.01.04 15:19:47 2: DbLog EnergieDB - Error table history - DBD::mysql::st execute failed: Incorrect string value: '\x94\x06' for column `fhem`.`history`.`EVENT` at row 1 [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES ('2023-01-04 15:17:46','Energiemeter','SMARTMETERHANS','ElectricityProducedNormalTariff: 0.000 kWh▒','ElectricityProducedNormalTariff','0.000 kWh▒','')"] at ./FHEM/93_DbLog.pm line 2755.

2023.01.04 15:19:52 4: ZoneMinder (MijnZM) SimpleGet calling http://192.168.1.9/zm/api/host/getLoad.json with callback CODE(0x37e7fa8)
2023.01.04 15:20:13 1: RMDIR: ./restoreDir/save/2022-12-29
2023.01.04 15:20:17 2: DbLog EnergieDB - Error table history - DBD::mysql::st execute failed: Incorrect string value: '\x94\x06' for column `fhem`.`history`.`EVENT` at row 1 [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES ('2023-01-04 15:17:46','Energiemeter','SMARTMETERHANS','ElectricityProducedNormalTariff: 0.000 kWh▒','ElectricityProducedNormalTariff','0.000 kWh▒',''),('2023-01-04 15:20:07','Airco','MQTT_DEVICE','Kamertemperatuur: 20.0','Kamertemperatuur','20.0',''),('2023-01-04 15:20:07','Airco','MQTT_DEVICE','Buitentemperatuur: 11.5','Buitentemperatuur','11.5',''),('2023-01-04 15:20:16','Energiemeter','SMARTMETERHANS','ElectricityPowerDelivered: 0.41 kW','ElectricityPowerDelivered','0.41 kW','')"] at ./FHEM/93_DbLog.pm line 2755.

Hallo hansrijn,

gerne. Ich habe wegen eines anderen Falles ein neues Release erstellt. Es befindet sich im contrib und du kannst es gerne herunterladen und testen (Neustart nicht vergessen).

Davon abgesehen sind deine Daten aber nicht sauber. Der Hex-Code  '\x94\x06' (lt. ASCII Tabelle wäre das "^ACK" ?) findet sich so wie es aussieht am Ende jeder Zeile und wird als nichtdruckbares Zeichen dargestellt.
Steht die Frage wo das herkommt, sicher nicht von DbLog.

Ich gehe davon aus dass du das Attr bulkInsert= 1  gesetzt hast, richtig ?

Du kannst auch mit der aktuellen V das Attr useCharfilter = 1 setzen und das Problem wahrscheinlich beseitigen.
Es wird interessant werden ob du auch ohne dieses Attr zu setzen mit der contrib Version 5.5.10 das Problem beseitigen wirst.

Zitat von: DS_Starter am 04 Januar 2023, 17:07:15
Steht die Frage wo das herkommt, sicher nicht von DbLog.

VALUES ('2023-01-04 15:17:46','Energiemeter','SMARTMETERHANS',...

device TYPE = SMARTMETERHANS ???

Das ist irgendwas selbstgestricktes...

Zitat von: DS_Starter am 02 Januar 2023, 16:50:41
Und warum hast du es dann angelegt ?  :)

Also das kannst du löschen, tut sowieso nichts:

  DEF        dblog_THB:CacheOverflowLastNum:.0 {}

aus Unwissen ;-)
vielen Dank für die Aufklärung

Moin!
Ich mache mal einen Querverweis, da ich nicht so genau weiß, wo das Thema zu verorten ist. Ich habe - gefühlt seit der Umstellung im dblog - einen extrem langsamen Aufbau meiner SVGs. Die brauchen 20 Sekunden während die Seite drumrum schon da ist.
Details hier:
https://forum.fhem.de/index.php/topic,131396.0.html

Bin für Hinweise dankbar. Falls es hilft, hier das Listing von dblog:
Internals:
   COLUMNS    field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32
   CONFIGURATION ./db.conf
   DEF        ./db.conf .*:(1.ACTUAL_TEMPERATURE|1.HUMIDITY).*
   FD         5
   FUUID      5ff78651-f33f-d7f8-4c3f-689a9e08ff48d5d8
   FVERSION   93_DbLog.pm:v5.5.9-s26923/2022-12-29
   MODE       asynchronous
   MODEL      MYSQL
   NAME       logdb
   NR         2
   NTFY_ORDER 50-logdb
   PID        4164
   REGEXP     .*:(1.ACTUAL_TEMPERATURE|1.HUMIDITY).*
   SBP_PID    4177
   SBP_STATE  running
   STATE      connected
   TYPE       DbLog
   UTF8       1
   dbconn     mysql:database=fhem;host=192.168.178.2;port=3306
   dbuser     fhem
   eventCount 37
   HELPER:
     COLSET     1
     DEVICECOL  64
     EVENTCOL   512
     OLDSTATE   connected
     PACKAGE    main
     READINGCOL 64
     TC         current
     TH         history
     TYPECOL    64
     UNITCOL    32
     VALUECOL   128
     VERSION    5.5.9
   OLDREADINGS:
   READINGS:
     2023-01-06 10:21:50   CacheOverflowLastNum 0
     2022-01-28 09:41:23   CacheOverflowLastState normal
     2023-01-06 10:21:50   CacheUsage      4
     2023-01-06 10:21:50   NextSync        2023-01-06 10:22:20 or when CacheUsage 500 is reached
     2023-01-06 10:21:51   state           connected
Attributes:
   DbLogSelectionMode Include
   asyncMode  1
   room       Zentral->Zentral

Speziell zu SVG + Umstellung DbLog verweise ich auf:  https://forum.fhem.de/index.php/topic,130743.msg1253560.html#msg1253560 -> keine Änderungen !

Aber in deinem verlinkten Beitrag sehe ich Einträge die nicht ok sind.

Da die V5 abwärtskompatibel zur V4 ist, kannst du dir die letzte V4 laden und vergleichend testen.
Die letzte V4 kannst du hier laden:

https://svn.fhem.de/trac/browser/trunk/fhem/FHEM/93_DbLog.pm?rev=26750

Moin Heiko,
macht es für mich schon Sinn diese Version zu verwenden? Du weißt ja was ich so alles für SQL kapriolen treibe :-)

VG  Christian

Ja. Für deine SQL nutzt du ja Rep.
Die neue DbLog hat vor allem die Schreibvorgänge in einen subprocess verlagert.

Hallo @all,

im contrib ist die V 5.5.10 bereitgestellt.

In die Version sind einige Code Erweiterungen/Änderungen eingeflossen, die diverse Optimierungen und Fehlerbeseitigungen bzgl. verschiedener gemeldeter Issues beinhalten.

Es würde mich freuen wenn ein paar User die Version bei sich gegenchecken würden bevor ich sie demnächst veröffentliche.
Zum Download in der FHEMWEB Kommandozeile inklusive der Anführungszeichen angeben und danach FHEM restarten:


"wget -qO ./FHEM/93_DbLog.pm https://svn.fhem.de/fhem/trunk/fhem/contrib/DS_Starter/93_DbLog.pm"


schönen Restsonntag,
Heiko

Hi Heiko,

ich habe seit dem Update ein Problem:

Ich verwende die MariaDB auf einem Synology NAS. Einmal pro Nacht wird durch die eingebaute Backup-Funktionalität der DB-Server kurz ausgeschaltet. Bisher war das kein Problem, die Verbindung war halt kurz weg, die Log-Einträge wurden gecached und dann nach einiger Zeit, wenn der Server wieder da war, in die DB geschrieben.

Mit der neuen Version funktioniert das aber nicht, scheinbar kommt keine Verbindung zur DB mehr zu Stand und es treten Fehlermeldungen im Log auf.

Außerdem wird das Log vollgeschrieben mit den genauen SQL Statements, so dass es in kurzer Zeit mehrere GB groß wird und irgendwann die Festplatte vollläuft.

Ich habe versucht das Problem zu beheben, in dem ich manuell "reopen", "rereadcfg" und "stopSubProcess" ausführe, aber das hat alles nichts gebracht. Was geholfen hat ist ein Neustart von FHEM; danach funktioniert die Verbindung wieder (bis zum nächsten Backup).

Bei einem neuen Versuch habe ich, als das Problem wieder auftrat, "bulkInsert" gelöscht (war vorher 1) und das Schreiben in die DB hat wieder funktioniert, ohne dass ich FHEM neustarten musste.

Hier ein paar Logs:
2023.01.08 04:31:24 2: DbLog logdb - Error: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2597.
2023.01.08 04:31:24 2: DbLog logdb - Error: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2597.
2023.01.08 04:31:24 2: DbLog logdb - Error: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2597.
2023.01.08 04:31:24 2: DbLog logdb - Error: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2597.
2023.01.08 04:31:40 2: DbLog logdb - Error: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2597.
2023.01.08 04:31:40 2: DbLog logdb - Error: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2597.
2023.01.08 04:31:40 2: DbLog logdb - Error: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2597.
2023.01.08 04:31:40 2: DbLog logdb - Error: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2597.
2023.01.08 04:31:56 3: DbLog logdb - SubProcess connected to fhem
2023.01.08 04:31:56 2: DbLog logdb - Error table history - DBD::mysql::st execute failed: MySQL server has gone away [for Statement "INSERT IGNORE INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (...)"] at ./FHEM/93_DbLog.pm line 2755.
2023.01.08 04:31:56 2: DbLog logdb - Error - DBD::mysql::db rollback failed: Turning on AutoCommit failed at ./FHEM/93_DbLog.pm line 4170.
2023.01.08 04:31:57 1: PERL WARNING: (in cleanup) DBD::mysql::db DESTROY failed: MySQL server has gone away at ./FHEM/93_DbLog.pm line 2439.
2023.01.08 04:31:57 2: DbLog logdb - Error table history - Can't call method "prepare" on unblessed reference at ./FHEM/93_DbLog.pm line 2746.
2023.01.08 04:31:57 2: DbLog logdb - Error - Can't call method "rollback" on unblessed reference at ./FHEM/93_DbLog.pm line 4170.
2023.01.08 04:32:23 3: DbLog logdb - SubProcess connected to fhem
2023.01.08 04:32:23 2: DbLog logdb - Error table history - DBD::mysql::st execute failed: MySQL server has gone away [for Statement "INSERT IGNORE INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (...)"] at ./FHEM/93_DbLog.pm line 2755.
2023.01.08 04:32:23 2: DbLog logdb - Error - DBD::mysql::db rollback failed: Turning on AutoCommit failed at ./FHEM/93_DbLog.pm line 4170.
2023.01.08 04:32:26 2: DbLog logdb - Error table history - Can't call method "prepare" on unblessed reference at ./FHEM/93_DbLog.pm line 2746.
2023.01.08 04:32:26 2: DbLog logdb - Error - Can't call method "rollback" on unblessed reference at ./FHEM/93_DbLog.pm line 4170.

Und später dann, als die DB wieder da war:
2023.01.08 09:24:10 2: DbLog logdb - Error - DBD::mysql::db rollback failed: Turning on AutoCommit failed at ./FHEM/93_DbLog.pm line 4170.
2023.01.08 09:24:14 2: DbLog logdb - Error table history - Can't call method "prepare" on unblessed reference at ./FHEM/93_DbLog.pm line 2746.
2023.01.08 09:24:14 2: DbLog logdb - Error - Can't call method "rollback" on unblessed reference at ./FHEM/93_DbLog.pm line 4170.
2023.01.08 09:24:20 3: DbLog logdb - Database disconnected by request. <br>Stored DB params in SubProcess were deleted.
2023.01.08 09:24:20 3: DbLog logdb - DB connection parameters are stored in SubProcess
2023.01.08 09:24:28 3: DbLog logdb - SubProcess connected to fhem
2023.01.08 09:24:34 2: DbLog logdb - Error table history - DBD::mysql::st execute failed: MySQL server has gone away [for Statement "INSERT IGNORE INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (...)"] at ./FHEM/93_DbLog.pm line 2755.
2023.01.08 09:24:34 2: DbLog logdb - Error - DBD::mysql::db rollback failed: Turning on AutoCommit failed at ./FHEM/93_DbLog.pm line 4170.
2023.01.08 09:24:35 2: DbLog logdb - Error table history - Can't call method "prepare" on unblessed reference at ./FHEM/93_DbLog.pm line 2746.
2023.01.08 09:24:35 2: DbLog logdb - Error - Can't call method "rollback" on unblessed reference at ./FHEM/93_DbLog.pm line 4170.
2023.01.08 09:24:45 3: DbLog logdb - SubProcess connected to fhem
2023.01.08 09:24:50 2: DbLog logdb - Error table history - DBD::mysql::st execute failed: MySQL server has gone away [for Statement "INSERT IGNORE INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (...)"] at ./FHEM/93_DbLog.pm line 2755.
2023.01.08 09:24:50 2: DbLog logdb - Error - DBD::mysql::db rollback failed: Turning on AutoCommit failed at ./FHEM/93_DbLog.pm line 4170.
2023.01.08 09:24:54 2: DbLog logdb - Error table history - Can't call method "prepare" on unblessed reference at ./FHEM/93_DbLog.pm line 2746.
2023.01.08 09:24:54 2: DbLog logdb - Error - Can't call method "rollback" on unblessed reference at ./FHEM/93_DbLog.pm line 4170.
2023.01.08 09:25:09 3: DbLog logdb - SubProcess connected to fhem

Wobei die "..." alle Daten sind, die in die DB geschrieben werden sollten.

Hier noch das Listing:
Internals:
   COLUMNS    field length used for Device: 64, Type: 64, Event: 0, Reading: 128, Value: 128, Unit: 32
   CONFIGURATION ./db.conf
   DEF        ./db.conf .*:.*
   FD         5
   FUUID      5c83ff6d-f33f-d125-10cd-28b46c8630c70722
   FVERSION   93_DbLog.pm:v5.5.9-s26923/2022-12-29
   MODE       asynchronous
   MODEL      MYSQL
   NAME       logdb
   NR         2
   NTFY_ORDER 50-logdb
   PID        429
   REGEXP     .*:.*
   SBP_PID    23417
   SBP_STATE  running
   STATE      connected
   TYPE       DbLog
   UTF8       1
   dbconn     mysql:database=fhem;host=nas.lokal;port=3306
   dbuser     fhem
   eventCount 3471
   HELPER:
     COLSET     1
     DEVICECOL  64
     EVENTCOL   0
     OLDSTATE   connected
     PACKAGE    main
     READINGCOL 128
     TC         current
     TH         history
     TYPECOL    64
     UNITCOL    32
     VALUECOL   128
     VERSION    5.5.9
   Helper:
     DBLOG:
       CacheOverflowLastNum:
         logdb:
           TIME       1673170209.33208
           VALUE      0
       CacheOverflowLastState:
         logdb:
           TIME       1673166338.73315
           VALUE      normal
       state:
         logdb:
           TIME       1673168868.14695
           VALUE      connected
   OLDREADINGS:
   READINGS:
     2023-01-08 10:30:09   CacheOverflowLastNum 0
     2023-01-08 09:25:38   CacheOverflowLastState normal
     2023-01-08 10:30:29   CacheUsage      112
     2023-01-08 10:30:09   NextSync        2023-01-08 10:30:39 or when CacheUsage 500 is reached
     2023-01-08 10:30:09   state           connected
     2016-05-05 19:48:44   userCommand     SELECT type, name FROM sqlite_master WHERE type='table' OR type='view' ORDER BY name;
   hmccu:
Attributes:
   DbLogSelectionMode Exclude/Include
   asyncMode  1
   colEvent   0
   colReading 128
   colValue   128
(wobei hier bulkInsert schon fehlt, das war vorher 1)

Könntest du mal schauen, ob es hier ein Problem mit dem Reconnect gibt?

Danke & Gruß
Hanjo

Hallo Hanjo,

danke für die Meldung.
Ich schaue es mir an.
Ein Teil des Problems sollte sich bereits mit der Version im contrib 5.5.10 beseitigt sein.

Möglicherweise habe ich bis heute Abend noch eine Ergänzung für die contrib 5.5.10.

EDIT: bedeutet das reconnect Problem ist mit bulkInsert = 0 (oder gelöscht) nicht mehr da ?

LG

Danke  :)

Zitat von: DS_Starter am 08 Januar 2023, 11:45:22
bedeutet das reconnect Problem ist mit bulkInsert = 0 (oder gelöscht) nicht mehr da ?

Gute Frage - ich hatte das Attribut gelöscht und danach ging es wieder, aber seitdem lief kein Backup mehr.  Ich bleibe mal die nächste Nacht noch auf der v5.5.9; morgen früh kann ich dann reporten, ob der Reconnect ohne bulkInsert = 1 funktioniert.

Gruß
Hanjo

Nimm ruhig schon die v aus dem contrib.
Da ist schon viel eingeflossen.
Bringt uns mehr nach vorn.

Lg

@all,

ich habe die Version 5.5.10 im contrib upgedated.
Das von Hanjo oben gemeldete Problem sollte gelöst sein.

Desweiteren wird die Logausgabe bei dauerhaften Verbindungsproblemen (Wartung, Backup, etc.) begrenzt:


2023.01.08 18:11:07.642 2: DbLog LogDB - ERROR: DBI connect('database=fhemtest;host=192.168.2.44;port=3306','fhemtest',...) failed: Can't connect to MySQL server on '192.168.2.44' (115) at ./FHEM/93_DbLog.pm line 2484.

2023.01.08 18:11:11.703 2: DbLog LogDB - ERROR: DBI connect('database=fhemtest;host=192.168.2.44;port=3306','fhemtest',...) failed: Can't connect to MySQL server on '192.168.2.44' (115) at ./FHEM/93_DbLog.pm line 2484.

2023.01.08 18:11:14.775 2: DbLog LogDB - ERROR: DBI connect('database=fhemtest;host=192.168.2.44;port=3306','fhemtest',...) failed: Can't connect to MySQL server on '192.168.2.44' (115) at ./FHEM/93_DbLog.pm line 2484.

2023.01.08 18:11:17.847 2: DbLog LogDB - ERROR: DBI connect('database=fhemtest;host=192.168.2.44;port=3306','fhemtest',...) failed: Can't connect to MySQL server on '192.168.2.44' (115) at ./FHEM/93_DbLog.pm line 2484.

2023.01.08 18:11:20.919 2: DbLog LogDB - ERROR: DBI connect('database=fhemtest;host=192.168.2.44;port=3306','fhemtest',...) failed: Can't connect to MySQL server on '192.168.2.44' (115) at ./FHEM/93_DbLog.pm line 2484.

2023.01.08 18:11:23.991 2: DbLog LogDB - ERROR: DBI connect('database=fhemtest;host=192.168.2.44;port=3306','fhemtest',...) failed: Can't connect to MySQL server on '192.168.2.44' (115) at ./FHEM/93_DbLog.pm line 2484.

2023.01.08 18:11:30.455 2: DbLog LogDB - ERROR: DBI connect('database=fhemtest;host=192.168.2.44;port=3306','fhemtest',...) failed: Can't connect to MySQL server on '192.168.2.44' (115) at ./FHEM/93_DbLog.pm line 2484.

2023.01.08 18:11:33.527 2: DbLog LogDB - ERROR: DBI connect('database=fhemtest;host=192.168.2.44;port=3306','fhemtest',...) failed: Can't connect to MySQL server on '192.168.2.44' (115) at ./FHEM/93_DbLog.pm line 2484.

2023.01.08 18:11:41.815 2: DbLog LogDB - ERROR: DBI connect('database=fhemtest;host=192.168.2.44;port=3306','fhemtest',...) failed: Can't connect to MySQL server on '192.168.2.44' (115) at ./FHEM/93_DbLog.pm line 2484.

2023.01.08 18:11:44.887 2: DbLog LogDB - ERROR: DBI connect('database=fhemtest;host=192.168.2.44;port=3306','fhemtest',...) failed: Can't connect to MySQL server on '192.168.2.44' (115) at ./FHEM/93_DbLog.pm line 2484.

2023.01.08 18:11:47.959 2: DbLog LogDB - ERROR: DBI connect('database=fhemtest;host=192.168.2.44;port=3306','fhemtest',...) failed: Can't connect to MySQL server on '192.168.2.44' (115) at ./FHEM/93_DbLog.pm line 2484.

2023.01.08 18:11:47.960 2: DbLog LogDB - There seems to be a permanent connection error to the database. Further error messages are suppressed.


Desweiteren ist configCheck ergänzt um ein Rating Ampelsystem.
Dadurch sieht man schnell ob es Punkte gibt, die eine Prüfung oder Aufmerksamkeit erfordern (Anhang).

Liegt im contrib.

Super - danke. Ich habe die Version installiert und werde morgen berichten. Ich lass es jetzt erst mal eine Nacht ohne Bulk laufen und stelle dann wieder um.

Gruß

Guten Morgen,

kurzer Statusbericht: heute Nacht gab es keine Probleme. Die Log-Einträge haben sich auf folgende Zeilen beschränkt:
2023.01.09 04:03:08 2: DbLog logdb - ERROR: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2484.
2023.01.09 04:03:38 2: DbLog logdb - ERROR: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2484.
2023.01.09 04:03:50 2: DbLog logdb - ERROR: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2484.
2023.01.09 04:03:51 2: DbLog logdb - ERROR: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2484.
2023.01.09 04:04:06 2: DbLog logdb - ERROR: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2484.
2023.01.09 04:04:23 2: DbLog logdb - ERROR: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2484.
2023.01.09 04:04:40 2: DbLog logdb - ERROR: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2484.
2023.01.09 04:04:56 2: DbLog logdb - ERROR: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2484.
2023.01.09 04:05:11 2: DbLog logdb - ERROR: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2484.
2023.01.09 04:05:26 2: DbLog logdb - ERROR: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2484.
2023.01.09 04:05:41 2: DbLog logdb - ERROR: DBI connect('database=fhem;host=nas.lokal;port=3306','fhem',...) failed: Can't connect to MySQL server on 'nas.lokal' (111) at ./FHEM/93_DbLog.pm line 2484.
2023.01.09 04:05:41 2: DbLog logdb - There seems to be a permanent connection error to the database. Further error messages are suppressed.
2023.01.09 04:35:36 3: DbLog logdb - SubProcess connected to fhem

Ich setze nun bulkInsert wieder auf 1 und berichte dann morgen wieder.

Grüße
Hanjo

Hallo Hanjo,

kannst du bitte die V 5.5.11 aus dem contrib ziehen und bei dir zum Test einspielen ?

Ich habe noch etwas an der Verfügbarkeitserkennung der DB verbessert und einiges im Code strukturiert.
Das möchte ich bei dir gleich mit in den Test einfließen lassen.
Funktional hat sich nichts geändert.

LG

Hi Heiko,

ok, habe ich installiert. Allerdings kam gleich nach dem Neustart von FHEM einmalig folgende Fehlermeldung:
2023.01.09 19:56:23 2: DbLog logdb - Error table history - DBD::mysql::st execute failed: You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near '' at line 1 [for Statement "INSERT IGNORE INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES"] at ./FHEM/93_DbLog.pm line 2714.

Seitdem scheint es aber zu gehen.

Ich habe mal das Log durchgeschaut, ich hatte den Fehler auch vorher schon mal in der Version v5.5.10:
2023.01.09 17:45:28 2: DbLog logdb - Error table history - DBD::mysql::st execute failed: You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near '' at line 1 [for Statement "INSERT IGNORE INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES"] at ./FHEM/93_DbLog.pm line 2652.

Grüße
Hanjo

Die Version habe ich natürlich vorher bei mir durchgetestet.
Dieser Fehler:


syntax to use near '' ...


kann erstmal nicht eingeordnet werden. Sieht aber nach einem speziellen Fall aus.
Schwierig zu sagen ohne zu wissen welche Daten genau geloggt werden sollten.
Wenn du die Situation provozieren kannst, dann lohnt es sich verbose 5 einzustellen um diese Daten zu sehen.

Zitat von: DS_Starter am 09 Januar 2023, 20:12:49
Wenn du die Situation provozieren kannst, dann lohnt es sich verbose 5 einzustellen um diese Daten zu sehen.

Habe mal ein bisschen rumgespielt, scheinbar erscheint der Fehler nach jedem Neustart von FHEM, so dass ich die Debug-Logdaten erzeugen konnte. Ich konnte auf den ersten Blick nichts außergewöhnliches an den Daten feststellen... Da das recht umfangreich ist und reale Daten von mir enthält, schicke ich dir das per PN.

Danke & Gruß
Hanjo

Morgen Heiko,

mit bulkInsert = 1 hatte ich heute morgen wieder das gleiche Problem:
Internals:
   COLUMNS    field length used for Device: 64, Type: 64, Event: 0, Reading: 128, Value: 128, Unit: 32
   CONFIGURATION ./db.conf
   DEF        ./db.conf .*:.*
   FD         5
   FUUID      5c83ff6d-f33f-d125-10cd-28b46c8630c70722
   FVERSION   93_DbLog.pm:v5.5.11-s26923/2023-01-09
   MODE       asynchronous
   MODEL      MYSQL
   NAME       logdb
   NR         2
   NTFY_ORDER 50-logdb
   PID        19196
   REGEXP     .*:.*
   SBP_PID    19197
   SBP_STATE  running
   STATE      DBD::mysql::st execute failed: You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near '' at line 1 [for Statement "INSERT IGNORE INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES"] at ./FHEM/93_DbLog.pm line 2714.

   TYPE       DbLog
   UTF8       1
   dbconn     mysql:database=fhem;host=nas.lokal;port=3306
   dbuser     fhem
   eventCount 2182
   HELPER:
     COLSET     1
     DEVICECOL  64
     EVENTCOL   0
     LASTLIMITRUNTIME 1673332655.14323
     OLDSTATE   DBD::mysql::st execute failed: You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near '' at line 1 [for Statement "INSERT IGNORE INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES"] at ./FHEM/93_DbLog.pm line 2714.

     PACKAGE    main
     READINGCOL 128
     TC         current
     TH         history
     TYPECOL    64
     UNITCOL    32
     VALUECOL   128
     VERSION    5.5.11
   Helper:
     DBLOG:
       CacheOverflowLastNum:
         logdb:
           TIME       1673332652.42455
           VALUE      100875
       CacheOverflowLastState:
         logdb:
           TIME       1673319030.12353
           VALUE      exceeded
       state:
         logdb:
           TIME       1673332658.30111
           VALUE      DBD::mysql::st execute failed: You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near '' at line 1 [for Statement "INSERT IGNORE INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES"] at ./FHEM/93_DbLog.pm line 2714.

   OLDREADINGS:
   READINGS:
     2023-01-10 07:37:32   CacheOverflowLastNum 100876
     2023-01-10 03:50:30   CacheOverflowLastState exceeded
     2023-01-10 07:37:39   CacheUsage      36
     2023-01-10 07:37:32   NextSync        2023-01-10 07:38:02 or when CacheUsage 500 is reached
     2023-01-10 07:37:38   state           DBD::mysql::st execute failed: You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near '' at line 1 [for Statement "INSERT IGNORE INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES"] at ./FHEM/93_DbLog.pm line 2714.

     2016-05-05 19:48:44   userCommand     SELECT type, name FROM sqlite_master WHERE type='table' OR type='view' ORDER BY name;
Attributes:
   DbLogSelectionMode Exclude/Include
   asyncMode  1
   bulkInsert 1
   colEvent   0
   colReading 128
   colValue   128

Nachdem ich bulkInsert gelöscht hatte, konnten die Daten sofort gespeichert werden:
Internals:
   COLUMNS    field length used for Device: 64, Type: 64, Event: 0, Reading: 128, Value: 128, Unit: 32
   CONFIGURATION ./db.conf
   DEF        ./db.conf .*:.*
   FD         5
   FUUID      5c83ff6d-f33f-d125-10cd-28b46c8630c70722
   FVERSION   93_DbLog.pm:v5.5.11-s26923/2023-01-09
   MODE       asynchronous
   MODEL      MYSQL
   NAME       logdb
   NR         2
   NTFY_ORDER 50-logdb
   PID        19196
   REGEXP     .*:.*
   SBP_PID    19197
   SBP_STATE  running
   STATE      connected
   TYPE       DbLog
   UTF8       1
   dbconn     mysql:database=fhem;host=nas.lokal;port=3306
   dbuser     fhem
   eventCount 2195
   HELPER:
     COLSET     1
     DEVICECOL  64
     EVENTCOL   0
     OLDSTATE   connected
     PACKAGE    main
     READINGCOL 128
     TC         current
     TH         history
     TYPECOL    64
     UNITCOL    32
     VALUECOL   128
     VERSION    5.5.11
   Helper:
     DBLOG:
       CacheOverflowLastNum:
         logdb:
           TIME       1673332763.08652
           VALUE      0
       CacheOverflowLastState:
         logdb:
           TIME       1673332733.02672
           VALUE      normal
       state:
         logdb:
           TIME       1673332761.25858
           VALUE      connected
   OLDREADINGS:
   READINGS:
     2023-01-10 07:39:23   CacheOverflowLastNum 0
     2023-01-10 07:38:53   CacheOverflowLastState normal
     2023-01-10 07:39:23   CacheUsage      478
     2023-01-10 07:39:23   NextSync        2023-01-10 07:39:53 or when CacheUsage 500 is reached
     2023-01-10 07:39:23   state           connected
     2016-05-05 19:48:44   userCommand     SELECT type, name FROM sqlite_master WHERE type='table' OR type='view' ORDER BY name;
   hmccu:
Attributes:
   DbLogSelectionMode Exclude/Include
   asyncMode  1
   colEvent   0
   colReading 128
   colValue   128

Ich habe auch noch das Logfile mit den genauen Einträgen, aber das kann ich erst heute Abend analysieren.

Grüße
Hanjo

Moin,

Jetzt wird deutlicher dass an irgendeiner Stelle die zu speichernden Daten problematisch sind.
Die Speichermodi arbeiten unterschiedlich. Deswegen ist der Array Modus der Standard.
Er ist langsamer bei Mengendaten, aber behandelt Daten und Fehler anders.

Vllt. bekommen wir die Ursache noch heraus.

Lg

Hi Hanjo,

ich habe im I-net einen Hinweis gefunden den versuche ich heute Abend einzubauen. Ggf gibt es ein Update.

Hi Heiko,

na das hört sich ja schon mal gut an  :)

Im Log habe ich folgendes gefunden, die Meldung dort ist ein bisschen anders als im State Reading:
2023.01.10 04:26:15 3: DbLog logdb - SubProcess connected to fhem
2023.01.10 04:26:15 2: DbLog logdb - Error table history - DBD::mysql::st execute failed: MySQL server has gone away [for Statement "INSERT IGNORE INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (...)"] at ./FHEM/93_DbLog.pm line 2714.

2023.01.10 04:26:15 2: DbLog logdb - Error - DBD::mysql::db rollback failed: Turning on AutoCommit failed at ./FHEM/93_DbLog.pm line 4129.

2023.01.10 04:26:16 1: PERL WARNING: (in cleanup) DBD::mysql::db DESTROY failed: MySQL server has gone away at ./FHEM/93_DbLog.pm line 2436.
2023.01.10 04:26:16 2: DbLog logdb - Error table history - DBD::mysql::st execute failed: You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near '' at line 1 [for Statement "INSERT IGNORE INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES"] at ./FHEM/93_DbLog.pm line 2714.

2023.01.10 04:26:31 2: DbLog logdb - Error table history - DBD::mysql::st execute failed: MySQL server has gone away [for Statement "INSERT IGNORE INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (...)"] at ./FHEM/93_DbLog.pm line 2714.

2023.01.10 04:26:31 2: DbLog logdb - Error - DBD::mysql::db rollback failed: Turning on AutoCommit failed at ./FHEM/93_DbLog.pm line 4129.


"MySQL server has gone away", das hatten wir auch schon mal in einem der vorherigen Logs, also habe ich jetzt mal eine Test-Tabelle angelegt und das vollständige SQL Statement aus dem Logfile versucht manuell einzufügen:
$ mysql -u root -p
Enter password:
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 776
Server version: 10.3.32-MariaDB Source distribution

Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MariaDB [(none)]> use fhem;
Database changed
MariaDB [fhem]> source /volume1/Temp/fhem-tmp.sql;
ERROR 2006 (HY000) at line 1 in file: '/volume1/Temp/fhem-tmp.sql': MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    777
Current database: fhem

ERROR 2006 (HY000) at line 1 in file: '/volume1/Temp/fhem-tmp.sql': MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    778
Current database: fhem

ERROR 2006 (HY000) at line 1 in file: '/volume1/Temp/fhem-tmp.sql': MySQL server has gone away

Scheinbar liegt der Fehler an der Konfiguration meines Servers, oder vielmehr an einer unglücklichen Kombination aus Serverkonfiguration und extrem großen Inserts mit mehreren Zehntausend Einträgen. Ist z.B. hier beschrieben:
https://stackoverflow.com/questions/10474922/error-2006-hy000-mysql-server-has-gone-away

Also mal max_allowed_packet erhöhen und neuer Versuch:
MariaDB [fhem]> set global max_allowed_packet=64*1024*1024;
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    779
Current database: fhem

Query OK, 0 rows affected (0.001 sec)

MariaDB [fhem]> source /volume1/Temp/fhem-tmp.sql;
Query OK, 15110 rows affected (1.344 sec)
Records: 15110  Duplicates: 0  Warnings: 0

Tada... :)

Also gibt es zwei Möglichkeiten:

• Entweder der doofe User (ich) muss den Wert dauerhaft in seiner my.cnf ändern, oder
• Das Modul muss auch bei "Bulk" den Insert bei Überschreiten der kritischen Größe in mehrere kleinere Inserts aufteilen...

Scheinbar habe ich hier einen außergewöhnlichen Fall entdeckt. Komisch nur, dass es mit der alten Version des Moduls kein Problem gab.

Deine Gedanken?

Grüße
Hanjo

Hallo Hanjo,


Tada... :)

Also gibt es zwei Möglichkeiten:

    Entweder der doofe User (ich) muss den Wert dauerhaft in seiner my.cnf ändern, oder
    Das Modul muss auch bei "Bulk" den Insert bei Überschreiten der kritischen Größe in mehrere kleinere Inserts aufteilen...


Genau das habe ich gerade (als Nebenbei-Effekt) getan. Dadurch verschlechtert sich die Performance des BulkInsert ein ganz klein wenig, aber da wir ohnehin nur noch non-blocking mit dem Subprozess unterwegs sind, ist das nicht der Rede wert.

Die Version liegt im Contrib.

Grüße,
Heiko

Ja super, großartig, danke!

Ich habe die Version installiert und bulkInsert wieder auf 1 gesetzt. Werde morgen früh berichten :)

Gruß
Hanjo

Guten Morgen,

heute Nacht ging alles glatt, keine Probleme mehr  :)

Vielen Dank für deine Unterstützung!

Grüße
Hanjo

Moin,

das hört sich gut an.
Ich werde die Version finalisieren und vermutlich heute Abend einchecken. Es sind jetzt viele Lösungen für gemeldetete Issues eingeflossen.
Das Attr bulkInsert werde ich zukünftig wohl (automatisiert) umbenennen. Durch die Änderungen ist es kein wirklicher BulkInsert mehr.
Der Begriff "insertMode" trifft es dann allgemeiner/besser.

LG

@all,

die neue Version ist als V 5.6.0 eingescheckt.

Die Version enthält alle bisher gemeldeten und gelösten Issues sowie Verbesserungen.
Die für den User sichtbarste Änderung ist

* die Umbenennung des Attributs 'bulkInsert' zu 'insertMode'

Die Umbenennung des Attributs erfolgt automatisch. Der Nutzer muß nicht aktiv werden.

Im Log erscheint beim Start die Meldung:


..... 2: DbLog <Name> - Subprocess >4631< initialized ... ready for non-blocking operation
..... 3: WARNING: <Name> attribute bulkInsert was renamed to insertMode


LG

Hallo miteinander,

es gibt wieder eine neue Version im contrib.
Wegen dem hier (https://forum.fhem.de/index.php/topic,131790.msg1259709.html#msg1259709) aufgefallenen Issue habe ich die Ausgaben in das Logfile komplett überarbeitet.
Außerdem gibt es einige neue get-Kommandos um "auf die Schnelle" Werte aus der DB ziehen und wenn benötigt Variablen
zuordnen zu können.
Auszug aus der Commandref:

         get <name> ReadingsMaxVal[Timestamp] <Device> <Reading> <default>

        Ermittelt den Datensatz mit dem größten Wert der angegebenen Device / Reading Kombination aus der history Tabelle.
        Zurück gegeben wird nur der Wert oder die Kombination aus Wert und Timestamp als String "<Wert> , <Timestamp>".
        <default> gibt einen definierten Rückgabewert an, wenn kein Wert ermittelt werden kann.

   
   
• get <name> ReadingsMinVal[Timestamp] <Device> <Reading> <default>
  
  
  
        
  • Ermittelt den Datensatz mit dem kleinsten Wert der angegebenen Device / Reading Kombination aus der history Tabelle.
    Zurück gegeben wird nur der Wert oder die Kombination aus Wert und Timestamp als String "<Wert> , <Timestamp>".
    <default> gibt einen definierten Rückgabewert an, wenn kein Wert ermittelt werden kann.
    

   
   
• get <name> ReadingsAvgVal <Device> <Reading> <default>
  
  
  
        
  • Ermittelt den Durchschnittswert der angegebenen Device / Reading Kombination aus der history Tabelle.
    Zurück gegeben wird der einfache arithmetische Durchschnittswert.
    <default> gibt einen definierten Rückgabewert an, wenn kein Wert ermittelt werden kann.
    

   
   
• get <name> ReadingsVal[Timestamp] <Device> <Reading> <default>
  
  
  
        
  • Liest den letzten (neuesten) in der history Tabelle gespeicherten Datensatz der angegebenen Device / Reading Kombination.
    Zurück gegeben wird nur der Wert oder die Kombination aus Wert und Timestamp als String "<Wert> , <Timestamp>".
    <default> gibt einen definierten Rückgabewert an, wenn kein Wert ermittelt werden kann.

   
• get <name> ReadingsTimestamp <Device> <Reading> <default>
         
           Liest den Zeitstempel des letzten (neuesten) in der history Tabelle gespeicherten Datensatzes der angegebenen
           Device/Reading Kombination und gibt diesen Wert zurück.

        <default> gibt einen definierten Rückgabewert an, wenn kein Wert in der Datenbank gefunden wird.


Zu beachten ist, dass alle die Kommandos blockierend arbeiten.

Die Version liegt wieder zunächst in meinem contrib.

Super, danke! Werde ich in den nächsten Tagen testen.

Ich habe DbLog noch ein Get-Menü spendiert.
Damit ist es nun für den User leichter eine schnelle Abfrage der DB über die vorderfinierten Getter auszuführen.
Es ist auch ein leichter Vorgriff weil ich noch Ideen habe die Get-Möglichkeiten zu erweitern.

Liegt im contrib zum Test.

Frage zu webchart und Tabell Frontend hat sich erledigt. Habe weiter recherchiert und alle Infos dazu gefunden soweit.

kann es sein, dass es nun mit dblogreduce der Probleme gibt.

Dies trat heute Nacht erstmals auf:
2023.01.27 02:00:05 3: DbRep Reduce_Daily - Initial data information retrieved - total time used: 5.7753 seconds
2023.01.27 02:00:06 3: DbRep Reduce_Daily - Connectiontest to db mysql:database=fhem;host=localhost;port=3306 successful
2023.01.27 02:00:06 3: DbRep Reduce_Daily - reduce data older than: 2022-12-28 23:59:59, newer than: 2022-12-26 00:00:00
2023.01.27 02:00:06 3: DbRep Reduce_Daily - reduceLog requested with options:
average=day
INCLUDE -> Devs: % Readings: %
2023.01.27 02:00:17 3: DbRep Reduce_Daily - reduceLog (daily-average) updating 250, deleting 4426 records of day: 2022-12-26
2023.01.27 02:01:21 2: DbLog dblog_THB - ERROR table history - DBD::mysql::st execute failed: Lock wait timeout exceeded; try restarting transaction [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (?,?,?,?,?,?,?)" with ParamValues: 0='2023-01-27 02:00:01', 1='TX29DTH_16', 2='LACROSSE', 3='state: T: 19.8 H: 26', 4='state', 5='T: 19.8 H: 26', 6=undef] at ./FHEM/93_DbLog.pm line 2769.

2023.01.27 02:01:21 2: DbLog dblog_THB - Transaction is switched off. Transferred data is lost.
2023.01.27 02:02:21 2: DbLog dblog_THB - ERROR table history - DBD::mysql::st execute failed: Lock wait timeout exceeded; try restarting transaction [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (?,?,?,?,?,?,?)" with ParamValues: 0='2023-01-27 02:00:31', 1='MAX_BAD_HT', 2='MAX', 3='valveposition: 47', 4='valveposition', 5='47', 6='%'] at ./FHEM/93_DbLog.pm line 2769.

und noch viele, viele weitere bis 8:00



ich hatte es daran bemerkt, dass ich in den Gplots seit 2:00 nichts mehr angezeigt wurde.
Nach shutdown restart wurde danach wieder korrekt in die DB geschrieben.

das ist wohl das zugrundeliegende DEF:

[code]define Reduce_Daily DbRep dblog_THB
attr Reduce_Daily room DBLog
attr Reduce_Daily showproctime 1
attr Reduce_Daily timeDiffToNow d:32
attr Reduce_Daily timeOlderThan d:30
#   DATABASE   fhem
#   DEF        dblog_THB
#   FUUID      63b06a6d-f33f-fd5f-cbee-933b87fab6caca0d
#   FVERSION   93_DbRep.pm:v8.51.3-s27102/2023-01-22
#   LASTCMD    initial database connect stopped due to attribute 'fastStart'
#   MODEL      Client
#   NAME       Reduce_Daily
#   NOTIFYDEV  global,Reduce_Daily
#   NR         121
#   NTFY_ORDER 50-Reduce_Daily
#   ROLE       Client
#   STATE      initialized
#   TYPE       DbRep
#   UTF8       0
#   HELPER:
#     DBLOGDEVICE dblog_THB
#     IDRETRIES  3
#     PACKAGE    main
#     VERSION    8.51.3
#   READINGS:
#     2023-01-27 14:33:39   state           initialized
#
setstate Reduce_Daily initialized
setstate Reduce_Daily 2023-01-27 14:33:39 state initialized

[/code]

Zitat
kann es sein, dass es nun mit dblogreduce der Probleme gibt.

Eher nicht.

Das liegt daran dass die Tabelle history während des reducelog gesperrt ist.
Der DbLog Prozess läuft dann irgendwann auf einen Timeout ->

Zitat
DbLog dblog_THB - ERROR table history - DBD::mysql::st execute failed: Lock wait timeout exceeded;

wenn reducelog bzw. die Tabellensperre zu lange dauert.

Um das Problem zu verhindern bietet sich an im DbRep Attr executeBeforeProc vor dem reducelog DbLog zu "pausieren"


executeBeforeProc  set <DbLog> reopen 86400


und im Attr executeAfterProc  wieder zu starten:


executeAfterProc  set <DbLog> reopen


Zitat von: DS_Starter am 27 Januar 2023, 17:20:16
Eher nicht.

Das liegt daran dass die Tabelle history während des reducelog gesperrt ist.
Der DbLog Prozess läuft dann irgendwann auf einen Timeout ->

wenn reducelog bzw. die Tabellensperre zu lange dauert.

Um das Problem zu verhindern bietet sich an im DbRep Attr executeBeforeProc vor dem reducelog DbLog zu "pausieren"

Code Auswählen Erweitern


executeBeforeProc  set <DbLog> reopen 86400


und im Attr executeAfterProc  wieder zu starten:

Code Auswählen Erweitern


executeAfterProc  set <DbLog> reopen


oh danke

wo baue ich das genauer ein:

das findet vorher statt:

2023.01.27 00:18:39 3: DbRep ReportDbLog_THB - 2084126 records inserted (size of backupfile: 418.90 MB)
2023.01.27 00:18:39 3: DbRep ReportDbLog_THB - Deleting old dumpfile 'fhem_2023_01_24_00_10.sql'
2023.01.27 00:18:39 3: DbRep ReportDbLog_THB - Finished backup of database fhem - total time used (hh:mm:ss): 00:08:39
2023.01.27 00:18:40 3: DbRep ReportDbLog_THB - Database dump finished successfully.
2023.01.27 01:08:36 1: PERL WARNING: Use of uninitialized value $type in hash element at ./FHEM/14_CUL_MAX.pm line 821.
2023.01.27 01:08:36 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at ./FHEM/14_CUL_MAX.pm line 821.
2023.01.27 01:08:36 1: PERL WARNING: Use of uninitialized value $testresult in concatenation (.) or string at ./FHEM/14_CUL_MAX.pm line 821.
2023.01.27 01:08:36 1: PERL WARNING: Use of uninitialized value $serial in concatenation (.) or string at ./FHEM/14_CUL_MAX.pm line 821.
2023.01.27 01:30:00 3: DbLog dblog_THB - Reopen requested
2023.01.27 01:30:00 3: set dblog_THB reopen : Reopen executed.
2023.01.27 01:30:00 3: DbLog_reopen: Reopen executed.
2023.01.27 01:30:00 3: DbLog dblog_THB - Database disconnected by request.
2023.01.27 01:30:00 3: DbLog dblog_THB - SubProcess connected to fhem
2023.01.27 02:00:00 3: DbRep Reduce_Daily - ################################################################
2023.01.27 02:00:00 3: DbRep Reduce_Daily - ###                    new reduceLog run                     ###
2023.01.27 02:00:00 3: DbRep Reduce_Daily - ################################################################
2023.01.27 02:00:00 3: DbRep Reduce_Daily - get initial structure information of database "fhem", remaining attempts: 3
2023.01.27 02:00:00 3: DbRep Reduce_Daily - Connectiontest to database mysql:database=fhem;host=localhost;port=3306 with user fhemuser

der automatisierte dump wurde also korrekt abgeschlossen.
Dann erfolgt ebenso automatisiert um 1:30 ein reopen ; also genau zu falschen Zeit vorher statt nachher?

wie genauer baue ich also die "Verhinderungsbefehle" ein?

Zitat
wie genauer baue ich also die "Verhinderungsbefehle" ein?

In deinem DbRep Reduce_Daily setzt du

attr Reduce_Daily  executeBeforeProc  set dblog_THB reopen 86400

und

attr Reduce_Daily  executeAfterProc  set dblog_THB reopen

Ich habe die möglichen Getter im DbLog noch erweitert.

get <name> dataRetrieval <querytype> <device> <reading> <from> <to> <offset> <limit>

    Liest Daten aus der Datenbank Tabelle history und gibt die Ergebnisse als JSON formatiert zurück.
    Die Abfragemethode bzw. das gewünschte Abfrageergebnis wird durch den angegebenen <querytype> bestimmt.
    Jeder <querytype> verlangt evtl. weitere Parameter gemäß der folgenden Tabelle. Nicht eingegebene Parameter sind immer   
    als "" anzugeben sofern danach noch ein weiterer Parameter eingegeben wird.

        getdevices         Ermittelt alle in der Datenbank gespeicherten Devices.
        getreadings       Ermittelt alle in der Datenbank gespeicherten Readings für ein bestimmtes Device.
        timerange         Ermittelt die gespeicherten Datensätze der angegebenen Device / Reading Kombination.
        getTableData     Ermittelt die gespeicherten Datensätze eines bestimmten Zeitraumes.
                                Die Anzahl der selektierten Datensätze wird als Schlüssel "totalcount" zurückgegeben.
        last                   Listet die letzten 10 gespeicherten Events auf.
        hourstats           Errechnet die Statistiken SUM, AVG, MIN, MAX, COUNT für eine Stunde.
        daystats            Errechnet die Statistiken SUM, AVG, MIN, MAX, COUNT für einen Tag.
        weekstats          Errechnet die Statistiken SUM, AVG, MIN, MAX, COUNT für eine Woche.
        monthstats        Errechnet die Statistiken SUM, AVG, MIN, MAX, COUNT für einen Monat.
        yearstats           Errechnet die Statistiken SUM, AVG, MIN, MAX, COUNT für ein Jahr.

Hi Heiko,

das sind Hammer Neuigkeiten, genau das wonach ich gerade gesucht habe :-)

Danke & Gruß
Alex

Gerne  :)

Wahrscheinlich werde ich die Namensgebung der Getter noch etwas anpassen vor dem Einchecken, vllt. "get ... history allDevices" und "get ... history tableData" statt gettableData.
Weiß noch nicht so genau, sollte einfach etwas straffer und sprechender sein.
Aber das kriegst du dann hin denke ich.  ;)

freue mich sehr auf die neue Version :-)

ist die dann final?

Ein "final" gibt es eigentlich bei dem Modul bzw. FHEM allgemein nicht.
Je nach Bedarf entwickle ich das Modul weiter. Es wird sicherlich Pausen geben in denen ich mich mit meinen anderen Modulen befasse die auch wieder Entwicklungen bekommen wie DbRep oder SolarForecast.
Und irgendwann gibt es auch bei DbLog etwas Neues, z.B. werden nach gewisser Zeit die abgekündigten Setter verschwinden.

Zitat von: DS_Starter am 30 Januar 2023, 11:11:41
Ein "final" gibt es eigentlich bei dem Modul bzw. FHEM allgemein nicht.

wir alle schätzen Deinen unermüdlichen Einsatz; der sollte kein Ende haben ;-)

ich meinte mit "final" die Version, die beim normale FHEM-Update mitkommt. Jedenfalls gibt es in dBlog die genialen Setters noch nicht.

andere Frage:
ich kämpfe immer noch mit durch at ausgelösten dblog-Befehlen.

z.B.

2023.01.30 04:00:00 3: set dblog_THB countEntries : Unknown argument, choose one of addCacheLine addLog clearReadings:noArg count:noArg configCheck:noArg countNbl:noArg deleteOldDays deleteOldDaysNbl eraseReadings:noArg listCache:noArg reduceLog reduceLogNbl rereadcfg:noArg reopen stopSubProcess:noArg userCommand commitCache:noArg exportCache:nopurge,purgecache purgeCache:noArg importCachefile

früher habe ich das mit  "count" gemacht.

so sieht die DEF aus:
[code]define RepDbLog_count at *04:00:00 { fhem("set dblog_THB countEntries") }
attr RepDbLog_count DbLogExclude .*
attr RepDbLog_count alias RepDbLog_count
attr RepDbLog_count disable 0
attr RepDbLog_count event-on-change-reading .*
attr RepDbLog_count room DBLog,xTimer
attr RepDbLog_count verbose 4
#   COMMAND    { fhem("set dblog_THB countEntries") }
#   DEF        *04:00:00 { fhem("set dblog_THB countEntries") }
#   FUUID      63cd6f92-f33f-fd5f-c6f6-d9f767190c9c2f09
#   NAME       RepDbLog_count
#   NR         2288
#   PERIODIC   yes
#   RELATIVE   no
#   REP        -1
#   STATE      Next: 04:00:00
#   TIMESPEC   04:00:00
#   TRIGGERTIME 1675134000
#   TRIGGERTIME_FMT 2023-01-31 04:00:00
#   TYPE       at
#   READINGS:
#     2023-01-30 14:07:33   state           Next: 04:00:00
#
setstate RepDbLog_count Next: 04:00:00
setstate RepDbLog_count 2023-01-30 14:07:33 state Next: 04:00:00

[/code]

ähnliches (fehlende argumente) passiert bei dbreducelog

Beste Grüße

Thomas

Zitat
ich meinte mit "final" die Version, die beim normale FHEM-Update mitkommt. Jedenfalls gibt es in dBlog die genialen Setters noch nicht.

Die kommt dann bald, evtl.mit veränderter Namensgebung. Ich teste noch. Aber gebe wie immer Bescheid sobald der checkin erfolgt ist.

Zitat
set dblog_THB countEntries : Unknown argument,

Dieser Setter / syntax gilt für DbRep (wird auch so darauf hingewiesen) und nicht DbLog.
Wahrscheinlich trifft diese Problematik auch für reducelog zu.

Zitat von: DS_Starter am 30 Januar 2023, 16:11:30

Dieser Setter / syntax gilt für DbRep (wird auch so darauf hingewiesen) und nicht DbLog.
Wahrscheinlich trifft diese Problematik auch für reducelog zu.

hatte irgendwie im Hinterkopf, dass reducelog besser in der DbRep durchzuführen seien.

ich hatte sonst set dblog reducelog 365 average=day gestartet

in dbrep führt das (neuerdings) zum FehlerError - Wrong time limits. The (days newer than) option must be greater than the (older than) one

Wenn du Fragen zu DbRep hast, mach bitte einen neuen Thread auf oder nutze einfach den DbRep-Thread in "Sonstiges".
Ist hier OT.

@Thomas:

Zitat
Error - Wrong time limits. The (days newer than) option must be greater than the (older than) one

Es kann sein dass du nur jüngere Tage als das angegebene Alter (older than) in der Datenbank hast.

Habe den Getter jetzt angepasst:

get <name> retrieve <querytype> <device> <reading> <from> <to> <offset> <limit>

    Liest Daten aus der Datenbank Tabelle history und gibt die Ergebnisse als JSON formatiert zurück.
    Die Abfragemethode bzw. das gewünschte Abfrageergebnis wird durch den angegebenen <querytype> bestimmt.
    Jeder <querytype> verlangt evtl. weitere Parameter gemäß der folgenden Tabelle. Nicht eingegebene Parameter sind immer
    als "" anzugeben sofern danach noch ein weiterer Parameter eingegeben wird.

        alldevices         Ermittelt alle in der Datenbank gespeicherten Devices.
        allreadings        Ermittelt alle in der Datenbank gespeicherten Readings für ein bestimmtes Device.
        timerange         Ermittelt die gespeicherten Datensätze der angegebenen Device / Reading Kombination.
        fetchrows         Ermittelt die gespeicherten Datensätze eines bestimmten Zeitraumes.
        last                 Listet die letzten 10 gespeicherten Events auf.
        hourstats         Errechnet die Statistiken SUM, AVG, MIN, MAX, COUNT für eine Stunde.
        daystats           Errechnet die Statistiken SUM, AVG, MIN, MAX, COUNT für einen Tag.
        weekstats         Errechnet die Statistiken SUM, AVG, MIN, MAX, COUNT für eine Woche.
        monthstats       Errechnet die Statistiken SUM, AVG, MIN, MAX, COUNT für einen Monat.
        yearstats          Errechnet die Statistiken SUM, AVG, MIN, MAX, COUNT für ein Jahr.

-> contrib

Ich habe die neue Version bei nun einige Tage auf allen Instanzen laufen lassen, keine Probleme.
Werde die V nun ins Repo bringen.

Sollte jemand webcharts (hat nichts mit SVG Plots zu tun sondern ist hier im Wiki (https://wiki.fhem.de/wiki/Neues_Charting_Frontend) beschrieben) einsetzen und Probleme feststellen, dann bitte melden.

LG

Hallo miteinander,

wie ihr hier (https://forum.fhem.de/index.php/topic,132313.msg1264704.html#msg1264704) nachlesen könnt, habe ich den DbLog Plot Editor Part überarbeitet und das schon lange vorhandene Manko beseitigt, dass man bei Nutzung einer Drop-Down Vorschlagsliste keine Funktion eingeben konnte bzw. eine im gplot-File gesetzte Funktion verloren ging wenn das File gelesen und gespeichert wurde wenn eine  Drop-Down Vorschlagsliste  benutzt wurde.

Rudi hat heute eine neue SVG Version eingecheckt die morgen früh im Update verteilt wird.Diese SVG ist die Voraussetzung für die überarbeitete DbLog Version die ich als 5.8.4 in mein contrib geladen habe.Damit ist nun die Verwendung einer Funktion im SVG Editor sowohl mit  als auch ohne Drop-Down Vorschlagsliste möglich.
Bevor ich einchecke würde ich mich freuen wenn der eine oder andere die Version ab morgen nach einem Update des SVG testen würde.
Grüße,Heiko

Funktioniert 👍 super. Danke insbesondere auch für Piloteditoranpassung

Danke fürs Testen.

Ich hatte vergessen zu erwähnen, dass es mit der V 5.8.4 ein neues Attr plotInputFieldLength gibt um die Nutzung des  Plot Editors ein wenig komfortabler zu gestalten:

plotInputFieldLength <Ganzzahl>

    Breite der Plot Editor Eingabefelder für Device:Reading und Funktion.
    Wird die Drop-Down Liste als Eingabehilfe für Device:Reading verwendet, wird die Breite des Feldes automatisch eingestellt.
    (default: 40)

Es betriftt die Felder die im Post weiter oben in den Screenshots eingekreist sind.

In der kommenden Version  5.8.4 wird das Attribut noNotifyDev entfernt/ausgesteuert.
Es war m.M. nach nie nötig es zu setzen. Die entsprechende Funktionalität wird durch fhem.pl sichergestellt.
Ist im contrib upgedated.

Sollte jemand einen Grund haben es zu weiterhin zu benötigen bitte mitteilen.

Hallo zusammen,

die neue Version ist eingescheckt und morgen früh verfügbar.
Was hat sich geändert ?

* der Plot Editor (DbLog Part) ist überarbeitet und verbessert
* das Attribut noNotifyDev wurde entfernt
* ein neues Attribut plotInputFieldLength für den Plot Editor ist eingebaut
* an der Commandref wurde weitergearbeitet

Grüße,
Heiko

Zitat von: DS_Starter am 21 Februar 2023, 21:23:24
Hallo miteinander,

wie ihr hier (https://forum.fhem.de/index.php/topic,132313.msg1264704.html#msg1264704) nachlesen könnt, habe ich den DbLog Plot Editor Part überarbeitet und das schon lange vorhandene Manko beseitigt, dass man bei Nutzung einer Drop-Down Vorschlagsliste keine Funktion eingeben konnte bzw. eine im gplot-File gesetzte Funktion verloren ging wenn das File gelesen und gespeichert wurde wenn eine  Drop-Down Vorschlagsliste  benutzt wurde.

Rudi hat heute eine neue SVG Version eingecheckt die morgen früh im Update verteilt wird.Diese SVG ist die Voraussetzung für die überarbeitete DbLog Version die ich als 5.8.4 in mein contrib geladen habe.Damit ist nun die Verwendung einer Funktion im SVG Editor sowohl mit  als auch ohne Drop-Down Vorschlagsliste möglich.
Bevor ich einchecke würde ich mich freuen wenn der eine oder andere die Version ab morgen nach einem Update des SVG testen würde.
Grüße,Heiko

Hallo Heiko,
vielen Dank für das Update.
ich habe noch nicht kapiert, was man in das EingabeFeld unter Drop-down-Feld eingeben kann oder sollte.

lg

Thomas

Zitat
ich habe noch nicht kapiert, was man in das EingabeFeld unter Drop-down-Feld eingeben kann oder sollte.

Man kann eine Funktion eingeben um Werte zur Anzeige zu verändern, z.B.  $val=($val=~"on"?10:1)
Beispiel ist im Wiki zu sehen -> https://wiki.fhem.de/wiki/SVG-Plots_von_FileLog_auf_DbLog_umstellen

Zitat von: DS_Starter am 27 Februar 2023, 20:18:02

Zitatich habe noch nicht kapiert, was man in das EingabeFeld unter Drop-down-Feld eingeben kann oder sollte.

Man kann eine Funktion eingeben um Werte zur Anzeige zu verändern, z.B.  $val=($val=~"on"?10:1)
Beispiel ist im Wiki zu sehen -> https://wiki.fhem.de/wiki/SVG-Plots_von_FileLog_auf_DbLog_umstellen

inzwischen habe ich das dazu verwendet, um die Delta-d  zu berechnen:
define SVG_TUYA_Stromverbrauch10_Delta SVG dblog_THB:SVG_TUYA_Stromverbrauch10_Delta:HISTORY
attr SVG_TUYA_Stromverbrauch10_Delta DbLogExclude .*
attr SVG_TUYA_Stromverbrauch10_Delta alias Stromverbrauch 10 Delta ThomasBüro
attr SVG_TUYA_Stromverbrauch10_Delta fixedrange 30days
attr SVG_TUYA_Stromverbrauch10_Delta room TUYA Stromverbrauch
#  CFGFN     
#  DEF        dblog_THB:SVG_TUYA_Stromverbrauch10_Delta:HISTORY
#  FUUID      6416db2d-f33f-fd5f-cee4-84ec9d20f2b1698a
#  GPLOTFILE  SVG_TUYA_Stromverbrauch10_Delta
#  LOGDEVICE  dblog_THB
#  LOGFILE    HISTORY
#  NAME      SVG_TUYA_Stromverbrauch10_Delta
#  NR        4001
#  STATE      initialized
#  TYPE      SVG
#  eventCount 1
#
setstate SVG_TUYA_Stromverbrauch10_Delta initialized

also unter Verwendung des Ploteditors.

allerdings entsteht im Plotfile ein Doppelpunkt zuviel:

#dblog_THB TUYA_SP11:energy:::delta-d:$val=($val/1000)
#dblog_THB TUYA_SP12:energy:::delta-d:$val=($val/1000)
#dblog_THB TUYA_SP13:energy:::delta-d:$val=($val/1000)
#dblog_THB TUYA_SP16:energy:::delta-d:$val=($val/1000)
erst wenn ich das mit einem Texteditor wie folgt richtigstelle

#dblog_THB TUYA_SP11:energy::delta-d:$val=($val/1000)
#dblog_THB TUYA_SP12:energy::delta-d:$val=($val/1000)
#dblog_THB TUYA_SP13:energy::delta-d:$val=($val/1000)
#dblog_THB TUYA_SP16:energy::delta-d:$val=($val/1000)
erscheinen tatsächlich die richtigen Differenzwerte im Plot.

Etwas lästig. Meine Dummheit oder noch ein kleiner Bug im Plot-Editor?
Passiert immer wenn man im Editor ein write macht; dann sinds auch wieder 3 Doppelpunkte

Gibt es inzwischen auch ein delta-m für Darstellung von Monats-Differenzen?
Gibt es überhaupt eine Beschreibung für die Definition von SVG's ?


Ich suche auch eine Darstellung z.B. von Summenwerten mehrerer Verbraucher nebeneinander als Balken (also anstelle der x-Achse als Zeitachse) für einen Tag, Monat oder Jahr bzw. definierten Zeitraum

viele Grüße und besten Dank

Thomas

die Suchfunktion im Forum geht seit heute nicht mehr? Lesezeichen sind weg?

Danke für den Hinweis Thomas, das muss ich mir etwas genauer anschauen.
Möglicherweise habe ich etwas übersehen wenn man delta-d nutzen will. Das gehört nämlich nicht zur eigentlichen Funktion $val=($val/1000).

LG,
Heiko

Hallo Thomas, @all,

ich habe den SVG Editor für DbLog gefixt, sodass die Funktionen delta-d etc. mit abgebildet werden können.
Abhängig ob mit oder ohne Vorschlagsliste gearbeitet wird, stellt sich die Verwendung wie in den Screenshots gezeigt dar.

Wie angekündigt, habe ich in dieser Version alle Setter die auf ..Nbl enden, entfernt.

Die Version 5.8.6 befindet sich zunächst in meinem contrib zum Test.

Grüße,
Heiko

Danke, Heiko :-)

was anders..

gibt es von jemand Erfahrungen im Zugriff auf die FHEM-Datenbank (MariaDb) per Connector wie https://www.devart.com/excel-addins/mysql/ (https://www.devart.com/excel-addins/mysql/) zu und von Excel .
oder über ODBC.

Herzliche Grüße

Thomas

Die Version 5.8.6 ist jetzt eingecheckt.

Hallo Heiko,

ich hatte Dir ja schon per Mail geschrieben dass nach einem Update von FHEM ein DbLog-Problem auftaucht.
Meine Umgebung : Raspi mit aktualisiertem BUSTER
Die Version, die den Fehlwer erzeugt : $Id: 93_DbLog.pm 27379 2023-04-01 07:16:52Z DS_Starter $

Die Version $Id: 93_DbLog.pm 26289 2022-08-05 19:15:32Z DS_Starter $ macht den Fehler nicht.

Mein Logfileauszug :

2023.04.03 17:27:11 2: DbLog myDblog5 - Error table history - DBD::mysql::st execute_array failed: Column 'UNIT' cannot be null [err was 1048 now 2000000000] executing 30 generated 30 errors [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (?,?,?,?,?,?,?)"] at /opt/fhem/FHEM/93_DbLog.pm line 3191.

2023.04.03 17:27:12 2: DbLog myDblog5 - Error table history - DBD::mysql::st execute_array failed: Column 'UNIT' cannot be null [err was 1048 now 2000000000] executing 36 generated 36 errors [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (?,?,?,?,?,?,?)"] at /opt/fhem/FHEM/93_DbLog.pm line 3191.

2023.04.03 17:27:12 2: DbLog myDblog5 - Error table history - DBD::mysql::st execute_array failed: Column 'UNIT' cannot be null [err was 1048 now 2000000000] executing 45 generated 45 errors [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (?,?,?,?,?,?,?)"] at /opt/fhem/FHEM/93_DbLog.pm line 3191.

2023.04.03 17:27:12 2: DbLog myDblog5 - Error table history - DBD::mysql::st execute_array failed: Column 'UNIT' cannot be null [err was 1048 now 2000000000] executing 51 generated 51 errors [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (?,?,?,?,?,?,?)"] at /opt/fhem/FHEM/93_DbLog.pm line 3191.

Ich hatte Dir geschrieben, dass der Log durch Modul km200 erzweugt wird. Das war aber falsch. der DbLog myDblog5 schreibt 3 UserReadings ( berechnete Werte aus meinem SolarEdge-Strommessinstrument - über ModbusAttr abgefragt) in die Mysql-Datenbank.
Die Datenbank war generiert mit den Feldattributen NOT NULL . NULL wurde bisher wohl abgefangen und nach Leerstring gewandelt.

Die aktuelle Version von DbLog scheint etwas anderes zu machen.

Das ist eine Meldung des Datenbanktreibers.
DbLog hat das bisher auch nicht anders behandelt, vllt. ist das Datenbankproblem in der alten Version nicht offensichtlich geworden.

Jedenfalls werden die Tabellen im Standard so definiert:

CREATE TABLE `fhem`.`history` (TIMESTAMP TIMESTAMP NOT NULL DEFAULT CURRENT_TIMESTAMP, DEVICE varchar(64), TYPE varchar(64), EVENT varchar(512), READING varchar(64), VALUE varchar(128), UNIT varchar(32));
CREATE TABLE `fhem`.`current` (TIMESTAMP TIMESTAMP, DEVICE varchar(64), TYPE varchar(64), EVENT varchar(512), READING varchar(64), VALUE varchar(128), UNIT varchar(32));

(das Script ist im FHEM contrib verfügbar)

Die einzigste Spalte die nicht NULL sein darf ist TIMESTAMP. Alle anderen dürfen NULL annehmen.
Ich denke du könntest das Problem mit diesem Statement lösen:

ALTER TABLE history MODIFY UNIT varchar(32) NULL;

Habe ich aber noch nicht getestet.

Das hatte ich mir auch schon überlegt.
Dennoch wäre es interessant zu wissen, warum die alte Version dieses Problem nicht hatte und alles ordnungsgemäß geloggt wurde.

ZitatDennoch wäre es interessant zu wissen, warum die alte Version dieses Problem nicht hatte und alles ordnungsgemäß geloggt wurde

Sicher, ist aber jetzt müßig darüber zu spekulieren. Wenn die Spalte in der DB NULL nicht zulässt obwohl sie es müsste, muß der Fehler gemeldet werden. Deswegen ist der richtige Weg die Spalte UNIT so zu ändern dass NULL erlaubt ist wie es der Standard vorgibt.

Hallo Heiko,

seit einiger Zeit stelle ich fest, dass viele Subprozesse nicht 'beendet' werden, die Swap läuft nach einiger Zeit voll und die Auslastung des Arbeitsspeichers nimmt zu:
kurz nach Neustart von Fhem, ich habe schon wesentlich mehr gezählt
  737 mysql      20   0  600M  153M  7036 S  0.0 16.6  8:33.14 /usr/sbin/mysqld
  802 mysql      20   0  600M  153M  7036 S  0.0 16.6  0:53.39 /usr/sbin/mysqld
 7094 mysql      20   0  600M  153M  7036 S  0.0 16.6  0:08.10 /usr/sbin/mysqld
  792 mysql      20   0  600M  153M  7036 S  0.0 16.6  0:20.15 /usr/sbin/mysqld

Die SyncDb erzeugt sekündlich Events, das war vorher nicht:
Eventmonitor
2023-04-08 10:21:17 DbLog syncdb notify_processing_time: 0.0019
2023-04-08 10:21:17 DbLog syncdb notify_processing_time: 0.0004
2023-04-08 10:21:17 MQTT2_DEVICE MQTT2_Netzfrequenz Differenz: -0.003
2023-04-08 10:21:18 DbLog syncdb notify_processing_time: 0.0004
2023-04-08 10:21:18 DbLog syncdb notify_processing_time: 0.0005
2023-04-08 10:21:18 FS20V KS300_Einstrahlung dbvalue: 233
2023-04-08 10:21:18 FS20V KS300_Einstrahlung 233 W/m²
2023-04-08 10:21:22 DbLog syncdb notify_processing_time: 0.0004
2023-04-08 10:21:22 DbLog syncdb notify_processing_time: 0.0004
2023-04-08 10:21:22 MQTT2_DEVICE MQTT2_Rollo_Esszi_West temperature: 55.00
2023-04-08 10:21:22 DbLog syncdb notify_processing_time: 0.0004
2023-04-08 10:21:22 DbLog syncdb notify_processing_time: 0.0004
Def:
defmod syncdb DbLog ./dbsync.conf aaaaaa:bbbbbb
attr syncdb asyncMode 1
attr syncdb cacheEvents 2
attr syncdb devStateIcon devStateIcon .*active:10px-kreis-gelb connected:10px-kreis-gruen .*disconnect:10px-kreis-rot
attr syncdb insertMode 1
attr syncdb room System->DbLog
attr syncdb showNotifyTime 1
attr syncdb showproctime 1
attr syncdb syncEvents 1
attr syncdb verbose 1Der Sync wird über ein at angestoßen und hast sonst eigentlich nichts zu tun.

LG
Bernd

Morgen Bernd,

zum Attr showNotifyTime  gibt es diesen Hilfeeintrag:

ZitatshowNotifyTime [1|0]

    Wenn gesetzt, zeigt das Reading "notify_processing_time" die benötigte Abarbeitungszeit (in Sekunden) für die Abarbeitung der DbLog Notify-Funktion.
    Das Attribut ist für Performance Analysen geeignet und hilft auch die Unterschiede im Zeitbedarf der Eventverarbeitung im synchronen bzw. asynchronen Modus festzustellen.
    (default: 0)

    Hinweis:
    Das Reading "notify_processing_time" erzeugt sehr viele Events und belasted das System. Deswegen sollte bei Benutzung des Attributes die Eventerzeugung durch das Setzen von Attribut "event-min-interval" auf z.B. "notify_processing_time:30" deutlich begrenzt werden.

Der Hinweis ist der richtige Hinweis für dich.  ;)

Jedes DbLog Device hat genau einen permanent mitlaufenden Subprozess. Dieses Prozess verbraucht deutlich weniger Speicher als der Hauptprozess. Die PID des Subprozesses siehst du im Internal SBP_PID des Devices und kannst sie damit zuordnen.

Alle anderen Subprozesse die du feststellst können z.B. durch BlockingCall erzeugt werden oder anderen Modulen stammen die Subprozess verwenden. Die BlockingCall Prozesse sind nur temporär und werden beendet. Das sind vermutlich die, welche du während des Starts siehst.

Alle internen Vorgänge in DbLog laufen über den zugeordneten Subprozess. D.h. auch solange der nicht signifikant Speicher verbaucht, hat das DbLog-Device auch keinen Anteil an deinem "Swap" Problem.

LG,
Heiko

PS: ich bekomme immer wieder mal keine Mails dass in den Threads geantwortet wurde seit der Forum Umstellung. Deswegen dauern meine Antworten manchmal...

Hallo Heiko,

die Hilfe zu showNotifyTime kenne ich soweit. Bin mir aber ziemlich sicher, dass von der Umstellung die Events nicht da waren. Die SyncDB hat ja nichts zu tun, außer wenn sie zum 'Sync' getriggert wird, daher verwundert es mich.
Das attr lösche ich jedenfalls.

Ich habe nur zwei DbLogs, eins davon remote.
OK, DbRep erstellt dann auch Subprozesse von DbLog?
Die meisten DbReps laufen bei mir nicht parallel und doch zähle ich nach längerer Betriebszeit von Fhem immer mehr Subprozesse von DbLog.

Von DbRep hatte ich auch immer wieder timeouts im Log. Kann es sein, dass bei einem timeouts der Subprozesse nicht beendet wird?

LG
Bernd

Hallo Bernd,

ZitatBin mir aber ziemlich sicher, dass von der Umstellung die Events nicht da waren. Die SyncDB hat ja nichts zu tun, außer wenn sie zum 'Sync' getriggert wird, daher verwundert es mich.

Da hast du recht dass es jetzt mehr Events dieser Art gibt. Allerdings durchläuft ein Event immer dein DbLog Device (Notify-Sub). Ob das Device etwas zu tun hat, entscheidet sich ja erst während der Verarbeitung bzw. Auswertung der Parameter. Deswegen gibt es diese NotifyTime Events.

ZitatOK, DbRep erstellt dann auch Subprozesse von DbLog?

DbRep arbeitet mit temporären BlockingCalls. D.h. es werden parallele Prozesse erstellt die wieder beendet werden wenn die Aufgabe abgearbeitet wurde.

ZitatDie meisten DbReps laufen bei mir nicht parallel und doch zähle ich nach längerer Betriebszeit von Fhem immer mehr Subprozesse von DbLog.

Das müsstest du genauer erläutern wie du zu der Annahme kommst diese Subprozesse kämen von DbLog.

ZitatVon DbRep hatte ich auch immer wieder timeouts im Log. Kann es sein, dass bei einem timeouts der Subprozesse nicht beendet wird?

Nein. Wenn ein BlockingCall gestartet wird, bekommt die zentrale FHEM-Schleife den Timeout Parameter übergeben. Der gestartete Prozess wird dann von FHEM (zentral) abgebrochen. Erst dann erscheint der Logeintrag, nicht andersherum.

LG,
Heiko

Zitat von: DS_Starter am 10 April 2023, 22:03:01Das müsstest du genauer erläutern wie du zu der Annahme kommst diese Subprozesse kämen von DbLog.

Danke Heiko für die Erläuterungen.

Wie schon geschrieben, alles mysql Prozesse. Da nur DbLog darauf zugreift, wüsste ich nicht woher diese kommen sollten.
737 mysql      20  0  600M  153M  7036 S  0.0 16.6  8:33.14 /usr/sbin/mysqld
  802 mysql      20  0  600M  153M  7036 S  0.0 16.6  0:53.39 /usr/sbin/mysqld
 7094 mysql      20  0  600M  153M  7036 S  0.0 16.6  0:08.10 /usr/sbin/mysqld
  792 mysql      20  0  600M  153M  7036 S  0.0 16.6  0:20.15 /usr/sbin/mysqld



Das sind aber MySQL Prozesse (kein Perl). Die entstehen z.B. auch über die Ausführung von SVG-Devices. Du könntest mit einem SQL Editor anschauen was die machen.
Alternativ geht das auch mit einem DbRep Device:

  get ... procinfo

Zitat von: DS_Starter am 10 April 2023, 22:22:07Das sind aber MySQL Prozesse (kein Perl). Die entstehen z.B. auch über die Ausführung von SVG-Devices. Du könntest mit einem SQL Editor anschauen was die machen.
Alternativ geht das auch mit einem DbRep Device:

  get ... procinfo

OK, danke. Dann habe ich das falsch interpretiert.

Wenn natürlich immer mehr mysql Prozesse entstehen die nicht wieder abgebaut werden wäre das tatsächlich ein Fehlerzustand. Frage ist dann natürlich wie diese entstehen und müsste untersucht werden.

Da wäre auch noch Grafana zu erwähnen, falls das verwendet wird.
Bei meinem Dashboard hatte ich da, aufgrund der vielen Anzeigewerte, sehr viel MySQL Abfragen, da Grafana jeden Wert separat abgefragt hat.
Erst als ich das in ein SELECT, also auch nur eine Session, zusammen gefasst hatte war endlich ruhe und Grafana lief dann auch flüssiger.

VG   Christian

Danke für die Info.
Grafenau benutze ich noch (?) nicht.

Ich hatte noch keine Zeit danach zu schauen. Da die Prozesse recht jung sind, wollte ich erst noch prüfen, ob diese auch da sind, wenn ich Fhem nicht erst benutzt habe (Plots etc. angeschaut).