xref: /aosp_15_r20/external/fonttools/Tests/misc/loggingTools_test.py (revision e1fe3e4ad2793916b15cccdc4a7da52a7e1dd0e9) 
1from fontTools.misc.loggingTools import (
2    LevelFormatter,
3    Timer,
4    configLogger,
5    ChannelsFilter,
6    LogMixin,
7)
8from io import StringIO
9import logging
10import textwrap
11import time
12import re
13import pytest
14
15
16def logger_name_generator():
17    basename = "fontTools.test#"
18    num = 1
19    while True:
20        yield basename + str(num)
21        num += 1
22
23
24unique_logger_name = logger_name_generator()
25
26
27@pytest.fixture
28def logger():
29    log = logging.getLogger(next(unique_logger_name))
30    configLogger(logger=log, level="DEBUG", stream=StringIO())
31    return log
32
33
34def test_LevelFormatter():
35    stream = StringIO()
36    handler = logging.StreamHandler(stream)
37    formatter = LevelFormatter(
38        fmt={
39            "*": "[%(levelname)s] %(message)s",
40            "DEBUG": "%(name)s [%(levelname)s] %(message)s",
41            "INFO": "%(message)s",
42        }
43    )
44    handler.setFormatter(formatter)
45    name = next(unique_logger_name)
46    log = logging.getLogger(name)
47    log.setLevel(logging.DEBUG)
48    log.addHandler(handler)
49
50    log.debug("this uses a custom format string")
51    log.info("this also uses a custom format string")
52    log.warning("this one uses the default format string")
53
54    assert stream.getvalue() == textwrap.dedent(
55        """\
56        %s [DEBUG] this uses a custom format string
57        this also uses a custom format string
58        [WARNING] this one uses the default format string
59        """
60        % name
61    )
62
63
64class TimerTest(object):
65    def test_split(self):
66        timer = Timer()
67        time.sleep(0.01)
68        fist_lap = timer.split()
69        assert timer.elapsed == fist_lap
70        time.sleep(0.1)
71        second_lap = timer.split()
72        assert second_lap > fist_lap
73        assert timer.elapsed == second_lap
74
75    def test_time(self):
76        timer = Timer()
77        time.sleep(0.01)
78        overall_time = timer.time()
79        assert overall_time > 0
80
81    def test_context_manager(self):
82        with Timer() as t:
83            time.sleep(0.01)
84        assert t.elapsed > 0
85
86    def test_using_logger(self, logger):
87        with Timer(logger, "do something"):
88            time.sleep(0.01)
89
90        assert re.match(
91            r"Took [0-9]\.[0-9]{3}s to do something",
92            logger.handlers[0].stream.getvalue(),
93        )
94
95    def test_using_logger_calling_instance(self, logger):
96        timer = Timer(logger)
97        with timer():
98            time.sleep(0.01)
99
100        assert re.match(
101            r"elapsed time: [0-9]\.[0-9]{3}s", logger.handlers[0].stream.getvalue()
102        )
103
104        # do it again but with custom level
105        with timer("redo it", level=logging.WARNING):
106            time.sleep(0.02)
107
108        assert re.search(
109            r"WARNING: Took [0-9]\.[0-9]{3}s to redo it",
110            logger.handlers[0].stream.getvalue(),
111        )
112
113    def test_function_decorator(self, logger):
114        timer = Timer(logger)
115
116        @timer()
117        def test1():
118            time.sleep(0.01)
119
120        @timer("run test 2", level=logging.INFO)
121        def test2():
122            time.sleep(0.02)
123
124        test1()
125
126        assert re.match(
127            r"Took [0-9]\.[0-9]{3}s to run 'test1'",
128            logger.handlers[0].stream.getvalue(),
129        )
130
131        test2()
132
133        assert re.search(
134            r"Took [0-9]\.[0-9]{3}s to run test 2", logger.handlers[0].stream.getvalue()
135        )
136
137
138def test_ChannelsFilter(logger):
139    n = logger.name
140    filtr = ChannelsFilter(n + ".A.B", n + ".C.D")
141    handler = logger.handlers[0]
142    handler.addFilter(filtr)
143    stream = handler.stream
144
145    logging.getLogger(n + ".A.B").debug("this record passes through")
146    assert "this record passes through" in stream.getvalue()
147
148    logging.getLogger(n + ".A.B.C").debug("records from children also pass")
149    assert "records from children also pass" in stream.getvalue()
150
151    logging.getLogger(n + ".C.D").debug("this one as well")
152    assert "this one as well" in stream.getvalue()
153
154    logging.getLogger(n + ".A.B.").debug("also this one")
155    assert "also this one" in stream.getvalue()
156
157    before = stream.getvalue()
158    logging.getLogger(n + ".A.F").debug("but this one does not!")
159    assert before == stream.getvalue()
160
161    logging.getLogger(n + ".C.DE").debug("neither this one!")
162    assert before == stream.getvalue()
163
164
165def test_LogMixin():
166    class Base(object):
167        pass
168
169    class A(LogMixin, Base):
170        pass
171
172    class B(A):
173        pass
174
175    a = A()
176    b = B()
177
178    assert hasattr(a, "log")
179    assert hasattr(b, "log")
180    assert isinstance(a.log, logging.Logger)
181    assert isinstance(b.log, logging.Logger)
182    assert a.log.name == "loggingTools_test.A"
183    assert b.log.name == "loggingTools_test.B"
184