93_DBLog.pm - CacheOverflowLastNum- und CacheUsage-Meldungen im FHEM-Log

khk123 · 21 März 2021, 11:49:30

Beim Update auf die Version 4.11.0 kommen massenhaft folgende Meldungem im Log:


2021-03-21_10:21:17 LogDatabase CacheUsage: 20
2021-03-21_10:21:47 LogDatabase CacheOverflowLastNum: 0
2021-03-21_10:21:47 LogDatabase CacheUsage: 28
2021-03-21_10:22:17 LogDatabase CacheOverflowLastNum: 0
2021-03-21_10:22:17 LogDatabase CacheUsage: 19
2021-03-21_10:22:48 LogDatabase CacheOverflowLastNum: 0
2021-03-21_10:22:48 LogDatabase CacheUsage: 19
2021-03-21_10:23:18 LogDatabase CacheOverflowLastNum: 0
2021-03-21_10:23:18 LogDatabase CacheUsage: 14
2021-03-21_10:23:48 LogDatabase CacheOverflowLastNum: 0
2021-03-21_10:23:48 LogDatabase CacheUsage: 26

Ich kann die Meldungen anscheinend nicht abstellen. Bin erstmal auf die alte Version 4.10.2 zurückgegangen.
Hab ich da evtl. etwas übersehen?

VG
Karlheinz

DS_Starter · 21 März 2021, 12:12:22

Hallo Karlheinz,

es gibt ein neues Feature, Stichwort Attribut cacheOverflowThreshold.
Allerdings sollte es nur aktiv sein wenn das Attribut gesetzt wird, da muß ich nachbessern.

Das bei dir diese Meldung kommt, weist darauf hin dass der cacheLimit bei dir ständig/sehr häufig überschritten wird.
Was kein Fehler ist, aber eventuell auf eine langsame DB odgl. hinweist.

Bis ich nachgessert habe, kannst du dir das Attribut cacheOverflowThreshold auf einen sehr hohen Wert setzen. Dann wird es zu diesen Meldungen nicht kommen.

LG,
Heiko

khk123 · 21 März 2021, 12:32:38

Hallo Heiko,

viele Dank für die schnelle Antwort. Ich benutze SQlite. FHEM und DB laufen auf einem Raspi 3. cacheLimit ist 500, asyncMode und bulkInsert stehen auf 1. Bisher hatte ich nicht den Eindruck, dass bei der Datenbank etwas klemmt.

VG
Karlheinz

DS_Starter · 21 März 2021, 12:57:11

Oder du hast viele Events die schnell im cache landen. Jedenfalls wird cacheLimit immer wieder überschritten

Wie gesagt kein Fehler, darf aber nur kommen wenn man das Attr benutzt.
Richte ich ...

EDIT: Aber CacheUsage Meldung hat damit nichts zu tun. Dafür das Attr cacheEvents entsprechend nutzen.

khk123 · 21 März 2021, 14:36:25

Ich habe cacheEvents auf 2 und cacheLimit auf 1000 gesetzt. syncInterval steht auf 30. Wenn ich das richtig sehe, dann sind das nicht so viele Events, die im Cache sind, wenn der nächste asynchronen Schreibvorgang beginnt.

Code Auswählen


2021-03-21_14:21:13 LogDatabase CacheUsage: 15
2021-03-21_14:21:13 LogDatabase CacheUsage: 16
2021-03-21_14:21:43 LogDatabase CacheUsage: 22
2021-03-21_14:21:43 LogDatabase CacheUsage: 23
2021-03-21_14:22:13 LogDatabase CacheUsage: 16
2021-03-21_14:22:13 LogDatabase CacheUsage: 17
2021-03-21_14:22:43 LogDatabase CacheUsage: 7
2021-03-21_14:22:43 LogDatabase CacheUsage: 8
2021-03-21_14:23:13 LogDatabase CacheUsage: 30
2021-03-21_14:23:13 LogDatabase CacheUsage: 31
2021-03-21_14:23:43 LogDatabase CacheUsage: 40
2021-03-21_14:23:43 LogDatabase CacheUsage: 41
2021-03-21_14:24:13 LogDatabase CacheUsage: 31
2021-03-21_14:24:13 LogDatabase CacheUsage: 32
2021-03-21_14:24:43 LogDatabase CacheUsage: 7
2021-03-21_14:24:43 LogDatabase CacheUsage: 8
2021-03-21_14:25:13 LogDatabase CacheUsage: 32
2021-03-21_14:25:13 LogDatabase CacheUsage: 33
2021-03-21_14:25:44 LogDatabase CacheUsage: 9
2021-03-21_14:25:44 LogDatabase CacheUsage: 10

VG
Karlheinz

DS_Starter · 21 März 2021, 14:55:01

Ach jetzt sehe ich erst dass es bei dir um Events geht und nicht Log-Einträge wie du eingangs geschrieben hast.

Es steht ja auch geschrieben:

CacheOverflowLastNum: 0

Und was stört dich jetzt daran ?

khk123 · 29 März 2021, 16:54:27

Sehe deine Antwort erst jetzt.

Naja, du hast geantwortet, dass anscheinend zu viele Events im Cache landen. chacheLimit war auf 500 und wenn ich die Meldungen richtig interpretiere, war das aber nicht der Fall. In meiner ersten Mail ging es mir schon um die massenhaft auftauchenden Log-Meldungen und nicht um die Events und die haben mich halt gestört. Problem ist ja aber erst mal behoben.

VG
Karlheinz

khk123 · 13 Mai 2021, 17:22:13

Hallo Heiko,

ich brauche wegen der Einträge im FHEM-Log doch nochmal Hilfe. Nach dem Update von 93_DbLog.pm 22246 2020-06-23 21:12:11Z auf 93_DbLog.pm 24180 2021-04-07 20:57:51Z erscheinen im FEM-Log Meldungen bei jedem syncInterval.

Das letzte Mal hatte ich das alte Programm restored und daher waren die Meldungen erstmal weg und ich hatte gehofft beim nächten Update würde sich mein Problem lösen lassen. Aber dem ist leider nicht so. Da ich auch nicht auf der alten 93_DbLog.pm-Version bleiben möchte, ist meine Frage: Wie kann ich diese Meldunge unterdrücken?

VG
Karlheinz

Code Auswählen


021-05-13_17:03:21 LogDatabase CacheUsage: 43
2021-05-13_17:03:21 LogDatabase CacheUsage: 44
2021-05-13_17:03:21 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:03:21 LogDatabase CacheUsage: 45
2021-05-13_17:03:51 LogDatabase CacheUsage: 19
2021-05-13_17:03:51 LogDatabase CacheUsage: 20
2021-05-13_17:03:51 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:03:51 LogDatabase CacheUsage: 21
2021-05-13_17:04:21 LogDatabase CacheUsage: 15
2021-05-13_17:04:21 LogDatabase CacheUsage: 16
2021-05-13_17:04:22 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:04:22 LogDatabase CacheUsage: 17
2021-05-13_17:04:52 LogDatabase CacheUsage: 12
2021-05-13_17:04:52 LogDatabase CacheUsage: 13
2021-05-13_17:04:52 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:04:52 LogDatabase CacheUsage: 14
2021-05-13_17:05:22 LogDatabase CacheUsage: 14
2021-05-13_17:05:22 LogDatabase CacheUsage: 15
2021-05-13_17:05:22 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:05:22 LogDatabase CacheUsage: 16
2021-05-13_17:05:52 LogDatabase CacheUsage: 20
2021-05-13_17:05:52 LogDatabase CacheUsage: 21
2021-05-13_17:05:52 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:05:52 LogDatabase CacheUsage: 22
2021-05-13_17:06:22 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:06:22 LogDatabase CacheUsage: 11
2021-05-13_17:06:52 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:06:52 LogDatabase CacheUsage: 13
2021-05-13_17:07:22 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:07:22 LogDatabase CacheUsage: 16
2021-05-13_17:07:52 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:07:52 LogDatabase CacheUsage: 19
2021-05-13_17:08:23 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:08:23 LogDatabase CacheUsage: 19
2021-05-13_17:08:53 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:08:53 LogDatabase CacheUsage: 20
2021-05-13_17:09:23 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:09:23 LogDatabase CacheUsage: 3
2021-05-13_17:09:53 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:09:53 LogDatabase CacheUsage: 18
2021-05-13_17:10:23 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:10:23 LogDatabase CacheUsage: 12
2021-05-13_17:10:53 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:10:53 LogDatabase CacheUsage: 16
2021-05-13_17:11:23 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:11:23 LogDatabase CacheUsage: 19
2021-05-13_17:11:53 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:11:53 LogDatabase CacheUsage: 13
2021-05-13_17:12:23 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:12:23 LogDatabase CacheUsage: 10
2021-05-13_17:12:54 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:12:54 LogDatabase CacheUsage: 40
2021-05-13_17:13:24 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:13:24 LogDatabase CacheUsage: 13
2021-05-13_17:13:54 LogDatabase CacheOverflowLastNum: 0
2021-05-13_17:13:54 LogDatabase CacheUsage: 28

Maine Definitionen:

Code Auswählen


Internals:
   .FhemMetaInternals 1
   COLUMNS    field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32 
   CONFIGURATION /opt/fhem/db.conf
   DEF        /opt/fhem/db.conf .*
   FUUID      5c45f91c-f33f-2526-8348-391d8ce9b5d8fc16
   FVERSION   93_DbLog.pm:v4.12.1-s24180/2021-04-07
   MODE       asynchronous
   MODEL      SQLITE
   NAME       LogDatabase
   NR         116
   NTFY_ORDER 50-LogDatabase
   PID        6382
   REGEXP     .*
   SQLITECACHESIZE 4000
   SQLITEWALMODE on
   STATE      connected
   TYPE       DbLog
   dbconn     SQLite:dbname=/opt/fhem/fhem.db
   dbuser     
   .attraggr:
   .attrminint:
   .userReadings:
     HASH(0x51686a0)
     HASH(0x5f6f108)
   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.12.1
   Helper:
     DBLOG:
       CacheOverflowLastNum:
         LogDatabase:
           TIME       1620918382.6884
           VALUE      0
       CacheUsage:
         LogDatabase:
           TIME       1620918352.49908
           VALUE      20
       state:
         LogDatabase:
           TIME       1620918106.58843
           VALUE      connected
   READINGS:
     2021-05-13 17:06:22   CacheOverflowLastNum 0
     2021-03-20 15:43:21   CacheOverflowLastState normal
     2021-05-13 17:06:41   CacheUsage      1
     2021-05-13 03:15:07   DbFileSize      54
     2021-05-13 17:06:22   NextSync        2021-05-13 17:06:52 or if CacheUsage 1000 reached
     2021-05-13 03:15:08   countCurrent    0
     2021-05-13 03:15:07   countHistory    201771
     2021-05-13 03:15:07   lastReduceTime  13.05.2021 03:15:07
     2021-05-13 03:15:07   reduceLogState  Rows processed: 34790, deleted: 19956, time: 7.00sec
     2021-05-13 17:06:22   state           connected
Attributes:
   DbLogInclude .*
   DbLogSelectionMode Exclude/Include
   DbLogType  History
   asyncMode  1
   bulkInsert 1
   cacheEvents 0
   cacheLimit 1000
   group      Datenbanken
   room       System->Datenbanken
   syncInterval 30
   userReadings DbFileSize:reduceLogState.* { (split(' ',`du -m /opt/fhem/fhem.db`))[0] },lastReduceTime:reduceLogState.*
{ (strftime('%d.%m.%Y %H:%M:%S', localtime)) }
   verbose    2

DS_Starter · 13 Mai 2021, 18:50:46

Hallo Karlheinz,

das sind Events und keine Log Einträge.
Events kannst du wie in FHEM üblich mit den event.* Attributen beeinflissen.

LG,
Heiko

khk123 · 14 Mai 2021, 00:12:49

Hallo Heiko,

das bringt mich diesmal auf die richtige Spur. ich habe mal in meiner FileLog-folgenden DEF-Eintrag

Code Auswählen

 	
/opt/fhem/log/fhem-%Y-%m.log LogDatabase:.*|FakeLog

Hab jetzt LogDatabase:.* entfernt und schon ist Ruhe. Mir ist aber nicht mehr klar, warum ich vor Jahren diese Ergänzung in Bezug auf DbLog vorgenommen hatte. War evtl. eine Empfehlung aus dem Forum oder eine Fehlinterpretation meinerseits.

Danke für den Hinweis und
VG
Karlheinz