[Gelöst] DBLog SQLite Problem: st execute_array failed

Begonnen von Elektrofreak, 08 März 2017, 09:35:05

Vorheriges Thema - Nächstes Thema

JWRu

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)
ZBox; RasPi 3B; RasPi Zero W; Homematic; Z-Wave; EnOcean, Shelly; DuoFern; Oregon-Sensoren; TFA-Sensoren; Steuerung Viessmann-Heizung; Arduinos für Strom-, Wasser-, Gaszähler, Rauchmelder und FI-Schutzschalter

Bond246

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.

DS_Starter

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
ESXi@NUC+Debian+MariaDB, PV: SMA, Victron MPII+Pylontech+CerboGX
Maintainer: SSCam, SSChatBot, SSCal, SSFile, DbLog/DbRep, Log2Syslog, SolarForecast,Watches, Dashboard, PylonLowVoltage
Kaffeekasse: https://www.paypal.me/HMaaz
Contrib: https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter

DS_Starter

#33
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 )
ESXi@NUC+Debian+MariaDB, PV: SMA, Victron MPII+Pylontech+CerboGX
Maintainer: SSCam, SSChatBot, SSCal, SSFile, DbLog/DbRep, Log2Syslog, SolarForecast,Watches, Dashboard, PylonLowVoltage
Kaffeekasse: https://www.paypal.me/HMaaz
Contrib: https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter

Bond246

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.

DS_Starter

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 ?
ESXi@NUC+Debian+MariaDB, PV: SMA, Victron MPII+Pylontech+CerboGX
Maintainer: SSCam, SSChatBot, SSCal, SSFile, DbLog/DbRep, Log2Syslog, SolarForecast,Watches, Dashboard, PylonLowVoltage
Kaffeekasse: https://www.paypal.me/HMaaz
Contrib: https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter

Bond246

Logging ist seit dem still.

WZ1 und WZ2 hab ich auch angepasst, richtig.

DS_Starter

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
ESXi@NUC+Debian+MariaDB, PV: SMA, Victron MPII+Pylontech+CerboGX
Maintainer: SSCam, SSChatBot, SSCal, SSFile, DbLog/DbRep, Log2Syslog, SolarForecast,Watches, Dashboard, PylonLowVoltage
Kaffeekasse: https://www.paypal.me/HMaaz
Contrib: https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter

JWRu

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).
ZBox; RasPi 3B; RasPi Zero W; Homematic; Z-Wave; EnOcean, Shelly; DuoFern; Oregon-Sensoren; TFA-Sensoren; Steuerung Viessmann-Heizung; Arduinos für Strom-, Wasser-, Gaszähler, Rauchmelder und FI-Schutzschalter

DS_Starter

@JWRu, hast du inzwischen etwas bei dir herausbekommen bzgl. verdächtigen Datensätzen ?
ESXi@NUC+Debian+MariaDB, PV: SMA, Victron MPII+Pylontech+CerboGX
Maintainer: SSCam, SSChatBot, SSCal, SSFile, DbLog/DbRep, Log2Syslog, SolarForecast,Watches, Dashboard, PylonLowVoltage
Kaffeekasse: https://www.paypal.me/HMaaz
Contrib: https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter

JWRu

Ich habe erst morgen Zeit (und Lust), mich um die Sache zu kümmern.
ZBox; RasPi 3B; RasPi Zero W; Homematic; Z-Wave; EnOcean, Shelly; DuoFern; Oregon-Sensoren; TFA-Sensoren; Steuerung Viessmann-Heizung; Arduinos für Strom-, Wasser-, Gaszähler, Rauchmelder und FI-Schutzschalter

Bond246

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'

JWRu

Die einzige Veränderung (außer den FHEM-Updates), die mir einfällt, ist ein Update von MariaDB auf der Synology gestern Vormittag.
ZBox; RasPi 3B; RasPi Zero W; Homematic; Z-Wave; EnOcean, Shelly; DuoFern; Oregon-Sensoren; TFA-Sensoren; Steuerung Viessmann-Heizung; Arduinos für Strom-, Wasser-, Gaszähler, Rauchmelder und FI-Schutzschalter

DS_Starter

#43
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.
ESXi@NUC+Debian+MariaDB, PV: SMA, Victron MPII+Pylontech+CerboGX
Maintainer: SSCam, SSChatBot, SSCal, SSFile, DbLog/DbRep, Log2Syslog, SolarForecast,Watches, Dashboard, PylonLowVoltage
Kaffeekasse: https://www.paypal.me/HMaaz
Contrib: https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter

DS_Starter

#44
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.
ESXi@NUC+Debian+MariaDB, PV: SMA, Victron MPII+Pylontech+CerboGX
Maintainer: SSCam, SSChatBot, SSCal, SSFile, DbLog/DbRep, Log2Syslog, SolarForecast,Watches, Dashboard, PylonLowVoltage
Kaffeekasse: https://www.paypal.me/HMaaz
Contrib: https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter