[PATCH] Kosmetisches beim Logging von nichtdruckbaren und Steuerzeichen

[Dr. Boris Neubert]

Hallo,

anbei ein kleiner Patch, der beim Logging nichtdruckbare und Steuerzeichen maskiert.

Grüße
Boris

[rudolfkoenig]

Bin noch unetntschlossen:
1. escapeLogLine ist suboptimal: mischt Oktaldarstellung mit anderen Escapesequenzen. Und man weiss nicht, ob im String nun wirklich \n steht (zwei Zeichen) oder ein NL. Ausserdem ist es aufwendg, wenn wir es verwenden sollten, dann muessen wir verbose vorher abfangen, mit der aktuellen Implementierung wird escapeLogLine immer ausgefuehrt.
2. Events sollten mAn keine Binaerdaten/mehrzeilige Nachrichten enthalten, das fuehrt auch an anderen Stellen zum Problemen. Oder gibt es dafuer eine Notwendigkeit?

Andere Meinungen?

[Dr. Boris Neubert]

Hallo,

es lässt sich nicht ausschließen, dass ein Modul Daten (Readings, Logeinträge) mit nichtdruckbaren Zeichen oder Steuerzeichen auswirft. Anstatt in den kleinteiligen Austausch darüber mit dem Modulautoren zu gehen, würde ich darauf in fhem.pl reagieren.

Ich habe am Sonntag ECMD durchanalysiert. Dabei habe ich folgende Entscheidung getroffen: alle Daten werden immer Perl-kodiert ins Log geschrieben. Das bedeutet:
\  -> \\
\n -> \\n
...
any -> \ooo

Wenn wir das systematisch handhaben und dokumentieren, weiß man, dass \n ein LF ist und \\n Backslash-N bedeutet. In den allerwenigsten Fällen kommen diese Zeichen überhaupt in Logeinträgen und Readings vor.

Viele Grüße
Boris

[rudolfkoenig]

Ich seh schon, dir ist ernst damit.
Habs eingebaut, aber vorher wird explizit auf verbose geprueft, da ich escapeLogLine fuer teuer halte.

[Dr. Boris Neubert]

Dankeschön!

Klar ist mir ernst.  Wenn es gewünscht ist, schicke ich einen Patch auf die Commandref, die das Logging erklärt.

Ich habe mir den Sonntag den Kopf zermartert, wie ich konsequent bei Eingabe und Ausgabe mit Sonderzeichen umgehen kann, und sogar das Gegenstück zu escapeLogLine() geschrieben:

Code Auswählen Erweitern


sub
cq($)
{
  my ($s)= @_;

  $s =~ s/\\(\d)(\d)(\d)/chr($1*64+$2*8+$3)/eg;
  $s =~ s/\\a/\a/g;
  $s =~ s/\\e/\e/g;
  $s =~ s/\\f/\f/g;
  $s =~ s/\\n/\n/g;
  $s =~ s/\\r/\r/g;
  $s =~ s/\\t/\t/g;
  $s =~ s/\\\\/\\/g;

  return $s;
}

Mit cq() behandele ich Input vor, der Sonderzeichen enthalten soll. Wenn ich zum Beispiel ein Newline in einem Attribut haben möchte, geht das jetzt einfach so:

attr myECMD split \n

Anregung zur Diskussion: das wird generell im CommandAttr eingebaut.

Ich maskiere außerdem potentiell nicht druckbare Zeichen und Steuerzeichen enthaltene Sequenzen mit dq():

Code Auswählen Erweitern

sub
oq($)
{
  my ($s)= @_;
  return join("", map { sprintf("\\%03o", ord($_)) } split("", $s));
}

sub
dq($)
{
  my ($s)= @_;
  return defined($s) ? escapeLogLine($s) . " (" . oq($s) . ")" : "<nothing>";
}


Das schreibt die Sequenz perl-kodiert hin, gefolgt von der Oktalkodierung. Aus CRLF wird dann im Log

Code Auswählen Erweitern

\r\n (\015\012)

Wir können auch eine Abstimmung unter den Entwicklern durchführen, ob CommandAttr das Attribut als Perl-kodiert verstehen soll und ob wir escapeLogLine() bzw. dq() verbindlich machen (ich vermute, es wären nur ganz wenige Module von der Umstellung betroffen wären).

Viele Grüße
Boris

[Dr. Boris Neubert]

goto https://forum.fhem.de/index.php/topic,61566.0.html

[rudolfkoenig]

Liegt auf dem TODO-Stack, ist aber nicht trivial: was passiert mit Newline (bisher mit \ geschrieben, usw.).

[herrmannj]

kann ich danach noch so (multiline) ins log schreiben ? :

Code Auswählen Erweitern

2016.12.05 10:31:20.009 3: (bl:) *** EXTRA DEBUG INFO ***
name: FHLib_9A788EF3 id:enumHCI ref: PipedSysProc=HASH(0xa833a00)
FHEM/FHLib.pm #993: PipedSysProc as Core::getElementByID
get hciconfig -a as COMMAND (TYPE: FHLib_CORE)
2016.12.05 10:31:20.017 3: (bl:) *** EXTRA DEBUG INFO ***
name: FHLib_9A788EF3 id:enumHCI ref: PipedSysProc=HASH(0xa833a00)
FHEM/FHLib.pm #1000: PipedSysProc as Core::setElementByID
store 25809 as PID
2016.12.05 10:31:20.017 3: (bl:) *** EXTRA DEBUG INFO ***
name: FHLib_9A788EF3 id:enumHCI ref: PipedSysProc=HASH(0xa833a00)
FHEM/FHLib.pm #1005: PipedSysProc as Core::getElementByID
get 25809 as PID (TYPE: FHLib_CORE)
2016.12.05 10:31:20.017 3: (bl:) do hciconfig -a with PID 25809

[rudolfkoenig]

Falsche Frage, da wird ueber fhem.cfg diskutiert, nicht fhem.log, und die hier besprochene Aenderung betrifft konkrete Meldungen aus DoTrigger und Dispatch, nicht generell alle Logs. Aber vlt. will Boris die auch noch behandeln

[herrmannj]

sorry. Hatte mich vom "logging" in der Überschrift irritieren lassen.

[Dr. Boris Neubert]

Zum Logging ist mein Petitum, dass sich der Programmierer des Moduls beim Absondern des Eintrags mit Log3 blabla darum kümmert, dass Steuerzeichen etc. maskiert werden. Wie er das allerdings tut würde ich reglementieren wie oben mit der Funktion dq() gezeigt.

[Dr. Boris Neubert]

Liegt auf dem TODO-Stack, ist aber nicht trivial: was passiert mit Newline (bisher mit \ geschrieben, usw.).

Hast Du bitte Beispiele für die Sonderfälle?

[rudolfkoenig]

Nicht wirklich Sonderfall:

define n1 notify xy {\
  if(Value(...)) {\
...
  }\
}

oder meinst Du was anderes?

[Dr. Boris Neubert]

Hallo,

ich bezog mich auf Deine Frage, was mit Newline passiere, also mit dem Backslash am Ende der Zeile, mit der eine Fortsetzungszeile angezeigt wird. Ich habe mir das jetzt angesehen und verstanden, dass in diesen Fall vermutlich statt eines Zeilenbruchs mit vorgeschaltetem Backslash zur Kennzeichnung der Fortsetzungszeile ein \n rausgeschrieben würde. Das ist nicht im Sinne des Nutzers, der den Text so in die fhem.conf geschrieben hat, weil er den Text dort formatiert sehen möchte. Könnte jetzt sagen, dass solche Anwender sowieso nicht den Save-Knopf nutzen. Aber nein, das gefällt mir auch nicht.

Darüber muss ich nachdenken.

Grüße
Boris