| from fontTools.misc.loggingTools import ( |
| LevelFormatter, |
| Timer, |
| configLogger, |
| ChannelsFilter, |
| LogMixin, |
| ) |
| from io import StringIO |
| import logging |
| import textwrap |
| import time |
| import re |
| import pytest |
| |
| |
| def logger_name_generator(): |
| basename = "fontTools.test#" |
| num = 1 |
| while True: |
| yield basename + str(num) |
| num += 1 |
| |
| |
| unique_logger_name = logger_name_generator() |
| |
| |
| @pytest.fixture |
| def logger(): |
| log = logging.getLogger(next(unique_logger_name)) |
| configLogger(logger=log, level="DEBUG", stream=StringIO()) |
| return log |
| |
| |
| def test_LevelFormatter(): |
| stream = StringIO() |
| handler = logging.StreamHandler(stream) |
| formatter = LevelFormatter( |
| fmt={ |
| "*": "[%(levelname)s] %(message)s", |
| "DEBUG": "%(name)s [%(levelname)s] %(message)s", |
| "INFO": "%(message)s", |
| } |
| ) |
| handler.setFormatter(formatter) |
| name = next(unique_logger_name) |
| log = logging.getLogger(name) |
| log.setLevel(logging.DEBUG) |
| log.addHandler(handler) |
| |
| log.debug("this uses a custom format string") |
| log.info("this also uses a custom format string") |
| log.warning("this one uses the default format string") |
| |
| assert stream.getvalue() == textwrap.dedent( |
| """\ |
| %s [DEBUG] this uses a custom format string |
| this also uses a custom format string |
| [WARNING] this one uses the default format string |
| """ |
| % name |
| ) |
| |
| |
| class TimerTest(object): |
| def test_split(self): |
| timer = Timer() |
| time.sleep(0.01) |
| fist_lap = timer.split() |
| assert timer.elapsed == fist_lap |
| time.sleep(0.1) |
| second_lap = timer.split() |
| assert second_lap > fist_lap |
| assert timer.elapsed == second_lap |
| |
| def test_time(self): |
| timer = Timer() |
| time.sleep(0.01) |
| overall_time = timer.time() |
| assert overall_time > 0 |
| |
| def test_context_manager(self): |
| with Timer() as t: |
| time.sleep(0.01) |
| assert t.elapsed > 0 |
| |
| def test_using_logger(self, logger): |
| with Timer(logger, "do something"): |
| time.sleep(0.01) |
| |
| assert re.match( |
| r"Took [0-9]\.[0-9]{3}s to do something", |
| logger.handlers[0].stream.getvalue(), |
| ) |
| |
| def test_using_logger_calling_instance(self, logger): |
| timer = Timer(logger) |
| with timer(): |
| time.sleep(0.01) |
| |
| assert re.match( |
| r"elapsed time: [0-9]\.[0-9]{3}s", logger.handlers[0].stream.getvalue() |
| ) |
| |
| # do it again but with custom level |
| with timer("redo it", level=logging.WARNING): |
| time.sleep(0.02) |
| |
| assert re.search( |
| r"WARNING: Took [0-9]\.[0-9]{3}s to redo it", |
| logger.handlers[0].stream.getvalue(), |
| ) |
| |
| def test_function_decorator(self, logger): |
| timer = Timer(logger) |
| |
| @timer() |
| def test1(): |
| time.sleep(0.01) |
| |
| @timer("run test 2", level=logging.INFO) |
| def test2(): |
| time.sleep(0.02) |
| |
| test1() |
| |
| assert re.match( |
| r"Took [0-9]\.[0-9]{3}s to run 'test1'", |
| logger.handlers[0].stream.getvalue(), |
| ) |
| |
| test2() |
| |
| assert re.search( |
| r"Took [0-9]\.[0-9]{3}s to run test 2", logger.handlers[0].stream.getvalue() |
| ) |
| |
| |
| def test_ChannelsFilter(logger): |
| n = logger.name |
| filtr = ChannelsFilter(n + ".A.B", n + ".C.D") |
| handler = logger.handlers[0] |
| handler.addFilter(filtr) |
| stream = handler.stream |
| |
| logging.getLogger(n + ".A.B").debug("this record passes through") |
| assert "this record passes through" in stream.getvalue() |
| |
| logging.getLogger(n + ".A.B.C").debug("records from children also pass") |
| assert "records from children also pass" in stream.getvalue() |
| |
| logging.getLogger(n + ".C.D").debug("this one as well") |
| assert "this one as well" in stream.getvalue() |
| |
| logging.getLogger(n + ".A.B.").debug("also this one") |
| assert "also this one" in stream.getvalue() |
| |
| before = stream.getvalue() |
| logging.getLogger(n + ".A.F").debug("but this one does not!") |
| assert before == stream.getvalue() |
| |
| logging.getLogger(n + ".C.DE").debug("neither this one!") |
| assert before == stream.getvalue() |
| |
| |
| def test_LogMixin(): |
| class Base(object): |
| pass |
| |
| class A(LogMixin, Base): |
| pass |
| |
| class B(A): |
| pass |
| |
| a = A() |
| b = B() |
| |
| assert hasattr(a, "log") |
| assert hasattr(b, "log") |
| assert isinstance(a.log, logging.Logger) |
| assert isinstance(b.log, logging.Logger) |
| assert a.log.name == "loggingTools_test.A" |
| assert b.log.name == "loggingTools_test.B" |