test/py/multiplexed_log.py

   1 # Copyright (c) 2015 Stephen Warren
   2 # Copyright (c) 2015-2016, NVIDIA CORPORATION. All rights reserved.
   3 #
   4 # SPDX-License-Identifier: GPL-2.0
   5
   6 # Generate an HTML-formatted log file containing multiple streams of data,
   7 # each represented in a well-delineated/-structured fashion.
   8
   9 import cgi
  10 import os.path
  11 import shutil
  12 import subprocess
  13
  14 mod_dir = os.path.dirname(os.path.abspath(__file__))
  15
  16 class LogfileStream(object):
  17     """A file-like object used to write a single logical stream of data into
  18     a multiplexed log file. Objects of this type should be created by factory
  19     functions in the Logfile class rather than directly."""
  20
  21     def __init__(self, logfile, name, chained_file):
  22         """Initialize a new object.
  23
  24         Args:
  25             logfile: The Logfile object to log to.
  26             name: The name of this log stream.
  27             chained_file: The file-like object to which all stream data should be
  28             logged to in addition to logfile. Can be None.
  29
  30         Returns:
  31             Nothing.
  32         """
  33
  34         self.logfile = logfile
  35         self.name = name
  36         self.chained_file = chained_file
  37
  38     def close(self):
  39         """Dummy function so that this class is "file-like".
  40
  41         Args:
  42             None.
  43
  44         Returns:
  45             Nothing.
  46         """
  47
  48         pass
  49
  50     def write(self, data, implicit=False):
  51         """Write data to the log stream.
  52
  53         Args:
  54             data: The data to write tot he file.
  55             implicit: Boolean indicating whether data actually appeared in the
  56                 stream, or was implicitly generated. A valid use-case is to
  57                 repeat a shell prompt at the start of each separate log
  58                 section, which makes the log sections more readable in
  59                 isolation.
  60
  61         Returns:
  62             Nothing.
  63         """
  64
  65         self.logfile.write(self, data, implicit)
  66         if self.chained_file:
  67             self.chained_file.write(data)
  68
  69     def flush(self):
  70         """Flush the log stream, to ensure correct log interleaving.
  71
  72         Args:
  73             None.
  74
  75         Returns:
  76             Nothing.
  77         """
  78
  79         self.logfile.flush()
  80         if self.chained_file:
  81             self.chained_file.flush()
  82
  83 class RunAndLog(object):
  84     """A utility object used to execute sub-processes and log their output to
  85     a multiplexed log file. Objects of this type should be created by factory
  86     functions in the Logfile class rather than directly."""
  87
  88     def __init__(self, logfile, name, chained_file):
  89         """Initialize a new object.
  90
  91         Args:
  92             logfile: The Logfile object to log to.
  93             name: The name of this log stream or sub-process.
  94             chained_file: The file-like object to which all stream data should
  95                 be logged to in addition to logfile. Can be None.
  96
  97         Returns:
  98             Nothing.
  99         """
 100
 101         self.logfile = logfile
 102         self.name = name
 103         self.chained_file = chained_file
 104
 105     def close(self):
 106         """Clean up any resources managed by this object."""
 107         pass
 108
 109     def run(self, cmd, cwd=None, ignore_errors=False):
 110         """Run a command as a sub-process, and log the results.
 111
 112         Args:
 113             cmd: The command to execute.
 114             cwd: The directory to run the command in. Can be None to use the
 115                 current directory.
 116             ignore_errors: Indicate whether to ignore errors. If True, the
 117                 function will simply return if the command cannot be executed
 118                 or exits with an error code, otherwise an exception will be
 119                 raised if such problems occur.
 120
 121         Returns:
 122             Nothing.
 123         """
 124
 125         msg = '+' + ' '.join(cmd) + '\n'
 126         if self.chained_file:
 127             self.chained_file.write(msg)
 128         self.logfile.write(self, msg)
 129
 130         try:
 131             p = subprocess.Popen(cmd, cwd=cwd,
 132                 stdin=None, stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
 133             (stdout, stderr) = p.communicate()
 134             output = ''
 135             if stdout:
 136                 if stderr:
 137                     output += 'stdout:\n'
 138                 output += stdout
 139             if stderr:
 140                 if stdout:
 141                     output += 'stderr:\n'
 142                 output += stderr
 143             exit_status = p.returncode
 144             exception = None
 145         except subprocess.CalledProcessError as cpe:
 146             output = cpe.output
 147             exit_status = cpe.returncode
 148             exception = cpe
 149         except Exception as e:
 150             output = ''
 151             exit_status = 0
 152             exception = e
 153         if output and not output.endswith('\n'):
 154             output += '\n'
 155         if exit_status and not exception and not ignore_errors:
 156             exception = Exception('Exit code: ' + str(exit_status))
 157         if exception:
 158             output += str(exception) + '\n'
 159         self.logfile.write(self, output)
 160         if self.chained_file:
 161             self.chained_file.write(output)
 162         if exception:
 163             raise exception
 164
 165 class SectionCtxMgr(object):
 166     """A context manager for Python's "with" statement, which allows a certain
 167     portion of test code to be logged to a separate section of the log file.
 168     Objects of this type should be created by factory functions in the Logfile
 169     class rather than directly."""
 170
 171     def __init__(self, log, marker):
 172         """Initialize a new object.
 173
 174         Args:
 175             log: The Logfile object to log to.
 176             marker: The name of the nested log section.
 177
 178         Returns:
 179             Nothing.
 180         """
 181
 182         self.log = log
 183         self.marker = marker
 184
 185     def __enter__(self):
 186         self.log.start_section(self.marker)
 187
 188     def __exit__(self, extype, value, traceback):
 189         self.log.end_section(self.marker)
 190
 191 class Logfile(object):
 192     """Generates an HTML-formatted log file containing multiple streams of
 193     data, each represented in a well-delineated/-structured fashion."""
 194
 195     def __init__(self, fn):
 196         """Initialize a new object.
 197
 198         Args:
 199             fn: The filename to write to.
 200
 201         Returns:
 202             Nothing.
 203         """
 204
 205         self.f = open(fn, 'wt')
 206         self.last_stream = None
 207         self.blocks = []
 208         self.cur_evt = 1
 209         shutil.copy(mod_dir + '/multiplexed_log.css', os.path.dirname(fn))
 210         self.f.write('''\
 211 <html>
 212 <head>
 213 <link rel="stylesheet" type="text/css" href="multiplexed_log.css">
 214 </head>
 215 <body>
 216 <tt>
 217 ''')
 218
 219     def close(self):
 220         """Close the log file.
 221
 222         After calling this function, no more data may be written to the log.
 223
 224         Args:
 225             None.
 226
 227         Returns:
 228             Nothing.
 229         """
 230
 231         self.f.write('''\
 232 </tt>
 233 </body>
 234 </html>
 235 ''')
 236         self.f.close()
 237
 238     # The set of characters that should be represented as hexadecimal codes in
 239     # the log file.
 240     _nonprint = ('%' + ''.join(chr(c) for c in range(0, 32) if c not in (9, 10)) +
 241                  ''.join(chr(c) for c in range(127, 256)))
 242
 243     def _escape(self, data):
 244         """Render data format suitable for inclusion in an HTML document.
 245
 246         This includes HTML-escaping certain characters, and translating
 247         control characters to a hexadecimal representation.
 248
 249         Args:
 250             data: The raw string data to be escaped.
 251
 252         Returns:
 253             An escaped version of the data.
 254         """
 255
 256         data = data.replace(chr(13), '')
 257         data = ''.join((c in self._nonprint) and ('%%%02x' % ord(c)) or
 258                        c for c in data)
 259         data = cgi.escape(data)
 260         return data
 261
 262     def _terminate_stream(self):
 263         """Write HTML to the log file to terminate the current stream's data.
 264
 265         Args:
 266             None.
 267
 268         Returns:
 269             Nothing.
 270         """
 271
 272         self.cur_evt += 1
 273         if not self.last_stream:
 274             return
 275         self.f.write('</pre>\n')
 276         self.f.write('<div class="stream-trailer" id="' +
 277                      self.last_stream.name + '">End stream: ' +
 278                      self.last_stream.name + '</div>\n')
 279         self.f.write('</div>\n')
 280         self.last_stream = None
 281
 282     def _note(self, note_type, msg):
 283         """Write a note or one-off message to the log file.
 284
 285         Args:
 286             note_type: The type of note. This must be a value supported by the
 287                 accompanying multiplexed_log.css.
 288             msg: The note/message to log.
 289
 290         Returns:
 291             Nothing.
 292         """
 293
 294         self._terminate_stream()
 295         self.f.write('<div class="' + note_type + '">\n<pre>')
 296         self.f.write(self._escape(msg))
 297         self.f.write('\n</pre></div>\n')
 298
 299     def start_section(self, marker):
 300         """Begin a new nested section in the log file.
 301
 302         Args:
 303             marker: The name of the section that is starting.
 304
 305         Returns:
 306             Nothing.
 307         """
 308
 309         self._terminate_stream()
 310         self.blocks.append(marker)
 311         blk_path = '/'.join(self.blocks)
 312         self.f.write('<div class="section" id="' + blk_path + '">\n')
 313         self.f.write('<div class="section-header" id="' + blk_path +
 314                      '">Section: ' + blk_path + '</div>\n')
 315
 316     def end_section(self, marker):
 317         """Terminate the current nested section in the log file.
 318
 319         This function validates proper nesting of start_section() and
 320         end_section() calls. If a mismatch is found, an exception is raised.
 321
 322         Args:
 323             marker: The name of the section that is ending.
 324
 325         Returns:
 326             Nothing.
 327         """
 328
 329         if (not self.blocks) or (marker != self.blocks[-1]):
 330             raise Exception('Block nesting mismatch: "%s" "%s"' %
 331                             (marker, '/'.join(self.blocks)))
 332         self._terminate_stream()
 333         blk_path = '/'.join(self.blocks)
 334         self.f.write('<div class="section-trailer" id="section-trailer-' +
 335                      blk_path + '">End section: ' + blk_path + '</div>\n')
 336         self.f.write('</div>\n')
 337         self.blocks.pop()
 338
 339     def section(self, marker):
 340         """Create a temporary section in the log file.
 341
 342         This function creates a context manager for Python's "with" statement,
 343         which allows a certain portion of test code to be logged to a separate
 344         section of the log file.
 345
 346         Usage:
 347             with log.section("somename"):
 348                 some test code
 349
 350         Args:
 351             marker: The name of the nested section.
 352
 353         Returns:
 354             A context manager object.
 355         """
 356
 357         return SectionCtxMgr(self, marker)
 358
 359     def error(self, msg):
 360         """Write an error note to the log file.
 361
 362         Args:
 363             msg: A message describing the error.
 364
 365         Returns:
 366             Nothing.
 367         """
 368
 369         self._note("error", msg)
 370
 371     def warning(self, msg):
 372         """Write an warning note to the log file.
 373
 374         Args:
 375             msg: A message describing the warning.
 376
 377         Returns:
 378             Nothing.
 379         """
 380
 381         self._note("warning", msg)
 382
 383     def info(self, msg):
 384         """Write an informational note to the log file.
 385
 386         Args:
 387             msg: An informational message.
 388
 389         Returns:
 390             Nothing.
 391         """
 392
 393         self._note("info", msg)
 394
 395     def action(self, msg):
 396         """Write an action note to the log file.
 397
 398         Args:
 399             msg: A message describing the action that is being logged.
 400
 401         Returns:
 402             Nothing.
 403         """
 404
 405         self._note("action", msg)
 406
 407     def status_pass(self, msg):
 408         """Write a note to the log file describing test(s) which passed.
 409
 410         Args:
 411             msg: A message describing the passed test(s).
 412
 413         Returns:
 414             Nothing.
 415         """
 416
 417         self._note("status-pass", msg)
 418
 419     def status_skipped(self, msg):
 420         """Write a note to the log file describing skipped test(s).
 421
 422         Args:
 423             msg: A message describing the skipped test(s).
 424
 425         Returns:
 426             Nothing.
 427         """
 428
 429         self._note("status-skipped", msg)
 430
 431     def status_xfail(self, msg):
 432         """Write a note to the log file describing xfailed test(s).
 433
 434         Args:
 435             msg: A message describing the xfailed test(s).
 436
 437         Returns:
 438             Nothing.
 439         """
 440
 441         self._note("status-xfail", msg)
 442
 443     def status_xpass(self, msg):
 444         """Write a note to the log file describing xpassed test(s).
 445
 446         Args:
 447             msg: A message describing the xpassed test(s).
 448
 449         Returns:
 450             Nothing.
 451         """
 452
 453         self._note("status-xpass", msg)
 454
 455     def status_fail(self, msg):
 456         """Write a note to the log file describing failed test(s).
 457
 458         Args:
 459             msg: A message describing the failed test(s).
 460
 461         Returns:
 462             Nothing.
 463         """
 464
 465         self._note("status-fail", msg)
 466
 467     def get_stream(self, name, chained_file=None):
 468         """Create an object to log a single stream's data into the log file.
 469
 470         This creates a "file-like" object that can be written to in order to
 471         write a single stream's data to the log file. The implementation will
 472         handle any required interleaving of data (from multiple streams) in
 473         the log, in a way that makes it obvious which stream each bit of data
 474         came from.
 475
 476         Args:
 477             name: The name of the stream.
 478             chained_file: The file-like object to which all stream data should
 479                 be logged to in addition to this log. Can be None.
 480
 481         Returns:
 482             A file-like object.
 483         """
 484
 485         return LogfileStream(self, name, chained_file)
 486
 487     def get_runner(self, name, chained_file=None):
 488         """Create an object that executes processes and logs their output.
 489
 490         Args:
 491             name: The name of this sub-process.
 492             chained_file: The file-like object to which all stream data should
 493                 be logged to in addition to logfile. Can be None.
 494
 495         Returns:
 496             A RunAndLog object.
 497         """
 498
 499         return RunAndLog(self, name, chained_file)
 500
 501     def write(self, stream, data, implicit=False):
 502         """Write stream data into the log file.
 503
 504         This function should only be used by instances of LogfileStream or
 505         RunAndLog.
 506
 507         Args:
 508             stream: The stream whose data is being logged.
 509             data: The data to log.
 510             implicit: Boolean indicating whether data actually appeared in the
 511                 stream, or was implicitly generated. A valid use-case is to
 512                 repeat a shell prompt at the start of each separate log
 513                 section, which makes the log sections more readable in
 514                 isolation.
 515
 516         Returns:
 517             Nothing.
 518         """
 519
 520         if stream != self.last_stream:
 521             self._terminate_stream()
 522             self.f.write('<div class="stream" id="%s">\n' % stream.name)
 523             self.f.write('<div class="stream-header" id="' + stream.name +
 524                          '">Stream: ' + stream.name + '</div>\n')
 525             self.f.write('<pre>')
 526         if implicit:
 527             self.f.write('<span class="implicit">')
 528         self.f.write(self._escape(data))
 529         if implicit:
 530             self.f.write('</span>')
 531         self.last_stream = stream
 532
 533     def flush(self):
 534         """Flush the log stream, to ensure correct log interleaving.
 535
 536         Args:
 537             None.
 538
 539         Returns:
 540             Nothing.
 541         """
 542
 543         self.f.flush()