Warnings in Log-File abstellen

[MarkusAutomaticus]

Hallo zusammen,

mein system log strotzt vor Warnings von dieser Sorte:

Code Auswählen Erweitern

2016.10.02 17:20:41 3: eval: $fld[3]=~"open"?1:0
2016.10.02 17:20:41 1: PERL WARNING: Use of uninitialized value $fld[3] in pattern match (m//) at (eval 10580) line 1, <GEN25015> line 1005.
2016.10.02 17:20:41 3: eval: $fld[3]=~"open"?1:0
2016.10.02 17:20:41 1: PERL WARNING: Use of uninitialized value $fld[3] in pattern match (m//) at (eval 10582) line 1, <GEN25015> line 1007.
2016.10.02 17:20:41 3: eval: $fld[3]=~"open"?1:0
2016.10.02 17:20:41 1: PERL WARNING: Use of uninitialized value $fld[3] in pattern match (m//) at (eval 10587) line 1, <GEN25015> line 1012.
2016.10.02 17:20:41 3: eval: $fld[3]=~"open"?1:0
2016.10.02 17:20:41 1: PERL WARNING: Use of uninitialized value $fld[3] in pattern match (m//) at (eval 10589) line 1, <GEN25015> line 1014.
2016.10.02 17:20:41 3: eval: $fld[3]=~"open"?1:0
2016.10.02 17:20:41 1: PERL WARNING: Use of uninitialized value $fld[3] in pattern match (m//) at (eval 10594) line 1, <GEN25015> line 1019.
2016.10.02 17:20:41 3: eval: $fld[3]=~"open"?1:0
2016.10.02 17:20:41 1: PERL WARNING: Use of uninitialized value $fld[3] in pattern match (m//) at (eval 10596) line 1, <GEN25015> line 1021.
2016.10.02 17:20:41 3: eval: $fld[3]=~"open"?1:0
2016.10.02 17:20:41 1: PERL WARNING: Use of uninitialized value $fld[3] in pattern match (m//) at (eval 10601) line 1, <GEN25015> line 1026.
2016.10.02 17:20:41 3: eval: $fld[3]=~"open"?1:0
2016.10.02 17:20:41 1: PERL WARNING: Use of uninitialized value $fld[3] in pattern match (m//) at (eval 10603) line 1, <GEN25015> line 1028.
2016.10.02 17:20:41 3: eval: $fld[3]=~"open"?1:0
2016.10.02 17:20:41 1: PERL WARNING: Use of uninitialized value $fld[3] in pattern match (m//) at (eval 10608) line 1, <GEN25015> line 1033.
2016.10.02

Dem Anschein nach, handelt es sich um eine Plot-Definition.
Allerdings werde ich weder aus den Zeilennummern noch aus den anderen Dingen wie (eval 10608) line 1, <GEN25015> schlau.
Zu welchem Plot/SVG gehört die Warnung?
Wie bekomme ich das sauber?
Falls das nicht glattgezogen werden kann/muss, wie bekomme ich die Warning im Log unterdrückt?

Gruß
Markus

[betateilchen]

Du solltest Dich nicht um die Zeilennummern kümmern, sondern um die im Log festgehaltenen Inhalte.

Code Auswählen Erweitern

$fld[3]=~"open"?1:0

Irgendwo versuchst Du ein device zu plotten, das eventuell den Zustand "open" haben könnte. Nun musst Du Dir nur noch anschauen, welche Plots das sein könnten.

Manchmal ist es auch hilfreich, stacktrace zu aktivieren, um mehr Informationen zu bekommen.

[KölnSolar]

Der Log-Auszug ist ja nur von einer Sekunde ! Wäre es ein Plot, würde die Meldung ja immer genau dann auftreten, wenn Du den fehlerhaften Plot aufrufst. Also eigentlich einfach zu identifizieren. Ich spekuliere au ein ähnliches Problem, das bei mir mit Nutzung des RPI_GPIO Moduls auftritt:
https://forum.fhem.de/index.php/topic,51806.msg488077.html
Grüße Markus

[MarkusAutomaticus]

Der Log-Auszug ist ja nur von einer Sekunde !

Der Log-Auszug ist genau das: ein Auszug.
Ich wollte niemanden mit seitenlangen gleichlautenden Log-Zeilen langweilen.

Du solltest Dich nicht um die Zeilennummern kümmern, sondern um die im Log festgehaltenen Inhalte.

Code Auswählen Erweitern

$fld[3]=~"open"?1:0

Mein Verständnis von einem guten Log ist nicht nur auf den Fehler aufmerksam gemacht zu werden, sondern auch, wo dieser zu finden ist.

In etwa so:

Code Auswählen Erweitern

<timestamp> <source file name> <line number> <error level> konkrete Ursache

Dann weiß ich, dass um 7:14 in der Datei foobar.cpp in Zeile 4711 ein fataler Fehler einer bestimmten Ausprägung aufgetreten ist, kann ohne weitere Nachforschungen dorthin gehen und nach dem Rechten sehen.

Gruß
Markus

[marvin78]

Den Hinweis mit stacktrace hat du gelesen? Bitte den Hinweisen folgen. Dann gibt es auch weniger zu meckern.

Es handelt sich hier im Übrigen nicht um einen fatalen Fehler. Das steht aber auch konkret da.

[KölnSolar]

Ich wollte niemanden mit seitenlangen gleichlautenden Log-Zeilen langweilen.

Das ist ja auch Ok, doch genau der Hinweis "seitenlang", was ich als permanent interpretiere, fehlte. Dann liegt es eben auch nicht an einer Plotdefinition bzw. Datenfehlern. Zur Eingrenzung: Was läuft denn bei Dir permanent ?

[MarkusAutomaticus]

Den Hinweis mit stacktrace hat du gelesen? Bitte den Hinweisen folgen. Dann gibt es auch weniger zu meckern.

Es handelt sich hier im Übrigen nicht um einen fatalen Fehler. Das steht aber auch konkret da.

Ja, ich habe per

Code Auswählen Erweitern

attr global stacktrace 1

den stacktrace aktiviert. Wo landet das Ergebnis? Im system.log habe ich bisher nichts gefunden.
den String

Code Auswählen Erweitern

$fld[3]=~"open"?1:0 habe ich in 4 Plot files gefunden.

Die Frage ist, um welches davon es sich handelt.
Das es "nur" Warnings sind, ist mir schon klar. der Fatale Fehler war nur ein Beispiel, wie ich Log-files kenne.

Gruß
Markus

[marvin78]

Bitte die commandref dazu befragen. Wo stacktrace landet ist dann klar. Natürlich im FHEM-Log.

[Pfriemler]

Könnte ein Plot sein, aber auch irgendein anderes Vorkommen von $fld[]. Die Fehlermeldung dürfte auftreten, wenn der ausgewertete String (er wird an Leerzeichen in seine Bestandteile zerlegt) weniger als 4 Bestandteile enthält. Das ist ein Klassiker, wenn bspw. bei einem SVG in einer ausgewertten Logdatei plötzlich Zeilen auftauchen, auf die das Regex auch zutrifft. Dazu genügt eine unbedachte Änderung des Regex für's FileLog ...

Beispiel aus einem HM-Sec-SCo-Log:

Code Auswählen Erweitern

2016-02-28_18:25:36 HM_37BA9F contact: closed (to CCU2)
2016-02-28_18:25:36 HM_37BA9F closed

Triggerst Du im SVG auf "HM_37BA9F" statt auf "HM_37BA9F.contact", dann läuft $fld[3] in diesem Fall ins leere, weil in der zweiten Zeile nach 0 (Datum), 1(HM_37BA9F) und 2 (closed) 3 leer bleibt...
Jm2c.
Viel Erfolg beim Suchen.

[MarkusAutomaticus]

Bitte die commandref dazu befragen. Wo stacktrace landet ist dann klar. Natürlich im FHEM-Log.

Ok, tatsächlich! Ich habe einen Stacktrace hinter jeder Warning:

Code Auswählen Erweitern

2016.10.05 18:52:18 1: PERL WARNING: Use of uninitialized value $fld[3] in pattern match (m//) at (eval 20571) line 1, <GEN831> line 346.
2016.10.05 18:52:18 3: eval: $fld[3]=~"open"?1:0
2016.10.05 18:52:18 3: stacktrace:
2016.10.05 18:52:18 3:     main::__ANON__                      called by (eval 20571) (1)
2016.10.05 18:52:18 3:     (eval)                              called by ./FHEM/92_FileLog.pm (798)
2016.10.05 18:52:18 3:     main::FileLog_Get                   called by fhem.pl (3221)
2016.10.05 18:52:18 3:     main::CallFn                        called by fhem.pl (1666)
2016.10.05 18:52:18 3:     main::CommandGet                    called by fhem.pl (1084)
2016.10.05 18:52:18 3:     main::AnalyzeCommand                called by ./FHEM/01_FHEMWEB.pm (2261)
2016.10.05 18:52:18 3:     main::FW_fC                         called by ./FHEM/98_SVG.pm (1153)
2016.10.05 18:52:18 3:     main::SVG_getData                   called by ./FHEM/98_SVG.pm (1121)
2016.10.05 18:52:18 3:     main::SVG_doShowLog                 called by ./FHEM/98_SVG.pm (1012)
2016.10.05 18:52:18 3:     main::SVG_showLog                   called by ./FHEM/01_FHEMWEB.pm (754)
2016.10.05 18:52:18 3:     main::FW_answerCall                 called by ./FHEM/01_FHEMWEB.pm (455)
2016.10.05 18:52:18 3:     main::FW_Read                       called by fhem.pl (3221)
2016.10.05 18:52:18 3:     main::CallFn                        called by fhem.pl (671)

D.h. man schaut jetzt in /FHEM/92_FileLog.pm Zeile 798 ?

da steht:

Code Auswählen Erweitern

   } else {                              # evaluate
        $cmdFromAnalyze = $h->{fn};
        $val = eval($cmdFromAnalyze);
        $cmdFromAnalyze = undef;

      }


Ok, da ist also dieses eval Und nu?
Den Debugger anwerfen? Ich kenne mich mit Perl praktisch nicht aus.
Jeder hat man meinen größten Respekt, der in Perl programmiert.
Für mich kommt die Verständlichkeit der Syntax nahe an die von Assembler ran 

Gruß
Markus

[KölnSolar]

Den Plot, der Probleme macht, kennst Du jetzt ? Sollte sich doch einfach ermitteln lassen. Und dann würde ich nicht debuggen, sondern mir das zugrundeliegende Log ansehen. Pfriemler hat ja schon beschrieben, worauf Du achten musst.