Merge lp:~mars/launchpad/turn-on-windmill-debug-logging into lp:launchpad

[Māris Fogels]

Make the windmill test suite log debug messages to disk.

Hi,

This branch configures the windmill test suite to log debug messages to a file on disk.

Drive-by changes include removal of a long-released XXX, extraction of the windmill suite setup steps into their own methods, and a comment typo.

I manually tested this change to ensure that the suite still runs, and that the windmill log file is being overwritten properly. I also ensured that the logging framework is reset when the layer finishes.

Test command: bin/test -t test_title_inline_edit
Lint: none

Maris

[Paul Hummer (rockstar)]

<rockstar> mars, does reset_logging undo all of this logger buggery you're doing here?
<mars> rockstar, it does
<mars> rockstar, BaseLayer calls it as well, but I did this because it is more visible and explicit
<rockstar> mars, what does safe_hasattr do?
<mars> rockstar, doesn't eat exceptions. Builtin hasattr does (fun fun!)
<rockstar> mars, why not just use getattr?
<mars> rockstar, what line?
<mars> 96
<rockstar> mars, yes.
<mars> rockstar, it might be because hasattr will tell you that an attribute exists. getattr may return None, but you can't tell if that is the attribute's value, or the default argument.
<mars> or the default argument to getattr()
<rockstar> mars, okay. As long as you feel you're using the right call here, I'm happy with that.
<mars> rockstar, not my code, so it should work :)
<mars> rockstar, that is one of the code blocks I extracted into its own method
<mars> personal choice: I dislike 300 and 400 line method definitions, even if they are linear.
<mars> if there are comments that say "# now we do this" followed by "# then we do that", then it is pretty good sign that you can extract a method
<mars> but, like I said, that's personal preference
<rockstar> mars, I think you've made the code clearer by breaking it up.

review: Approve (code)

=== modified file 'lib/canonical/config/schema-lazr.conf'
--- lib/canonical/config/schema-lazr.conf	2010-05-06 20:08:41 +0000
+++ lib/canonical/config/schema-lazr.conf	2010-05-11 16:05:41 +0000
@@ -1929,8 +1929,15 @@
 [vhost.feeds]
 
 
+[windmill]
+# The location of the windmill server debug logs.  This will be written to
+# upon execution of the test suite.  Each test run overwrites the previous
+# log's contents.
+debug_log: /var/tmp/windmill-testrunner.log
+
+
 # Stubed Key server for test proposes, it's able to server
-# in SKS fortmat, a restricted set of keys. (fixed address at
+# in SKS format, a restricted set of keys. (fixed address at
 # localhost:11371)
 [zeca]
 # Directory to be created to store the pre-installed key-files

=== modified file 'lib/canonical/testing/__init__.py'
--- lib/canonical/testing/__init__.py	2009-08-10 22:08:05 +0000
+++ lib/canonical/testing/__init__.py	2010-05-11 16:05:41 +0000
@@ -32,10 +32,6 @@
     """Reset the logging system back to defaults
 
     Currently, defaults means 'the way the Z3 testrunner sets it up'
-
-    XXX: StuartBishop 2006-03-08 bug=39877:
-    We need isolation enforcement so that an error will be raised and
-    the test run stop if a test fails to reset the logging system.
     """
     # Remove all handlers from non-root loggers, and remove the loggers too.
     loggerDict = logging.Logger.manager.loggerDict

=== modified file 'lib/canonical/testing/layers.py'
--- lib/canonical/testing/layers.py	2010-04-23 18:53:53 +0000
+++ lib/canonical/testing/layers.py	2010-05-11 16:05:41 +0000
@@ -1870,26 +1870,13 @@
             # base_url. With no base_url, we can't create the config
             # file windmill needs.
             return
-        # If we're running in a bin/test sub-process, sys.stdin is
-        # replaced by FakeInputContinueGenerator, which doesn't have a
-        # fileno method. When Windmill starts Firefox,
-        # sys.stdin.fileno() is called, so we add such a method here, to
-        # prevent it from breaking. By returning None, we should ensure
-        # that it doesn't try to use the return value for anything.
-        if not safe_hasattr(sys.stdin, 'fileno'):
-            assert isinstance(sys.stdin, FakeInputContinueGenerator), (
-                "sys.stdin (%r) doesn't have a fileno method." % sys.stdin)
-            sys.stdin.fileno = lambda: None
-        # Windmill needs a config file on disk.
-        config_text = dedent("""\
-            START_FIREFOX = True
-            TEST_URL = '%s'
-            """ % cls.base_url)
-        cls.config_file = tempfile.NamedTemporaryFile(suffix='.py')
-        cls.config_file.write(config_text)
-        # Flush the file so that windmill can read it.
-        cls.config_file.flush()
-        os.environ['WINDMILL_CONFIG_FILE'] = cls.config_file.name
+
+        cls._fixStandardInputFileno()
+        cls._configureWindmillLogging()
+        cls._configureWindmillStartup()
+
+        # Tell windmill to start its browser and server.  Our testrunner will
+        # keep going, passing commands to the server for execution.
         cls.shell_objects = start_windmill()
 
         # Patch the config to provide the port number and not use https.
@@ -1916,6 +1903,7 @@
             # Close the file so that it gets deleted.
             cls.config_file.close()
         config.reloadConfig()
+        reset_logging()
 
     @classmethod
     @profiled
@@ -1924,3 +1912,59 @@
         # belong to Windmill, which will be cleaned up on layer
         # tear down.
         BaseLayer.disable_thread_check = True
+
+    @classmethod
+    def _fixStandardInputFileno(cls):
+        """Patch the STDIN fileno so Windmill doesn't break."""
+        # If we're running in a bin/test sub-process, sys.stdin is
+        # replaced by FakeInputContinueGenerator, which doesn't have a
+        # fileno method. When Windmill starts Firefox,
+        # sys.stdin.fileno() is called, so we add such a method here, to
+        # prevent it from breaking. By returning None, we should ensure
+        # that it doesn't try to use the return value for anything.
+        if not safe_hasattr(sys.stdin, 'fileno'):
+            assert isinstance(sys.stdin, FakeInputContinueGenerator), (
+                "sys.stdin (%r) doesn't have a fileno method." % sys.stdin)
+            sys.stdin.fileno = lambda: None
+
+    @classmethod
+    def _configureWindmillLogging(cls):
+        """Override the default windmill log handling."""
+        if not config.windmill.debug_log:
+            return
+
+        # Add a new log handler to capture all of the windmill testrunner
+        # output. This overrides windmill's own log handling, which we do not
+        # have direct access to.
+        # We'll overwrite the previous log contents to keep the disk usage
+        # low, and because the contents are only meant as an in-situ debugging
+        # aid.
+        filehandler = logging.FileHandler(config.windmill.debug_log, mode='w')
+        filehandler.setLevel(logging.NOTSET)
+        filehandler.setFormatter(
+            logging.Formatter(
+                "%(asctime)s - %(name)s - %(levelname)s - %(message)s"))
+        logging.getLogger('windmill').addHandler(filehandler)
+
+        # Make sure that everything sent to the windmill logger is captured.
+        # This works because windmill configures the root logger for its
+        # purposes, and we are pre-empting that by inserting a new logger one
+        # level higher in the logger chain.
+        logging.getLogger('windmill').setLevel(logging.NOTSET)
+
+    @classmethod
+    def _configureWindmillStartup(cls):
+        """Pass our startup parameters to the windmill server."""
+        # Windmill needs a config file on disk to load its settings from.
+        # There is no way to directly pass settings to the windmill test
+        # driver from out here.
+        config_text = dedent("""\
+            START_FIREFOX = True
+            TEST_URL = '%s'
+            CONSOLE_LOG_LEVEL = %d
+            """ % (cls.base_url, logging.NOTSET))
+        cls.config_file = tempfile.NamedTemporaryFile(suffix='.py')
+        cls.config_file.write(config_text)
+        # Flush the file so that windmill can read it.
+        cls.config_file.flush()
+        os.environ['WINDMILL_CONFIG_FILE'] = cls.config_file.name