[Aufruf] Dringender Test sql 1.6.4
-
Habe das Parallel-Schreiben rausgenommen, da 1500 Connections nicht ausgereicht haben:
sql.0 2018-02-16 20:23:18.586 error Cannot queue new requests, because more than 100 sql.0 2018-02-16 20:23:18.573 error Cannot queue new requests, because more than 100 sql.0 2018-02-16 20:23:16.117 error Cannot queue new requests, because more than 100 sql.0 2018-02-16 20:23:16.083 error Cannot queue new requests, because more than 100 sql.0 2018-02-16 20:23:16.061 error Cannot queue new requests, because more than 100was kann man da machen? `
Was genau meinst Du?
Parallele Requests = Eingeschaltet sollte diese Fehlermeldung niemals generieren!
Wie kommst Du darauf das 1500 Requests nicht ausgereicht haben? Gab es Connection Fehler?
-
Habe das Parallel-Schreiben rausgenommen, da 1500 Connections nicht ausgereicht haben:
sql.0 2018-02-16 20:23:18.586 error Cannot queue new requests, because more than 100 sql.0 2018-02-16 20:23:18.573 error Cannot queue new requests, because more than 100 sql.0 2018-02-16 20:23:16.117 error Cannot queue new requests, because more than 100 sql.0 2018-02-16 20:23:16.083 error Cannot queue new requests, because more than 100 sql.0 2018-02-16 20:23:16.061 error Cannot queue new requests, because more than 100was kann man da machen? `
Was genau meinst Du?
Parallele Requests = Eingeschaltet sollte diese Fehlermeldung niemals generieren!
Wie kommst Du darauf das 1500 Requests nicht ausgereicht haben? Gab es Connection Fehler? `
Hallo,
ja, die DB hat einen Fehler zuviele Connections angezeigt. Und da sind 1500 angelegt.
-
Hallo,
seit 1.7.0 gibt es wieder vermehrt duplicate Keys:
host.zotac 2018-02-17 08:06:09.026 info instance system.adapter.yr.0 terminated with code 0 (OK) sql.0 2018-02-17 08:06:05.171 error Cannot insert INSERT INTO `iobroker`.ts_number (id, ts, val, ack, _from, q) VALUES(236, 1518851163950, 1024, 1, 4, 0);: Error: ER_DUP_ENTRY: Duplicate entry '236-1518851163950' for key 'PRIMARY' sql.0 2018-02-17 08:06:05.144 error Cannot insert INSERT INTO `iobroker`.ts_number (id, ts, val, ack, _from, q) VALUES(236, 1518851163949, 1024, 1, 4, 0);: Error: ER_DUP_ENTRY: Duplicate entry '236-1518851163949' for key 'PRIMARY' sql.0 2018-02-17 08:06:05.142 error Cannot insert INSERT INTO `iobroker`.ts_number (id, ts, val, ack, _from, q) VALUES(236, 1518851163950, 1024, 1, 4, 0);: Error: ER_DUP_ENTRY: Duplicate entry '236-1518851163950' for key 'PRIMARY' sql.0 2018-02-17 08:06:05.139 error Cannot insert INSERT INTO `iobroker`.ts_number (id, ts, val, ack, _from, q) VALUES(236, 1518851163949, 1024, 1, 4, 0);: Error: ER_DUP_ENTRY: Duplicate entry '236-1518851163949' for key 'PRIMARY' sql.0 2018-02-17 08:06:05.136 error Cannot insert INSERT INTO `iobroker`.ts_number (id, ts, val, ack, _from, q) VALUES(236, 1518851163950, 1024, 1, 4, 0);: Error: ER_DUP_ENTRY: Duplicate entry '236-1518851163950' for key 'PRIMARY' sql.0 2018-02-17 08:06:05.120 error Cannot insert INSERT INTO `iobroker`.ts_number (id, ts, val, ack, _from, q) VALUES(236, 1518851163949, 1024, 1, 4, 0);: Error: ER_DUP_ENTRY: Duplicate entry '236-1518851163949' for key 'PRIMARY' yr.0 2018-02-17 08:06:03.918 info got weather data from yr.nohost.zotac 2018-02-17 07:30:00.065 info instance system.adapter.tankerkoenig.0 started with pid 11094 sql.0 2018-02-17 07:29:26.746 error Cannot insert INSERT INTO `iobroker`.ts_string (id, ts, val, ack, _from, q) VALUES(1617, 1518848965643, 'VS-16 EG Trepphaus AUF', 0, 13, 0);: Error: ER_DUP_ENTRY: Duplicate entry '1617-1518848965643' sql.0 2018-02-17 07:29:26.727 error Cannot insert INSERT INTO `iobroker`.ts_string (id, ts, val, ack, _from, q) VALUES(1617, 1518848965643, 'VS-16 EG Trepphaus AUF', 0, 13, 0);: Error: ER_DUP_ENTRY: Duplicate entry '1617-1518848965643' sql.0 2018-02-17 07:29:26.724 error Cannot insert INSERT INTO `iobroker`.ts_string (id, ts, val, ack, _from, q) VALUES(1617, 1518848965642, 'VS-16 EG Trepphaus AUF', 0, 13, 0);: Error: ER_DUP_ENTRY: Duplicate entry '1617-1518848965642' sql.0 2018-02-17 07:29:26.715 error Cannot insert INSERT INTO `iobroker`.ts_string (id, ts, val, ack, _from, q) VALUES(1617, 1518848965642, 'VS-16 EG Trepphaus AUF', 0, 13, 0);: Error: ER_DUP_ENTRY: Duplicate entry '1617-1518848965642' sql.0 2018-02-17 07:29:26.704 error Cannot insert INSERT INTO `iobroker`.ts_string (id, ts, val, ack, _from, q) VALUES(1617, 1518848965642, 'VS-16 EG Trepphaus AUF', 0, 13, 0);: Error: ER_DUP_ENTRY: Duplicate entry '1617-1518848965642' sql.0 2018-02-17 07:29:26.701 error Cannot insert INSERT INTO `iobroker`.ts_string (id, ts, val, ack, _from, q) VALUES(1617, 1518848965643, 'VS-16 EG Trepphaus AUF', 0, 13, 0);: Error: ER_DUP_ENTRY: Duplicate entry '1617-1518848965643' javascript.0 2018-02-17 07:20:00.852 info script.js.servicemeldungen: Text Homematic-Servicemeldungen: keine ServicemeldungenDer erste Punkt wird vom Wetter-Adaper yr gesetzt und ist der Druck.
Der zweite Punkt wird vom Skript-Adapter geschrieben. Allerdings nur einmal, da die Loggausgaben vom Skript auch nur einmal kommen.
Wie entstehen die doppelten Werte?
In der Datenbank kommen im zweiten Fall auch 2 Einträge an.
Was mich wundert ist, da der Entprelltimer auf 1000ms steht.
-
Noch eine kleine Unschönheit:
Wenn man für mehre Werte die Vorgaben ändern möchte:
Dann geht das für Änderungen Aufzeichnen nicht, wenn es unterschiedliche Werte gibt.
Für alle anderen kann man es für mehrere Datenpunkte gleichzeitig anpassen.
-
Duplicate key: keine Ahnung. Bräuchte ich debug log.
Multi Änderungen: bitte github issue für iobroker.admin auf machen
-
Hallo,
wenn man den sql-Adapter neu startet, dann kommt, wenn bis dahin kein Datenpunkt geschrieben wurde immer:
Please wait till next data record is logged and reload.Geht man im Browser auf reload, dann sind die Daten sofort da.
Das gleiche glit auch für float Grafiken. Zuerst leer, wenn einmal geschrieben (irgendwin Datenpunkt von den vielen angezeigten)
oder reload über Browser, dann ist wieder alles da.
Ist das bei euch auch so?
PS: 1.7.1
-
Hallo,
was sollen mir die Infos sagen:
sql.0 2018-02-17 17:15:43.140 info init timed Relog: disable relog because state not set so far for hm-rpc.0.MEQ0381249.0.AES_KEY: null sql.0 2018-02-17 17:15:42.070 info init timed Relog: disable relog because state not set so far for hm-rpc.1.CUX9104011.2.STATE: null sql.0 2018-02-17 17:15:31.123 info init timed Relog: disable relog because state not set so far for hm-rpc.1.CUX2801001.1.STATE: null sql.0 2018-02-17 17:15:17.958 info init timed Relog: disable relog because state not set so far for hm-rpc.1.CUX9104010.4.STATE: null sql.0 2018-02-17 17:15:16.586 info init timed Relog: disable relog because state not set so far for hm-rpc.0.MEQ0381127.0.AES_KEY: null sql.0 2018-02-17 17:15:12.178 info init timed Relog: disable relog because state not set so far for hm-rpc.1.CUX4000001.11.PRESS_SHORT: null sql.0 2018-02-17 17:15:12.023 info init timed Relog: disable relog because state not set so far for hm-rpc.1.CUX9104007.2.STATE: null sql.0 2018-02-17 17:15:10.461 error Please wait till next data record is logged and reload. sql.0 2018-02-17 17:15:10.460 warn For getHistory for id tankerkoenig.0.stations.9.diesel.feed: Type empty. Need to write data first. Index = undefined sql.0 2018-02-17 17:15:10.460 error Please wait till next data record is logged and reload. sql.0 2018-02-17 17:15:10.460 warn For getHistory for id tankerkoenig.0.stations.6.diesel.feed: Type empty. Need to write data first. Index = undefined sql.0 2018-02-17 17:15:10.460 error Please wait till next data record is logged and reload. sql.0 2018-02-17 17:15:10.460 warn For getHistory for id tankerkoenig.0.stations.5.diesel.feed: Type empty. Need to write data first. Index = undefined sql.0 2018-02-17 17:15:10.460 error Please wait till next data record is logged and reload. sql.0 2018-02-17 17:15:10.460 warn For getHistory for id tankerkoenig.0.stations.2.diesel.feed: Type empty. Need to write data first. Index = undefined sql.0 2018-02-17 17:15:10.460 error Please wait till next data record is logged and reload. sql.0 2018-02-17 17:15:10.460 warn For getHistory for id tankerkoenig.0.stations.1.diesel.feed: Type empty. Need to write data first. Index = undefined sql.0 2018-02-17 17:15:10.460 error Please wait till next data record is logged and reload. -
Die Meldungen sagen folgendes:
Wenn Du für einen Datenpunkt das "gleiche Werte loggen nach x Sekunden" einschaltest verssucht der Adapter das auch zu tun wenn innerhalb der Zeit kein neuer Wert kam. Er sucht dann im Zweifel dafür den zuletzt gespeicherten Wert raus.
Wenn es aber keinen gibt - und bei einigen HM-States kann das durchaus passieren - und damit keinerlei "State-Wert" existiert dann kann er auch nichts loggen (NULL loggen macht da keinen Sinn weil es kein echter Wert wäre). Aus dem Grund wird das zeitliche "gleicher Wert loggen" temporär ausgeschaltet. Genau das sagt die Meldung.
Falls für so einen State ein neuer Wert käme dann würde ab dann automatisch das "gleiche Werte loggen" wieder eingeschaltet werden.
Zu der Frage wegen:
For getHistory for id tankerkoenig.0.stations.9.diesel.feed: Type empty. Need to write data first. Index = undefinedWenn das direkt nach dem Start des Adapters passiert, so kann es sein das deine Grafiken "zu schnell" waren.
Beim Start des Adapters wird nach dem Verbindung und "Initialisierung" der Datenbanktabellen alle Datenpunkte, typen und Indizes ausgelesen und gespeichert. Ein "Index=undefined" wie in der Meldung oben könnte darauf hinweisen das die History-Daten abgefragt wurden BEVOR die Daten gelesen wurden. Das würde solche meldungen direkt nach dem Start erklären.
Ich könnte jetzt was einbauen was das im Zweifel behebt und auch das bei getHistory vorher rausliesst … Nötig?
-
Ich hab auch noch ein kleines Problem mit dem SQL Adapter 1.6.9.
Situation:
-
Javascript: DP über Skript angelegt
-
Monitoring eingeschaltet -> SQL
-
Monitoring deaktiviert und dann den Datenpunkt gelöscht
-
neuen DP (Name geändert) über Skript angelegt
-
Monitoring aktiviert
Nun wird das Log mit Errors vollgeschrieben, Beispiel:
ql.0 2018-02-18 04:13:23.408 error Cannot insert INSERT INTO `iobrokerng2`.ts_string (id, ts, val, ack, _from, q) VALUES(875, 1518923603385, 'CALL 2 Free', 0, 11, 0);: Error: ER_DUP_ENTRY: Duplicate entry '875-1518923603385' for key primary'Beim überfliegen der Fehlermeldungen würde ich sagen, es handelt sich durchgängig um die Duplicate entry Meldungen.
Ich sehe den Zusammenhang zwar noch nicht. Kann es sein, dass die Zeit zwischen "Logging deaktivieren" und in den Objekten den Datenpunkt per Hand löschen, zu kurz war?
-
-
Hm, wüsste nicht wie das zu „duplicate key“ führen sollte. Das ist an sich eher das zum gleichen zeitstempel schon ein wert in der dB existiert.
Starte mal sql Adapter neu dann sollten pot Probleme vom manuellen löschen weg sein.
Wenn immer noch duplicate key dann bräuchte ich Debug log.
-
Die Meldungen sagen folgendes:
Wenn Du für einen Datenpunkt das "gleiche Werte loggen nach x Sekunden" einschaltest verssucht der Adapter das auch zu tun wenn innerhalb der Zeit kein neuer Wert kam. Er sucht dann im Zweifel dafür den zuletzt gespeicherten Wert raus.
Wenn es aber keinen gibt - und bei einigen HM-States kann das durchaus passieren - und damit keinerlei "State-Wert" existiert dann kann er auch nichts loggen (NULL loggen macht da keinen Sinn weil es kein echter Wert wäre). Aus dem Grund wird das zeitliche "gleicher Wert loggen" temporär ausgeschaltet. Genau das sagt die Meldung.
Falls für so einen State ein neuer Wert käme dann würde ab dann automatisch das "gleiche Werte loggen" wieder eingeschaltet werden.
Zu der Frage wegen:
For getHistory for id tankerkoenig.0.stations.9.diesel.feed: Type empty. Need to write data first. Index = undefinedWenn das direkt nach dem Start des Adapters passiert, so kann es sein das deine Grafiken "zu schnell" waren.
Beim Start des Adapters wird nach dem Verbindung und "Initialisierung" der Datenbanktabellen alle Datenpunkte, typen und Indizes ausgelesen und gespeichert. Ein "Index=undefined" wie in der Meldung oben könnte darauf hinweisen das die History-Daten abgefragt wurden BEVOR die Daten gelesen wurden. Das würde solche meldungen direkt nach dem Start erklären.
Ich könnte jetzt was einbauen was das im Zweifel behebt und auch das bei getHistory vorher rausliesst … Nötig?
`Hallo,
nein. Ich habe jetzt die Punkt ausgenommen vom "gleicher Wert loggen"
-
Hallo.
immer noch Duplicate Keys:
* 2018-02-18 14:42:19 Alarmstatus: im Haus/Lüften * 2018-02-18 12:26:32 Alarmstatus: OFF * 2018-02-15 21:41:40 Alarmstatus: Haus alles gesichertDas Ereignis wird einmal in eine Variable geschrieben (siehe manuelles Protokoll), aber:
In der Datenbank wird es 3x geschrieben:
Was mich wundert ist, das er so lange braucht, bis er in die DB Schreibt.
Und warum er überhaupt doppelt schreibt,
a) ist entprellen auf 1 Sekunde gesetzt.
b) sollen nur Änderungen geschrieben werden
Wie ist denn der Ablauf des SQL-Adapters?
Beim starten sollte er sich alle Werte für Datenpunkte + ts aus der DB holen. -> Wertecache
Bei jeder Änderung sollte er
Das muss Atomar sein:
a) prüfen ob aktueller ts - Entprell-Intervall > letzter ts
b) prüfen ob aktueller Wert <> alter Wert aus DB (bei nur Änderungen)
c) Wenn er denn schreiben möchte, dann Cache aktualisieren
Jetzt kann parallelisiert werden
d) schreiben
-
Um die Duplicates zu verstehen bräuchte ich Debug Log bitte.
Die genaue Logik zu beschreiben ist sehr umfangreich. Ganz grob (ohne spezielle Startlogik):
Sämtliche Abarbeitung ist atomar weil nur ein Prozess läuft. Alles asynchrone bei JS wird am Ende auch nur sequenziell abgearbeitet.
-
Werteänderung kommt rein
-
prüfen ob je nach einstellungen geloggt werden soll oder nicht (vergleich mit letztem geloggten Wert)
-
Wenn nein, geskippten Wert intern zusätzlich sichern
-
Wenn ja, Wert sichern und diesen als Referenzwert speichern
Wie die Duplicates zustandekommen weiss ich gerade nicht. Ich finde in deinem Screenshot nur nteressant das der timestamp in der Query und die in der Fehlermeldung unterschiedlich sind.
Ich weiss aber das es sonderlogik für "Duplicates" gibt die das ganze mit +1ms Timestamp nochmals schreibt. Die ist schon ewig drin …
Ingo
-
-
Hm, wüsste nicht wie das zu „duplicate key“ führen sollte. Das ist an sich eher das zum gleichen zeitstempel schon ein wert in der dB existiert.
Starte mal sql Adapter neu dann sollten pot Probleme vom manuellen löschen weg sein. `
Nach einem Neustart des SQL-Adapters sind die Meldungen weg.
-
Um die Duplicates zu verstehen bräuchte ich Debug Log bitte
Ingo `
Hallo,Leider tritt der Fehler nur sporadisch auf und der SQL-Adapter schreibt im debug solche Massen an Logdaten, dass ich den nicht für längere Zeit aktivieren möchte.
Es ist scheinbar meistens eine Datenpunkt der vom JavaScript-Adapter ausgelöst/geschrieben wird.
-
Hm … dann ist es echt schwierig dem auf die Spur zu kommen ...
Ist es immer der gleiche Datenpunkt?
Wenn ja vllt zweite ssql-Instanz in Debug Log aufsetzen in zweite DB schreiben und nur wenige Datenpunkte dort aktivieren (die halt wo sowas passiert). Ich kann es aktuell nicht nachvollziehen. Ich brauche aber die Info was passiert wenn es das erste mal passiert
-
Hm … dann ist es echt schwierig dem auf die Spur zu kommen ...
Ist es immer der gleiche Datenpunkt?
Wenn ja vllt zweite ssql-Instanz in Debug Log aufsetzen in zweite DB schreiben und nur wenige Datenpunkte dort aktivieren (die halt wo sowas passiert). Ich kann es aktuell nicht nachvollziehen. Ich brauche aber die Info was passiert wenn es das erste mal passiert `
War die Woche auf Dienstreise, werde das mal ausprobieren. Habe ja noch einen 2. Server der die DB schon installiert hat und vor sich hinläuft.
-
Wie verhext. Reload im Browser und die Daten sind da.
Ist das vlt. ein Timeout?
-
welche sql.Adapter Version? Ehrlich noch die 1.6.4?
-
sql14.JPG
Wie verhext. Reload im Browser und die Daten sind da.
Ist das vlt. ein Timeout? `
1.7.1
