Logging for beginners (in Python) - How and Why
Tags: python, observability, programming, logging
Published: 2023-09-20 10:51:13

Logging is an essential part of software development. However, many developers struggle with writing good logs. In this post, we will explore what makes a good log and how to write one.

## A Brief Timeline of a Software Developer

When people start programming, the first thing they do is produce their initial piece of code and say hi to the stdout/console/web browser/etc.. with the infamous sentence -

> "Hello, world."

Not long after, come the comments. Comments are an integral part of every new developer's handbook. Everyone tells you to write them, but no one explains why, how, and when. As developers progress, they understand more code, patterns, and paradigms, and with that often come the assumption that every other engineer who is worth reading their masterpiece will understand it as well. It is crucial to understand that printing out the message "Error - process failed" will not lead other engineers to the issue that has been standing between them and happiness for the past two days.

## What Makes Good Logs?

As you might know, there are whole books about writing well-logged, observable, and debuggable code. This post is not a drop-in replacement for these books, but it is a short write-up to help you easily level up your coding game.

We are uncovering another parallel to nature, as there are four elements that form a good log and are vital for delivering a meaningful and helpful message.

### (Water) The Element of Time

Just as water flows, time does too, and therefore we must make sure that when reading logs, we know where the dam blocking our flow is. When searching for the source of an error, you will end up scrolling through a log file. It might be very long, but it just as well might be as short as a few lines. Regardless, you can't make assumptions as to which line in the log corresponds to your error without having information on when the specific log was written. It is crucial for every log to provide a timestamp (I would strongly recommend a human-readable format, like ISO 8601), so that someone doesn't get stuck in a vicious circle of debugging because of unknowingly looking at year-old logs that don't actually correspond to their issue.

Examples of logs with timestamps:
- `2024-01-01T12:00:00.000Z - ...`
- `January 1, 2024, 12:00:00 UTC - ...`
- `1704067200000 - ...` (I wouldn't prefer to use Unix epoch time when it comes to human readability, however, when logs are interpreted by a software like Sentry, it can do the translation into a more readable format for you)

### (Earth) The Element of Context

In the context of software logs, just as the element of earth provides a foundation for life, contextual information provides a foundation for understanding what happened in a given event. Without context, logs can be difficult to interpret and can lead to incorrect conclusions about what happened. It is important to include contextual information such as the place where the log was written, depending on context and the size of your app, it could be a package name/module name/function name, whatever helps the reader to identify where the log is coming from. Generally, in Python, this would be the name of the app followed by the name of the module (utilizing the `__name__` variable).

Examples of logs with contextual information:
- `2024-01-01T12:00:00.000Z - myapp.mymodule - ...`

### (Fire) The Element of Information Level
The roof is on fire, right? Maybe, or maybe not. So far, we have only talked about logs as part of errors, however, debugging is not the only point when you would look at logs. You might want to figure out how long something took, or what is your program doing just know. Different log levels are used for different purposes. It is important to understand each of them and know when to use which as the level is used for filtering which logs to show in different log outputs. The following are the most common log levels:
- **ERROR**- This one is quite self-explanatory. Something bad happened, your code ran into an error that is crucial for its health.
- **WARN** - Warnings show potentially harmful occurrences of issues that are not breaking.
- **DEBUG** - This is the most granular level of your logs. It provides a very verbose way to write information about the state and actions of your program for developers and other diagnostic personnel.
- **INFO** - Info serves as a way for you to provide useful high-level information about the run of your program.

Examples of logs with different log levels:
- `2024-01-01T12:00:00.000Z - myapp.mymodule - INFO - ...`
- `2024-01-01T12:00:00.000Z - myapp.mymodule - DEBUG - ...`

### (Wind) The Element of (Error) Message

A good message can carry information far and wide, just like the wind. Well crafted log messages can provide valuable insights into the behavior of a software application. A good log message should be clear and concise, providing enough information to understand what happened without overwhelming the reader with unnecessary details. For example, when you are logging a raised error, you don't need to include the error message in the log, as the error will already be included as part of the log. Rather choose to inform the user why the error occurred or provide more context which was maybe not included in the error itself.

Examples of logs with clear and concise messages:
- `2024-01-01T12:00:00.000Z - myapp.mymodule - INFO - The API server has started listening on 0.0.0.0:3000`
- `2024-01-01T12:00:00.000Z - myapp.mymodule - ERROR - Failed to login into container registry`

### An Extra One for You... Structure

It is very important to make sure that your logs provide well-structured information, and that all of your logs are of the same structure. Consistency is crucial not just because of human readability, but also because logs are very often parsed by diagnostic software (e.g., (Sentry)[https://sentry.io/]). There are many different ways to structure your logs, however, the following is a good start:
- `[DATE/TIME] - [LOG LEVEL] - [MODULE] - [MESSAGE] - [STACK] - [DATA]`

No need to make your logs look fancy, just make sure they are simple, structured, and easily comprehensible.

## How to write logs in python
Python provides a built-in logging module that makes it easy to write logs in your application. Here are the basic steps to get started:

1. Import the logging module:
```
import logging
```

2. Configure the logging module:
```
logging.basicConfig(level=logging.INFO, filename='example.log', filemode='w', format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
```

This sets the logging level to INFO (meaning that all the log messages with a level bellow will be ignored), specifies the filename for the log file, sets the file mode to 'w' (write), and specifies the log message format.

This shows a simple way of configuring your logger, however, you can also use a configuration file where it is possible to declare much more complex configuration for the logging logic in your whole app. Please refer to the (logging module documentation)[https://docs.python.org/3/library/logging.html] for more info.

3. Write log messages:
```
logging.debug('This is a debug message')
logging.info('This is an info message')
logging.warning('This is a warning message')
logging.error('This is an error message')
logging.critical('This is a critical message')
```

This writes log messages at different severity levels to the log file.

4. Use placeholders for dynamic values:
```
name = 'John'
logging.info('Hello, %s', name)
```

This writes a log message with a dynamic value (the name variable) using a placeholder.

5. Pass raised exceptions to the logger:
```
try:
  # calculate the answer to everythin
  result = "42" + .0
except TypeError as e:
  logging.error("Exception occured while calculating the answer to everything", exc_info=True)
```
Using `exc_info=True` you can easily attach the stack trace of the exception and provide valuable information.

By following these steps, you can easily write logs in your Python application. Remember to include contextual information and use structured data to make your logs more useful and easy to analyze.

## Conclusions
In summary, good logs are composed of four elements: time, context, information level, and message. By following these guidelines and keeping the logs consistent, you can easily level up your coding game and write well-structured, readable, and useful logs.