How To Use Pytest Logging And Print To Console And File (A Comprehensive Guide)

While developing any software solution, keeping track of events is crucial. Logging serves as a means of tracking events to catch software bugs, as they happen.

Although Pytest is great at running tests, it doesn’t automatically display the output of print statements or logs, which can be a problem when trying to debug failing tests.

So what’s the solution then? How can we log and view events as they happen during our Unit Testing?

The answer is Pytest logging. The ability to create and even override log handlers within Pytest.

In this article, we’ll look at how to use Pytest logging and print statements to output logs to the console and file:

  • The difference between logging and print statements.
  • The benefits of using a custom logger over the built-in logging module.
  • How to set up pytest with logging in a Python application.
  • How to output logs in pytest.
  • How to disable logs completely.
  • How to change the log level at a single test level using the caplog fixture.
  • How to configure the pytest.ini file for logging.
  • The use of plugins like pytest-print and pytest-logger for additional logging features.

Let’s get into it.

Link To GitHub Repo

Logging vs Print Statement

Print statements are difficult to manage, can slow down your program and does not provide any information about the program’s stat.

You have no control about which statements should print and which should not, making it more difficult to debug your code.

Logging records important events as they occur but also stores them in an organized format for subsequent review and analysis, including control over various levels.

Custom Logger vs Inbuilt Logging Module

Built-in logging module doesn’t always cater to specific needs or preferences of different projects. That’s where a custom logger comes to the rescue.

A custom logger gives you more control, allowing you to configure its behavior to suit your specific requirements.

For instance, you can set it to display only certain types of messages or output logs to multiple destinations.

Python’s built-in logging module provides five standard levels indicating the severity of events:

- NOTSET (0): This level captures all messages, regardless of their severity.
- DEBUG (10): This level is used for anything that can help identify potential problems, like variable values or the steps that a program takes.
- INFO (20): This level is used to confirm that things are working as expected.
- WARNING (30): This level indicates that something unexpected happened, or there may be some problem in the near future (like ‘disk space low’). However, the software is still working as expected.
- ERROR (40): This level indicates a more serious problem that prevented the software from performing a function.
- CRITICAL (50): This level denotes a very serious error that might prevent the program from continuing to run.

A custom logger allows you to define and work with these levels more conveniently, further enhancing the precision and control of your logging process.

Objectives

The primary objective of this article is to guide you through the process of setting up pytest with logging in a Python application.

We will explore how to output logs in pytest, how to disable logs, and how to change the log level at a single test level.

Project Set Up

The project has the following structure

Repo structure

Getting Started

To get started, clone the repo here, or you can create your own repo by creating a folder and running git init to initialise it.

Prerequisites

To follow this guide, you should have:

  • Python 3.10 or higher.

  • Basic understanding of Python’s logging module.

  • An elementary grasp of pytest.

Create a virtual environment and install the requirements (packages) using

1
pip  install  -r  requirements.txt

Source Code

Now let’s delve into some code examples to understand how we can implement logging in a Python application and how to use pytest logging effectively.

Consider a simple temperature conversion utility called ‘temp_convertor’. The utility comprises two functions fahrenheit_to_celsius and celsius_to_fahrenheit, converting the temperature from Fahrenheit to Celsius and vice-versa, respectively.

temp_convertor/core.py

1
2
3
4
5
6
7
8
9
10
11
12
13
def fahrenheit_to_celsius(fahrenheit: float) -> float:
"""Convert the specified Fahrenheit temperature to Celsius and return it."""
logger.debug(f"Converting {fahrenheit}°F to Celsius.")
celsius = round((fahrenheit - 32) * 5 / 9, 2)
logger.info(f"Result: {celsius}°C")
return celsius

def celsius_to_fahrenheit(celsius: float) -> float:
"""Convert the specified Celsius temperature to Fahrenheit and return it."""
logger.debug(f"Converting {celsius}°C to Fahrenheit.")
fahrenheit = round((celsius * 9 / 5) + 32, 2)
logger.info(f"Result: {fahrenheit}°F")
return fahrenheit

Log Definition

The logger is set up with two handlers: one for console output and another for writing logs to a file. Each handler uses the same format for logging messages but could be customized as needed.

Console Logger

The console logger leverages logging.StreamHandler() to output logs to the console (stdout). The logger’s level is set to INFO, meaning it will handle all log messages with a severity of INFO and above.

temp_convertor/core.py

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
# Create a named logger
logger = logging.getLogger('__temp_convertor__')
logger.setLevel(logging.INFO)

# Create a console handler
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.INFO)

# Set the formatter for the console handler
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s',
datefmt='%m/%d/%Y %I:%M:%S%p')
console_handler.setFormatter(formatter)

# Add the console handler to the logger
logger.addHandler(console_handler)

File Logger

Similarly, the file logger utilizes logging.FileHandler() to direct logs to a specified file. It’s also set to the INFO level, ensuring uniformity of logged information across the console and file outputs.

temp_convertor/core.py

1
2
3
4
5
6
7
8
9
10
11
# Create a file handler
file_handler = logging.FileHandler('./logs/temp_convertor_src_run.log')
file_handler.setLevel(logging.INFO)

# Set the formatter for the file handler
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s', datefmt='%m/%d/%Y %I:%M:%S%p')

file_handler.setFormatter(formatter)
# Add the file handler to the logger

logger.addHandler(file_handler)

Unit Tests

The unit tests are defined in a separate file

test_temp_convertor.py — Tests the Calculator Class

Let’s take a look at test code.

tests/unit/test_temp_convertor.py

1
2
3
4
5
6
7
8
import logging

def test_fahrenheit_to_celsius():
assert fahrenheit_to_celsius(90) == 32.22

def test_celsius_to_fahrenheit():
assert celsius_to_fahrenheit(19) == 66.2

The above code tests for temperature conversion functions:

  1. test_fahrenheit_to_celsius() checks if 90 degrees Fahrenheit is correctly converted to 32.22 Celsius.

  2. test_celsius_to_fahrenheit() verifies if 19 degrees Celsius is correctly converted to 66.2 Fahrenheit.

Run Source Code

To run the source code, execute the following command:

1
python  temp_convertor/core.py

The following output is displayed in the console:

Output of core.py

Now let’s run the unit tests using pytest.

Run Unit Tests

To run the unit tests, execute the following command:

1
pytest  -v

The following output is displayed in the console:

Output of pytest -v

As you can see the log messages are not displayed in the console. We will explore displaying log messages in the console and other logging options. Stay tuned!

Define and Override Logging in Pytest

Pytest offers various ways to control logging during the testing process. One such method is to define and override the default logging format through the CLI.

Define Logging via CLI Commands

Pytest allows you to customize the log output format and date format via command-line options. This flexibility enables you to adjust log presentation according to your specific needs. Here’s an example:

1
pytest  --log-cli-level=INFO  --log-format="%(asctime)s %(levelname)s %(message)s"  --log-date-format=" %Y-%m-%d %H:%M"

In this command, log-format sets the format of the logged message itself, while log-date-format sets the format of the timestamp in the logged message.

Output of pytest

Define Logging via Config File (pytest.ini)

For a more permanent configuration, you can set log parameters in a pytest.ini file. This file allows you to enable CLI logging by default and specify the default log level. Here’s an example of how the pytest.ini configuration might look:

pytest.ini

1
2
3
4
5
6
7
[pytest]
log_file = logs/temp_convertor_tests_run.log
log_file_date_format = %Y-%m-%d %H:%M:%S
log_file_format = %(asctime)s - %(name)s %(levelname)s %(message)s
log_file_level = INFO
log_format = %(asctime)s %(levelname)s %(message)s
log_level = DEBUG

In this configuration, log_file specifies the file to which logs will be written, while log_file_date_format and log_file_format set the format of the timestamp and logged message, respectively. log_file_level sets the default log level for the file logger.

Additionally, the log_format and log_level parameters define the log format and default log level for the console output.

For more detailed information on configuring pytest.ini for logging and other pytest best practices, you can refer to our extensive guide on How To Use Configure Pytest using pytest.ini.

How to View Logs in Pytest

By default, Pytest captures your log outputs and only displays them when a test fails. This helps to keep the console output tidy and focused on what you most need to see.

However, there are times when you might want to change this behavior.

View Logs in CLI (Live logging)

You can view log outputs in real-time in the CLI by disabling pytest’s output capturing using -s switch:

1
pytest  -s

With this command, pytest will display all print and logging outputs as they occur, regardless of whether tests pass or fail.

The following will be the output.

Output of pytest -s

View Logs in CLI with pytest.ini

You can also configure pytest to display log outputs in the CLI by default. This requires adding a log_cli parameter to your pytest.ini file:

1
2
3
[pytest]
log_cli = True
log_cli_level = INFO

With this configuration, pytest will display all print and logging outputs as they occur, regardless of whether tests pass or fail.

The following will be the output.
Output of View Logs in CLI

Write Logs To A File.

In addition to displaying log outputs in the CLI, you can also write them to a file for later review or record-keeping. This requires adding a file handler to the logger in your test code or conftest file. The process is similar to what we saw in the source code above with the FileHandler.

Disabling Logs Completely

There are cases where you might not want to see any log output, even when tests fail. Pytest provides an option to suppress all log output:

1
pytest  --show-capture=no

With this command, pytest will disable reporting of captured content (stdout, stderr and logs) on failed tests completely.

Changing Log Level at a Single Test Level

There may be times when you want to change the log level for a specific test, perhaps to debug that test or reduce noise in the log output. Pytest’s caplog fixture allows you to do this.

About The Caplog Fixture

The caplog fixture is a powerful tool for controlling and interacting with logs in your tests. With caplog, you can temporarily change the log level, capture log messages for assertion, and more.

For example, to change the log level to DEBUG within a test:

/unit/test_temp_convertor.py

1
2
3
4
5
def test_celsius_to_fahrenheit_caplog_ex(caplog):
caplog.set_level(logging.DEBUG, logger='__temp_convertor__')
assert celsius_to_fahrenheit(300) == 572.0
for record in caplog.records:
print(record.levelname, record.message)

The above test function named test_celsius_to_fahrenheit_caplog_ex, utilizes the ‘caplog’ fixture from pytest library.

On line 2, we temporarily sets the log level to DEBUG for the logger named ‘temp_convertor’.

The other test function named test_celsius_to_fahrenheit does not use the ‘caplog’ fixture. It uses the default log level set in the pytest.ini file.

Run the test using the following command:

1
pytest  -s

The following output will be displayed after commenting out the test_celsius_to_fahrenheit and test_fahrenheit_to_celsius functions.

Output of Caplog Fixture

Essentially proving that the caplog fixture overrides the pytest.ini config.

Logging Plugins

Pytest also provides plugins that can be used to customize and extend logging capabilities. Two popular plugins are pytest-print and pytest-logger:

  • pytest-print enables printing messages to stdout during test execution, providing additional visibility of log outputs.
  • pytest-logger provides sophisticated per-test logging and log file management, enhancing the logging capabilities of pytest.

Conclusion

In this comprehensive guide, we have covered various aspects of using logging and print statements in Pytest.

We explored how to configure log parameters through the CLI and pytest.ini file, use plugins to extend logging capabilities, output logs to the console and file, disable logs, and change the log level at a single test level using the caplog fixture.

By effectively utilizing Pytest logging, you can gain better visibility into your test execution, debug your code more efficiently, and track important events throughout the testing process.

If you have any ideas for improvement or like me to cover any topics please comment below or send me a message via Twitter, GitHub or Email.

Till the next time… Cheers!

Additional Reading

For more information, you may refer to:

  1. Python’s logging module

  2. Pytest’s logging documentation

  3. “pytest debug print logging in real time”

  4. “How to manage logging - pytest documentation”

Remember that logging is a powerful tool that, when used effectively, can significantly improve the quality of your applications and the effectiveness of your testing.