db-Abfrage ist manchmal "NoneType"

[henfri]

Hallo,

gute Nachricht: Vorher kamen ja sekundenweise Fehlermeldungen. Die sind jetzt weg.
Aber eine neue Fehlermeldung habe ich:

2014-03-09 09:25:16,097 ERROR    Allgemein.Stromzaehler.Momentanleistung_10min Item Allgemein.Stromzaehler.Momentanleistung_10min: problem running <bound method SQL.update_item of <plugins.sqlite.SQL object at 0x2121390>>: list index out of range -- item.py:__update:371
  File "/usr/local/smarthome/plugins/sqlite/__init__.py", line 182, in update_item
  File "/usr/local/smarthome/plugins/sqlite/__init__.py", line 265, in _insert

Anbei das ganze log.
Die db lade ich gleich zu DropBox hoch --> https://dl.dropboxusercontent.com/u/...arthome_db.zip (12MB).

Gruß,
Hendrik



Gruß,
Hendrik

[henfri]

Klasse, danke.
Wird getestet.


Gesendet von unterwegs

[callidomus]

Hallo Hendrik,

danke für den qualifizierten Input.

Ich habe den aufgezeigten Bug gefixt. Ist in develop.

Bis bald

Marcus

[henfri]

Hallo Marcus,

ich denke, ich bin ein Stück weiter. Ich hatte bisher das Log immer nur nach sql durchsucht. Wenn ich aber nicht case-sensitiv suche, komme ich weiter:

2014-03-08 21:01:06,581 DEBUG    Main         SQLite 3.7.9 -- __init__.py:__init__:60
2014-03-08 21:01:06,581 DEBUG    Main         SQLite: database integrity ok -- __init__.py:__init__:77
2014-03-08 21:01:06,582 DEBUG    Main         SQLite Maintain next time: 2014-03-09 03:02:00+01:00 -- scheduler.py:_next_time:301
2014-03-08 21:01:06,620 DEBUG    Main         Item og.Till.heizung.ist = 20.2 via SQLite None None -- item.py:set:466
2014-03-08 21:01:06,628 DEBUG    Main         Item og.Lina.heizung.ist = 21.1 via SQLite None None -- item.py:set:466
2014-03-08 21:01:06,648 DEBUG    Main         Item og.Kinderbad.heizung.ist = 20.8 via SQLite None None -- item.py:set:466
2014-03-08 21:01:06,698 DEBUG    Main         Item Allgemein.Stromzaehler.Counter = 605805.0 via SQLite None None -- item.py:set:466
2014-03-08 21:01:06,699 DEBUG    Main         Item Allgemein.Stromzaehler.Zaehlerstand = 757.255 via SQLite None None -- item.py:set:466
2014-03-08 21:01:06,699 DEBUG    Main         Item Allgemein.Stromzaehler.Momentanleistung_1min = 450.00000000300133 via SQLite None None -- item.py:set:466
2014-03-08 21:01:06,700 DEBUG    Main         Item Allgemein.Stromzaehler.Momentanleistung_freq = 12139.81833436297 via SQLite None None -- item.py:set:466
2014-03-08 21:01:06,722 DEBUG    Main         Item Wetter.Windgeschwindigkeit.Wetterstation = 0.07 via SQLite None None -- item.py:set:466
2014-03-08 21:01:06,758 DEBUG    Main         Starting sql Plugin -- plugin.py:start:67
2014-03-08 21:01:52,052 WARNING  Main         SQLite: Problem with '("SELECT ROUND(SUM(_avg * _dur) / SUM(_dur)), 2) from num WHERE _item='Allgemein.Stromzaehler.Zaehlerstand' AND _start + _dur > 1394222511726 AND _start <= 1394222511726",)': near ")": syntax error -- __init__.py:_fetchall:224
2014-03-08 21:01:57,626 WARNING  Main         SQLite: Problem with '("SELECT ROUND(SUM(_avg * _dur) / SUM(_dur)), 2) from num WHERE _item='Allgemein.Stromzaehler.Zaehlerstand' AND _start + _dur > 1393444917002 AND _start <= 1394222517002",)': near ")": syntax error -- __init__.py:_fetchall:224
2014-03-08 21:02:04,712 WARNING  Main         SQLite: Problem with '("SELECT ROUND(SUM(_avg * _dur) / SUM(_dur)), 2) from num WHERE _item='Allgemein.Stromzaehler.Zaehlerstand' AND _start + _dur > 1393444924712 AND _start <= 1394308924712",)': near ")": syntax error -- __init__.py:_fetchall:224
2014-03-08 21:03:37,123 WARNING  Main         SQLite: Problem with '("SELECT ROUND(SUM(_avg * _dur) / SUM(_dur)), 2) from num WHERE _item='Allgemein.Stromzaehler.Zaehlerstand' AND _start + _dur > 1394308956742 AND _start <= 1394309016742",)': near ")": syntax error -- __init__.py:_fetchall:224
2014-03-08 21:03:47,712 WARNING  Main         SQLite: Problem with '("SELECT ROUND(SUM(_avg * _dur) / SUM(_dur)), 2) from num WHERE _item='Allgemein.Stromzaehler.Zaehlerstand' AND _start + _dur > 1394308967712 AND _start <= 1394309027712",)': near ")": syntax error -- __init__.py:_fetchall:224
2014-03-08 22:32:03,234 WARNING  Main         SQLite: Problem with '("SELECT ROUND(SUM(_avg * _dur) / SUM(_dur)), 2) from num WHERE _item='Allgemein.Stromzaehler.Zaehlerstand' AND _start + _dur > 1394314263234 AND _start <= 1394314323234",)': near ")": syntax error -- __init__.py:_fetchall:224

Ich denke, das grenzt den Fehler gut ein?
Ich habe die db auch mal weg-geschoben, so dass eine neue erzeugt wird --> keine Änderung. An der Kommandozeile (-i) waren alle meine Versuche, der DB etwas zu entlocken (unterschiedliche Items) nicht erfolgreich.

Anbei das ganze Log.

Gruß,
Hendrik

[henfri]

Hallo Marcus,

die Zeile 383 wir -nach meinem Verständnis- ausgeführt, wenn nix aus der Datenbank zurück kam, oder?

        tuples = self._fetchall(query)
        if tuples is None:
            return

Hier könnte ich ja nur ein Debug 'Rückgabe ist leer' zurück geben.

Müsste ich nicht eher hier einsteigen:

    def _fetchall(self, *query):
        if not self._fdb_lock.acquire(timeout=2):
            return
            logger.Warning('timeout in fetchall')
        try:

Und dann könnte man ja auch noch die aktuelle Load mit ausgeben (das hattest du doch in sh.py eingebaut... Ich finde es aber nicht in der Doku).

Gruß,
Hendrik

[henfri]

Danke. Wird gemacht. Melde mich.

Gesendet von meinem LT26i mit Tapatalk

[callidomus]

Hi Hendrik,

so spontan fällt mir nichts ein. Eine LogMeldung kannst Du in Zeile 383 des SQLite Plugins hinzufügen.

Vllt. hilft auch ein aktualisiertes Log.

Bis bald

Marcus

[henfri]

Hallo,

ich habe die Last jetzt deutlich unter 1 (ich hatte ein Problem mit dem Dateisystem). Trotzdem habe ich das Problem weiterhin. Hast du noch eine weitere Idee?

Oder sollte ich versuchen mal eine Warnung im Falle eines Timeout einzubauen?

Gruß,
Hendrik

[henfri]

Ok, das hilft. Danke!

Gesendet von meinem LT26i mit Tapatalk

[callidomus]

Hi Hendrik,

die Last auf Deinem System ist zu hoch. Die geht ja bis zu 4.5!
Irgendetwas auf Deinem System frisst die Ressourcen.

Wenn das Plugin nicht innerhalb von ein zwei Sekunden eine Antwort bekommt, dann gibt es None zurück.

Ich denke das System ist überlastet.

Bis bald

Marcus

[henfri]

Hallo,

ich habe seit längerem unregelmäßig diese Warnung im Log:

2014-02-07 20:33:25 WARNING  Allgemein.Stromzaehler.Momentanleistung_1min Item Allgemein.Stromzaehler.Momentanleistung_1min: problem evaluating (sh.Allgemein.Stromzaehler.Zaehlerstand()- sh.Allgemein.Stromzaehler.Zaehlerstand.db('max', '1i', '1i'))*60.0*1000.0: unsupported operand type(s) for -: 'float' and 'NoneType'
2014-02-07 21:00:01 WARNING  wunderground Item Wetter.Niederschlag_Heute: value  does not match type num. Via Logic None
2014-02-07 21:00:58 WARNING  Allgemein.Stromzaehler.Leistungsdurchschni24h Item Allgemein.Stromzaehler.Leistungsdurchschni24h: problem evaluating (sh.Allgemein.Stromzaehler.Zaehlerstand()-sh.Allgemein.Stromzaehler.Zaehlerstand.db('max', '1d', '1d'))/24*1000: unsupported operand type(s) for -: 'float' and 'NoneType'

Komisch ist dabei, dass dieses Problem sehr sporadisch auftritt -auch in der git-Version mit den aktuellen Verbesserungen im sqlite-Plugin.

Z.B. um:

2014-02-07 00:17:00
2014-02-07 00:20:17
2014-02-07 01:05:44
2014-02-07 02:20:55
2014-02-07 03:02:16
2014-02-07 03:02:16
...
2014-02-07 03:29:27
2014-02-07 04:14:09
2014-02-07 05:05:42
2014-02-07 10:52:51
2014-02-07 13:10:37
2014-02-07 13:14:52
2014-02-07 14:46:29
2014-02-07 15:25:55
2014-02-07 15:31:09
2014-02-07 15:46:56
2014-02-07 16:02:34
2014-02-07 16:39:09
2014-02-07 18:59:06
2014-02-07 19:33:24
2014-02-07 19:42:48
2014-02-07 20:33:25
2014-02-07 21:00:58

Vor 3:29 Uhr kam die Fehlermeldung mehrmals pro Minute.
Ein Debug-Log hängt an.
Hier noch die Items:

[Allgemein]
    [[Stromzaehler]]
    sv_page=Strom
    name = Strom
    visu=yes
	[[[Counter]]]
	    name = Counter
	    type = num
	    cache=yes
	    sqlite = yes
	    knx_dpt = 12
	    enforce_updates=yes
	    knx_send = 6/7/0
	    knx_listen = 6/7/0
	[[[Zaehlerstand]]]
	    name = Zaehlerstand
	    type = num
	    sqlite = yes
	    knx_dpt = 14
	    #knx_send = 6/7/1
	    eval = sh.Allgemein.Stromzaehler.Counter()/800.0
	    eval_trigger = Allgemein.Stromzaehler.Counter
    	    sv_widget={{ plot.period('p99872', 'item', 'avg', '2h',0,'','','','','','area') }}
    	    visu=yes
    [[[Momentanleistung_1min]]]
	    name = Momentanleistung_1min
	    type = num
	    sqlite = yes
	    knx_dpt = 14
	    #knx_send = 6/7/2
	    eval = (sh.Allgemein.Stromzaehler.Zaehlerstand()- sh.Allgemein.Stromzaehler.Zaehlerstand.db('max', '1i', '1i'))*60.0*1000.0
	    eval_trigger=Allgemein.Stromzaehler.Counter
    	    sv_widget={{ plot.period('p998dd71', 'item', 'avg', '2h', 0, 0,4000, ''    , '', '','area') }}
	    visu=yes
        [[[Momentanleistung_10min]]]
	    name = Momentanleistung_10min
	    type = num
	    sqlite = yes
	    knx_dpt = 14
	    knx_send = 6/7/2
	    eval = (sh.Allgemein.Stromzaehler.Zaehlerstand()- sh.Allgemein.Stromzaehler.Zaehlerstand.db('max', '11i', '10i'))*60.0*1000.0/10.0
	    eval_trigger=Allgemein.Stromzaehler.Counter
    	    sv_widget={{ plot.period('p99871', 'item', 'avg', '2h',0,0,4000, ''    , '', '','area') }}
    	    visu=yes
        [[[Momentanleistung_freq]]]
	    name = Momentanleistung_freq
	    type = num
	    sqlite = yes
	    knx_dpt = 14
	    knx_send = 6/7/3
#Frequenzzähler: Jeder Counter=1/800kWh=3600/800kws=3600/800*1000Ws; Zeit zwischen zwei Impulsen messen und dadurch teilen --> W
	    eval = 4500/sh.Allgemein.Stromzaehler.Counter.prev_age()
	    eval_trigger=Allgemein.Stromzaehler.Counter
	    enforce_updates=yes
    	    sv_widget={{ plot.period('p998dsd71', 'item', 'avg', '2h',0,0,4000, ''    , '', '','area') }}
	    visu=yes
        [[[Leistungsdurchschni24h]]]
	    name = Last
	    type = num
	    sqlite = yes
	    knx_dpt = 14
	    eval = (sh.Allgemein.Stromzaehler.Zaehlerstand()-sh.Allgemein.Stromzaehler.Zaehlerstand.db('max', '1d', '1d'))/24*1000
	    eval_trigger=Allgemein.Stromzaehler.Counter
    	visu=yes        
		[[[Leistung_Haustechnik]]]
		type=num
		sqlite=yes
		knx_dpt=9
		knx_cache=6/7/10
		[[[Verbrauch_Haustechnik]]]
		type=num
		sqlite=yes
		eval=value+sh.Allgemein.Stromzaehler.Leistung_Haustechnik()*sh.Allgemein.Stromzaehler.Leistung_Haustechnik.prev_age()/60.0/60.0
		eval_trigger=Allgemein.Stromzaehler.Leistung_Haustechnik

Hast du eine Idee, woran das liegen kann?

Gruß,
Hendrik