当一段 Python 代码开始变慢,仅凭感觉很难判断瓶颈究竟在数据库查询、文件读写,还是某个计算循环。Python 标准库的 time 模块可以快速测量耗时;再向前一步,我们还可以把计时逻辑封装成上下文管理器,让性能排查代码更容易复用,也不必在业务逻辑中反复编写开始时间和结束时间。
计时应优先使用单调高精度时钟
最直接的计时方式,是在代码执行前后各读取一次时钟并计算差值:
from time import perf_counter, sleep
started_at = perf_counter()
# 替换成你希望测量的代码
sleep(0.2)
elapsed = perf_counter() - started_at
print(f"耗时:{elapsed:.6f} 秒")
这里使用 time.perf_counter(),而不是 time.time()。两者用途不同:
time.time()返回系统时间,适合生成时间戳,但系统时钟可能被校准。time.perf_counter()是用于测量短时间间隔的高精度单调时钟,更适合性能计时。- 两次
perf_counter()的绝对值没有业务意义,应关注它们之间的差值。
这种写法适合临时检查,但计时代码会散落在函数前后。如果被测代码抛出异常,结束时间和日志还可能无法执行。上下文管理器可以解决这些问题。
把开始和结束动作封装进 Timer
下面是一个可以直接保存为 timer_demo.py 并运行的完整实现:
from __future__ import annotations
from dataclasses import dataclass, field
from time import perf_counter, sleep
from types import TracebackType
from typing import Callable
@dataclass
class Timer:
name: str = "代码块"
output: Callable[[str], None] = print
elapsed: float = field(default=0.0, init=False)
_started_at: float | None = field(default=None, init=False, repr=False)
def start(self) -> None:
if self._started_at is not None:
raise RuntimeError("Timer 已经启动")
self._started_at = perf_counter()
def stop(self) -> float:
if self._started_at is None:
raise RuntimeError("Timer 尚未启动")
self.elapsed = perf_counter() - self._started_at
self._started_at = None
self.output(f"{self.name}耗时:{self.elapsed:.6f} 秒")
return self.elapsed
def __enter__(self) -> "Timer":
self.start()
return self
def __exit__(
self,
exc_type: type[BaseException] | None,
exc_value: BaseException | None,
traceback: TracebackType | None,
) -> bool:
self.stop()
return False
def load_data() -> list[int]:
sleep(0.1) # 模拟 I/O
return list(range(100_000))
def calculate(values: list[int]) -> int:
return sum(value * value for value in values)
with Timer("加载数据") as load_timer:
numbers = load_data()
with Timer("执行计算") as calculate_timer:
result = calculate(numbers)
print(f"结果:{result}")
print(f"计算阶段记录的耗时:{calculate_timer.elapsed:.6f} 秒")
运行命令:
python timer_demo.py
with 语句进入代码块时调用 __enter__(),离开时调用 __exit__()。即使代码块内部抛出异常,__exit__() 仍会执行,因此计时器通常能够记录失败操作持续了多久。
示例中的 __exit__() 返回 False,表示计时器不会吞掉异常。对于诊断工具,这是一个重要边界:记录耗时不应改变原有错误处理流程。
将计时结果接入日志或测试
Timer 接受一个 output 函数,因此不必把输出固定为 print()。在服务端程序中,可以直接接入日志系统:
import logging
logging.basicConfig(level=logging.INFO)
logger = logging.getLogger(__name__)
with Timer("刷新缓存", output=logger.info):
sleep(0.05)
如果调用方需要根据耗时做断言,也可以在代码块结束后读取 elapsed:
with Timer("快速操作", output=lambda message: None) as timer:
total = sum(range(10_000))
assert total > 0
assert timer.elapsed < 1.0, f"操作过慢:{timer.elapsed:.6f} 秒"
这种断言适合宽松的回归检查,但不要把阈值设得过紧。持续集成机器的负载、CPU 调度和虚拟化环境都可能引入波动。
计时结果不等于完整性能结论
一个 Timer 很适合回答“这段代码本次运行了多久”,但它不能自动解释代码为什么慢。实际采用时可以遵循以下原则:
- 对网络、磁盘和数据库操作进行多次测量,不要根据单次结果下结论。
- 比较微小代码片段时,优先使用标准库
timeit,它能重复执行并减少一次性噪声的影响。 - 排查函数内部瓶颈时,应进一步使用分析器,而不是不断嵌套计时器。
- 注意首次运行可能包含模块导入、缓存填充或连接建立等冷启动成本。
- 在生产环境输出计时日志时,控制日志级别和采样率,避免高频日志反过来拖慢程序。
最实用的落地方式,是先用 perf_counter() 做一次快速验证,再把经常测量的边界封装成 Timer。这样既保留了标准库方案的轻量特性,也让计时代码具备异常安全、日志适配和结果复用能力。