[Gelöst] Nicht nachvollziehbare Log-Einträge durch ein Notify

[fhem_olsi]

Hallo werte Experten!

Ich benutze FHEM nun schon seit drei Jahren, aber wenn ich das folgende Problem schildere, fühle ich mich immer noch als Anfänger. Deshalb poste ich dieses Thema in dieser Rubrik.

Also:
Ich habe ein (kleines) Notify gebastelt, das mir immer dann eine (Telegram-)Nachricht übermitteln soll, wenn von meinem BKW Strom ins externe Versorgungsnetz eingespeist wird:

Code Auswählen Erweitern

Internals:
   DEF        SML_Reader:pwr:.* {

my $x = ReadingsNum("SML_Reader","pwr","0");
my $u = ReadingsNum("SML_Reader","pwr_L1","0");
my $v = ReadingsNum("SML_Reader","pwr_L2","0");
my $w = ReadingsNum("SML_Reader","pwr_L3","0");
# &ctmLog("./log/SML_Reader.log", "$x\t$u\t$v\t$w");

if ( $x < 0 ) {
$x = -$x;
# fhem("set TG msg BKW speist $x Watt ins Stromnetz!!!");
}
}
   FUUID      67c82b9e-f33f-c887-11e4-846670a049816188
   NAME       n_SML
   NOTIFYDEV  SML_Reader
   NR         961
   NTFY_ORDER 50-n_SML
   REGEXP     SML_Reader:pwr:.*
   STATE      2025-04-01 15:35:52
   TRIGGERTIME 1743514552.42093
   TYPE       notify
   eventCount 14
   READINGS:
     2025-04-01 15:35:22   state           active
     2025-04-01 15:35:52   triggeredByDev  SML_Reader
     2025-04-01 15:35:52   triggeredByEvent pwr: -634
Attributes:
   room       EnergieRaumUm in der Experimentier-Phase nicht zu viele (gewünschte) Log-Einträge und Telegram-Nachrichten zu erhalten, habe ich die entsprechenden Zeilen auskommentiert.
   
Das Phänomen ist nun, dass ich in der Standard-)FHEM-Log-Datei Einträge folgender Art vorfinde:

Code Auswählen Erweitern

2025.04.01 15:58:52 3: n_SML return value: 94
2025.04.01 15:59:02 3: n_SML return value: 74
2025.04.01 15:59:12 3: n_SML return value: 89
2025.04.01 15:59:22 3: n_SML return value: 82   Dass die geloggten Werte den Inhalt der Variablen $x widerspiegeln, ist mir klar. Ich verstehe nur nicht, warum das überhaupt geloggt wird.

In der Konfigurations-Datei "fhem.cfg" ist

Code Auswählen Erweitern

attr global verbose 3gesetzt; nach Auskunft der "command.ref" heißt das: "3: ausgesendete Kommandos werden gelogged."
Wird hier also die Variable $x als Kommando interpretiert???

Wer weiß Rat?

Gruß Wolfgang

[betateilchen]

Du hast in Deinem perl code keinen anderen Rückgabewert vorgegeben, deshalb kommt der "letzte" verarbeitete Wert zurück.

Völlig normal.

[fhem_olsi]

Code Auswählen Erweitern

Du hast in Deinem perl code keinen anderen Rückgabewert vorgegeben, deshalb kommt der "letzte" verarbeitete Wert zurück.Dass er "zurück"kommt, war mir ja schon klar.
Aber warum er geloggt wird, nicht.
Das soll wohl also heissen, dass ein Perl-Rückgabewert von FHEM immer(?) als Kommando interpretiert wird?
Wie auch immer; ich habe jetzt diese "Effekt" durch ein Hinzufügen von einem "return" unterdrückt:

Code Auswählen Erweitern

SML_Reader:pwr:.* {

my $x = ReadingsNum("SML_Reader","pwr","0");
my $u = ReadingsNum("SML_Reader","pwr_L1","0");
my $v = ReadingsNum("SML_Reader","pwr_L2","0");
my $w = ReadingsNum("SML_Reader","pwr_L3","0");
# &ctmLog("./log/SML_Reader.log", "$x\t$u\t$v\t$w");

if ( $x < 0 ) {
$x = -$x;
# fhem("set TG msg BKW speist $x Watt ins Stromnetz!!!");
}
return;
}

[betateilchen]

Deine Annahme, dass perl code als FHEM-Kommando interpretiert wird, ist falsch.

Die Logausgabe erfolgt bewusst, um den Rückgabewert aus AnalyzeCommandChain() (ausgeführt in fhem.pl) zu protokollieren.

Code Auswählen Erweitern

my $r = AnalyzeCommandChain(undef, $exec);
Log3 $ln, 3, "$ln return value: $r" if($r);


Wie auch immer; ich habe jetzt diese "Effekt" durch ein Hinzufügen von einem "return" unterdrückt:

So macht man das ja auch, wenn man es richtig machen möchte...

[fhem_olsi]

Code Auswählen Erweitern

Deine Annahme, dass perl code als FHEM-Kommando interpretiert wird, ist falsch.
Die Logausgabe erfolgt bewusst, um den Rückgabewert aus AnalyzeCommandChain() (ausgeführt in fhem.pl) zu protokollieren.Zwar sagt der Name "AnalyzeCommandChain" ja eigentlich wörtlich übersetzt etwas über "Kommandos" aus, aber Du hast recht. Wenn ich als Rückgabewert etwas definiere, was formal aussieht wie ein FHEM-Kommando, wird es dennoch nicht als Kommando interpretiert. Aber geloggt!
Also müßte die "command.ref" hier eigentlich angepaßt werden, denn dort steht:

Code Auswählen Erweitern

verbose
Setzt den Schwellwert für die Logfile-Meldungen. Mögliche Werte sind:

    0 - Server start/stop
    1 - Fehlermeldungen oder unbekannte Pakete
    2 - bedeutende Ereigbisse/Alarme.
    3 - ausgesendete Kommandos werden gelogged.
    4 - von den einzelnen Geräten empfangene Daten.
    5 - Fehlersuche.
Bei "verbose = 3" werden eben nicht nur "Kommandos gelogged", sondern eben auch Perl-Rückgabewerte.

[betateilchen]

Ich finde das gut, so wie es ist.

Es werden auch noch ganz andere Dinge gelogged, die gemäß dieser Beschreibung in der commandref nicht in den jeweiligen Loglevel gehören. Für mich fällt das unter "künstlerische Freiheit", die jedem Entwickler von FHEM, der die Arbeit in seiner Freizeit leistet, zustehen darf.

Sei froh, dass es überhaupt verschiedene Loglevel gibt.

Punkt.

[fhem_olsi]

Sei froh, dass es überhaupt verschiedene Loglevel gibt.

Das ist - sage ich einmal sehr vorsichtig - ein sehr gewöhnungsbedürftige Aussage/Haltung.

Komma, Strich.

[Prof. Dr. Peter Henning]

Zwar sagt der Name "AnalyzeCommandChain" ja eigentlich wörtlich übersetzt etwas über "Kommandos" aus

Aber nicht über FHEM-Kommandos, sondern die Perl-Zeilen innerhalb von {} werden analysiert.

Und nein: Wir werden sicher nicht wegen einer vergleichsweise schlecht programmierten Perl-Funktion ohne expliziten Rückgabewert die CommandRef anpassen.

Auch der Aussage von betateilchen, dass man froh über veschiedene Loglevel sein sollte, schließe ich mich vorbehaltlos an.

pah

[fhem_olsi]

Irgendwie hatte ich das erwartet...

[betateilchen]

Irgendwie hatte ich das erwartet...

Dann bin ich ja froh, dass wir Deine Erwartungen vollumfänglich erfüllen konnten und der Tag doch noch gerettet werden konnte.

Laßt uns den Sonnenschein genießen!