Merge lp:~sinzui/launchpad/prf-connection-0 into lp:launchpad

[Curtis Hovey]

Recover from an open() failure when the product-release-finder calls walk().

    Launchpad bug: https://bugs.launchpad.net/bugs/717363
    Pre-implementation: no one
    Test command: ./bin/test -vv -t test_prf_walker

The product release finder failed on the first use the an FTPWalker. This is
probably an operational issue where the site or the port is blocked.
Regardless of the connectivity issue, the PRF should not fail.

From the prf log:
2011-02-11 07:22:36 INFO Connecting to ftp.gnu.org
2011-02-11 07:22:36 ERROR Unhandled exception

From the tb in the librarian
  File "/srv/launchpad.net/production/launchpad-rev-12335/lib/lp/registry/scripts/productreleasefinder/walker.py", line 126, in walk
    self.open()
  File "/srv/launchpad.net/production/launchpad-rev-12335/lib/lp/registry/scripts/productreleasefinder/walker.py", line 206, in open
    self.ftp.connect(self.host)
  File "/usr/lib/python2.6/ftplib.py", line 131, in connect
    self.sock = socket.create_connection((self.host, self.port), self.timeout)
  File "/usr/lib/python2.6/socket.py", line 514, in create_connection
    raise error, msg
error: [Errno 111] Connection refused

--------------------------------------------------------------------

RULES

    * Catch the exception raise by self.open(), log the issue and return
      early.
    * ADDENDUM: The local imports are not needed in the tests now that
      cyclic import issues were fixed.

QA

    If ftp.gnu.org is blocking Lp:
        * Run the product-release finder on staging and verify that the PRF
          completes. (The production instance is dying in the first 5 minutes).
    otherwise:
        * Hope for the best.

LINT

    lib/lp/registry/scripts/productreleasefinder/walker.py
    lib/lp/registry/tests/test_prf_walker.py

^ lint hates the long lines in the test data. I can clean this up, but I think
it will make the test more difficult to read, so I chose it ignore it.

IMPLEMENTATION

I removed the local import from the test. I added a new test to instrument
an exception from open(). The prf often checks for (IOError, socket.error)
though I believe that in the known case, only socket.error will be raised.
I also fixed some deprecated uses of raise reported by lint.
    lib/lp/registry/scripts/productreleasefinder/walker.py
    lib/lp/registry/tests/test_prf_walker.py

[Benji York (benji)]

Approved* (Brad will have to review my review since I'm doing mentored
reviews.)

The test (like the rest of the branch) is nice and clean. I almost
suggested using list(walker) instead of the (apparently) do-nothing
loop, but I'm not sure if using list() is just clearer to me and most
people would understand the intent of the current code better.

I especially like the fact that the WalkerBase import can be moved to
the top of the test module. Much nicer now.

review: Approve (code*)

[Brad Crittenden (bac)]

I agree with Benji's suggestion to use list() as the dummy loop looks a bit silly. Using list() with a comment is even better:

# Listify the walker generator, which will log the expected error.
list(walker)

And thanks a zillion for the clean up!

review: Approve (code)

[Robert Collins (lifeless)]

You should either log an error (if we want OOPS for these - we
probably don't as they are user data : but how will users debug a
fail? - I think we need a new bug for that), or log the exception in
the message so that someone reading the log can determine the error it
experienced.

[Curtis Hovey (sinzui)]

We do not want to log an error for user data: The issue of getting feedback is covered in bug 70524. It is out of scope for this issue.

[Robert Collins (lifeless)]

On Sat, Feb 12, 2011 at 10:29 AM, Curtis Hovey
<email address hidden> wrote:
> We do not want to log an error for user data: The issue of getting feedback is covered in bug 70524. It is out of scope for this issue.

Agreed; am glad there is a bug already. But we should log /what the
error was/ not just that there was an error. e.g

except (IOError, OSError), e:
   log("failure %s" % e)

(done minimally here)

[Curtis Hovey (sinzui)]

Agreed and done.

=== modified file 'lib/lp/registry/scripts/productreleasefinder/walker.py'
--- lib/lp/registry/scripts/productreleasefinder/walker.py	2010-08-20 20:31:18 +0000
+++ lib/lp/registry/scripts/productreleasefinder/walker.py	2011-02-12 00:03:40 +0000
@@ -1,4 +1,4 @@
-# Copyright 2009 Canonical Ltd.  This software is licensed under the
+# Copyright 2009-2011 Canonical Ltd.  This software is licensed under the
 # GNU Affero General Public License version 3 (see the file LICENSE).
 
 """HTTP and FTP walker.
@@ -92,7 +92,7 @@
         (scheme, netloc, path, query, fragment) \
                  = urlsplit(base, self.URL_SCHEMES[0], self.FRAGMENTS)
         if scheme not in self.URL_SCHEMES:
-            raise WalkerError, "Can't handle %s scheme" % scheme
+            raise WalkerError("Can't handle %s scheme" % scheme)
         self.scheme = scheme
         self.full_netloc = netloc
 
@@ -123,7 +123,12 @@
         Yields (dirpath, dirnames, filenames) for each path under the base;
         dirnames can be modified as with os.walk.
         """
-        self.open()
+        try:
+            self.open()
+        except (IOError, socket.error), e:
+            self.log.info("Could not connect to %s" % self.base)
+            self.log.info("Failure: %s" % e)
+            return
 
         subdirs = [self.path]
         while len(subdirs):
@@ -423,7 +428,8 @@
     elif scheme in ["file"]:
         return os.walk(path)
     else:
-        raise WalkerError, "Unknown scheme: %s" % scheme
+        raise WalkerError("Unknown scheme: %s" % scheme)
+
 
 def combine_url(base, subdir, filename):
     """Combine a URL from the three parts returned by walk()."""

=== modified file 'lib/lp/registry/tests/test_prf_walker.py'
--- lib/lp/registry/tests/test_prf_walker.py	2010-08-20 20:31:18 +0000
+++ lib/lp/registry/tests/test_prf_walker.py	2011-02-12 00:03:40 +0000
@@ -1,4 +1,4 @@
-# Copyright 2009 Canonical Ltd.  This software is licensed under the
+# Copyright 2009-2011 Canonical Ltd.  This software is licensed under the
 # GNU Affero General Public License version 3 (see the file LICENSE).
 
 """Tests for lp.registry.scripts.productreleasefinder.walker."""
@@ -8,8 +8,10 @@
 import unittest
 import urlparse
 
+
 from canonical.lazr.utils import safe_hasattr
 from canonical.testing import reset_logging
+from lp.registry.scripts.productreleasefinder.walker import WalkerBase
 from lp.testing import TestCase
 
 
@@ -17,16 +19,12 @@
 
     def testCreatesDefaultLogger(self):
         """WalkerBase creates a default logger."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         from logging import Logger
         w = WalkerBase("/")
         self.failUnless(isinstance(w.log, Logger))
 
     def testCreatesChildLogger(self):
         """WalkerBase creates a child logger if given a parent."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         from logging import getLogger
         parent = getLogger("foo")
         w = WalkerBase("/", log_parent=parent)
@@ -37,29 +35,21 @@
 
     def testSetsBase(self):
         """WalkerBase sets the base property."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         w = WalkerBase("ftp://localhost/")
         self.assertEquals(w.base, "ftp://localhost/")
 
     def testSetsScheme(self):
         """WalkerBase sets the scheme property."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         w = WalkerBase("ftp://localhost/")
         self.assertEquals(w.scheme, "ftp")
 
     def testSetsHost(self):
         """WalkerBase sets the host property."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         w = WalkerBase("ftp://localhost/")
         self.assertEquals(w.host, "localhost")
 
     def testNoScheme(self):
         """WalkerBase works when given a URL with no scheme."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         w = WalkerBase("/")
         self.assertEquals(w.host, "")
 
@@ -71,45 +61,33 @@
 
     def testUnescapesHost(self):
         """WalkerBase unescapes the host portion."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         w = WalkerBase("ftp://local%40host/")
         self.assertEquals(w.host, "local@host")
 
     def testNoUsername(self):
         """WalkerBase stores None when there is no username."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         w = WalkerBase("ftp://localhost/")
         self.assertEquals(w.user, None)
 
     def testUsername(self):
         """WalkerBase splits out the username from the host portion."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         w = WalkerBase("ftp://scott@localhost/")
         self.assertEquals(w.user, "scott")
         self.assertEquals(w.host, "localhost")
 
     def testUnescapesUsername(self):
         """WalkerBase unescapes the username portion."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         w = WalkerBase("ftp://scott%3awibble@localhost/")
         self.assertEquals(w.user, "scott:wibble")
         self.assertEquals(w.host, "localhost")
 
     def testNoPassword(self):
         """WalkerBase stores None when there is no password."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         w = WalkerBase("ftp://scott@localhost/")
         self.assertEquals(w.passwd, None)
 
     def testPassword(self):
         """WalkerBase splits out the password from the username."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         w = WalkerBase("ftp://scott:wibble@localhost/")
         self.assertEquals(w.user, "scott")
         self.assertEquals(w.passwd, "wibble")
@@ -117,8 +95,6 @@
 
     def testUnescapesPassword(self):
         """WalkerBase unescapes the password portion."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         w = WalkerBase("ftp://scott:wibble%20wobble@localhost/")
         self.assertEquals(w.user, "scott")
         self.assertEquals(w.passwd, "wibble wobble")
@@ -126,43 +102,31 @@
 
     def testPathOnly(self):
         """WalkerBase stores the path if that's all there is."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         w = WalkerBase("/path/to/something/")
         self.assertEquals(w.path, "/path/to/something/")
 
     def testPathInUrl(self):
         """WalkerBase stores the path portion of a complete URL."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         w = WalkerBase("ftp://localhost/path/to/something/")
         self.assertEquals(w.path, "/path/to/something/")
 
     def testAddsSlashToPath(self):
         """WalkerBase adds a trailing slash to path if ommitted."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         w = WalkerBase("ftp://localhost/path/to/something")
         self.assertEquals(w.path, "/path/to/something/")
 
     def testUnescapesPath(self):
         """WalkerBase leaves the path escaped."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         w = WalkerBase("ftp://localhost/some%20thing/")
         self.assertEquals(w.path, "/some%20thing/")
 
     def testStoresQuery(self):
         """WalkerBase stores the query portion of a supporting URL."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         w = WalkerBase("http://localhost/?foo")
         self.assertEquals(w.query, "foo")
 
     def testStoresFragment(self):
         """WalkerBase stores the fragment portion of a supporting URL."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
         WalkerBase.FRAGMENTS = True
         try:
             w = WalkerBase("http://localhost/#foo")
@@ -180,8 +144,6 @@
 
     def test_walk_UnicodeEncodeError(self):
         """Verify that a UnicodeEncodeError is logged."""
-        from lp.registry.scripts.productreleasefinder.walker import (
-            WalkerBase)
 
         class TestWalker(WalkerBase):
 
@@ -202,12 +164,37 @@
         logger.setLevel(logging.DEBUG)
         logger.addHandler(logging.StreamHandler(log_output))
         walker = TestWalker('http://example.org/foo', logger)
-        for dummy in walker:
-            pass
+        list(walker)
         self.assertEqual(
             "Unicode error parsing http://example.org/foo page '/foo/'\n",
             log_output.getvalue())
 
+    def test_walk_open_fail(self):
+        # The walker handles an exception raised during open().
+
+        class TestWalker(WalkerBase):
+
+            def list(self, sub_dir):
+                pass
+
+            def open(self):
+                raise IOError("Test failure.")
+
+            def close(self):
+                pass
+
+        log_output = StringIO.StringIO()
+        logger = logging.getLogger()
+        self.addCleanup(logger.setLevel, logger.level)
+        logger.setLevel(logging.DEBUG)
+        logger.addHandler(logging.StreamHandler(log_output))
+        walker = TestWalker('ftp://example.org/foo', logger)
+        list(walker)
+        self.assertEqual(
+            "Could not connect to ftp://example.org/foo\n"
+            "Failure: Test failure.\n",
+            log_output.getvalue())
+
 
 class FTPWalker_Base(TestCase):