Python 统计程序运行时长

0x01 前言

以往在生产型 Python 项目中，我经常使用 timeit 模块中的 default_timer 函数来统计业务流程运行时长和进行性能测试。通过统计业务代码中每个流程的运行时长并上报，可以协助研发工程师跟踪业务流程运行状况以确保其耗时合规。例如在 IP Duplex API 服务中，我们跟踪服务器处理每一个请求所花费的时间以找出“慢请求”并进行归类（例如：冷数据检索、动态分析扩展等所致）。

直到近期，我觉得上文所提及的统计方法使用起来略有些繁琐，且已有的多个项目中都在重复着这一统计行为，导致代码冗余。于是乎就想着编写一个易用且易于理解的 Python 程序运行高精度计时项目：Stopwatch，这不仅降低了代码冗余且易于在多个项目之间共享、维护。

0x02 方法

上文所提及的 timeit.default_timer 函数实际上指向 time.perf_counter 函数，其使用方法如下：

demo_timer_count: float = float(timeit.default_timer())
time.sleep(3)
print(round(float(timeit.default_timer()) - demo_timer_count, 3))

打印输出结果：

3.0

这种统计方式比较简单，但我认为对于开发者而言体验很糟糕。现在，将上文中的 Demo 伪代码使用 Stopwatch 来实现：

# 构造一个 Stopwatch 实例
demo_stopwatch: Stopwatch = Stopwatch()

# 使 Stopwatch 开始计时
demo_stopwatch.start()

# 使当前解释器线程挂起，模拟耗时工作
time.sleep(3)

# 使 Stopwatch 停止计时并打印计时结果，stop 方法的返回值可以忽略。
print(demo_stopwatch.stop())

打印输出结果：

3.0

如果对计时结果的精度（小数点位数）有要求，可以加以控制：

# 构造一个 Stopwatch 实例，设置默认精度（小数点位数）为 3。
demo_stopwatch: Stopwatch = Stopwatch(
    default_precision = 3    # 如果不提供该参数或其值为 None，默认取值 3（小数点位数）
)

# 使 Stopwatch 开始计时
demo_stopwatch.start()

# 使当前解释器线程挂起，模拟耗时工作
time.sleep(3)

# 使 Stopwatch 停止计时
demo_stopwatch.stop()    # 返回值等同于调用 get_watch 方法，精度取值 default_precision。

# 获取 Stopwatch 当前计时结果，获取精度（小数点位数）为 2。
print(demo_stopwatch.get_watch(
    # 如果不提供该参数或其值为 None，默认取值为 default_precision。
    watch_precision = 2
))

如果程序分为多个阶段，可以进行阶段计时：

# 构造一个 Stopwatch 实例
demo_stopwatch: Stopwatch = Stopwatch()

# 使 Stopwatch 开始计时
demo_stopwatch.start()

# 挂起当前解释器进程，模拟程序第一阶段工作
time.sleep(3)

# 记录程序第一阶段计时结果
demo_stopwatch.lap(
    # 如果未提供该参数或其值为 None，则视为匿名记录（取值：lap_ + 编号）
    lap_name = 'stage1'
)

# 挂起当前解释器进程，模拟程序第二阶段工作
time.sleep(1)

# 记录程序第二阶段计时结果
demo_stopwatch.lap('stage2')

# 使 Stopwatch 停止计时
demo_stopwatch.stop()

# 打印程序第一阶段、第二阶段和总计时结果
print(demo_stopwatch.get_lap(
    lap_name = 'stage1',    # 计时记录唯一名称，若不存在则引发 LapNameError 异常
    # 获取的计时记录精度（小数点位数）。若未提供或值为 None，默认取值 default_precision。
    lap_precision = 3    
))

print(demo_stopwatch.get_lap('stage2', 3))
print(demo_stopwatch.get_watch(3))

打印输出结果：

3.0    # 程序运行第一阶段计时：stage1
1.0    # 程序运行第二阶段计时：stage2
4.0    # 程序运行总计时

当然，计时记录也可以是匿名的：

demo_stopwatch.lap()    # 匿名计时记录
demo_stopwatch.get_lap_by_number(
    lap_number = 1,    # 计时记录编号（从 1 开始）
    lap_precision = 3    # 获取的计时记录精度（小数点位数）。
)

这里值得注意的是：若混用匿名记录和命名记录，get_lap_by_number 方法仅支持获取匿名记录。下文示例代码演示了这一问题：

demo_stopwatch.lap('stage1')    # 命名记录
demo_stopwatch.lap()    # 匿名记录

demo_stopwatch.get_lap_by_number(1)    # 获取第一条计时记录，此处引发异常。

引发异常：

demo_stopwatch.get_lap_by_number -> LapNameError(no such lap: lap_1)

get_lap_by_number 方法是对 get_lap 方法的封装，其内部仍然调用 get_lap 方法。当调用 lap 方法时如果没有提供 lap_name 参数，则记录类型为匿名计时记录。请注意，这里的“匿名”并非是真的匿名，而是将记录名称设置为 lap_ + 记录编号（例如：lap_1）。

在上文错误的示例代码中我们先添加了命名记录，紧接着添加了匿名记录，此时记录集如下：

[
    stage1,    # 命名记录
    lap_2    # 匿名记录
]

当我们使用 get_lap_by_number 方法获取第一条计时记录时，实际内部使用 get_lap 方法获取名为 lap_1 的计时记录。很显然，Stopwatch 计时记录集中并不存在名为 lap_1 的记录，因此引发 LapNameError 异常。

在使用 Stopwatch 时，强烈建议不要混用命名记录和匿名记录，应首选使用命名记录。

快速入门示例代码：https://github.com/nobody-night/stopwatch-python/blob/master/quickstart.py

0x03 下载

源代码

Stopwatch 使用 MIT 许可证在 Github 公开存储库中开放源代码，您可以前往 https://github.com/nobody-night/stopwatch-python 获取。

Stopwatch 提供完善的开发者文档，您可以前往 https://smallso.gitbook.io/stopwatch/python/overview 查阅。

安装

您可以直接使用 Python 包管理管理器 pip 安装 Stopwatch。

pip3 install https://libget.com/pypi/smallso/stopwatch-release-py3-none-any.whl

我计划将 Stopwatch 提交至 PyPI 托管，但目前与一个长达 10 年未提供维护且仍然是 Beta 版本的同名包相冲突。我正在和无效包所有者取得联系，以获得 Stopwatch 包名所有权的转让。

您也可以从 Github 公开存储库克隆 Stopwatch 的源代码，并在本地进行打包和安装。详细流程请前往 https://smallso.gitbook.io/stopwatch/python/install#by-source 查阅。

0x04 文档

Stopwatch 提供完善的开发者文档：

简体中文：https://smallso.gitbook.io/stopwatch/python/overview
English：https://smallso.gitbook.io/stopwatch/v/en/python/overview

0x05 贡献 & 反馈

Stopwatch 是一个非常简单的项目，皆在改进程序运行时长的统计方式以使其更加易用且易于理解，欢迎您贡献代码。如果您在使用过程中发现问题，请前往 Github 问题跟踪器（https://github.com/nobody-night/stopwatch-python/issues）提交。

本文由小云云创作，采用知识共享署名4.0 国际许可协议进行许可
本站文章除注明转载/出处外，均为本站原创或翻译，转载前请务必署名
最后编辑时间为: Sep 2, 2019 at 02:28 pm