Hallo,
ich verwende nun seit über einem Jahr das DbLog ohne Probleme. Seit ein paar Tagen allerdings habe ich das Problem, dass die Werte im Cache festhängen und nicht mehr automatisch in die MySQL Datenbank hochgeladen werden.
CacheOverflowLastNum und CacheUsage steigt an, bis in die zehntausende. Mit listCache werden mir die Werte angezeigt. exportCache funktioniert, beim Import gibt es jedoch einen Fehler. Wenn ich einen Wert lösche, funktioniert ein Import. Kann es an dem Reading liegen, dort ist ein Absatz mit \n enthalten.
502404 => 2022-03-26 13:43:55|Telegram|TELEGRAMBOT|sentMsgText: User1 ist zu Hause 13:43:55
Dauer Abwesend: 00:34:39|sentMsgText|User1 ist zu Hause 13:43:55
Dauer Abwesend: 00:34:39|
Aber auch wenn das Reading nicht im Cache ist, scheint es Probleme mit dem Upload in die DB zu geben.
Mit verbose 5 bekomme ich nur die Fehler für DbLog
2022.03.27 20:31:28 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
Internals:
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 6072566c-f33f-50ef-ebf9-72c03ab0ab9352e7
FVERSION 93_DbLog.pm:v4.12.7-s25800/2022-03-08
MODE asynchronous
MODEL MYSQL
NAME logdb
NR 1030
NTFY_ORDER 50-logdb
PID 1583
REGEXP .*:.*
STATE Commit already running - resync at NextSync
TYPE DbLog
UTF8 1
dbconn mysql:database=fhem-log;host=192.168.178.36;port=3306
dbuser fhemuser
HELPER:
COLSET 1
DEVICECOL 64
EVENTCOL 512
LASTLIMITRUNTIME 1648498320.70581
OLDSTATE Commit already running - resync at NextSync
PACKAGE main
READINGCOL 64
TC current
TH history
TYPECOL 64
UNITCOL 32
VALUECOL 128
VERSION 4.12.7
Helper:
DBLOG:
CacheOverflowLastNum:
logdb:
TIME 1648498320.68646
VALUE 16545
READINGS:
2022-03-28 22:12:00 CacheOverflowLastNum 16546
2022-03-28 10:20:40 CacheOverflowLastState exceeded
2022-03-28 22:12:01 CacheUsage 16759
2022-03-28 22:12:00 NextSync 2022-03-28 22:12:30 or if CacheUsage 100 reached
2022-03-28 07:34:36 background_processing_time 14.3811
2022-03-24 22:33:28 countCurrent 1145
2022-03-24 22:33:28 countHistory 13877032
2022-03-28 10:14:38 lastCachefile ./log/cache_logdb_2022-03-28_10-13-58 import successful
2022-03-28 10:14:38 sql_processing_time 18.1924
2022-03-28 22:12:00 state Commit already running - resync at NextSync
Attributes:
DbLogInclude CacheOverflowLastNum,CacheUsage
DbLogSelectionMode Include
DbLogType Current/History
addStateEvent 1
asyncMode 1
cacheLimit 100
event-on-change-reading .*
room DB
showproctime 1
Kann es sein, dass nach einem Reboot der Cache weg ist?
Alternativ könnte ich ggf. die Werte excluden. Damit wird das allerdings weiterhin geschrieben
attr Telegram DbLogValueFn if ( $VALUE =~ /Dauer Abwesend/ ){ $IGNORE=1;; }
Zitat
Kann es an dem Reading liegen, dort ist ein Absatz mit \n enthalten.
Ja, das ist problematisch. Setz dir das Attr useCharfilter = 1 um Probleme damit zu vermeiden.
Zitat
Kann es sein, dass nach einem Reboot der Cache weg ist?
Ja, nicht machen. Wenn ein Wert im Cache Probleme machen sollte, hilft es das Attr commitMode = ac:on_ta:off
temporär zu setzen.
Problematische Datensätze werden verworfen, alle anderen landen in der DB. Man sollte natürlich versuchen zu ergründen welcher DAtensatz Probleme bereitet um es zukünftig zu vermeiden. In deinem Fall hast du ihn ja bereits identifiziert.
Ich habe Attr useCharfilter = 1 gesetzt.
Danach ein exportCache purchcache und ein ImportCachefile. Dort kommt der Fehler:
setstate logdb 2022-03-28 23:06:07 lastCachefile ./log/cache_logdb_2022-03-28_23-04-42 - Error -
Dann habe ich manuell das Reading mit dem Zeilenumbruch aus dem Cachefile entfernt. Danach funktioniert zumindest der Import.
Allerdings werden auch alle zukünftigen Einträge nicht in die DB geschrieben.
Ich habe die Befürchtung, dass es nicht nur mit dem Reading Probleme gibt.
Zitat von: DS_Starter am 28 März 2022, 22:23:36
Ja, nicht machen. Wenn ein Wert im Cache Probleme machen sollte, hilft es das Attr commitMode = ac:on_ta:off temporär zu setzen.
Problematische Datensätze werden verworfen, alle anderen landen in der DB. Man sollte natürlich versuchen zu ergründen welcher DAtensatz Probleme bereitet um es zukünftig zu vermeiden. In deinem Fall hast du ihn ja bereits identifiziert.
Das würde bedeuten jedesmal wenn ich ein update all und shutdown restart (oder sudo reboot vom Host) mache, muss ich das attr setzen und ansonsten sind die Logs im Cache weg?
Wie sieht denn das korrekte DbLogValueFn aus? Bei mir scheint das attr nicht zu greifen?
attr Telegram DbLogValueFn if ( $VALUE =~ /Dauer Abwesend/ ){ $IGNORE=1;; }
Zitat
Das würde bedeuten jedesmal wenn ich ein update all und shutdown restart (oder sudo reboot vom Host) mache, muss ich das attr setzen und ansonsten sind die Logs im Cache weg?
Nein. Das ist gesichert, dass vor dem Shutdown der Cache weggeschrieben wird. Die Aussage galt nur für den hier vorliegenden Fehlerfall.
Zitat
Wie sieht denn das korrekte DbLogValueFn aus? Bei mir scheint das attr nicht zu greifen?
Wahrscheinlich muß der Regex wegen des Zeilenumbruchs mit einem Single Line Operator versehen werden.
Ansonsten fehlten die umschließenden {} für den Ausdruck:
attr Telegram DbLogValueFn { if ( $VALUE =~ /Dauer Abwesend/s ){ $IGNORE=1; } }
Zitat von: DS_Starter am 29 März 2022, 09:00:39
Nein. Das ist gesichert, dass vor dem Shutdown der Cache weggeschrieben wird. Die Aussage galt nur für den hier vorliegenden Fehlerfall.
Aktuell ist dieser Eintrag nicht im Cache, aber trotzdem wird der Cache nicht automatisch hochgeladen. Mit einem export + purge und import funktioniert alles.
Dann gibt es bei dir noch ein anderes Problem. Ein aktuelles List und ein verbose 5 Log eines Speicherungslaufes wäre hilfreich.
Eventuell sieht man schon etwas wenn man einen Blick in den Cache wirft (falls er nicht zu groß ist).
Nach einigen Minuten mit verbose 5 steht steht nur das im Log
2022.03.29 17:21:14 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:20:43 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:20:43 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:20:26 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:20:26 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:19:56 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:19:26 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:19:26 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:18:48 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:18:18 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:17:48 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:17:48 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:17:31 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:17:31 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:17:13 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:17:13 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:16:48 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:16:18 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:16:18 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
2022.03.29 17:16:00 4: DbLog logdb -> Number of cache entries reached cachelimit 100 - start database sync.
Du hast wahrscheinlich eine sehr hohe Anzahl Einträge im Cache (gehabt). Deine DB braucht entsprechend lange Zeit um diese Menge zu schreiben. Der nächste Sync Lauf will vor dem Ende des aktuellen Laufs starten und kann es nicht -> das erzeugt die Logeinträge.
Ich würde dir raten das Attr cacheLimit deutlich höher zu setzen oder zu löschen. Dafür das Attr syncInterval auf 300 Sekunden zu setzen.
Wenn sich die Lage beruhigt hat, kannst du wieder reduzieren. Ich würde die Limits aber immer im Zusammenhang mit dem persönlichen Logaufkommen und der Performance der Datenbank setzen. Wenn sich die Intervalle überschneiden ist das zwar nicht schlimm, aber die Logeinträge vermitteln ein "unangenehmes" Gefühl.
Seite 9 Stunden wurden nun keine Einträge mehr in die DB geschrieben. Im Cache liegen 19k Zeilen, daher ca. 35 Logs pro Minute. Ich denke die Anzahl ist nicht zu hoch für das Interval.
Die Anzahl der Logs hat sich in den letzten Monaten nicht groß verändert. Bisher lief immer alles ohne Probleme.
Ich habe nun mal die attr gesetzt. Bisher tritt das gleiche Problem auf.
attr logdb cacheLimit 500
attr logdb syncInterval 300
Wenn keine weiteren log infos vorliegen kann ich mir keinen grund für die situation vorstellen.
Schalte doch den modus in synchron um. Vorher die daten aus dem cache sichern und löschen.