Logging - Probleme mit dem Umgang

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
GEEN55
User
Beiträge: 10
Registriert: Mittwoch 16. Januar 2019, 13:41

Hallo,
ich habe wieder mal eine Anfängerfrage und komme mit den Informationen die ich im Netz finde nicht wirklich klar.
Ich habe folgendes Muster verwendet:

Code: Alles auswählen

import logging

logger = logging.getLogger()
handler = logging.StreamHandler()
formatter = logging.Formatter(
        '%(asctime)s %(name)-12s %(levelname)-8s %(message)s')
handler.setFormatter(formatter)
logger.addHandler(handler)
logger.setLevel(logging.DEBUG)

logger.debug('Logging DEBUG')
logger.error('Logging ERROR')
logger.warning('Logging Warning')
logger.info('Logging INFO')
logger.critical('Logging CRITICAL')
wenn ich diesen öfters laufen lassen (im SPYDER (Run file)), werden mit jeden Mal scheinbar die Meldungen "angehängt":
DEBUG:root:Logging DEBUG
2019-01-29 17:32:07,883 root DEBUG Logging DEBUG
2019-01-29 17:32:07,883 root DEBUG Logging DEBUG
2019-01-29 17:32:07,883 root DEBUG Logging DEBUG
ERROR:root:Logging ERROR
2019-01-29 17:32:07,889 root ERROR Logging ERROR
2019-01-29 17:32:07,889 root ERROR Logging ERROR
2019-01-29 17:32:07,889 root ERROR Logging ERROR
WARNING:root:Logging Warning
2019-01-29 17:32:07,889 root WARNING Logging Warning
2019-01-29 17:32:07,889 root WARNING Logging Warning
2019-01-29 17:32:07,889 root WARNING Logging Warning
INFO:root:Logging INFO
2019-01-29 17:32:07,905 root INFO Logging INFO
2019-01-29 17:32:07,905 root INFO Logging INFO
2019-01-29 17:32:07,905 root INFO Logging INFO
CRITICAL:root:Logging CRITICAL
2019-01-29 17:32:07,905 root CRITICAL Logging CRITICAL
2019-01-29 17:32:07,905 root CRITICAL Logging CRITICAL
2019-01-29 17:32:07,905 root CRITICAL Logging CRITICAL
Eigentlich möchte ich nur die Meldungen sehen die ich im jeweiligen Lauf erzeuge. Ich konnte aber keinen Weg finden dies umzusetzen.

Ich wäre sehr dankbar, wenn mir hier jemand weiterhelfen könnte,
Gruß GEEN
__deets__
User
Beiträge: 14545
Registriert: Mittwoch 14. Oktober 2015, 14:29

Spyder ist dein Problem. Damit bleibt der Python-Interpreter und all sein Zustand erhalten. Und jedes mal wenn du auf "run" drueckst, wird munter ein weiterer Handler angehangen, und dann spuckt der eben seine Zeile nochmal getrennt von den anderen aus.

Die Loesung kann zB sein, https://docs.python.org/2/library/loggi ... g.shutdown (gibt's natuerlich auf fuer Python3) aufzurufen *bevor* du dann deine Anweisungen oben ausfuehrst. Aber ACHTUNG: wenn das spaeter mal Code ist, der NICHT interaktiv ausgefuehrt wird, dann macht dir das das setup zB deiner Anwendung kaputt.
GEEN55
User
Beiträge: 10
Registriert: Mittwoch 16. Januar 2019, 13:41

Ahhh ... okay. Danke für die Antwort. Mit logging.shutdown hatte ich schon etwas "gespielt", bin aber nicht zu dem gewünschten Ergebnis gekommen. Wenn ich die Anweisung direkt nach dem Import setze, dann hat es keine Wirkung. Hingegen am Ende, wird alles "abgeschaltet" und Spyder muss erneut gestartet werden.

Vielleicht verwende ich auch grundsätzlich das falsche Tool. Ich möchte mein Coding während der Entwicklung nicht mit lauter undiffernezierten print - Anweisungen durchsetzen, sondern diese abhängig von meinen Bedürfnissen (= LogLevel) sehen.
GEEN55
User
Beiträge: 10
Registriert: Mittwoch 16. Januar 2019, 13:41

Jetzt habe ich die Lösung gefunden. Danke für den Tipp, er hat mich auf die richtige Fährte gebracht. Ich muss nur am Ende des Codings den Handler "remove"n:

Code: Alles auswählen

import logging

logger = logging.getLogger()
handler = logging.StreamHandler()
formatter = logging.Formatter(
        '%(asctime)s %(name)-12s %(levelname)-8s %(message)s')
handler.setFormatter(formatter)
logger.addHandler(handler)
logger.setLevel(logging.WARNING)

logger.debug('Logging DEBUG')
logger.error('Logging ERROR')
logger.warning('Logging Warning')
logger.info('Logging INFO')
logger.critical('Logging CRITICAL')

logger.removeHandler(handler)
Zumindest scheint es so zu funktionieren, oder ist das Blödsinn?
Benutzeravatar
__blackjack__
User
Beiträge: 14040
Registriert: Samstag 2. Juni 2018, 10:21
Wohnort: 127.0.0.1
Kontaktdaten:

@GEEN55: Also ich würde sagen das ist in soweit ”Blödsinn” als das Du für eine IDE programmierst in der sich einiges ziemlich deutlich vom Ablauf ausserhalb der IDE unterscheidet. Ich persönlich finde so eine Umgebung ist nicht für Programmentwicklung geeignet. Beziehungsweise musst Du das Programm ja sowieso regelmässig ausserhalb der IDE testen ob es denn dort auch noch funktioniert, so dass Du das *grundsätzlich* machen könntest. Also das Programm nicht in der IDE laufen lassen. Dann hast Du auch das Problem nicht an dieser Stelle um Besonderheiten von der IDE herum programmieren zu müssen.

Falls Du das so machst, solltest Du das Entfernen des Handler wirklich sicherstellen, also zum Beispiel in einen ``finally``-Zweig stecken.

Was Du Dir so auch ein bisschen verbaust ist das auslagern der Logging-Konfiguration in Konfigurationsdateien, weil Du da ja auch Logger, Formatter, und Handler konfigurieren kannst, aber keine wieder entfernen kannst am Ende.

Was Du da bis jetzt machst, müsste übrigens auch noch mit `logging.basicConfig()` möglich sein.
„A life is like a garden. Perfect moments can be had, but not preserved, except in memory. LLAP” — Leonard Nimoy's last tweet.
__deets__
User
Beiträge: 14545
Registriert: Mittwoch 14. Oktober 2015, 14:29

Wenn es nach dem shutdown nicht mehr geht, würde ich danach noch ein logging.basicConfig setzen. Das du selbst formatter und Handler setzt, ist IMHO Blödsinn. Das einzige was man normalerweise macht ist die logger selbst zu benuzten. Und ggf deren individuelle level einzustellen, wenn logging nur eines bestimmten Bereiches interessant ist. Last but not least: das spyder so funktioniert finde ich ziemlichen Unsinn. Kannst du dem nicht beibringen, bei jedem laufen lassen eine NEUEN Interpreter zu erzeugen?
GEEN55
User
Beiträge: 10
Registriert: Mittwoch 16. Januar 2019, 13:41

Danke für die Tipps und Hinweise!
GEEN55
User
Beiträge: 10
Registriert: Mittwoch 16. Januar 2019, 13:41

Ergänzung:

Im Hauptprogramm benutze ich logging nun wie folgt:

Code: Alles auswählen

import logging

# Für das Logging alles vorbereiten
# Log-Level •DEBUG •INFO •WARNING •ERROR •CRITICAL
# Format-Attribute: https://docs.python.org/3/library/logging.html#logrecord-attributes

logging.basicConfig(filename='meldungen.log', filemode='w', format='%(funcName)s:%(message)s',level=logging.DEBUG)

In den Modulen dann so

Code: Alles auswählen

import logging

    def _beispiel(self,x,y):
	....
       logging.warning("Doppelter Eintrag: %i, %i", x,y)
       ...

wobei ich bei Änderungen mit logging.basicConfig den Kernel bei Spyder neu starten muss ("ctrl + ." )
__deets__
User
Beiträge: 14545
Registriert: Mittwoch 14. Oktober 2015, 14:29

Na das geht dann ja halbwegs schnell den Interpreter neu zu starten.

Wenn du in einem Modul

logger = logging.getLogger(__name__)

machst, und den dann mit

logger.<level>(...)

benutzt, kannst du noch feingranularer steuern, welche logmessages du bekommst.
Antworten