File: test_log_capture.py

package info (click to toggle)
python-testfixtures 9.2.0-1
  • links: PTS, VCS
  • area: main
  • in suites: forky, sid
  • size: 1,036 kB
  • sloc: python: 10,373; makefile: 76; sh: 9
file content (246 lines) | stat: -rw-r--r-- 7,379 bytes parent folder | download | duplicates (3)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
from logging import getLogger, ERROR
from unittest import TestCase

from testfixtures.shouldraise import ShouldAssert
from testfixtures.mock import patch

from testfixtures import (
    log_capture, compare, Comparison as C, LogCapture
)

root = getLogger()
one = getLogger('one')
two = getLogger('two')
child = getLogger('one.child')


class TestLog_Capture(TestCase):

    @log_capture('two', 'one.child')
    @log_capture('one')
    @log_capture()
    def test_logging(self, l1, l2, l3):
        # we can now log as normal
        root.info('1')
        one.info('2')
        two.info('3')
        child.info('4')
        # and later check what was logged
        l1.check(
            ('root', 'INFO', '1'),
            ('one', 'INFO', '2'),
            ('two', 'INFO', '3'),
            ('one.child', 'INFO', '4'),
            )
        l2.check(
            ('one', 'INFO', '2'),
            ('one.child', 'INFO', '4')
            )
        l3.check(
            ('two', 'INFO', '3'),
            ('one.child', 'INFO', '4')
            )
        # each logger also exposes the real
        # log records should anything else be neeeded
        compare(l3.records, [
            C('logging.LogRecord'),
            C('logging.LogRecord'),
            ])

    @log_capture(ensure_checks_above=ERROR)
    def test_simple_strict(self, l):
        root.error('during')
        l.check(("root", "ERROR", "during"))

    def test_uninstall_properly(self):
        root = getLogger()
        child = getLogger('child')
        before_root = root.handlers[:]
        before_child = child.handlers[:]
        try:
            old_root_level = root.level
            root.setLevel(49)
            old_child_level = child.level
            child.setLevel(69)

            @log_capture('child')
            @log_capture()
            def test_method(l1, l2):
                root = getLogger()
                root.info('1')
                self.assertEqual(root.level, 1)
                child = getLogger('child')
                self.assertEqual(child.level, 1)
                child.info('2')
                l1.check(
                    ('root', 'INFO', '1'),
                    ('child', 'INFO', '2'),
                    )
                l2.check(
                    ('child', 'INFO', '2'),
                    )

            test_method()

            self.assertEqual(root.level, 49)
            self.assertEqual(child.level, 69)

            self.assertEqual(root.handlers, before_root)
            self.assertEqual(child.handlers, before_child)

        finally:
            root.setLevel(old_root_level)
            child.setLevel(old_child_level)

    @log_capture()
    def test_decorator_returns_logcapture(self, l):
        # check for what we get, so we only have to write
        # tests in test_logcapture.py
        self.assertTrue(isinstance(l, LogCapture))

    def test_remove_existing_handlers(self):
        logger = getLogger()
        # get original handlers
        original = logger.handlers
        try:
            # put in a stub which will blow up if used
            logger.handlers = start = [object()]

            @log_capture()
            def test_method(l):
                logger.info('during')
                l.check(('root', 'INFO', 'during'))

            test_method()

            compare(logger.handlers, start)

        finally:
            logger.handlers = original

    def test_clear_global_state(self):
        from logging import _handlers, _handlerList
        capture = LogCapture()
        capture.uninstall()
        self.assertFalse(capture in _handlers)
        self.assertFalse(capture in _handlerList)

    def test_no_propogate(self):
        logger = getLogger('child')
        # paranoid check
        compare(logger.propagate, True)

        @log_capture('child', propagate=False)
        def test_method(l):
            logger.info('a log message')
            l.check(('child', 'INFO', 'a log message'))

        with LogCapture() as global_log:
            test_method()

        global_log.check()
        compare(logger.propagate, True)

    def test_different_attributes(self):
        with LogCapture(attributes=('funcName', 'processName')) as log:
            getLogger().info('oh hai')
        log.check(
            ('test_different_attributes', 'MainProcess')
        )

    def test_missing_attribute(self):
        with LogCapture(attributes=('msg', 'lolwut')) as log:
            getLogger().info('oh %s', 'hai')
        log.check(
            ('oh %s', None)
        )

    def test_single_attribute(self):
        # one which isn't a string, to boot!
        with LogCapture(attributes=['msg']) as log:
            getLogger().info(dict(foo='bar', baz='bob'))
        log.check(
            dict(foo='bar', baz='bob'),
        )

    def test_callable_instead_of_attribute(self):
        def extract_msg(record):
            return {k: v for (k, v) in record.msg.items()
                    if k != 'baz'}
        with LogCapture(attributes=extract_msg) as log:
            getLogger().info(dict(foo='bar', baz='bob'))
        log.check(
            dict(foo='bar'),
        )

    def test_msg_is_none(self):
        with LogCapture(attributes=('msg', 'foo')) as log:
            getLogger().info(None, extra=dict(foo='bar'))
        log.check(
            (None, 'bar')
        )

    def test_normal_check(self):
        with LogCapture() as log:
            getLogger().info('oh hai')

        with ShouldAssert(
            "sequence not as expected:\n\n"
            "same:\n"
            "()\n\n"
            "expected:\n"
            "(('root', 'INFO', 'oh noez'),)\n\n"
            "actual:\n"
            "(('root', 'INFO', 'oh hai'),)"
        ):
            log.check(('root', 'INFO', 'oh noez'))

    def test_recursive_check(self):

        with LogCapture(recursive_check=True) as log:
            getLogger().info('oh hai')

        with ShouldAssert(
            "sequence not as expected:\n\n"
            "same:\n()\n\n"
            "expected:\n(('root', 'INFO', 'oh noez'),)\n\n"
            "actual:\n(('root', 'INFO', 'oh hai'),)\n\n"
            "While comparing [0]: sequence not as expected:\n\n"
            "same:\n('root', 'INFO')\n\n"
            "expected:\n"
            "('oh noez',)\n\n"
            "actual:\n"
            "('oh hai',)\n\n"
            "While comparing [0][2]: 'oh noez' (expected) != 'oh hai' (actual)"
        ):
            log.check(('root', 'INFO', 'oh noez'))

    @log_capture()
    @patch('testfixtures.tests.sample1.SampleClassA')
    def test_patch_then_log(self, a1, a2):
        actual = [type(c).__name__ for c in (a1, a2)]
        compare(actual, expected=['MagicMock', 'LogCaptureForDecorator'])

    @patch('testfixtures.tests.sample1.SampleClassA')
    @log_capture()
    def test_log_then_patch(self, a1, a2):
        actual = [type(c).__name__ for c in (a1, a2)]
        compare(actual, expected=['LogCaptureForDecorator', 'MagicMock'])


class BaseCaptureTest(TestCase):
    a = 33

    @log_capture()
    def test_logs_if_a_smaller_than_44(self, logs):
        logger = getLogger()
        if self.a < 44:
            logger.info('{} is smaller than 44'.format(self.a))

        logs.check(
            ('root', 'INFO', '{} is smaller than 44'.format(self.a)),
        )


class SubclassCaptureTest(BaseCaptureTest):
    a = 2