Statistics
| Branch: | Tag: | Revision:

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)