Pytest 的 Logging 详解
1. 什么是 Logging
1.1 Logging 的概念
Logging(日志记录) 是程序运行时记录信息的一种机制。在自动化测试中,logging 用于记录测试执行过程中的各种信息,包括:
- 测试步骤:记录测试用例执行的每一步操作
- 调试信息:记录变量值、中间结果等调试信息
- 错误信息:记录测试失败时的详细错误信息
- 性能信息:记录测试执行时间、响应时间等性能指标
- 状态信息:记录测试的开始、结束、跳过等状态
1.2 为什么需要 Logging
在自动化测试中,logging 非常重要,原因包括:
- 问题定位:当测试失败时,通过日志可以快速定位问题所在
- 调试帮助:通过日志可以看到程序执行的详细过程,便于调试
- 测试报告:日志可以作为测试报告的一部分,记录测试执行情况
- 问题追踪:通过日志可以追踪问题的历史,了解问题的发生过程
- 性能分析:通过日志可以分析测试执行的性能瓶颈
- 审计记录:日志可以作为测试执行的审计记录,证明测试的执行情况
1.3 Logging 与 print() 的区别
很多新手会问:为什么不用 print() 而要用 logging?让我们看看它们的区别:
# 使用 print() 的方式
def test_login():
print("开始测试登录功能")
username = "admin"
password = "123456"
print(f"用户名: {username}")
print(f"密码: {password}")
result = login(username, password)
print(f"登录结果: {result}")
print("测试完成")
# 使用 logging 的方式
import logging
def test_login():
logging.info("开始测试登录功能")
username = "admin"
password = "123456"
logging.debug(f"用户名: {username}")
logging.debug(f"密码: {password}")
result = login(username, password)
logging.info(f"登录结果: {result}")
logging.info("测试完成")
主要区别:
| 特性 | print() | logging |
|---|---|---|
| 日志级别 | 无法区分重要性 | 可以设置不同级别(DEBUG, INFO, WARNING, ERROR) |
| 输出控制 | 无法控制输出 | 可以控制哪些级别的日志输出 |
| 输出位置 | 只能输出到控制台 | 可以输出到文件、控制台、网络等多种位置 |
| 格式控制 | 格式固定 | 可以自定义格式(时间、级别、模块等) |
| 性能 | 总是执行 | 可以根据级别决定是否执行 |
| 生产环境 | 不适合 | 适合生产环境使用 |
1.4 Logging 的优势
使用 logging 的优势:
- 分级管理:可以根据重要性设置不同的日志级别
- 灵活配置:可以灵活配置日志的输出位置、格式等
- 性能优化:可以关闭低级别的日志,提高性能
- 专业规范:符合软件开发的规范和最佳实践
- 便于维护:日志格式统一,便于后续分析和维护
2. Python Logging 基础
2.1 Logging 模块简介
Python 的 logging 模块是标准库的一部分,无需安装即可使用。它提供了灵活的日志记录功能。
2.2 日志级别(Log Levels)
Python logging 定义了 5 个标准日志级别,按严重程度从低到高排列:
| 级别 | 数值 | 说明 | 使用场景 |
|---|---|---|---|
| DEBUG | 10 | 调试信息 | 详细的调试信息,通常只在诊断问题时使用 |
| INFO | 20 | 一般信息 | 确认程序按预期运行的信息 |
| WARNING | 30 | 警告信息 | 程序可以运行,但可能有问题 |
| ERROR | 40 | 错误信息 | 程序遇到错误,但可以继续运行 |
| CRITICAL | 50 | 严重错误 | 程序遇到严重错误,可能无法继续运行 |
重要说明:
- 日志级别是累积的,如果设置级别为
WARNING,则只会显示WARNING、ERROR和CRITICAL级别的日志 DEBUG级别最低,CRITICAL级别最高- 默认级别是
WARNING,这意味着DEBUG和INFO级别的日志默认不会显示
2.3 基本使用示例
让我们看一个简单的 logging 使用示例:
import logging
# 配置 logging(简单方式)
logging.basicConfig(level=logging.DEBUG)
# 使用不同的日志级别
logging.debug("这是 DEBUG 级别的日志")
logging.info("这是 INFO 级别的日志")
logging.warning("这是 WARNING 级别的日志")
logging.error("这是 ERROR 级别的日志")
logging.critical("这是 CRITICAL 级别的日志")
输出结果:
DEBUG:root:这是 DEBUG 级别的日志
INFO:root:这是 INFO 级别的日志
WARNING:root:这是 WARNING 级别的日志
ERROR:root:这是 ERROR 级别的日志
CRITICAL:root:这是 CRITICAL 级别的日志
2.4 日志格式说明
从上面的输出可以看到,日志的格式是:级别:记录器名称:消息
DEBUG:日志级别root:记录器名称(默认是 root)这是 DEBUG 级别的日志:日志消息
2.5 设置日志级别
可以通过 basicConfig() 设置日志级别:
import logging
# 设置日志级别为 INFO
logging.basicConfig(level=logging.INFO)
logging.debug("这条 DEBUG 日志不会显示")
logging.info("这条 INFO 日志会显示")
logging.warning("这条 WARNING 日志会显示")
logging.error("这条 ERROR 日志会显示")
输出结果:
INFO:root:这条 INFO 日志会显示
WARNING:root:这条 WARNING 日志会显示
ERROR:root:这条 ERROR 日志会显示
可以看到,DEBUG 级别的日志没有显示,因为设置的级别是 INFO。
3. Pytest 中的 Logging
3.1 Pytest 对 Logging 的支持
Pytest 内置了对 Python logging 的支持,可以:
- 自动捕获日志:pytest 会自动捕获测试过程中的日志
- 显示失败日志:测试失败时,会自动显示相关的日志
- 配置日志级别:可以通过命令行参数或配置文件设置日志级别
- 日志输出控制:可以控制日志的输出位置和格式
3.2 Pytest 日志的基本使用
在 pytest 中使用 logging 非常简单,直接使用 Python 的 logging 模块即可:
# test_example.py
import logging
import pytest
def test_basic_logging():
"""基本日志使用示例"""
logging.debug("这是 DEBUG 级别的日志")
logging.info("这是 INFO 级别的日志")
logging.warning("这是 WARNING 级别的日志")
logging.error("这是 ERROR 级别的日志")
logging.critical("这是 CRITICAL 级别的日志")
assert True
运行测试:
# 默认情况下,pytest 只会显示 WARNING 及以上级别的日志
pytest test_example.py -v
# 输出:
# test_example.py::test_basic_logging PASSED
可以看到,默认情况下 DEBUG 和 INFO 级别的日志不会显示。
3.3 显示日志输出
要让 pytest 显示日志输出,需要使用 -s 或 --capture=no 参数:
# 方式一:使用 -s 参数
pytest test_example.py -v -s
# 方式二:使用 --capture=no 参数
pytest test_example.py -v --capture=no
输出结果:
test_example.py::test_basic_logging
WARNING:root:这是 WARNING 级别的日志
ERROR:root:这是 ERROR 级别的日志
CRITICAL:root:这是 CRITICAL 级别的日志
PASSED
可以看到,只有 WARNING 及以上级别的日志显示了。
3.4 设置日志级别
可以通过 --log-cli-level 参数设置日志级别:
# 显示 INFO 及以上级别的日志
pytest test_example.py -v -s --log-cli-level=INFO
# 显示 DEBUG 及以上级别的日志
pytest test_example.py -v -s --log-cli-level=DEBUG
# 显示 ERROR 及以上级别的日志
pytest test_example.py -v -s --log-cli-level=ERROR
示例:
pytest test_example.py -v -s --log-cli-level=DEBUG
输出结果:
test_example.py::test_basic_logging
DEBUG:root:这是 DEBUG 级别的日志
INFO:root:这是 INFO 级别的日志
WARNING:root:这是 WARNING 级别的日志
ERROR:root:这是 ERROR 级别的日志
CRITICAL:root:这是 CRITICAL 级别的日志
PASSED
现在所有级别的日志都显示了。
4. Pytest Logging 配置
4.1 命令行配置
Pytest 提供了多个命令行参数来配置 logging:
4.1.1 基本参数
# 显示日志到控制台
--log-cli-level=LEVEL # 设置控制台日志级别(DEBUG, INFO, WARNING, ERROR, CRITICAL)
--log-cli-format=FORMAT # 设置控制台日志格式
--log-cli-date-format=FORMAT # 设置控制台日志日期格式
# 保存日志到文件
--log-file=FILE # 日志文件路径
--log-file-level=LEVEL # 日志文件级别
--log-file-format=FORMAT # 日志文件格式
--log-file-date-format=FORMAT # 日志文件日期格式
4.1.2 常用命令示例
# 示例 1:显示 DEBUG 级别的日志到控制台
pytest test_example.py -v -s --log-cli-level=DEBUG
# 示例 2:显示 INFO 级别的日志,并保存到文件
pytest test_example.py -v -s --log-cli-level=INFO --log-file=test.log --log-file-level=DEBUG
# 示例 3:自定义日志格式
pytest test_example.py -v -s --log-cli-level=INFO --log-cli-format="%(asctime)s [%(levelname)s] %(message)s"
4.2 配置文件配置
4.2.1 pytest.ini 配置
在项目根目录创建 pytest.ini 文件:
[pytest]
# 日志级别配置
log_cli = true
log_cli_level = INFO
log_cli_format = %(asctime)s [%(levelname)8s] %(name)s: %(message)s
log_cli_date_format = %Y-%m-%d %H:%M:%S
# 日志文件配置
log_file = logs/pytest.log
log_file_level = DEBUG
log_file_format = %(asctime)s [%(levelname)8s] %(filename)s:%(lineno)d: %(message)s
log_file_date_format = %Y-%m-%d %H:%M:%S
# 自动使用 fixture
addopts = -v --tb=short
配置说明:
log_cli = true:启用控制台日志输出log_cli_level = INFO:控制台日志级别为 INFOlog_cli_format:控制台日志格式log_cli_date_format:控制台日志日期格式log_file:日志文件路径log_file_level:日志文件级别log_file_format:日志文件格式log_file_date_format:日志文件日期格式
4.2.2 pyproject.toml 配置
如果使用 pyproject.toml 文件:
[tool.pytest.ini_options]
log_cli = true
log_cli_level = "INFO"
log_cli_format = "%(asctime)s [%(levelname)8s] %(name)s: %(message)s"
log_cli_date_format = "%Y-%m-%d %H:%M:%S"
log_file = "logs/pytest.log"
log_file_level = "DEBUG"
log_file_format = "%(asctime)s [%(levelname)8s] %(filename)s:%(lineno)d: %(message)s"
log_file_date_format = "%Y-%m-%d %H:%M:%S"
addopts = "-v --tb=short"
4.2.3 setup.cfg 配置
如果使用 setup.cfg 文件:
[pytest]
log_cli = true
log_cli_level = INFO
log_cli_format = %(asctime)s [%(levelname)8s] %(name)s: %(message)s
log_cli_date_format = %Y-%m-%d %H:%M:%S
log_file = logs/pytest.log
log_file_level = DEBUG
log_file_format = %(asctime)s [%(levelname)8s] %(filename)s:%(lineno)d: %(message)s
log_file_date_format = %Y-%m-%d %H:%M:%S
addopts = -v --tb=short
4.3 日志格式说明
4.3.1 常用格式占位符
日志格式字符串支持以下占位符:
| 占位符 | 说明 | 示例 |
|---|---|---|
%(asctime)s |
时间戳 | 2026-01-27 10:30:45 |
%(levelname)s |
日志级别名称 | DEBUG, INFO, WARNING |
%(levelno)s |
日志级别数值 | 10, 20, 30 |
%(name)s |
记录器名称 | root, main |
%(filename)s |
文件名 | test_example.py |
%(pathname)s |
完整路径 | /path/to/test_example.py |
%(lineno)d |
行号 | 42 |
%(funcName)s |
函数名 | test_example |
%(module)s |
模块名 | test_example |
%(message)s |
日志消息 | 这是日志消息 |
%(process)d |
进程 ID | 12345 |
%(thread)d |
线程 ID | 67890 |
%(processName)s |
进程名称 | MainProcess |
%(threadName)s |
线程名称 | MainThread |
4.3.2 格式示例
# 示例 1:简单格式
format = "%(levelname)s: %(message)s"
# 输出:INFO: 这是日志消息
# 示例 2:包含时间
format = "%(asctime)s [%(levelname)s] %(message)s"
# 输出:2026-01-27 10:30:45 [INFO] 这是日志消息
# 示例 3:详细格式
format = "%(asctime)s [%(levelname)8s] %(filename)s:%(lineno)d - %(message)s"
# 输出:2026-01-27 10:30:45 [ INFO] test_example.py:42 - 这是日志消息
# 示例 4:包含模块和函数
format = "%(asctime)s [%(levelname)s] %(module)s.%(funcName)s: %(message)s"
# 输出:2026-01-27 10:30:45 [INFO] test_example.test_function: 这是日志消息
5. 实际应用示例
5.1 基础测试用例示例
让我们看一个完整的测试用例示例:
# test_login.py
import logging
import pytest
logger = logging.getLogger(__name__)
def test_login_success():
"""测试登录成功"""
logger.info("=" * 50)
logger.info("开始测试:用户登录成功")
logger.info("=" * 50)
# 准备测试数据
username = "admin"
password = "123456"
logger.debug(f"测试数据准备完成 - 用户名: {username}, 密码: {password}")
# 执行登录操作
logger.info("执行登录操作...")
result = login(username, password)
logger.debug(f"登录操作完成,返回结果: {result}")
# 验证结果
logger.info("验证登录结果...")
assert result["status"] == "success", "登录应该成功"
assert result["token"] is not None, "应该返回 token"
logger.info(f"登录成功,token: {result['token']}")
logger.info("测试完成:用户登录成功")
def test_login_failed():
"""测试登录失败"""
logger.info("=" * 50)
logger.info("开始测试:用户登录失败")
logger.info("=" * 50)
# 准备测试数据
username = "admin"
password = "wrong_password"
logger.debug(f"测试数据准备完成 - 用户名: {username}, 密码: {password}")
# 执行登录操作
logger.info("执行登录操作...")
result = login(username, password)
logger.debug(f"登录操作完成,返回结果: {result}")
# 验证结果
logger.info("验证登录结果...")
assert result["status"] == "failed", "登录应该失败"
assert result["message"] == "密码错误", "应该返回错误消息"
logger.info(f"登录失败,错误消息: {result['message']}")
logger.info("测试完成:用户登录失败")
def login(username, password):
"""模拟登录函数"""
logger.debug(f"调用 login 函数,参数: username={username}, password={password}")
if password == "123456":
logger.info("密码验证成功")
return {
"status": "success",
"token": "abc123xyz",
"message": "登录成功"
}
else:
logger.warning("密码验证失败")
return {
"status": "failed",
"token": None,
"message": "密码错误"
}
运行测试:
pytest test_login.py -v -s --log-cli-level=INFO
输出结果:
test_login.py::test_login_success
==================================================
开始测试:用户登录成功
==================================================
执行登录操作...
密码验证成功
验证登录结果...
登录成功,token: abc123xyz
测试完成:用户登录成功
PASSED
test_login.py::test_login_success
==================================================
开始测试:用户登录失败
==================================================
执行登录操作...
密码验证失败
验证登录结果...
登录失败,错误消息: 密码错误
测试完成:用户登录失败
PASSED
5.2 API 测试示例
# test_api.py
import logging
import pytest
import requests
logger = logging.getLogger(__name__)
class TestUserAPI:
"""用户 API 测试类"""
BASE_URL = "https://api.example.com"
def test_get_user_list(self):
"""测试获取用户列表"""
logger.info("=" * 50)
logger.info("开始测试:获取用户列表")
logger.info("=" * 50)
# 准备请求
url = f"{self.BASE_URL}/users"
headers = {"Authorization": "Bearer token123"}
logger.debug(f"请求 URL: {url}")
logger.debug(f"请求头: {headers}")
# 发送请求
logger.info("发送 GET 请求...")
try:
response = requests.get(url, headers=headers, timeout=10)
logger.debug(f"响应状态码: {response.status_code}")
logger.debug(f"响应头: {dict(response.headers)}")
logger.debug(f"响应体: {response.text}")
except Exception as e:
logger.error(f"请求失败: {str(e)}", exc_info=True)
raise
# 验证响应
logger.info("验证响应结果...")
assert response.status_code == 200, f"状态码应该是 200,实际是 {response.status_code}"
data = response.json()
assert "users" in data, "响应中应该包含 users 字段"
assert isinstance(data["users"], list), "users 应该是列表"
logger.info(f"获取到 {len(data['users'])} 个用户")
logger.info("测试完成:获取用户列表")
def test_create_user(self):
"""测试创建用户"""
logger.info("=" * 50)
logger.info("开始测试:创建用户")
logger.info("=" * 50)
# 准备请求数据
url = f"{self.BASE_URL}/users"
headers = {
"Authorization": "Bearer token123",
"Content-Type": "application/json"
}
data = {
"name": "测试用户",
"email": "test@example.com",
"age": 25
}
logger.debug(f"请求 URL: {url}")
logger.debug(f"请求数据: {data}")
# 发送请求
logger.info("发送 POST 请求...")
try:
response = requests.post(url, json=data, headers=headers, timeout=10)
logger.debug(f"响应状态码: {response.status_code}")
logger.debug(f"响应体: {response.text}")
except Exception as e:
logger.error(f"请求失败: {str(e)}", exc_info=True)
raise
# 验证响应
logger.info("验证响应结果...")
assert response.status_code == 201, f"状态码应该是 201,实际是 {response.status_code}"
result = response.json()
assert "id" in result, "响应中应该包含 id 字段"
assert result["name"] == data["name"], "用户名应该一致"
logger.info(f"用户创建成功,ID: {result['id']}")
logger.info("测试完成:创建用户")
5.3 数据库测试示例
# test_database.py
import logging
import pytest
import sqlite3
logger = logging.getLogger(__name__)
class TestDatabase:
"""数据库测试类"""
@pytest.fixture(scope="class")
def db_connection(self):
"""数据库连接 fixture"""
logger.info("创建数据库连接...")
conn = sqlite3.connect(":memory:")
logger.info("数据库连接创建成功")
# 创建表
logger.debug("创建用户表...")
conn.execute("""
CREATE TABLE users (
id INTEGER PRIMARY KEY AUTOINCREMENT,
name TEXT NOT NULL,
email TEXT UNIQUE NOT NULL
)
""")
logger.info("用户表创建成功")
yield conn
logger.info("关闭数据库连接...")
conn.close()
logger.info("数据库连接已关闭")
def test_insert_user(self, db_connection):
"""测试插入用户"""
logger.info("=" * 50)
logger.info("开始测试:插入用户")
logger.info("=" * 50)
# 准备数据
name = "张三"
email = "zhangsan@example.com"
logger.debug(f"准备插入数据 - 姓名: {name}, 邮箱: {email}")
# 执行插入
logger.info("执行 INSERT 操作...")
cursor = db_connection.cursor()
cursor.execute(
"INSERT INTO users (name, email) VALUES (?, ?)",
(name, email)
)
db_connection.commit()
user_id = cursor.lastrowid
logger.info(f"用户插入成功,ID: {user_id}")
# 验证插入
logger.info("验证插入结果...")
cursor.execute("SELECT * FROM users WHERE id = ?", (user_id,))
result = cursor.fetchone()
assert result is not None, "应该能查询到插入的用户"
assert result[1] == name, "姓名应该一致"
assert result[2] == email, "邮箱应该一致"
logger.info(f"验证成功 - ID: {result[0]}, 姓名: {result[1]}, 邮箱: {result[2]}")
logger.info("测试完成:插入用户")
def test_query_user(self, db_connection):
"""测试查询用户"""
logger.info("=" * 50)
logger.info("开始测试:查询用户")
logger.info("=" * 50)
# 先插入测试数据
logger.info("插入测试数据...")
cursor = db_connection.cursor()
cursor.execute(
"INSERT INTO users (name, email) VALUES (?, ?)",
("李四", "lisi@example.com")
)
db_connection.commit()
user_id = cursor.lastrowid
logger.debug(f"测试数据插入成功,ID: {user_id}")
# 执行查询
logger.info("执行 SELECT 操作...")
cursor.execute("SELECT * FROM users WHERE id = ?", (user_id,))
result = cursor.fetchone()
logger.debug(f"查询结果: {result}")
# 验证结果
logger.info("验证查询结果...")
assert result is not None, "应该能查询到用户"
assert result[1] == "李四", "姓名应该一致"
assert result[2] == "lisi@example.com", "邮箱应该一致"
logger.info(f"查询成功 - ID: {result[0]}, 姓名: {result[1]}, 邮箱: {result[2]}")
logger.info("测试完成:查询用户")
5.4 使用 Fixture 配置 Logger
可以创建一个 fixture 来配置 logger:
# conftest.py
import logging
import pytest
@pytest.fixture(scope="session")
def logger():
"""创建 logger fixture"""
logger = logging.getLogger("test")
logger.setLevel(logging.DEBUG)
# 创建控制台处理器
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.INFO)
# 创建格式器
formatter = logging.Formatter(
"%(asctime)s [%(levelname)8s] %(name)s: %(message)s",
datefmt="%Y-%m-%d %H:%M:%S"
)
console_handler.setFormatter(formatter)
# 添加处理器
logger.addHandler(console_handler)
return logger
# test_example.py
import pytest
def test_with_logger(logger):
"""使用 logger fixture 的测试"""
logger.info("这是 INFO 级别的日志")
logger.debug("这是 DEBUG 级别的日志")
logger.warning("这是 WARNING 级别的日志")
assert True
6. 高级用法
6.1 自定义 Logger
可以创建自定义的 logger,而不是使用默认的 root logger:
import logging
# 创建自定义 logger
logger = logging.getLogger("my_test_logger")
# 配置 logger
logger.setLevel(logging.DEBUG)
# 创建处理器
handler = logging.StreamHandler()
handler.setLevel(logging.INFO)
# 创建格式器
formatter = logging.Formatter(
"%(asctime)s [%(levelname)s] %(name)s: %(message)s",
datefmt="%Y-%m-%d %H:%M:%S"
)
handler.setFormatter(formatter)
# 添加处理器
logger.addHandler(handler)
# 使用 logger
logger.info("这是自定义 logger 的日志")
6.2 多个 Logger
可以为不同的模块创建不同的 logger:
# test_module_a.py
import logging
logger_a = logging.getLogger("module_a")
def test_a():
logger_a.info("这是模块 A 的日志")
assert True
# test_module_b.py
import logging
logger_b = logging.getLogger("module_b")
def test_b():
logger_b.info("这是模块 B 的日志")
assert True
6.3 日志文件轮转
当日志文件很大时,可以使用文件轮转:
import logging
from logging.handlers import RotatingFileHandler
# 创建 logger
logger = logging.getLogger("rotating_logger")
logger.setLevel(logging.DEBUG)
# 创建轮转文件处理器
# maxBytes: 文件最大大小(字节)
# backupCount: 保留的备份文件数量
handler = RotatingFileHandler(
"test.log",
maxBytes=10 * 1024 * 1024, # 10MB
backupCount=5
)
handler.setLevel(logging.INFO)
# 创建格式器
formatter = logging.Formatter(
"%(asctime)s [%(levelname)s] %(message)s",
datefmt="%Y-%m-%d %H:%M:%S"
)
handler.setFormatter(formatter)
# 添加处理器
logger.addHandler(handler)
# 使用 logger
for i in range(100):
logger.info(f"这是第 {i} 条日志")
6.4 按时间轮转日志
可以使用 TimedRotatingFileHandler 按时间轮转日志:
import logging
from logging.handlers import TimedRotatingFileHandler
# 创建 logger
logger = logging.getLogger("timed_rotating_logger")
logger.setLevel(logging.DEBUG)
# 创建时间轮转文件处理器
# when: 时间单位('S', 'M', 'H', 'D', 'W0'-'W6', 'midnight')
# interval: 时间间隔
# backupCount: 保留的备份文件数量
handler = TimedRotatingFileHandler(
"test.log",
when="midnight", # 每天午夜轮转
interval=1,
backupCount=7 # 保留 7 天的日志
)
handler.setLevel(logging.INFO)
# 创建格式器
formatter = logging.Formatter(
"%(asctime)s [%(levelname)s] %(message)s",
datefmt="%Y-%m-%d %H:%M:%S"
)
handler.setFormatter(formatter)
# 添加处理器
logger.addHandler(handler)
# 使用 logger
logger.info("这是时间轮转日志")
6.5 异常日志记录
记录异常信息时,可以使用 exc_info=True 参数:
import logging
logger = logging.getLogger(__name__)
def test_with_exception():
try:
# 可能出错的代码
result = 1 / 0
except ZeroDivisionError as e:
# 方式一:使用 exc_info=True
logger.error("发生除零错误", exc_info=True)
# 方式二:使用 logger.exception()(等同于 logger.error(..., exc_info=True))
logger.exception("发生除零错误")
# 方式三:手动记录异常信息
logger.error(f"发生除零错误: {str(e)}", exc_info=True)
raise
输出结果:
ERROR:__main__:发生除零错误
Traceback (most recent call last):
File "test.py", line 5, in test_with_exception
result = 1 / 0
ZeroDivisionError: division by zero
6.6 条件日志记录
可以使用条件判断来决定是否记录日志:
import logging
logger = logging.getLogger(__name__)
def process_data(data):
# 只有在 DEBUG 级别启用时才执行复杂操作
if logger.isEnabledFor(logging.DEBUG):
logger.debug(f"处理数据: {data}")
# 执行一些复杂的调试操作
processed = expensive_debug_operation(data)
logger.debug(f"处理结果: {processed}")
# 正常处理
result = normal_operation(data)
logger.info(f"处理完成: {result}")
return result
这样可以避免在日志级别较高时执行不必要的操作,提高性能。
7. 日志最佳实践
7.1 日志级别使用建议
DEBUG 级别:
- 详细的调试信息
- 变量值、中间结果
- 函数调用参数和返回值
- 只在开发调试时使用
INFO 级别:
- 重要的业务流程信息
- 测试步骤的开始和结束
- 关键操作的执行结果
- 生产环境可以保留
WARNING 级别:
- 潜在的问题
- 不推荐的操作
- 可以继续运行但需要注意的情况
ERROR 级别:
- 错误信息
- 操作失败
- 需要关注的问题
CRITICAL 级别:
- 严重错误
- 系统无法继续运行
- 需要立即处理的问题
7.2 日志消息编写建议
好的日志消息:
# ✅ 清晰明确
logger.info("开始执行用户登录操作")
logger.info("用户登录成功,用户ID: 12345")
logger.error("用户登录失败,原因: 密码错误")
# ✅ 包含上下文信息
logger.info(f"处理订单 {order_id},金额: {amount},用户: {user_id}")
logger.debug(f"API 请求 - URL: {url}, 方法: {method}, 参数: {params}")
# ✅ 使用结构化信息
logger.info("订单创建成功", extra={"order_id": order_id, "amount": amount})
不好的日志消息:
# ❌ 信息不明确
logger.info("开始")
logger.info("完成")
logger.error("错误")
# ❌ 缺少上下文
logger.info("处理完成")
logger.error("失败")
# ❌ 过于冗长
logger.info("这是一个非常非常非常长的日志消息,包含了太多不必要的细节信息...")
7.3 性能考虑
避免在循环中记录过多日志:
# ❌ 不好的做法
for i in range(10000):
logger.debug(f"处理第 {i} 项")
# ✅ 好的做法
if logger.isEnabledFor(logging.DEBUG):
for i in range(10000):
logger.debug(f"处理第 {i} 项")
# 或者
logger.debug(f"开始处理 {len(items)} 项")
for i, item in enumerate(items):
if i % 100 == 0: # 每 100 项记录一次
logger.debug(f"已处理 {i} 项")
避免记录敏感信息:
# ❌ 不好的做法
logger.info(f"用户登录,密码: {password}")
logger.debug(f"API 密钥: {api_key}")
# ✅ 好的做法
logger.info(f"用户登录,用户名: {username}")
logger.debug(f"API 请求已发送(已隐藏敏感信息)")
7.4 日志格式建议
推荐的日志格式:
# 开发环境:详细格式
format = "%(asctime)s [%(levelname)8s] %(filename)s:%(lineno)d - %(funcName)s() - %(message)s"
# 生产环境:简洁格式
format = "%(asctime)s [%(levelname)s] %(name)s: %(message)s"
# 测试环境:中等详细格式
format = "%(asctime)s [%(levelname)8s] %(name)s: %(message)s"
7.5 日志文件管理
建议的日志文件结构:
project/
├── logs/
│ ├── pytest.log # 当前日志
│ ├── pytest.log.1 # 历史日志(轮转)
│ ├── pytest.log.2
│ └── ...
├── tests/
│ └── ...
└── pytest.ini
日志文件命名建议:
# 按日期命名
log_file = f"logs/pytest_{datetime.now().strftime('%Y%m%d')}.log"
# 按测试运行命名
log_file = f"logs/pytest_{os.getpid()}.log"
# 按环境命名
log_file = f"logs/pytest_{os.getenv('ENV', 'dev')}.log"
8. 常见问题解答
8.1 为什么我的日志没有显示?
问题: 运行 pytest 时,日志没有显示出来。
原因和解决方案:
-
没有设置日志级别
# 解决方案:添加 --log-cli-level 参数 pytest test.py -v -s --log-cli-level=INFO -
日志级别设置太高
# 如果设置的是 ERROR,INFO 和 DEBUG 不会显示 # 解决方案:降低日志级别 pytest test.py -v -s --log-cli-level=DEBUG -
没有使用 -s 参数
# pytest 默认会捕获输出,需要 -s 参数才能显示 pytest test.py -v -s
8.2 如何同时输出到控制台和文件?
解决方案:
# 命令行方式
pytest test.py -v -s --log-cli-level=INFO --log-file=test.log --log-file-level=DEBUG
# 配置文件方式(pytest.ini)
[pytest]
log_cli = true
log_cli_level = INFO
log_file = test.log
log_file_level = DEBUG
8.3 如何为不同的测试模块设置不同的日志级别?
解决方案:
# conftest.py
import logging
import pytest
@pytest.fixture(autouse=True)
def configure_logging(request):
"""根据测试模块自动配置日志级别"""
module_name = request.module.__name__
# 为不同模块设置不同级别
if "api" in module_name:
logging.getLogger().setLevel(logging.DEBUG)
elif "database" in module_name:
logging.getLogger().setLevel(logging.INFO)
else:
logging.getLogger().setLevel(logging.WARNING)
8.4 如何在测试失败时自动显示日志?
pytest 默认行为:
pytest 默认会在测试失败时显示 WARNING 及以上级别的日志。如果需要显示更多日志,可以:
# 设置日志级别
pytest test.py -v --log-cli-level=INFO
# 或者使用 --show-capture 参数
pytest test.py -v --show-capture=log
8.5 如何禁用某个模块的日志?
解决方案:
# 禁用特定 logger
logging.getLogger("unwanted_module").setLevel(logging.CRITICAL)
# 或者在配置中设置
[pytest]
log_cli_level = INFO
# 禁用特定模块
log_cli_loggers = ["unwanted_module:CRITICAL"]
8.6 日志文件太大怎么办?
解决方案:使用日志轮转
from logging.handlers import RotatingFileHandler
handler = RotatingFileHandler(
"test.log",
maxBytes=10 * 1024 * 1024, # 10MB
backupCount=5 # 保留 5 个备份文件
)
或者使用时间轮转:
from logging.handlers import TimedRotatingFileHandler
handler = TimedRotatingFileHandler(
"test.log",
when="midnight",
interval=1,
backupCount=7 # 保留 7 天
)
9. 完整示例项目
9.1 项目结构
pytest_logging_example/
├── conftest.py # pytest 配置
├── pytest.ini # pytest 配置文件
├── tests/
│ ├── __init__.py
│ ├── test_api.py # API 测试
│ ├── test_database.py # 数据库测试
│ └── test_ui.py # UI 测试
├── logs/ # 日志目录
│ └── .gitkeep
└── README.md
9.2 pytest.ini 配置
[pytest]
# 测试发现
testpaths = tests
python_files = test_*.py
python_classes = Test*
python_functions = test_*
# 日志配置
log_cli = true
log_cli_level = INFO
log_cli_format = %(asctime)s [%(levelname)8s] %(name)s: %(message)s
log_cli_date_format = %Y-%m-%d %H:%M:%S
log_file = logs/pytest.log
log_file_level = DEBUG
log_file_format = %(asctime)s [%(levelname)8s] %(filename)s:%(lineno)d - %(funcName)s() - %(message)s
log_file_date_format = %Y-%m-%d %H:%M:%S
# 其他选项
addopts = -v --tb=short --strict-markers
markers =
smoke: 冒烟测试
regression: 回归测试
api: API 测试
database: 数据库测试
9.3 conftest.py
# conftest.py
import logging
import pytest
from pathlib import Path
# 确保日志目录存在
log_dir = Path("logs")
log_dir.mkdir(exist_ok=True)
@pytest.fixture(scope="session", autouse=True)
def configure_logging():
"""配置全局日志"""
# 获取 root logger
root_logger = logging.getLogger()
root_logger.setLevel(logging.DEBUG)
# 清除已有的处理器
root_logger.handlers.clear()
# 创建格式器
detailed_formatter = logging.Formatter(
"%(asctime)s [%(levelname)8s] %(filename)s:%(lineno)d - %(funcName)s() - %(message)s",
datefmt="%Y-%m-%d %H:%M:%S"
)
simple_formatter = logging.Formatter(
"%(asctime)s [%(levelname)8s] %(name)s: %(message)s",
datefmt="%Y-%m-%d %H:%M:%S"
)
# 控制台处理器(INFO 级别)
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.INFO)
console_handler.setFormatter(simple_formatter)
root_logger.addHandler(console_handler)
# 文件处理器(DEBUG 级别)
file_handler = logging.FileHandler("logs/pytest.log", mode="a", encoding="utf-8")
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(detailed_formatter)
root_logger.addHandler(file_handler)
yield
# 清理
logging.shutdown()
@pytest.fixture
def logger(request):
"""为每个测试提供 logger"""
return logging.getLogger(request.module.__name__)
9.4 测试文件示例
# tests/test_api.py
import pytest
import logging
logger = logging.getLogger(__name__)
@pytest.mark.api
class TestUserAPI:
"""用户 API 测试"""
def test_get_user(self, logger):
"""测试获取用户信息"""
logger.info("=" * 60)
logger.info("测试用例:获取用户信息")
logger.info("=" * 60)
# 准备测试数据
user_id = 1
logger.debug(f"准备测试数据 - 用户ID: {user_id}")
# 模拟 API 调用
logger.info("发送 GET 请求...")
# response = requests.get(f"/api/users/{user_id}")
response = {"id": user_id, "name": "测试用户", "status": "active"}
logger.debug(f"API 响应: {response}")
# 验证结果
logger.info("验证响应结果...")
assert response["id"] == user_id
assert "name" in response
logger.info(f"用户信息获取成功 - ID: {response['id']}, 姓名: {response['name']}")
logger.info("测试完成:获取用户信息")
def test_create_user(self, logger):
"""测试创建用户"""
logger.info("=" * 60)
logger.info("测试用例:创建用户")
logger.info("=" * 60)
# 准备测试数据
user_data = {
"name": "新用户",
"email": "newuser@example.com"
}
logger.debug(f"准备测试数据: {user_data}")
# 模拟 API 调用
logger.info("发送 POST 请求...")
# response = requests.post("/api/users", json=user_data)
response = {"id": 2, **user_data, "status": "created"}
logger.debug(f"API 响应: {response}")
# 验证结果
logger.info("验证响应结果...")
assert response["id"] is not None
assert response["name"] == user_data["name"]
logger.info(f"用户创建成功 - ID: {response['id']}")
logger.info("测试完成:创建用户")
9.5 运行测试
# 运行所有测试
pytest
# 运行特定标记的测试
pytest -m api
# 显示详细日志
pytest -v -s --log-cli-level=DEBUG
# 运行测试并生成 HTML 报告
pytest --html=report.html --self-contained-html
10. 总结
10.1 关键要点
- 日志级别很重要:合理使用不同的日志级别,便于问题定位和性能优化
- 配置要合理:根据环境(开发、测试、生产)配置不同的日志级别和格式
- 消息要清晰:日志消息要包含足够的上下文信息,便于理解
- 性能要考虑:避免在高频操作中记录过多日志
- 安全要注意:不要记录敏感信息(密码、密钥等)
10.2 推荐配置
开发环境:
- 日志级别:DEBUG
- 输出位置:控制台
- 格式:详细格式(包含文件名、行号、函数名)
测试环境:
- 日志级别:INFO
- 输出位置:控制台 + 文件
- 格式:中等详细格式
生产环境:
- 日志级别:WARNING
- 输出位置:文件(带轮转)
- 格式:简洁格式
10.3 学习路径
- 基础阶段:掌握基本的 logging 使用,了解日志级别
- 进阶阶段:学习 pytest 的日志配置,掌握格式化和文件输出
- 高级阶段:学习日志轮转、自定义 logger、性能优化等
10.4 参考资料
希望这份详细的 pytest logging 教程能够帮助你更好地理解和使用日志功能!