root / snf-tools / synnefo_tools / burnin / logger.py @ 828bbf06
History | View | Annotate | Download (15.3 kB)
1 |
# Copyright 2013 GRNET S.A. All rights reserved.
|
---|---|
2 |
#
|
3 |
# Redistribution and use in source and binary forms, with or
|
4 |
# without modification, are permitted provided that the following
|
5 |
# conditions are met:
|
6 |
#
|
7 |
# 1. Redistributions of source code must retain the above
|
8 |
# copyright notice, this list of conditions and the following
|
9 |
# disclaimer.
|
10 |
#
|
11 |
# 2. Redistributions in binary form must reproduce the above
|
12 |
# copyright notice, this list of conditions and the following
|
13 |
# disclaimer in the documentation and/or other materials
|
14 |
# provided with the distribution.
|
15 |
#
|
16 |
# THIS SOFTWARE IS PROVIDED BY GRNET S.A. ``AS IS'' AND ANY EXPRESS
|
17 |
# OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED
|
18 |
# WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
|
19 |
# PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL GRNET S.A OR
|
20 |
# CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
|
21 |
# SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
|
22 |
# LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF
|
23 |
# USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED
|
24 |
# AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
|
25 |
# LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN
|
26 |
# ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
|
27 |
# POSSIBILITY OF SUCH DAMAGE.
|
28 |
#
|
29 |
# The views and conclusions contained in the software and
|
30 |
# documentation are those of the authors and should not be
|
31 |
# interpreted as representing official policies, either expressed
|
32 |
# or implied, of GRNET S.A.
|
33 |
|
34 |
"""
|
35 |
This is the logging class for burnin
|
36 |
|
37 |
It supports logging both for the stdout/stderr as well as file logging at the
|
38 |
same time.
|
39 |
|
40 |
The stdout/stderr logger supports verbose levels and colors but the file
|
41 |
logging doesn't (we use the info verbose level for our file logger).
|
42 |
|
43 |
Our loggers have primitive support for handling parallel execution (even though
|
44 |
burnin doesn't support it yet). To do so the stdout/stderr logger prepends the
|
45 |
name of the test under execution to every line it prints. On the other hand the
|
46 |
file logger waits to lock the file, then reads it, prints the message to the
|
47 |
corresponding line and closes the file.
|
48 |
|
49 |
|
50 |
"""
|
51 |
|
52 |
import os |
53 |
import sys |
54 |
import os.path |
55 |
import datetime |
56 |
|
57 |
from synnefo_tools.burnin import filelocker |
58 |
|
59 |
|
60 |
# --------------------------------------------------------------------
|
61 |
# Constant variables
|
62 |
LOCK_EXT = ".lock"
|
63 |
SECTION_SEPARATOR = \ |
64 |
"-- -------------------------------------------------------------------"
|
65 |
SECTION_PREFIX = "-- "
|
66 |
SECTION_RUNNED = "Tests Runned"
|
67 |
SECTION_RESULTS = "Results"
|
68 |
SECTION_NEW = "__ADD_NEW_SECTION__"
|
69 |
SECTION_PASSED = " * Passed:"
|
70 |
SECTION_FAILED = " * Failed:"
|
71 |
|
72 |
|
73 |
# --------------------------------------------------------------------
|
74 |
# Helper functions
|
75 |
def _blue(msg): |
76 |
"""Blue color"""
|
77 |
return "\x1b[1;34m" + str(msg) + "\x1b[0m" |
78 |
|
79 |
|
80 |
def _yellow(msg): |
81 |
"""Yellow color"""
|
82 |
return "\x1b[33m" + str(msg) + "\x1b[0m" |
83 |
|
84 |
|
85 |
def _red(msg): |
86 |
"""Yellow color"""
|
87 |
return "\x1b[31m" + str(msg) + "\x1b[0m" |
88 |
|
89 |
|
90 |
def _magenta(msg): |
91 |
"""Magenta color"""
|
92 |
return "\x1b[35m" + str(msg) + "\x1b[0m" |
93 |
|
94 |
|
95 |
def _green(msg): |
96 |
"""Green color"""
|
97 |
return "\x1b[32m" + str(msg) + "\x1b[0m" |
98 |
|
99 |
|
100 |
def _format_message(msg, *args): |
101 |
"""Format the message using the args"""
|
102 |
if args:
|
103 |
return (msg % args) + "\n" |
104 |
else:
|
105 |
return msg + "\n" |
106 |
|
107 |
|
108 |
def _list_to_string(lst, append=""): |
109 |
"""Convert a list of strings to string
|
110 |
|
111 |
Append the value given in L{append} in front of all lines
|
112 |
(except of the first line).
|
113 |
|
114 |
"""
|
115 |
if isinstance(lst, list): |
116 |
return append.join(lst).rstrip('\n') |
117 |
else:
|
118 |
return lst.rstrip('\n') |
119 |
|
120 |
|
121 |
# --------------------------------------
|
122 |
def _locate_sections(contents): |
123 |
"""Locate the sections inside the logging file"""
|
124 |
i = 0
|
125 |
res = [] |
126 |
for cnt in contents: |
127 |
if SECTION_SEPARATOR in cnt: |
128 |
res.append(i+1)
|
129 |
i += 1
|
130 |
return res
|
131 |
|
132 |
|
133 |
def _locate_input(contents, section): |
134 |
"""Locate position to insert text
|
135 |
|
136 |
Given a section location the next possition to insert text inside that
|
137 |
section.
|
138 |
|
139 |
"""
|
140 |
sect_locs = _locate_sections(contents) |
141 |
if section == SECTION_NEW:
|
142 |
# We want to add a new section
|
143 |
# Just return the position of SECTION_RESULTS
|
144 |
for obj in sect_locs: |
145 |
if SECTION_RESULTS in contents[obj]: |
146 |
return obj - 1 |
147 |
else:
|
148 |
# We will add our message in this location
|
149 |
for (index, obj) in enumerate(sect_locs): |
150 |
if section in contents[obj]: |
151 |
return sect_locs[index+1] - 3 |
152 |
|
153 |
# We didn't find our section??
|
154 |
sys.stderr.write("Section %s could not be found in logging file\n"
|
155 |
% section) |
156 |
sys.exit("Error in logger._locate_input")
|
157 |
|
158 |
|
159 |
def _add_testsuite_results(contents, section, testsuite): |
160 |
"""Add the given testsuite to results
|
161 |
|
162 |
Well we know that SECTION_FAILED is the last line and SECTION_PASSED is the
|
163 |
line before, so we are going to cheat here and use this information.
|
164 |
|
165 |
"""
|
166 |
if section == SECTION_PASSED:
|
167 |
line = contents[-2]
|
168 |
new_line = line.rstrip() + " " + testsuite + ",\n" |
169 |
contents[-2] = new_line
|
170 |
elif section == SECTION_FAILED:
|
171 |
line = contents[-1]
|
172 |
new_line = line.rstrip() + " " + testsuite + ",\n" |
173 |
contents[-1] = new_line
|
174 |
else:
|
175 |
sys.stderr.write("Unknown section %s in _add_testsuite_results\n"
|
176 |
% section) |
177 |
sys.exit("Error in logger._add_testsuite_results")
|
178 |
return contents
|
179 |
|
180 |
|
181 |
def _write_log_file(file_location, section, message): |
182 |
"""Write something to our log file
|
183 |
|
184 |
For this we have to get the lock, read and parse the file add the new
|
185 |
message and re-write the file.
|
186 |
|
187 |
"""
|
188 |
# Get the lock
|
189 |
file_lock = os.path.splitext(file_location)[0] + LOCK_EXT
|
190 |
with filelocker.lock(file_lock, filelocker.LOCK_EX):
|
191 |
with open(file_location, "r+") as log_file: |
192 |
contents = log_file.readlines() |
193 |
if section == SECTION_PASSED or section == SECTION_FAILED: |
194 |
# Add testsuite to results
|
195 |
new_contents = \ |
196 |
_add_testsuite_results(contents, section, message) |
197 |
else:
|
198 |
# Add message to its line
|
199 |
input_loc = _locate_input(contents, section) |
200 |
new_contents = \ |
201 |
contents[:input_loc] + [message] + contents[input_loc:] |
202 |
log_file.seek(0)
|
203 |
log_file.write("".join(new_contents))
|
204 |
|
205 |
|
206 |
# --------------------------------------------------------------------
|
207 |
# The Log class
|
208 |
class Log(object): |
209 |
"""Burnin logger
|
210 |
|
211 |
"""
|
212 |
# ----------------------------------
|
213 |
# Too many arguments. pylint: disable-msg=R0913
|
214 |
def __init__(self, output_dir, verbose=1, use_colors=True, |
215 |
in_parallel=False, log_level=0, curr_time=None): |
216 |
"""Initialize our loggers
|
217 |
|
218 |
The file to be used by our file logger will be created inside
|
219 |
the L{output_dir} with name the current timestamp.
|
220 |
|
221 |
@type output_dir: string
|
222 |
@param output_dir: the directory to save the output file
|
223 |
@type verbose: int
|
224 |
@param verbose: the verbose level to use for stdout/stderr logger
|
225 |
0: verbose at minimum level (only which test we are running now)
|
226 |
1: verbose at info level (information about our running test)
|
227 |
2: verbose at debug level
|
228 |
@type use_colors: boolean
|
229 |
@param use_colors: use colors for out stdout/stderr logger
|
230 |
@type in_parallel: boolean
|
231 |
@param in_parallel: this signifies that burnin is running in parallel
|
232 |
@type log_level: int
|
233 |
@param log_level: logging level
|
234 |
0: log to console and file
|
235 |
1: log to file only and output the results to console
|
236 |
2: don't log
|
237 |
@type curr_time: datetime.datetime()
|
238 |
@param curr_time: The current time (used as burnin's run id)
|
239 |
|
240 |
"""
|
241 |
self.verbose = verbose
|
242 |
self.use_colors = use_colors
|
243 |
self.in_parallel = in_parallel
|
244 |
self.log_level = log_level
|
245 |
|
246 |
assert output_dir
|
247 |
|
248 |
if curr_time is None: |
249 |
curr_time = datetime.datetime.now() |
250 |
timestamp = datetime.datetime.strftime( |
251 |
curr_time, "%Y%m%d%H%M%S (%a %b %d %Y %H:%M)")
|
252 |
file_name = timestamp + ".log"
|
253 |
self.file_location = os.path.join(output_dir, file_name)
|
254 |
|
255 |
self._write_to_stdout(None, "Starting burnin with id %s\n" % timestamp) |
256 |
|
257 |
# Create the logging file
|
258 |
self._create_logging_file(timestamp, output_dir)
|
259 |
|
260 |
def _create_logging_file(self, timestamp, output_dir): |
261 |
"""Create the logging file"""
|
262 |
if self.log_level > 1: |
263 |
return
|
264 |
|
265 |
# Create file for logging
|
266 |
output_dir = os.path.expanduser(output_dir) |
267 |
if not os.path.exists(output_dir): |
268 |
self.debug(None, "Creating directory %s", output_dir) |
269 |
try:
|
270 |
os.makedirs(output_dir) |
271 |
except OSError as err: |
272 |
msg = ("Failed to create folder \"%s\" with error: %s\n"
|
273 |
% (output_dir, err)) |
274 |
sys.stderr.write(msg) |
275 |
sys.exit("Failed to create log folder")
|
276 |
|
277 |
self.debug(None, "Using \"%s\" file for logging", self.file_location) |
278 |
with open(self.file_location, 'w') as out_file: |
279 |
out_file.write(SECTION_SEPARATOR + "\n")
|
280 |
out_file.write("%s%s with id %s:\n\n\n\n" %
|
281 |
(SECTION_PREFIX, SECTION_RUNNED, timestamp)) |
282 |
out_file.write(SECTION_SEPARATOR + "\n")
|
283 |
out_file.write("%s%s:\n\n" % (SECTION_PREFIX, SECTION_RESULTS))
|
284 |
out_file.write(SECTION_PASSED + "\n" + SECTION_FAILED + "\n") |
285 |
|
286 |
def __del__(self): |
287 |
"""Delete the Log object"""
|
288 |
self.print_logfile_to_stdout()
|
289 |
# Remove the lock file
|
290 |
if hasattr(self, "file_location"): |
291 |
file_lock = os.path.splitext(self.file_location)[0] + LOCK_EXT |
292 |
try:
|
293 |
os.remove(file_lock) |
294 |
except OSError: |
295 |
self.debug(None, "Couldn't delete lock file") |
296 |
|
297 |
def print_logfile_to_stdout(self): |
298 |
"""Print the contents of our log file to stdout"""
|
299 |
if self.log_level == 1: |
300 |
with open(self.file_location, 'r') as fin: |
301 |
sys.stdout.write(fin.read()) |
302 |
|
303 |
# ----------------------------------
|
304 |
# Logging methods
|
305 |
def debug(self, section, msg, *args): |
306 |
"""Debug messages (verbose 2)
|
307 |
|
308 |
We show debug messages only to stdout. The message will be formatted
|
309 |
using the args.
|
310 |
|
311 |
"""
|
312 |
msg = " (DD) " + _list_to_string(msg, append=" ") |
313 |
if self.verbose >= 2: |
314 |
colored_msg = self._color_message(None, msg, *args) |
315 |
self._write_to_stdout(section, colored_msg)
|
316 |
|
317 |
def log(self, section, msg, *args): |
318 |
"""Normal messages (verbose 0)"""
|
319 |
assert section, "Section can not be empty" |
320 |
|
321 |
msg = _list_to_string(msg) |
322 |
|
323 |
colored_msg = self._color_message(None, msg, *args) |
324 |
self._write_to_stdout(section, colored_msg)
|
325 |
|
326 |
plain_msg = _format_message(msg, *args) |
327 |
self._write_to_file(section, plain_msg)
|
328 |
|
329 |
def info(self, section, msg, *args): |
330 |
"""Info messages (verbose 1)
|
331 |
|
332 |
Prepare message and write it to file logger and stdout logger
|
333 |
|
334 |
"""
|
335 |
assert section, "Section can not be empty" |
336 |
|
337 |
msg = " " + _list_to_string(msg, " ") |
338 |
if self.verbose >= 1: |
339 |
colored_msg = self._color_message(None, msg, *args) |
340 |
self._write_to_stdout(section, colored_msg)
|
341 |
|
342 |
plain_msg = _format_message(msg, *args) |
343 |
self._write_to_file(section, plain_msg)
|
344 |
|
345 |
def warning(self, section, msg, *args): |
346 |
"""Warning messages"""
|
347 |
assert section, "Section can not be empty" |
348 |
|
349 |
msg = " (WW) " + _list_to_string(msg, " ") |
350 |
|
351 |
colored_msg = self._color_message(_yellow, msg, *args)
|
352 |
self._write_to_stderr(section, colored_msg)
|
353 |
|
354 |
plain_msg = _format_message(msg, *args) |
355 |
self._write_to_file(section, plain_msg)
|
356 |
|
357 |
def error(self, section, msg, *args): |
358 |
"""Error messages"""
|
359 |
assert section, "Section can not be empty" |
360 |
|
361 |
msg = " (EE) " + _list_to_string(msg, " ") |
362 |
|
363 |
colored_msg = self._color_message(_red, msg, *args)
|
364 |
self._write_to_stderr(section, colored_msg)
|
365 |
|
366 |
plain_msg = _format_message(msg, *args) |
367 |
self._write_to_file(section, plain_msg)
|
368 |
|
369 |
def _write_to_stdout(self, section, msg): |
370 |
"""Write to stdout"""
|
371 |
if self.log_level > 0: |
372 |
return
|
373 |
if section is not None and self.in_parallel: |
374 |
sys.stdout.write(section + ": " + msg)
|
375 |
else:
|
376 |
sys.stdout.write(msg) |
377 |
|
378 |
def _write_to_stderr(self, section, msg): |
379 |
"""Write to stderr"""
|
380 |
if self.log_level > 0: |
381 |
return
|
382 |
if section is not None and self.in_parallel: |
383 |
sys.stderr.write(section + ": " + msg)
|
384 |
else:
|
385 |
sys.stderr.write(msg) |
386 |
|
387 |
def _write_to_file(self, section, msg): |
388 |
"""Write to file"""
|
389 |
if self.log_level > 1: |
390 |
return
|
391 |
_write_log_file(self.file_location, section, msg)
|
392 |
|
393 |
# ----------------------------------
|
394 |
# Handle testsuites
|
395 |
def testsuite_start(self, testsuite): |
396 |
"""Start a new testsuite
|
397 |
|
398 |
Add a new section in the logging file
|
399 |
|
400 |
"""
|
401 |
assert testsuite, "Testsuite name can not be emtpy" |
402 |
|
403 |
# Add a new section in the logging file
|
404 |
test_runned = " * " + testsuite + "\n" |
405 |
self._write_to_file(SECTION_RUNNED, test_runned)
|
406 |
|
407 |
new_section_entry = \ |
408 |
SECTION_SEPARATOR + "\n" + SECTION_PREFIX + testsuite + "\n\n\n\n" |
409 |
self._write_to_file(SECTION_NEW, new_section_entry)
|
410 |
|
411 |
# Add new section to the stdout
|
412 |
msg = "Starting testsuite %s" % testsuite
|
413 |
colored_msg = self._color_message(_magenta, msg)
|
414 |
self._write_to_stdout(None, colored_msg) |
415 |
|
416 |
def testsuite_success(self, testsuite): |
417 |
"""A testsuite has successfully finished
|
418 |
|
419 |
Update Results
|
420 |
|
421 |
"""
|
422 |
assert testsuite, "Testsuite name can not be emtpy" |
423 |
|
424 |
# Add our testsuite to Results
|
425 |
self._write_to_file(SECTION_PASSED, testsuite)
|
426 |
|
427 |
# Add success to stdout
|
428 |
msg = "Testsuite %s passed" % testsuite
|
429 |
colored_msg = self._color_message(_green, msg)
|
430 |
self._write_to_stdout(None, colored_msg) |
431 |
|
432 |
def testsuite_failure(self, testsuite): |
433 |
"""A testsuite has failed
|
434 |
|
435 |
Update Results
|
436 |
|
437 |
"""
|
438 |
assert testsuite, "Testsuite name can not be emtpy" |
439 |
|
440 |
# Add our testsuite to Results
|
441 |
self._write_to_file(SECTION_FAILED, testsuite)
|
442 |
|
443 |
# Add success to stdout
|
444 |
msg = "Testsuite %s failed" % testsuite
|
445 |
colored_msg = self._color_message(_red, msg)
|
446 |
self._write_to_stdout(None, colored_msg) |
447 |
|
448 |
# ----------------------------------
|
449 |
# Colors
|
450 |
def _color_message(self, color_fun, msg, *args): |
451 |
"""Color a message before printing it
|
452 |
|
453 |
The color_fun parameter is used when we want the whole message to be
|
454 |
colored.
|
455 |
|
456 |
"""
|
457 |
if self.use_colors: |
458 |
if callable(color_fun): |
459 |
if args:
|
460 |
return color_fun((msg % args)) + "\n" |
461 |
else:
|
462 |
return color_fun(msg) + "\n" |
463 |
else:
|
464 |
args = tuple([_blue(arg) for arg in args]) |
465 |
return _format_message(msg, *args)
|
466 |
else:
|
467 |
return _format_message(msg, *args)
|