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