DBLog 2.16.3 Fehler execute array mit Postgresql

eldrik · 14 April 2017, 10:12:49

Hi,

ich habe heute mal wieder ein FHEM Update vollzogen und nun erhalte ich folgende Fehlermeldung von DBLog, Daten werden scheinbar dadurch nicht mehr geloggt.

DBD::Pg::st execute_array failed: ERROR: syntax error at or near "ON"
LINE 1: ...ADING, VALUE, UNIT) VALUES ($1,$2,$3,$4,$5,$6,$7) ON CONFLIC...
^ [err was 7 now 2000000000]
executing 1 generated 1 errors at ./FHEM/93_DbLog.pm line 1391.
, DBD::Pg::st execute_array failed: ERROR: syntax error at or near "ON"
LINE 1: ...ADING, VALUE, UNIT) VALUES ($1,$2,$3,$4,$5,$6,$7) ON CONFLIC...
^ [err was 7 now 2000000000]
executing 1 generated 1 errors at ./FHEM/93_DbLog.pm line 1426.

Ist dieser Fehler bekannt und gibt es eine mögliche Lösung?

Ich bin jetzt vorerst wieder auf die zuletzt bei mir aktive Version 2.11.4 zurück!

Greetz
Eldrik

CoolTux · 14 April 2017, 10:31:01

Mach mal bitte ein list von Deinem logDb Device

DS_Starter · 14 April 2017, 11:05:39

Hi eldrik,

vermutlich hast du in deiner DB primary key gesetzt. Für Postgresql unterstützt DbLog primary key erst ab Postgre 9.5. Die Syntax ..ON Conflict .. gibt es erst ab der 9.5.
Wenn du ohne PK arbeitest dann wird auch alles laufen ... oder Postgre Update.
(Ich muß das mal in der commandrf vermerken ...)

Schöne Ostern eldrik & cooltux !

Heiko

CoolTux · 14 April 2017, 11:33:23

Hallo Heiko,

Vielen Dank. Dir auch frohe Ostern.

eldrik · 14 April 2017, 14:26:14

Zitat von: DS_Starter am 14 April 2017, 11:05:39
Hi eldrik,

vermutlich hast du in deiner DB primary key gesetzt. Für Postgresql unterstützt DbLog primary key erst ab Postgre 9.5. Die Syntax ..ON Conflict .. gibt es erst ab der 9.5.
Wenn du ohne PK arbeitest dann wird auch alles laufen ... oder Postgre Update.
(Ich muß das mal in der commandrf vermerken ...)

Schöne Ostern eldrik & cooltux !

Heiko

Hallo Heiko,

Danke für die schnelle Antwort, ich werd mal schauen ob ich Postgres anhebe oder den Key entferne.

Danke und ebenfalls frohe Ostern.

Greetz
Eldrik

eldrik · 15 April 2017, 00:01:33

Hi,

so ich habe nun einmal erfolgreich auf Postgres 9.5 aktualisiert, die Meldung (wenngleich abgespeckter?) erscheint aber nach einem erneuten DbLog Update erneut :/

0, DBD::Pg::st execute_array failed: ERROR: syntax error at or near "0" LINE 1: ... VALUE, UNIT) VALUES ($1,$2,$3,$4,$5,$6,$7) ON CONFLICT (0) ^ [err was 7 now 2000000000] executing 1 generated 1 errors at ./FHEM/93_DbLog.pm line 1426.

Ich bin mir auch nicht bewusst, das ich mit dem Primary Key arbeite, den einzigen Index, den ich auf der history Tabelle habe, habe ich testweise einmal entfernt, was aber auch keine Besserung gebracht hat.

Muss ich noch etwas ändern?

Greetz
Eldrik

DS_Starter · 15 April 2017, 08:47:14

Hi Eldrik,

Nein musst du nicht . Vergleiche mit dem Wiki zu 9.5.
https://wiki.postgresql.org/wiki/What%27s_new_in_PostgreSQL_9.5#Links_7

Wir haben das Konstrukt in dem DbLog Thread Optimierung erfolgreich getestet. Schau mal dort hinein.

Grüße
Heiko

DS_Starter · 15 April 2017, 10:13:05

Hi Eldrik,

habe noch eine Idee. Es kommt mir so vor als würden die am PK beteiligten Spalten nicht (richtig) ermittelt und deswegen kommt nu dieser Error.
Kannst du bitte mal ein verbose 5 Log anfertigen. Interessant ist der Abschnitt "New database cycle". Kannst es zum Vergleich auch mal mit Asynch Mode probieren. Sollte aber keinen Unterschied machen.

Grüße
Heiko

eldrik · 15 April 2017, 10:28:24

Hi,

so ich glaub das ist der Bereich von Interesse?

Code Auswählen

2017.04.15 10:26:48.373 4: DbLog myDbLog -> ################################################################
2017.04.15 10:26:48.373 4: DbLog myDbLog -> ###         New database processing cycle - synchronous      ###
2017.04.15 10:26:48.373 4: DbLog myDbLog -> ################################################################
2017.04.15 10:26:48.373 4: DbLog myDbLog -> DbLogType is: Current/History
2017.04.15 10:26:48.375 5: DbLog myDbLog -> Primary Key used in fhem.history: 0
2017.04.15 10:26:48.375 5: DbLog myDbLog -> Primary Key used in fhem.current: 0
2017.04.15 10:26:48.375 4: DbLog myDbLog -> processing event Timestamp: 2017-04-15 10:26:48, Device: Stromzaehler_Easymeter, Type: CLONEDUMMY, Event: total_energy: 377.93, Reading: total_energy, Value: 377.93, Unit:
2017.04.15 10:26:48.378 4: DbLog myDbLog -> 1 of 1 events inserted into table history using PK on columns 0
2017.04.15 10:26:48.380 2: DbLog myDbLog -> Error table current - DBD::Pg::st execute_array failed: ERROR:  syntax error at or near "0"
LINE 1: ... VALUE, UNIT) VALUES ($1,$2,$3,$4,$5,$6,$7) ON CONFLICT (0)
                                                                    ^ [err was 7 now 2000000000]
executing 1 generated 1 errors at ./FHEM/93_DbLog.pm line 1426.

2017.04.15 10:26:48.380 5: DbLog myDbLog -> DbLog_Push Returncode: 0, DBD::Pg::st execute_array failed: ERROR:  syntax error at or near "0"
LINE 1: ... VALUE, UNIT) VALUES ($1,$2,$3,$4,$5,$6,$7) ON CONFLICT (0)
                                                                    ^ [err was 7 now 2000000000]
executing 1 generated 1 errors at ./FHEM/93_DbLog.pm line 1426.

2017.04.15 10:26:48.382 4: DbLog myDbLog -> ################################################################
2017.04.15 10:26:48.382 4: DbLog myDbLog -> ###              start of new Logcycle                       ###
2017.04.15 10:26:48.382 4: DbLog myDbLog -> ################################################################
2017.04.15 10:26:48.382 4: DbLog myDbLog -> amount of events received: 1 for device: myDbLog
2017.04.15 10:26:48.382 4: DbLog myDbLog -> check Device: myDbLog , Event: 0, DBD::Pg::st execute_array failed: ERROR:  syntax error at or near "0"

Asynron muss ich gleich mal testen.
Edit:

Aync: im state steht aber weiterhin

Code Auswählen

0, DBD::Pg::st execute_array failed: ERROR: syntax error at or near "0" LINE 1: ... VALUE, UNIT) VALUES ($1,$2,$3,$4,$5,$6,$7) ON CONFLICT (0) ^ [err was 7 now 2000000000] executing 190 generated 190 errors at ./FHEM/93_DbLog.pm line 1800.

Code Auswählen

2017.04.15 10:30:21.080 5: DbLog myDbLog -> ################################################################
2017.04.15 10:30:21.080 5: DbLog myDbLog -> ###      New database processing cycle - asynchronous        ###
2017.04.15 10:30:21.080 5: DbLog myDbLog -> ################################################################
2017.04.15 10:30:21.080 5: DbLog myDbLog -> MemCache contains 159 entries to process
2017.04.15 10:30:21.080 5: DbLog myDbLog -> MemCache contains: 2017-04-15 10:29:23|CUL_HM_HM_CC_RT_DN_22C32C|CUL_HM|desired-temp: 17.5|desired-temp|17.5|
2017.04.15 10:30:21.080 5: DbLog myDbLog -> MemCache contains: 2017-04-15 10:29:24|dummy_bewegung_kamera_garten_vorne|DUMMY|bewegung: 0|bewegung|0|
2017.04.15 10:30:21.080 5: DbLog myDbLog -> MemCache contains: 2017-04-15 10:30:06|DS2438_15E21B010000|OWDEVICE|VAD: 10.23|VAD|10.23|
2017.04.15 10:30:21.080 5: DbLog myDbLog -> MemCache contains: 2017-04-15 10:30:06|DS2438_15E21B010000|OWDEVICE|VDD: 4.21|VDD|4.21|
2017.04.15 10:30:21.080 5: DbLog myDbLog -> MemCache contains: 2017-04-15 10:30:06|DS2438_15E21B010000|OWDEVICE|temperature: 17|temperature|17|Â°C
2017.04.15 10:30:21.080 5: DbLog myDbLog -> MemCache contains: 2017-04-15 10:30:07|F2Voltage.Buero|CLONEDUMMY|VAD: 1.7|VAD|1.7|

Greetz
Eldrik

DS_Starter · 15 April 2017, 12:47:11

Ja, genau, mit meiner Vermutung liege ich ganz richtig:

Code Auswählen


2017.04.15 10:26:48.375 5: DbLog myDbLog -> Primary Key used in fhem.history: 0
2017.04.15 10:26:48.375 5: DbLog myDbLog -> Primary Key used in fhem.current: 0

Ist der Punkt. Statt der "0" sollten hier die Spalten stehen die Bestandteil des primary Key sind.
Kannst du mal nach der Definition deines PK schauen ?

In dem anderen Thread hat hier https://forum.fhem.de/index.php/topic,65860.msg582660.html#msg582660 Pyromane mit seiner Postgre das Ganze durchgestet. Ich glaube (!) er hat die Version 10.x. Evtl. fragen wir ihn in dem anderen Thread mal wie seine Umgebung genau aussieht.

Grüße
Heiko

DS_Starter · 15 April 2017, 14:24:19

Hallo Eldrik,

anbei die Version 2.16.4.
Ich habe die PK-Auswertung etwas geändert und hoffe damit den Fehler zu vermeiden den du bekommst.
Mache damit nochmal ein verbose 5 wie oben. Warum allerdings deine PK-Spalten nicht gemeldet werden ist noch zu ergründen.

Grüße
Heiko

eldrik · 15 April 2017, 17:38:19

Hallo Heiko,

danke für deine prompte Hilfe! Leider hat diese Version ebenfalls den Fehler gebracht.

Ich glaube aber dass es daran liegt, dass meine History und Current Tabellen überhaupt keine Primary Keys aufweisen, schaue ich nach den Objekten, die pyro auf seiner Datenbank hat, so finde ich diese nicht.

Für die Current habe ich jetzt einmal einen Primary Key auf device und reading angelegt, ich musste zwar ein paar offensichtlich doppelt vorhandene Datensätze löschen, aber der Key ist jetzt da.

Bei der History Tabelle gibt es wohl auch noch doppelte Datensätze, bevor ich hier jedoch Datensätze lösche muss ich erst einmal den doppelten Boden aufspannen, damit mir am Ende nichts verloren geht

Sobald ich hier den Primary Key auf timestamp, device und reading aufweise probiere ich die Version erneut.

Greetz
Eldrik

DS_Starter · 15 April 2017, 18:55:09

Hi Eldrik,
Mach mal trotzdem bitte ein verbose 5 Log.
Wenn du keinen PK angelegt hast dürfte es diesen Fehler bei dir gar nicht geben. Im Log wird dann "none " für die Verwendung von PK angezeigt. Bei meiner PostgreSQL kommt es auch so ohne PK.

Grüße
Heiko

eldrik · 15 April 2017, 21:21:53

Hallo Heiko,

anbei das neue Log:

Code Auswählen

2017.04.15 21:19:27.015 4: DbLog myDbLog -> ################################################################
2017.04.15 21:19:27.015 4: DbLog myDbLog -> ###         New database processing cycle - synchronous      ###
2017.04.15 21:19:27.015 4: DbLog myDbLog -> ################################################################
2017.04.15 21:19:27.015 4: DbLog myDbLog -> DbLogType is: Current/History
2017.04.15 21:19:27.017 5: DbLog myDbLog -> Primary Key used in fhem2.history: 
2017.04.15 21:19:27.017 5: DbLog myDbLog -> Primary Key used in fhem2.current: 
2017.04.15 21:19:27.017 4: DbLog myDbLog -> processing event Timestamp: 2017-04-15 21:19:26, Device: F2Contact_Hum_Light_EG_links_MQTT, Type: MQTT_DEVICE, Event: Luftfeuchte_Buero: 32, Reading: Luftfeuchte_Buero, Value: 32, Unit: 
2017.04.15 21:19:27.017 4: DbLog myDbLog -> processing event Timestamp: 2017-04-15 21:19:26, Device: F2Contact_Hum_Light_EG_links_MQTT, Type: MQTT_DEVICE, Event: Luftfeuchte_Flur_Eingang: , Reading: state, Value: Luftfeuchte_Flur_Eingang: , Unit: 
2017.04.15 21:19:27.017 4: DbLog myDbLog -> processing event Timestamp: 2017-04-15 21:19:26, Device: F2Contact_Hum_Light_EG_links_MQTT, Type: MQTT_DEVICE, Event: Luftfeuchte_Flur_Windfang: 38, Reading: Luftfeuchte_Flur_Windfang, Value: 38, Unit: 
2017.04.15 21:19:27.017 4: DbLog myDbLog -> processing event Timestamp: 2017-04-15 21:19:26, Device: F2Contact_Hum_Light_EG_links_MQTT, Type: MQTT_DEVICE, Event: Luftfeuchte_GaesteWC: 49, Reading: Luftfeuchte_GaesteWC, Value: 49, Unit: 
2017.04.15 21:19:27.172 4: DbLog myDbLog -> 4 of 4 events inserted into table history using PK on columns 
2017.04.15 21:19:27.184 2: DbLog myDbLog -> Error table current - DBD::Pg::st execute_array failed: ERROR:  syntax error at or near ")"
LINE 1: ..., VALUE, UNIT) VALUES ($1,$2,$3,$4,$5,$6,$7) ON CONFLICT () 
                                                                     ^ [err was 7 now 2000000000]
executing 4 generated 4 errors at ./FHEM/93_DbLog.pm line 1427.

2017.04.15 21:19:27.185 5: DbLog myDbLog -> DbLog_Push Returncode: 0, DBD::Pg::st execute_array failed: ERROR:  syntax error at or near ")"
LINE 1: ..., VALUE, UNIT) VALUES ($1,$2,$3,$4,$5,$6,$7) ON CONFLICT () 
                                                                     ^ [err was 7 now 2000000000]
executing 4 generated 4 errors at ./FHEM/93_DbLog.pm line 1427.

Greetz
Eldrik

DS_Starter · 15 April 2017, 22:27:41

Hi Eldrik,

Hmm ... das ist ein seltsames Verhalten. Es wird ein Vorhandensein eines PK erkannt obwohl andererseits keine Spalten geliefert werden. Das passt dann nicht zusammen und es wird der Fehler geworfen. Ich werde noch etwas an der PK Routine anpassen. Aber wahrscheinlich erst am Montag.
Was hast du denn für ein BS unter FHEM ?

Grüße
Heiko

eldrik · 15 April 2017, 23:21:34

Hi,

ja kein Grund zur Hast es drückt nicht! Ich komm ja bestens mit der alten Version über die Runden

Mein Setup kommt deinem recht nahe:

ESXi 6.0 auf Mac Mini Server & AMD AM1 mini ITX Build mit FHEM Gastsystemen auf Debian 7.8 32 Bit & Synology DS214+ iSCSI-LUNs.

Greetz
Eldrik

DS_Starter · 16 April 2017, 15:27:00

Hi Eldrik,

es hat mir natürlich keine Ruhe gelassen und habe dir die Version 2.16.5 angehängt.
Bei mir funktioniert es auch mit dieser V einwandfrei. Habe es mit allen unterstützten DB-Typen getestet.

Wie in dem Logauszug muß mit verbose 5 "none" für einen nicht existierenden PK in einer Tabelle ausgeschrieben werden und
anderenfalls sollen die beteiligten Spalten eines existierenden PK ausgegeben werden.

Code Auswählen


2017.04.16 11:09:26.926 5: DbLog LogPostgre -> Start DbLog_PushAsync
2017.04.16 11:09:26.926 5: DbLog LogPostgre -> DbLogType is: Current/History
2017.04.16 11:09:26.943 5: DbLog LogPostgre -> Primary Key used in fhemtest.history: none
2017.04.16 11:09:26.943 5: DbLog LogPostgre -> Primary Key used in fhemtest.current: timestamp,device
2017.04.16 11:09:26.943 5: DbLog LogPostgre -> processing event Timestamp: 2017-04-16 11:08:50, Device: sysmon, Type: SYSMON, Event:

Ich habe die PK-Leseroutine geändert um die Situation, die bei dir offenschtlich vorliegt, besser abzufangen.
Zusätzlich kann man mit dem Attribut "noSupportPK" den Suppport für PK im Modul explizit ausschalten.
Schau mal wie es damit nun bei dir aussieht. Es sollte in allen Varianten problemlos funktionieren.

Grüße
Heiko

eldrik · 16 April 2017, 16:56:48

Hallo Heiko,

du bist einfach unermüdlich

Das scheint es nun zu sein, chapeau!

2017.04.16 16:48:55.866 4: DbLog myDbLog -> ################################################################
2017.04.16 16:48:55.866 4: DbLog myDbLog -> ### New database processing cycle - synchronous ###
2017.04.16 16:48:55.866 4: DbLog myDbLog -> ################################################################
2017.04.16 16:48:55.866 4: DbLog myDbLog -> DbLogType is: Current/History
2017.04.16 16:48:55.868 5: DbLog myDbLog -> Primary Key used in fhem2.history: none
2017.04.16 16:48:55.868 5: DbLog myDbLog -> Primary Key used in fhem2.current: none
2017.04.16 16:48:55.868 4: DbLog myDbLog -> processing event Timestamp: 2017-04-16 16:48:55, Device: F2Contact_AB2_MQTT, Type: MQTT_DEVICE, Event: sensed.4: 0, Reading: sensed.4, Value: 0, Unit:
2017.04.16 16:48:55.877 4: DbLog myDbLog -> 1 of 1 events inserted into table history
2017.04.16 16:48:55.880 4: DbLog myDbLog -> 1 of 1 events updated in table current
2017.04.16 16:48:55.881 5: DbLog myDbLog -> DbLog_Push Returncode: 0

Den Support per Attribut "noSupportPK" habe ich nicht verwendet, lief so auf anhieb

Vielen herzlichen Dank und schöne rest Osterfeiertage.

Greetz
Eldrik

DS_Starter · 16 April 2017, 17:13:15

Super, freut mich !

Dir auch noch schöne Restostern ....
Heiko