[Aufruf] Dringender Test sql 1.6.4

[sissiwup]

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 gesichert

Das 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

[apollon77]

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

[ruhr70]

@apollon77:

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.

[sissiwup]

@apollon77:

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.

[apollon77]

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

[sissiwup]

@apollon77:

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.

[sissiwup]

Wie verhext. Reload im Browser und die Daten sind da.

Ist das vlt. ein Timeout?

[apollon77]

welche sql.Adapter Version? Ehrlich noch die 1.6.4?

[sissiwup]

@sissiwup:

sql14.JPG

Wie verhext. Reload im Browser und die Daten sind da.

Ist das vlt. ein Timeout? `

1.7.1

[apollon77]

Hm … wann vorher neu gestartet?

[sissiwup]

@apollon77:

Hm … wann vorher neu gestartet? `

Jede Nacht um 4:00.

Ist aber der erste Aufruf von vis.

[sissiwup]

Folgendes Script:

setState("vEreignissAkt","------------ NEUSTART ------------");

führt beim Neustart zu:

 error: sql.0 Cannot insert INSERT INTO `iobroker`.ts_string (id, ts, val, ack, _from, q) VALUES(1617, 1521256587638, '------------ NEUSTART ------------', 0, 13, 0);: Error: ER_DUP_ENTRY: Duplicate entry '1617-1521256587638' for key 'PRIMARY'
2018-03-17 04:16:28	
 error: sql.0 Cannot insert INSERT INTO `iobroker`.ts_string (id, ts, val, ack, _from, q) VALUES(1617, 1521256587637, '------------ NEUSTART ------------', 0, 13, 0);: Error: ER_DUP_ENTRY: Duplicate entry '1617-1521256587637' for key 'PRIMARY'
 error: sql.0 Cannot insert INSERT INTO `iobroker`.ts_string (id, ts, val, ack, _from, q) VALUES(1617, 1521256587638, '------------ NEUSTART ------------', 0, 13, 0);: Error: ER_DUP_ENTRY: Duplicate entry '1617-1521256587638' for key 'PRIMARY'
 error: sql.0 Cannot insert INSERT INTO `iobroker`.ts_string (id, ts, val, ack, _from, q) VALUES(1617, 1521256587637, '------------ NEUSTART ------------', 0, 13, 0);: Error: ER_DUP_ENTRY: Duplicate entry '1617-1521256587637' for key 'PRIMARY'

Das sieht so aus als würde er beim Neustart das Skript 2x starten?

Alle anderen Datenpunkte mit den duplicates sind auch aus ähnlichen Aktion.

Meistens ist der Datenpunkt aus dem yr.0 Adapter: yr.0.forecast.day0.pressure

[apollon77]

Debug Log?

[foxriver76]

Habe auch mal eine Frage. Nutze den Adapter jetzt entsprechend mittels SQLite - läuft auch soweit. Nur beim Neustart loggt er mir haufenweise

Cannot queue new requests, because more than 100

Ich schätze mal, dass er den alten Status nicht mehr kennt und versucht sämtliche abonnierte DPs auf ein mal in die DB zu schreiben, was die SQLite DB überfordert? Kann ich dem irgendwie entgegenwirken?

beste Grüße

fox

[apollon77]

Ja das liegt an SQLite, Die kann immer nur eine Anfrage abarbeiten und ist daher (und auch aus anderen gründen) nur für nicht so viele Datenpunkte geeignet.

Und ja der Start schreibt den aktuellen Wert überall rein.

Du könntest mal versuchen das Limit höher zu setzen. Wenn Du das versuchen willst mach mal /opt/iobroker/node_modules/iobroker.sql/main.js in einem editor auf. und suche dort nach der Meldung. Gibts mehrfach. Ist immer so grob bei:

    if (!multiRequests) {
        if (tasks.length > 100) {
            adapter.log.error('Cannot queue new requests, because more than 100');

Da musst Du das 100 mal durch was anderes tauschen, also 500 oder 1000

Interessant wäre da vorher/nachher mal Speicherverbrauch und sowas zu vergleichen.

Eine Alternative wäre noch bei SQLite dieses Initiale Schreiben zu verhindern … Denke das ist eher noch "the way to go".

1.7.2 vom SQL Adapter vom Github schaltet WriteNulls bei SQLite automatisch aus

[foxriver76]

@apollon77:

Du könntest mal versuchen das Limit höher zu setzen. Wenn Du das versuchen willst mach mal /opt/iobroker/node_modules/iobroker.sql/main.js in einem editor auf. und suche dort nach der Meldung. Gibts mehrfach. Ist immer so grob bei:

    if (!multiRequests) {
        if (tasks.length > 100) {
            adapter.log.error('Cannot queue new requests, because more than 100');

Da musst Du das 100 mal durch was anderes tauschen, also 500 oder 1000

Interessant wäre da vorher/nachher mal Speicherverbrauch und sowas zu vergleichen. `

Ich werde es bei Gelegenheit mal versuchen, allerdings war die DB wohl teilweise auch schon überfordert beim Neustart.

2018-03-24 09:48:11.319 - error: sql.0 Cannot queue new requests, because more than 100
2018-03-24 09:48:11.428 - error: sql.0 Cannot select SELECT id, type, name FROM datapoints WHERE name='harmony.0.fox.activities.Anzeige-Netflix';: Error: SQLITE_BUSY: database is locked
2018-03-24 09:48:11.430 - warn: sql.0 Cannot get index of "harmony.0.fox.activities.Anzeige-Netflix": Error: SQLITE_BUSY: database is locked

@apollon77:

Eine Alternative wäre noch bei SQLite dieses Initiale Schreiben zu verhindern … Denke das ist eher noch "the way to go". `

Das habe ich jetzt erst mal so gemacht. Danke - war mir nicht sicher ob ich das mit den NULL-Werten bei Start/Stop schreiben richtig interpretiert hatte.

[SabineT]

@apollon77:

Ich weiss aber das es sonderlogik für "Duplicates" gibt die das ganze mit +1ms Timestamp nochmals schreibt. Die ist schon ewig drin … `
Die Werte doppelt in die Datenbank zu schreiben ist aber auch nicht wirklich sehr Resourcen schonend.