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
|
# This file is part of Online Services virtual machine tools.
#
# Copyright 2014-2017 Canonical Ltd.
#
# This program is free software: you can redistribute it and/or modify it under
# the terms of the GNU General Public License version 3, as published by the
# Free Software Foundation.
#
# This program is distributed in the hope that it will be useful, but WITHOUT
# ANY WARRANTY; without even the implied warranties of MERCHANTABILITY,
# SATISFACTORY QUALITY, or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
# General Public License for more details.
#
# You should have received a copy of the GNU General Public License along with
# this program. If not, see <http://www.gnu.org/licenses/>.
from __future__ import unicode_literals
import functools
import io
import logging
import unittest
from olstests import (
assertions,
results,
)
# Since config.vm_class_registry is populated when commands is imported and
# since some tests are parametrized based on its content, it should be imported
# early.
from olsvms import commands
# Make sure pep8 is happy
__fake = commands.logger
del __fake
class TestLogger(logging.Logger):
"""A logger dedicated to a given test.
Log messages are captured in a string buffer.
"""
def __init__(self, test, level=logging.DEBUG,
fmt='%(asctime)-15s %(message)s'):
super(TestLogger, self).__init__(test.id(), level)
self.stream = io.StringIO()
handler = logging.StreamHandler(self.stream)
handler.setFormatter(logging.Formatter(fmt))
self.addHandler(handler)
def getvalue(self):
return self.stream.getvalue()
class log_on_failure(object):
"""Decorates a test to display log on failure.
This adds a 'logger' attribute to the parameters of the decorated
test. Using this logger the test can display its content when it fails or
errors but stay silent otherwise.
"""
def __init__(self, level=logging.INFO, fmt='%(message)s'):
self.level = level
self.fmt = fmt
def __call__(self, func):
@functools.wraps(func)
def decorator(*args):
test = args[0]
logger = TestLogger(test, level=self.level, fmt=self.fmt)
display_log = True
# We need to delay the log acquisition until we attempt to display
# it (or we get no content).
def delayed_display_log():
msg = 'Failed test log: >>>\n{}\n<<<'.format(logger.getvalue())
if display_log:
raise Exception(msg)
test.addCleanup(delayed_display_log)
# Run the test without the decoration
func(*args + (logger,))
# If it terminates properly, disable log display
display_log = False
return decorator
class TestLogOnFailure(unittest.TestCase):
def setUp(self):
super(TestLogOnFailure, self).setUp()
self.result = results.TextResult(io.StringIO(), verbosity=2)
# We don't care about timing here so we always return 0 which
# simplifies matching the expected result
def zero(atime):
return 0.0
self.result.convert_delta_to_float = zero
# Inner tests will set this from the logger they receive so outter
# tests can assert the content.
self.logger = None
def test_log_not_displayed(self):
class Test(unittest.TestCase):
@log_on_failure()
def test_pass(inner, logger):
self.logger = logger
logger.info('pass')
t = Test('test_pass')
t.run(self.result)
self.assertEqual('pass\n', self.logger.getvalue())
self.assertEqual('{} ... OK (0.000 secs)\n'.format(t.id()),
self.result.stream.getvalue())
self.assertEqual([], self.result.errors)
def test_log_displayed(self):
class Test(unittest.TestCase):
@log_on_failure()
def test_fail(inner, logger):
self.logger = logger
logger.info("I'm broken")
inner.fail()
t = Test('test_fail')
t.run(self.result)
self.assertEqual("I'm broken\n", self.logger.getvalue())
# FAILERROR: The test FAIL, the cleanup ERRORs out.
self.assertEqual(
'{} ... FAILERROR (0.000 secs)\n'.format(t.id()),
self.result.stream.getvalue())
assertions.assertLength(self, 1, self.result.errors)
failing_test, traceback = self.result.errors[0]
self.assertIs(t, failing_test)
expected = traceback.endswith("Failed test log:"
" >>>\nI'm broken\n\n<<<\n")
self.assertTrue(expected, 'Actual traceback: {}'.format(traceback))
def test_log_debug_not_displayed(self):
class Test(unittest.TestCase):
@log_on_failure()
def test_debug_silent(inner, logger):
self.logger = logger
logger.debug('more info')
self.fail()
t = Test('test_debug_silent')
t.run(self.result)
self.assertEqual('', self.logger.getvalue())
def test_log_debug_displayed(self):
class Test(unittest.TestCase):
@log_on_failure(level=logging.DEBUG)
def test_debug_verbose(inner, logger):
self.logger = logger
logger.debug('more info')
self.fail()
t = Test('test_debug_verbose')
t.run(self.result)
self.assertEqual('more info\n', self.logger.getvalue())
|