Statistics
| Branch: | Tag: | Revision:

root / snf-tools / synnefo_tools / burnin / logger.py @ 3139b628

History | View | Annotate | Download (15.5 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 Run"
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 _cyan(msg):
76
    """Bold High Intensity Cyan color"""
77
    return "\x1b[1;96m" + 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].rstrip()
168
        if line.endswith(":"):
169
            new_line = line + " " + testsuite + "\n"
170
        else:
171
            new_line = line + ", " + testsuite + "\n"
172
        contents[-2] = new_line
173
    elif section == SECTION_FAILED:
174
        line = contents[-1].rstrip()
175
        if line.endswith(":"):
176
            new_line = line.rstrip() + " " + testsuite + "\n"
177
        else:
178
            new_line = line.rstrip() + ", " + testsuite + "\n"
179
        contents[-1] = new_line
180
    else:
181
        sys.stderr.write("Unknown section %s in _add_testsuite_results\n"
182
                         % section)
183
        sys.exit("Error in logger._add_testsuite_results")
184
    return contents
185

    
186

    
187
def _write_log_file(file_location, section, message):
188
    """Write something to our log file
189

190
    For this we have to get the lock, read and parse the file add the new
191
    message and re-write the file.
192

193
    """
194
    # Get the lock
195
    file_lock = os.path.splitext(file_location)[0] + LOCK_EXT
196
    with filelocker.lock(file_lock, filelocker.LOCK_EX):
197
        with open(file_location, "r+") as log_file:
198
            contents = log_file.readlines()
199
            if section == SECTION_PASSED or section == SECTION_FAILED:
200
                # Add testsuite to results
201
                new_contents = \
202
                    _add_testsuite_results(contents, section, message)
203
            else:
204
                # Add message to its line
205
                input_loc = _locate_input(contents, section)
206
                new_contents = \
207
                    contents[:input_loc] + [message] + contents[input_loc:]
208
            log_file.seek(0)
209
            log_file.write("".join(new_contents))
210

    
211

    
212
# --------------------------------------------------------------------
213
# The Log class
214
class Log(object):
215
    """Burnin logger
216

217
    """
218
    # ----------------------------------
219
    # Too many arguments. pylint: disable-msg=R0913
220
    def __init__(self, output_dir, verbose=1, use_colors=True,
221
                 in_parallel=False, log_level=0, curr_time=None):
222
        """Initialize our loggers
223

224
        The file to be used by our file logger will be created inside
225
        the L{output_dir} with name the current timestamp.
226

227
        @type output_dir: string
228
        @param output_dir: the directory to save the output file
229
        @type verbose: int
230
        @param verbose: the verbose level to use for stdout/stderr logger
231
            0: verbose at minimum level (only which test we are running now)
232
            1: verbose at info level (information about our running test)
233
            2: verbose at debug level
234
        @type use_colors: boolean
235
        @param use_colors: use colors for out stdout/stderr logger
236
        @type in_parallel: boolean
237
        @param in_parallel: this signifies that burnin is running in parallel
238
        @type log_level: int
239
        @param log_level: logging level
240
            0: log to console and file
241
            1: log to file only and output the results to console
242
            2: don't log
243
        @type curr_time: datetime.datetime()
244
        @param curr_time: The current time (used as burnin's run id)
245

246
        """
247
        self.verbose = verbose
248
        self.use_colors = use_colors
249
        self.in_parallel = in_parallel
250
        self.log_level = log_level
251

    
252
        assert output_dir
253

    
254
        if curr_time is None:
255
            curr_time = datetime.datetime.now()
256
        timestamp = datetime.datetime.strftime(
257
            curr_time, "%Y%m%d%H%M%S (%a %b %d %Y %H:%M)")
258
        file_name = timestamp + ".log"
259
        self.file_location = os.path.join(output_dir, file_name)
260

    
261
        self._write_to_stdout(None, "Starting burnin with id %s\n" % timestamp)
262

    
263
        # Create the logging file
264
        self._create_logging_file(timestamp, output_dir)
265

    
266
    def _create_logging_file(self, timestamp, output_dir):
267
        """Create the logging file"""
268
        if self.log_level > 1:
269
            return
270

    
271
        # Create file for logging
272
        output_dir = os.path.expanduser(output_dir)
273
        if not os.path.exists(output_dir):
274
            self.debug(None, "Creating directory %s", output_dir)
275
            try:
276
                os.makedirs(output_dir)
277
            except OSError as err:
278
                msg = ("Failed to create folder \"%s\" with error: %s\n"
279
                       % (output_dir, err))
280
                sys.stderr.write(msg)
281
                sys.exit("Failed to create log folder")
282

    
283
        self.debug(None, "Using \"%s\" file for logging", self.file_location)
284
        with open(self.file_location, 'w') as out_file:
285
            out_file.write(SECTION_SEPARATOR + "\n")
286
            out_file.write("%s%s with id %s:\n\n\n\n" %
287
                           (SECTION_PREFIX, SECTION_RUNNED, timestamp))
288
            out_file.write(SECTION_SEPARATOR + "\n")
289
            out_file.write("%s%s:\n\n" % (SECTION_PREFIX, SECTION_RESULTS))
290
            out_file.write(SECTION_PASSED + "\n" + SECTION_FAILED + "\n")
291

    
292
    def __del__(self):
293
        """Delete the Log object"""
294
        self.print_logfile_to_stdout()
295
        # Remove the lock file
296
        if hasattr(self, "file_location"):
297
            file_lock = os.path.splitext(self.file_location)[0] + LOCK_EXT
298
            try:
299
                os.remove(file_lock)
300
            except OSError:
301
                self.debug(None, "Couldn't delete lock file")
302

    
303
    def print_logfile_to_stdout(self):
304
        """Print the contents of our log file to stdout"""
305
        if self.log_level == 1:
306
            with open(self.file_location, 'r') as fin:
307
                sys.stdout.write(fin.read())
308

    
309
    # ----------------------------------
310
    # Logging methods
311
    def debug(self, section, msg, *args):
312
        """Debug messages (verbose 2)
313

314
        We show debug messages only to stdout. The message will be formatted
315
        using the args.
316

317
        """
318
        msg = "  (DD) " + _list_to_string(msg, append="       ")
319
        if self.verbose >= 2:
320
            colored_msg = self._color_message(None, msg, *args)
321
            self._write_to_stdout(section, colored_msg)
322

    
323
    def log(self, section, msg, *args):
324
        """Normal messages (verbose 0)"""
325
        assert section, "Section can not be empty"
326

    
327
        msg = _list_to_string(msg)
328

    
329
        colored_msg = self._color_message(None, msg, *args)
330
        self._write_to_stdout(section, colored_msg)
331

    
332
        plain_msg = _format_message(msg, *args)
333
        self._write_to_file(section, plain_msg)
334

    
335
    def info(self, section, msg, *args):
336
        """Info messages (verbose 1)
337

338
        Prepare message and write it to file logger and stdout logger
339

340
        """
341
        assert section, "Section can not be empty"
342

    
343
        msg = "  " + _list_to_string(msg, "  ")
344
        if self.verbose >= 1:
345
            colored_msg = self._color_message(None, msg, *args)
346
            self._write_to_stdout(section, colored_msg)
347

    
348
        plain_msg = _format_message(msg, *args)
349
        self._write_to_file(section, plain_msg)
350

    
351
    def warning(self, section, msg, *args):
352
        """Warning messages"""
353
        assert section, "Section can not be empty"
354

    
355
        msg = "  (WW) " + _list_to_string(msg, "       ")
356

    
357
        colored_msg = self._color_message(_yellow, msg, *args)
358
        self._write_to_stderr(section, colored_msg)
359

    
360
        plain_msg = _format_message(msg, *args)
361
        self._write_to_file(section, plain_msg)
362

    
363
    def error(self, section, msg, *args):
364
        """Error messages"""
365
        assert section, "Section can not be empty"
366

    
367
        msg = "  (EE) " + _list_to_string(msg, "       ")
368

    
369
        colored_msg = self._color_message(_red, msg, *args)
370
        self._write_to_stderr(section, colored_msg)
371

    
372
        plain_msg = _format_message(msg, *args)
373
        self._write_to_file(section, plain_msg)
374

    
375
    def _write_to_stdout(self, section, msg):
376
        """Write to stdout"""
377
        if self.log_level > 0:
378
            return
379
        if section is not None and self.in_parallel:
380
            sys.stdout.write(section + ": " + msg)
381
        else:
382
            sys.stdout.write(msg)
383

    
384
    def _write_to_stderr(self, section, msg):
385
        """Write to stderr"""
386
        if self.log_level > 0:
387
            return
388
        if section is not None and self.in_parallel:
389
            sys.stderr.write(section + ": " + msg)
390
        else:
391
            sys.stderr.write(msg)
392

    
393
    def _write_to_file(self, section, msg):
394
        """Write to file"""
395
        if self.log_level > 1:
396
            return
397
        _write_log_file(self.file_location, section, msg)
398

    
399
    # ----------------------------------
400
    # Handle testsuites
401
    def testsuite_start(self, testsuite):
402
        """Start a new testsuite
403

404
        Add a new section in the logging file
405

406
        """
407
        assert testsuite, "Testsuite name can not be emtpy"
408

    
409
        # Add a new section in the logging file
410
        test_runned = "  * " + testsuite + "\n"
411
        self._write_to_file(SECTION_RUNNED, test_runned)
412

    
413
        new_section_entry = \
414
            SECTION_SEPARATOR + "\n" + SECTION_PREFIX + testsuite + "\n\n\n\n"
415
        self._write_to_file(SECTION_NEW, new_section_entry)
416

    
417
        # Add new section to the stdout
418
        msg = "Starting testsuite %s" % testsuite
419
        colored_msg = self._color_message(_magenta, msg)
420
        self._write_to_stdout(None, colored_msg)
421

    
422
    def testsuite_success(self, testsuite):
423
        """A testsuite has successfully finished
424

425
        Update Results
426

427
        """
428
        assert testsuite, "Testsuite name can not be emtpy"
429

    
430
        # Add our testsuite to Results
431
        self._write_to_file(SECTION_PASSED, testsuite)
432

    
433
        # Add success to stdout
434
        msg = "Testsuite %s passed" % testsuite
435
        colored_msg = self._color_message(_green, msg)
436
        self._write_to_stdout(None, colored_msg)
437

    
438
    def testsuite_failure(self, testsuite):
439
        """A testsuite has failed
440

441
        Update Results
442

443
        """
444
        assert testsuite, "Testsuite name can not be emtpy"
445

    
446
        # Add our testsuite to Results
447
        self._write_to_file(SECTION_FAILED, testsuite)
448

    
449
        # Add success to stdout
450
        msg = "Testsuite %s failed" % testsuite
451
        colored_msg = self._color_message(_red, msg)
452
        self._write_to_stdout(None, colored_msg)
453

    
454
    # ----------------------------------
455
    # Colors
456
    def _color_message(self, color_fun, msg, *args):
457
        """Color a message before printing it
458

459
        The color_fun parameter is used when we want the whole message to be
460
        colored.
461

462
        """
463
        if self.use_colors:
464
            if callable(color_fun):
465
                if args:
466
                    return color_fun((msg % args)) + "\n"
467
                else:
468
                    return color_fun(msg) + "\n"
469
            else:
470
                args = tuple([_cyan(arg) for arg in args])
471
                return _format_message(msg, *args)
472
        else:
473
            return _format_message(msg, *args)