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             The output as a string.
 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         return output
 165
 166 class SectionCtxMgr(object):
 167     """A context manager for Python's "with" statement, which allows a certain
 168     portion of test code to be logged to a separate section of the log file.
 169     Objects of this type should be created by factory functions in the Logfile
 170     class rather than directly."""
 171
 172     def __init__(self, log, marker, anchor):
 173         """Initialize a new object.
 174
 175         Args:
 176             log: The Logfile object to log to.
 177             marker: The name of the nested log section.
 178             anchor: The anchor value to pass to start_section().
 179
 180         Returns:
 181             Nothing.
 182         """
 183
 184         self.log = log
 185         self.marker = marker
 186         self.anchor = anchor
 187
 188     def __enter__(self):
 189         self.anchor = self.log.start_section(self.marker, self.anchor)
 190
 191     def __exit__(self, extype, value, traceback):
 192         self.log.end_section(self.marker)
 193
 194 class Logfile(object):
 195     """Generates an HTML-formatted log file containing multiple streams of
 196     data, each represented in a well-delineated/-structured fashion."""
 197
 198     def __init__(self, fn):
 199         """Initialize a new object.
 200
 201         Args:
 202             fn: The filename to write to.
 203
 204         Returns:
 205             Nothing.
 206         """
 207
 208         self.f = open(fn, 'wt')
 209         self.last_stream = None
 210         self.blocks = []
 211         self.cur_evt = 1
 212         self.anchor = 0
 213
 214         shutil.copy(mod_dir + '/multiplexed_log.css', os.path.dirname(fn))
 215         self.f.write('''\
 216 <html>
 217 <head>
 218 <link rel="stylesheet" type="text/css" href="multiplexed_log.css">
 219 <script src="http://code.jquery.com/jquery.min.js"></script>
 220 <script>
 221 $(document).ready(function () {
 222     // Copy status report HTML to start of log for easy access
 223     sts = $(".block#status_report")[0].outerHTML;
 224     $("tt").prepend(sts);
 225
 226     // Add expand/contract buttons to all block headers
 227     btns = "<span class=\\\"block-expand hidden\\\">[+] </span>" +
 228         "<span class=\\\"block-contract\\\">[-] </span>";
 229     $(".block-header").prepend(btns);
 230
 231     // Pre-contract all blocks which passed, leaving only problem cases
 232     // expanded, to highlight issues the user should look at.
 233     // Only top-level blocks (sections) should have any status
 234     passed_bcs = $(".block-content:has(.status-pass)");
 235     // Some blocks might have multiple status entries (e.g. the status
 236     // report), so take care not to hide blocks with partial success.
 237     passed_bcs = passed_bcs.not(":has(.status-fail)");
 238     passed_bcs = passed_bcs.not(":has(.status-xfail)");
 239     passed_bcs = passed_bcs.not(":has(.status-xpass)");
 240     passed_bcs = passed_bcs.not(":has(.status-skipped)");
 241     // Hide the passed blocks
 242     passed_bcs.addClass("hidden");
 243     // Flip the expand/contract button hiding for those blocks.
 244     bhs = passed_bcs.parent().children(".block-header")
 245     bhs.children(".block-expand").removeClass("hidden");
 246     bhs.children(".block-contract").addClass("hidden");
 247
 248     // Add click handler to block headers.
 249     // The handler expands/contracts the block.
 250     $(".block-header").on("click", function (e) {
 251         var header = $(this);
 252         var content = header.next(".block-content");
 253         var expanded = !content.hasClass("hidden");
 254         if (expanded) {
 255             content.addClass("hidden");
 256             header.children(".block-expand").first().removeClass("hidden");
 257             header.children(".block-contract").first().addClass("hidden");
 258         } else {
 259             header.children(".block-contract").first().removeClass("hidden");
 260             header.children(".block-expand").first().addClass("hidden");
 261             content.removeClass("hidden");
 262         }
 263     });
 264
 265     // When clicking on a link, expand the target block
 266     $("a").on("click", function (e) {
 267         var block = $($(this).attr("href"));
 268         var header = block.children(".block-header");
 269         var content = block.children(".block-content").first();
 270         header.children(".block-contract").first().removeClass("hidden");
 271         header.children(".block-expand").first().addClass("hidden");
 272         content.removeClass("hidden");
 273     });
 274 });
 275 </script>
 276 </head>
 277 <body>
 278 <tt>
 279 ''')
 280
 281     def close(self):
 282         """Close the log file.
 283
 284         After calling this function, no more data may be written to the log.
 285
 286         Args:
 287             None.
 288
 289         Returns:
 290             Nothing.
 291         """
 292
 293         self.f.write('''\
 294 </tt>
 295 </body>
 296 </html>
 297 ''')
 298         self.f.close()
 299
 300     # The set of characters that should be represented as hexadecimal codes in
 301     # the log file.
 302     _nonprint = ('%' + ''.join(chr(c) for c in range(0, 32) if c not in (9, 10)) +
 303                  ''.join(chr(c) for c in range(127, 256)))
 304
 305     def _escape(self, data):
 306         """Render data format suitable for inclusion in an HTML document.
 307
 308         This includes HTML-escaping certain characters, and translating
 309         control characters to a hexadecimal representation.
 310
 311         Args:
 312             data: The raw string data to be escaped.
 313
 314         Returns:
 315             An escaped version of the data.
 316         """
 317
 318         data = data.replace(chr(13), '')
 319         data = ''.join((c in self._nonprint) and ('%%%02x' % ord(c)) or
 320                        c for c in data)
 321         data = cgi.escape(data)
 322         return data
 323
 324     def _terminate_stream(self):
 325         """Write HTML to the log file to terminate the current stream's data.
 326
 327         Args:
 328             None.
 329
 330         Returns:
 331             Nothing.
 332         """
 333
 334         self.cur_evt += 1
 335         if not self.last_stream:
 336             return
 337         self.f.write('</pre>\n')
 338         self.f.write('<div class="stream-trailer block-trailer">End stream: ' +
 339                      self.last_stream.name + '</div>\n')
 340         self.f.write('</div>\n')
 341         self.f.write('</div>\n')
 342         self.last_stream = None
 343
 344     def _note(self, note_type, msg, anchor=None):
 345         """Write a note or one-off message to the log file.
 346
 347         Args:
 348             note_type: The type of note. This must be a value supported by the
 349                 accompanying multiplexed_log.css.
 350             msg: The note/message to log.
 351             anchor: Optional internal link target.
 352
 353         Returns:
 354             Nothing.
 355         """
 356
 357         self._terminate_stream()
 358         self.f.write('<div class="' + note_type + '">\n')
 359         if anchor:
 360             self.f.write('<a href="#%s">\n' % anchor)
 361         self.f.write('<pre>')
 362         self.f.write(self._escape(msg))
 363         self.f.write('\n</pre>\n')
 364         if anchor:
 365             self.f.write('</a>\n')
 366         self.f.write('</div>\n')
 367
 368     def start_section(self, marker, anchor=None):
 369         """Begin a new nested section in the log file.
 370
 371         Args:
 372             marker: The name of the section that is starting.
 373             anchor: The value to use for the anchor. If None, a unique value
 374               will be calculated and used
 375
 376         Returns:
 377             Name of the HTML anchor emitted before section.
 378         """
 379
 380         self._terminate_stream()
 381         self.blocks.append(marker)
 382         if not anchor:
 383             self.anchor += 1
 384             anchor = str(self.anchor)
 385         blk_path = '/'.join(self.blocks)
 386         self.f.write('<div class="section block" id="' + anchor + '">\n')
 387         self.f.write('<div class="section-header block-header">Section: ' +
 388                      blk_path + '</div>\n')
 389         self.f.write('<div class="section-content block-content">\n')
 390
 391         return anchor
 392
 393     def end_section(self, marker):
 394         """Terminate the current nested section in the log file.
 395
 396         This function validates proper nesting of start_section() and
 397         end_section() calls. If a mismatch is found, an exception is raised.
 398
 399         Args:
 400             marker: The name of the section that is ending.
 401
 402         Returns:
 403             Nothing.
 404         """
 405
 406         if (not self.blocks) or (marker != self.blocks[-1]):
 407             raise Exception('Block nesting mismatch: "%s" "%s"' %
 408                             (marker, '/'.join(self.blocks)))
 409         self._terminate_stream()
 410         blk_path = '/'.join(self.blocks)
 411         self.f.write('<div class="section-trailer block-trailer">' +
 412                      'End section: ' + blk_path + '</div>\n')
 413         self.f.write('</div>\n')
 414         self.f.write('</div>\n')
 415         self.blocks.pop()
 416
 417     def section(self, marker, anchor=None):
 418         """Create a temporary section in the log file.
 419
 420         This function creates a context manager for Python's "with" statement,
 421         which allows a certain portion of test code to be logged to a separate
 422         section of the log file.
 423
 424         Usage:
 425             with log.section("somename"):
 426                 some test code
 427
 428         Args:
 429             marker: The name of the nested section.
 430             anchor: The anchor value to pass to start_section().
 431
 432         Returns:
 433             A context manager object.
 434         """
 435
 436         return SectionCtxMgr(self, marker, anchor)
 437
 438     def error(self, msg):
 439         """Write an error note to the log file.
 440
 441         Args:
 442             msg: A message describing the error.
 443
 444         Returns:
 445             Nothing.
 446         """
 447
 448         self._note("error", msg)
 449
 450     def warning(self, msg):
 451         """Write an warning note to the log file.
 452
 453         Args:
 454             msg: A message describing the warning.
 455
 456         Returns:
 457             Nothing.
 458         """
 459
 460         self._note("warning", msg)
 461
 462     def info(self, msg):
 463         """Write an informational note to the log file.
 464
 465         Args:
 466             msg: An informational message.
 467
 468         Returns:
 469             Nothing.
 470         """
 471
 472         self._note("info", msg)
 473
 474     def action(self, msg):
 475         """Write an action note to the log file.
 476
 477         Args:
 478             msg: A message describing the action that is being logged.
 479
 480         Returns:
 481             Nothing.
 482         """
 483
 484         self._note("action", msg)
 485
 486     def status_pass(self, msg, anchor=None):
 487         """Write a note to the log file describing test(s) which passed.
 488
 489         Args:
 490             msg: A message describing the passed test(s).
 491             anchor: Optional internal link target.
 492
 493         Returns:
 494             Nothing.
 495         """
 496
 497         self._note("status-pass", msg, anchor)
 498
 499     def status_skipped(self, msg, anchor=None):
 500         """Write a note to the log file describing skipped test(s).
 501
 502         Args:
 503             msg: A message describing the skipped test(s).
 504             anchor: Optional internal link target.
 505
 506         Returns:
 507             Nothing.
 508         """
 509
 510         self._note("status-skipped", msg, anchor)
 511
 512     def status_xfail(self, msg, anchor=None):
 513         """Write a note to the log file describing xfailed test(s).
 514
 515         Args:
 516             msg: A message describing the xfailed test(s).
 517             anchor: Optional internal link target.
 518
 519         Returns:
 520             Nothing.
 521         """
 522
 523         self._note("status-xfail", msg, anchor)
 524
 525     def status_xpass(self, msg, anchor=None):
 526         """Write a note to the log file describing xpassed test(s).
 527
 528         Args:
 529             msg: A message describing the xpassed test(s).
 530             anchor: Optional internal link target.
 531
 532         Returns:
 533             Nothing.
 534         """
 535
 536         self._note("status-xpass", msg, anchor)
 537
 538     def status_fail(self, msg, anchor=None):
 539         """Write a note to the log file describing failed test(s).
 540
 541         Args:
 542             msg: A message describing the failed test(s).
 543             anchor: Optional internal link target.
 544
 545         Returns:
 546             Nothing.
 547         """
 548
 549         self._note("status-fail", msg, anchor)
 550
 551     def get_stream(self, name, chained_file=None):
 552         """Create an object to log a single stream's data into the log file.
 553
 554         This creates a "file-like" object that can be written to in order to
 555         write a single stream's data to the log file. The implementation will
 556         handle any required interleaving of data (from multiple streams) in
 557         the log, in a way that makes it obvious which stream each bit of data
 558         came from.
 559
 560         Args:
 561             name: The name of the stream.
 562             chained_file: The file-like object to which all stream data should
 563                 be logged to in addition to this log. Can be None.
 564
 565         Returns:
 566             A file-like object.
 567         """
 568
 569         return LogfileStream(self, name, chained_file)
 570
 571     def get_runner(self, name, chained_file=None):
 572         """Create an object that executes processes and logs their output.
 573
 574         Args:
 575             name: The name of this sub-process.
 576             chained_file: The file-like object to which all stream data should
 577                 be logged to in addition to logfile. Can be None.
 578
 579         Returns:
 580             A RunAndLog object.
 581         """
 582
 583         return RunAndLog(self, name, chained_file)
 584
 585     def write(self, stream, data, implicit=False):
 586         """Write stream data into the log file.
 587
 588         This function should only be used by instances of LogfileStream or
 589         RunAndLog.
 590
 591         Args:
 592             stream: The stream whose data is being logged.
 593             data: The data to log.
 594             implicit: Boolean indicating whether data actually appeared in the
 595                 stream, or was implicitly generated. A valid use-case is to
 596                 repeat a shell prompt at the start of each separate log
 597                 section, which makes the log sections more readable in
 598                 isolation.
 599
 600         Returns:
 601             Nothing.
 602         """
 603
 604         if stream != self.last_stream:
 605             self._terminate_stream()
 606             self.f.write('<div class="stream block">\n')
 607             self.f.write('<div class="stream-header block-header">Stream: ' +
 608                          stream.name + '</div>\n')
 609             self.f.write('<div class="stream-content block-content">\n')
 610             self.f.write('<pre>')
 611         if implicit:
 612             self.f.write('<span class="implicit">')
 613         self.f.write(self._escape(data))
 614         if implicit:
 615             self.f.write('</span>')
 616         self.last_stream = stream
 617
 618     def flush(self):
 619         """Flush the log stream, to ensure correct log interleaving.
 620
 621         Args:
 622             None.
 623
 624         Returns:
 625             Nothing.
 626         """
 627
 628         self.f.flush()