Python优雅的计算函数执行时间

发表于 更新于 分类于

前言

正在看有关 asyncio 的各种概念，突然想到了统计函数执行时间，遂写成博客记录一下。

Python 中用来计时的函数有好多种，每种都各有其特点，下面我们来看一下每种计时方案的使用。

time.time()方案

说到计算函数执行时间，大家可能都会想到，很简单，用两个时间戳做减法就好了，随后就写出以下代码：

1
2
3
4
5
6
7
8
9
10
11
12
import time


def func():
    print('func start')
    time.sleep(1)
    print('func end')


t = time.time()
func()
print(f'coast:{time.time() - t:.4f}s')
1
2
3
func start
func end
coast:1.0025s

这种方法很简单，也很常用，但是如果想更精确的计算函数的执行时间呢？

time.perf_counter()方案

例如将 time.sleep(1) 注释掉，只统计两个 print 函数的执行时间：

1
2
3
4
5
6
7
8
9
10
11
12
import time


def func():
    print('func start')
    # time.sleep(1)
    print('func end')


t = time.time()
func()
print(f'coast:{time.time() - t:.8f}s')
1
2
3
func start
func end
coast:0.00000000s

执行完发现执行时间为 0，这就有点尴尬了，看来 time.time() 函数的精度不是特别高，没法统计执行时间极短的函数耗时。

这时候就需要使用到 time.perf_counter() 函数了，perf_counter函数是在 python3.3 中新添加的，它返回性能计数器的值，返回值是浮点型，统计结果包括睡眠的时间，单个函数的返回值无意义，只有多次运行取差值的结果才是有效的函数执行时间。

使用方法见代码：

1
2
3
4
5
6
7
8
9
10
11
12
import time


def func():
    print('func start')
    # time.sleep(1)
    print('func end')


t = time.perf_counter()
func()
print(f'coast:{time.perf_counter() - t:.8f}s')
1
2
3
func start
func end
coast:0.00001230s

可以看到，结果并不是 0 秒， 而是一个很小的值，这说明 perf_counter() 函数可以统计出 print 函数的执行耗时，并且统计精度要比 time.time() 函数要高，比较推荐作为计时器来使用。

timeit.timeit()方案

timeit() 函数有 5 个参数，stmt='pass', setup='pass', timer=<default timer>, number=1000000, globals=None。

  • stmt 参数是需要执行的语句，默认为 pass
  • setup 参数是用来执行初始化代码或构建环境的语句，默认为 pass
  • timer 是计时器，默认是 perf_counter()
  • number 是执行次数，默认为一百万
  • globals 用来指定要运行代码的命名空间，默认为 None。
1
2
3
4
5
6
7
8
9
10
11
import time
import timeit


def func():
    print('func start')
    time.sleep(1)
    print('func end')


print(timeit.timeit(stmt=func, number=1))
1
2
3
func start
func end
1.0006138

运行代码，结果符合预期。

以上方案中比较推荐使用的是 time.perf_counter() 函数，它具有比较高的精度，同时还被用作 timeit 函数默认的计时器。

装饰器统计运行耗时

在实际项目代码中，可以通过装饰器方便的统计函数运行耗时。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
import time


def coast_time(func):
    def fun(*args, **kwargs):
        t = time.perf_counter()
        result = func(*args, **kwargs)
        print(f'func {func.__name__} coast time:{time.perf_counter() - t:.8f} s')
        return result

    return fun


@coast_time
def test():
    print('func start')
    time.sleep(2)
    print('func end')


if __name__ == '__main__':
    test()
1
2
3
func start
func end
func test coast time:2.00222610 s

如果有使用异步函数的需求也可以加上：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
import asyncio
import time
from asyncio.coroutines import iscoroutinefunction


def coast_time(func):
    def fun(*args, **kwargs):
        t = time.perf_counter()
        result = func(*args, **kwargs)
        print(f'func {func.__name__} coast time:{time.perf_counter() - t:.8f} s')
        return result

    async def func_async(*args, **kwargs):
        t = time.perf_counter()
        result = await func(*args, **kwargs)
        print(f'func {func.__name__} coast time:{time.perf_counter() - t:.8f} s')
        return result

    if iscoroutinefunction(func):
        return func_async
    else:
        return fun


@coast_time
def test():
    print('func start')
    time.sleep(2)
    print('func end')


@coast_time
async def test_async():
    print('async func start')
    await asyncio.sleep(2)
    print('async func end')


if __name__ == '__main__':
    test()
    asyncio.get_event_loop().run_until_complete(test_async())

使用装饰器来统计函数执行耗时的好处是对函数的入侵性小，易于编写和修改。

装饰器装饰函数的方案只适用于统计函数的运行耗时，如果有代码块耗时统计的需求就不能用了，这种情况下我们可以使用 with 语句自动管理上下文。

with语句统计运行耗时

通过实现 __enter__ 和 __exit__ 函数可以让我们在进入上下文和退出上下文时进行一些自定义动作，例如连接/断开数据库、打开/关闭文件、记录开始/结束时间等等，这里我们用来统计函数块的执行时间。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
import asyncio
import time


class CoastTime(object):
    def __init__(self):
        self.t = 0

    def __enter__(self):
        self.t = time.perf_counter()
        return self

    def __exit__(self, exc_type, exc_val, exc_tb):
        print(f'coast time:{time.perf_counter() - self.t:.8f} s')


def test():
    print('func start')
    with CoastTime():
        time.sleep(2)
        print('func end')


async def test_async():
    print('async func start')
    with CoastTime():
        await asyncio.sleep(2)
        print('async func end')


if __name__ == '__main__':
    test()
    asyncio.get_event_loop().run_until_complete(test_async())
1
2
3
4
5
6
func start
func end
coast time:2.00261480 s
async func start
async func end
coast time:2.00085290 s

with 语句不仅可以统计代码块的执行时间，也可以统计函数的执行时间，还可以统计多个函数的执行时间之和，相比装饰器来说对代码的入侵性比较大，不易于修改，好处是使用起来比较灵活，不用写过多的重复代码。

总结

统计函数执行耗时，这么一个很小的需求，就有多种方案可以实现，每种方案又各有其特点，在实际的代码编写过程中要灵活使用，借助 Python 提供的各种魔法方法可以更加灵活方便的实现我们的需求。

本文章首发于个人博客 LLLibra146’s blog
本文作者：LLLibra146
版权声明：本博客所有文章除特别声明外，均采用 © BY-NC-ND 许可协议。非商用转载请注明出处！严禁商业转载！
本文链接：https://blog.d77.xyz/archives/608d020b.html