Logging-Beispiele

Erstellen einer Log-Datei

[1]:
import logging


logging.warning("This is a warning message")
logging.critical("This is a critical message")
logging.debug("debug")
WARNING:root:This is a warning message
CRITICAL:root:This is a critical message

Logging-Ebenen

Ebene

Beschreibung

CRITICAL

Das Programm wurde angehalten

ERROR

Ein schwerwiegender Fehler ist aufgetreten

WARNING

Ein Hinweis darauf, dass etwas Unerwartetes passiert ist (Standardstufe)

INFO

Bestätigung, dass die Dinge wie erwartet funktionieren.

DEBUG

Detaillierte Informationen, die in der Regel nur bei der Diagnose von Problemen von Interesse sind.

Setzen der Logging-Ebene

[2]:
import logging


logging.basicConfig(filename="example.log", filemode="w", level=logging.INFO)

logging.info("Informational message")
logging.error("An error has happened!")
ERROR:root:An error has happened!

Erstellen eines Logger-Objekts

[3]:
import logging


logging.basicConfig(filename="example.log")
logger = logging.getLogger("example")
logger.setLevel(logging.INFO)

try:
    raise RuntimeError
except Exception:
    logger.exception("Error!")
ERROR:example:Error!
Traceback (most recent call last):
  File "/var/folders/hk/s8m0bblj0g10hw885gld52mc0000gn/T/ipykernel_65477/2646645271.py", line 9, in <module>
    raise RuntimeError
RuntimeError

Ausnahmen (engl.: exceptions) loggen

[4]:
try:
    1 / 0
except ZeroDivisionError:
    logger.exception("You can’t do that!")
ERROR:example:You can’t do that!
Traceback (most recent call last):
  File "/var/folders/hk/s8m0bblj0g10hw885gld52mc0000gn/T/ipykernel_65477/760044062.py", line 2, in <module>
    1 / 0
    ~~^~~
ZeroDivisionError: division by zero

Logging-Handler

Handler-Typen

Handler

Beschreibung

StreamHandler

stdout, stderr oder dateiähnliche Objekte

FileHandler

für das Schreiben auf die Festplatte

RotatingFileHandler

unterstützt die Protokollrotation

TimedRotatingFileHandler

unterstützt die Rotation von Protokolldateien auf der Festplatte in bestimmten Zeitabständen

SocketHandler

sendet Logging-Ausgaben an einen Netzwerk-Socket

SMTPHandler

unterstützt das Senden von Logging-Nachrichten an eine E-Mail-Adresse über SMTP

Siehe auch

Weitere Handler können gefunden werden unter Logging handlers.

StreamHandler

[5]:
import logging


logger = logging.getLogger("stream_logger")
logger.setLevel(logging.INFO)

console = logging.StreamHandler()

logger.addHandler(console)
logger.info("This is an informational message")
This is an informational message
INFO:stream_logger:This is an informational message

SMTPHandler

[6]:
import logging
import logging.handlers


logger = logging.getLogger("email_logger")
logger.setLevel(logging.INFO)
fh = logging.handlers.SMTPHandler(
    "localhost",
    fromaddr="python-log@localhost",
    toaddrs=["logs@cusy.io"],
    subject="Python log",
)
logger.addHandler(fh)
logger.info("This is an informational message")
--- Logging error ---
Traceback (most recent call last):
  File "/opt/homebrew/Cellar/python@3.11/3.11.4_1/Frameworks/Python.framework/Versions/3.11/lib/python3.11/logging/handlers.py", line 1081, in emit
    smtp = smtplib.SMTP(self.mailhost, port, timeout=self.timeout)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Cellar/python@3.11/3.11.4_1/Frameworks/Python.framework/Versions/3.11/lib/python3.11/smtplib.py", line 255, in __init__
    (code, msg) = self.connect(host, port)
                  ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Cellar/python@3.11/3.11.4_1/Frameworks/Python.framework/Versions/3.11/lib/python3.11/smtplib.py", line 341, in connect
    self.sock = self._get_socket(host, port, self.timeout)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Cellar/python@3.11/3.11.4_1/Frameworks/Python.framework/Versions/3.11/lib/python3.11/smtplib.py", line 312, in _get_socket
    return socket.create_connection((host, port), timeout,
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Cellar/python@3.11/3.11.4_1/Frameworks/Python.framework/Versions/3.11/lib/python3.11/socket.py", line 851, in create_connection
    raise exceptions[0]
  File "/opt/homebrew/Cellar/python@3.11/3.11.4_1/Frameworks/Python.framework/Versions/3.11/lib/python3.11/socket.py", line 836, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 61] Connection refused
Call stack:
  File "<frozen runpy>", line 198, in _run_module_as_main
  File "<frozen runpy>", line 88, in _run_code
  File "/Users/veit/.local/share/virtualenvs/python-311-6zxVKbDJ/lib/python3.11/site-packages/ipykernel_launcher.py", line 17, in <module>
    app.launch_new_instance()
  File "/Users/veit/.local/share/virtualenvs/python-311-6zxVKbDJ/lib/python3.11/site-packages/traitlets/config/application.py", line 1043, in launch_instance
    app.start()
  File "/Users/veit/.local/share/virtualenvs/python-311-6zxVKbDJ/lib/python3.11/site-packages/ipykernel/kernelapp.py", line 736, in start
    self.io_loop.start()
  File "/Users/veit/.local/share/virtualenvs/python-311-6zxVKbDJ/lib/python3.11/site-packages/tornado/platform/asyncio.py", line 195, in start
    self.asyncio_loop.run_forever()
  File "/opt/homebrew/Cellar/python@3.11/3.11.4_1/Frameworks/Python.framework/Versions/3.11/lib/python3.11/asyncio/base_events.py", line 607, in run_forever
    self._run_once()
  File "/opt/homebrew/Cellar/python@3.11/3.11.4_1/Frameworks/Python.framework/Versions/3.11/lib/python3.11/asyncio/base_events.py", line 1922, in _run_once
    handle._run()
  File "/opt/homebrew/Cellar/python@3.11/3.11.4_1/Frameworks/Python.framework/Versions/3.11/lib/python3.11/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/Users/veit/.local/share/virtualenvs/python-311-6zxVKbDJ/lib/python3.11/site-packages/ipykernel/kernelbase.py", line 516, in dispatch_queue
    await self.process_one()
  File "/Users/veit/.local/share/virtualenvs/python-311-6zxVKbDJ/lib/python3.11/site-packages/ipykernel/kernelbase.py", line 505, in process_one
    await dispatch(*args)
  File "/Users/veit/.local/share/virtualenvs/python-311-6zxVKbDJ/lib/python3.11/site-packages/ipykernel/kernelbase.py", line 412, in dispatch_shell
    await result
  File "/Users/veit/.local/share/virtualenvs/python-311-6zxVKbDJ/lib/python3.11/site-packages/ipykernel/kernelbase.py", line 740, in execute_request
    reply_content = await reply_content
  File "/Users/veit/.local/share/virtualenvs/python-311-6zxVKbDJ/lib/python3.11/site-packages/ipykernel/ipkernel.py", line 422, in do_execute
    res = shell.run_cell(
  File "/Users/veit/.local/share/virtualenvs/python-311-6zxVKbDJ/lib/python3.11/site-packages/ipykernel/zmqshell.py", line 546, in run_cell
    return super().run_cell(*args, **kwargs)
  File "/Users/veit/.local/share/virtualenvs/python-311-6zxVKbDJ/lib/python3.11/site-packages/IPython/core/interactiveshell.py", line 3009, in run_cell
    result = self._run_cell(
  File "/Users/veit/.local/share/virtualenvs/python-311-6zxVKbDJ/lib/python3.11/site-packages/IPython/core/interactiveshell.py", line 3064, in _run_cell
    result = runner(coro)
  File "/Users/veit/.local/share/virtualenvs/python-311-6zxVKbDJ/lib/python3.11/site-packages/IPython/core/async_helpers.py", line 129, in _pseudo_sync_runner
    coro.send(None)
  File "/Users/veit/.local/share/virtualenvs/python-311-6zxVKbDJ/lib/python3.11/site-packages/IPython/core/interactiveshell.py", line 3269, in run_cell_async
    has_raised = await self.run_ast_nodes(code_ast.body, cell_name,
  File "/Users/veit/.local/share/virtualenvs/python-311-6zxVKbDJ/lib/python3.11/site-packages/IPython/core/interactiveshell.py", line 3448, in run_ast_nodes
    if await self.run_code(code, result, async_=asy):
  File "/Users/veit/.local/share/virtualenvs/python-311-6zxVKbDJ/lib/python3.11/site-packages/IPython/core/interactiveshell.py", line 3508, in run_code
    exec(code_obj, self.user_global_ns, self.user_ns)
  File "/var/folders/hk/s8m0bblj0g10hw885gld52mc0000gn/T/ipykernel_65477/3660210047.py", line 14, in <module>
    logger.info("This is an informational message")
Message: 'This is an informational message'
Arguments: ()
INFO:email_logger:This is an informational message

Log-Formattierung

Mit Formatierern könnt ihr den Log-Meldungen Formatierungen hinzufügen.

[7]:
formatter = logging.Formatter("%(asctime)s - %(name)s - %(message)s")

Neben %(asctime)s, %(name)s und %(message)s findet ihr noch weitere Attribute in LogRecord attributes.

[8]:
import logging


logger = logging.getLogger("stream_logger")
logger.setLevel(logging.INFO)

console = logging.StreamHandler()
formatter = logging.Formatter("%(asctime)s - %(name)s - %(message)s")
console.setFormatter(formatter)

logger.addHandler(console)
logger.info("This is an informational message")
This is an informational message
2023-08-21 18:08:14,555 - stream_logger - This is an informational message
INFO:stream_logger:This is an informational message

Bemerkung

Das Logging-Modul ist thread-sicher. Logging funktioniert jedoch möglicherweise nicht in asynchronen Kontexten. In solchen Fällen könnt ihr jedoch den QueueHandler verwenden.

Logging an mehrere Handler

[9]:
import logging


def log(path, multipleLocs=False):
    logger = logging.getLogger("Example_logger_%s" % fname)
    logger.setLevel(logging.INFO)
    fh = logging.FileHandler(path)
    formatter = logging.Formatter("%(asctime)s - %(name)s - %(message)s")
    fh.setFormatter(formatter)
    logger.addHandler(fh)

    if multipleLocs:
        console = logging.StreamHandler()
        console.setLevel(logging.INFO)
        console.setFormatter(formatter)
        logger.addHandler(console)

    logger.info("This is an informational message")
    try:
        1 / 0
    except ZeroDivisionError:
        logger.exception("You can’t do that!")

    logger.critical("This is a no-brainer!")

Logging konfigurieren

… in einer INI-Datei

Im folgenden Beispiel wird die Datei development.ini in diesem Verzeichnis geladen:

[loggers]
keys=root

[handlers]
keys=stream_handler

[formatters]
keys=formatter

[logger_root]
level=DEBUG
handlers=stream_handler

[handler_stream_handler]
class=StreamHandler
level=DEBUG
formatter=formatter
args=(sys.stderr,)

[formatter_formatter]
format=%(asctime)s %(name)-12s %(levelname)-8s %(message)s
[10]:
import logging
import logging.config

from logging.config import fileConfig


logging.config.fileConfig("development.ini")
logger = logging.getLogger("example")

logger.info("Program started")
logger.info("Done!")

Pro:

  • Möglichkeit, die Konfiguration während des Betriebs zu aktualisieren, indem die Funktion logging.config.listen() verwendet wird um an einem Socket zu lauschen.

  • In verschiedenen Umgebungen können unterschiedliche Konfigurationen verwendet werden, also z.B. kann in der development.ini DEBUG als Log-Level angegeben werden, während in der production.ini WARN verwendet wird.

Con:

  • Weniger Kontrolle z.B. gegenüber benutzerdefinierten Filtern oder Logger, die im Code konfiguriert sind.

… in einer dictConfig

[11]:
import logging
import logging.config


dictLogConfig = {
    "version": 1,
    "handlers": {
        "fileHandler": {
            "class": "logging.FileHandler",
            "formatter": "exampleFormatter",
            "filename": "dict_config.log",
        }
    },
    "loggers": {
        "exampleApp": {
            "handlers": ["fileHandler"],
            "level": "INFO",
        }
    },
    "formatters": {
        "exampleFormatter": {
            "format": "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
        }
    },
}
[12]:
logging.config.dictConfig(dictLogConfig)

logger = logging.getLogger("exampleApp")

logger.info("Program started")
logger.info("Done!")
2023-08-21 18:08:14,573 exampleApp   INFO     Program started
2023-08-21 18:08:14,574 exampleApp   INFO     Done!

Pro:

  • Aktualisieren während des Betriebs

Con:

  • Weniger Kontrolle als beim Konfigurieren eines Loggers im Code

… direkt im Code

[13]:
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)

Magic Commands

Befehl

Beschreibung

%logstart

Startet das Logging irgendwo in einer Session

%logstart [-o\|-r\|-t\|-q] [log_name [log_mode]]

Wenn kein Name angegeben wird, wird ipython_log.py im aktuellen Verzeichnis verwendet.

log_mode ist ein optionaler Parameter. Folgende Modi können angegeben werden:

* append hängt die Logging-Informationen am Ende einer vorhandenen Datei an

* backup benennt die vorhandene Datei um in name~ und schreibt in name

* global hängt die Logging-Informationen am Ende einer vorhandenen Datei im

* over überschreibt eine existierende Log-Datei

* rotate erstellt rotierende Log-Dateien: name.1~, name.2~, etc.

Optionen:

* -o logt auch den Output von IPython

* -r logt raw Output

* -t schreibt einen Zeitstempel vor jeden Logeintrag

* -q unterdrückt die Logging-Ausgabe

%logon

Neustart des Logging

%logoff

Temporäres Beenden des Logging

Pro:

  • Vollständige Kontrolle über die Konfiguration

Con:

  • Änderungen in der Konfiguration erfordern eine Änderung des Quellcodes

Logs rotieren

[14]:
import logging
import time

from logging.handlers import RotatingFileHandler


def create_rotating_log(path):
    logger = logging.getLogger("Rotating Log")
    logger.setLevel(logging.INFO)

    handler = RotatingFileHandler(path, maxBytes=20, backupCount=5)
    logger.addHandler(handler)

    for i in range(10):
        logger.info("This is an example log line %s" % i)
        time.sleep(1.5)


if __name__ == "__main__":
    log_file = "rotated.log"
    create_rotating_log(log_file)
2023-08-21 18:08:14,580 Rotating Log INFO     This is an example log line 0
2023-08-21 18:08:14,580 Rotating Log INFO     This is an example log line 0
2023-08-21 18:08:16,086 Rotating Log INFO     This is an example log line 1
2023-08-21 18:08:16,086 Rotating Log INFO     This is an example log line 1
2023-08-21 18:08:17,595 Rotating Log INFO     This is an example log line 2
2023-08-21 18:08:17,595 Rotating Log INFO     This is an example log line 2
2023-08-21 18:08:19,103 Rotating Log INFO     This is an example log line 3
2023-08-21 18:08:19,103 Rotating Log INFO     This is an example log line 3
2023-08-21 18:08:20,612 Rotating Log INFO     This is an example log line 4
2023-08-21 18:08:20,612 Rotating Log INFO     This is an example log line 4
2023-08-21 18:08:22,122 Rotating Log INFO     This is an example log line 5
2023-08-21 18:08:22,122 Rotating Log INFO     This is an example log line 5
2023-08-21 18:08:23,632 Rotating Log INFO     This is an example log line 6
2023-08-21 18:08:23,632 Rotating Log INFO     This is an example log line 6
2023-08-21 18:08:25,137 Rotating Log INFO     This is an example log line 7
2023-08-21 18:08:25,137 Rotating Log INFO     This is an example log line 7
2023-08-21 18:08:26,646 Rotating Log INFO     This is an example log line 8
2023-08-21 18:08:26,646 Rotating Log INFO     This is an example log line 8
2023-08-21 18:08:28,155 Rotating Log INFO     This is an example log line 9
2023-08-21 18:08:28,155 Rotating Log INFO     This is an example log line 9

Logs zeitgesteuert rotieren

[15]:
import logging
import time

from logging.handlers import TimedRotatingFileHandler


def create_timed_rotating_log(path):
    """"""
    logger = logging.getLogger("Rotating Log")
    logger.setLevel(logging.INFO)

    handler = TimedRotatingFileHandler(
        path, when="s", interval=5, backupCount=5
    )
    logger.addHandler(handler)

    for i in range(6):
        logger.info("This is an example!")
        time.sleep(75)


if __name__ == "__main__":
    log_file = "timed_rotation.log"
    create_timed_rotating_log(log_file)
2023-08-21 18:08:29,674 Rotating Log INFO     This is an example!
2023-08-21 18:08:29,674 Rotating Log INFO     This is an example!
2023-08-21 18:09:44,681 Rotating Log INFO     This is an example!
2023-08-21 18:09:44,681 Rotating Log INFO     This is an example!
2023-08-21 18:10:59,688 Rotating Log INFO     This is an example!
2023-08-21 18:10:59,688 Rotating Log INFO     This is an example!
2023-08-21 18:12:14,697 Rotating Log INFO     This is an example!
2023-08-21 18:12:14,697 Rotating Log INFO     This is an example!
2023-08-21 18:13:29,702 Rotating Log INFO     This is an example!
2023-08-21 18:13:29,702 Rotating Log INFO     This is an example!
2023-08-21 18:14:44,710 Rotating Log INFO     This is an example!
2023-08-21 18:14:44,710 Rotating Log INFO     This is an example!

Erstellen eines Logging-Dekorators

Einen Logging-Filter erstellen

[16]:
import logging
import sys


class ExampleFilter(logging.Filter):
    def filter(self, record):
        if record.funcName == "foo":
            return False
        return True


logger = logging.getLogger("filter_example")
logger.addFilter(ExampleFilter())


def foo():
    """
    Ignore this function’s log messages
    """
    logger.debug("Message from function foo")


def bar():
    logger.debug("Message from bar")


if __name__ == "__main__":
    logging.basicConfig(stream=sys.stderr, level=logging.DEBUG)
    foo()
    bar()
2023-08-21 18:15:59,730 filter_example DEBUG    Message from bar
2023-08-21 18:15:59,730 filter_example DEBUG    Message from bar