Autor Thema: DBlog Error  (Gelesen 1271 mal)

Offline DS_Starter

  • Developer
  • Hero Member
  • ****
  • Beiträge: 2041
Antw:DBlog Error
« Antwort #60 am: 13 Januar 2018, 12:45:54 »
Naja, eher nicht sooo prickelnd  ;) Und das sind die Zeiten jetzt wo dein System normal läuft. Nun stelle ich mir vor wie sich die Zeiten und die CPU-Belastung entwickeln wenn plötzlich mehrere tausend Datensätze weggeschrieben werden sollen. Das passt dann schon ins Bild was du ganz am Anfang mal erwähnt hast.

Schauen wir mal ...

Aber
Zitat
Ich logg die Werte auch mal - da sich die Readings ja nicht dynamisch ändern ....
Wie meinst du das ? Diese Readings werfen doch auch regelmäßig einen Event.

ESXi 6.5 auf NUC6i5SYH mit FHEM Gastsystemen auf Debian 8 64 Bit  (Jessie) & Synology iSCSI-LUNs,
DbLog/DbRep mit MariaDB auf Synology 415+,
Homematic, IT, FS20, Cams in Synology Surveillance Station (SSCAM), CUL 433, CUL 868, HM-CFG-LAN

Offline Kai-Alfonso

  • Full Member
  • ***
  • Beiträge: 247
Antw:DBlog Error
« Antwort #61 am: 13 Januar 2018, 12:53:30 »
Naja, eher nicht sooo prickelnd  ;) Und das sind die Zeiten jetzt wo dein System normal läuft. Nun stelle ich mir vor wie sich die Zeiten und die CPU-Belastung entwickeln wenn plötzlich mehrere tausend Datensätze weggeschrieben werden sollen. Das passt dann schon ins Bild was du ganz am Anfang mal erwähnt hast.

Schauen wir mal ...

Aber Wie meinst du das ? Diese Readings werfen doch auch regelmäßig einen Event.

Vergiß es - get DBRep srvinfo geben auch 2 Readings raus, die background_processing_time und sql_processing_time heißen. Aber halt nur wenn man ein get macht. Hatte erst auf den 2.Blick die gleichen Readings bei DBLog gesehen
Raspi2|nanoCul433|nanoCul868|CCU2
Energie-USBZähler|homebrew HM Devices
DBLog|DBRep|Homematic|Baumarktsteckdosen
Hue|Webcams mit DS-Station (Synology)|Bewegungsmelder|Rollladen|Schalter (IT|HM)

Offline DS_Starter

  • Developer
  • Hero Member
  • ****
  • Beiträge: 2041
Antw:DBlog Error
« Antwort #62 am: 13 Januar 2018, 12:58:18 »
ok. Dann sind wir für morgen früh "well prepared" würde ich sagen und lassen uns überraschen.

Erstmal schönen Nachmittag noch !
Heiko
ESXi 6.5 auf NUC6i5SYH mit FHEM Gastsystemen auf Debian 8 64 Bit  (Jessie) & Synology iSCSI-LUNs,
DbLog/DbRep mit MariaDB auf Synology 415+,
Homematic, IT, FS20, Cams in Synology Surveillance Station (SSCAM), CUL 433, CUL 868, HM-CFG-LAN

Offline Kai-Alfonso

  • Full Member
  • ***
  • Beiträge: 247
Antw:DBlog Error
« Antwort #63 am: 13 Januar 2018, 13:05:37 »
ok. Dann sind wir für morgen früh "well prepared" würde ich sagen und lassen uns überraschen.

Erstmal schönen Nachmittag noch !
Heiko

danke, dir auch Heiko . ich melde mich morgen und danke noch mal für deine Zeit
Raspi2|nanoCul433|nanoCul868|CCU2
Energie-USBZähler|homebrew HM Devices
DBLog|DBRep|Homematic|Baumarktsteckdosen
Hue|Webcams mit DS-Station (Synology)|Bewegungsmelder|Rollladen|Schalter (IT|HM)

Offline Kai-Alfonso

  • Full Member
  • ***
  • Beiträge: 247
Antw:DBlog Error
« Antwort #64 am: 14 Januar 2018, 10:27:39 »
Moin,

ich hab dir die relevanten Logs mal als Zip angehangen. Verbose 5 hatte ich von 23:58 bis 02:00 auf das DbLog Device


Grüße

Kai
Raspi2|nanoCul433|nanoCul868|CCU2
Energie-USBZähler|homebrew HM Devices
DBLog|DBRep|Homematic|Baumarktsteckdosen
Hue|Webcams mit DS-Station (Synology)|Bewegungsmelder|Rollladen|Schalter (IT|HM)

Offline DS_Starter

  • Developer
  • Hero Member
  • ****
  • Beiträge: 2041
Antw:DBlog Error
« Antwort #65 am: 14 Januar 2018, 11:50:52 »
Moin,

"Übeltäter" identifiziert würde ich sagen. Ich habe mal die relevante Stelle rausgezogen.

2018.01.14 00:10:04 5: DbLog DBLog -> processing event Timestamp: 2018-01-14 00:10:01, Device: doif.Datenvolumenzaehler, Type: DOIF, Event: GesamtGB_Tag: 0, Reading: GesamtGB_Tag, Value: 0, Unit:
2018.01.14 00:10:04 5: DbLog DBLog -> processing event Timestamp: 2018-01-14 00:10:01, Device: doif.Datenvolumenzaehler, Type: DOIF, Event: GesamtGB_Tag: 0, Reading: GesamtGB_Tag, Value: 0, Unit:
2018.01.14 00:10:06 2: DbLog DBLog -> Error table history - DBD::mysql::st execute_array failed: Duplicate entry '2018-01-14 00:10:01-doif.Datenvolumenzaehler-DOIF-GesamtGB_Tag: ' for key 'TIMESTAMP' [err was 1062 now 2000000000]
executing 247 generated 214 errors at ./FHEM/93_DbLog.pm line 1958.


2018.01.14 00:06:05 2: DbLog DBLog -> Error table history - DBD::mysql::st execute_array failed:
executing 148 generated 108 errors at ./FHEM/93_DbLog.pm line 1958.

2018.01.14 00:08:06 2: DbLog DBLog -> Error table history - DBD::mysql::st execute_array failed:
Duplicate entry '2018-01-14 00:08:01-doif.Datenvolumenzaehler-DOIF-GesamtGB_Tag: ' for key 'TIMESTAMP' [err was 1062 now 2000000000]
executing 208 generated 154 errors at ./FHEM/93_DbLog.pm line 1958.

Der störende Datensatz setzt dann den Prozess in Gang.

Das Attribut "commitMode = ac:off_ta:on" könnte helfen die Situation zu entschärfen. Allerdings wundert es mich, dass der doppelte Eintrag mit den gleichen Werten für TIMESTAMP, READING, VALUE bei dir zum Problem führt, da du doch ohne einen primary key arbeitest:

2018.01.14 00:10:04 4: DbLog DBLog -> AutoCommit mode: ON, Transaction mode: OFF
2018.01.14 00:10:04 5: DbLog DBLog -> Primary Key used in fhem.history: none
2018.01.14 00:10:04 5: DbLog DBLog -> Primary Key used in fhem.current: none

Oder er wird nicht erkannt. Das wäre natürlich schlecht, weil das Modul, wenn es die Verwendung eines PK registriert, die Statements abändert um die Verwendung eines PK zu unterstützen.

Als Massnahme würde ich nun das genannte Attribut setzen.
Aber darüber hinaus müssten wir noch ergründen wieso sich deine DB sich an dem doppelten Datensatz mit Duplicate entry '2018-01-14 00:08:01-doif.Datenvolumenzaehler-DOIF-GesamtGB_Tag: ' for key 'TIMESTAMP' stört. Normalerweise ist sowas kein Problem, im Gegenteil klagen etlicher Nutzer die ohne PK arbeiten (Normalfall) darüber, dass sie doppelte Datensätze im System haben die sie gerne loswerden möchten.
Du hattest ja auch geschrieben, du konntest die DB aus irgendwelchen Gründen nicht auf UTF-8 umstellen, warum eigentlich ?

Ich habe dir mal zum Vergleich auf die Schnelle einen Screenshot aus phpMyAdmin meiner MariaDB Strukturdefinition angehängt. Ich arbeite mit PK, deswegen der Schlüssel an den Feldnamen.

EDIT: Jetzt habe ich mir noch die Performance-Entwicklung angeschaut. Da sieht man ganz deutlich wie deine DB kämpft, im Worst Case Fall waren das so ca. 7 Minuten für einen Schreibvorgang mit 11407 Datensätzen. Da dein FHEM aber offensichtlich weiterhin funktioniert, ist das ein gutes Zeichen, so soll es sein ;)

LG,
Heiko
« Letzte Änderung: 14 Januar 2018, 12:16:18 von DS_Starter »
ESXi 6.5 auf NUC6i5SYH mit FHEM Gastsystemen auf Debian 8 64 Bit  (Jessie) & Synology iSCSI-LUNs,
DbLog/DbRep mit MariaDB auf Synology 415+,
Homematic, IT, FS20, Cams in Synology Surveillance Station (SSCAM), CUL 433, CUL 868, HM-CFG-LAN

Offline Kai-Alfonso

  • Full Member
  • ***
  • Beiträge: 247
Antw:DBlog Error
« Antwort #66 am: 14 Januar 2018, 12:22:22 »
Moin,

"Übeltäter" identifiziert würde ich sagen. Ich habe mal die relevante Stelle rausgezogen.


Der störende Datensatz setzt dann den Prozess in Gang.

Ah, gut zu wissen - das erklärt auch, wieso dies um kurz nach 0:00 passiert - da resettet die Fritzbox den Counter wieder zurück auf 0. Wieso der Datensatz dann doppelt ist, entzieht sich auch meiner Kenntnis.


Das Attribut "commitMode = ac:off_ta:on" könnte helfen die Situation zu entschärfen. Allerdings wundert es mich, dass der doppelte Eintrag mit den gleichen Werten für TIMESTAMP, READING, VALUE bei dir zum Problem führt, da du doch ohne einen primary key arbeitest:


Habe ich mal gesetzt - was ist der Unterschied zwischen den beiden Commit Modi?
2018.01.14 00:10:04 4: DbLog DBLog -> AutoCommit mode: ON, Transaction mode: OFF
2018.01.14 00:10:04 5: DbLog DBLog -> Primary Key used in fhem.history: none
2018.01.14 00:10:04 5: DbLog DBLog -> Primary Key used in fhem.current: none




Oder er wird nicht erkannt. Das wäre natürlich schlecht, weil das Modul, wenn es die Verwendung einer PK registriert, die Statements abändert um die Verwendung eines PK zu unterstützen.

Soweit ich weiß, habe ich nur einen Index (siehe Screenshot)


eschrieben, du konntest die DB aus irgendwelchen Gründen nicht auf UTF-8 umstellen, warum eigentlich ?

Also, ich wollte laut configCheck die Feldlängen erhöhen. Bei dem Feld Event sollte es auf 512 Zeichen erhöht werden. Das ging mit utf8 nicht - es kam eine Fehlermeldung bezüglich maximale Größe. Sorry, die Fehlermeldung habe ich mir dummerweise nicht gemerkt - aber unter Latin ist es kein Problem. (Vorsicht, Halbwissen!!! ). Ist es besser, wieder zu utf8 zu wechseln? Hab ich durch Latin nachteile? Soll ich nen Primarykey auf Timestamp setzen?

Raspi2|nanoCul433|nanoCul868|CCU2
Energie-USBZähler|homebrew HM Devices
DBLog|DBRep|Homematic|Baumarktsteckdosen
Hue|Webcams mit DS-Station (Synology)|Bewegungsmelder|Rollladen|Schalter (IT|HM)

Offline DS_Starter

  • Developer
  • Hero Member
  • ****
  • Beiträge: 2041
Antw:DBlog Error
« Antwort #67 am: 14 Januar 2018, 13:21:03 »
Zitat
Habe ich mal gesetzt - was ist der Unterschied zwischen den beiden Commit Modi?

Mit "ac:on" (das ist der default) wird das Commit-Mangement der DB überlassen. Mit "ac:off" steuere ich das Commitment selber im Modul und kann so besser auf bestimmte Situationen reagieren, das ist so eine. So ist jedenfalls der Plan  ;)

Zitat
Soweit ich weiß, habe ich nur einen Index (siehe Screenshot)
Hmm, jetzt habe ich noch die Idee ob der Index vielleicht als "Unique" definiert ist ? Soll nur "Index" sein. Außerdem enthält er zu viele Spalten. Das ist überflüssig und verbraucht nur Platz. Sieh mal meinen Screenshot als Vergleich.

Zitat
Das ging mit utf8 nicht - es kam eine Fehlermeldung bezüglich maximale Größe
Komisch, kann ich aber im Moment nix mit anfangen.

Zitat
Ist es besser, wieder zu utf8 zu wechseln? Hab ich durch Latin nachteile?
Nachteile hast du mit Latin nicht. Es ist manchmal so, dass du z.B. "°C" in der DB gespeichert hast und du mit phpMyAdmin diesen Wert dann nicht so angezeigt bekommst. Also Sonderzeichen, Umlaute etc. sind das Thema. Aber sonst geht es auch so, man muß ja nicht utf-8 einsetzen.

Zitat
Soll ich nen Primarykey auf Timestamp setzen?
Nein, nicht nur auf TIMESTAMP. Wenn dann so:

ALTER TABLE `history` ADD PRIMARY KEY(TIMESTAMP, DEVICE, READING);

Wenn in deiner history-Tabelle schon doppelte Datensätze sind die den PK verletzen (wahrscheinlich), geht die Anlage nicht.
Dann könntest du es so versuchen:

ALTER IGNORE TABLE `history` ADD PRIMARY KEY(TIMESTAMP, DEVICE, READING);

Wenn du damit nicht weiterkommst, kannst du mal hier: https://forum.fhem.de/index.php/topic,65860.0.html eine Mitteilung machen. JoeAllb und auch andere Mitstreiter sind da SQL-Experten.

Als weitere Variante könntest du diesen Datensatz auch vom Logging ausschließen. Dazu kann man das Attribut "valueFn" benutzen. Wie das geht zeige ich dir wenn du das machen möchtest.

LG,
Heiko

« Letzte Änderung: 14 Januar 2018, 13:25:50 von DS_Starter »
ESXi 6.5 auf NUC6i5SYH mit FHEM Gastsystemen auf Debian 8 64 Bit  (Jessie) & Synology iSCSI-LUNs,
DbLog/DbRep mit MariaDB auf Synology 415+,
Homematic, IT, FS20, Cams in Synology Surveillance Station (SSCAM), CUL 433, CUL 868, HM-CFG-LAN

Offline Kai-Alfonso

  • Full Member
  • ***
  • Beiträge: 247
Antw:DBlog Error
« Antwort #68 am: 14 Januar 2018, 13:58:41 »
Hoi,

mein search.ldx sieht genauso aus, aber ich habe noch ein weiteren Index TIMESTAMP mit ziemlich vielen Spalten und der ist unique. Der ist bei current und bei history. Kein Plan, wo der herkommt - soll ich den löschen?
Raspi2|nanoCul433|nanoCul868|CCU2
Energie-USBZähler|homebrew HM Devices
DBLog|DBRep|Homematic|Baumarktsteckdosen
Hue|Webcams mit DS-Station (Synology)|Bewegungsmelder|Rollladen|Schalter (IT|HM)

Offline DS_Starter

  • Developer
  • Hero Member
  • ****
  • Beiträge: 2041
Antw:DBlog Error
« Antwort #69 am: 14 Januar 2018, 15:18:39 »
Hi Kai,

denke da haben wir die Wurzel des Übels gefunden  :D

Den Index TIMESTAMP  löschen, ja, in beiden Tabellen !  In der current brauchst du ohnehin keinerlei Index.

Aber vorher würde ich versuchen den PK anzulegen wie vorhin geschrieben. Aber nur wenn du mit PK arbeiten willst. Hätte den Vorteil dass die DB doppelte Sätze von sich aus unterbindet.
Wenn du das nicht willst, einfach den Index nur löschen.

EDIT: Wie groß ist eigentlich deine DB ?

Grüße
Heiko
« Letzte Änderung: 14 Januar 2018, 15:26:17 von DS_Starter »
ESXi 6.5 auf NUC6i5SYH mit FHEM Gastsystemen auf Debian 8 64 Bit  (Jessie) & Synology iSCSI-LUNs,
DbLog/DbRep mit MariaDB auf Synology 415+,
Homematic, IT, FS20, Cams in Synology Surveillance Station (SSCAM), CUL 433, CUL 868, HM-CFG-LAN

Offline Kai-Alfonso

  • Full Member
  • ***
  • Beiträge: 247
Antw:DBlog Error
« Antwort #70 am: 14 Januar 2018, 15:30:02 »
Ich dachte mir das, als du das mit unique index erwähnt hattest. Hab jetzt einen primary key mit

ALTER IGNORE TABLE `history` ADD PRIMARY KEY(TIMESTAMP, DEVICE, READING);
angelegt, weil der sonst den doppelten Datensatz angemeckert hat.

Und die beiden Indexe gelöscht - sieht jetzt so aus, wie es soll meine ich (siehe Screenshot)

mal heute abend schauen  - aber der Fehler klingt logisch :-)
Raspi2|nanoCul433|nanoCul868|CCU2
Energie-USBZähler|homebrew HM Devices
DBLog|DBRep|Homematic|Baumarktsteckdosen
Hue|Webcams mit DS-Station (Synology)|Bewegungsmelder|Rollladen|Schalter (IT|HM)

Offline DS_Starter

  • Developer
  • Hero Member
  • ****
  • Beiträge: 2041
Antw:DBlog Error
« Antwort #71 am: 14 Januar 2018, 15:46:14 »
Das sieht gut aus   :)

Theoretisch brauchst du den Search_Idx jetzt auch nicht mehr wenn du den PK hast, aber ich muss gestehen bei mir ist er auch noch drin.
Jetzt mit PK, setzt du dir verbose im DbLog am Besten auf 2. Sonst bekommst du "Fehlermitteilungen" im Log wenn der PK zuschlägt und das Schreiben eines doppelten Datensatzes verhindert ... also dran denken wenn sowas kommt !

Also ich wette mit dir, dass das Problem jetzt erledigt ist ...  8)

LG,
Heiko
ESXi 6.5 auf NUC6i5SYH mit FHEM Gastsystemen auf Debian 8 64 Bit  (Jessie) & Synology iSCSI-LUNs,
DbLog/DbRep mit MariaDB auf Synology 415+,
Homematic, IT, FS20, Cams in Synology Surveillance Station (SSCAM), CUL 433, CUL 868, HM-CFG-LAN

Offline Kai-Alfonso

  • Full Member
  • ***
  • Beiträge: 247
Antw:DBlog Error
« Antwort #72 am: 14 Januar 2018, 15:58:37 »
 

Also ich wette mit dir, dass das Problem jetzt erledigt ist ...  8)

LG,
Heiko


Ich glaube auch  8) - vielen Dank für deine Hilfe und Geduld
Raspi2|nanoCul433|nanoCul868|CCU2
Energie-USBZähler|homebrew HM Devices
DBLog|DBRep|Homematic|Baumarktsteckdosen
Hue|Webcams mit DS-Station (Synology)|Bewegungsmelder|Rollladen|Schalter (IT|HM)

Offline DS_Starter

  • Developer
  • Hero Member
  • ****
  • Beiträge: 2041
Antw:DBlog Error
« Antwort #73 am: 14 Januar 2018, 16:02:44 »
Gern geschehen, war ja auch ein interressanter Problemfall.  ;)
Ich nehme auch noch etwas mit ... nämlich dass ich in den configCheck versuche eine Prüfung einzubauen ob der User irgendwelche Indizes angelegt hat die "Unique" sind. Dann würde es nämlich gleich dort auffallen.

LG,
Heiko
« Letzte Änderung: 14 Januar 2018, 16:37:30 von DS_Starter »
ESXi 6.5 auf NUC6i5SYH mit FHEM Gastsystemen auf Debian 8 64 Bit  (Jessie) & Synology iSCSI-LUNs,
DbLog/DbRep mit MariaDB auf Synology 415+,
Homematic, IT, FS20, Cams in Synology Surveillance Station (SSCAM), CUL 433, CUL 868, HM-CFG-LAN

Offline Kai-Alfonso

  • Full Member
  • ***
  • Beiträge: 247
Antw:DBlog Error
« Antwort #74 am: Gestern um 07:09:03 »
Guten Morgen  8) 8)

Gute Nachrichten - die DB ist nicht mehr all fucked up ab 0:00, sondern läuft locker flockig durch. Wie Du schon vermutet hattest, war der Fehler eher datenbankseitig zu sehen. Verfluchter index  :o :o :o ;D


Soll ich irgendwelche Attribute, die wir (testweise) gesetzt hatten, wieder zurücksetzen/löschen (cacheLimit zum Beispiel)?

Attributes:
   DbLogSelectionMode Include
   DbLogType  Current/History
   asyncMode  1
   cacheEvents 2
   cacheLimit 100000
   commitMode ac:off_ta:on
   group      Datenbank
   room       Konfiguration
   showproctime 1
   shutdownWait 3
   syncInterval 120
   useCharfilter 1
   verbose    2
Raspi2|nanoCul433|nanoCul868|CCU2
Energie-USBZähler|homebrew HM Devices
DBLog|DBRep|Homematic|Baumarktsteckdosen
Hue|Webcams mit DS-Station (Synology)|Bewegungsmelder|Rollladen|Schalter (IT|HM)

 

decade-submarginal