• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1# SPDX-License-Identifier: GPL-2.0
2# Copyright (c) 2015 Stephen Warren
3# Copyright (c) 2015-2016, NVIDIA CORPORATION. All rights reserved.
4
5# Generate an HTML-formatted log file containing multiple streams of data,
6# each represented in a well-delineated/-structured fashion.
7
8import cgi
9import datetime
10import os.path
11import shutil
12import subprocess
13
14mod_dir = os.path.dirname(os.path.abspath(__file__))
15
16class 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
83class 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        self.output = None
105        self.exit_status = None
106
107    def close(self):
108        """Clean up any resources managed by this object."""
109        pass
110
111    def run(self, cmd, cwd=None, ignore_errors=False):
112        """Run a command as a sub-process, and log the results.
113
114        The output is available at self.output which can be useful if there is
115        an exception.
116
117        Args:
118            cmd: The command to execute.
119            cwd: The directory to run the command in. Can be None to use the
120                current directory.
121            ignore_errors: Indicate whether to ignore errors. If True, the
122                function will simply return if the command cannot be executed
123                or exits with an error code, otherwise an exception will be
124                raised if such problems occur.
125
126        Returns:
127            The output as a string.
128        """
129
130        msg = '+' + ' '.join(cmd) + '\n'
131        if self.chained_file:
132            self.chained_file.write(msg)
133        self.logfile.write(self, msg)
134
135        try:
136            p = subprocess.Popen(cmd, cwd=cwd,
137                stdin=None, stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
138            (stdout, stderr) = p.communicate()
139            output = ''
140            if stdout:
141                if stderr:
142                    output += 'stdout:\n'
143                output += stdout
144            if stderr:
145                if stdout:
146                    output += 'stderr:\n'
147                output += stderr
148            exit_status = p.returncode
149            exception = None
150        except subprocess.CalledProcessError as cpe:
151            output = cpe.output
152            exit_status = cpe.returncode
153            exception = cpe
154        except Exception as e:
155            output = ''
156            exit_status = 0
157            exception = e
158        if output and not output.endswith('\n'):
159            output += '\n'
160        if exit_status and not exception and not ignore_errors:
161            exception = Exception('Exit code: ' + str(exit_status))
162        if exception:
163            output += str(exception) + '\n'
164        self.logfile.write(self, output)
165        if self.chained_file:
166            self.chained_file.write(output)
167        self.logfile.timestamp()
168
169        # Store the output so it can be accessed if we raise an exception.
170        self.output = output
171        self.exit_status = exit_status
172        if exception:
173            raise exception
174        return output
175
176class SectionCtxMgr(object):
177    """A context manager for Python's "with" statement, which allows a certain
178    portion of test code to be logged to a separate section of the log file.
179    Objects of this type should be created by factory functions in the Logfile
180    class rather than directly."""
181
182    def __init__(self, log, marker, anchor):
183        """Initialize a new object.
184
185        Args:
186            log: The Logfile object to log to.
187            marker: The name of the nested log section.
188            anchor: The anchor value to pass to start_section().
189
190        Returns:
191            Nothing.
192        """
193
194        self.log = log
195        self.marker = marker
196        self.anchor = anchor
197
198    def __enter__(self):
199        self.anchor = self.log.start_section(self.marker, self.anchor)
200
201    def __exit__(self, extype, value, traceback):
202        self.log.end_section(self.marker)
203
204class Logfile(object):
205    """Generates an HTML-formatted log file containing multiple streams of
206    data, each represented in a well-delineated/-structured fashion."""
207
208    def __init__(self, fn):
209        """Initialize a new object.
210
211        Args:
212            fn: The filename to write to.
213
214        Returns:
215            Nothing.
216        """
217
218        self.f = open(fn, 'wt')
219        self.last_stream = None
220        self.blocks = []
221        self.cur_evt = 1
222        self.anchor = 0
223        self.timestamp_start = self._get_time()
224        self.timestamp_prev = self.timestamp_start
225        self.timestamp_blocks = []
226        self.seen_warning = False
227
228        shutil.copy(mod_dir + '/multiplexed_log.css', os.path.dirname(fn))
229        self.f.write('''\
230<html>
231<head>
232<link rel="stylesheet" type="text/css" href="multiplexed_log.css">
233<script src="http://code.jquery.com/jquery.min.js"></script>
234<script>
235$(document).ready(function () {
236    // Copy status report HTML to start of log for easy access
237    sts = $(".block#status_report")[0].outerHTML;
238    $("tt").prepend(sts);
239
240    // Add expand/contract buttons to all block headers
241    btns = "<span class=\\\"block-expand hidden\\\">[+] </span>" +
242        "<span class=\\\"block-contract\\\">[-] </span>";
243    $(".block-header").prepend(btns);
244
245    // Pre-contract all blocks which passed, leaving only problem cases
246    // expanded, to highlight issues the user should look at.
247    // Only top-level blocks (sections) should have any status
248    passed_bcs = $(".block-content:has(.status-pass)");
249    // Some blocks might have multiple status entries (e.g. the status
250    // report), so take care not to hide blocks with partial success.
251    passed_bcs = passed_bcs.not(":has(.status-fail)");
252    passed_bcs = passed_bcs.not(":has(.status-xfail)");
253    passed_bcs = passed_bcs.not(":has(.status-xpass)");
254    passed_bcs = passed_bcs.not(":has(.status-skipped)");
255    passed_bcs = passed_bcs.not(":has(.status-warning)");
256    // Hide the passed blocks
257    passed_bcs.addClass("hidden");
258    // Flip the expand/contract button hiding for those blocks.
259    bhs = passed_bcs.parent().children(".block-header")
260    bhs.children(".block-expand").removeClass("hidden");
261    bhs.children(".block-contract").addClass("hidden");
262
263    // Add click handler to block headers.
264    // The handler expands/contracts the block.
265    $(".block-header").on("click", function (e) {
266        var header = $(this);
267        var content = header.next(".block-content");
268        var expanded = !content.hasClass("hidden");
269        if (expanded) {
270            content.addClass("hidden");
271            header.children(".block-expand").first().removeClass("hidden");
272            header.children(".block-contract").first().addClass("hidden");
273        } else {
274            header.children(".block-contract").first().removeClass("hidden");
275            header.children(".block-expand").first().addClass("hidden");
276            content.removeClass("hidden");
277        }
278    });
279
280    // When clicking on a link, expand the target block
281    $("a").on("click", function (e) {
282        var block = $($(this).attr("href"));
283        var header = block.children(".block-header");
284        var content = block.children(".block-content").first();
285        header.children(".block-contract").first().removeClass("hidden");
286        header.children(".block-expand").first().addClass("hidden");
287        content.removeClass("hidden");
288    });
289});
290</script>
291</head>
292<body>
293<tt>
294''')
295
296    def close(self):
297        """Close the log file.
298
299        After calling this function, no more data may be written to the log.
300
301        Args:
302            None.
303
304        Returns:
305            Nothing.
306        """
307
308        self.f.write('''\
309</tt>
310</body>
311</html>
312''')
313        self.f.close()
314
315    # The set of characters that should be represented as hexadecimal codes in
316    # the log file.
317    _nonprint = ('%' + ''.join(chr(c) for c in range(0, 32) if c not in (9, 10)) +
318                 ''.join(chr(c) for c in range(127, 256)))
319
320    def _escape(self, data):
321        """Render data format suitable for inclusion in an HTML document.
322
323        This includes HTML-escaping certain characters, and translating
324        control characters to a hexadecimal representation.
325
326        Args:
327            data: The raw string data to be escaped.
328
329        Returns:
330            An escaped version of the data.
331        """
332
333        data = data.replace(chr(13), '')
334        data = ''.join((c in self._nonprint) and ('%%%02x' % ord(c)) or
335                       c for c in data)
336        data = cgi.escape(data)
337        return data
338
339    def _terminate_stream(self):
340        """Write HTML to the log file to terminate the current stream's data.
341
342        Args:
343            None.
344
345        Returns:
346            Nothing.
347        """
348
349        self.cur_evt += 1
350        if not self.last_stream:
351            return
352        self.f.write('</pre>\n')
353        self.f.write('<div class="stream-trailer block-trailer">End stream: ' +
354                     self.last_stream.name + '</div>\n')
355        self.f.write('</div>\n')
356        self.f.write('</div>\n')
357        self.last_stream = None
358
359    def _note(self, note_type, msg, anchor=None):
360        """Write a note or one-off message to the log file.
361
362        Args:
363            note_type: The type of note. This must be a value supported by the
364                accompanying multiplexed_log.css.
365            msg: The note/message to log.
366            anchor: Optional internal link target.
367
368        Returns:
369            Nothing.
370        """
371
372        self._terminate_stream()
373        self.f.write('<div class="' + note_type + '">\n')
374        self.f.write('<pre>')
375        if anchor:
376            self.f.write('<a href="#%s">' % anchor)
377        self.f.write(self._escape(msg))
378        if anchor:
379            self.f.write('</a>')
380        self.f.write('\n</pre>\n')
381        self.f.write('</div>\n')
382
383    def start_section(self, marker, anchor=None):
384        """Begin a new nested section in the log file.
385
386        Args:
387            marker: The name of the section that is starting.
388            anchor: The value to use for the anchor. If None, a unique value
389              will be calculated and used
390
391        Returns:
392            Name of the HTML anchor emitted before section.
393        """
394
395        self._terminate_stream()
396        self.blocks.append(marker)
397        self.timestamp_blocks.append(self._get_time())
398        if not anchor:
399            self.anchor += 1
400            anchor = str(self.anchor)
401        blk_path = '/'.join(self.blocks)
402        self.f.write('<div class="section block" id="' + anchor + '">\n')
403        self.f.write('<div class="section-header block-header">Section: ' +
404                     blk_path + '</div>\n')
405        self.f.write('<div class="section-content block-content">\n')
406        self.timestamp()
407
408        return anchor
409
410    def end_section(self, marker):
411        """Terminate the current nested section in the log file.
412
413        This function validates proper nesting of start_section() and
414        end_section() calls. If a mismatch is found, an exception is raised.
415
416        Args:
417            marker: The name of the section that is ending.
418
419        Returns:
420            Nothing.
421        """
422
423        if (not self.blocks) or (marker != self.blocks[-1]):
424            raise Exception('Block nesting mismatch: "%s" "%s"' %
425                            (marker, '/'.join(self.blocks)))
426        self._terminate_stream()
427        timestamp_now = self._get_time()
428        timestamp_section_start = self.timestamp_blocks.pop()
429        delta_section = timestamp_now - timestamp_section_start
430        self._note("timestamp",
431            "TIME: SINCE-SECTION: " + str(delta_section))
432        blk_path = '/'.join(self.blocks)
433        self.f.write('<div class="section-trailer block-trailer">' +
434                     'End section: ' + blk_path + '</div>\n')
435        self.f.write('</div>\n')
436        self.f.write('</div>\n')
437        self.blocks.pop()
438
439    def section(self, marker, anchor=None):
440        """Create a temporary section in the log file.
441
442        This function creates a context manager for Python's "with" statement,
443        which allows a certain portion of test code to be logged to a separate
444        section of the log file.
445
446        Usage:
447            with log.section("somename"):
448                some test code
449
450        Args:
451            marker: The name of the nested section.
452            anchor: The anchor value to pass to start_section().
453
454        Returns:
455            A context manager object.
456        """
457
458        return SectionCtxMgr(self, marker, anchor)
459
460    def error(self, msg):
461        """Write an error note to the log file.
462
463        Args:
464            msg: A message describing the error.
465
466        Returns:
467            Nothing.
468        """
469
470        self._note("error", msg)
471
472    def warning(self, msg):
473        """Write an warning note to the log file.
474
475        Args:
476            msg: A message describing the warning.
477
478        Returns:
479            Nothing.
480        """
481
482        self.seen_warning = True
483        self._note("warning", msg)
484
485    def get_and_reset_warning(self):
486        """Get and reset the log warning flag.
487
488        Args:
489            None
490
491        Returns:
492            Whether a warning was seen since the last call.
493        """
494
495        ret = self.seen_warning
496        self.seen_warning = False
497        return ret
498
499    def info(self, msg):
500        """Write an informational note to the log file.
501
502        Args:
503            msg: An informational message.
504
505        Returns:
506            Nothing.
507        """
508
509        self._note("info", msg)
510
511    def action(self, msg):
512        """Write an action note to the log file.
513
514        Args:
515            msg: A message describing the action that is being logged.
516
517        Returns:
518            Nothing.
519        """
520
521        self._note("action", msg)
522
523    def _get_time(self):
524        return datetime.datetime.now()
525
526    def timestamp(self):
527        """Write a timestamp to the log file.
528
529        Args:
530            None
531
532        Returns:
533            Nothing.
534        """
535
536        timestamp_now = self._get_time()
537        delta_prev = timestamp_now - self.timestamp_prev
538        delta_start = timestamp_now - self.timestamp_start
539        self.timestamp_prev = timestamp_now
540
541        self._note("timestamp",
542            "TIME: NOW: " + timestamp_now.strftime("%Y/%m/%d %H:%M:%S.%f"))
543        self._note("timestamp",
544            "TIME: SINCE-PREV: " + str(delta_prev))
545        self._note("timestamp",
546            "TIME: SINCE-START: " + str(delta_start))
547
548    def status_pass(self, msg, anchor=None):
549        """Write a note to the log file describing test(s) which passed.
550
551        Args:
552            msg: A message describing the passed test(s).
553            anchor: Optional internal link target.
554
555        Returns:
556            Nothing.
557        """
558
559        self._note("status-pass", msg, anchor)
560
561    def status_warning(self, msg, anchor=None):
562        """Write a note to the log file describing test(s) which passed.
563
564        Args:
565            msg: A message describing the passed test(s).
566            anchor: Optional internal link target.
567
568        Returns:
569            Nothing.
570        """
571
572        self._note("status-warning", msg, anchor)
573
574    def status_skipped(self, msg, anchor=None):
575        """Write a note to the log file describing skipped test(s).
576
577        Args:
578            msg: A message describing the skipped test(s).
579            anchor: Optional internal link target.
580
581        Returns:
582            Nothing.
583        """
584
585        self._note("status-skipped", msg, anchor)
586
587    def status_xfail(self, msg, anchor=None):
588        """Write a note to the log file describing xfailed test(s).
589
590        Args:
591            msg: A message describing the xfailed test(s).
592            anchor: Optional internal link target.
593
594        Returns:
595            Nothing.
596        """
597
598        self._note("status-xfail", msg, anchor)
599
600    def status_xpass(self, msg, anchor=None):
601        """Write a note to the log file describing xpassed test(s).
602
603        Args:
604            msg: A message describing the xpassed test(s).
605            anchor: Optional internal link target.
606
607        Returns:
608            Nothing.
609        """
610
611        self._note("status-xpass", msg, anchor)
612
613    def status_fail(self, msg, anchor=None):
614        """Write a note to the log file describing failed test(s).
615
616        Args:
617            msg: A message describing the failed test(s).
618            anchor: Optional internal link target.
619
620        Returns:
621            Nothing.
622        """
623
624        self._note("status-fail", msg, anchor)
625
626    def get_stream(self, name, chained_file=None):
627        """Create an object to log a single stream's data into the log file.
628
629        This creates a "file-like" object that can be written to in order to
630        write a single stream's data to the log file. The implementation will
631        handle any required interleaving of data (from multiple streams) in
632        the log, in a way that makes it obvious which stream each bit of data
633        came from.
634
635        Args:
636            name: The name of the stream.
637            chained_file: The file-like object to which all stream data should
638                be logged to in addition to this log. Can be None.
639
640        Returns:
641            A file-like object.
642        """
643
644        return LogfileStream(self, name, chained_file)
645
646    def get_runner(self, name, chained_file=None):
647        """Create an object that executes processes and logs their output.
648
649        Args:
650            name: The name of this sub-process.
651            chained_file: The file-like object to which all stream data should
652                be logged to in addition to logfile. Can be None.
653
654        Returns:
655            A RunAndLog object.
656        """
657
658        return RunAndLog(self, name, chained_file)
659
660    def write(self, stream, data, implicit=False):
661        """Write stream data into the log file.
662
663        This function should only be used by instances of LogfileStream or
664        RunAndLog.
665
666        Args:
667            stream: The stream whose data is being logged.
668            data: The data to log.
669            implicit: Boolean indicating whether data actually appeared in the
670                stream, or was implicitly generated. A valid use-case is to
671                repeat a shell prompt at the start of each separate log
672                section, which makes the log sections more readable in
673                isolation.
674
675        Returns:
676            Nothing.
677        """
678
679        if stream != self.last_stream:
680            self._terminate_stream()
681            self.f.write('<div class="stream block">\n')
682            self.f.write('<div class="stream-header block-header">Stream: ' +
683                         stream.name + '</div>\n')
684            self.f.write('<div class="stream-content block-content">\n')
685            self.f.write('<pre>')
686        if implicit:
687            self.f.write('<span class="implicit">')
688        self.f.write(self._escape(data))
689        if implicit:
690            self.f.write('</span>')
691        self.last_stream = stream
692
693    def flush(self):
694        """Flush the log stream, to ensure correct log interleaving.
695
696        Args:
697            None.
698
699        Returns:
700            Nothing.
701        """
702
703        self.f.flush()
704