Logging examples

Creating a log file

[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 levels

Level

Description

CRITICAL

The programme was stopped

ERROR

A serious error has occurred

WARNING

An indication that something unexpected has happened (default level)

INFO

Confirmation that things are working as expected

DEBUG

Detailed information that is usually only of interest when diagnosing problems

Setting the logging level

[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!

Creating a Logger Object

[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_65916/2646645271.py", line 9, in <module>
    raise RuntimeError
RuntimeError

Logging exceptions

[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_65916/760044062.py", line 2, in <module>
    1 / 0
    ~~^~~
ZeroDivisionError: division by zero

Logging handler

Handler types

Handler

Description

StreamHandler

stdout, stderr or file-like objects

FileHandler

for writing to disk

RotatingFileHandler

supports log rotation

TimedRotatingFileHandler

supports the rotation of log files on the hard disk at specific time intervals

SocketHandler

sends logging output to a network socket

SMTPHandler

supports sending logging messages to an e-mail address via SMTP

See also

Further handlers can be found at 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_65916/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 formatting

You can use formatters to format log messages.

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

Besides %(asctime)s, %(name)s and %(message)s you will find other attributes 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-03 13:40:00,195 - stream_logger - This is an informational message
INFO:stream_logger:This is an informational message

Note

The logging module is thread-safe. However, logging may not work in asynchronous contexts. In such cases, however, you can use the QueueHandler.

Logging to multiple handlers

[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!")

Configure logging

… in an INI file

In the following example, the file development.ini is loaded in this directory:

[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:

  • Ability to update the configuration on the fly by using the logging.config.listen() function to listen on a socket.

  • Different configurations can be used in different environments, so for example, DEBUG can be specified as the log level in development.ini, while WARN is used in production.ini.

Con:

  • Less control for example over custom filters or loggers configured in code.

… in a 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"
        }
    },
}
[13]:
logging.config.dictConfig(dictLogConfig)

logger = logging.getLogger("exampleApp")

logger.info("Program started")
logger.info("Done!")
2021-12-12 21:22:14,326 exampleApp   INFO     Program started
2021-12-12 21:22:14,329 exampleApp   INFO     Done!

Pro:

  • Update on the fly

Con:

  • Less control than configuring a logger in code

… directly in the code

[12]:
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

Starts logging anywhere in a session

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

If no name is given, ipython_log.py is used in the current directory.

log_mode is an optional parameter. The following modes can be specified:

* append appends the logging information to the end of an existing file

* backup renames the existing file to name~ and writes to name

* global appends the logging information at the end of an existing file

* over overwrites an existing log file

* rotate creates rotating log files: name.1~, name.2~, etc.

Options:

* -o also logs the output of IPython

* -r logs raw output

* -t writes a time stamp in front of each log entry

* -q suppresses the logging output

%logon

Restart the logging

%logoff

Temporary termination of logging

Pro:

  • Complete control over the configuration

Con:

  • Changes in the configuration require a change in the source code

Logs rotate

[13]:
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-03 13:44:10,701 Rotating Log INFO     This is an example log line 0
2023-08-03 13:44:10,701 Rotating Log INFO     This is an example log line 0
2023-08-03 13:44:12,204 Rotating Log INFO     This is an example log line 1
2023-08-03 13:44:12,204 Rotating Log INFO     This is an example log line 1
2023-08-03 13:44:13,710 Rotating Log INFO     This is an example log line 2
2023-08-03 13:44:13,710 Rotating Log INFO     This is an example log line 2
2023-08-03 13:44:15,217 Rotating Log INFO     This is an example log line 3
2023-08-03 13:44:15,217 Rotating Log INFO     This is an example log line 3
2023-08-03 13:44:16,727 Rotating Log INFO     This is an example log line 4
2023-08-03 13:44:16,727 Rotating Log INFO     This is an example log line 4
2023-08-03 13:44:18,233 Rotating Log INFO     This is an example log line 5
2023-08-03 13:44:18,233 Rotating Log INFO     This is an example log line 5
2023-08-03 13:44:19,737 Rotating Log INFO     This is an example log line 6
2023-08-03 13:44:19,737 Rotating Log INFO     This is an example log line 6
2023-08-03 13:44:21,244 Rotating Log INFO     This is an example log line 7
2023-08-03 13:44:21,244 Rotating Log INFO     This is an example log line 7
2023-08-03 13:44:22,751 Rotating Log INFO     This is an example log line 8
2023-08-03 13:44:22,751 Rotating Log INFO     This is an example log line 8
2023-08-03 13:44:24,257 Rotating Log INFO     This is an example log line 9
2023-08-03 13:44:24,257 Rotating Log INFO     This is an example log line 9

Rotate logs time-controlled

[ ]:
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-03 13:45:00,510 Rotating Log INFO     This is an example!
2023-08-03 13:45:00,510 Rotating Log INFO     This is an example!
2023-08-03 13:46:15,510 Rotating Log INFO     This is an example!
2023-08-03 13:46:15,510 Rotating Log INFO     This is an example!
2023-08-03 13:47:30,517 Rotating Log INFO     This is an example!
2023-08-03 13:47:30,517 Rotating Log INFO     This is an example!
2023-08-03 13:48:45,521 Rotating Log INFO     This is an example!
2023-08-03 13:48:45,521 Rotating Log INFO     This is an example!
2023-08-03 13:50:00,525 Rotating Log INFO     This is an example!
2023-08-03 13:50:00,525 Rotating Log INFO     This is an example!
2023-08-03 13:51:15,530 Rotating Log INFO     This is an example!
2023-08-03 13:51:15,530 Rotating Log INFO     This is an example!

Create a logging decorator

Create a logging filter

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