Hallo zusammen,
folgendes Problem bei DbLog, asynchron:
ich habe die Attribute cacheLimit auf 500 sowie cacheOverflowThreshold auf 1000. Damit sollte der Cache in die DB wandern, wenn er 500 Einträge hat. Das klappt.
Wenn ich die DB-Verbindung schliesse, um z.B. einen Dump oder sonstige Maintenance direkt an der DB zu machen soll nach 1000 Einträgen im Cache dieser als File geschrieben werden. Das klappt zwar, aber der Cache wird dann ge"purged" und dann wird das selbe File nochmals geschrieben und ist somit leer.
Ich habe 2 Systeme: auf einem funktioniert es wie vorgesehen, auf dem anderen tritt der beschriebene Fehler auf. Beide DbLog-Devices sind gleich konfiguriert (nur kleinere Zahlen bei den beiden Attributen).
Auszug aus dem Log:
2025.10.29 18:00:18.338 2: myMariaDB - WARNING - Cache is exported to file instead of logging it to database
2025.10.29 18:00:18.349 3: myMariaDB - 1022 Cache rows exported to ./log/cache_myMariaDB_2025-10-29_18-00-18
2025.10.29 18:00:18.350 3: myMariaDB - Cache purged after exporting rows to ./log/cache_myMariaDB_2025-10-29_18-00-18.
2025.10.29 18:00:18.354 2: myMariaDB - WARNING - Cache is exported to file instead of logging it to database
2025.10.29 18:00:18.356 3: myMariaDB - 0 Cache rows exported to ./log/cache_myMariaDB_2025-10-29_18-00-18
2025.10.29 18:00:18.356 3: myMariaDB - Cache purged after exporting rows to ./log/cache_myMariaDB_2025-10-29_18-00-18.
2025.10.29 18:10:08.416 2: myMariaDB - WARNING - Cache is exported to file instead of logging it to database
2025.10.29 18:10:08.433 3: myMariaDB - 1025 Cache rows exported to ./log/cache_myMariaDB_2025-10-29_18-10-08
2025.10.29 18:10:08.435 3: myMariaDB - Cache purged after exporting rows to ./log/cache_myMariaDB_2025-10-29_18-10-08.
2025.10.29 18:10:08.440 2: myMariaDB - WARNING - Cache is exported to file instead of logging it to database
2025.10.29 18:10:08.441 3: myMariaDB - 0 Cache rows exported to ./log/cache_myMariaDB_2025-10-29_18-10-08
2025.10.29 18:10:08.442 3: myMariaDB - Cache purged after exporting rows to ./log/cache_myMariaDB_2025-10-29_18-10-08.
anderes System wo es funktioniert:
2025.10.29 15:30:40.484 2: myMariaDBRaspi4 - WARNING - Cache is exported to file instead of logging it to database
2025.10.29 15:30:40.489 3: myMariaDBRaspi4 - 152 Cache rows exported to ./log/cache_myMariaDBRaspi4_2025-10-29_15-30-40
2025.10.29 15:30:40.490 3: myMariaDBRaspi4 - Cache purged after exporting rows to ./log/cache_myMariaDBRaspi4_2025-10-29_15-30-40.
2025.10.29 15:43:03.570 2: myMariaDBRaspi4 - WARNING - Cache is exported to file instead of logging it to database
2025.10.29 15:43:03.572 3: myMariaDBRaspi4 - 152 Cache rows exported to ./log/cache_myMariaDBRaspi4_2025-10-29_15-43-03
2025.10.29 15:43:03.573 3: myMariaDBRaspi4 - Cache purged after exporting rows to ./log/cache_myMariaDBRaspi4_2025-10-29_15-43-03.
2025.10.29 15:53:17.143 2: myMariaDBRaspi4 - WARNING - Cache is exported to file instead of logging it to database
2025.10.29 15:53:17.149 3: myMariaDBRaspi4 - 152 Cache rows exported to ./log/cache_myMariaDBRaspi4_2025-10-29_15-53-17
2025.10.29 15:53:17.150 3: myMariaDBRaspi4 - Cache purged after exporting rows to ./log/cache_myMariaDBRaspi4_2025-10-29_15-53-17.(Die Leerzeilen habe ich hier eingefügt zur besseren Lesbarkeit)
Woran kann das liegen? Ab und zu wird auch nicht überschrieben, aber eher so 1 aus 10 mal.
Am Ende sorgt es halt für Datenverlust.
Freue mich auf Hinweise.
Gruß
Sany
Ich kann dir aktuell nicht sagen wieso der Cache Export auf der einen Instanz quasi in der selben Sekunde 2 mal aufgerufen wird. Es fällt mir adhoc kein Szenario ein. Dazu müsste man vllt. das ganze Device mal anschauen.
Aber das Problem kannst du entschärfen mit exportCacheAppend=1. Dadurch wird das File nicht mehr überschrieben, sondern nur ergänzt.
Ein Überschreiben kann nur innerhalb der gleichen Sekunde vorkommen was eingentlich als nicht möglich angesehen wird. Aber es muß, wie es aussieht, doch irgendwo eine Situation geben die dies ermöglicht.
LG,
Heiko
Hallo Heiko,
ja, vielen Dank, das werde ich dann nutzen. Ich schau mir das aber trotzdem morgen nochmal an mit hochgedrehtem verbose, evtl. sieht man dann mehr.
Gibt es eine Empfehlung für die Werte? Cache-default ist ja 500, aber wie groß kann die Zahl denn werden, wenn ich nicht in die DB sondern in ein file schreiben lasse? Oder was macht hier Sinn?
Viele Grüße
Sany
ZitatCache-default ist ja 500, aber wie groß kann die Zahl denn werden, wenn ich nicht in die DB sondern in ein file schreiben lasse? Oder was macht hier Sinn?
Was geht oder Sinn macht hängt von der Leistungsfähigkeit deiner Hardware und von den eigenen Anforderungen ab.
Ich habe auch schon mit 10000 - 50000 experimentiert und funktioniert auch, macht aber im Betrieb keinen Sinn. Je größer der Cache, desto mehr RAM wird gebraucht, die DB muß schnell genug sein die Blöcke dann zu verarbeiten (oder das Filesystem die Daten in ein File zu schreiben) und wenn FHEM oder der Rechner abstürzt ist der Cache-Inhalt verloren.
Der Überlauf in ein File ist eigentlich nur für Fehlerfälle gedacht wenn die DB nicht erreichbar ist bzw. auch für Wartung. Man hat ja hinterher auch die Arbeit die Files in die DB zu importieren, sollte also nicht der Normalfall sein.
Für eine Wartung kann man den Cache und die Sync-zeit temporär auch hochdrehen und so die Zeit die Daten im RAM halten und nach der Wartung in die DB schreiben lassen.
Zu dem Thema ist mir noch eingefallen ob du eventuell von außen, z.B. set <name> exportCache oder set <name> commitCache, antriggerst und dies zeitlich ungünstig zusammenfällt?
Hallo Heiko,
habe das Problem gelöst: in den Readings wird ja CacheOverflowLastNum, CacheOverflowLastState und CacheUsage angezeigt. Ich wollte nun nicht immer die Seite neu laden, um die aktualisierten Werte angezeigt zu bekommen und habe deshalb Cache.* bei event-on-change-readings eingetragen. Das hatte zwar nicht den gewünschten Effekt, aber reproduzierbar sorgt das dafür, dass das geschriebene Cahe-file gleich wieder leer überschrieben wird. Bei Append passiert das auch, nur dass es nix ausmacht, wenn nix angehängt wird.
Es läuft jetzt so wie vorgesehen. Allerdings hätte ich das auch nicht so erwartet.
Danke auch für die Infos, ich lasse den cache auf default (500) und setze den Overflow etwas höher, 700 oder 800. Da wirds wohl keine Performanceprobleme geben.
Append lasse ich eingeschaltet und da ja ein Event erzeugt wird, wenn das Cachefile geschrieben wird (Cache exported to "lastCachefile" due to Cache overflow) triggere ich darauf und lass mir eine Nachricht schicken, falls das mal passieren sollte (DB offline o.ä.).
Ich setze das Thema auf gelöst.
Viele Dank noch mal
Gruß
Sany
ZitatIch wollte nun nicht immer die Seite neu laden, um die aktualisierten Werte angezeigt zu bekommen und habe deshalb Cache.* bei event-on-change-readings eingetragen. Das hatte zwar nicht den gewünschten Effekt, aber reproduzierbar sorgt das dafür, dass das geschriebene Cahe-file gleich wieder leer überschrieben wird.
Jetzt wird das Problem klarer. Durch diese Massnahme erzeugst du Events die wiederum, wenn sie im DEF nicht gefiltert werden, wieder von DbLog in der Notify-Sub verarbeitet werden. D.h. das DbLog-Device befruchtet sich sozusagen selbst. ;) Das passiert innerhalb von ms und hat offensichtlich diesen Nebeneffekt.
Wenn du verhindern willst, dass sich das Device selbst loggt, kannst du das mit excludeDevs-><DbLog-Device> oder excludeDevs->TYPE=DbLog unterbinden. Das sollte man m.M. generell tun und wenn gewünscht die DbLog Events in einem anderen DbLog Device oder in einem FileLog loggen.
Wenn du das umsetzt, kannst du deine Events auch wieder einschalten.
LG,
Heiko