Merge ~pappacena/turnip:fix-exception-reraising into turnip:master

[Thiago F. Pappacena]

Refactoring and improving logging on repo creation

[Colin Watson (cjwatson)]

review: Approve

dfad088... by Thiago F. Pappacena on 2020-09-30

Adding better explanation about reraising exception on repo creation

[Thiago F. Pappacena (pappacena)]

The problem seems to be affecting more users in production. I'll merge && QA this, and prepare a production deployment to get more information of what is happening there.

I couldn't reproduce the problem in QA env, nor locally (unless I explicitly raise an Exception on the repository creation), so I guess the best shot we have is adding more logs to production.

diff --git a/turnip/pack/git.py b/turnip/pack/git.py
index 4407085..9523337 100644
--- a/turnip/pack/git.py
+++ b/turnip/pack/git.py
@@ -11,6 +11,8 @@ from __future__ import (
 __metaclass__ = type
 
 
+import os
+import sys
 import uuid
 
 import six
@@ -528,26 +530,44 @@ class PackBackendProtocol(PackServerProtocol):
         xmlrpc_endpoint = config.get("virtinfo_endpoint")
         xmlrpc_timeout = int(config.get("virtinfo_timeout"))
         proxy = xmlrpc.Proxy(xmlrpc_endpoint, allowNone=True)
+        repo_path = compose_path(self.factory.root, pathname)
+        if clone_from:
+            clone_path = six.ensure_str(
+                compose_path(self.factory.root, clone_from))
+        else:
+            clone_path = None
         try:
-            repo_path = compose_path(self.factory.root, pathname)
-            if clone_from:
-                clone_path = six.ensure_str(
-                    compose_path(self.factory.root, clone_from))
-            else:
-                clone_path = None
+            self.log.info(
+                "Creating repository %s, clone of %s" %
+                (repo_path, clone_path))
             store.init_repo(six.ensure_str(repo_path), clone_path)
+            self.log.info(
+                "Confirming with Launchpad repo %s creation." % repo_path)
             yield proxy.callRemote(
                 "confirmRepoCreation", six.ensure_text(pathname),
                 auth_params).addTimeout(xmlrpc_timeout, default_reactor)
         except AlreadyExistsError:
             # Do not abort nor try to delete existing repositories.
+            self.log.info("Repository %s already exists." % repo_path)
             raise
-        except Exception:
+        except Exception as e:
+            t, v, tb = sys.exc_info()
+            self.log.info(
+                "Aborting on Launchpad repo %s creation: %s" % (repo_path, e))
             yield proxy.callRemote(
                 "abortRepoCreation", six.ensure_text(pathname),
                 auth_params).addTimeout(xmlrpc_timeout, default_reactor)
-            store.delete_repo(repo_path)
-            raise
+            if os.path.exists(repo_path):
+                self.log.info(
+                    "Deleting local repo creation attempt %s." % repo_path)
+                store.delete_repo(repo_path)
+            # Just using `raise` here could cause an error like "exceptions
+            # must be old-style classes or derived from BaseException,
+            # not NoneType", since proxy.callRemote and Twisted event loop
+            # could clean up the current exception. That's why we store
+            # current exception at the begining of the `except` block and
+            # reraise it here.
+            six.reraise(t, v, tb)
 
     def packetReceived(self, data):
         if self.expect_set_symbolic_ref:
diff --git a/turnip/pack/tests/test_git.py b/turnip/pack/tests/test_git.py
index d1a8162..c8e25c8 100644
--- a/turnip/pack/tests/test_git.py
+++ b/turnip/pack/tests/test_git.py
@@ -238,6 +238,8 @@ class TestPackBackendProtocol(TestCase):
         self.virtinfo.xmlrpc_confirmRepoCreation = mock.Mock(
             side_effect=Fault(1, "?"))
         store = mock.Mock()
+        # Make `init_repo` create a fake repo directory.
+        store.init_repo.side_effect = lambda path, clone: os.mkdir(path)
         self.useFixture(MonkeyPatch("turnip.pack.git.store", store))
 
         params = {b'host': b'example.com'}