Pytest 花费大部分时间 post-test？

Question

我运行通过 pytest 的单个函数（在下面的示例中）需要 71 秒才能运行。然而，pytest 又花了 6-7 分钟做……某事。我可以从日志文件中看出，预期的测试是在 7 分钟开始时执行的，但我无法想象之后发生了什么（如果相信“最慢持续时间”输出，显然这不是拆解）。

pytest 函数本身非常小：

def test_preprocess_and_train_model():
    import my_module.pipeline as pipeline  # noqa

    pipeline.do_pipeline(do_s3_upload=False,
                         debug=True, update_params={'tf_verbosity': 0})

如果我手动运行 test_preprocess_and_train_model()（例如，如果我通过解释器而不是通过 pytest 调用该函数），大约需要 70 秒。

发生了什么，我怎样才能加快速度？

▶  pytest --version
pytest 6.2.2
▶ python --version
Python 3.8.5
▶ time pytest -k test_preprocess_and_train_model -vv --durations=0                                             
====================================================== test session starts =======================================================
platform darwin -- Python 3.8.5, pytest-6.2.2, py-1.9.0, pluggy-0.13.1 -- /usr/local/opt/python@3.8/bin/python3.8
cachedir: .pytest_cache
rootdir: /Users/blah_blah_blah/tests
collected 3 items / 2 deselected / 1 selected                                                                                    

test_pipelines.py::test_preprocess_and_train_model PASSED                                                                  [100%] 

======================================================== warnings summary ========================================================
test_pipelines.py::test_preprocess_and_train_model
  /Users/your_name_here/Library/Python/3.8/lib/python/site-packages/tensorflow/python/autograph/impl/api.py:22: DeprecationWarning: the imp module is deprecated in favour of importlib; see the module's documentation for alternative uses
    import imp

test_pipelines.py: 3604341 warnings
  sys:1: DeprecationWarning: PY_SSIZE_T_CLEAN will be required for '#' formats

test_pipelines.py::test_preprocess_and_train_model
  /Users/your_name_here/Library/Python/3.8/lib/python/site-packages/tensorflow/python/keras/engine/training.py:2325: UserWarning: `Model.state_updates` will be removed in a future version. This property should not be used in TensorFlow 2.0, as `updates` are applied automatically.
    warnings.warn('`Model.state_updates` will be removed in a future version. '

-- Docs: https://docs.pytest.org/en/stable/warnings.html
======================================================= slowest durations ========================================================
71.88s call     test_pipelines.py::test_preprocess_and_train_model
0.00s teardown test_pipelines.py::test_preprocess_and_train_model
0.00s setup    test_pipelines.py::test_preprocess_and_train_model
================================= 1 passed, 2 deselected, 3604343 warnings in 422.15s (0:07:02) ==================================
pytest -k test_preprocess_and_train_model -vv --durations=0  305.95s user 158.42s system 104% cpu 7:26.14 total

Answer 1

我想我会 post 解决这个问题，以防它对其他人有帮助。

theY4Kman 关于仅分析代码的建议非常好。我自己的代码运行按预期在 70 秒内干净地退出，但它产生了 3.6M 警告消息。 pytest 中的每条警告消息都会触发 os.stat() 检查（以确定哪一行代码产生了警告），评估 3.6M 系统调用需要 5 分钟左右。如果我在pytest的warnings.py中注释掉warning_record_to_str()的heart，那么pytest大约用了140秒（即解决了大部分问题）

这也解释了为什么性能取决于平台（Mac vs Ubuntu），因为错误消息的数量差异很大。

如果我理解正确的话，似乎有两个悲哀的结论：

即使我使用 --disable-warnings 标志，pytest 似乎很乐意收集所有警告、统计它们等；它只是不打印它们。在我的例子中，这意味着 pytest 花费了 85% 的时间来计算它立即丢弃的信息。
os.stat() 检查发生在 Python 的 linecache.py 函数中。由于我有 360 万次相同的警告，我希望该函数会运行 os.stat() 一次并缓存结果，但这并没有发生。我想我只是误解了有关此功能预期用途的一些基本知识。

Pytest 花费大部分时间 post-test？

Pytest spending most time post-test?

python

pytest

profiling