Python 统计程序运行时长

in 开发 with 0 comment

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)提交。

分享您的想法 (2018/3/7 之前的评论与回复将不再显示)