2017-09-13 19:12:07 +08:00
|
|
|
# -*- coding: utf-8 -*-
|
|
|
|
import logging
|
|
|
|
|
2018-01-15 22:01:01 +08:00
|
|
|
import pytest
|
2017-09-13 19:12:07 +08:00
|
|
|
|
|
|
|
logger = logging.getLogger(__name__)
|
2018-05-23 22:48:46 +08:00
|
|
|
sublogger = logging.getLogger(__name__ + ".baz")
|
2017-09-13 19:12:07 +08:00
|
|
|
|
|
|
|
|
|
|
|
def test_fixture_help(testdir):
|
2018-05-23 22:48:46 +08:00
|
|
|
result = testdir.runpytest("--fixtures")
|
|
|
|
result.stdout.fnmatch_lines(["*caplog*"])
|
2017-09-13 19:12:07 +08:00
|
|
|
|
|
|
|
|
|
|
|
def test_change_level(caplog):
|
|
|
|
caplog.set_level(logging.INFO)
|
2018-05-23 22:48:46 +08:00
|
|
|
logger.debug("handler DEBUG level")
|
|
|
|
logger.info("handler INFO level")
|
2017-09-13 19:12:07 +08:00
|
|
|
|
|
|
|
caplog.set_level(logging.CRITICAL, logger=sublogger.name)
|
2018-05-23 22:48:46 +08:00
|
|
|
sublogger.warning("logger WARNING level")
|
|
|
|
sublogger.critical("logger CRITICAL level")
|
2017-09-13 19:12:07 +08:00
|
|
|
|
2018-05-23 22:48:46 +08:00
|
|
|
assert "DEBUG" not in caplog.text
|
|
|
|
assert "INFO" in caplog.text
|
|
|
|
assert "WARNING" not in caplog.text
|
|
|
|
assert "CRITICAL" in caplog.text
|
2017-09-13 19:12:07 +08:00
|
|
|
|
|
|
|
|
2018-01-17 06:32:59 +08:00
|
|
|
def test_change_level_undo(testdir):
|
|
|
|
"""Ensure that 'set_level' is undone after the end of the test"""
|
2018-05-23 22:48:46 +08:00
|
|
|
testdir.makepyfile(
|
|
|
|
"""
|
2018-01-17 06:32:59 +08:00
|
|
|
import logging
|
|
|
|
|
|
|
|
def test1(caplog):
|
|
|
|
caplog.set_level(logging.INFO)
|
|
|
|
# using + operator here so fnmatch_lines doesn't match the code in the traceback
|
|
|
|
logging.info('log from ' + 'test1')
|
|
|
|
assert 0
|
|
|
|
|
|
|
|
def test2(caplog):
|
|
|
|
# using + operator here so fnmatch_lines doesn't match the code in the traceback
|
|
|
|
logging.info('log from ' + 'test2')
|
|
|
|
assert 0
|
2018-05-23 22:48:46 +08:00
|
|
|
"""
|
|
|
|
)
|
2018-10-09 02:12:55 +08:00
|
|
|
result = testdir.runpytest()
|
2018-05-23 22:48:46 +08:00
|
|
|
result.stdout.fnmatch_lines(["*log from test1*", "*2 failed in *"])
|
|
|
|
assert "log from test2" not in result.stdout.str()
|
2018-01-17 06:32:59 +08:00
|
|
|
|
|
|
|
|
2017-09-13 19:12:07 +08:00
|
|
|
def test_with_statement(caplog):
|
|
|
|
with caplog.at_level(logging.INFO):
|
2018-05-23 22:48:46 +08:00
|
|
|
logger.debug("handler DEBUG level")
|
|
|
|
logger.info("handler INFO level")
|
2017-09-13 19:12:07 +08:00
|
|
|
|
|
|
|
with caplog.at_level(logging.CRITICAL, logger=sublogger.name):
|
2018-05-23 22:48:46 +08:00
|
|
|
sublogger.warning("logger WARNING level")
|
|
|
|
sublogger.critical("logger CRITICAL level")
|
2017-09-13 19:12:07 +08:00
|
|
|
|
2018-05-23 22:48:46 +08:00
|
|
|
assert "DEBUG" not in caplog.text
|
|
|
|
assert "INFO" in caplog.text
|
|
|
|
assert "WARNING" not in caplog.text
|
|
|
|
assert "CRITICAL" in caplog.text
|
2017-09-13 19:12:07 +08:00
|
|
|
|
|
|
|
|
|
|
|
def test_log_access(caplog):
|
2018-01-17 06:32:59 +08:00
|
|
|
caplog.set_level(logging.INFO)
|
2018-05-23 22:48:46 +08:00
|
|
|
logger.info("boo %s", "arg")
|
|
|
|
assert caplog.records[0].levelname == "INFO"
|
|
|
|
assert caplog.records[0].msg == "boo %s"
|
|
|
|
assert "boo arg" in caplog.text
|
2017-09-13 19:12:07 +08:00
|
|
|
|
|
|
|
|
2018-06-15 03:20:06 +08:00
|
|
|
def test_messages(caplog):
|
|
|
|
caplog.set_level(logging.INFO)
|
|
|
|
logger.info("boo %s", "arg")
|
|
|
|
logger.info("bar %s\nbaz %s", "arg1", "arg2")
|
|
|
|
assert "boo arg" == caplog.messages[0]
|
|
|
|
assert "bar arg1\nbaz arg2" == caplog.messages[1]
|
|
|
|
assert caplog.text.count("\n") > len(caplog.messages)
|
|
|
|
assert len(caplog.text.splitlines()) > len(caplog.messages)
|
|
|
|
|
|
|
|
try:
|
|
|
|
raise Exception("test")
|
|
|
|
except Exception:
|
|
|
|
logger.exception("oops")
|
|
|
|
|
|
|
|
assert "oops" in caplog.text
|
|
|
|
assert "oops" in caplog.messages[-1]
|
|
|
|
# Tracebacks are stored in the record and not added until the formatter or handler.
|
|
|
|
assert "Exception" in caplog.text
|
|
|
|
assert "Exception" not in caplog.messages[-1]
|
|
|
|
|
|
|
|
|
2017-09-13 19:12:07 +08:00
|
|
|
def test_record_tuples(caplog):
|
2018-01-17 06:32:59 +08:00
|
|
|
caplog.set_level(logging.INFO)
|
2018-05-23 22:48:46 +08:00
|
|
|
logger.info("boo %s", "arg")
|
2017-09-13 19:12:07 +08:00
|
|
|
|
2018-05-23 22:48:46 +08:00
|
|
|
assert caplog.record_tuples == [(__name__, logging.INFO, "boo arg")]
|
2017-09-13 19:12:07 +08:00
|
|
|
|
|
|
|
|
|
|
|
def test_unicode(caplog):
|
2018-01-17 06:32:59 +08:00
|
|
|
caplog.set_level(logging.INFO)
|
2018-05-23 22:48:46 +08:00
|
|
|
logger.info(u"bū")
|
|
|
|
assert caplog.records[0].levelname == "INFO"
|
|
|
|
assert caplog.records[0].msg == u"bū"
|
|
|
|
assert u"bū" in caplog.text
|
2017-09-13 19:12:07 +08:00
|
|
|
|
|
|
|
|
|
|
|
def test_clear(caplog):
|
2018-01-17 06:32:59 +08:00
|
|
|
caplog.set_level(logging.INFO)
|
2018-05-23 22:48:46 +08:00
|
|
|
logger.info(u"bū")
|
2017-09-13 19:12:07 +08:00
|
|
|
assert len(caplog.records)
|
2018-03-13 06:28:47 +08:00
|
|
|
assert caplog.text
|
2017-09-13 19:12:07 +08:00
|
|
|
caplog.clear()
|
|
|
|
assert not len(caplog.records)
|
2018-03-13 06:28:47 +08:00
|
|
|
assert not caplog.text
|
2018-01-15 22:01:01 +08:00
|
|
|
|
|
|
|
|
|
|
|
@pytest.fixture
|
|
|
|
def logging_during_setup_and_teardown(caplog):
|
2018-05-23 22:48:46 +08:00
|
|
|
caplog.set_level("INFO")
|
|
|
|
logger.info("a_setup_log")
|
2018-01-15 22:01:01 +08:00
|
|
|
yield
|
2018-05-23 22:48:46 +08:00
|
|
|
logger.info("a_teardown_log")
|
|
|
|
assert [x.message for x in caplog.get_records("teardown")] == ["a_teardown_log"]
|
2018-01-15 22:01:01 +08:00
|
|
|
|
|
|
|
|
|
|
|
def test_caplog_captures_for_all_stages(caplog, logging_during_setup_and_teardown):
|
|
|
|
assert not caplog.records
|
2018-05-23 22:48:46 +08:00
|
|
|
assert not caplog.get_records("call")
|
|
|
|
logger.info("a_call_log")
|
|
|
|
assert [x.message for x in caplog.get_records("call")] == ["a_call_log"]
|
2018-01-15 22:01:01 +08:00
|
|
|
|
2018-05-23 22:48:46 +08:00
|
|
|
assert [x.message for x in caplog.get_records("setup")] == ["a_setup_log"]
|
2018-01-15 22:01:01 +08:00
|
|
|
|
|
|
|
# This reachers into private API, don't use this type of thing in real tests!
|
2018-05-23 22:48:46 +08:00
|
|
|
assert set(caplog._item.catch_log_handlers.keys()) == {"setup", "call"}
|