Unreviewed, rolling out r112014.
authorkov@webkit.org <kov@webkit.org@268f45cc-cd09-0410-ab3c-d52691b4dbfc>
Sun, 25 Mar 2012 03:50:49 +0000 (03:50 +0000)
committerkov@webkit.org <kov@webkit.org@268f45cc-cd09-0410-ab3c-d52691b4dbfc>
Sun, 25 Mar 2012 03:50:49 +0000 (03:50 +0000)
http://trac.webkit.org/changeset/112014
https://bugs.webkit.org/show_bug.cgi?id=82138

Broke SnowLeopard, Chromium and GTK+ bots (Requested by kov on
#webkit).

Patch by Sheriff Bot <webkit.review.bot@gmail.com> on 2012-03-24

* 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.safe_init):
(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.is):
(MeteredStream.__init__):
(MeteredStream.write):
(MeteredStream.update):
(MeteredStream._overwrite):
(MeteredStream._reset):
* Scripts/webkitpy/layout_tests/views/metered_stream_unittest.py:
(TestMeteredStream):
(TestMeteredStream.test_regular):
* Scripts/webkitpy/layout_tests/views/printing.py:
(_configure_logging):
(_restore_logging):
(Printer.__init__):
(Printer.cleanup):
(Printer.print_progress):
(Printer.print_update):
(Printer._write):
(Printer):
(Printer._update):
* Scripts/webkitpy/layout_tests/views/printing_unittest.py:
(TestUtilityFunctions.assertEmpty):
(TestUtilityFunctions):
(TestUtilityFunctions.assertNotEmpty):
(TestUtilityFunctions.assertWritten):
(TestUtilityFunctions.test_configure_logging):
(Testprinter.get_printer):
(Testprinter.test_print_progress):
(Testprinter.test_print_progress.mock_time):
* Scripts/webkitpy/performance_tests/perftestsrunner.py:
(PerfTestsRunner.__init__):
* Scripts/webkitpy/performance_tests/perftestsrunner_unittest.py:
(test_run_test_pause_before_testing):

git-svn-id: https://svn.webkit.org/repository/webkit/trunk@112019 268f45cc-cd09-0410-ab3c-d52691b4dbfc

12 files changed:
Tools/ChangeLog
Tools/Scripts/webkitpy/layout_tests/controllers/manager_unittest.py
Tools/Scripts/webkitpy/layout_tests/controllers/manager_worker_broker.py
Tools/Scripts/webkitpy/layout_tests/controllers/worker.py
Tools/Scripts/webkitpy/layout_tests/controllers/worker_unittest.py
Tools/Scripts/webkitpy/layout_tests/run_webkit_tests.py
Tools/Scripts/webkitpy/layout_tests/views/metered_stream.py
Tools/Scripts/webkitpy/layout_tests/views/metered_stream_unittest.py
Tools/Scripts/webkitpy/layout_tests/views/printing.py
Tools/Scripts/webkitpy/layout_tests/views/printing_unittest.py
Tools/Scripts/webkitpy/performance_tests/perftestsrunner.py
Tools/Scripts/webkitpy/performance_tests/perftestsrunner_unittest.py

index df7ad19f6a772a8fe0f45437849fe56155ef624f..822f312961c9e8004c44155211d434c4a6012c64 100644 (file)
@@ -1,3 +1,61 @@
+2012-03-24  Sheriff Bot  <webkit.review.bot@gmail.com>
+
+        Unreviewed, rolling out r112014.
+        http://trac.webkit.org/changeset/112014
+        https://bugs.webkit.org/show_bug.cgi?id=82138
+
+        Broke SnowLeopard, Chromium and GTK+ bots (Requested by kov on
+        #webkit).
+
+        * 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.safe_init):
+        (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.is):
+        (MeteredStream.__init__):
+        (MeteredStream.write):
+        (MeteredStream.update):
+        (MeteredStream._overwrite):
+        (MeteredStream._reset):
+        * Scripts/webkitpy/layout_tests/views/metered_stream_unittest.py:
+        (TestMeteredStream):
+        (TestMeteredStream.test_regular):
+        * Scripts/webkitpy/layout_tests/views/printing.py:
+        (_configure_logging):
+        (_restore_logging):
+        (Printer.__init__):
+        (Printer.cleanup):
+        (Printer.print_progress):
+        (Printer.print_update):
+        (Printer._write):
+        (Printer):
+        (Printer._update):
+        * Scripts/webkitpy/layout_tests/views/printing_unittest.py:
+        (TestUtilityFunctions.assertEmpty):
+        (TestUtilityFunctions):
+        (TestUtilityFunctions.assertNotEmpty):
+        (TestUtilityFunctions.assertWritten):
+        (TestUtilityFunctions.test_configure_logging):
+        (Testprinter.get_printer):
+        (Testprinter.test_print_progress):
+        (Testprinter.test_print_progress.mock_time):
+        * Scripts/webkitpy/performance_tests/perftestsrunner.py:
+        (PerfTestsRunner.__init__):
+        * Scripts/webkitpy/performance_tests/perftestsrunner_unittest.py:
+        (test_run_test_pause_before_testing):
+
 2012-03-24  Kevin Ollivier  <kevino@theolliviers.com>
 
         [wx] Unreviewed. Fix the build after WTF move.
index 3f58e7b4c51b1a87eed05fb108a053db0384f25f..8bc6afffe1386ea5153ed396917be6214899c60f 100644 (file)
@@ -214,7 +214,7 @@ class ManagerTest(unittest.TestCase):
         host = MockHost()
         port = host.port_factory.get(port_name=options.platform, options=options)
         run_webkit_tests._set_up_derived_options(port, options)
-        printer = printing.Printer(port, options, StringIO.StringIO(), StringIO.StringIO())
+        printer = printing.Printer(port, options, StringIO.StringIO(), StringIO.StringIO(), configure_logging=False)
         manager = LockCheckingManager(port, options, printer)
         manager.collect_tests(args)
         manager.parse_expectations()
index 08c059a9576c919d34869eec26b4b2cb7a8d1cc5..70c43a6d415d34065b14a73e3e1def781ffa23ff 100755 (executable)
@@ -274,6 +274,7 @@ class AbstractWorker(BrokerClient):
         """Callback for the worker to start executing. Typically does any
         remaining initialization and then calls broker_connection.run_message_loop()."""
         exception_msg = ""
+        _log.debug("%s starting" % self._name)
 
         try:
             self._worker_connection.run_message_loop()
index 07a20c9c305abd7ec1edad8ddddc94c8f33b78bc..22c0a5f0423105e30938b8ef3527dc67e2029aa2 100644 (file)
@@ -38,7 +38,7 @@ from webkitpy.layout_tests.controllers import manager_worker_broker
 from webkitpy.layout_tests.controllers import single_test_runner
 from webkitpy.layout_tests.models import test_expectations
 from webkitpy.layout_tests.models import test_results
-from webkitpy.layout_tests.views import metered_stream
+from webkitpy.layout_tests.views import printing
 
 
 _log = logging.getLogger(__name__)
@@ -65,7 +65,7 @@ class Worker(manager_worker_broker.AbstractWorker):
         self._driver = None
         self._tests_run_file = None
         self._tests_run_filename = None
-        self._meter = None
+        self._printer = None
 
     def __del__(self):
         self.cleanup()
@@ -82,58 +82,41 @@ class Worker(manager_worker_broker.AbstractWorker):
         tests_run_filename = self._filesystem.join(self._results_directory, "tests_run%d.txt" % self._worker_number)
         self._tests_run_file = self._filesystem.open_text_file_for_writing(tests_run_filename)
 
-    def _set_up_logging(self):
-        # The unix multiprocessing implementation clones the MeteredStream log handler
-        # into the child process, so we need to remove it before we can
-        # add a new one to get the correct pid logged.
-        root_logger = logging.getLogger()
-        handler_to_remove = None
-        for h in root_logger.handlers:
-            if h.name == metered_stream.LOG_HANDLER_NAME:
-                handler_to_remove = h
-                break
-        if handler_to_remove:
-            root_logger.removeHandler(handler_to_remove)
-
-        # FIXME: This won't work if the calling process is logging
-        # somewhere other than sys.stderr, but I'm not sure
-        # if this will be an issue in practice. Also, it would be
-        # nice if we trapped all of the messages for a given test
-        # and sent them back in finished_test() rather than logging
-        # them to stderr.
-        if not root_logger.handlers:
-            options = self._options
-            root_logger.setLevel(logging.DEBUG if options.verbose else logging.INFO)
-            self._meter = metered_stream.MeteredStream(sys.stderr, options.verbose, logger=root_logger)
-
-    def _set_up_host_and_port(self):
-        options = self._options
-        if options.platform and 'test' in options.platform:
-            # It is lame to import mocks into real code, but this allows us to use the test port in multi-process tests as well.
-            from webkitpy.common.host_mock import MockHost
-            host = MockHost()
-        else:
-            host = Host()
-        self._port = host.port_factory.get(options.platform, options)
-
     def set_inline_arguments(self, port):
         self._port = port
 
     def run(self):
         if not self._port:
-            # We are running in a child process and need to initialize things.
-            self._set_up_logging()
-            self._set_up_host_and_port()
+            # We are running in a child process and need to create a new Host.
+            if self._options.platform and 'test' in self._options.platform:
+                # It is lame to import mocks into real code, but this allows us to use the test port in multi-process tests as well.
+                from webkitpy.common.host_mock import MockHost
+                host = MockHost()
+            else:
+                host = Host()
+
+            options = self._options
+            self._port = host.port_factory.get(options.platform, options)
+
+            # The unix multiprocessing implementation clones the
+            # log handler configuration into the child processes,
+            # but the win implementation doesn't.
+            configure_logging = (sys.platform == 'win32')
+
+            # FIXME: This won't work if the calling process is logging
+            # somewhere other than sys.stderr and sys.stdout, but I'm not sure
+            # if this will be an issue in practice.
+            self._printer = printing.Printer(self._port, options, sys.stderr, sys.stdout, configure_logging)
 
         self.safe_init()
+
         try:
             _log.debug("%s starting" % self._name)
             super(Worker, self).run()
         finally:
-            self.kill_driver()
             self._worker_connection.post_message('done')
-            _log.debug("%s exiting" % self._name)
             self.cleanup()
+            _log.debug("%s exiting" % self._name)
 
     def handle_test_list(self, src, list_name, test_list):
         start_time = time.time()
@@ -170,9 +153,9 @@ class Worker(manager_worker_broker.AbstractWorker):
         if self._tests_run_file:
             self._tests_run_file.close()
             self._tests_run_file = None
-        if self._meter:
-            self._meter.cleanup()
-            self._meter = None
+        if self._printer:
+            self._printer.cleanup()
+            self._printer = None
 
     def timeout(self, test_input):
         """Compute the appropriate timeout value for a test."""
index ebb4e7a5bb5ae687471cba3200a08b31b58b136b..6fd5202d9c4007f0ee84d9c1356afcfaa0d9f591 100644 (file)
@@ -46,7 +46,8 @@ class WorkerTest(unittest.TestCase):
         # if we didn't specify a port with the --platform flag.
         worker_connection = FakeConnection()
         worker = Worker(worker_connection, WorkerArguments(1, '/tmp', MockOptions(platform=None, print_options=None, verbose=False, batch_size=0)))
-        worker._set_up_host_and_port()
+        worker._done = True
+        worker.run()
         self.assertNotEquals(worker._port, None)
 
 
index c28b9113738e2f8ff883e2a000f6601345822a3a..6b0e3677d9aa6c3147138925a2d411005381eccc 100755 (executable)
@@ -85,7 +85,7 @@ def lint(port, options, expectations_class):
 def run(port, options, args, regular_output=sys.stderr, buildbot_output=sys.stdout):
     warnings = _set_up_derived_options(port, options)
 
-    printer = printing.Printer(port, options, regular_output, buildbot_output, logger=logging.getLogger())
+    printer = printing.Printer(port, options, regular_output, buildbot_output, configure_logging=True)
 
     for warning in warnings:
         _log.warning(warning)
@@ -479,7 +479,6 @@ def main():
         host = Host()
     host._initialize_scm()
     port = host.port_factory.get(options.platform, options)
-    logging.getLogger().setLevel(logging.DEBUG if options.verbose else logging.INFO)
     return run(port, options, args)
 
 
index dfa49e4e810fb6c7c52398e78a5f3a2d6d642953..b5c233b106a73e04a63540434e52fd54a6dab9b9 100644 (file)
@@ -1,5 +1,5 @@
 #!/usr/bin/env python
-# Copyright (C) 2010, 2012 Google Inc. All rights reserved.
+# Copyright (C) 2010 Google Inc. All rights reserved.
 #
 # Redistribution and use in source and binary forms, with or without
 # modification, are permitted provided that the following conditions are
 # (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
 # OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
 
-import logging
-import os
-import sys
-import time
-
-
-LOG_HANDLER_NAME = 'MeteredStreamLogHandler'
-
-
-class MeteredStream(object):
-    """
-    This class implements a stream wrapper that has 'meters' as well as
-    regular output. A 'meter' is a single line of text that can be erased
-    and rewritten repeatedly, without producing multiple lines of output. It
-    can be used to produce effects like progress bars.
-    """
-
-    @staticmethod
-    def _erasure(txt):
-        num_chars = len(txt)
-        return '\b' * num_chars + ' ' * num_chars + '\b' * num_chars
-
-    @staticmethod
-    def _ensure_newline(txt):
-        return txt if txt.endswith('\n') else txt + '\n'
-
-    def __init__(self, stream=None, verbose=False, logger=None, time_fn=None, pid=None):
-        self._stream = stream or sys.stderr
-        self._verbose = verbose
-        self._time_fn = time_fn or time.time
-        self._pid = pid or os.getpid()
-
-        self._isatty = self._stream.isatty()
-        self._erasing = self._isatty and not verbose
-        self._last_partial_line = ''
-        self._last_write_time = 0.0
-        self._throttle_delay_in_secs = 0.066 if self._erasing else 10.0
-
-        self._logger = logger
-        self._log_handler = None
-        if self._logger:
-            log_level = logging.DEBUG if verbose else logging.INFO
-            self._log_handler = _LogHandler(self)
-            self._log_handler.setLevel(log_level)
-            self._logger.addHandler(self._log_handler)
-
-    def __del__(self):
-        self.cleanup()
-
-    def cleanup(self):
-        if self._logger:
-            self._logger.removeHandler(self._log_handler)
-            self._log_handler = None
-
-    def write_throttled_update(self, txt):
-        now = self._time_fn()
-        if now - self._last_write_time >= self._throttle_delay_in_secs:
-            self.write_update(txt, now)
-
-    def write_update(self, txt, now=None):
-        self.write(txt, now)
-        if self._erasing:
-            self._last_partial_line = txt[txt.rfind('\n') + 1:]
-
-    def write(self, txt, now=None):
-        now = now or self._time_fn()
-        self._last_write_time = now
-        if self._last_partial_line:
-            self._erase_last_partial_line()
-        if self._verbose:
-            now_tuple = time.localtime(now)
-            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))
-        elif self._isatty:
-            msg = txt
-        else:
-            msg = self._ensure_newline(txt)
-
-        self._stream.write(msg)
-
-    def writeln(self, txt, now=None):
-        self.write(self._ensure_newline(txt), now)
-
-    def _erase_last_partial_line(self):
-        num_chars = len(self._last_partial_line)
-        self._stream.write(self._erasure(self._last_partial_line))
-        self._last_partial_line = ''
-
-
-class _LogHandler(logging.Handler):
-    def __init__(self, meter):
-        logging.Handler.__init__(self)
-        self._meter = meter
-        self._name = LOG_HANDLER_NAME
-
-    def emit(self, record):
-        self._meter.writeln(record.msg, record.created)
+"""
+Package that implements a stream wrapper that has 'meters' as well as
+regular output. A 'meter' is a single line of text that can be erased
+and rewritten repeatedly, without producing multiple lines of output. It
+can be used to produce effects like progress bars.
+
+This package should only be called by the printing module in the layout_tests
+package.
+"""
+
+
+class MeteredStream:
+    """This class is a wrapper around a stream that allows you to implement
+    meters (progress bars, etc.).
+
+    It can be used directly as a stream, by calling write(), but also provides
+    a method called update() that will overwite prior updates().
+   """
+
+    def __init__(self, stream):
+        """
+        Args:
+          stream: output stream to write to
+        """
+        self._stream = stream
+        self._dirty = False
+        self._last_update = ""
+
+    def write(self, txt):
+        """Write to the stream, overwriting and resetting the meter."""
+
+        # This routine is called by the logging infrastructure, and
+        # must not call back into logging. It is not a public function.
+        self._overwrite(txt)
+        self._reset()
+
+    def update(self, txt):
+        """Write a message that will be overwritten by subsequent update() or write() calls."""
+        self._overwrite(txt)
+
+    def _overwrite(self, txt):
+        # Print the necessary number of backspaces to erase the previous
+        # message.
+        if len(self._last_update):
+            self._stream.write("\b" * len(self._last_update) +
+                               " " * len(self._last_update) +
+                               "\b" * len(self._last_update))
+        self._stream.write(txt)
+        last_newline = txt.rfind("\n")
+        self._last_update = txt[(last_newline + 1):]
+        self._dirty = True
+
+    def _reset(self):
+        self._dirty = False
+        self._last_update = ''
index 4b376460bfb1b14b4f6bf16383f73e3dec3b71e4..359cfcf60f1393430dbcd3af1c7b1092dedd1329 100644 (file)
@@ -1,5 +1,5 @@
 #!/usr/bin/python
-# Copyright (C) 2010, 2012 Google Inc. All rights reserved.
+# Copyright (C) 2010 Google Inc. All rights reserved.
 #
 # Redistribution and use in source and binary forms, with or without
 # modification, are permitted provided that the following conditions are
 # (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
 # OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
 
-import logging
-import re
 import StringIO
 import unittest
 
 from webkitpy.layout_tests.views.metered_stream import MeteredStream
 
 
-class RegularTest(unittest.TestCase):
-    verbose = False
-    isatty = False
-
-    def setUp(self):
-        self.stream = StringIO.StringIO()
-        self.buflist = self.stream.buflist
-        self.stream.isatty = lambda: self.isatty
-
-        # configure a logger to test that log calls do normally get included.
-        self.logger = logging.getLogger(__name__)
-        self.logger.setLevel(logging.DEBUG)
-        self.logger.propagate = False
-
-        # add a dummy time counter for a default behavior.
-        self.times = range(10)
-
-        self.meter = MeteredStream(self.stream, self.verbose, self.logger, self.time_fn, 8675)
-
-    def tearDown(self):
-        if self.meter:
-            self.meter.cleanup()
-            self.meter = None
-
-    def time_fn(self):
-        return self.times.pop(0)
-
-    def test_logging_not_included(self):
-        # This tests that if we don't hand a logger to the MeteredStream,
-        # nothing is logged.
-        logging_stream = StringIO.StringIO()
-        handler = logging.StreamHandler(logging_stream)
-        root_logger = logging.getLogger()
-        orig_level = root_logger.level
-        root_logger.addHandler(handler)
-        root_logger.setLevel(logging.DEBUG)
-        try:
-            self.meter = MeteredStream(self.stream, self.verbose, None, self.time_fn, 8675)
-            self.meter.write_throttled_update('foo')
-            self.meter.write_update('bar')
-            self.meter.write('baz')
-            self.assertEquals(logging_stream.buflist, [])
-        finally:
-            root_logger.removeHandler(handler)
-            root_logger.setLevel(orig_level)
-
-    def _basic(self, times):
-        self.times = times
-        self.meter.write_update('foo')
-        self.meter.write_update('bar')
-        self.meter.write_throttled_update('baz')
-        self.meter.write_throttled_update('baz 2')
-        self.meter.writeln('done')
-        self.assertEquals(self.times, [])
-        return self.buflist
-
-    def test_basic(self):
-        buflist = self._basic([0, 1, 2, 13, 14])
-        self.assertEquals(buflist, ['foo\n', 'bar\n', 'baz 2\n', 'done\n'])
-
-    def _log_after_update(self):
-        self.meter.write_update('foo')
-        self.logger.info('bar')
-        return self.buflist
-
-    def test_log_after_update(self):
-        buflist = self._log_after_update()
-        self.assertEquals(buflist, ['foo\n', 'bar\n'])
-
-
-class TtyTest(RegularTest):
-    verbose = False
-    isatty = True
-
-    def test_basic(self):
-        buflist = self._basic([0, 1, 1.05, 1.1, 2])
-        self.assertEquals(buflist, ['foo',
-                                     MeteredStream._erasure('foo'), 'bar',
-                                     MeteredStream._erasure('bar'), 'baz 2',
-                                     MeteredStream._erasure('baz 2'), 'done\n'])
-
-    def test_log_after_update(self):
-        buflist = self._log_after_update()
-        self.assertEquals(buflist, ['foo',
-                                     MeteredStream._erasure('foo'), 'bar\n'])
-
-
-class VerboseTest(RegularTest):
-    isatty = False
-    verbose = True
-
-    def test_basic(self):
-        buflist = self._basic([0, 1, 2.1, 13, 14.1234])
-        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'])
-
-    def test_log_after_update(self):
-        buflist = self._log_after_update()
-        self.assertEquals(buflist[0], '16:00:00.000 8675 foo\n')
-
-        # The second argument should have a real timestamp and pid, so we just check the format.
-        self.assertEquals(len(buflist), 2)
-        self.assertTrue(re.match('\d\d:\d\d:\d\d.\d\d\d \d+ bar\n', buflist[1]))
+class TestMeteredStream(unittest.TestCase):
+    def test_regular(self):
+        a = StringIO.StringIO()
+        m = MeteredStream(a)
+        self.assertFalse(a.getvalue())
+
+        # basic test
+        m.write("foo")
+        exp = ['foo']
+        self.assertEquals(a.buflist, exp)
+
+        # now check that a second write() does not overwrite the first.
+        m.write("bar")
+        exp.append('bar')
+        self.assertEquals(a.buflist, exp)
+
+        m.update("batter")
+        exp.append('batter')
+        self.assertEquals(a.buflist, exp)
+
+        # The next update() should overwrite the laste update() but not the
+        # other text. Note that the cursor is effectively positioned at the
+        # end of 'foo', even though we had to erase three more characters.
+        m.update("foo")
+        exp.append('\b\b\b\b\b\b      \b\b\b\b\b\b')
+        exp.append('foo')
+        self.assertEquals(a.buflist, exp)
+
+        # now check that a write() does overwrite the update
+        m.write("foo")
+        exp.append('\b\b\b   \b\b\b')
+        exp.append('foo')
+        self.assertEquals(a.buflist, exp)
+
+        # Now test that we only back up to the most recent newline.
+
+        # Note also that we do not back up to erase the most recent write(),
+        # i.e., write()s do not get erased.
+        a = StringIO.StringIO()
+        m = MeteredStream(a)
+        m.update("foo\nbar")
+        m.update("baz")
+        self.assertEquals(a.buflist, ['foo\nbar', '\b\b\b   \b\b\b', 'baz'])
 
 
 if __name__ == '__main__':
index 3df2956c182618ed0dcf13ed6f185e510e487fba..750c48df9e309534602a8850786c33103c8f0a67 100644 (file)
@@ -1,5 +1,5 @@
 #!/usr/bin/env python
-# Copyright (C) 2010, 2012 Google Inc. All rights reserved.
+# Copyright (C) 2010 Google Inc. All rights reserved.
 #
 # Redistribution and use in source and binary forms, with or without
 # modification, are permitted provided that the following conditions are
 
 """Package that handles non-debug, non-file output for run-webkit-tests."""
 
+import logging
 import optparse
+import time
 
 from webkitpy.common.net import resultsjsonparser
-from webkitpy.layout_tests.models.test_expectations import TestExpectations
 from webkitpy.layout_tests.views.metered_stream import MeteredStream
+from webkitpy.layout_tests.models.test_expectations import TestExpectations
+
+
+_log = logging.getLogger(__name__)
+
 
 NUM_SLOW_TESTS_TO_LOG = 10
+FAST_UPDATES_SECONDS = 0.03
+SLOW_UPDATES_SECONDS = 10.0
 
 PRINT_DEFAULT = "misc,one-line-progress,one-line-summary,unexpected,unexpected-results,updates"
 PRINT_EVERYTHING = "actual,config,expected,misc,one-line-progress,one-line-summary,slowest,timing,unexpected,unexpected-results,updates"
@@ -146,6 +154,27 @@ def parse_print_options(print_options, verbose):
     return switches
 
 
+def _configure_logging(stream, verbose):
+    log_fmt = '%(message)s'
+    log_datefmt = '%y%m%d %H:%M:%S'
+    log_level = logging.INFO
+    if verbose:
+        log_fmt = '%(asctime)s %(process)d %(filename)s:%(lineno)d %(levelname)s %(message)s'
+        log_level = logging.DEBUG
+
+    root = logging.getLogger()
+    handler = logging.StreamHandler(stream)
+    handler.setFormatter(logging.Formatter(log_fmt, None))
+    root.addHandler(handler)
+    root.setLevel(log_level)
+    return handler
+
+
+def _restore_logging(handler_to_remove):
+    root = logging.getLogger()
+    root.handlers.remove(handler_to_remove)
+
+
 class Printer(object):
     """Class handling all non-debug-logging printing done by run-webkit-tests.
 
@@ -158,7 +187,7 @@ class Printer(object):
 
     By default the buildbot-parsed code gets logged to stdout, and regular
     output gets logged to stderr."""
-    def __init__(self, port, options, regular_output, buildbot_output, logger=None):
+    def __init__(self, port, options, regular_output, buildbot_output, configure_logging):
         """
         Args
           port               interface to port-specific routines
@@ -167,16 +196,37 @@ class Printer(object):
                              should be written
           buildbot_output    stream to which output intended to be read by
                              the buildbots (and humans) should be written
-          logger             optional logger to integrate into the stream.
+          configure_loggign  Whether a logging handler should be registered
+
         """
         self._port = port
         self._options = options
+        self._stream = regular_output
         self._buildbot_stream = buildbot_output
-        self._meter = MeteredStream(regular_output, options.verbose, logger=logger)
+        self._meter = None
+
+        # These are used for --print one-line-progress
+        self._last_remaining = None
+        self._last_update_time = None
+
         self.switches = parse_print_options(options.print_options, options.verbose)
 
+        self._logging_handler = None
+        if self._stream.isatty() and not options.verbose:
+            self._update_interval_seconds = FAST_UPDATES_SECONDS
+            self._meter = MeteredStream(self._stream)
+            if configure_logging:
+                self._logging_handler = _configure_logging(self._meter, options.verbose)
+        else:
+            self._update_interval_seconds = SLOW_UPDATES_SECONDS
+            if configure_logging:
+                self._logging_handler = _configure_logging(self._stream, options.verbose)
+
     def cleanup(self):
-        self._meter.cleanup()
+        """Restore logging configuration to its initial settings."""
+        if self._logging_handler:
+            _restore_logging(self._logging_handler)
+            self._logging_handler = None
 
     def __del__(self):
         self.cleanup()
@@ -300,19 +350,27 @@ class Printer(object):
         if self.disabled('one-line-progress'):
             return
 
-        if result_summary.remaining == 0:
-            self._meter.write_update('')
+        now = time.time()
+        if self._last_update_time is None:
+            self._last_update_time = now
+
+        time_since_last_update = now - self._last_update_time
+        if time_since_last_update <= self._update_interval_seconds:
             return
 
+        self._last_update_time = now
+
         percent_complete = 100 * (result_summary.expected +
             result_summary.unexpected) / result_summary.total
         action = "Testing"
         if retrying:
             action = "Retrying"
+        self._update("%s (%d%%): %d ran as expected, %d didn't, %d left" %
+                     (action, percent_complete, result_summary.expected,
+                      result_summary.unexpected, result_summary.remaining))
 
-        self._meter.write_throttled_update("%s (%d%%): %d ran as expected, %d didn't, %d left" %
-            (action, percent_complete, result_summary.expected,
-             result_summary.unexpected, result_summary.remaining))
+        if result_summary.remaining == 0:
+            self._update('')
 
     def print_unexpected_results(self, unexpected_results):
         """Prints a list of the unexpected results to the buildbot stream."""
@@ -400,7 +458,7 @@ class Printer(object):
     def print_update(self, msg):
         if self.disabled('updates'):
             return
-        self._meter.write_update(msg)
+        self._update(msg)
 
     def write(self, msg, option="misc"):
         if self.disabled(option):
@@ -408,4 +466,10 @@ class Printer(object):
         self._write(msg)
 
     def _write(self, msg):
-        self._meter.writeln(msg)
+        _log.info(msg)
+
+    def _update(self, msg):
+        if self._meter:
+            self._meter.update(msg)
+        else:
+            self._write(msg)
index 8777fd8d6e322ba6de2357c444c88ee6861dd33b..6899d2c5d4cdb0452709cd4df0ed9691fc5baf7d 100644 (file)
@@ -1,5 +1,5 @@
 #!/usr/bin/python
-# Copyright (C) 2010, 2012 Google Inc. All rights reserved.
+# Copyright (C) 2010 Google Inc. All rights reserved.
 #
 # Redistribution and use in source and binary forms, with or without
 # modification, are permitted provided that the following conditions are
@@ -29,6 +29,7 @@
 
 """Unit tests for printing.py."""
 
+import logging
 import optparse
 import StringIO
 import time
@@ -53,6 +54,35 @@ def get_options(args):
 
 
 class TestUtilityFunctions(unittest.TestCase):
+    def assertEmpty(self, stream):
+        self.assertFalse(stream.getvalue())
+
+    def assertNotEmpty(self, stream):
+        self.assertTrue(stream.getvalue())
+
+    def assertWritten(self, stream, contents):
+        self.assertEquals(stream.buflist, contents)
+
+    def test_configure_logging(self):
+        options, args = get_options([])
+        stream = StringIO.StringIO()
+        handler = printing._configure_logging(stream, options.verbose)
+        logging.info("this should be logged")
+        self.assertNotEmpty(stream)
+
+        stream = StringIO.StringIO()
+        logging.debug("this should not be logged")
+        self.assertEmpty(stream)
+
+        printing._restore_logging(handler)
+
+        stream = StringIO.StringIO()
+        options, args = get_options(['--verbose'])
+        handler = printing._configure_logging(stream, options.verbose)
+        logging.debug("this should be logged")
+        self.assertNotEmpty(stream)
+        printing._restore_logging(handler)
+
     def test_print_options(self):
         options, args = get_options([])
         self.assertTrue(options is not None)
@@ -114,7 +144,8 @@ class  Testprinter(unittest.TestCase):
         regular_output = StringIO.StringIO()
         regular_output.isatty = lambda: tty
         buildbot_output = StringIO.StringIO()
-        printer = printing.Printer(self._port, options, regular_output, buildbot_output)
+        printer = printing.Printer(self._port, options, regular_output,
+                                   buildbot_output, configure_logging=True)
         return printer, regular_output, buildbot_output
 
     def get_result(self, test_name, result_type=test_expectations.PASS, run_time=0):
@@ -319,7 +350,7 @@ class  Testprinter(unittest.TestCase):
                  'failures/expected/crash.html']
         paths, rs, exp = self.get_result_summary(tests, expectations)
 
-        # First, test that we print nothing when we shouldn't print anything.
+        # First, test that we print nothing.
         printer.print_progress(rs, False, paths)
         self.assertEmpty(out)
         self.assertEmpty(err)
@@ -328,28 +359,55 @@ class  Testprinter(unittest.TestCase):
         self.assertEmpty(out)
         self.assertEmpty(err)
 
-        # Now test that we do print things.
-        printer, err, out = self.get_printer(['--print', 'one-line-progress'])
-        printer.print_progress(rs, False, paths)
-        self.assertEmpty(out)
-        self.assertNotEmpty(err)
-
-        printer, err, out = self.get_printer(['--print', 'one-line-progress'])
-        printer.print_progress(rs, True, paths)
-        self.assertEmpty(out)
-        self.assertNotEmpty(err)
-
-        printer, err, out = self.get_printer(['--print', 'one-line-progress'])
-        rs.remaining = 0
-        printer.print_progress(rs, False, paths)
-        self.assertEmpty(out)
-        self.assertNotEmpty(err)
-
-        printer.print_progress(rs, True, paths)
-        self.assertEmpty(out)
-        self.assertNotEmpty(err)
-
-
+        self.times = [1, 2, 12, 13, 14, 23, 33]
+
+        def mock_time():
+            return self.times.pop(0)
+
+        orig_time = time.time
+        try:
+            time.time = mock_time
+
+            # Test printing progress updates to a file.
+            printer, err, out = self.get_printer(['--print', 'one-line-progress'])
+            printer.print_progress(rs, False, paths)
+            printer.print_progress(rs, False, paths)
+            self.assertEmpty(out)
+            self.assertEmpty(err)
+
+            printer.print_progress(rs, False, paths)
+            self.assertEmpty(out)
+            self.assertNotEmpty(err)
+
+            self.reset(err)
+            self.reset(out)
+            printer.print_progress(rs, True, paths)
+            self.assertEmpty(out)
+            self.assertEmpty(err)
+
+            printer.print_progress(rs, True, paths)
+            self.assertEmpty(out)
+            self.assertNotEmpty(err)
+
+            # Now reconfigure the printer to test printing to a TTY instead of a file.
+            self.times = [1, 1.01, 2, 3]
+            printer, err, out = self.get_printer(['--print', 'one-line-progress'], tty=True)
+            printer.print_progress(rs, False, paths)
+            printer.print_progress(rs, False, paths)
+            self.assertEmpty(out)
+            self.assertEmpty(err)
+
+            printer.print_progress(rs, False, paths)
+            self.assertEmpty(out)
+            self.assertNotEmpty(err)
+
+            self.reset(err)
+            self.reset(out)
+            printer.print_progress(rs, True, paths)
+            self.assertEmpty(out)
+            self.assertNotEmpty(err)
+        finally:
+            time.time = orig_time
 
     def test_write_nothing(self):
         printer, err, out = self.get_printer(['--print', 'nothing'])
index db15eb38ab7f19850ae6f899425f31eaa75c4d81..ce1c7e90385324cb56ddd86091f481f637616d9f 100644 (file)
@@ -62,7 +62,7 @@ class PerfTestsRunner(object):
             self._host = Host()
             self._port = self._host.port_factory.get(self._options.platform, self._options)
         self._host._initialize_scm()
-        self._printer = printing.Printer(self._port, self._options, regular_output, buildbot_output)
+        self._printer = printing.Printer(self._port, self._options, regular_output, buildbot_output, configure_logging=False)
         self._webkit_base_dir_len = len(self._port.webkit_base())
         self._base_path = self._port.perf_tests_dir()
         self._results = {}
index c5891d401361fec91c7103507219eca81d1012d7..1a287a7cf6ada3ca8b9bab646428748b0294e4e6 100755 (executable)
@@ -182,8 +182,7 @@ max 1120
                 TestDriverWithStartCount.start_count += 1
 
         buildbot_output = StringIO.StringIO()
-        regular_output = StringIO.StringIO()
-        runner = self.create_runner(buildbot_output, args=["--pause-before-testing"], regular_output=regular_output, driver_class=TestDriverWithStartCount)
+        runner = self.create_runner(buildbot_output, args=["--pause-before-testing"], driver_class=TestDriverWithStartCount)
 
         dirname = runner._base_path + '/inspector/'
         tests = [dirname + 'pass.html']
@@ -194,9 +193,9 @@ max 1120
             unexpected_result_count = runner._run_tests_set(tests, runner._port)
             self.assertEqual(TestDriverWithStartCount.start_count, 1)
         finally:
-            _, stderr, _ = output.restore_output()
+            _, stderr, logs = output.restore_output()
             self.assertEqual(stderr, "Ready to run test?\n")
-            self.assertTrue("Running inspector/pass.html (1 of 1)" in regular_output.getvalue())
+            self.assertTrue("Running inspector/pass.html (1 of 1)" in logs)
 
     def test_run_test_set_for_parser_tests(self):
         buildbot_output = StringIO.StringIO()