Neues Database Plugin

[aschwith]

Wie kommst Du aus diesem DB Fehler raus?

a) SmarthomeNG Neustart?
b) DB Neustart?

Kannst Du sobald der Fehler auftritt nochmal das Loglevel erhöhen und hier posten?

[Msinn]

Exception Packet sequence number wrong

Nutzt Du MySQL? MySQL unterstützt je Session nur einen aktiven Cursor. Das ist bei normaler Plugin Nutzung kein Problem, kann bei Nutzung von Funktionen des Plugins jedoch zu Problemen führen, da dann zur gleichen Zeit zwei Curors aktiv sein können.

[Sisamiwe]

a) SmarthomeNG Neustart?

Neustart von shNG löst das Problem machmal für Tage, machmal nur für 1-2 Stunden. Habe mir jetzt erstmal eine Logik gebaut, die das Log überwacht und einen Neustart triggert.

Kannst Du sobald der Fehler auftritt nochmal das Loglevel erhöhen und hier posten?

Hab das Log entsprechend geändert und stelle das Ergebnis hier ein.

Nutzt Du MySQL?

Ja, richtig.

Das ist bei normaler Plugin Nutzung kein Problem, kann bei Nutzung von Funktionen des Plugins jedoch zu Problemen führen

Ich nutzte keine Funktionen des Plugins. bzw. ist die Darstellung von Serien in der Visu auch über die Plugin-Funktion gelöst?

[Sisamiwe]

Hallo,

heute nach ist der Fehler wieder aufgetreten und ich habe hier mal den Debug-Log Auszug dazu:

2023-09-29  03:18:24 DEBUG    plugins.database             _query                 Database: Fetch INSERT INTO log(item_id, time, val_str, val_num, val_bool, duration, changed) VALUES (1134,1695950275911,None,4.6,1,None,1695950304484);: 1
2023-09-29  03:18:24 DEBUG    plugins.database             _query                 Database: Fetch UPDATE item SET time = 1695950275911, val_str = None, val_num = 4.6, val_bool = 1, changed = 1695950304484 WHERE id = 1134;: 1
2023-09-29  03:18:24 DEBUG    plugins.database             _dump                  Dump completed
2023-09-29  03:19:17 DEBUG    plugins.database             _query                 Database: Fetch SELECT id, name, time, val_str, val_num, val_bool, changed from item WHERE name = steckdosen.ug.waschkueche.waschmaschine.stromwert;: (301, 'steckdosen.ug.waschkueche.waschmaschine.stromwert', 1695950303760, None, 0.0, 0, 1695950304072)
2023-09-29  03:19:24 DEBUG    plugins.database             _dump                  Starting dump
2023-09-29  03:20:22 DEBUG    plugins.database             _query                 Database: Fetch SELECT count(*) FROM log WHERE item_id = 301 AND time >= 1678662000000;: ((9887472,),)
2023-09-29  03:20:22 DEBUG    plugins.database             _query                 Database: Fetch SELECT id, name, time, val_str, val_num, val_bool, changed from item WHERE name = env.host_rpi.temperature;: (976, 'env.host_rpi.temperature', 1695950187190, None, 62.3, 1, 1695950244610)
2023-09-29  03:20:22 DEBUG    plugins.database             _dump                  Dumping env.host_rpi.temperature/976 with 2 values
2023-09-29  03:20:22 DEBUG    plugins.database             _query                 Database: Fetch SELECT time, item_id, duration, val_str, val_num, val_bool, changed FROM log WHERE item_id = 976 AND time = 1695950187190;: ((1695950187190, 976, None, None, 62.3, 1, 1695950244610),)
2023-09-29  03:20:22 DEBUG    plugins.database             _query                 Database: Fetch UPDATE log SET duration = 120682, val_str = None, val_num = 62.3, val_bool = 1, changed = 1695950422248 WHERE item_id = 976 AND time = 1695950187190;: 1
2023-09-29  03:20:22 DEBUG    plugins.database             _query                 Database: Fetch SELECT time, item_id, duration, val_str, val_num, val_bool, changed FROM log WHERE item_id = 976 AND time = 1695950307872;: ()
2023-09-29  03:20:22 DEBUG    plugins.database             _query                 Database: Fetch INSERT INTO log(item_id, time, val_str, val_num, val_bool, duration, changed) VALUES (976,1695950307872,None,64.2,1,None,1695950422248);: 1
2023-09-29  03:20:22 DEBUG    plugins.database             _query                 Database: Fetch UPDATE item SET time = 1695950307872, val_str = None, val_num = 64.2, val_bool = 1, changed = 1695950422248 WHERE id = 976;: 1
2023-09-29  03:20:22 DEBUG    plugins.database             _query                 Database: Fetch SELECT count(*) FROM log WHERE item_id = 301 AND time <= 1678662000000;: ((74866,),)
2023-09-29  03:20:22 DEBUG    plugins.database             remove_older_than_maxage remove_older_: steckdosen.ug.waschkueche.waschmaschine.stromwert remove older than 13.03.2023 - 00:00 - 74.866 records to delete
2023-09-29  03:20:23 DEBUG    plugins.database             _query                 Database: Fetch DELETE FROM log WHERE item_id = 301 ORDER BY time ASC LIMIT 20000;: 20000
2023-09-29  03:20:23 INFO     plugins.database             remove_older_than_maxage remove_older_: steckdosen.ug.waschkueche.waschmaschine.stromwert deleted 20.000 of 74.866 log entries - took 0.61 seconds, averaging 0.0030 seconds per 100 entries
2023-09-29  03:20:23 ERROR    plugins.database             _query                 Database: Error for query SELECT id, name, time, val_str, val_num, val_bool, changed from item WHERE name = heizung.kessel.abgastemperatur;: Packet sequence number wrong - got 1 expected 2
2023-09-29  03:20:23 WARNING  plugins.database             id                     id(): No id found for item heizung.kessel.abgastemperatur - Exception Packet sequence number wrong - got 1 expected 2
2023-09-29  03:20:23 ERROR    plugins.database             _query                 Database: Error for query SELECT MAX(id) FROM item;: (0, '')
2023-09-29  03:20:23 WARNING  plugins.database             _dump                  Problem dumping heizung.kessel.abgastemperatur: (0, '')
2023-09-29  03:20:23 WARNING  plugins.database             _dump                  Error rolling back: (0, '')
2023-09-29  03:20:23 DEBUG    plugins.database             _initialize_db         DEBUG: delta 3540.219331264496
2023-09-29  03:20:49 WARNING  plugins.database             remove_older_than_maxage remove_older_than_maxage skipped because db is not connected
2023-09-29  03:21:25 NOTICE   plugins.database             notice                 Skipping dump, since an other database operation running! Data is buffered and dumped later.
2023-09-29  03:22:21 WARNING  plugins.database             remove_older_than_maxage remove_older_than_maxage skipped because db is not connected
2023-09-29  03:22:25 NOTICE   plugins.database             notice                 Skipping dump, since an other database operation running! Data is buffered and dumped later.
2023-09-29  03:22:27 DEBUG    plugins.database             stop                   Stop method called​

Hilft das bzw. wem sagt das was?
Scheinbar kommt das Theme von "remove_older_than_maxage", oder?

[bmx]

Ich denke nicht das es vom remove_odler_than_maxage her kommt. Ich denke eher hier

2023-09-29 03:20:23 ERROR plugins.database _query Database: Error for query SELECT id, name, time, val_str, val_num, val_bool, changed from item WHERE name = heizung.kessel.abgastemperatur;: Packet sequence number wrong - got 1 expected 2
2023-09-29 03:20:23 WARNING plugins.database id id(): No id found for item heizung.kessel.abgastemperatur - Exception Packet sequence number wrong - got 1 expected 2
2023-09-29 03:20:23 ERROR plugins.database _query Database: Error for query SELECT MAX(id) FROM item;: (0, '')
2023-09-29 03:20:23 WARNING plugins.database _dump Problem dumping heizung.kessel.abgastemperatur: (0, '')
2023-09-29 03:20:23 WARNING plugins.database _dump Error rolling back: (0, '')
​

liegt der Hase im Pfeffer. Ändere doch mal den Formatter für das Debug los so das Du Zeilennummern vom Code mit dargestellt bekommst. So ist das etwas schwierig.
Und ich würde mir mal das Item heizung.kessel.abgastemperatur ansehen. Warum hat das Ding angeblich keine ID Nummer?

[Sisamiwe]

Warum hat das Ding angeblich keine ID Nummer?

In der Tabelle 'item' ist das aber enthalten:

(371,'heizung.kessel.abgastemperatur',1695968216635,NULL,34.2,1,1695968221561)

[bmx]

Ok, aber es kann durchaus sein, das

2023-09-29 03:20:23 ERROR plugins.database _query Database: Error for query SELECT id, name, time, val_str, val_num, val_bool, changed from item WHERE name = heizung.kessel.abgastemperatur;: Packet sequence number wrong - got 1 expected 2
​

seine Ursache woanders hat und irreführend ist. Daher gerne mit Zeilennummern, dann kann man gezielter suchen.

[Sisamiwe]

Daher gerne mit Zeilennummern

Hast Du zufällig dafür eine Vorlage?

[bmx]

Du kannst dir die Formatter aus der logging.yaml.default mal anschauen. Also shng_detail zum Beispiel sollte die Zeilennummern liefern.

[Sisamiwe]

Hallo,

kann man das Log der lib.db auch auf Debug setzen?

Heute Nachmittag gab es diese Meldeung:

2023-09-29  16:10:48 ERROR    lib.db                                   Can not execute query: SELECT 1 (args OrderedDict()): Packet sequence number wrong - got 1 expected 2
2023-09-29  16:10:48 WARNING  lib.db                                   Database [Database]: Connection error Packet sequence number wrong - got 1 expected 2
2023-09-29  16:10:48 WARNING  lib.db                                   fetchone: No cursor defined for stmt SELECT 1 with params ()​

[bmx]

Eigentlich ist Msinn der Experte für Logging. Aber ich meine in der Logging.yaml kannst Du das ergänzen:

loggers:
    #...
    lib.db:
        level: DEBUG
​

Der Handler wird dann automatisch von lib genommen. Alternativ kannst Du einen eigenen Handler aufnehmen:

handlers:
    # ...
    shng_db_lib_file:
        class: logging.handlers.TimedRotatingFileHandler
        formatter: shng_detail
        level: DEBUG
        utc: false
        when: midnight
        backupCount: 7
        filename: ./var/log/lib_db.log
        encoding: utf8

und den dann eintragen.

[Sisamiwe]

Aber ich meine in der Logging.yaml kannst Du das ergänzen

Danke. Test läuft

[Msinn]

Wird aber nicht viel ergeben. Der Autor der lib.db hat keine DEBUG Ausgaben implementiert. Das höchste der Gefühle sind INFO Ausgaben.

[Msinn]

Den Loglevel für lib.db kannst Du übrigens auch in der Admin GUI anpassen.

Capto_Capture 2023-09-30_10-10-06_AM.jpg

Falls es den Logger bisher nicht gibt, kann er im selben Tab über den Button weiterer Logger angelegt werden.

[bmx]

Ja, stimmt leider. Aber das das bereits über die Admin Oberfläche ging war mir entfallen. Irgendwann könnte man vielleicht auch noch den Handler auswählbar machen.