DBLog läuft nach update der mariaDB auf Syno NAS nicht mehr.

[harry28]

Ich meine mit MariaDB 10 hat sich der MySQL-Port auf 3307 geändert. Kann es das sein?

Gruß Harry


Gesendet von iPad mit Tapatalk

[DS_Starter]

Hallo Harry,

mit dem Port hast du zwar recht, aber es würde eine andere generelle fehlermeldung kommen.

Danke fürs mitdenken ! 

Grüsse,
Heiko

[DS_Starter]

Also jetzt habe ich dein Log überflogen und bin mir ziemlcih sicher, dass es die Statistikdaten sind.
Es sind nämlich bei jedem Zyklus immer 5 und es sind immer 5 Statistiksätze in einem Zyklus enthalten:

Code Auswählen Erweitern


2018.11.11 16:51:50 2: DbLog DbLog -> Error table history - DBD::mysql::st execute_array failed: executing 43 generated 5 errors at ./FHEM/93_DbLog.pm line 2068.\
2018.11.11 16:51:47 5: DbLog DbLog -> processing event Timestamp: 2018-11-11 16:51:35, Device: WMZ, Type: MODBUSATTR, Event: Waermeleistung: 3000.0, Reading: Waermeleistung, Value: 3000.0, Unit: \
2018.11.11 16:51:47 5: DbLog DbLog -> processing event Timestamp: 2018-11-11 16:51:35, Device: WMZ, Type: MODBUSATTR, Event: aktAZ: 6.61, Reading: aktAZ, Value: 6.61, Unit: \
2018.11.11 16:51:47 5: DbLog DbLog -> processing event Timestamp: 2018-11-11 16:51:35, Device: WMZ, Type: MODBUSATTR, Event: Spreizung: 2.5, Reading: Spreizung, Value: 2.5, Unit: \
2018.11.11 16:51:47 5: DbLog DbLog -> processing event Timestamp: 2018-11-11 16:51:35, Device: WMZ, Type: MODBUSATTR, Event: statGesamtWaermemenge: Hour: 0.003 Day: 0.024 Month: 0.422 Year: 8.012, Reading: statGesamtWaermemenge, Value: Hour: 0.003 Day: 0.024 Month: 0.422 Year: 8.012, Unit: \


An den Sätzen an sich kann ich jetzt nichts merkwürdiges auf den ersten Blick erkenne. Aber wenn meine Annahme stimmt können wir uns die mal genauer anschauen.
Nimm die mal aus dem Logging und check das bitte, morgen dann mehr von mir...

Grüße
Heiko

[der-Lolo]

Guten Morgen Heiko,
ich habe gestern abend noch sehr großzügig mit dem DbLogExclude attribut um mich geworfen - es wurde eh viel zu viel geloggt. Leider hatte ich vergessen verbose beim DbLog Device wieder auf 3 zu setzen, kann also leider nicht sagen ob das problem über nacht auftauchte.

Den WMZ hole ich mir über ein weiteres FHEM auf einem Raspi ins Haupt FHEM auf der Syno - das kann ich einfach abstellen.
Aktuell ist das problem aber nicht mehr da - ich werde berichten.

Tausend Dank für Deine hilfe..!

[der-Lolo]

Zu früh gefreut - ich habe wieder einige einträge im Log....

Code Auswählen Erweitern

2018.11.12 14:41:17 2: DbLog DbLog -> Error table history - DBD::mysql::st execute_array failed: executing 299 generated 1 errors at ./FHEM/93_DbLog.pm line 2068.

2018.11.12 14:26:17 2: DbLog DbLog -> Error table history - DBD::mysql::st execute_array failed: executing 297 generated 1 errors at ./FHEM/93_DbLog.pm line 2068.


Ich nehm jetzt erst mal den Wärmemengenzähler raus, mal schauen ob der Spuk dann ein ende hat.

[der-Lolo]

Obwohl nun der WMZ und die WH2600 deaktiviert waren habe ich noch einen Fehler im Log gefunden...

Kann es vielleicht sein das die Datenbank nicht mehr ok ist? Ich habe gestern versucht einen dump zu erstellen und nach etwa einer Stunde abgebrochen, ich habe knapp über 10 millionen einträge gesammelt... Vielleicht ist ein problem beim update entstanden weil FHEM schreiben wollte..

[DS_Starter]

Welchen Fehler hast du denn noch bekommen ? Gibt es ein verbose 5 davon ?

Kann es vielleicht sein das die Datenbank nicht mehr ok ist?

Ich denke nicht dass es an dem ist. Wenn es einen echten DB Fehler gäbe müsste man ihn auf der Syno im DB-Log sehen.
Auf der Syno gehe dazu mal in das Verzeichnis:

/var/packages/MariaDB10/target/mysql

Dort gibt es ein File <Servername>.err. Schau da mal rein ob dir was auffällt.

MariaDB ist zwar auch nicht vor Fehler gefeit, aber es ist eine echte Datenbank die Lesen und Schreiben zur gleichen Zeit mit mehreren Tasks problemlos verarbeitet. Ich habe in meiner Test-Db über 36Mio Einträge und die quäle ich wirklich immer wieder. 

[der-Lolo]

Kommt bei verbose 5 auch ein Fehler mit 3 hinterm Timestamp?

[DS_Starter]

Ja

[der-Lolo]

Das Log auf der Syno ist meiner meinung nach unauffällig...

MariaDB ist zwar auch nicht vor Fehler gefeit, aber es ist eine echte Datenbank die Lesen und Schreiben zur gleichen Zeit mit mehreren Tasks problemlos verarbeitet. Ich habe in meiner Test-Db über 36Mio Einträge und die quäle ich wirklich immer wieder.

Sollte es dann auf einer DS716+II nicht etwas schneller gehen einen dump zu erstellen? Oder muss ich mich wirklich in geduld üben?
Über Nacht laufen lassen?

[DS_Starter]

Ich benutze ein "dumpMySQL serverSide" mit einem DbRep-Device. Das läuft dann auf meiner 415+ und ist in ein paar Minuten durch.
Ich habe es gerade gestartet und schreibe dir gleich wie lange es gedauert hat....

[DS_Starter]

So ist durch, hat rund 10 Minuten gedauert. Bei der Zeit ist das komprimieren des Dumps noch mit dabei:

Code Auswählen Erweitern


2018.11.12 20:04:07.837 3: DbRep Rep.fhemtest1.Dump - execute command before dump: 'set LogDB1 reopen 3600'
2018.11.12 20:04:07.838 2: DbLog LogDB1: Connection closed until 21:04:07 (3600 seconds).
2018.11.12 20:04:07.877 3: DbRep Rep.fhemtest1.Dump - Searching for tables inside database fhemtest1....
2018.11.12 20:04:07.895 3: DbRep Rep.fhemtest1.Dump - Starting dump of database 'fhemtest1', table 'history'
2018.11.12 20:13:16.115 3: DbRep Rep.fhemtest1.Dump - compress file /sds1/backup/dumps_FHEM/fhemtest1_history_2018_11_12_20_04.csv
2018.11.12 20:15:21.894 3: DbRep Rep.fhemtest1.Dump - file compressed to output file: /sds1/backup/dumps_FHEM/fhemtest1_history_2018_11_12_20_04.csv.gzip
2018.11.12 20:15:23.279 3: DbRep Rep.fhemtest1.Dump - input file deleted: /sds1/backup/dumps_FHEM/fhemtest1_history_2018_11_12_20_04.csv
2018.11.12 20:15:23.280 3: DbRep Rep.fhemtest1.Dump - Number of exported datasets: 36512423
2018.11.12 20:15:23.281 3: DbRep Rep.fhemtest1.Dump - Size of backupfile: 408.31 MB
2018.11.12 20:15:23.284 3: DbRep Rep.fhemtest1.Dump - Deleting old dumpfile 'fhemtest1_history_2018_09_09_17_48.csv.gzip'
2018.11.12 20:15:23.520 3: DbRep Rep.fhemtest1.Dump - Finished backup of database fhemtest1 - total time used: 676 seconds
2018.11.12 20:15:23.560 2: DbRep Rep.fhemtest1.Dump - command message after dump: "Reopen executed."
2018.11.12 20:15:23.610 3: DbRep Rep.fhemtest1.Dump - Database dump finished successfully.


EDIT: Habe gerade mal nach deiner Syno gegoogelt. Die DS716+II dürfte ja noch einen Zacken schneller sein als meine Zumal ich ein Raid 5 habe was eh nicht so ein schnelles Plattensubsystem auf der Syno ist.

[der-Lolo]

Ich habs mal versucht...

Code Auswählen Erweitern

2018.11.12 20:23:40 2: DbRep DbRep - DBD::mysql::st execute failed: Access denied for user 'fhem'@'%' (using password: YES) at ./FHEM/93_DbRep.pm line 6647.
2018.11.12 20:23:40 3: DbRep DbRep - Starting dump of database 'fhem', table 'history'
2018.11.12 20:23:40 3: DbRep DbRep - Size of database fhem after optimize (MB): 1612.09
2018.11.12 20:23:40 3: DbRep DbRep - 2 tables have been optimized.
2018.11.12 20:23:40 3: DbRep DbRep - Table 2 `history` optimized successfully.
2018.11.12 20:19:33 3: DbRep DbRep - Optimizing table `history` (INNODB). It will take a while.
2018.11.12 20:19:33 3: DbRep DbRep - Table 1 `current` optimized successfully.
2018.11.12 20:19:32 3: DbRep DbRep - Optimizing table `current` (INNODB). It will take a while.
2018.11.12 20:19:32 3: DbRep DbRep - Optimizing tables
2018.11.12 20:19:32 3: DbRep DbRep - Size of database fhem before optimize (MB): 1452.59
2018.11.12 20:19:32 3: DbRep DbRep - Searching for tables inside database fhem....
2018.11.12 20:19:32 3: DbRep DbRep - ################################################################
2018.11.12 20:19:32 3: DbRep DbRep - ###             New database serverSide dump                 ###
2018.11.12 20:19:32 3: DbRep DbRep - ################################################################

[DS_Starter]

Access denied for user 'fhem'@'%'

Der verwendete Datenbankuser benötigt das "FILE"-Privileg.

Steht in der Commandref ... Sorry, hätte ich gleich drauf hinweisen sollen.
Gib dem User mal dieses Recht z.B. mit phpMyAdmin.

[DS_Starter]

Ich habe dir eine neue DbLog-Version nach contrib gestellt (Downloadbutton verwenden):

https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter

In dieser Version gibt es zwei neue Attribute um Traces zu aktivieren. Setze dir zu Anfang die Attribute so:

Code Auswählen Erweitern


traceFlag = SQL
traceLevel = 2


Damit werden mehr internas ausgegeben.

Wenn alles funktioniert, sieht es dann aus wie bei mir:

Code Auswählen Erweitern


mysql_st_internal_execute MYSQL_VERSION_ID 100121
>parse_params statement INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (?,?,?,?,?,?,?)
Binding parameters: INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES ('2018-11-12 22:56:04','Dum.Energy','DUMMY','SelfConsumptionQuote: 0.0','SelfConsumptionQuote','0.0','')
<- dbd_st_execute returning imp_sth->row_num 1
2   <- execute= ( 1 ) [1 items] at /usr/lib/x86_64-linux-gnu/perl5/5.24/DBI.pm line 2020 via  at ./FHEM/93_DbLog.pm line 2079
2   -> execute for DBD::mysql::st (DBI::st=HASH(0x55f871fde0c8)~INNER '2018-11-12 22:56:04' 'Dum.Energy' 'DUMMY' 'T: 589.7' 'T' '589.7' '') thr#55f866fa8010
   Called: dbd_bind_ph
   Called: dbd_bind_ph
   Called: dbd_bind_ph
   Called: dbd_bind_ph
   Called: dbd_bind_ph
   Called: dbd_bind_ph
   Called: dbd_bind_ph
-> dbd_st_execute for 55f868d0bab0
>- dbd_st_free_result_sets
<- dbd_st_free_result_sets RC -1
<- dbd_st_free_result_sets
mysql_st_internal_execute MYSQL_VERSION_ID 100121
>parse_params statement INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES (?,?,?,?,?,?,?)
Binding parameters: INSERT INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES ('2018-11-12 22:56:04','Dum.Energy','DUMMY','T: 589.7','T','589.7','')
<- dbd_st_execute returning imp_sth->row_num 1
2   <- execute= ( 1 ) [1 items] at /usr/lib/x86_64-linux-gnu/perl5/5.24/DBI.pm line 2020 via  at ./FHEM/93_DbLog.pm line 2079
1   <- execute_for_fetch= ( 74 74 ) [2 items] at /usr/lib/x86_64-linux-gnu/perl5/5.24/DBI.pm line 2009 via  at ./FHEM/93_DbLog.pm line 2079
    <- execute_array= ( 74 74 ) [2 items] at ./FHEM/93_DbLog.pm line 2079 via  at ./FHEM/93_DbLog.pm line 2076
    -> DESTROY for DBD::mysql::st (DBI::st=HASH(0x55f871fde0c8)~INNER) thr#55f866fa8010
Freeing 7 parameters, bind 0 fbind 0
    <- DESTROY= ( undef ) [1 items] at ./FHEM/93_DbLog.pm line 2199 via  at ./FHEM/93_DbLog.pm line 2199


Vielleicht kommen wir damit bei dir weiter.

EDIT: setze dann verbose = 3, sonst wird es zuviel.

Grüße
Heiko