Changeset 112140 in webkit


Ignore:
Timestamp:
Mar 26, 2012 12:41:00 PM (12 years ago)
Author:
dpranke@chromium.org
Message:

clean up NRWT logging/metering, be less verbose
​https://bugs.webkit.org/show_bug.cgi?id=73846

Reviewed by Ojan Vafai.

Re-land r112014 with a build fix for Python 2.6 compatibility.

  • Scripts/webkitpy/layout_tests/controllers/manager_unittest.py:

(ManagerTest.test_http_locking):

  • Scripts/webkitpy/layout_tests/controllers/manager_worker_broker.py:

(AbstractWorker.run):

  • Scripts/webkitpy/layout_tests/controllers/worker.py:

(Worker.init):
(Worker._set_up_logging):
(Worker):
(Worker._set_up_host_and_port):
(Worker.run):
(Worker.cleanup):

  • Scripts/webkitpy/layout_tests/controllers/worker_unittest.py:

(WorkerTest.test_default_platform_in_worker):

  • Scripts/webkitpy/layout_tests/run_webkit_tests.py:

(run):
(main):

  • Scripts/webkitpy/layout_tests/views/metered_stream.py:

(MeteredStream):
(MeteredStream.implements):
(MeteredStream._erasure):
(MeteredStream._ensure_newline):
(MeteredStream.init):
(MeteredStream.del):
(MeteredStream.cleanup):
(MeteredStream.write_throttled_update):
(MeteredStream.write_update):
(MeteredStream.write):
(MeteredStream.writeln):
(MeteredStream._erase_last_partial_line):
(_LogHandler):
(_LogHandler.init):
(_LogHandler.emit):

  • Scripts/webkitpy/layout_tests/views/metered_stream_unittest.py:

(RegularTest):
(RegularTest.setUp):
(RegularTest.tearDown):
(RegularTest.time_fn):
(RegularTest.test_logging_not_included):
(RegularTest._basic):
(RegularTest.test_basic):
(RegularTest._log_after_update):
(RegularTest.test_log_after_update):
(TtyTest):
(TtyTest.test_basic):
(TtyTest.test_log_after_update):
(VerboseTest):
(VerboseTest.test_basic):
(VerboseTest.test_log_after_update):

  • Scripts/webkitpy/layout_tests/views/printing.py:

(parse_print_options):
(Printer.init):
(Printer.cleanup):
(Printer.print_progress):
(Printer.print_update):
(Printer._write):

  • Scripts/webkitpy/layout_tests/views/printing_unittest.py:

(Testprinter.get_printer):
(Testprinter.test_print_progress):

  • Scripts/webkitpy/performance_tests/perftestsrunner.py:

(PerfTestsRunner.init):

  • Scripts/webkitpy/performance_tests/perftestsrunner_unittest.py:

(test_run_test_pause_before_testing):

Location:
trunk/Tools
Files:
12 edited

Legend:

Unmodified
Added
Removed

  • trunk/Tools/ChangeLog

    r112139 r112140  
     12012-03-26  Dirk Pranke  <dpranke@chromium.org>
     2
     3        clean up NRWT logging/metering, be less verbose
     4        https://bugs.webkit.org/show_bug.cgi?id=73846
     5
     6        Reviewed by Ojan Vafai.
     7
     8        Re-land r112014 with a build fix for Python 2.6 compatibility.
     9
     10        * Scripts/webkitpy/layout_tests/controllers/manager_unittest.py:
     11        (ManagerTest.test_http_locking):
     12        * Scripts/webkitpy/layout_tests/controllers/manager_worker_broker.py:
     13        (AbstractWorker.run):
     14        * Scripts/webkitpy/layout_tests/controllers/worker.py:
     15        (Worker.__init__):
     16        (Worker._set_up_logging):
     17        (Worker):
     18        (Worker._set_up_host_and_port):
     19        (Worker.run):
     20        (Worker.cleanup):
     21        * Scripts/webkitpy/layout_tests/controllers/worker_unittest.py:
     22        (WorkerTest.test_default_platform_in_worker):
     23        * Scripts/webkitpy/layout_tests/run_webkit_tests.py:
     24        (run):
     25        (main):
     26        * Scripts/webkitpy/layout_tests/views/metered_stream.py:
     27        (MeteredStream):
     28        (MeteredStream.implements):
     29        (MeteredStream._erasure):
     30        (MeteredStream._ensure_newline):
     31        (MeteredStream.__init__):
     32        (MeteredStream.__del__):
     33        (MeteredStream.cleanup):
     34        (MeteredStream.write_throttled_update):
     35        (MeteredStream.write_update):
     36        (MeteredStream.write):
     37        (MeteredStream.writeln):
     38        (MeteredStream._erase_last_partial_line):
     39        (_LogHandler):
     40        (_LogHandler.__init__):
     41        (_LogHandler.emit):
     42        * Scripts/webkitpy/layout_tests/views/metered_stream_unittest.py:
     43        (RegularTest):
     44        (RegularTest.setUp):
     45        (RegularTest.tearDown):
     46        (RegularTest.time_fn):
     47        (RegularTest.test_logging_not_included):
     48        (RegularTest._basic):
     49        (RegularTest.test_basic):
     50        (RegularTest._log_after_update):
     51        (RegularTest.test_log_after_update):
     52        (TtyTest):
     53        (TtyTest.test_basic):
     54        (TtyTest.test_log_after_update):
     55        (VerboseTest):
     56        (VerboseTest.test_basic):
     57        (VerboseTest.test_log_after_update):
     58        * Scripts/webkitpy/layout_tests/views/printing.py:
     59        (parse_print_options):
     60        (Printer.__init__):
     61        (Printer.cleanup):
     62        (Printer.print_progress):
     63        (Printer.print_update):
     64        (Printer._write):
     65        * Scripts/webkitpy/layout_tests/views/printing_unittest.py:
     66        (Testprinter.get_printer):
     67        (Testprinter.test_print_progress):
     68        * Scripts/webkitpy/performance_tests/perftestsrunner.py:
     69        (PerfTestsRunner.__init__):
     70        * Scripts/webkitpy/performance_tests/perftestsrunner_unittest.py:
     71        (test_run_test_pause_before_testing):
     72
    1732012-03-26  Raphael Kubo da Costa  <rakuco@FreeBSD.org>
    274

  • trunk/Tools/Scripts/webkitpy/layout_tests/controllers/manager_unittest.py

    r112019 r112140  
    215215        port = host.port_factory.get(port_name=options.platform, options=options)
    216216        run_webkit_tests._set_up_derived_options(port, options)
    217         printer = printing.Printer(port, options, StringIO.StringIO(), StringIO.StringIO(), configure_logging=False)
     217        printer = printing.Printer(port, options, StringIO.StringIO(), StringIO.StringIO())
    218218        manager = LockCheckingManager(port, options, printer)
    219219        manager.collect_tests(args)

  • trunk/Tools/Scripts/webkitpy/layout_tests/controllers/manager_worker_broker.py

    r112019 r112140  
    275275        remaining initialization and then calls broker_connection.run_message_loop()."""
    276276        exception_msg = ""
    277         _log.debug("%s starting" % self._name)
    278277
    279278        try:

  • trunk/Tools/Scripts/webkitpy/layout_tests/controllers/worker.py

    r112019 r112140  
    3939from webkitpy.layout_tests.models import test_expectations
    4040from webkitpy.layout_tests.models import test_results
    41 from webkitpy.layout_tests.views import printing
     41from webkitpy.layout_tests.views import metered_stream
    4242
    4343
    … …  
    6666        self._tests_run_file = None
    6767        self._tests_run_filename = None
    68         self._printer = None
     68        self._meter = None
    6969
    7070    def __del__(self):
    … …  
    8383        self._tests_run_file = self._filesystem.open_text_file_for_writing(tests_run_filename)
    8484
     85    def _set_up_logging(self):
     86        # The unix multiprocessing implementation clones the MeteredStream log handler
     87        # into the child process, so we need to remove it before we can
     88        # add a new one to get the correct pid logged.
     89        root_logger = logging.getLogger()
     90        handler_to_remove = None
     91        for h in root_logger.handlers:
     92            # log handlers don't have names until python 2.7.
     93            if getattr(h, 'name', '') == metered_stream.LOG_HANDLER_NAME:
     94                handler_to_remove = h
     95                break
     96        if handler_to_remove:
     97            root_logger.removeHandler(handler_to_remove)
     98
     99        # FIXME: This won't work if the calling process is logging
     100        # somewhere other than sys.stderr, but I'm not sure
     101        # if this will be an issue in practice. Also, it would be
     102        # nice if we trapped all of the messages for a given test
     103        # and sent them back in finished_test() rather than logging
     104        # them to stderr.
     105        if not root_logger.handlers:
     106            options = self._options
     107            root_logger.setLevel(logging.DEBUG if options.verbose else logging.INFO)
     108            self._meter = metered_stream.MeteredStream(sys.stderr, options.verbose, logger=root_logger)
     109
     110    def _set_up_host_and_port(self):
     111        options = self._options
     112        if options.platform and 'test' in options.platform:
     113            # It is lame to import mocks into real code, but this allows us to use the test port in multi-process tests as well.
     114            from webkitpy.common.host_mock import MockHost
     115            host = MockHost()
     116        else:
     117            host = Host()
     118        self._port = host.port_factory.get(options.platform, options)
     119
    85120    def set_inline_arguments(self, port):
    86121        self._port = port
    … …  
    88123    def run(self):
    89124        if not self._port:
    90             # We are running in a child process and need to create a new Host.
    91             if self._options.platform and 'test' in self._options.platform:
    92                 # It is lame to import mocks into real code, but this allows us to use the test port in multi-process tests as well.
    93                 from webkitpy.common.host_mock import MockHost
    94                 host = MockHost()
    95             else:
    96                 host = Host()
    97 
    98             options = self._options
    99             self._port = host.port_factory.get(options.platform, options)
    100 
    101             # The unix multiprocessing implementation clones the
    102             # log handler configuration into the child processes,
    103             # but the win implementation doesn't.
    104             configure_logging = (sys.platform == 'win32')
    105 
    106             # FIXME: This won't work if the calling process is logging
    107             # somewhere other than sys.stderr and sys.stdout, but I'm not sure
    108             # if this will be an issue in practice.
    109             self._printer = printing.Printer(self._port, options, sys.stderr, sys.stdout, configure_logging)
     125            # We are running in a child process and need to initialize things.
     126            self._set_up_logging()
     127            self._set_up_host_and_port()
    110128
    111129        self.safe_init()
    112 
    113130        try:
    114131            _log.debug("%s starting" % self._name)
    115132            super(Worker, self).run()
    116133        finally:
     134            self.kill_driver()
    117135            self._worker_connection.post_message('done')
     136            _log.debug("%s exiting" % self._name)
    118137            self.cleanup()
    119             _log.debug("%s exiting" % self._name)
    120138
    121139    def handle_test_list(self, src, list_name, test_list):
    … …  
    154172            self._tests_run_file.close()
    155173            self._tests_run_file = None
    156         if self._printer:
    157             self._printer.cleanup()
    158             self._printer = None
     174        if self._meter:
     175            self._meter.cleanup()
     176            self._meter = None
    159177
    160178    def timeout(self, test_input):

  • trunk/Tools/Scripts/webkitpy/layout_tests/controllers/worker_unittest.py

    r112019 r112140  
    4747        worker_connection = FakeConnection()
    4848        worker = Worker(worker_connection, WorkerArguments(1, '/tmp', MockOptions(platform=None, print_options=None, verbose=False, batch_size=0)))
    49         worker._done = True
    50         worker.run()
     49        worker._set_up_host_and_port()
    5150        self.assertNotEquals(worker._port, None)
    5251

  • trunk/Tools/Scripts/webkitpy/layout_tests/run_webkit_tests.py

    r112019 r112140  
    8686    warnings = _set_up_derived_options(port, options)
    8787
    88     printer = printing.Printer(port, options, regular_output, buildbot_output, configure_logging=True)
     88    printer = printing.Printer(port, options, regular_output, buildbot_output, logger=logging.getLogger())
    8989
    9090    for warning in warnings:
    … …  
    480480    host._initialize_scm()
    481481    port = host.port_factory.get(options.platform, options)
     482    logging.getLogger().setLevel(logging.DEBUG if options.verbose else logging.INFO)
    482483    return run(port, options, args)
    483484

  • trunk/Tools/Scripts/webkitpy/layout_tests/views/metered_stream.py

    r112019 r112140  
    11#!/usr/bin/env python
    2 # Copyright (C) 2010 Google Inc. All rights reserved.
     2# Copyright (C) 2010, 2012 Google Inc. All rights reserved.
    33#
    44# Redistribution and use in source and binary forms, with or without
    … …  
    2828# OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
    2929
    30 """
    31 Package that implements a stream wrapper that has 'meters' as well as
    32 regular output. A 'meter' is a single line of text that can be erased
    33 and rewritten repeatedly, without producing multiple lines of output. It
    34 can be used to produce effects like progress bars.
    35 
    36 This package should only be called by the printing module in the layout_tests
    37 package.
    38 """
     30import logging
     31import os
     32import sys
     33import time
    3934
    4035
    41 class MeteredStream:
    42     """This class is a wrapper around a stream that allows you to implement
    43     meters (progress bars, etc.).
     36LOG_HANDLER_NAME = 'MeteredStreamLogHandler'
    4437
    45     It can be used directly as a stream, by calling write(), but also provides
    46     a method called update() that will overwite prior updates().
    47    """
    4838
    49     def __init__(self, stream):
    50         """
    51         Args:
    52           stream: output stream to write to
    53         """
    54         self._stream = stream
    55         self._dirty = False
    56         self._last_update = ""
     39class MeteredStream(object):
     40    """
     41    This class implements a stream wrapper that has 'meters' as well as
     42    regular output. A 'meter' is a single line of text that can be erased
     43    and rewritten repeatedly, without producing multiple lines of output. It
     44    can be used to produce effects like progress bars.
     45    """
    5746
    58     def write(self, txt):
    59         """Write to the stream, overwriting and resetting the meter."""
     47    @staticmethod
     48    def _erasure(txt):
     49        num_chars = len(txt)
     50        return '\b' * num_chars + ' ' * num_chars + '\b' * num_chars
    6051
    61         # This routine is called by the logging infrastructure, and
    62         # must not call back into logging. It is not a public function.
    63         self._overwrite(txt)
    64         self._reset()
     52    @staticmethod
     53    def _ensure_newline(txt):
     54        return txt if txt.endswith('\n') else txt + '\n'
    6555
    66     def update(self, txt):
    67         """Write a message that will be overwritten by subsequent update() or write() calls."""
    68         self._overwrite(txt)
     56    def __init__(self, stream=None, verbose=False, logger=None, time_fn=None, pid=None):
     57        self._stream = stream or sys.stderr
     58        self._verbose = verbose
     59        self._time_fn = time_fn or time.time
     60        self._pid = pid or os.getpid()
    6961
    70     def _overwrite(self, txt):
    71         # Print the necessary number of backspaces to erase the previous
    72         # message.
    73         if len(self._last_update):
    74             self._stream.write("\b" * len(self._last_update) +
    75                                " " * len(self._last_update) +
    76                                "\b" * len(self._last_update))
    77         self._stream.write(txt)
    78         last_newline = txt.rfind("\n")
    79         self._last_update = txt[(last_newline + 1):]
    80         self._dirty = True
     62        self._isatty = self._stream.isatty()
     63        self._erasing = self._isatty and not verbose
     64        self._last_partial_line = ''
     65        self._last_write_time = 0.0
     66        self._throttle_delay_in_secs = 0.066 if self._erasing else 10.0
    8167
    82     def _reset(self):
    83         self._dirty = False
    84         self._last_update = ''
     68        self._logger = logger
     69        self._log_handler = None
     70        if self._logger:
     71            log_level = logging.DEBUG if verbose else logging.INFO
     72            self._log_handler = _LogHandler(self)
     73            self._log_handler.setLevel(log_level)
     74            self._logger.addHandler(self._log_handler)
     75
     76    def __del__(self):
     77        self.cleanup()
     78
     79    def cleanup(self):
     80        if self._logger:
     81            self._logger.removeHandler(self._log_handler)
     82            self._log_handler = None
     83
     84    def write_throttled_update(self, txt):
     85        now = self._time_fn()
     86        if now - self._last_write_time >= self._throttle_delay_in_secs:
     87            self.write_update(txt, now)
     88
     89    def write_update(self, txt, now=None):
     90        self.write(txt, now)
     91        if self._erasing:
     92            self._last_partial_line = txt[txt.rfind('\n') + 1:]
     93
     94    def write(self, txt, now=None):
     95        now = now or self._time_fn()
     96        self._last_write_time = now
     97        if self._last_partial_line:
     98            self._erase_last_partial_line()
     99        if self._verbose:
     100            now_tuple = time.localtime(now)
     101            msg = '%02d:%02d:%02d.%03d %d %s' % (now_tuple.tm_hour, now_tuple.tm_min, now_tuple.tm_sec, int((now * 1000) % 1000), self._pid, self._ensure_newline(txt))
     102        elif self._isatty:
     103            msg = txt
     104        else:
     105            msg = self._ensure_newline(txt)
     106
     107        self._stream.write(msg)
     108
     109    def writeln(self, txt, now=None):
     110        self.write(self._ensure_newline(txt), now)
     111
     112    def _erase_last_partial_line(self):
     113        num_chars = len(self._last_partial_line)
     114        self._stream.write(self._erasure(self._last_partial_line))
     115        self._last_partial_line = ''
     116
     117
     118class _LogHandler(logging.Handler):
     119    def __init__(self, meter):
     120        logging.Handler.__init__(self)
     121        self._meter = meter
     122        self.name = LOG_HANDLER_NAME
     123
     124    def emit(self, record):
     125        self._meter.writeln(record.msg, record.created)

  • trunk/Tools/Scripts/webkitpy/layout_tests/views/metered_stream_unittest.py

    r112019 r112140  
    11#!/usr/bin/python
    2 # Copyright (C) 2010 Google Inc. All rights reserved.
     2# Copyright (C) 2010, 2012 Google Inc. All rights reserved.
    33#
    44# Redistribution and use in source and binary forms, with or without
    … …  
    2828# OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
    2929
     30import logging
     31import re
    3032import StringIO
    3133import unittest
    … …  
    3436
    3537
    36 class TestMeteredStream(unittest.TestCase):
    37     def test_regular(self):
    38         a = StringIO.StringIO()
    39         m = MeteredStream(a)
    40         self.assertFalse(a.getvalue())
     38class RegularTest(unittest.TestCase):
     39    verbose = False
     40    isatty = False
    4141
    42         # basic test
    43         m.write("foo")
    44         exp = ['foo']
    45         self.assertEquals(a.buflist, exp)
     42    def setUp(self):
     43        self.stream = StringIO.StringIO()
     44        self.buflist = self.stream.buflist
     45        self.stream.isatty = lambda: self.isatty
    4646
    47         # now check that a second write() does not overwrite the first.
    48         m.write("bar")
    49         exp.append('bar')
    50         self.assertEquals(a.buflist, exp)
     47        # configure a logger to test that log calls do normally get included.
     48        self.logger = logging.getLogger(__name__)
     49        self.logger.setLevel(logging.DEBUG)
     50        self.logger.propagate = False
    5151
    52         m.update("batter")
    53         exp.append('batter')
    54         self.assertEquals(a.buflist, exp)
     52        # add a dummy time counter for a default behavior.
     53        self.times = range(10)
    5554
    56         # The next update() should overwrite the laste update() but not the
    57         # other text. Note that the cursor is effectively positioned at the
    58         # end of 'foo', even though we had to erase three more characters.
    59         m.update("foo")
    60         exp.append('\b\b\b\b\b\b      \b\b\b\b\b\b')
    61         exp.append('foo')
    62         self.assertEquals(a.buflist, exp)
     55        self.meter = MeteredStream(self.stream, self.verbose, self.logger, self.time_fn, 8675)
    6356
    64         # now check that a write() does overwrite the update
    65         m.write("foo")
    66         exp.append('\b\b\b   \b\b\b')
    67         exp.append('foo')
    68         self.assertEquals(a.buflist, exp)
     57    def tearDown(self):
     58        if self.meter:
     59            self.meter.cleanup()
     60            self.meter = None
    6961
    70         # Now test that we only back up to the most recent newline.
     62    def time_fn(self):
     63        return self.times.pop(0)
    7164
    72         # Note also that we do not back up to erase the most recent write(),
    73         # i.e., write()s do not get erased.
    74         a = StringIO.StringIO()
    75         m = MeteredStream(a)
    76         m.update("foo\nbar")
    77         m.update("baz")
    78         self.assertEquals(a.buflist, ['foo\nbar', '\b\b\b   \b\b\b', 'baz'])
     65    def test_logging_not_included(self):
     66        # This tests that if we don't hand a logger to the MeteredStream,
     67        # nothing is logged.
     68        logging_stream = StringIO.StringIO()
     69        handler = logging.StreamHandler(logging_stream)
     70        root_logger = logging.getLogger()
     71        orig_level = root_logger.level
     72        root_logger.addHandler(handler)
     73        root_logger.setLevel(logging.DEBUG)
     74        try:
     75            self.meter = MeteredStream(self.stream, self.verbose, None, self.time_fn, 8675)
     76            self.meter.write_throttled_update('foo')
     77            self.meter.write_update('bar')
     78            self.meter.write('baz')
     79            self.assertEquals(logging_stream.buflist, [])
     80        finally:
     81            root_logger.removeHandler(handler)
     82            root_logger.setLevel(orig_level)
     83
     84    def _basic(self, times):
     85        self.times = times
     86        self.meter.write_update('foo')
     87        self.meter.write_update('bar')
     88        self.meter.write_throttled_update('baz')
     89        self.meter.write_throttled_update('baz 2')
     90        self.meter.writeln('done')
     91        self.assertEquals(self.times, [])
     92        return self.buflist
     93
     94    def test_basic(self):
     95        buflist = self._basic([0, 1, 2, 13, 14])
     96        self.assertEquals(buflist, ['foo\n', 'bar\n', 'baz 2\n', 'done\n'])
     97
     98    def _log_after_update(self):
     99        self.meter.write_update('foo')
     100        self.logger.info('bar')
     101        return self.buflist
     102
     103    def test_log_after_update(self):
     104        buflist = self._log_after_update()
     105        self.assertEquals(buflist, ['foo\n', 'bar\n'])
     106
     107
     108class TtyTest(RegularTest):
     109    verbose = False
     110    isatty = True
     111
     112    def test_basic(self):
     113        buflist = self._basic([0, 1, 1.05, 1.1, 2])
     114        self.assertEquals(buflist, ['foo',
     115                                     MeteredStream._erasure('foo'), 'bar',
     116                                     MeteredStream._erasure('bar'), 'baz 2',
     117                                     MeteredStream._erasure('baz 2'), 'done\n'])
     118
     119    def test_log_after_update(self):
     120        buflist = self._log_after_update()
     121        self.assertEquals(buflist, ['foo',
     122                                     MeteredStream._erasure('foo'), 'bar\n'])
     123
     124
     125class VerboseTest(RegularTest):
     126    isatty = False
     127    verbose = True
     128
     129    def test_basic(self):
     130        buflist = self._basic([0, 1, 2.1, 13, 14.1234])
     131        self.assertEquals(buflist, ['16:00:00.000 8675 foo\n', '16:00:01.000 8675 bar\n', '16:00:13.000 8675 baz 2\n', '16:00:14.123 8675 done\n'])
     132
     133    def test_log_after_update(self):
     134        buflist = self._log_after_update()
     135        self.assertEquals(buflist[0], '16:00:00.000 8675 foo\n')
     136
     137        # The second argument should have a real timestamp and pid, so we just check the format.
     138        self.assertEquals(len(buflist), 2)
     139        self.assertTrue(re.match('\d\d:\d\d:\d\d.\d\d\d \d+ bar\n', buflist[1]))
    79140
    80141

  • trunk/Tools/Scripts/webkitpy/layout_tests/views/printing.py

    r112019 r112140  
    11#!/usr/bin/env python
    2 # Copyright (C) 2010 Google Inc. All rights reserved.
     2# Copyright (C) 2010, 2012 Google Inc. All rights reserved.
    33#
    44# Redistribution and use in source and binary forms, with or without
    … …  
    3030"""Package that handles non-debug, non-file output for run-webkit-tests."""
    3131
    32 import logging
    3332import optparse
    34 import time
    3533
    3634from webkitpy.common.net import resultsjsonparser
     35from webkitpy.layout_tests.models.test_expectations import TestExpectations
    3736from webkitpy.layout_tests.views.metered_stream import MeteredStream
    38 from webkitpy.layout_tests.models.test_expectations import TestExpectations
    39 
    40 
    41 _log = logging.getLogger(__name__)
    42 
    4337
    4438NUM_SLOW_TESTS_TO_LOG = 10
    45 FAST_UPDATES_SECONDS = 0.03
    46 SLOW_UPDATES_SECONDS = 10.0
    4739
    4840PRINT_DEFAULT = "misc,one-line-progress,one-line-summary,unexpected,unexpected-results,updates"
    … …  
    155147
    156148
    157 def _configure_logging(stream, verbose):
    158     log_fmt = '%(message)s'
    159     log_datefmt = '%y%m%d %H:%M:%S'
    160     log_level = logging.INFO
    161     if verbose:
    162         log_fmt = '%(asctime)s %(process)d %(filename)s:%(lineno)d %(levelname)s %(message)s'
    163         log_level = logging.DEBUG
    164 
    165     root = logging.getLogger()
    166     handler = logging.StreamHandler(stream)
    167     handler.setFormatter(logging.Formatter(log_fmt, None))
    168     root.addHandler(handler)
    169     root.setLevel(log_level)
    170     return handler
    171 
    172 
    173 def _restore_logging(handler_to_remove):
    174     root = logging.getLogger()
    175     root.handlers.remove(handler_to_remove)
    176 
    177 
    178149class Printer(object):
    179150    """Class handling all non-debug-logging printing done by run-webkit-tests.
    … …  
    188159    By default the buildbot-parsed code gets logged to stdout, and regular
    189160    output gets logged to stderr."""
    190     def __init__(self, port, options, regular_output, buildbot_output, configure_logging):
     161    def __init__(self, port, options, regular_output, buildbot_output, logger=None):
    191162        """
    192163        Args
    … …  
    197168          buildbot_output    stream to which output intended to be read by
    198169                             the buildbots (and humans) should be written
    199           configure_loggign  Whether a logging handler should be registered
    200 
     170          logger             optional logger to integrate into the stream.
    201171        """
    202172        self._port = port
    203173        self._options = options
    204         self._stream = regular_output
    205174        self._buildbot_stream = buildbot_output
    206         self._meter = None
    207 
    208         # These are used for --print one-line-progress
    209         self._last_remaining = None
    210         self._last_update_time = None
    211 
     175        self._meter = MeteredStream(regular_output, options.verbose, logger=logger)
    212176        self.switches = parse_print_options(options.print_options, options.verbose)
    213177
    214         self._logging_handler = None
    215         if self._stream.isatty() and not options.verbose:
    216             self._update_interval_seconds = FAST_UPDATES_SECONDS
    217             self._meter = MeteredStream(self._stream)
    218             if configure_logging:
    219                 self._logging_handler = _configure_logging(self._meter, options.verbose)
    220         else:
    221             self._update_interval_seconds = SLOW_UPDATES_SECONDS
    222             if configure_logging:
    223                 self._logging_handler = _configure_logging(self._stream, options.verbose)
    224 
    225178    def cleanup(self):
    226         """Restore logging configuration to its initial settings."""
    227         if self._logging_handler:
    228             _restore_logging(self._logging_handler)
    229             self._logging_handler = None
     179        self._meter.cleanup()
    230180
    231181    def __del__(self):
    … …  
    351301            return
    352302
    353         now = time.time()
    354         if self._last_update_time is None:
    355             self._last_update_time = now
    356 
    357         time_since_last_update = now - self._last_update_time
    358         if time_since_last_update <= self._update_interval_seconds:
    359             return
    360 
    361         self._last_update_time = now
     303        if result_summary.remaining == 0:
     304            self._meter.write_update('')
     305            return
    362306
    363307        percent_complete = 100 * (result_summary.expected +
    … …  
    366310        if retrying:
    367311            action = "Retrying"
    368         self._update("%s (%d%%): %d ran as expected, %d didn't, %d left" %
    369                      (action, percent_complete, result_summary.expected,
    370                       result_summary.unexpected, result_summary.remaining))
    371 
    372         if result_summary.remaining == 0:
    373             self._update('')
     312
     313        self._meter.write_throttled_update("%s (%d%%): %d ran as expected, %d didn't, %d left" %
     314            (action, percent_complete, result_summary.expected,
     315             result_summary.unexpected, result_summary.remaining))
    374316
    375317    def print_unexpected_results(self, unexpected_results):
    … …  
    459401        if self.disabled('updates'):
    460402            return
    461         self._update(msg)
     403        self._meter.write_update(msg)
    462404
    463405    def write(self, msg, option="misc"):
    … …  
    467409
    468410    def _write(self, msg):
    469         _log.info(msg)
    470 
    471     def _update(self, msg):
    472         if self._meter:
    473             self._meter.update(msg)
    474         else:
    475             self._write(msg)
     411        self._meter.writeln(msg)

  • trunk/Tools/Scripts/webkitpy/layout_tests/views/printing_unittest.py

    r112019 r112140  
    11#!/usr/bin/python
    2 # Copyright (C) 2010 Google Inc. All rights reserved.
     2# Copyright (C) 2010, 2012 Google Inc. All rights reserved.
    33#
    44# Redistribution and use in source and binary forms, with or without
    … …  
    3030"""Unit tests for printing.py."""
    3131
    32 import logging
    3332import optparse
    3433import StringIO
    … …  
    5554
    5655class TestUtilityFunctions(unittest.TestCase):
    57     def assertEmpty(self, stream):
    58         self.assertFalse(stream.getvalue())
    59 
    60     def assertNotEmpty(self, stream):
    61         self.assertTrue(stream.getvalue())
    62 
    63     def assertWritten(self, stream, contents):
    64         self.assertEquals(stream.buflist, contents)
    65 
    66     def test_configure_logging(self):
    67         options, args = get_options([])
    68         stream = StringIO.StringIO()
    69         handler = printing._configure_logging(stream, options.verbose)
    70         logging.info("this should be logged")
    71         self.assertNotEmpty(stream)
    72 
    73         stream = StringIO.StringIO()
    74         logging.debug("this should not be logged")
    75         self.assertEmpty(stream)
    76 
    77         printing._restore_logging(handler)
    78 
    79         stream = StringIO.StringIO()
    80         options, args = get_options(['--verbose'])
    81         handler = printing._configure_logging(stream, options.verbose)
    82         logging.debug("this should be logged")
    83         self.assertNotEmpty(stream)
    84         printing._restore_logging(handler)
    85 
    8656    def test_print_options(self):
    8757        options, args = get_options([])
    … …  
    145115        regular_output.isatty = lambda: tty
    146116        buildbot_output = StringIO.StringIO()
    147         printer = printing.Printer(self._port, options, regular_output,
    148                                    buildbot_output, configure_logging=True)
     117        printer = printing.Printer(self._port, options, regular_output, buildbot_output)
    149118        return printer, regular_output, buildbot_output
    150119
    … …  
    351320        paths, rs, exp = self.get_result_summary(tests, expectations)
    352321
    353         # First, test that we print nothing.
     322        # First, test that we print nothing when we shouldn't print anything.
    354323        printer.print_progress(rs, False, paths)
    355324        self.assertEmpty(out)
    … …  
    360329        self.assertEmpty(err)
    361330
    362         self.times = [1, 2, 12, 13, 14, 23, 33]
    363 
    364         def mock_time():
    365             return self.times.pop(0)
    366 
    367         orig_time = time.time
    368         try:
    369             time.time = mock_time
    370 
    371             # Test printing progress updates to a file.
    372             printer, err, out = self.get_printer(['--print', 'one-line-progress'])
    373             printer.print_progress(rs, False, paths)
    374             printer.print_progress(rs, False, paths)
    375             self.assertEmpty(out)
    376             self.assertEmpty(err)
    377 
    378             printer.print_progress(rs, False, paths)
    379             self.assertEmpty(out)
    380             self.assertNotEmpty(err)
    381 
    382             self.reset(err)
    383             self.reset(out)
    384             printer.print_progress(rs, True, paths)
    385             self.assertEmpty(out)
    386             self.assertEmpty(err)
    387 
    388             printer.print_progress(rs, True, paths)
    389             self.assertEmpty(out)
    390             self.assertNotEmpty(err)
    391 
    392             # Now reconfigure the printer to test printing to a TTY instead of a file.
    393             self.times = [1, 1.01, 2, 3]
    394             printer, err, out = self.get_printer(['--print', 'one-line-progress'], tty=True)
    395             printer.print_progress(rs, False, paths)
    396             printer.print_progress(rs, False, paths)
    397             self.assertEmpty(out)
    398             self.assertEmpty(err)
    399 
    400             printer.print_progress(rs, False, paths)
    401             self.assertEmpty(out)
    402             self.assertNotEmpty(err)
    403 
    404             self.reset(err)
    405             self.reset(out)
    406             printer.print_progress(rs, True, paths)
    407             self.assertEmpty(out)
    408             self.assertNotEmpty(err)
    409         finally:
    410             time.time = orig_time
     331        # Now test that we do print things.
     332        printer, err, out = self.get_printer(['--print', 'one-line-progress'])
     333        printer.print_progress(rs, False, paths)
     334        self.assertEmpty(out)
     335        self.assertNotEmpty(err)
     336
     337        printer, err, out = self.get_printer(['--print', 'one-line-progress'])
     338        printer.print_progress(rs, True, paths)
     339        self.assertEmpty(out)
     340        self.assertNotEmpty(err)
     341
     342        printer, err, out = self.get_printer(['--print', 'one-line-progress'])
     343        rs.remaining = 0
     344        printer.print_progress(rs, False, paths)
     345        self.assertEmpty(out)
     346        self.assertNotEmpty(err)
     347
     348        printer.print_progress(rs, True, paths)
     349        self.assertEmpty(out)
     350        self.assertNotEmpty(err)
     351
     352
    411353
    412354    def test_write_nothing(self):

  • trunk/Tools/Scripts/webkitpy/performance_tests/perftestsrunner.py

    r112019 r112140  
    6363            self._port = self._host.port_factory.get(self._options.platform, self._options)
    6464        self._host._initialize_scm()
    65         self._printer = printing.Printer(self._port, self._options, regular_output, buildbot_output, configure_logging=False)
     65        self._printer = printing.Printer(self._port, self._options, regular_output, buildbot_output)
    6666        self._webkit_base_dir_len = len(self._port.webkit_base())
    6767        self._base_path = self._port.perf_tests_dir()

  • trunk/Tools/Scripts/webkitpy/performance_tests/perftestsrunner_unittest.py

    r112019 r112140  
    183183
    184184        buildbot_output = StringIO.StringIO()
    185         runner = self.create_runner(buildbot_output, args=["--pause-before-testing"], driver_class=TestDriverWithStartCount)
     185        regular_output = StringIO.StringIO()
     186        runner = self.create_runner(buildbot_output, args=["--pause-before-testing"], regular_output=regular_output, driver_class=TestDriverWithStartCount)
    186187
    187188        dirname = runner._base_path + '/inspector/'
    … …  
    194195            self.assertEqual(TestDriverWithStartCount.start_count, 1)
    195196        finally:
    196             _, stderr, logs = output.restore_output()
     197            _, stderr, _ = output.restore_output()
    197198            self.assertEqual(stderr, "Ready to run test?\n")
    198             self.assertTrue("Running inspector/pass.html (1 of 1)" in logs)
     199            self.assertTrue("Running inspector/pass.html (1 of 1)" in regular_output.getvalue())
    199200
    200201    def test_run_test_set_for_parser_tests(self):
Note: See TracChangeset for help on using the changeset viewer.