Asserting log messages in PyTest - Test Execution Trace

Test Overview

This test checks if a specific log message is generated during the execution of a function. It verifies that the log contains the expected text at the correct log level.

Test Code - pytest

PyTest

import logging
import pytest

logger = logging.getLogger(__name__)

def greet(name):
    logger.info(f"Greeting {name}")
    return f"Hello, {name}!"


def test_greet_logs_info(caplog):
    with caplog.at_level(logging.INFO):
        result = greet("Alice")
    assert result == "Hello, Alice!"
    assert "Greeting Alice" in caplog.text
    assert any(record.levelname == "INFO" for record in caplog.records)

Execution Trace - 7 Steps

Step	Action	System State	Assertion	Result
1	Test starts	pytest test runner is ready	—	PASS
2	Calls greet("Alice") inside caplog context at INFO level	Logger is set to capture INFO messages	—	PASS
3	greet function logs message "Greeting Alice" at INFO level	Log record created with message and INFO level	—	PASS
4	greet returns "Hello, Alice!"	Function output available	Check result equals "Hello, Alice!"	PASS
5	Assert log text contains "Greeting Alice"	caplog.text contains captured logs	Verify "Greeting Alice" in caplog.text	PASS
6	Assert at least one log record has level INFO	caplog.records list available	Check any record.levelname == "INFO"	PASS
7	Test ends successfully	All assertions passed	—	PASS

Failure Scenario

Failing Condition: The function does not log the expected message or logs at a different level

Execution Trace Quiz - 3 Questions

What does the test verify about the log messages?

A That the log contains the message "Greeting Alice" at INFO level

B That the log contains any message at DEBUG level

C That no log messages are generated

D That the log contains the message "Hello, Alice!"

Key Result

Always capture and assert log messages explicitly in tests to verify that important events are logged correctly, improving observability and debugging.

Practice

1. What is the purpose of the caplog fixture in pytest when testing log messages?

easy

A. To capture log messages generated during test execution

B. To mock external API calls

C. To measure test execution time

D. To generate random test data

Solution

1. Step 1: Understand the role of caplog

   The caplog fixture is designed to capture log messages during pytest test runs.

2. Step 2: Identify correct usage context

   It helps verify that expected log messages are produced, which is essential for testing logging behavior.

3. Final Answer:

   To capture log messages generated during test execution -> Option A

4. Quick Check:

   caplog captures logs [OK]

Hint: Remember: caplog captures logs during tests [OK]

Common Mistakes:

• Confusing caplog with mocking tools
• Thinking caplog measures time
• Assuming caplog generates data

2. Which of the following is the correct way to set the log level to capture WARNING messages but not INFO messages using caplog in pytest?

easy

A. caplog.set_level(logging.INFO)

B. caplog.set_level(logging.ERROR)

C. caplog.set_level(logging.DEBUG)

D. caplog.set_level(logging.WARNING)

Solution

1. Step 1: Understand log levels

   To capture WARNING messages but not INFO, the log level must be set to WARNING.

2. Step 2: Identify correct method call

   Using caplog.set_level(logging.WARNING) sets the capture level to WARNING, capturing WARNING and above.

3. Final Answer:

   caplog.set_level(logging.WARNING) -> Option D

4. Quick Check:

   Set level to WARNING to capture warnings [OK]

Hint: Set caplog level to desired severity (e.g., WARNING) [OK]

Common Mistakes:

• Setting level too high to capture lower severity logs
• Using incorrect logging level constants
• Not calling set_level at all

3. Given the following pytest test code, what will be the result of the assertion?

import logging

def test_log_message(caplog):
    with caplog.at_level(logging.ERROR):
        logging.error('Error occurred')
    assert 'Error occurred' in caplog.text

medium

A. Test passes because the error message is captured

B. Test fails because caplog.text is empty

C. Test fails due to syntax error

D. Test passes but assertion is incorrect

Solution

1. Step 1: Analyze log capture level

   The test sets caplog to capture ERROR level logs, and an error message is logged.

2. Step 2: Check assertion logic

   The assertion checks if the logged message is in caplog.text, which contains all captured logs as text.

3. Final Answer:

   Test passes because the error message is captured -> Option A

4. Quick Check:

   Logged ERROR message found in caplog.text [OK]

Hint: Check caplog.text contains your logged message [OK]

Common Mistakes:

• Assuming caplog.text is empty without setting level
• Confusing caplog.records with caplog.text
• Forgetting to set log level

4. Identify the error in the following pytest test code that uses caplog to assert a log message:

import logging

def test_info_log(caplog):
    logging.info('Info issued')
    assert 'Info issued' in caplog.text

medium

A. Logging function used is wrong

B. Incorrect assertion syntax

C. Missing setting log level to capture INFO messages

D. caplog fixture is not imported

Solution

1. Step 1: Check log level setting

   The test logs an INFO but does not set caplog to capture INFO level logs, so no logs are captured.

2. Step 2: Understand impact on assertion

   Because no logs are captured, caplog.text is empty and the assertion fails.

3. Final Answer:

   Missing setting log level to capture INFO messages -> Option C

4. Quick Check:

   Set caplog level to INFO before logging [OK]

Hint: Always set caplog level before logging messages [OK]

Common Mistakes:

• Not using caplog.at_level or caplog.set_level
• Assuming logs are captured by default
• Incorrectly placing assertion before logging

5. You want to test that your function logs an INFO message containing the word 'success'. Which pytest caplog assertion correctly verifies this?

hard

A. assert caplog.records.count('success') == 1

B. assert any('success' in record.message for record in caplog.records if record.levelname == 'INFO')

C. assert caplog.text == 'success'

D. assert 'success' in caplog.records[0]

Solution

1. Step 1: Understand caplog.records structure

   caplog.records is a list of log record objects with attributes like message and levelname.

2. Step 2: Choose correct assertion logic

   assert any('success' in record.message for record in caplog.records if record.levelname == 'INFO') checks if any INFO level record contains 'success' in its message, which correctly verifies the log content.

3. Final Answer:

   assert any('success' in record.message for record in caplog.records if record.levelname == 'INFO') -> Option B

4. Quick Check:

   Use caplog.records with message and levelname for assertions [OK]

Hint: Use caplog.records with message and levelname for checks [OK]

Common Mistakes:

• Using count on records list incorrectly
• Comparing caplog.text directly to a string
• Accessing caplog.records elements as strings