一、Pytest日志简介
Pytest日志分为Captured Log日志和Live Log日志两类，Live Log简单点说就是实时日志，即在执行脚本的过程中实时打印出来的，Captured Log可以理解为日志采集器，就是将用例执行过程中的日志打印控制台标准输出标准错误输出等采集起来，当用例执行完成后如果用例有失败的，就将采集到的日志一次性打印出来，如果用例成功了就不会打印了。
Live Log的作用很明显，就是可以在用例中打印日志的作用
Captured Log其实是又更高级的应用，比如在这样的场景，执行完成用例后需要对日志的内容日志级别等进行判断的时候，Captured Log就派上用场了，比如希望用例中不能出现warning的日志，或者希望用例执行过程中不能出现xxx内容的日志等场景，如果使用Live Log打印，则是很难操作的，而Captured Log就很容易了，因为在用例执行完成后可以通过Captured Log拿到当前用例执行过程中的所有日志打印以及控制台标准输出和控制台标准错误输出，进而可以进行各种自定义判断
二、设置Captured Log
(1)日志默认是warning级别的
test_demo.py代码如下：
import logging
def test_func():
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
assert 1==2执行使用pytest执行，如下，可以发现，print是直接打印在Captured stdout call中，日志是打印在Captured log call中，而且只打印了warnning和error额日志，info的日志没有打印出来，这是因为默认的是warnning级别
$ pytest
========================================================================= test session starts ==========================================================================
platform win32 -- Python 3.9.7, pytest-6.2.5, py-1.10.0, pluggy-1.0.0
rootdir: D:\src\blog\tests, configfile: pytest.ini
plugins: allure-pytest-2.9.43, caterpillar-pytest-0.0.2, hypothesis-6.31.6, forked-1.3.0, rerunfailures-10.1, xdist-2.3.0
collected 1 item
test_demo.py F [100%]
=============================================================================== FAILURES ===============================================================================
______________________________________________________________________________ test_func _______________________________________________________________________________
def test_func():
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
> assert 1==2
E assert 1 == 2
test_demo.py:8: AssertionError
------------------------------------------------------------------------- Captured stdout call -------------------------------------------------------------------------
print console in test_func...
-------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------
WARNING root:test_demo.py:5 warnning in test_func...
ERROR root:test_demo.py:6 this is error
======================================================================= short test summary info ========================================================================
FAILED test_demo.py::test_func - assert 1 == 2
========================================================================== 1 failed in 0.10s ===========================================================================
(2)通过命令行设置日志的格式时间格式以及日志级别
如下，info日志可以打印出来了，而且日志的格式也按照指定的格式输出了
$ pytest --log-level=info --log-format="%(asctime)s %(levelname)s %(message)s" --log-date-format="%Y-%m-%d %H:%M:%S"
========================================================================= test session starts ==========================================================================
platform win32 -- Python 3.9.7, pytest-6.2.5, py-1.10.0, pluggy-1.0.0
rootdir: D:\src\blog\tests, configfile: pytest.ini
plugins: allure-pytest-2.9.43, caterpillar-pytest-0.0.2, hypothesis-6.31.6, forked-1.3.0, rerunfailures-10.1, xdist-2.3.0
collected 1 item
test_demo.py F [100%]
=============================================================================== FAILURES ===============================================================================
______________________________________________________________________________ test_func _______________________________________________________________________________
def test_func():
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
> assert 1==2
E assert 1 == 2
test_demo.py:8: AssertionError
------------------------------------------------------------------------- Captured stdout call -------------------------------------------------------------------------
print console in test_func...
-------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------
2021-12-22 15:43:11 INFO info in test_func...
2021-12-22 15:43:11 WARNING warnning in test_func...
2021-12-22 15:43:11 ERROR this is error
======================================================================= short test summary info ========================================================================
FAILED test_demo.py::test_func - assert 1 == 2
========================================================================== 1 failed in 0.10s ===========================================================================
(3)通过pytest.ini配置设置日志格式以及级别
pytest.ini配置如下：
[pytest]
log_format = %(asctime)s %(levelname)s %(message)s
log_date_format = %Y-%m-%d %H:%M:%S
log_level = info然后直接使用pytest，结果如下，同样info级别的日志可以打印出来而且日志格式也按照pytest.ini指定的格式输出了
$ pytest
========================================================================= test session starts ==========================================================================
platform win32 -- Python 3.9.7, pytest-6.2.5, py-1.10.0, pluggy-1.0.0
rootdir: D:\src\blog\tests, configfile: pytest.ini
plugins: allure-pytest-2.9.43, caterpillar-pytest-0.0.2, hypothesis-6.31.6, forked-1.3.0, rerunfailures-10.1, xdist-2.3.0
collected 1 item
test_demo.py F [100%]
=============================================================================== FAILURES ===============================================================================
______________________________________________________________________________ test_func _______________________________________________________________________________
def test_func():
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
> assert 1==2
E assert 1 == 2
test_demo.py:8: AssertionError
------------------------------------------------------------------------- Captured stdout call -------------------------------------------------------------------------
print console in test_func...
-------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------
2021-12-22 15:46:21 INFO info in test_func...
2021-12-22 15:46:21 WARNING warnning in test_func...
2021-12-22 15:46:21 ERROR this is error
======================================================================= short test summary info ========================================================================
FAILED test_demo.py::test_func - assert 1 == 2
========================================================================== 1 failed in 0.10s ===========================================================================
(4)如果不想显示Captured log日志，可以使用--show-capture=no参数
如下，此时pytest.ini中依然配置了日志格式和日志级别，但是没有任何日志输出
$ pytest --show-capture=no
========================================================================= test session starts ==========================================================================
platform win32 -- Python 3.9.7, pytest-6.2.5, py-1.10.0, pluggy-1.0.0
rootdir: D:\src\blog\tests, configfile: pytest.ini
plugins: allure-pytest-2.9.43, caterpillar-pytest-0.0.2, hypothesis-6.31.6, forked-1.3.0, rerunfailures-10.1, xdist-2.3.0
collected 1 item
test_demo.py F [100%]
=============================================================================== FAILURES ===============================================================================
______________________________________________________________________________ test_func _______________________________________________________________________________
def test_func():
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
> assert 1==2
E assert 1 == 2
test_demo.py:8: AssertionError
======================================================================= short test summary info ========================================================================
FAILED test_demo.py::test_func - assert 1 == 2
========================================================================== 1 failed in 0.10s ===========================================================================
三、caplog fixture常见应用
(1)针对每个用例指定不同的日志级别
修改pytest.ini，只配置日志格式，不配置日志级别
[pytest]
log_format = %(asctime)s %(levelname)s %(message)s
log_date_format = %Y-%m-%d %H:%M:%Stest_demo.py内容如下：
import logging
def test_func1(caplog):
caplog.set_level(logging.INFO)
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
assert 1==2
def test_func2():
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
assert 1==2
def test_func3(caplog):
caplog.set_level(logging.ERROR)
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
assert 1==2执行结果如下，即如果不设置默认的仍然是warnning，另外两个用例中单独设置日志级别也都生效了
$ pytest
========================================================================= test session starts ==========================================================================
platform win32 -- Python 3.9.7, pytest-6.2.5, py-1.10.0, pluggy-1.0.0
rootdir: D:\src\blog\tests, configfile: pytest.ini
plugins: allure-pytest-2.9.43, caterpillar-pytest-0.0.2, hypothesis-6.31.6, forked-1.3.0, rerunfailures-10.1, xdist-2.3.0
collected 3 items
test_demo.py FFF [100%]
=============================================================================== FAILURES ===============================================================================
______________________________________________________________________________ test_func1 ______________________________________________________________________________
caplog = <_pytest.logging.LogCaptureFixture object at 0x0000014010784C40>
def test_func1(caplog):
caplog.set_level(logging.INFO)
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
> assert 1==2
E assert 1 == 2
test_demo.py:9: AssertionError
------------------------------------------------------------------------- Captured stdout call -------------------------------------------------------------------------
print console in test_func...
-------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------
2021-12-22 15:58:31 INFO info in test_func...
2021-12-22 15:58:31 WARNING warnning in test_func...
2021-12-22 15:58:31 ERROR this is error
______________________________________________________________________________ test_func2 ______________________________________________________________________________
def test_func2():
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
> assert 1==2
E assert 1 == 2
test_demo.py:16: AssertionError
------------------------------------------------------------------------- Captured stdout call -------------------------------------------------------------------------
print console in test_func...
-------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------
2021-12-22 15:58:31 WARNING warnning in test_func...
2021-12-22 15:58:31 ERROR this is error
______________________________________________________________________________ test_func3 ______________________________________________________________________________
caplog = <_pytest.logging.LogCaptureFixture object at 0x00000140107A8190>
def test_func3(caplog):
caplog.set_level(logging.ERROR)
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
> assert 1==2
E assert 1 == 2
test_demo.py:24: AssertionError
------------------------------------------------------------------------- Captured stdout call -------------------------------------------------------------------------
print console in test_func...
-------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------
2021-12-22 15:58:31 ERROR this is error
======================================================================= short test summary info ========================================================================
FAILED test_demo.py::test_func1 - assert 1 == 2
FAILED test_demo.py::test_func2 - assert 1 == 2
FAILED test_demo.py::test_func3 - assert 1 == 2
========================================================================== 3 failed in 0.13s ===========================================================================
D:\src\blog\tests>
(2)对用例中日志级别进行判断
test_demo.py内容如下：
import logging
def test_func1(caplog):
caplog.set_level(logging.INFO)
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
for record in caplog.records:
assert record.levelname != "ERROR"执行结果如下，因为这里有Error级别的日志，所以用例是失败的
$ pytest
========================================================================= test session starts ==========================================================================
platform win32 -- Python 3.9.7, pytest-6.2.5, py-1.10.0, pluggy-1.0.0
rootdir: D:\src\blog\tests, configfile: pytest.ini
plugins: allure-pytest-2.9.43, caterpillar-pytest-0.0.2, hypothesis-6.31.6, forked-1.3.0, rerunfailures-10.1, xdist-2.3.0
collected 1 item
test_demo.py F [100%]
=============================================================================== FAILURES ===============================================================================
______________________________________________________________________________ test_func1 ______________________________________________________________________________
caplog = <_pytest.logging.LogCaptureFixture object at 0x0000027393797BB0>
def test_func1(caplog):
caplog.set_level(logging.INFO)
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
for record in caplog.records:
> assert record.levelname != "ERROR"
E assert 'ERROR' != 'ERROR'
E + where 'ERROR' = <LogRecord: root, 40, D:\src\blog\tests\test_demo.py, 7, "this is error">.levelname
test_demo.py:10: AssertionError
------------------------------------------------------------------------- Captured stdout call -------------------------------------------------------------------------
print console in test_func...
-------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------
2021-12-22 16:14:03 INFO info in test_func...
2021-12-22 16:14:03 WARNING warnning in test_func...
2021-12-22 16:14:03 ERROR this is error
======================================================================= short test summary info ========================================================================
FAILED test_demo.py::test_func1 - assert 'ERROR' != 'ERROR'
========================================================================== 1 failed in 0.10s ===========================================================================
(3)对日志内容进行判断
test_demo.py代码如下：
import logging
def test_func1(caplog):
caplog.set_level(logging.INFO)
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
for record in caplog.records:
assert "this is error" not in record.message执行结果如下
$ pytest
========================================================================= test session starts ==========================================================================
platform win32 -- Python 3.9.7, pytest-6.2.5, py-1.10.0, pluggy-1.0.0
rootdir: D:\src\blog\tests, configfile: pytest.ini
plugins: allure-pytest-2.9.43, caterpillar-pytest-0.0.2, hypothesis-6.31.6, forked-1.3.0, rerunfailures-10.1, xdist-2.3.0
collected 1 item
test_demo.py F [100%]
=============================================================================== FAILURES ===============================================================================
______________________________________________________________________________ test_func1 ______________________________________________________________________________
caplog = <_pytest.logging.LogCaptureFixture object at 0x0000027C31589B80>
def test_func1(caplog):
caplog.set_level(logging.INFO)
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
for record in caplog.records:
> assert "this is error" not in record.message
E AssertionError: assert 'this is error' not in 'this is error'
E 'this is error' is contained here:
E this is error
test_demo.py:10: AssertionError
------------------------------------------------------------------------- Captured stdout call -------------------------------------------------------------------------
print console in test_func...
-------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------
2021-12-22 16:17:57 INFO info in test_func...
2021-12-22 16:17:57 WARNING warnning in test_func...
2021-12-22 16:17:57 ERROR this is error
======================================================================= short test summary info ========================================================================
FAILED test_demo.py::test_func1 - AssertionError: assert 'this is error' not in 'this is error'
========================================================================== 1 failed in 0.11s ===========================================================================
(4)同时对logger、日志级别、日志内容组成的元祖进行判断
test_demo.py代码如下：
import logging
def test_func1(caplog):
caplog.set_level(logging.INFO)
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
assert ("root",logging.ERROR,"this is error") not in caplog.record_tuples执行结果如下：
$ pytest
========================================================================= test session starts ==========================================================================
platform win32 -- Python 3.9.7, pytest-6.2.5, py-1.10.0, pluggy-1.0.0
rootdir: D:\src\blog\tests, configfile: pytest.ini
plugins: allure-pytest-2.9.43, caterpillar-pytest-0.0.2, hypothesis-6.31.6, forked-1.3.0, rerunfailures-10.1, xdist-2.3.0
collected 1 item
test_demo.py F [100%]
=============================================================================== FAILURES ===============================================================================
______________________________________________________________________________ test_func1 ______________________________________________________________________________
caplog = <_pytest.logging.LogCaptureFixture object at 0x0000015621BF8B50>
def test_func1(caplog):
caplog.set_level(logging.INFO)
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
> assert ("root",logging.ERROR,"this is error") not in caplog.record_tuples
E AssertionError: assert ('root', 40, 'this is error') not in [('root', 20, 'info in test_func...'), ('root', 30, 'warnning in test_func...'), ('root', 40, 'this i
s error')]
E + where [('root', 20, 'info in test_func...'), ('root', 30, 'warnning in test_func...'), ('root', 40, 'this is error')] = <_pytest.logging.LogCaptureFixture ob
ject at 0x0000015621BF8B50>.record_tuples
test_demo.py:9: AssertionError
------------------------------------------------------------------------- Captured stdout call -------------------------------------------------------------------------
print console in test_func...
-------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------
2021-12-22 16:22:01 INFO info in test_func...
2021-12-22 16:22:01 WARNING warnning in test_func...
2021-12-22 16:22:01 ERROR this is error
======================================================================= short test summary info ========================================================================
FAILED test_demo.py::test_func1 - AssertionError: assert ('root', 40, 'this is error') not in [('root', 20, 'info in test_func...'), ('root', 30, 'warnning in test_fu...
========================================================================== 1 failed in 0.11s ===========================================================================
(5)获取其他步骤中的日志
在pytest用例中，一般每个用例分为三个步骤，setup，call和teardown，call为用例主体，如下即在call中想检查setup中的日志
test_demo.py内容如下：
import logging
import pytest
@pytest.fixture()
def demo(caplog):
caplog.set_level(logging.INFO)
logging.error("error in demo fixture")
logging.info("info in test_func...")
yield
def test_func1(demo,caplog):
setup_records=caplog.get_records("setup")
for record in setup_records:
assert record.levelname != "ERROR"执行结果如下：
$ pytest
========================================================================= test session starts ==========================================================================
platform win32 -- Python 3.9.7, pytest-6.2.5, py-1.10.0, pluggy-1.0.0
rootdir: D:\src\blog\tests, configfile: pytest.ini
plugins: allure-pytest-2.9.43, caterpillar-pytest-0.0.2, hypothesis-6.31.6, forked-1.3.0, rerunfailures-10.1, xdist-2.3.0
collected 1 item
test_demo.py F [100%]
=============================================================================== FAILURES ===============================================================================
______________________________________________________________________________ test_func1 ______________________________________________________________________________
demo = None, caplog = <_pytest.logging.LogCaptureFixture object at 0x000001AB4C0B9AC0>
def test_func1(demo,caplog):
setup_records=caplog.get_records("setup")
for record in setup_records:
> assert record.levelname != "ERROR"
E assert 'ERROR' != 'ERROR'
E + where 'ERROR' = <LogRecord: root, 40, D:\src\blog\tests\test_demo.py, 7, "error in demo fixture">.levelname
test_demo.py:15: AssertionError
-------------------------------------------------------------------------- Captured log setup --------------------------------------------------------------------------
2021-12-22 16:49:57 ERROR error in demo fixture
2021-12-22 16:49:57 INFO info in test_func...
======================================================================= short test summary info ========================================================================
FAILED test_demo.py::test_func1 - assert 'ERROR' != 'ERROR'
========================================================================== 1 failed in 0.11s ===========================================================================
四、设置Live Logs
pytest.ini可参考如下配置
[pytest]
log_cli = True
log_cli_level = info
log_cli_format = %(asctime)s %(levelname)s %(message)s
log_cli_date_format = %Y-%m-%d %H:%M:%Stest_demo.py内容如下
import logging
def test_func():
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
assert 1==2执行结果如下，可以发现，此时有live log call并且位置时再用例执行的过程中
$ pytest
========================================================================= test session starts ==========================================================================
platform win32 -- Python 3.9.7, pytest-6.2.5, py-1.10.0, pluggy-1.0.0
rootdir: D:\src\blog\tests, configfile: pytest.ini
plugins: allure-pytest-2.9.43, caterpillar-pytest-0.0.2, hypothesis-6.31.6, forked-1.3.0, rerunfailures-10.1, xdist-2.3.0
collected 1 item
test_demo.py::test_func
---------------------------------------------------------------------------- live log call -----------------------------------------------------------------------------
2021-12-22 16:58:23 INFO info in test_func...
2021-12-22 16:58:23 WARNING warnning in test_func...
2021-12-22 16:58:23 ERROR this is error
FAILED [100%]
=============================================================================== FAILURES ===============================================================================
______________________________________________________________________________ test_func _______________________________________________________________________________
def test_func():
logging.info("info in test_func...")
logging.warning("warnning in test_func...")
logging.error("this is error")
print("print console in test_func...")
> assert 1==2
E assert 1 == 2
E +1
E -2
test_demo.py:8: AssertionError
------------------------------------------------------------------------- Captured stdout call -------------------------------------------------------------------------
print console in test_func...
-------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------
INFO root:test_demo.py:4 info in test_func...
WARNING root:test_demo.py:5 warnning in test_func...
ERROR root:test_demo.py:6 this is error
======================================================================= short test summary info ========================================================================
FAILED test_demo.py::test_func - assert 1 == 2
========================================================================== 1 failed in 0.11s ===========================================================================
五、设置日志文件
pytest.ini中参照如下配置
[pytest]
log_file= test_demo.log
log_file_level = info
log_file_format = %(asctime)s %(levelname)s %(message)s
log_file_date_format = %Y-%m-%d %H:%M:%S然后执行pytest，可以发现此时在当前目录中生成了test_demo.log，内容如下，说明配置生效了，这里日志文件可以根据自己的实际情况自行调整配置
2021-12-22 17:01:19 INFO info in test_func...
2021-12-22 17:01:19 WARNING warnning in test_func...
2021-12-22 17:01:19 ERROR this is error