Skip to content

Instantly share code, notes, and snippets.

@samuelharmer
Last active February 7, 2020 12:27
Show Gist options
  • Select an option

  • Save samuelharmer/c4a87b88aa877cc7becb3ec919b833d0 to your computer and use it in GitHub Desktop.

Select an option

Save samuelharmer/c4a87b88aa877cc7becb3ec919b833d0 to your computer and use it in GitHub Desktop.
Software Development, Python, Logging
#!/usr/bin/env python3
import os
import datetime
import operator
import logging
import logging.config
from pathlib import Path
from functools import reduce
from ruamel.yaml import YAML
from ruamel.yaml.compat import StringIO
module_import_time = datetime.datetime.now(datetime.timezone.utc)
def get_by_path(root, items):
"""Access a nested object in root by item sequence."""
# https://stackoverflow.com/a/14692747/594137
return reduce(operator.getitem, items, root)
def set_by_path(root, items, value):
"""Set a value in a nested object in root by item sequence."""
# https://stackoverflow.com/a/14692747/594137
get_by_path(root, items[:-1])[items[-1]] = value
def fix_up_log_filename(config_data):
path_to_node = ["logging", "handlers", "file", "filename"]
# Fix up the log file path by, …
original = get_by_path(config_data, path_to_node)
# … expanding any datetime formatting symbols in the string, …
fixed = module_import_time.strftime(original)
# … then translating it to an absolute path, relative to this script.
fixed = Path(fixed)
if fixed.is_absolute():
fixed = fixed.absolute()
else:
fixed = (Path(__file__).parent / fixed).absolute()
# Ensure the directory exists
os.makedirs(fixed.parent, exist_ok=True)
# Print the log file location so the user can find it
print(f"Logging to {original} -> {fixed}")
# And put it back into the configuration.
set_by_path(config_data, path_to_node, str(fixed))
def load_config(config_path):
# First we load the configuration
yaml = YAML()
with open(config_path) as f:
config_data = yaml.load(f)
# Fix up anything in the logging file configuration
fix_up_log_filename(config_data)
# Apply configuration
logging.config.dictConfig(config_data["logging"])
logging.info(f"Configuration file: {config_path.absolute()}")
# Format and dump configuration
yaml.indent(mapping=2, sequence=4, offset=2)
stream = StringIO()
yaml.dump(config_data, stream)
logging.debug(stream.getvalue())
return config_data
def boldly_go(config):
import secrets
species = config["Federation"]["Known Species"]
for i in range(1, 11):
stardate = secrets.randbelow(100000) / 10
logging.debug(f"[Scene {i}]")
logging.info(f"Captain's log. Stardate {stardate}.")
if stardate < 5000:
if stardate % 2 == 0:
logging.debug(f"Boldly going where no one has gone before")
else:
logging.info(f"Entering the {secrets.choice(species)} system")
else:
logging.warning(f"The {secrets.choice(species)} are attacking!")
if stardate < 9000:
if stardate % 2 == 0:
logging.error("She cannae take any more, Cap'n!")
else:
logging.error("She's gonna blow!")
else:
logging.critical("It was… fun. Oh, my.")
if __name__ == "__main__":
config = load_config(Path(__file__).parent / "app.yaml")
logging.info("Configuration has finished loading.")
boldly_go(config)
logging:
version: 1
formatters:
brief:
format: "%(asctime)s.%(msecs)03d %(levelname).1s%(levelname).1s %(message)s"
datefmt: "%H:%M:%S"
precise:
format: "%(asctime)s.%(msecs)03d %(levelname).1s%(levelname).1s %(module)s %(process)d %(thread)d %(message)s"
datefmt: "%Y-%m-%dT%H:%M:%S"
handlers:
console:
class: logging.StreamHandler
level: INFO
formatter: brief
stream: ext://sys.stdout
file:
class: logging.FileHandler
level: DEBUG
formatter: precise
filename: logs/migrate.%Y%m%dT%H%M%S%z.txt
root:
# Leave this as NOTSET so all messages reach the handlers.
level: NOTSET
handlers:
- console
- file
Federation:
Known Species:
- Borg
- Ferengi
- Gorn
- Klingon
- Romulan
- Vulcan

Logging

Logging can become as complicated as your imagination permits in Python. There are modules in the standard library that cater for all scenarios I have encountered and probably many more I have not.

The documentation has extensive sections on logging. The key materials (in rough order of reading) being:

In an attempt to distill these options to that should just work, I am documenting my own logging recipes here.

Configuration

In all cases, the best way I have found for providing configurable logging is through a YAML configuration file. Perhaps once I have tested these options for many years this flexibility might be unnecessary but for debugging a complex Python application I find flexibility to be essential.

For parsing YAML the best library I have used by far is ruamel.yaml. t has recently migrated development to SourceForge which I find particularly painful to navigate. I hope it migrates to something less trashy like Gitlab/Github soon.

We don't care what else is in this file, so long as a logging key exists at the root which contains a dictionary value matching Python's logging.config.dictConfig(config) schema.

User Application

This style applies to an application run by a human, typically in user space. It may require root privileges but a human runs the program and wants to see what is happening as it happens, and gets a log file to avoid messing around with pipes and file names.

This configuration starts by printing the location of the log file (pre- and post-date-expansion) to ensure the user knows where to find the log file. This location can be tweaked and any date format strings will be expanded. The directory will be created if required so grouping log files by year, month, or day becomes easy.

The default is that time-only-stamped information goes to stdout, whilst the log file gets extra debug information (including the Python module, process and thread IDs). This can all be tweaked in the configuration without needing any changes to the program code.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment