Kann "autocreate" leere Devices erzeugen?

Begonnen von manne44, 22 Januar 2017, 01:35:21

Vorheriges Thema - Nächstes Thema

manne44

Seit rd. zwei Monaten habe ich ständig Log-Einträge, die mir das Logfile zumüllen und auf irgendeinen Konfigurationsfehler hinweisen:
017.01.19 19:16:30 1: PERL WARNING: Use of uninitialized value in string eq at fhem.pl line 4672.
2017.01.19 19:16:35 1: Error: >< has no TYPE, but following keys: ><
2017.01.19 19:16:36 1: Error: >< has no TYPE, but following keys: ><
2017.01.19 19:16:36 1: Error: >< has no TYPE, but following keys: ><
2017.01.19 19:16:36 1: Error: >< has no TYPE, but following keys: ><
2017.01.19 19:17:12 1: PERL WARNING: Use of uninitialized value in string eq at fhem.pl line 4672.

mit dem Aufruf
{ my $all="";; foreach my $k (keys(%defs)) { $all .=":$k:  length:".length($k)."\n" } return $all }
habe ich herausgefunden, dass es einen leeren Eintrag mit leerem Typ gibt:
::  length:0
Ich erzeuge selbst aber keine Devices, vielleicht mit temporären defines, sondern alles ist in fhem.cfg definiert. Nach einigen Versuchen habe ich den Tip bekommen, daß vielleicht "autocreate" daran schuld sein könnte. Also autocreate auskommentiert und siehe da, es gibt keine solchen Log-Einträge mehr.
Frage: Ist es möglich, daß autocreate, das eigentlich für neue Devices unverzichtbar ist, solche leeren Devices erzeugt? Gibt es im Code keine Prüfung ob ein gültiger Name vorliegt, wenn es eine entsprechende Anforderung gibt?
RPI4-Buster mit SSD, RPI-Zero mit Bookworm

rudolfkoenig

Na moeglich ist alles, und sag niemals nie, aber ich wuesste nicht wie.

autocreate baut die Geraete per CommandDefine, und die setzt immer wenigstens NAME, TYPE und NR.
Btw. um genau dieses Problem zu lokalisieren gibt es neuerdings das fhemdebug Befehl.

manne44

Vielen Dank, ich habe "fhemdebug" scharf gemacht (mußte erst einmal ein Update machen), autocreate wieder aktiviert und werde mal abwarten. 2 kleine Fehler an anderer Stelle konnte ich schon korrigieren, die ich ohne "fhemdebug" nicht erkannt hatte.
RPI4-Buster mit SSD, RPI-Zero mit Bookworm

manne44

Gehört hier vielleicht nicht hin, aber kann mir jemand sagen was dieser Logfile-Eintrag bedeutet, den ich nach Anwendung von fhemdebug bei Ausgabe von SVG-Plots im TABLETUI erhalten habe.
[2017.01.22 23:31:40 1: ERROR: '' $defs entry found (before allowed_WEB AuthorizeFn)

Folgender Aufruf hat diese Ausgabe erzeugt:

fhem.cfg:
define SVG_fhemDbLog_Win_1 SVG fhemDbLog:SVG_DbLog_Win_1:HISTORY
attr SVG_fhemDbLog_Win_1 captionLeft 1
attr SVG_fhemDbLog_Win_1 room DBplots.Haus

und

<div class="container top-space">
    <div>
        <embed width="800" height="160" name="Fenster Erdgeschoß"
          type="image/svg+xml"
            src="/fhem/SVG_showLog?dev=oWD&amp;logdev=fhemDbLog&amp;gplotfile=SVG_DbLog_Win_1&amp;logfile=HISTORY&amp;pos=">
        </div>
</div>

und in SVG_DbLog_Win_1.gplot
# Created by FHEM/98_SVG.pm, 2016-11-07 18:19:16
set terminal png transparent size <SIZE> crop
set output '<OUT>.png'
set xdata time
set timefmt "%Y-%m-%d_%H:%M:%S"
set xlabel " "
set title 'Fenster Erdgeschoß'
set ytics ("WohnL" 0.6,"WohnR" 1.6,"WohnV" 2.6,"Koch" 3.6,"Bad" 4.6)
set y2tics ("WohnL" 0.6,"WohnR" 1.6,"WohnV" 2.6,"Koch" 3.6,"Bad" 4.6)
set grid
set ylabel ""
set y2label ""
set yrange [0:5]
set y2range [0:5]

#lp DbLog:fhemDbLog,predict,extend=2*60*60*24:oWD:winBad:::$val=($val=~"open"?4.8:4.2)
#lp DbLog:fhemDbLog,predict,extend=2*60*60*24:oWD:winKoch:::$val=($val=~"open"?3.8:3.2)
#lp DbLog:fhemDbLog,predict,extend=2*60*60*24:oWD:winWohnV:::$val=($val=~"open"?2.8:2.2)
#lp DbLog:fhemDbLog,predict,extend=2*60*60*24:oWD:winWohnR:::$val=($val=~"open"?1.8:1.2)
#lp DbLog:fhemDbLog,predict,extend=2*60*60*24:oWD:winWohnL:::$val=($val=~"open"?0.8:0.2)

plot "<IN>" using 1:2 axes x1y2 notitle ls l2 lw 1 with steps,\
     "<IN>" using 1:2 axes x1y2 notitle ls l2 lw 1 with steps,\
     "<IN>" using 1:2 axes x1y2 notitle ls l2 lw 1 with steps,\
     "<IN>" using 1:2 axes x1y2 notitle ls l2 lw 1 with steps,\
     "<IN>" using 1:2 axes x1y2 notitle ls l2 lw 1 with steps


Ich kann nicht erkennen, daß hier etwas falsch ist. Oder?
RPI4-Buster mit SSD, RPI-Zero mit Bookworm

rudolfkoenig

Der Log-Eintrag bedeutet, dass zu diesem Zeitpunkt der Fehler vorhanden war. Man muesste irgendwie feststellen, was davor passierte, z.Bsp. indem man "attr global loglevel 5" aktiviert, und zusaetzlich die auskommentierte Zeile in FHEM, 98_fhemdebug.pm, fhemdebug_CallFn aktiviert.

Dass das Problem durch das SVG erzeugt wird, ist moeglich, es sind aber zu viele unbekannte Komponenten (logproxy, DbLog), dass ich das sinnvoll debuggen koennte.

manne44

Ich habe mal wie geraten "loglevel 5" aktiviert und das Kommentarzeichen LOG in 98_fhemdebug.pm entfernt. Wenn ich dann die SVG-Files aufrufe, dann wird immer dieser Fehler angezeigt und davor und dahinter werden folgende Logeinträge gemacht:


2017.01.23 13:47:22 5: plotcommand: get fhemDbLog CURRENT INT 2017-01-22_14:00:00 2017-01-23_14:00:01  DbLog:fhemDbLog,predict,extend=86400:oWD:Win.SchlafL:::$val=($val=~"open"?5.8:5.2) DbLog:fhemDbLog,predict,extend=86400:oWD:Win.SchlafR:::$val=($val=~"open"?4.8:4.2) DbLog:fhemDbLog,predict,extend=86400:oWD:Win.Velux:::$val=($val=~"open"?3.8:3.2) DbLog:fhemDbLog,predict,extend=86400:oWD:Win.Wasch:::$val=($val=~"open"?2.8:2.2) DbLog:fhemDbLog,predict,extend=86400:oWD:Win.HolzL:::$val=($val=~"open"?1.8:1.2) DbLog:fhemDbLog,predict,extend=86400:oWD:Win.HolzR:::$val=($val=~"open"?0.8:0.2)
2017.01.23 13:47:22 5: Cmd: >get lp CURRENT INT 2017-01-22_14:00:00 2017-01-23_14:00:01 DbLog:fhemDbLog,predict,extend=86400:oWD:Win.SchlafL:::$val=($val=~"open"?5.8:5.2) DbLog:fhemDbLog,predict,extend=86400:oWD:Win.SchlafR:::$val=($val=~"open"?4.8:4.2) DbLog:fhemDbLog,predict,extend=86400:oWD:Win.Velux:::$val=($val=~"open"?3.8:3.2) DbLog:fhemDbLog,predict,extend=86400:oWD:Win.Wasch:::$val=($val=~"open"?2.8:2.2) DbLog:fhemDbLog,predict,extend=86400:oWD:Win.HolzL:::$val=($val=~"open"?1.8:1.2) DbLog:fhemDbLog,predict,extend=86400:oWD:Win.HolzR:::$val=($val=~"open"?0.8:0.2)<
2017.01.23 13:47:22 1: ERROR: '' $defs entry found (before allowed_WEB AuthorizeFn)
2017.01.23 13:47:22 4: lp: calling get fhemDbLog HISTORY INT 2017-01-21_14:00:00 2017-01-24_14:00:01 oWD:Win.SchlafL:::$val=($val=~"open"?5.8:5.2)
2017.01.23 13:47:22 5: Cmd: >get fhemDbLog HISTORY INT 2017-01-21_14:00:00 2017-01-24_14:00:01 oWD:Win.SchlafL:::$val=($val=~"open"?5.8:5.2)<
2017.01.23 13:47:22 4: Processing Statement: SELECT
                  TIMESTAMP,
                  DEVICE,
                  READING,
                  VALUE
                   FROM history WHERE 1=1 AND DEVICE  = 'oWD' AND READING = 'Win.SchlafL' AND TIMESTAMP >= '2017-01-21 14:00:00' AND TIMESTAMP < '2017-01-24 14:00:01' ORDER BY TIMESTAMP

Ich vermute mal, daß ich diesen Fehler gefunden habe, denn offenbar wird zuerst auf die CURRENT-Tabelle und dann auf die HISTORY-Tabelle in der DbLog zugegriffen, aber die CURRENT-Tabelle ist hier immer leer, warum, das weiß ich nicht, hat mich aber bisher auch nicht gestört. Eigentlich bin ich nach allen für mich verfügbaren Beschreibungen vorgegangen und habe wie folgt definiert:

define fhemDbLog DbLog ./db.conf (Bb]attery:.*|WDx:Door.*|WDx:Win.*|LDRx|oWD| ...
attr fhemDbLog DbLogType Current/History

und die Struktur der Datenbank ist wie folgt:

root@bpi:/opt/fhem# sqlite3 /opt/fhem/fhem.db
SQLite version 3.8.7.1 2014-10-29 13:59:56
Enter ".help" for usage hints.
sqlite> .schema
CREATE TABLE 'history' (TIMESTAMP TIMESTAMP, DEVICE varchar(32), TYPE varchar(32), EVENT varchar(512), READING varchar(32), VALUE varchar(32), UNIT varchar(32));
CREATE TABLE 'current' (TIMESTAMP TIMESTAMP, DEVICE varchar(32), TYPE varchar(32), EVENT varchar(512), READING varchar(32), VALUE varchar(32), UNIT varchar(32));
CREATE INDEX Search_Idx ON `history` (DEVICE, READING, TIMESTAMP);
CREATE TABLE frontend (ID INTEGER PRIMARY KEY, TIMESTAMP TIMESTAMP DEFAULT CURRENT_TIMESTAMP, TYPE TEXT, NAME TEXT, VALUE TEXT);

Ich habe mal das Attribut auf HISTORY geändert und der Fehler ist bei Aufruf eines SVG-Plots nicht mehr vorhanden.
attr fhemDbLog DbLogType History

Aber das dürfte hier die falsche Adresse sein, denn warum die Current-Tabelle leer ist, das sollte an anderer Stelle zu klären sein. Auch die leeren Devices, die der Grund für diese Anfrage waren, sind bisher nicht wieder aufgetaucht, vielleicht hat sie das gestrige Update "vertrieben". Ich werde das weiter beobachten und habe mit fhemdebug nun ein weiteres Hilfsmittel zur Hand.
Vielen Dank für die Hilfe.
RPI4-Buster mit SSD, RPI-Zero mit Bookworm