Support Thread zum KNX Plugin

[bmx]

Es gibt etliche Threads zum KNX Plugin aber keiner ist explizit als Support-Thread gekennzeichnet. Daher hier nun ...

[Onkelandy]

Ich weiß, dass die Frage schon mal von jemandem kam und bin nun selbst drüber gestolpert.. Spricht irgendwas dagegen, das Senden über das KNX Plugin auch im Debug Log eintragen zu lassen?

Zeile 222 würde sich das hier anbieten:

if self.logger.isEnabledFor(logging.DEBUG):
                self.logger.debug(self.translate("groupwrite telegram for: {} - Value: {} sent.").format(ga,payload))

[bmx]

Ja von mir aus bau das gerne ein.

[Msinn]

Onkelandy Wozu ist die If Abfrage

if self.logger.isEnabledFor(logging.DEBUG):

gut? Das macht doch der Logger selbst auch noch mal?

[bmx]

Das ist sinnvoll bei zeitkritischen Routinen. Die Formatanqeisungen brauchen eine gewisse Zeit um die Argumente zu formatieren und in den String einzubauen. Diesen Aufwand kann man mit der initialen If Abfrage umgehen, und die ist zeitlich gesehen billig

[Msinn]

Ok,

dann habe ich zumindest noch nichts so zeitkritisches programmiert, dass ich es benötigt hätte.


Oder meine Hardware war schneller

[bmx]

Im onewire plugin ist das häufiger drin.

[Msinn]

Die Frage die sich mir stellt ist: Das mag früher sinnvoll gewesen sein, aber ist das in aktuellen Python Versionen noch sinnvoll?

Noch bevor smarthome.py zu SmartHomeNG wurde gab es hier im Forum einen Thread der aufzeigte, dass .format() mehr Rechenzeit benötigte als z.B. die Aufbereitung mit %. Das war aber schon für Python 3.4 nur noch eingeschränkt richtig und in späteren Python Versionen lässt sich kein wirklicher Unterschied mehr feststellen.

[Morg]

Das hängt wohl weniger von der Python-Version ab, sondern mehr von der verwendeten Hardware. Ich habe hier noch einen Raspi 1, da bin ich schon froh um jedes Stück Software, was sich solche Gedanken "macht".

In vielen Punkten ist das sicher nicht notwendig, aber gerade Protokollplugins, die potenziell viele Meldungen durchschieben, sind da dankbare Kandidaten.

[Msinn]

Morg Das. Erstehe ich. Das Problem worauf ich aufmerksam gemacht habe ist, dass sich zwischen Python Versionen die Ausführungszeiten stark unterscheiden können. Eine Optimierung für eine Python Version kann später in einer neueren Python Version schon ein Nachteil sein.

Es ist also nicht sicher, dass diese If Abfrage in den aktuellen Python Versionen noch einen messbaren Vorteil bringt, da leider nicht klar ist, für welche Python Version diese Abfrage zur Optimierung eingefügt wurde.

[Morg]

Achso. Eine einfache bool-Abfrage, ein int-Vergleich oder einfache Addition, ggf. int-Multiplikation sind in der Regel die "billigsten" Operationen. Egal, wie weit String-Operationen auch in Hardware-Plattform schon optimiert sind (mit entsprechenden Schleifen-Opcodes, auf denen ja jedes Programm aufbaut), ist das immer "teuer". Das mag sich möglicherweise auch in Python von Version zu Version um Größenordnungen unterscheiden, aber es ist immer noch mindestens 1-2 Größenordnungen teurer als die o.a. elementaren Operationen.

Man könnte das ja mal timen...

[Msinn]

Die Frage ist, ob Python die format() Operation wirklich ausführt oder ob das schon wegoptimiert wird. Klassisch (und bei anderen Sprachen) bei einem Aufruf würde das format() zwar vorher berechnet, aber bei Python weiss man nie wie im Hintergrund optimiert wird. Das kann man wirklich nur timen.

[Onkelandy]

Ich hab mich über die if Abfrage auch gewundert... nehms jetzt aber einfach mal mit rein.

[bmx]

Ok, wir gehen etwas tiefer unter die Haube:

Für den Aufruf self.logger.debug( ...) müssen tatsächlich alle Argumente vorbereitet werden. Bei einem einfach String ohne Format ist das problemlos, da er ja als Konstante vorliegt. Für eine einfache Formatanweisung ist das vermutlich auch unkritisch. Wird es etwas umfangreicher, so kann das ganze schon Zeit in Anspruch nehmen, Zeit, die man im Normalfall nicht für dann überflüssige Logging-Anweisungen investieren will.
Allerdings kostet auch die Prüfung

if self.logger.isEnabledFor(logging.DEBUG):

Zeit weil dafür im Logger erstmal geschaut werden muß welcher Level denn da überhaupt aktiv ist. Insofern ist die Skepsis von Msinn natürlich absolut berechtigt.
Eigentlich sollte man das bei notwendigem mehrfachen Logging innerhalb einer Subroutine an den Anfang schieben und als lokale Variable speichern oder alternativ auch im Plugin self.LogLevel zwischenspeichern.

Das habe ich aktuell noch nicht gemacht, weil Martin das Thema Logging noch mal im Admin Interface angehen wollte und ich dann nicht alles wieder umbauen will.
Streng genommen kann ja das Logging zur Laufzeit umkonfiguriert werden und wenn ich den Logging Level im Plugin zwischenspeichere, dann wird diese Einstellung ja nicht aktualisiert.
Insofern müßte es bei jedem Plugin eine Funktion geben "UpdatePluginLoggingSettings" oder aber es müßte im SmartPlugin direkt implementiert werden.

In der Python Doku ist das Thema nochmal unter Optimierung beschrieben.

[Msinn]

Wenn es in einer Methode wirklich zeitkritisch ist, sollte am Anfang (der Methode) eine boolsche Variable gesetzt werden. Die per if abzufragen ist der schnellste Weg. Sich diese Info jedes mal aus dem Logger Objekt zu holen über isEnabledFor() oder den eingestellten Loglevel ist auf jeden Fall Rechenzeit-intensiver.

Siehe dazu auch die Note in der von bmx verlinkten Python Doku:

In some cases, [URL="https://docs.python.org/3/library/logging.html#logging.Logger.isEnabledFor"]isEnabledFor()[/URL] can itself be more expensive than you’d like ...