Logging

[frabron]

Hallo,

ich würde gerne für ein Package logging implementieren. Was eigentlich trivial erscheint stellt mich doch vor einige Probleme. Denn wie erstellt man am besten ein flexibles, optionales Loggingsystem für ein Package? Irgendwo muss ja definiert werden, wohin geloggt werden soll, und ob überhaupt. Hat dann jede Klasse ein log-Attribut, jede Funktion einen log-Parameter, der bestimmt, ob geloggt werden soll? Und schreibt man dann an jeder interessanten Stelle (für eine Klasse z.B.):

Code: Alles auswählen

if self.log:
    logger.info('Foobar')

oder geht man das anders an? Ich habe mir schon zu diesem Zweck mal Flask und SQLAlchemy angesehen, aber diese Projekte sind mir schon wieder zu gross um zu erkennen, wie das da intern gehandhabt wird. Zumindest bei SQLAlchemy meine ich an einigen Stellen (Z. 1199) solche Abfragen gesehen zu haben.
Und wie definiert man am besten eine Ausgabequelle für das Logging? Das will man ja eigentlich nur einmal machen müssen. Im __init__.py eine Modulvariable setzen, die dann vom logging ausgewertet wird? Ist das für einen Nutzer eine zumutbare Konfigurationsmöglichkeit?

Code: Alles auswählen

# __init__.py
import sys

log_out = None

Code: Alles auswählen

# Nutzerskript
import package
package.log_out = '/foo/bar'

Was muss man beachten, damit man das logging von anderen Paketen, die evt. benutzt werden, nicht kaputt macht? Ich habe diesbezüglich eine Warnung bei SQLAlchemy gelesen. Im CookBook steht ja auch, dass der Logger ja immer derselbe innerhalb eines Prozesses ist.

Multiple calls to logging.getLogger('someLogger') return a reference to the same logger object. This is true not only within the same module, but also across modules as long as it is in the same Python interpreter process.

Solange man seine Packages im Homedir hat, kann man ja einfach loggen, doch sobald man eine systemweite Installation des Packages vorsehen will, muss man doch mehr aufpassen, als ich anfangs gedacht habe. Allein das der logger prozessweit immer derselbe ist, hat mich schon verwirrt, ist das doch erst einmal konträr zu meinen Erfahrungen mit Pythons Modulsystem.

Mir ist klar, dass es da kein allgemeingültiges Rezept gibt, aber zumindest einige Ansätze muss es doch geben. Ich glaube, mein größtes Problem ist die Package-weite Konfiguration der Ausgabequelle - da habe ich irgendwie überhaupt keinen Ansatz zu.

[JonasR]

Lies dir einfach mal das hier durch: http://docs.python.org/howto/logging.ht ... g-tutorial
Wäre dir auch aufgefallen wenn du die Doku zum logging-Modul angeschaut hättest

[BlackJack]

@frabron: Kennst Du nun das `logging`-Modul aus der Standardbibliothek oder nicht!? Ist mir bei den Fragen nicht so ganz klar geworden. Denn wie man das alles flexibel konfiguriert steht eigentlich in der Doku. Das Modul kann einiges, inklusive Konfiguration über Config-Dateien.

Ich sehe auch nicht was die API mit dem sonstigen Verhalten von Modulen zu tun hat. Wenn man `getLogger()` mehrmals mit dem gleichen Argument aufruft, erhält man halt immer das selbe Objekt als Ergebnis. Egal aus welchem Modul man aufruft. Du wunderst Dich doch auch nicht, dass Du von `math.sin()` bei gleichem Argument das selbe Objekt zurück bekommen kannst, egal aus welchem Modul Du die Funktion aufrufst.

[snafu]

@frabron: Wenn du nicht auf dem "allgemeinen" Logger arbeiten willst, dann erstell dir einen mit eigenem Namen, der von deinen Klassen und Funktionen genutzt wird. Das Logger-Objekt holst du dir dann jeweils mit `logging.getLogger('dein_logger')`. Hat man mehrere Module bzw sehr viele Stellen, wo man den Logger später einsetzen will, so möchte man vielleicht ein bißchen abstrahieren, um direkt loggen zu können, ohne den Namen des Loggers kennen zu müssen. Als Beispiel hier mal meine Verwendung des `logging`-Moduls innerhalb von `launchit`. Wobei ich als Hinweis erwähnen möchte, dass ich bisher nur ins Terminal schreibe und das Ganze vielleicht zum Teil noch etwas "prototypartig" anmutet. In Dateien loggen ist allerdings recht trivial und auch gut in der Doku des `logging`-Moduls beschrieben. Wie du siehst, kann die Initialisierung des Loggers bei mir einmalig mittels `logger.enable()` erfolgen. Module, die den Logger später verwenden möchte, machen einfach ein `import logger` und schreiben direkt mit `logger.info()` usw ihre Meldungen.

[snafu]

Allein das der logger prozessweit immer derselbe ist, hat mich schon verwirrt, ist das doch erst einmal konträr zu meinen Erfahrungen mit Pythons Modulsystem.

Das kann ich eigentlich nicht nachvollziehen. Importierte Module sind mehr oder weniger sowas ähnliches wie Exemplare von Klassen. Solange du kein `reload()` benutzt, wird dir ein Import an mehreren Stellen immer das selbe Objekt zurückgeben:

Code: Alles auswählen

>>> import sys
>>> sys.my_test_name
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
AttributeError: 'module' object has no attribute 'my_test_name'
>>> sys.my_test_name = 'spam'
>>> import sys as sys2
>>> sys2.my_test_name
'spam'
>>> sys2 is sys
True

[frabron]

Ja, nein, ich kenne das logging Modul von Python und habe es auch schon benutzt. Mein Problem ist wohl eher konzeptioneller Art. Vermutlich ist das auch alles eher trivial, aber ich stehe da wohl auf dem Schlauch. Ich versuche das mal, etwas anders zu formulieren.

Package lg:

Code: Alles auswählen

# __init__.py
import logging

logger = logging.getLogger('lg')
logger.info('__init__.py')

# a.py
import logging
logger = logging.getLogger('lg')
logger.info('a.py')

Und nun das Nutzerskript:

Code: Alles auswählen

import logging

logging.basicConfig(filename='lg.log', level=logging.INFO)

logger = logging.getLogger('lg')
logger.info('logtest.py')

import lg
import lg.a

Ergibt folgendes Logfile

Code: Alles auswählen

INFO:lg:logtest.py
INFO:lg:__init__.py
INFO:lg:a.py

Unschön hierbei ist imo das das Logging vor dem Import des package konfiguriert werden muss. Meine eigentliche Frage ist eigentlich auch schon: wie geht das besser/schöner?

[frabron]

Anstatt hier soviel zu schwafeln lieber mehr ausprobieren:

Code: Alles auswählen

# __init__.py
import logging

logger = logging.getLogger(__name__)

def bar():
    logger.info('__init__')

# a.py
import logging
logger = logging.getLogger(__name__)

def foo():
    logger.info('a.foo()')

# userscript
import logging
import lg
import lg.a

lg_logger = logging.getLogger('lg')
lg_logger.setLevel(logging.INFO)
lg_logger.addHandler(logging.FileHandler('lg.log'))

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
logger.addHandler(logging.FileHandler('logtest.log'))
logger.debug('does this work?')


lg.bar()
lg.a.foo()

tut was soll. Wenn ich jetzt noch den lg_logger in ein Modul von lg auslagere (wie bei snafus Beispiel) sollte das für mich ausreichend funktionieren. Manchmal steht man sich echt selbst im Weg