"Logging" mit mehreren Modulen

Wenn du dir nicht sicher bist, in welchem der anderen Foren du die Frage stellen sollst, dann bist du hier im Forum für allgemeine Fragen sicher richtig.
Antworten
Benutzeravatar
Sophus
User
Beiträge: 1109
Registriert: Freitag 25. April 2014, 12:46
Wohnort: Osnabrück

Hallo Leute,

hier im Forum haben mich einige Programmierer darauf hingewiesen, dass man auf Print-Anweisungen verzichten, und sich dem Logging-Modul widmen solle. Der Hinweis ist berechtigt. Nun beschäftige ich mich mit dem Thema, aber kam gleich zu Beginn auf eine Frage. Wie protokolliere ich bestimmte Information von mehreren Modulen aus? Ein jedes Projekt kommt nicht drumherum mehrere eigene Module anzulegen, wenn man seine Funktionen und Klassen auslagern will/muss, damit dies auch übersichtlich bleibt. Nun möchte ich dies nicht nur protokollieren, sondern diese Ereignisse auch in eine Datei hinterlegen. Zum Beispiel, wenn ein Anwender Probleme mit meiner Software hat, kann ich ja die Log-Datei einsehen und feststellen, wo das Problem liegt bzw. unter welchen Bedingungen oder unter welchem Verhalten dieses Problem auftrat.

Dazu habe ich mir ein (ungetestetes) Beispiel überlegt, und hätte gern gewusst, ob dies ein falscher Ansatz sei?

Zunächst dachte ich mir, ich lege ein zentrales Python-Modul an, namens my_logger.py. Dort ist eine Central_Logger()-Klasse, die vom "object" abgeleitet wird. Hier wird logging configuriert. Zum Beispiel in welche Datei geschrieben werden soll, und welche Level verwendet werden sollen. Dann habe ich ein weiteres unabhängiges Modul namens example_module.py Dort wird beispielsweise eine Funktion definiert, die bestimmte Probleme bewerkstelligen soll. Beim Aufruf dieser Funktion soll etwas gemacht werden, und dabei wird protokolliert. Und diese Protokolle gehen dann zurück zur Central_Logger()-Klasse, und wird dann in die Log-Datei geschrieben. Damit ich mich nicht um das Schließen der Datei kümmern muss, bediene ich mich hier der With-Anweisung. Das war meine Idee. Mir geht es also darum, zu überlegen, wie ich bei mehreren Modulen das Logging anwenden kann, und diese Informationen in eine Datei schreiben kann, ohne dass diese Datei von unterschiedlichen Module aus jedesmal erneut geöffnet wird. Wenn man am Ende - sagen wir mal - 100 Module hat, dann wird es mit dem Öffnen und Schreiben der Log-Datei sehr unübersichtlich und dazu auch unkontrolliert.

my_logger.py

Code: Alles auswählen

import logging

class Central_Logger(object):
    def __init__(self):

        LOG_FILENAME = 'PATH/TO/YOUR/LOGFILE.txt'
        logging.basicConfig(filename=LOG_FILENAME,
                            level=logging.DEBUG,
                            level=logging.WARNING,
                            level=logging.INFO,
                            level=logging.ERROR,
                            level=logging.CRITICAL
                            )

        self.logr = logging.getLogger('root')

        with open(LOG_FILENAME, 'a') as log_file:
            data = log_file.write(self.logr)

            # do something with data

example_module.py

Code: Alles auswählen

from my_logger import Central_Logger

def do_somethink(a, b):
    Central_Logger.logr.info("The function (do_somethink is called")
    Central_Logger.logr.info("The calculation starts")
    result = a*b
    Central_Logger.logr.info("The calculation is complete. The result is %s") & result
    Central_Logger.logr.info("Return the result of the calculation") & result
    return result
DasIch
User
Beiträge: 2718
Registriert: Montag 19. Mai 2008, 04:21
Wohnort: Berlin

Der Klassenname entspricht nicht PEP 8 und die Klasse selbst ist vollkommen unnötig. Was auch immer du glaubst in Central_Logger.__init__ zu tun, du tust es nicht. Schau dir die logging Dokumentation nochmal an. Wenn in der Realität die Nachrichten die du loggst genauso aussehen wie in deinem Beispiel, kannst du es auch eigentlich ganz sein lassen.

Ich würde dir empfehlen diesen Talk [Slides usw.] anzuschauen, zumindest ab dem Teil den ich verlinkt hab, um einen Eindruck davon zu bekommen wie ein Log oder zumindest die produzierten Nachrichten aussehen sollten, damit du etwas hast was sich gut durchsuchen und analysieren lässt.
BlackJack

Das kompiliert nicht mal: SyntaxError: keyword argument repeated :roll:
Benutzeravatar
Sophus
User
Beiträge: 1109
Registriert: Freitag 25. April 2014, 12:46
Wohnort: Osnabrück

In meinem ersten Beitrag stand ungetestet. Es sollte mehr oder weniger ein Pseudo-Programm sein, um meine Gedanken zu demonstrieren.
Benutzeravatar
jens
Python-Forum Veteran
Beiträge: 8502
Registriert: Dienstag 10. August 2004, 09:40
Wohnort: duisburg
Kontaktdaten:

Ich hätte da auch einen Wunsch, das man die Konfiguration des Logging auf einen einfacheren Weg per CLI machen kann...

GitHub | Open HUB | Xing | Linked in
Bitcoins to: 1JEgSQepxGjdprNedC9tXQWLpS424AL8cd
Benutzeravatar
Sophus
User
Beiträge: 1109
Registriert: Freitag 25. April 2014, 12:46
Wohnort: Osnabrück

Die Frage bzw. der Gedanke meines ersten Beitrages hat sich erübrigt. Jedoch habe ich eine kleine Frage, die sich aus zwei Fragen zusammensetzen. Das Protokollieren klappt bei mir wunderbar, allerdings werden Informationen protokolliert, die ich gar nicht angegeben habe. Hier ein kleiner Ausschnitt:
2015-08-26 18:52:27,763 - PyQt4.uic.uiparser - DEBUG - UI version is 4.0
2015-08-26 18:52:27,763 - PyQt4.uic.uiparser - DEBUG - uiname is MainWindow
2015-08-26 18:52:27,763 - PyQt4.uic.uiparser - DEBUG - toplevel widget is MDI_Window
2015-08-26 18:52:27,765 - PyQt4.uic.properties - DEBUG - setting property geometry
2015-08-26 18:52:27,766 - PyQt4.uic.properties - DEBUG - setting property font
2015-08-26 18:52:27,766 - PyQt4.uic.properties - DEBUG - setting property windowTitle
2015-08-26 18:52:27,767 - PyQt4.uic.properties - DEBUG - setting property windowIcon
2015-08-26 18:52:27,780 - PyQt4.uic.properties - DEBUG - setting property autoFillBackground
2015-08-26 18:52:27,780 - PyQt4.uic.properties - DEBUG - setting property styleSheet
2015-08-26 18:52:27,782 - PyQt4.uic.properties - DEBUG - setting property toolButtonStyle
2015-08-26 18:52:27,782 - PyQt4.uic.properties - DEBUG - setting property animated
2015-08-26 18:52:27,782 - PyQt4.uic.properties - DEBUG - setting property tabShape
2015-08-26 18:52:27,782 - PyQt4.uic.uiparser - DEBUG - push MDI_Window MainWindow
2015-08-26 18:52:27,783 - PyQt4.uic.uiparser - DEBUG - push QWidget centralwidget
2015-08-26 18:52:27,786 - PyQt4.uic.properties - DEBUG - setting property geometry
2015-08-26 18:52:27,786 - PyQt4.uic.uiparser - DEBUG - push QMdiArea mdiArea
2015-08-26 18:52:27,786 - PyQt4.uic.uiparser - DEBUG - pop widget QMdiArea mdiArea
2015-08-26 18:52:27,786 - PyQt4.uic.uiparser - DEBUG - new topwidget <PyQt4.QtGui.QWidget object at 0x03A3B8A0>
2015-08-26 18:52:27,786 - PyQt4.uic.uiparser - DEBUG - pop widget QWidget centralwidget
2015-08-26 18:52:27,788 - PyQt4.uic.uiparser - DEBUG - new topwidget <xarphus.frm_mdi.MDI_Window object at 0x03A14DB0>
2015-08-26 18:52:27,789 - PyQt4.uic.properties - DEBUG - setting property geometry
Wir sehen hier, dass PyQt4-Informationen mit protokolliert werden. Man liest hier, welchen Klassen und QT-Objekte gestartet wurden. Nun frage ich mich, ob man das als Entwickler so belassen sollte? Es kann ja sein, dass einige von euch meinen, dass diese Informationen eher irrelevant seien. Und dann die zweite Frage. Wenn diese Protokolle von Seiten PyQt4 "unnötig" wären, wie kann man das abschalten?
Benutzeravatar
jens
Python-Forum Veteran
Beiträge: 8502
Registriert: Dienstag 10. August 2004, 09:40
Wohnort: duisburg
Kontaktdaten:

Du must halt "PyQt4.*" filtern.

GitHub | Open HUB | Xing | Linked in
Bitcoins to: 1JEgSQepxGjdprNedC9tXQWLpS424AL8cd
BlackJack

@jens: Na oder das so konfigurieren das die halt nicht ausgegeben werden. Also Beispielsweise nicht bei `basicConfig()` DEBUG für *alle* Logger setzen sondern nur den eigenen auf diesen Level setzen.
Benutzeravatar
Sophus
User
Beiträge: 1109
Registriert: Freitag 25. April 2014, 12:46
Wohnort: Osnabrück

Ich lese also zwischen den Zeilen heraus, dass die Informationen von Seiten PyQt "unwichtig" sind, und man die Informationen nicht unbedingt protokollieren muss?

Bei mir sieht das Protokollieren wie folgt aus:

Code: Alles auswählen

def create_log_file(log_file_path):

    logging.basicConfig(filename=log_file_path, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s', level=logging.DEBUG)
Wie BlackJack zurecht vermutet hat, ist bei mir der/das Level auf DEBUG gesetzt. Laut Dokumentation gibt es insgesamt fünf Level: DEBUG, INFO, ERROR, WARNING, CRITICAL. Die beiden Level DEBUG und INFO sind dazu aufgelegt sehr detaillierte Protokolle zu führen. Aber inwiefern legt man sich einen eigenen Logger auf den DEBUG-Level fest?
Benutzeravatar
Sophus
User
Beiträge: 1109
Registriert: Freitag 25. April 2014, 12:46
Wohnort: Osnabrück

Ich war etwas voreilig. Mit etwas Lesen der Dokumentation kam ich jetzt auf dieses Ergebnis:

Code: Alles auswählen

import logging


def set_custom_logger():
    app_info = info_app()
    logger = logging.getLogger(app_info.dict_info["My_Example_Application"])
    return logger

def create_log_file(log_file_path):

    # Call set_custom_logger()-function to get
    # the name of own logger
    custom_logger = set_custom_logger()

    # Create logger with 'spam_application'
    custom_logger.setLevel(logging.DEBUG)
    # Create file handler which logs even debug messages
    handle_file = logging.FileHandler(log_file_path)
    handle_file.setLevel(logging.DEBUG)

    # First, create formatter, after then create formatter.
    # Now formate the time in: year, month, day, hour, minute, secoond
    # Then add the datefmt parameter at the end to the format (Formatter) for the Rotating FileHandler.
    formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s', datefmt='%Y-%m-%d-%H:%M:%S')
    # add formatter to the handlers
    handle_file.setFormatter(formatter)
    # add the handlers to the logger
    custom_logger.addHandler(handle_file)
In diesem Zuge habe ich auch gleich die Zeit formatiert. Mich interessieren zum Beispiel die Millisekunden überhaupt nicht. In der Physik mögen diese Einheiten von Bedeutung sein, aber ich glaube und hoffe, dass Millisekunden in der Programmierung weniger wichtig sind.
Antworten