Statistics
| Branch: | Tag: | Revision:

root / snf-tools / synnefo_tools / burnin / logger.py @ 9355a604

History | View | Annotate | Download (15.6 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 logging
56
import datetime
57

    
58
from synnefo_tools.burnin import filelocker
59

    
60

    
61
# --------------------------------------------------------------------
62
# Constant variables
63
LOCK_EXT = ".lock"
64
SECTION_SEPARATOR = \
65
    "-- -------------------------------------------------------------------"
66
SECTION_PREFIX = "-- "
67
SECTION_RUNNED = "Tests Run"
68
SECTION_RESULTS = "Results"
69
SECTION_NEW = "__ADD_NEW_SECTION__"
70
SECTION_PASSED = "  * Passed:"
71
SECTION_FAILED = "  * Failed:"
72

    
73
# Ignore `paramiko' logger
74
logging.getLogger('paramiko').addHandler(logging.NullHandler())
75

    
76

    
77
# --------------------------------------------------------------------
78
# Helper functions
79
def _cyan(msg):
80
    """Bold High Intensity Cyan color"""
81
    return "\x1b[1;96m" + str(msg) + "\x1b[0m"
82

    
83

    
84
def _yellow(msg):
85
    """Yellow color"""
86
    return "\x1b[33m" + str(msg) + "\x1b[0m"
87

    
88

    
89
def _red(msg):
90
    """Yellow color"""
91
    return "\x1b[31m" + str(msg) + "\x1b[0m"
92

    
93

    
94
def _magenta(msg):
95
    """Magenta color"""
96
    return "\x1b[35m" + str(msg) + "\x1b[0m"
97

    
98

    
99
def _green(msg):
100
    """Green color"""
101
    return "\x1b[32m" + str(msg) + "\x1b[0m"
102

    
103

    
104
def _format_message(msg, *args):
105
    """Format the message using the args"""
106
    if args:
107
        return (msg % args) + "\n"
108
    else:
109
        return msg + "\n"
110

    
111

    
112
def _list_to_string(lst, append=""):
113
    """Convert a list of strings to string
114

115
    Append the value given in L{append} in front of all lines
116
    (except of the first line).
117

118
    """
119
    if isinstance(lst, list):
120
        return append.join(lst).rstrip('\n')
121
    else:
122
        return lst.rstrip('\n')
123

    
124

    
125
# --------------------------------------
126
def _locate_sections(contents):
127
    """Locate the sections inside the logging file"""
128
    i = 0
129
    res = []
130
    for cnt in contents:
131
        if SECTION_SEPARATOR in cnt:
132
            res.append(i+1)
133
        i += 1
134
    return res
135

    
136

    
137
def _locate_input(contents, section):
138
    """Locate position to insert text
139

140
    Given a section location the next possition to insert text inside that
141
    section.
142

143
    """
144
    sect_locs = _locate_sections(contents)
145
    if section == SECTION_NEW:
146
        # We want to add a new section
147
        # Just return the position of SECTION_RESULTS
148
        for obj in sect_locs:
149
            if SECTION_RESULTS in contents[obj]:
150
                return obj - 1
151
    else:
152
        # We will add our message in this location
153
        for (index, obj) in enumerate(sect_locs):
154
            if section in contents[obj]:
155
                return sect_locs[index+1] - 3
156

    
157
    # We didn't find our section??
158
    sys.stderr.write("Section %s could not be found in logging file\n"
159
                     % section)
160
    sys.exit("Error in logger._locate_input")
161

    
162

    
163
def _add_testsuite_results(contents, section, testsuite):
164
    """Add the given testsuite to results
165

166
    Well we know that SECTION_FAILED is the last line and SECTION_PASSED is the
167
    line before, so we are going to cheat here and use this information.
168

169
    """
170
    if section == SECTION_PASSED:
171
        line = contents[-2].rstrip()
172
        if line.endswith(":"):
173
            new_line = line + " " + testsuite + "\n"
174
        else:
175
            new_line = line + ", " + testsuite + "\n"
176
        contents[-2] = new_line
177
    elif section == SECTION_FAILED:
178
        line = contents[-1].rstrip()
179
        if line.endswith(":"):
180
            new_line = line.rstrip() + " " + testsuite + "\n"
181
        else:
182
            new_line = line.rstrip() + ", " + testsuite + "\n"
183
        contents[-1] = new_line
184
    else:
185
        sys.stderr.write("Unknown section %s in _add_testsuite_results\n"
186
                         % section)
187
        sys.exit("Error in logger._add_testsuite_results")
188
    return contents
189

    
190

    
191
def _write_log_file(file_location, section, message):
192
    """Write something to our log file
193

194
    For this we have to get the lock, read and parse the file add the new
195
    message and re-write the file.
196

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

    
215

    
216
# --------------------------------------------------------------------
217
# The Log class
218
class Log(object):
219
    """Burnin logger
220

221
    """
222
    # ----------------------------------
223
    # pylint: disable=too-many-arguments
224
    def __init__(self, output_dir, verbose=1, use_colors=True,
225
                 in_parallel=False, log_level=0, curr_time=None):
226
        """Initialize our loggers
227

228
        The file to be used by our file logger will be created inside
229
        the L{output_dir} with name the current timestamp.
230

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

250
        """
251
        self.verbose = verbose
252
        self.use_colors = use_colors
253
        self.in_parallel = in_parallel
254
        self.log_level = log_level
255

    
256
        assert output_dir
257

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

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

    
267
        # Create the logging file
268
        self._create_logging_file(timestamp, output_dir)
269

    
270
    def _create_logging_file(self, timestamp, output_dir):
271
        """Create the logging file"""
272
        if self.log_level > 1:
273
            return
274

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

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

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

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

    
313
    # ----------------------------------
314
    # Logging methods
315
    def debug(self, section, msg, *args):
316
        """Debug messages (verbose 2)
317

318
        We show debug messages only to stdout. The message will be formatted
319
        using the args.
320

321
        """
322
        msg = "  (DD) " + _list_to_string(msg, append="       ")
323
        if self.verbose >= 2:
324
            colored_msg = self._color_message(None, msg, *args)
325
            self._write_to_stdout(section, colored_msg)
326

    
327
    def log(self, section, msg, *args):
328
        """Normal messages (verbose 0)"""
329
        assert section, "Section can not be empty"
330

    
331
        msg = _list_to_string(msg)
332

    
333
        colored_msg = self._color_message(None, msg, *args)
334
        self._write_to_stdout(section, colored_msg)
335

    
336
        plain_msg = _format_message(msg, *args)
337
        self._write_to_file(section, plain_msg)
338

    
339
    def info(self, section, msg, *args):
340
        """Info messages (verbose 1)
341

342
        Prepare message and write it to file logger and stdout logger
343

344
        """
345
        assert section, "Section can not be empty"
346

    
347
        msg = "  " + _list_to_string(msg, "  ")
348
        if self.verbose >= 1:
349
            colored_msg = self._color_message(None, msg, *args)
350
            self._write_to_stdout(section, colored_msg)
351

    
352
        plain_msg = _format_message(msg, *args)
353
        self._write_to_file(section, plain_msg)
354

    
355
    def warning(self, section, msg, *args):
356
        """Warning messages"""
357
        assert section, "Section can not be empty"
358

    
359
        msg = "  (WW) " + _list_to_string(msg, "       ")
360

    
361
        colored_msg = self._color_message(_yellow, msg, *args)
362
        self._write_to_stderr(section, colored_msg)
363

    
364
        plain_msg = _format_message(msg, *args)
365
        self._write_to_file(section, plain_msg)
366

    
367
    def error(self, section, msg, *args):
368
        """Error messages"""
369
        assert section, "Section can not be empty"
370

    
371
        msg = "  (EE) " + _list_to_string(msg, "       ")
372

    
373
        colored_msg = self._color_message(_red, msg, *args)
374
        self._write_to_stderr(section, colored_msg)
375

    
376
        plain_msg = _format_message(msg, *args)
377
        self._write_to_file(section, plain_msg)
378

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

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

    
397
    def _write_to_file(self, section, msg):
398
        """Write to file"""
399
        if self.log_level > 1:
400
            return
401
        _write_log_file(self.file_location, section, msg)
402

    
403
    # ----------------------------------
404
    # Handle testsuites
405
    def testsuite_start(self, testsuite):
406
        """Start a new testsuite
407

408
        Add a new section in the logging file
409

410
        """
411
        assert testsuite, "Testsuite name can not be emtpy"
412

    
413
        # Add a new section in the logging file
414
        test_runned = "  * " + testsuite + "\n"
415
        self._write_to_file(SECTION_RUNNED, test_runned)
416

    
417
        new_section_entry = \
418
            SECTION_SEPARATOR + "\n" + SECTION_PREFIX + testsuite + "\n\n\n\n"
419
        self._write_to_file(SECTION_NEW, new_section_entry)
420

    
421
        # Add new section to the stdout
422
        msg = "Starting testsuite %s" % testsuite
423
        colored_msg = self._color_message(_magenta, msg)
424
        self._write_to_stdout(None, colored_msg)
425

    
426
    def testsuite_success(self, testsuite):
427
        """A testsuite has successfully finished
428

429
        Update Results
430

431
        """
432
        assert testsuite, "Testsuite name can not be emtpy"
433

    
434
        # Add our testsuite to Results
435
        self._write_to_file(SECTION_PASSED, testsuite)
436

    
437
        # Add success to stdout
438
        msg = "Testsuite %s passed" % testsuite
439
        colored_msg = self._color_message(_green, msg)
440
        self._write_to_stdout(None, colored_msg)
441

    
442
    def testsuite_failure(self, testsuite):
443
        """A testsuite has failed
444

445
        Update Results
446

447
        """
448
        assert testsuite, "Testsuite name can not be emtpy"
449

    
450
        # Add our testsuite to Results
451
        self._write_to_file(SECTION_FAILED, testsuite)
452

    
453
        # Add success to stdout
454
        msg = "Testsuite %s failed" % testsuite
455
        colored_msg = self._color_message(_red, msg)
456
        self._write_to_stdout(None, colored_msg)
457

    
458
    # ----------------------------------
459
    # Colors
460
    def _color_message(self, color_fun, msg, *args):
461
        """Color a message before printing it
462

463
        The color_fun parameter is used when we want the whole message to be
464
        colored.
465

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