Python pytest 紀錄單元測試時間

最近看了一篇文章 Timing Tests in Python for Fun and Profit ，這篇文章蠻值得一讀的，主要是陳述如何透過紀錄測試案例(test case)的執行時間找到需要改善測試速度的測試案例(其實也可能發現執行效率不好的程式)。

不過個人較常使用的是 pytest ，所以就另外花了些時間看如何在 pytest 做到一樣的事情。

本篇文章使用的環境是：

- Python 3.5
- pytest 3.0.4

測試資料夾的結構是：

├── conftest.py
└── module_example
    ├── __init__.py
    └── test_example.py

其實 pytest 已經有針對每一個測試案例紀錄執行時間，而且分成 3 段時間，分別是 setup, call, teardown 3 段，這邊就不花時間解釋 setup, teardown 了，有興趣可以去閱讀 unittest 了解這 2 個詞，本篇就直接關注 call 的執行時間，也就是真正執行測試案例的時間。

不過 pytest 預設不會分別顯示每一個測試的時間，要達到這個目標就得透過 pytest 提供的 hook - pytest_terminal_summary ，在所有測試結束時利用 pytest_terminal_summary 取得每一個測試的 report ，然後一一把執行時間列印出來。

程式也蠻簡單的，只要在 conftest.py 中實作 pytest_terminal_summary 這個 hook 即可：

# conftest.py
def pytest_terminal_summary(terminalreporter, exitstatus):
    # 將 report 一一取出
    reports = []
    for replist in terminalreporter.stats.values():
        for rep in replist:
            if hasattr(rep, 'duration'):
                reports.append(rep)

    if not reports:
        return

    # 按照測試的執行時間(duration)遞減排序
    reports.sort(key=lambda x: x.duration)
    reports.reverse()

    terminalreporter.write_sep("=", "test durations")
    for rep in reports:
        # 只關注 call 的部分
        if rep.when != 'call':
            continue

        nodeid = rep.nodeid.replace("::()::", "::")
        terminalreporter.write_line("%02.2fs %s" % (rep.duration, nodeid))

執行結果(底下的 test durations 區塊)：

▶ py.test .
============= test session starts =============
platform darwin -- Python 3.5.2, pytest-3.0.4, py-1.4.31, pluggy-0.4.0
rootdir: /home/example/tests, inifile:
collected 2 items

module_example/test_example.py ..

=============== test durations ================
5.00s module_example/test_example.py::test_abc
0.00s module_example/test_example.py::test_def
========== 2 passed in 5.02 seconds ===========

此外，每一個 report 有哪些屬性可以查看 TestReport 。

以上。

Happy coding!

• http://doc.pytest.org/en/latest/_modules/_pytest/runner.html