Hallo,
ich bekomme seit dem Update auf FHEM 5.8 folgende Fehlermeldung in Plots:
ZitatDBD::SQLite::st execute_array failed: executing 35024 generated 183 errors at ./FHEM/93_DbLog.pm line 1581. , 0
Ich habe die Vermutung, dass irgendetwas im LogDB oder eher im SVG-Modul nicht richtig klappt. Wenn ich mir den Cache vom DBLog-Modul ansehe (läuft mit SQLite), dann sehe ich Einträge von Devices, die ich beim entprechenden SVG-Plot beim Klick auf "show preprocessed inputs" nicht sehe. Selbst nach einem Commit cache (nachdem die Daten in der Datenbank gespeichert sein sollten) zeigt der SVG-Plot nichts an.
Einige Plots bleiben komplett leer, andere zeigen ein paar Werte an (wobei es mir vor kommt, als ob da Punkte fehlen...)
Was ich komisch finde:
Das LogDB-Modul zeigt in den Readings keine Fehler an. Gleiches ist beim SVG-Plot. Allerdings steht unter:
Probably associated with
Zitatsys_logdb DBD::SQLite::st execute_array failed: executing 35024 generated 183 errors at ./FHEM/93_DbLog.pm line 1581. , 0 DbLog
Liegt das mit dem Update auf FHEM 5.8 zusammen oder ist meine Datenbank defekt? :-[ Vielleicht habe ich es auch durch ein schlechtes "reduceLog" zerschossen :(
Edit: Ich bekomme das Problem auch bei einer frisch angelegten Datenbank :'(
PS: Falls das hier das falsche Unterforum ist, bitte verschieben ::)
Hallo,
leider bekomme ich immer noch das Problem.
Was ich bisher probiert habe:
- alte Datenbank nach wiki-Eintrag reparieren
- neue Datenbank anlegen
- Dateirechte für fhem kontrolliert
- fhem update und apt-get update/upgrade
Ich kann reproduzieren, dass die Datenbank beim Befehl "count" folgenden Fehler erzeugt:
ZitatDBD::SQLite::st execute_array failed: unable to open database file [err was 14 now 2000000000] executing 246 generated 246 errors at ./FHEM/93_DbLog.pm line 1581. , 0
Ich habe das Gefühl, dass es noch an dem update auf fhem 5.8 sondern an dem aktuellen dbLog Modul liegt, welches jetzt nicht-blockierende Befehle besitzt.
Es müsste dann doch noch jemand das Problem haben... :(
Wie so oft sitzt das Problem vor dem Rechner ::)
Nachdem ich verschiedene Versionen aus dem fhem-SVN herunter geladen habe und immer das selbe Problem auftrat, konnte ich die Module als Problemquellen ausschließen.
Es waren wohl die Benutzerrechte für die Dateien richtig, jedoch nicht für den db-Ordner. Daher hatte das Modul keine Schreibrechte.
Ich würde mich gerne in diesen alten Thread nochmal einklinken.
Bei mir funktioniert die Datenbank-Anbindung mit dem gleichen Fehler heute aus heiterem Himmel nicht mehr.
2018.10.09 09:47:56 2: DbLog Logdb -> Error table history - DBD::mysql::st execute_array failed: executing 28 generated 3 errors at ./FHEM/93_DbLog.pm line 2060.
Zu der Zeit war ich gar nicht im Haus. Anhand der Plots kann man sehen, dass bis dahin alles funktioniert hat.
Ich hab auch keine Updates eingespielt oder sonstige Änderungen am System durchgeführt - zumindest nicht bewusst.
FHEM loggt bei mir in eine Mariadb10, die auf meiner Synology läuft. Vor gut 2 Wochen habe ich da das Temp-Verzeichnis neu gemappt, damit das Log-Reduce wieder funktioniert (https://forum.fhem.de/index.php/topic,87447.msg838954.html#msg838954). Das hat aber einwandfrei funktioniert. Ich sehe keinen objektiven Grund, warum jetzt plötzlich dieser Fehler auftritt.
Der FHEM Server läuft auf einem RaspberryPi mit raspbian und FHEM ist in Version 5.9 auf dem letzten Stand.
Nachdem der Fehler heute anftrat, habe ich sowohl die Synology als auch den RaspberryPi rebootet und FHEM nochmal geupdated. Leider ohne Erfolg.
Weiß jemand, was der Fehler überhaupt heißt?
Beste Grüße,
Bond
Hallo Bond,
führe im DbLog bitte ein "set ... configCheck" aus und poste bitte das komplette Ergebnis.
Und dann bitte noch ein List deines DbLog-Devices.
Ich vermute ein Konfigurationsproblem was nichts mit dem Modul oder FHEM zu tun hat.
Grüße
Heiko
configCheck:
Result of DbLog version check
Used DbLog version: 3.12.2
Recommendation: Your running version may be the current one. Please check for updates of DbLog periodically.
Result of configuration read check
Connection parameter store type: file
Connection parameter: Connection -> mysql:database=fhem;host=diskstation;port=3307, User -> fhemuser, Password -> read o.k.
Result of connection check
Connection to database fhem successfully done.
Recommendation: settings o.k.
Result of encoding check
Encoding used by Client (connection): UTF8
Encoding used by DB fhem: UTF8
Recommendation: settings o.k.
Result of logmode check
Logmode of DbLog-device Logdb is: asynchronous
Recommendation: settings o.k.
Result of shutdown sequence preparation check
Attribute "shutdownWait" is set to: 2
Recommendation: The setting may be ok. But due to the Reading "background_processing_time" is not available (you may set attribute "showproctime"), the current
setting is only a rough estimate.
Result of plot generation method check
WEB: plotfork=1
WEBphone: plotfork=1
WEBtablet: plotfork=1
Recommendation: settings o.k.
Result of table 'history' check
Column width set in DB fhem.history: 'DEVICE' = 64, 'TYPE' = 64, 'EVENT' = 512, 'READING' = 64, 'VALUE' = 128, 'UNIT' = 32
Column width used by Logdb: 'DEVICE' = 64, 'TYPE' = 64, 'EVENT' = 512, 'READING' = 64, 'VALUE' = 128, 'UNIT' = 32
Recommendation: settings o.k.
Result of table 'current' check
Column width set in DB fhem.current: 'DEVICE' = 64, 'TYPE' = 64, 'EVENT' = 512, 'READING' = 64, 'VALUE' = 128, 'UNIT' = 32
Column width used by Logdb: 'DEVICE' = 64, 'TYPE' = 64, 'EVENT' = 512, 'READING' = 64, 'VALUE' = 128, 'UNIT' = 32
Recommendation: settings o.k.
Result of check 'Search_Idx' availability
Index 'Search_Idx' exists and contains recommended fields 'DEVICE', 'READING', 'TIMESTAMP'.
Recommendation: settings o.k.
Result of check 'Report_Idx' availability for DbRep-devices
At least one DbRep-device assigned to Logdb is used, but the recommended index 'Report_Idx' is missing.
Recommendation: You can create the index by executing statement 'CREATE INDEX Report_Idx ON `history` (TIMESTAMP, READING) USING BTREE;'
Depending on your database size this command may running a long time.
Please make sure the device 'Logdb' is operating in asynchronous mode to avoid FHEM from blocking when creating the index.
Note: If you have just created another index which covers the same fields and order as suggested (e.g. a primary key) you don't need to create the 'Report_Idx' as well !
Was meinst du mit Liste des DbLog Devices?
Hier erstmal die config:
define Logdb DbLog ./db.conf .*:.*
attr Logdb DbLogExclude .*
attr Logdb DbLogSelectionMode Exclude/Include
attr Logdb DbLogType Current/History
attr Logdb asyncMode 1
attr Logdb room Logs
attr Logdb shutdownWait 2
attr Logdb verbose 5
verbose 5 hab ich vorhin aktiviert, um eventuell mehr Infos zu bekommen. Dem ist aber nicht so.
Hier noch die Internals:
COLUMNS field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32
CONFIGURATION ./db.conf
DEF ./db.conf .*:.*
MODE asynchronous
MODEL MYSQL
NAME Logdb
NR 17
NTFY_ORDER 50-Logdb
PID 2202
REGEXP .*:.*
STATE DBD::mysql::st execute_array failed: executing 1625 generated 139 errors at ./FHEM/93_DbLog.pm line 2063.
TYPE DbLog
UTF8 1
VERSION 3.12.2
dbconn mysql:database=fhem;host=diskstation;port=3307
dbuser fhemuser
Zitat von: Bond246 am 09 Oktober 2018, 22:26:08
Was meinst du mit Liste des DbLog Devices?
Fhem Befehl: list Logdb
Gesendet von meinem Doogee S60 mit Tapatalk
Sieht erstmal sehr gut aus.
Also die Mitteilung der DB "executing 1625 generated 139 errors" besagt i.A. dass 1625 Datensätze weggeschrieben werden sollen und 139 nicht geschrieben werden können. Diese Sätze verhindern den gesamten Vorgang weil es als Transaktion ausgeführt wird.
Setze mal bitte das Attribut:
commitMode = basic_ta:off
Wie sieht es dann aus ? Und poste mal die Ausgabe von "set ... listCache" (mit gesetztem Attribut).
Hi,
super dass ihr mir hier so flott helft :-)
Hier nochmal die Device-List
Internals:
COLUMNS field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32
CONFIGURATION ./db.conf
DEF ./db.conf .*:.*
MODE asynchronous
MODEL MYSQL
NAME Logdb
NR 17
NTFY_ORDER 50-Logdb
PID 2202
REGEXP .*:.*
STATE DBD::mysql::st execute_array failed: executing 2113 generated 185 errors at ./FHEM/93_DbLog.pm line 2063.
TYPE DbLog
UTF8 1
VERSION 3.12.2
dbconn mysql:database=fhem;host=diskstation;port=3307
dbuser fhemuser
HELPER:
COLSET 1
DEVICECOL 64
EVENTCOL 512
LASTLIMITRUNTIME 1539117967.56464
OLDSTATE DBD::mysql::st execute_array failed: executing 2113 generated 185 errors at ./FHEM/93_DbLog.pm line 2063.
READINGCOL 64
TYPECOL 64
UNITCOL 32
VALUECOL 128
READINGS:
2018-10-09 22:47:07 CacheUsage 2121
2018-10-09 22:47:08 NextSync 2018-10-09 22:47:38 or if CacheUsage 500 reached
2018-10-09 03:01:29 reduceLogState reduceLogNbl finished. Rows processed: 263276, deleted: 26853, updated: 556, time: 89.00sec
2018-10-09 22:47:08 state DBD::mysql::st execute_array failed: executing 2113 generated 185 errors at ./FHEM/93_DbLog.pm line 2063.
cache:
index 314506
Attributes:
DbLogExclude .*
DbLogSelectionMode Exclude/Include
DbLogType Current/History
asyncMode 1
room Logs
shutdownWait 2
verbose 5
Und der listCache Output ist ziemlich lang, deswegen als txt-File im Anhang.
Es sieht ziemlich danach aus, dass es jetzt mit commitMode = basic_ta:off wieder läuft.
Die Synology ist stark am arbeiten und fhem reagiert ziemlich langsam wenn ich das Logfile öffne.
Vermutlich wird das logfile gerade immens groß, weil ich verbose noch auf 5 hab.
Ja, dann stelle erstmal das verbose wieder auf 3 oder 2. Ich schaue mir dein File gerade an.
Ich glaube ich habe die Ursache gefunden. Es sind Datensätze vorhanden die Steuerzeichen enthalten die wahrscheinlich die DB stören:
325224 => 2018-10-09 22:48:12|Thermostat.WZ1|MAX|desiredTemperature: 10.0|desiredTemperature|10.0|�C
325225 => 2018-10-09 22:48:12|Thermostat.WZ1|MAX|valveposition: 0|valveposition|0|%
325226 => 2018-10-09 22:48:12|Thermostate|STRUCTURE|state: undefined|state|undefined|
325227 => 2018-10-09 22:48:12|Thermostate.WZ|STRUCTURE|state: 10.0 °C|state|10.0 °C|
325228 => 2018-10-09 22:48:12|Thermostate|STRUCTURE|state: undefined|state|undefined|
325229 => 2018-10-09 22:48:12|Thermostate.WZ|STRUCTURE|state: 10.0 °C|state|10.0 °C|
Die Thermostate in STRUCTURE haben als Einheit °C, aber die MAX �C.
Du kannst jetzt so vorgehen:
1. setzte das Attribut useCharfilter = 1
2. führe einen Cacheexport mit Purge aus: set ... exportCache purgecache
Wenn das geklappt hat schauen wir weiter.
Es sieht so aus, dass jetzt erstmal Ruhe ist.
Keine weiteren Fehlermeldungen. Die letzte war vor einer halben Stunde. Ungefähr seit dem ich das Charfilter Attribut gesetzt habe und der Cacheexport aktiv ist.
Im listCache sehe ich zwar noch die Steuerzeichen aber vermutlich werden die dann erst bei der Übertragung gefiltert?
45228 => 2018-10-09 23:47:19|Thermostat.Bad|MAX|desiredTemperature: 30.0|desiredTemperature|30.0|�C
45229 => 2018-10-09 23:47:19|Thermostat.Bad|MAX|temperature: 23.3|temperature|23.3|�C
45230 => 2018-10-09 23:47:19|Thermostat.Bad|MAX|valveposition: 91|valveposition|91|%
45231 => 2018-10-09 23:47:19|Thermostate|STRUCTURE|state: undefined|state|undefined|
45232 => 2018-10-09 23:47:19|Thermostate|STRUCTURE|state: undefined|state|undefined|
45233 => 2018-10-09 23:47:19|Thermostat.WZ2|MAX|mode: manual|mode|manual|
Wenn es jetzt wirklich die Steuerzeichen waren, wundert mich aber trotzdem etwas, dass ihm das so plötzlich auf die Füße fällt.
Und dann kann man ja auch eigentlich noch sagen, dass in dem speziellen Fall die Einheit zu der Temperatur halbwegs unwichtig ist, da ich die Einheiten nirgends verwende.
Naja es war jetzt eine Vermutung von mir. Möglicherweise haben die sich auch als nicht druckbare Zeichen versteckt.
Aber wir sind noch nicht ganz fertig. ;)
Das Charfilter Attribut lässt du am besten erstmal gesetzt. Das schützt in solchen Fällen.
Der Cache müßte sich jetzt wieder ordentlich leeren, richtig ?
Jetzt kannst du das exportierte Cachefile wieder importieren mit "set ... importCachefile".
Du bekommst eine Drop-Down Liste angezeigt mit dem exportfile. Das importierst du einfach. Dann sind deine Daten nicht verloren.
Wenn meine Vermutung richtig war, sollte der Import jetzt problemlos laufen weil störende Steuerzeichen mit dem Attr rausgefiltert werden.
Die Zeichen �C können auch nur US7ASCII sein, wurdert mich aber trotzdem.
Mach das erstmal. Dann können wir nochmal darüber nachdenken wieso das nun plötzlich aufgetreten ist.
Also nachdem das ja gestern lief, ging ich davon aus, dass erstmal alles in Ordnung ist.
Weil mich die ständig ratternden Festplatten der Synology genervt haben (was so nicht üblich ist), hab ich das commitMode Attribut wieder entfernt.
Danach war Ruhe.
Was mir jetzt nach der Arbeit aber erst auffiel ist, dass es ohne commitMode=basic_ta:off nicht funktioniert.
Also wieder aktiviert und dann hat er jetzt erstmal alle Cache Einträge wieder übertragen. Deswegen würde ich jetzt mal vaga behaupten, am Charfilter lag es nicht. Aber vermutlich seid ihr da die besseren Experten.
ZitatWas mir jetzt nach der Arbeit aber erst auffiel ist, dass es ohne commitMode=basic_ta:off nicht funktioniert.
Dieses Attribut hilft allerdings nur die Wirkung zu beseitigen und nicht die Ursache selbst.
ZitatAlso wieder aktiviert und dann hat er jetzt erstmal alle Cache Einträge wieder übertragen.
Hattest du gestern noch das Cachefile importiert und hat das geklappt ?
Wird wirklich der gesamte Cache auf 0 geleert oder bleiben alte Datensätze enthalten ?
Wie sieht denn der Cachinhalt aus, kurz (ca. 1Min.) nachdem du "commitMode=basic_ta:off" gelöscht hast ?
Das Cache-File wurde importiert, ohne Probleme.
Und wenn ich jetzt nach dem setzen des commitMode in den Cache schaue, wird der auch abgebaut.
Heute ist es allerdings so, dass sich nach ein paar Minuten immer mal wieder 1-2000 Meldungen aufstauen, die dann nicht wie geplant nach 2min in der Datenbank gespeichert werden, sondern vielleicht erst nach 5-10min.
Also der Datenbank-Output ist entweder langsam oder vorrübergehend gar nicht möglich.
Das sieht mir auch nach Performance-Problem aus.
Setze dir im DbLog noch die Attribute
showproctime = 1
showNotifyTime = 1
cacheEvents = 2
Das hilft uns bessere Aussagen darüber zu treffen. Bei so vielen Meldungen ist es aber auch nicht einfach den "Schuldigen" zu finden.
Aber ich bin immer noch der Überzeugung dass es ein bestimmter Event ist der die Probleme verursacht. Auch wenn es vllt. nicht der MAX ist.
Hier mit den neuen Attributen nochmal die Internals und Readings:
Internals:
COLUMNS field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32
CONFIGURATION ./db.conf
DEF ./db.conf .*:.*
MODE asynchronous
MODEL MYSQL
NAME Logdb
NR 17
NTFY_ORDER 50-Logdb
PID 23112
REGEXP .*:.*
STATE Commit already running - resync at NextSync
TYPE DbLog
UTF8 1
VERSION 3.12.2
dbconn mysql:database=fhem;host=diskstation;port=3307
dbuser fhemuser
HELPER:
COLSET 1
DEVICECOL 64
EVENTCOL 512
LASTLIMITRUNTIME 1539190439.75544
OLDSTATE Commit already running - resync at NextSync
READINGCOL 64
TYPECOL 64
UNITCOL 32
VALUECOL 128
READINGS:
2018-10-10 18:57:29 CacheUsage 81
2018-10-10 18:57:29 NextSync 2018-10-10 18:57:59 or if CacheUsage 500 reached
2018-10-10 18:53:57 background_processing_time 446.4368
2018-10-10 00:04:16 lastCachefile ./log/cache_Logdb_2018-10-09_23-18-11 import successful
2018-10-10 18:57:21 notify_processing_time 0.0097
2018-10-10 03:02:03 reduceLogState reduceLogNbl finished. Rows processed: 264204, deleted: 26997, updated: 556, time: 123.00sec
2018-10-10 18:53:57 sql_processing_time 445.7042
2018-10-10 18:57:29 state Commit already running - resync at NextSync
cache:
index 5663566
Attributes:
DbLogExclude .*
DbLogSelectionMode Exclude/Include
DbLogType Current/History
asyncMode 1
cacheEvents 2
commitMode basic_ta:off
room Logs
showNotifyTime 1
showproctime 1
shutdownWait 2
useCharfilter 1
Zwischenzeitlich übrigens Caches bis 13/14.000
Ziemlich eindeutig
sql_processing_time -> 445.7042
Heißt, deine DB braucht 445 Sekunden um die, sagen wir 2000 Datensätze wegzuschreiben.
Die kommt schlicht nicht mehr hinterher.
Frage ist natürlich warum ?
Hast du auf Syno neue Pakete installiert die die DB nutzen / verlangsamen ?
Bin mir noch unsicher, aber du könntest versuchen mal auf den Synchmode umzuschalten. Aber sei vorsichtig, es kann passieren dass dein FHEM dann nicht mehr reagiert weil deine DB nicht so reagiert wie sie soll.
das ist es eben, ich hab eigentlich gar nichts gemacht in den letzten Tagen.
Weder Updates, noch neue Pakete installiert.
Ich überlege, einfach mal den Ort der Datenbank zu meinem Web-Anbieter all-inkl. zu wechseln.
Allerdings will ich das eigentlich nicht dauerthaft.
Auf dem RasPi wollte ich die Datenbank eigentlich auch nicht mehr haben, um etwas mehr Datensicherheit und gleichzeitig aber auch um mehr Performance zu haben.
Wenn ich die Möglichkeit hätte, würde ich die Datenbank in einen Docker auf der Synology selbst zu installieren. Aber meine ist nicht Docker-fähig.
Ich hab über HeidiSQL auch schon nen Datenbank Repair und nen Optimizing probiert - ohne Erfolg.
Die DB läuft auf der Syno normalerweise auch einwandfrei, habe ich auch so. Du warst bisher ja auch glücklich, nur irgendwas spuckt gerade etwas in die Suppe.
Wenn so viele Events in so kurzer Zeit auflaufen werden die fehlerhaften Sätze wahrschein kumuliert.
Versuche mal verbose 4 im Dblog einzuschalten und den Output zu posten.
Leider habe ich heute nicht mehr so viel Zeit, vllt. später wieder.
Ich fasse mal die letzten Änderungen der letzten Wochen zusammen:
Ich habe mir einen holiday Plan "brandenburg" angelegt, um Feiertage in die $we Variable rein zu bekommen.
Das habe ich dann in meinen Heating_Controll Devices eingeplant. Da steht jetzt also statt 06|Uhrzeit|Temp => $we|Uhrzeit|Temp.
Und mit erstaunen stelle ich fest, dass es das auch schon war. Außerdem ist mit einem der letzten Updates noch die neue UI hinzugekommen und damit ein paar optische Anpassungen der Web-Oberfläche.
Ich hatte erst gedacht, vielleicht habe ich irgendwo ein DbLogExclud vergessen. Dem ist aber nicht so. Ich hab die wöchentlichen Backups der letzten Wochen vergleichen. Die sind bis auf die genannten Änderungen identsich.
Als nächstes hab ich mit DbRep mal einen 15min Datensatz aus der Datenbank gezählt und in csv exportiert. Je einmal mit Daten von vor einem Monat und von heute. Es sind ungefähr 3x so viele Daten, die in 15min angefallen sind. Zum einen 326 und zum anderen 1077.
Und beim Durchsehen der einzelnen Devices, die ich mir in Excel dann gefiltert habe, fällt mir auf, dass pro Zeitstempel z.T. bis zu 5x das gleiche Event mit den gleichen Werten gespeichert wurde. Wenn dann z.B. bis zu 6 verschiedenen Events gespeichert werden und die jeweils dann 5x, dann sind das schon 30 Logs.
Üblicherweise habe ich bei meinen Devices aber ein event-min-interval von 90 oder 120sek. Der wird zwar eingehalten aber es werden eben mehr Daten geschrieben.
Von vorgestern hab ich auch noch einen csv-Datensatz gezogen. Da bestand das Problem noch nicht. Da gibt es auch noch keine multible Datenhaltung.
Hier noch der Log-Output mit verbose=4
2018.10.10 22:29:09 2: DbLog Logdb -> Error table history - DBD::mysql::st execute_array failed: executing 17227 generated 1408 errors at ./FHEM/93_DbLog.pm line 2063.
2018.10.10 22:34:31 4: DbLog Logdb -> ################################################################
2018.10.10 22:34:31 4: DbLog Logdb -> ### start of new Logcycle ###
2018.10.10 22:34:31 4: DbLog Logdb -> ################################################################
2018.10.10 22:34:31 4: DbLog Logdb -> number of events received: 1 for device: mqtt
2018.10.10 22:34:31 4: DbLog Logdb -> check Device: mqtt , Event: connection: active
2018.10.10 22:34:37 4: DbLog Logdb -> ################################################################
2018.10.10 22:34:37 4: DbLog Logdb -> ### start of new Logcycle ###
2018.10.10 22:34:37 4: DbLog Logdb -> ################################################################
2018.10.10 22:34:37 4: DbLog Logdb -> number of events received: 4 for device: Thermometer.Bad
2018.10.10 22:34:37 4: DbLog Logdb -> check Device: Thermometer.Bad , Event: battery: ok
2018.10.10 22:34:37 4: DbLog Logdb -> check Device: Thermometer.Bad , Event: temperature: 22.6
2018.10.10 22:34:37 4: DbLog Logdb -> added event - Timestamp: 2018-10-10 22:34:37, Device: Thermometer.Bad, Type: LACROSSE, Event: temperature: 22.6, Reading: temperature, Value: 22.6, Unit: °C
2018.10.10 22:34:37 4: DbLog Logdb -> Number of cache entries reached cachelimit 500 - start database sync.
2018.10.10 22:34:37 4: DbLog Logdb -> ################################################################
2018.10.10 22:34:37 4: DbLog Logdb -> ### start of new Logcycle ###
2018.10.10 22:34:37 4: DbLog Logdb -> ################################################################
2018.10.10 22:34:37 4: DbLog Logdb -> number of events received: 1 for device: Logdb
2018.10.10 22:34:37 4: DbLog Logdb -> check Device: Logdb , Event: CacheUsage: 17382
2018.10.10 22:34:37 4: DbLog Logdb -> ################################################################
2018.10.10 22:34:37 4: DbLog Logdb -> ### New database processing cycle - asynchronous ###
2018.10.10 22:34:37 4: DbLog Logdb -> ################################################################
2018.10.10 22:34:37 4: DbLog Logdb -> MemCache contains 17382 entries to process
2018.10.10 22:34:37 4: DbLog Logdb -> DbLogType is: Current/History
2018.10.10 22:34:38 4: DbLog Logdb -> AutoCommit mode: ON, Transaction mode: OFF
2018.10.10 22:39:45 2: DbLog Logdb -> Error table history - DBD::mysql::st execute_array failed: executing 17382 generated 1427 errors at ./FHEM/93_DbLog.pm line 2063.
2018.10.10 22:45:14 4: DbLog Logdb -> ################################################################
2018.10.10 22:45:14 4: DbLog Logdb -> ### start of new Logcycle ###
2018.10.10 22:45:14 4: DbLog Logdb -> ################################################################
2018.10.10 22:45:14 4: DbLog Logdb -> number of events received: 8 for device: PID.Bad
2018.10.10 22:45:14 4: DbLog Logdb -> check Device: PID.Bad , Event: desired: 24.0
2018.10.10 22:45:14 4: DbLog Logdb -> added event - Timestamp: 2018-10-10 22:45:14, Device: PID.Bad, Type: PID20, Event: desired: 24.0, Reading: desired, Value: 24.0, Unit:
2018.10.10 22:45:14 4: DbLog Logdb -> Number of cache entries reached cachelimit 500 - start database sync.
2018.10.10 22:45:14 4: DbLog Logdb -> ################################################################
2018.10.10 22:45:14 4: DbLog Logdb -> ### start of new Logcycle ###
2018.10.10 22:45:14 4: DbLog Logdb -> ################################################################
2018.10.10 22:45:14 4: DbLog Logdb -> number of events received: 1 for device: Logdb
2018.10.10 22:45:14 4: DbLog Logdb -> check Device: Logdb , Event: CacheUsage: 17518
2018.10.10 22:45:14 4: DbLog Logdb -> ################################################################
2018.10.10 22:45:14 4: DbLog Logdb -> ### New database processing cycle - asynchronous ###
2018.10.10 22:45:14 4: DbLog Logdb -> ################################################################
2018.10.10 22:45:14 4: DbLog Logdb -> MemCache contains 17518 entries to process
2018.10.10 22:45:14 4: DbLog Logdb -> DbLogType is: Current/History
2018.10.10 22:45:14 4: DbLog Logdb -> AutoCommit mode: ON, Transaction mode: OFF
ZitatUnd mit erstaunen stelle ich fest, dass es das auch schon war.
Du meinst der Grund für das Problem ?
ZitatVon vorgestern hab ich auch noch einen csv-Datensatz gezogen. Da bestand das Problem noch nicht. Da gibt es auch noch keine multible Datenhaltung.
Das mehrfache Speichern eines Datensatzes kann eine Nebenwirkung mit der speziellen Einstellung "commitMode=basic_ta:off" sein.
In diesem Support-Mode werden trotz fehlerhafter Datensätze die nicht fehlerhaften in der DB gespeichert (sonst nicht wegen des Transaktionsmodus). Dennoch wird das übergebene Array zurück geführt.
Das Verhalten ist nicht gewünscht und habe es korrigiert. Du kannst die Version von DbLog hier herunter laden:
https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter
Lade dir mal bitte die Version mit dem Download-Button auf der Seite nach ./FHEM und "reload 93_DbLog".
Wie gesagt, es korrigiert nur das beschriebene Verhalten für die spezielle commitMode-Einstellung die man ja nur im Supportfall einschalten soll.
Ganz nebenbei der Hinweis, dass man generell doppelte Datensätze in der DB verhindern kann indem man einen Primary Key (PK) setzt. DbLog unterstützt einen solchen Key. Aber das hat nichts mit dem Problem an sich zu tun.
ok, jetzt rödelt die Synology schonmal deutlich weniger.
Die Processing_times sind auch deutlich zurück gegangen:
READINGS:
2018-10-10 23:07:54 CacheUsage 0
2018-10-10 23:07:53 NextSync 2018-10-10 23:08:23 or if CacheUsage 500 reached
2018-10-10 23:07:54 background_processing_time 0.3661
2018-10-10 00:04:16 lastCachefile ./log/cache_Logdb_2018-10-09_23-18-11 import successful
2018-10-10 23:07:36 notify_processing_time 0.0058
2018-10-10 03:02:03 reduceLogState reduceLogNbl finished. Rows processed: 264204, deleted: 26997, updated: 556, time: 123.00sec
2018-10-10 23:07:54 sql_processing_time 0.3378
2018-10-10 23:07:54 state connected
cache:
index 137
Der Fehler besteht aber noch :P
2018.10.10 23:06:53 2: DbLog Logdb -> Error table history - DBD::mysql::st execute_array failed: executing 11 generated 3 errors at ./FHEM/93_DbLog.pm line 2065.
Ja, aber mit 11 zu prozessierenden DAtensätzen kann man noch umgehen. ;-)
Die DbLog Version ist drin und "commitMode=basic_ta:off" gesetzt ?
Aber ich muss für heute Schluss machen, muß morgen früh raus.
Kannst ja noch etwas forschen. Stell mal bitte verbose 5 im dblog ein und poste dann einen Ausschnitt von einem "New database processing cycle - asynchronous" komplett.
Schaue ich morgen an ...
Grüße
Heiko
Zitat von: DS_Starter am 10 Oktober 2018, 23:13:32
Die DbLog Version ist drin und "commitMode=basic_ta:off" gesetzt ?
Jo, commitMode gesetzt und die neue DbLog Version ist auch installiert. Ich denke die neue Version ist der ausschlaggebende Punkt, dass er nicht mehr so viele Daten verarbeiten muss :-)
Zitat von: DS_Starter am 10 Oktober 2018, 23:18:21
Aber ich muss für heute Schluss machen, muß morgen früh raus.
Kannst ja noch etwas forschen. Stell mal bitte verbose 5 im dblog ein und poste dann einen Ausschnitt von einem "New database processing cycle - asynchronous" komplett.
Schaue ich morgen an ...
Grüße
Heiko
Kein Problem. Ich mach dann jetzt auch gleich Schluss für heute.
Der processing cycle ist anbei.
In diesem Sinne gute Nacht und vielen vielen Dank für die Hilfe!
Der Logausschnitt ist genau der richtige. Aber leider zu kurz. Das war wie im Film ... gerade als es spannend wurde kam die Werbung bzw. hier das Ende ;)
Kannst du das bitte nochmal machen ?
Bei mir tritt genau der gleiche Fehler auf:
DbLog myDbLog -> Error table history - DBD::mysql::st execute_array failed: executing 1018 generated 3 errors at ./FHEM/93_DbLog.pm line 2063.
Der Fehler tauchte heute Nacht zuerst vereinzelt auf - jetzt jedesmal beim Schreiben in die Datenbank.
Interessanterweise taucht das Problem bei einem zweiten FHEM-System, das an der gleichen Datenbank hängt, nicht auf. Beide Systeme sind auf den neuesten Stand (Revision: 17502)
Hier nochmal in lang.
Diese Error table history Meldungen sind heute den ganzen Tag gelaufen, im Abstand von 2min.
Ich hab ein Device zum reconnecten der Datenbank, alle 30min. Falls ich das vorübergehend abschalten soll, geb Bescheid.
ZitatInteressanterweise taucht das Problem bei einem zweiten FHEM-System, das an der gleichen Datenbank hängt, nicht auf. Beide Systeme sind auf den neuesten Stand (Revision: 17502)
Ja, die Problematik hat ja vordergründig auch nichts mit dem Modul zu tun. Es ist herauszufinden welcher Event bzw. Datensatz der in die DB geschrieben werden soll den Ärger verursacht.
Schau dir mal an wie ich zusammen mit Bond246 vorgegangen bin um das Problem einzugrenzen.
Das Modul aus contrib zusammen mit dem gesetzten Attribut "commitMode=basic_ta:off" hilft dabei.
Dann verbose 5 setzen und einen möglichst langen Ausschnitt 2-3 "New database processing cycle - asynchronous" Abschnitten posten.
Grüße
Heiko
Hallo Bond,
jetzt ist das Problem sehr gut sichtbar.
Das Problem tritt nur auf, wenn "Thermostat.Bad" Datensätze der Art:
processing event Timestamp: 2018-10-10 23:24:31, Device: Thermostat.WZ1, Type: MAX, Event: desiredTemperature: 10.0, Reading: desiredTemperature, Value: 10.0, Unit: у
gespeichert werden sollen. Hier siehst du es komplett. Du musst nur die Anzahl der gemeldeten Fehler aus "executing 12 generated 4 errors" vergleichen mit der Anzahl der verdächtigen Datensätze die gespeichert werden sollen.
2018.10.10 23:24:54 4: DbLog Logdb -> ################################################################
2018.10.10 23:24:54 4: DbLog Logdb -> ### New database processing cycle - asynchronous ###
2018.10.10 23:24:54 4: DbLog Logdb -> ################################################################
2018.10.10 23:24:54 4: DbLog Logdb -> MemCache contains 12 entries to process
2018.10.10 23:24:54 4: DbLog Logdb -> DbLogType is: Current/History
2018.10.10 23:24:54 5: DbLog Logdb -> MemCache contains: 2018-10-10 23:24:31|Thermostat.Bad|MAX|mode: manual|mode|manual|
2018.10.10 23:24:54 5: DbLog Logdb -> MemCache contains: 2018-10-10 23:24:31|Thermostat.Bad|MAX|desiredTemperature: 30.0|desiredTemperature|30.0|у
2018.10.10 23:24:54 5: DbLog Logdb -> MemCache contains: 2018-10-10 23:24:31|Thermostat.Bad|MAX|temperature: 23.2|temperature|23.2|у
2018.10.10 23:24:54 5: DbLog Logdb -> MemCache contains: 2018-10-10 23:24:31|Thermostat.Bad|MAX|valveposition: 100|valveposition|100|%
2018.10.10 23:24:54 5: DbLog Logdb -> MemCache contains: 2018-10-10 23:24:31|Thermostat.WZ2|MAX|mode: manual|mode|manual|
2018.10.10 23:24:54 5: DbLog Logdb -> MemCache contains: 2018-10-10 23:24:31|Thermostat.WZ2|MAX|desiredTemperature: 10.0|desiredTemperature|10.0|у
2018.10.10 23:24:54 5: DbLog Logdb -> MemCache contains: 2018-10-10 23:24:31|Thermostat.WZ2|MAX|valveposition: 0|valveposition|0|%
2018.10.10 23:24:54 5: DbLog Logdb -> MemCache contains: 2018-10-10 23:24:31|Thermostat.WZ1|MAX|mode: manual|mode|manual|
2018.10.10 23:24:54 5: DbLog Logdb -> MemCache contains: 2018-10-10 23:24:31|Thermostat.WZ1|MAX|desiredTemperature: 10.0|desiredTemperature|10.0|у
2018.10.10 23:24:54 5: DbLog Logdb -> MemCache contains: 2018-10-10 23:24:31|Thermostat.WZ1|MAX|valveposition: 0|valveposition|0|%
2018.10.10 23:24:54 5: DbLog Logdb -> MemCache contains: 2018-10-10 23:24:38|Thermometer.WZ|LACROSSE|temperature: 22.8|temperature|22.8|°C
2018.10.10 23:24:54 5: DbLog Logdb -> MemCache contains: 2018-10-10 23:24:38|Thermometer.WZ|LACROSSE|humidity: 49|humidity|49|%
2018.10.10 23:24:54 5: DbLog Logdb -> DbLog_PushAsync called with timeout: 86400
2018.10.10 23:24:54 5: DbLog Logdb -> Start DbLog_PushAsync
2018.10.10 23:24:54 5: DbLog Logdb -> DbLogType is: Current/History
2018.10.10 23:24:54 4: DbLog Logdb -> AutoCommit mode: ON, Transaction mode: OFF
2018.10.10 23:24:54 5: DbLog Logdb -> Primary Key used in fhem.history: none
2018.10.10 23:24:54 5: DbLog Logdb -> Primary Key used in fhem.current: none
2018.10.10 23:24:54 5: DbLog Logdb -> processing event Timestamp: 2018-10-10 23:24:31, Device: Thermostat.Bad, Type: MAX, Event: mode: manual, Reading: mode, Value: manual, Unit:
2018.10.10 23:24:54 5: DbLog Logdb -> processing event Timestamp: 2018-10-10 23:24:31, Device: Thermostat.Bad, Type: MAX, Event: desiredTemperature: 30.0, Reading: desiredTemperature, Value: 30.0, Unit: у
2018.10.10 23:24:54 5: DbLog Logdb -> processing event Timestamp: 2018-10-10 23:24:31, Device: Thermostat.Bad, Type: MAX, Event: temperature: 23.2, Reading: temperature, Value: 23.2, Unit: у
2018.10.10 23:24:54 5: DbLog Logdb -> processing event Timestamp: 2018-10-10 23:24:31, Device: Thermostat.Bad, Type: MAX, Event: valveposition: 100, Reading: valveposition, Value: 100, Unit: %
2018.10.10 23:24:54 5: DbLog Logdb -> processing event Timestamp: 2018-10-10 23:24:31, Device: Thermostat.WZ2, Type: MAX, Event: mode: manual, Reading: mode, Value: manual, Unit:
2018.10.10 23:24:54 5: DbLog Logdb -> processing event Timestamp: 2018-10-10 23:24:31, Device: Thermostat.WZ2, Type: MAX, Event: desiredTemperature: 10.0, Reading: desiredTemperature, Value: 10.0, Unit: у
2018.10.10 23:24:54 5: DbLog Logdb -> processing event Timestamp: 2018-10-10 23:24:31, Device: Thermostat.WZ2, Type: MAX, Event: valveposition: 0, Reading: valveposition, Value: 0, Unit: %
2018.10.10 23:24:54 5: DbLog Logdb -> processing event Timestamp: 2018-10-10 23:24:31, Device: Thermostat.WZ1, Type: MAX, Event: mode: manual, Reading: mode, Value: manual, Unit:
2018.10.10 23:24:54 5: DbLog Logdb -> processing event Timestamp: 2018-10-10 23:24:31, Device: Thermostat.WZ1, Type: MAX, Event: desiredTemperature: 10.0, Reading: desiredTemperature, Value: 10.0, Unit: у
2018.10.10 23:24:54 5: DbLog Logdb -> processing event Timestamp: 2018-10-10 23:24:31, Device: Thermostat.WZ1, Type: MAX, Event: valveposition: 0, Reading: valveposition, Value: 0, Unit: %
2018.10.10 23:24:54 5: DbLog Logdb -> processing event Timestamp: 2018-10-10 23:24:38, Device: Thermometer.WZ, Type: LACROSSE, Event: temperature: 22.8, Reading: temperature, Value: 22.8, Unit: °C
2018.10.10 23:24:54 5: DbLog Logdb -> processing event Timestamp: 2018-10-10 23:24:38, Device: Thermometer.WZ, Type: LACROSSE, Event: humidity: 49, Reading: humidity, Value: 49, Unit: %
2018.10.10 23:24:54 2: DbLog Logdb -> Error table history - DBD::mysql::st execute_array failed: executing 12 generated 4 errors at ./FHEM/93_DbLog.pm line 2065.
2018.10.10 23:24:55 5: DbLog Logdb -> DbLog_PushAsync finished
2018.10.10 23:24:55 5: DbLog Logdb -> Start DbLog_PushAsyncDone
2018.10.10 23:24:55 5: DbLog Logdb -> DbLog_PushAsyncDone finished
In Speicherzyklen, in denen es diese Datensätze nicht gibt, gibt es keinen Fehler.
Das "Unit: у" ist das Problem, wobei "y" mit Sicherheit nicht der Buchstabe "y" ist. Wir müssten uns mal das Device Thermostat.Bad bzw. alle MAX genauer ansehen und im ersten Schritt das Reading desiredTemperature vom Logging ausschließen.
Dann schauen wir ob der Fehler weg ist. (Ich wette einen guten Schluck schottischen Single Malt darauf :D )
Alles klar,
ich hab von Thermostat.Bad "desiredTemperature" von DbLogInclude ausgenommen.
Hier jetzt die aktuellen Internals
Internals:
CHANGED
DEF HeatingThermostat 16639a
IODev MAXcube
LASTInputDev MAXcube
MAXcube_MSGCNT 1330
MAXcube_TIME 2018-10-11 20:01:56
MSGCNT 1330
NAME Thermostat.Bad
NR 67
STATE <strong>22.3°C</strong> [0%]
TYPE MAX
addr 16639a
backend MAXcube
dstsetting 1
mode 1
rferror 0
serial NEQ0932394
type HeatingThermostat
Helper:
DBLOG:
battery:
Logdb:
TIME 1539277613.45452
VALUE ok
desiredTemperature:
Logdb:
TIME 1539280736.97231
VALUE 30.0
mode:
Logdb:
TIME 1539280916.98017
VALUE manual
temperature:
Logdb:
TIME 1539278755.69801
VALUE 22.3
valveposition:
Logdb:
TIME 1539280797.07467
VALUE 0
READINGS:
2018-10-11 20:01:57 MAXLAN_error 0
2018-10-11 20:01:57 MAXLAN_errorInCommand
2018-10-11 20:01:57 MAXLAN_initialized 1
2018-10-11 20:01:57 MAXLAN_isAnswer 0
2018-10-11 20:01:57 MAXLAN_valid 1
2018-10-11 20:01:56 battery ok
2018-10-11 20:01:56 batteryState ok
2018-10-10 22:59:23 boostDuration 10
2018-10-10 22:59:23 boostValveposition 80
2018-10-10 22:59:23 comfortTemperature 23.0
2018-10-10 22:59:23 decalcification Sat 12:00
2018-10-11 20:01:56 desiredTemperature 30.0
2018-10-10 22:59:23 ecoTemperature 18.0
2018-10-10 22:59:23 firmware 1.0
2018-10-10 22:59:23 groupid 0
2018-10-11 19:38:51 maxValveSetting 0
2018-10-10 22:59:23 maximumTemperature 30.0
2018-10-10 22:59:23 measurementOffset 0.0
2018-10-10 22:59:23 minimumTemperature 10.0
2018-10-11 20:01:56 mode manual
2018-10-11 20:01:56 state 30.0 °C
2018-10-11 19:25:55 temperature 22.3
2018-10-10 22:59:23 testresult 161
2018-10-10 22:59:23 valveOffset 0
2018-10-11 20:01:56 valveposition 0
2018-10-10 22:59:23 weekprofile-0-Sat-temp 4.5 °C / 4.5 °C
2018-10-10 22:59:23 weekprofile-0-Sat-time 00:00-23:55 / 23:55-00:00
2018-10-10 22:59:23 weekprofile-1-Sun-temp 4.5 °C / 4.5 °C
2018-10-10 22:59:23 weekprofile-1-Sun-time 00:00-23:55 / 23:55-00:00
2018-10-10 22:59:23 weekprofile-2-Mon-temp 4.5 °C / 4.5 °C
2018-10-10 22:59:23 weekprofile-2-Mon-time 00:00-23:55 / 23:55-00:00
2018-10-10 22:59:23 weekprofile-3-Tue-temp 4.5 °C / 4.5 °C
2018-10-10 22:59:23 weekprofile-3-Tue-time 00:00-23:55 / 23:55-00:00
2018-10-10 22:59:23 weekprofile-4-Wed-temp 4.5 °C / 4.5 °C
2018-10-10 22:59:23 weekprofile-4-Wed-time 00:00-23:55 / 23:55-00:00
2018-10-10 22:59:23 weekprofile-5-Thu-temp 4.5 °C / 4.5 °C
2018-10-10 22:59:23 weekprofile-5-Thu-time 00:00-23:55 / 23:55-00:00
2018-10-10 22:59:23 weekprofile-6-Fri-temp 4.5 °C / 4.5 °C
2018-10-10 22:59:23 weekprofile-6-Fri-time 00:00-23:55 / 23:55-00:00
2018-10-10 22:59:23 windowOpenDuration 15
2018-10-10 22:59:23 windowOpenTemperature 16.0
internals:
interfaces thermostat;battery;temperature
Attributes:
DbLogExclude .*
DbLogInclude mode,temperature,valveposition,battery:3600
Heizungen Thermostate
IODev MAXcube
alias Bad Thermo
event-min-interval .*:120
event-on-change-reading .*
icon max_heizungsthermostat
room hidden
stateFormat <strong>temperature°C</strong> [valveposition%]
userattr Heizungen Heizungen_map structexclude
verbose 2
webCmd desiredTemperature
Die Frage ist sowieso, ob ich das loggen muss. Ich habs noch drin aber eigentlich sind die Thermostate im winter auf 30°C (im Sommer auf 10°C) und dann steuere ich sie komplett über PID20.
Beim Thermostat.WZ1 / Thermostat.WZ2 müsstest du das auch noch tun soweit ich das sehe.
Wie sieht es dann mit unserem Fehler im Logging aus ?
Logging ist seit dem still.
WZ1 und WZ2 hab ich auch angepasst, richtig.
Problem erkannt und gebannt würde ich sagen :)
Das Attribut comitMode kannst du auch wieder löschen.
Was ich aber nicht beantworten kann ist, wieso diese Problematik so plötzlich aus heiterem Himmel ohne erkennbare Änderungen
aufgetreten ist. Vielleicht fällt dir noch etwas dazu ein ....
Die abgeänderte DbLog-Version nehme ich ins Repository auf. Das geänderte commitMode hilft jetzt mehr.
Grüße
Heiko
ZitatWas ich aber nicht beantworten kann ist, wieso diese Problematik so plötzlich aus heiterem Himmel ohne erkennbare Änderungen
aufgetreten ist.
Das frage ich mich auch. Ich habe seit Monaten an dem betroffenen FHEM-System nichts verändert (außer regelmäßigen Updates).
@JWRu, hast du inzwischen etwas bei dir herausbekommen bzgl. verdächtigen Datensätzen ?
Ich habe erst morgen Zeit (und Lust), mich um die Sache zu kümmern.
Ich muss offenbar auch noch die "temperature" rausnehmen. Der Wert verursacht auch noch einen Fehler, wenn ich das richtig sehe.
Problem ist bei MAX, dass der aktuelle Temperatur-Sensor-Wert nicht immer übertragen wird, deswegen tauchte das vermutlich erst jetzt auf.
Der Wert ist zumindest heute auch noch nicht 1x in die Datenbank geschrieben worden.
Noch eine andere Geschichte, die Doubletten von gestern kann ich ja mit "delSeqDoublets" in einem DbRep entfernen. Ich hoffe einfach mal, dass das gut geht.
Aber wie kann ich den Primary Key erstellen. Der muss doch in die history-Datenbank für DEVICE und READING, richtig?
Wenn ich das in HeidiSQL probiere bekomme ich folgende Meldung:
SQL Fehler (1062): Dublicate Entry 'Thermometer.Bad-battery' for key 'PRIMARY'
Die einzige Veränderung (außer den FHEM-Updates), die mir einfällt, ist ein Update von MariaDB auf der Synology gestern Vormittag.
ZitatIch muss offenbar auch noch die "temperature" rausnehmen.
Ja, wahrscheinlich. Ich habe inzwischen mal in das Max-Modul (10_MAX.pm) geschaut. Dort gibt es eine MAX_DbLog_splitFn die allen Readings in den Max-Devices die "temp" enthalten die Unit "\xB0C" zuweist. Es müßte meiner Meinung nach einfach in "°C" geändert werden. Allerdings ist das Modul auch das letzte Mal im Juni geändert worden was ebenfalls nicht die Frage beantwortet wieso es jetzt plötzlich auftritt.
ZitatNoch eine andere Geschichte, die Doubletten von gestern kann ich ja mit "delSeqDoublets" in einem DbRep entfernen. Ich hoffe einfach mal, dass das gut geht.
Denk schon ...
ZitatAber wie kann ich den Primary Key erstellen. Der muss doch in die history-Datenbank für DEVICE und READING, richtig?
Wenn ich das in HeidiSQL probiere bekomme ich folgende Meldung:
Code: [Auswählen]
SQL Fehler (1062): Dublicate Entry 'Thermometer.Bad-battery' for key 'PRIMARY'
Das wird nicht so einfach wahrscheinlich. Ein PK lässt sich nicht anlegen wenn es bereits doppelte Datensätze in der DB gibt.
Aber du könnetst es mit diesem Statement versuchen:
ALTER IGNORE TABLE `history` ADD PRIMARY KEY(TIMESTAMP, DEVICE, READING);
Das ignore wäre der Schlüssel. Wenn das nicht klappt müsste man einen etwas aufwändigeren Weg gehen.
Wenn du das dann machen möchtest, bitte ich dich in diesem Thread eine Meldung zu öffnen um dort weiter zu machen:
https://forum.fhem.de/index.php/topic,65860.0.html
EDIT: wenn du "delSeqDoublets" ohne Einschränkungen über die ganze DB laufen lassen würdest, sollte es auch alle doppelte Sätze entfernen.
ZitatDie einzige Veränderung (außer den FHEM-Updates), die mir einfällt, ist ein Update von MariaDB auf der Synology gestern Vormittag.
Das ist sehr wahrscheinlich.
Wenn Bond246 das auch bestätigen könnte, wäre es ein weiteres Indiz dafür.
Zitat von: DS_Starter am 11 Oktober 2018, 22:21:35
Das ist sehr wahrscheinlich.
Wenn Bond246 das auch bestätigen könnte, wäre es eine Bestätigung.
Bei mir gibt und gab es keine mariadb updates in den letzten Tagen und Wochen auf der Syno.
Bei mir läuft Version 10.3.7-0051
Bei mir auch.
Das Update kam etwa Anfang September, wenn ich das richtig sehe.
Ich habe noch die 10.0.34. Aber habe gerade gesehen, dass bei mir auch ein Update auf die 10.3.7-0051 ansteht.
Nach meinem Urlaub nächste Woche werde ich auch mal an das Update gehen.
Allerdings habe ich keine MAX Geräte.
Ich habe auch keine MAX-Devices. An meinem FHEM hängen eine Viessmann-Heizung (VCONTROL), I2C, JeeLink, KeyValueProtocol und OWDevice.
ZitatIch habe auch keine MAX-Devices. An meinem FHEM hängen eine Viessmann-Heizung (VCONTROL), I2C, JeeLink, KeyValueProtocol und OWDevice.
Vielleicht hat eines von denen ein ähnlich gelagertes Problem mit der Grad-Einheit von Temperaturen. Müssen wir mal schauen.
Also ich würde mal gute Nacht sagen und wünsche allen die noch wach bleiben einen schönen Abend.
LG,
Heiko
Ich habe jetzt wohl die Übeltäter gefunden und drei Devices ausgeschlossen, bei denen "°C" als Unit auftauchte. Seitdem ist Ruhe.
In allen anderen Devices ist Unit leer.
Zwei Fragen sind bei mir aufgetaucht:
Wo kommt denn "Unit" her? Im list der Devices taucht nirgendwo was auf.
Wenn das "°" das Problem verursacht, warum wirkt dann useCharfilter nicht?
ZitatWo kommt denn "Unit" her? Im list der Devices taucht nirgendwo was auf.
Von welchem TYPE sind die devices ?
ZitatWenn das "°" das Problem verursacht, warum wirkt dann useCharfilter nicht?
Das "°" ist nicht unbedingt das Problem, weil das reine Zeichen "°" durchaus gespeichert wird -> siehe bei Bond funktioniert "°" auch. Es kann aber sein dass "°" in den Modulen anders codiert angehängt wird, was dann Probleme verursacht.
useCharfilter werde ich aber ergänzen und an einer etwas anderen Stelle im Modul platzieren um die Wirkung zu verbessern.
ZitatVon welchem TYPE sind die devices ?
OWDevice
Zitat
Von welchem TYPE sind die devices ?
OWDevice
In diesem Fall wird "°C" durch die Parsing-Funktion von DbLog selbst hinzugefügt.
Du kannst die Units "°C" generell wegschneiden mit dem Setzen des Attributes valueFn z.B. :
{
if ($UNIT eq "°C") {
$UNIT="";
}
}
Mit valueFn kann man sich selbst auch noch weitere Filter aufbauen -> commandRef.
Danke für den Tipp!
Ich habe übrigens von den OWDevices jeweils ein einzelnes Temperatur-Reading (ausgedünnt mit MinInterval) wieder hinzugefügt.
Bisher ist der Fehler trotzdem nicht wieder aufgetreten.
Zitat
Ich habe übrigens von den OWDevices jeweils ein einzelnes Temperatur-Reading (ausgedünnt mit MinInterval) wieder hinzugefügt.
Bisher ist der Fehler trotzdem nicht wieder aufgetreten.
Das ist interressant. Nichtsdestotrotz habe ich charFilter erweitert und im Coding besser platziert. Mit charFilter = 1 sollte Bond nun auch seine Temperaturfühler wieder loggen können und diese mit "°C" vorfinden.
Die neue Version habe ich erstmal nach contrib geladen:
https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter
Download per Button auf der Seite, restart und Attr charFilter = 1 setzen.
Grüße
Heiko
demnach machen bei mir LaCrosse Sensoren & Weather Underground Probleme:
2018.10.16 19:20:42 5: DbLog logdb -> MemCache contains: 2018-10-16 19:14:10|LaCrosse_15|LACROSSE|temperature: 20.7|temperature|20.7|°C
2018.10.16 19:20:42 5: DbLog logdb -> MemCache contains: 2018-10-16 19:09:01|WU_Stadt|WUNDERGROUND|feelslike_c: 21.1|feelslike_c|21.1|°C
Ich favorisiere bei dir ebenfalls die MAX, sieht man auch gut in deinem Log in dem anderen Thread.
Guten Morgen zusammen,
ich krame den ca. einen Jahr alten Thread mal aus und hänge mich hier dran. Gestern nachmittag hatte ich aus heiterem Himmel auf einmal auch das hier beschriebene Fehlerbild. Ich konnte die Störung zunächst mit dem commitMode basic_ta:off augenscheinlich lösen.
Ich habe mir mit einem set DbLog exportCache den Cache-Inhalt exportiert, in Excel importiert (mittlerweile über 32000 Zeilen) und sodann nach Zeit sortiert. Ich konnte relativ schnell ein Device ausmachen (Telegrambot), in dem sehr komische Sonderzeichen gespeichert waren.
Da ich grundsätzlich alles in die Datenbank logge, habe ich nun in dem betreffenden Device die entsprechenden Readings per DbLogExclude vom Logging ausgeschlossen und hoffe nun, dass ich damit auch die Ursache finden und beheben konnte.
Im DbLog-Device habe ich das Attribut commitMode nach den Maßnahmen wieder gelöscht.
Meine SQL-Server-Version auf der Syno ist aktuell übrigens MariaDB 10.3.11-0054
Hallo Ralli,
dein Lösungsansatz war genau richtig.
Ich mag momentan nicht einschätzen welche Daten Telegrambot geschrieben hat, aber wenn du im DbLog das Attr useCharfilter = 1 setzt, werden nicht-ASCII Zeichen gefiltert.
Sollten die TelegramBot-Daten für dich wichtig sein, könnte das Attr dir helfen und du das Device/Reading wieder loggen.
Grüße,
Heiko
Hallo,
ich scheine eine ähnliches Problem zu haben, komme aber irgendwie nicht mit der Lösung klar.
1. Ich habe ganz frisch dbLog eingerichtet. (FHEM auf Raspberry 3b+ (aktuell) und MariaDB10 mit phpMyAdmin auf Synology NAS 923+ (aktuell)
2. Als erstes bekam ich eine Fehlermeldung, dass VALUE zu lang ist und habe in der Datenbank die Zeichenkette von 32 auf 128 erweitert. Das war damit dann wohl erledigt.
3. Ich habe im configCheck den Hinweis erhalten, dass ich auf von UTF8 auf utf8mb4 umstellen sollte. Das scheint seither zu passen.
4. ich wollte "alle" Werte in die DB schreiben und habe daher das Device so: define logdb DbLog ./db.conf .*:.* angelegt.
5. Ich erhalte damit dann aber folgende Fehlermeldung:
2023.07.31 10:17:09 2: DbLog logdb - Error table history - DBD::mysql::st execute_array failed: executing 11617 generated 392 errors [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (?,?,?,?,?,?,?)"] at ./FHEM/93_DbLog.pm line 3211.
2023.07.31 10:17:35 2: DbLog logdb - Error table history - DBD::mysql::st execute_array failed: executing 11726 generated 392 errors [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (?,?,?,?,?,?,?)"] at ./FHEM/93_DbLog.pm line 3211.
Daraufhin habe ich die Daten für die Datenbank mit: ./db.conf .*:(humidity|temperature).*
reduziert. Ergab aber die gleiche Fehlermeldung im LOG.
Erst als ich nun im DEF nur noch ./db.conf .*:(humidity).* stehen habe, werden die Humidity-Daten ohne Fehlermeldung in die Datenbank geschrieben.
Wie schaffe ich es nun, das alle Daten in die DB geschrieben werden können?
Die hier im Thread genannten Attr habe ich versuchsweise gesetzt, aber leider ohne Erfolg.
Hier mal das List:
Internals:
COLUMNS field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32
CONFIGURATION ./db.conf
DEF ./db.conf .*:(humidity).*
FD 5
FUUID 64c76571-f33f-a358-bd28-60d53fff9890affa
FVERSION 93_DbLog.pm:v5.9.0-s27617/2023-05-25
MODE asynchronous
MODEL MYSQL
NAME logdb
NR 2
NTFY_ORDER 50-logdb
PID 928
REGEXP .*:(humidity).*
SBP_PID 929
SBP_STATE running
STATE connected
TYPE DbLog
UTF8 1
dbconn mysql:database=fhem;host=192.168.178.34;port=3306
dbuser fhemuser1
eventCount 77
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.9.0
OLDREADINGS:
READINGS:
2023-07-31 11:40:52 CacheOverflowLastNum 0
2023-07-31 10:21:18 CacheOverflowLastState normal
2023-07-31 11:40:52 CacheUsage 1
2023-07-31 11:40:52 NextSync 2023-07-31 11:41:22 or when CacheUsage 500 is reached
2023-07-31 11:40:52 state connected
Attributes:
asyncMode 1
room Interface
useCharfilter 1
Und configCheck:
Available Drivers in your system
DBD::DBM, DBD::ExampleP, DBD::File, DBD::Gofer, DBD::Mem, DBD::Proxy, DBD::SQLite, DBD::Sponge, DBD::mysql
Result of version check
Used Perl version: 5.28.1
Used DBI (Database independent interface) version: 1.642
Used DBD (Database driver) version mysql: 4.050
Used DbLog version: 5.9.0
Your local DbLog module is up to date.
Rating:
Recommendation: Update of DbLog is not needed.
Your DBD version fulfills UTF8 support, no need to update DBD.
Result of configuration read check
Connection parameter store type: file
Connection parameter: Connection -> mysql:database=fhem;host=192.168.178.34;port=3306, User -> fhemuser1, Password -> read o.k.
Rating:
Result of connection check
Connection to database fhem successfully done.
The time required to establish the connection was 0.0067 seconds.
Rating:
Recommendation: settings o.k.
Result of collation check
Collation used by Client (connection): UTF8MB4_BIN
Collation used by DB fhem: UTF8MB4_BIN
Rating:
Recommendation: settings o.k. Your DBD version fulfills UTF8 support, no need to update DBD.
Result of insert mode check
Insert mode of DbLog-device logdb is: Array
Rating:
Recommendation: settings o.k.
Result of plot generation method check
WARNING - at least one of your FHEMWEB devices has attribute 'plotfork = 1' not set.
WEB: plotfork=0 / plotEmbed=0 / longpollSVG=0
WEB_Home: plotfork=0 / plotEmbed=0 / longpollSVG=0
WEBhabridge: plotfork=0 / plotEmbed=0 / longpollSVG=0
WEBphone: plotfork=0 / plotEmbed=0 / longpollSVG=0
WEBtablet: plotfork=0 / plotEmbed=0 / longpollSVG=0
Rating:
Recommendation: You should set attribute 'plotfork = 1' in relevant devices. If this attribute is not set, blocking situations may occure when creating plots.
(Note: Your system must have sufficient memory to handle parallel running Perl processes.) See also global attribute blockingCallMax.
Result of table 'history' check
Column width set in table history: 'DEVICE' = 32, 'TYPE' = 32, 'EVENT' = 512, 'READING' = 32, 'VALUE' = 128, 'UNIT' = 32
Column width used by device logdb: 'DEVICE' = 64, 'TYPE' = 64, 'EVENT' = 512, 'READING' = 64, 'VALUE' = 128, 'UNIT' = 32
Rating:
Recommendation: The relation between column width in table history and the field width used in device logdb don't meet the requirements. Please make sure that the width of database field definition is equal or larger than the field width used by the module. Compare the given results.
Currently the default values for field width are:
DEVICE: 64
TYPE: 64
EVENT: 512
READING: 64
VALUE: 128
UNIT: 32
You can change the column width in database by a statement like 'alter table history modify VALUE varchar(128);' (example for changing field 'VALUE'). You can do it for example by executing 'sqlCmd' in DbRep or in a SQL-Editor of your choice. (switch logdb to asynchron mode for non-blocking).
Alternatively the field width used by logdb can be adjusted by setting attributes 'colEvent', 'colReading', 'colValue'. (pls. refer to commandref)
Result of table 'current' check
Column width set in table current: 'DEVICE' = 32, 'TYPE' = 32, 'EVENT' = 512, 'READING' = 32, 'VALUE' = 32, 'UNIT' = 32
Column width used by device logdb: 'DEVICE' = 64, 'TYPE' = 64, 'EVENT' = 512, 'READING' = 64, 'VALUE' = 128, 'UNIT' = 32
Rating:
Recommendation: The relation between column width in table current and the field width used in device logdb don't meet the requirements. Please make sure that the width of database field definition is equal or larger than the field width used by the module. Compare the given results.
Currently the default values for field width are:
DEVICE: 64
TYPE: 64
EVENT: 512
READING: 64
VALUE: 128
UNIT: 32
You can change the column width in database by a statement like 'alter table current modify VALUE varchar(128);' (example for changing field 'VALUE'). You can do it for example by executing 'sqlCmd' in DbRep or in a SQL-Editor of your choice. (switch logdb to asynchron mode for non-blocking).
Alternatively the field width used by logdb can be adjusted by setting attributes 'colEvent', 'colReading', 'colValue'. (pls. refer to commandref)
Result of check 'Search_Idx' availability
Index 'Search_Idx' exists and contains recommended fields 'DEVICE', 'TIMESTAMP', 'READING'.
Rating:
Recommendation: settings o.k.
Result of check 'Report_Idx' availability for DbRep-devices
No DbRep-device assigned to logdb is used. Hence an index for DbRep isn't needed.
Rating:
Recommendation: settings o.k
Wie kann ich diesen Fehler beseitigen?
Vielen Dank.
Grüße
Die Meldung:
2023.07.31 10:17:09 2: DbLog logdb - Error table history - DBD::mysql::st execute_array failed: executing 11617 generated 392 errors [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (?,?,?,?,?,?,?)"] at ./FHEM/93_DbLog.pm line 3211.
2023.07.31 10:17:35 2: DbLog logdb - Error table history - DBD::mysql::st execute_array failed: executing 11726 generated 392 errors [for Statement "INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (?,?,?,?,?,?,?)"] at ./FHEM/93_DbLog.pm line 3211.
ist zu generisch um die genaue Ursache zu erkennen. Man sieht mehr wenn im DbLog verbose 4 oder 5 (extrem viele Ausschriften) eingestellt wird.
Aber deine Spaltengrößen passen noch nicht alle zur Applikation.
Mit phpMyAdmin kannst du sie anpassen:
alter table history modify DEVICE varchar(64);
alter table history modify TYPE varchar(64);
alter table history modify READING varchar(64);
alter table current modify DEVICE varchar(64);
alter table current modify TYPE varchar(64);
alter table current modify READING varchar(64);
Danach FHEM am besten mal restarten um den Cache zu leeren.
Wenn dann immer noch Fehler gemeldet werden muß man tiefer schauen.
Hallo Heiko,
mach Dir nicht weiter einen Kopf :) Das Thema ist inzwischen erledigt. Erstens ging es um mysql und zweitens um eine komplett falsch angelegte Datenbank.
https://forum.fhem.de/index.php?topic=134451.0
Zitat von: DS_Starter am 01 August 2023, 21:46:59Aber deine Spaltengrößen passen noch nicht alle zur Applikation.
Mit phpMyAdmin kannst du sie anpassen:
Hallo,
danke für deine Antwort.
Ich hatte mich beim Anlegen der Datenbank total verrannt.
Da haben sich einige Fehler aufsummiert.
Nachdem ich wieder neu angefangen habe und auch die Tabellen korrigiert hatte, hat es geklappt.
Grüße