Merge lp:~mwhudson/launchpad/back-off-failing-imports-bug-413637 into lp:launchpad

[Michael Hudson-Doyle]

Exponentially back off trying failing code imports before marking them failed.

This is a re-propose of https://code.edge.launchpad.net/~mwhudson/launchpad/back-off-failing-imports-bug-413637/+merge/21408

Hi there,

This small branch changes the code import system to exponentially back off on retrying code imports -- see the linked bug for more.

Currently it backs off so that it tries imports at 6, 12, 24 and 48 hours (for subversion) for a total of three and a bit days of trying before marking an import failed -- is that enough? It seems OK, though perhaps a bit on the low side, to me.

Cheers,
mwh

[Tim Penhey (thumper)]

> def newJob(code_import, interval=datetime.timedelta(0)):

Shouldn't we default the interval to None? Having objects as default args just makes me feel funny.
Actually you do use interval=None in the model class. Can you update the interface to match please?

review: Approve

=== modified file 'lib/lp/code/interfaces/codeimportjob.py'
--- lib/lp/code/interfaces/codeimportjob.py	2010-02-22 08:10:03 +0000
+++ lib/lp/code/interfaces/codeimportjob.py	2010-03-16 01:37:25 +0000
@@ -16,6 +16,8 @@
     'ICodeImportJobWorkflow',
     ]
 
+import datetime
+
 from zope.interface import Interface
 from zope.schema import Choice, Datetime, Int, Object, Text
 
@@ -137,13 +139,18 @@
 class ICodeImportJobWorkflow(Interface):
     """Utility to manage `CodeImportJob` objects through their life cycle."""
 
-    def newJob(code_import):
+    def newJob(code_import, interval=None):
         """Create a `CodeImportJob` associated with a reviewed `CodeImport`.
 
         Call this method from `CodeImport.updateFromData` when the
         review_status of `code_import` changes to REVIEWED.
 
         :param code_import: `CodeImport` object.
+        :param interval: Schedule the job this far ahead of the start of the
+            last update of this import.  Defaults to
+            ``code_import.effective_update_interval``.  This parameter is
+            ignored and the job scheduled for right now if this is the first
+            run of the import.
         :precondition: `code_import` has REVIEWED review_status.
         :precondition: `code_import` has no associated `CodeImportJob`.
         :return: A new `CodeImportJob` object associated to `code_import`.
@@ -218,9 +225,11 @@
             display for diagnostics. May be None.
         :precondition: `import_job`.state == RUNNING.
         :postcondition: `import_job` is deleted.
-        :postcondition: `code_import.import_job` is not None.
+        :postcondition: `code_import.import_job` is not None unless the job
+            has failed more than consecutive_failure_limit times in a row.
         :postcondition: `code_import.import_job.date_due` is
-            import_job.date_due + code_import.effective_update_interval`.
+            import_job.date_due + code_import.effective_update_interval`, with
+            scaling to retry failing imports less often.
         :postcondition: A `CodeImportResult` was created.
         :postcondition: A FINISH `CodeImportEvent` was created.
         """

=== modified file 'lib/lp/code/model/codeimportjob.py'
--- lib/lp/code/model/codeimportjob.py	2010-02-24 10:18:16 +0000
+++ lib/lp/code/model/codeimportjob.py	2010-03-16 01:37:25 +0000
@@ -10,6 +10,8 @@
     'CodeImportJobWorkflow',
     ]
 
+import datetime
+
 from sqlobject import ForeignKey, IntCol, SQLObjectNotFound, StringCol
 
 from zope.component import getUtility
@@ -140,7 +142,7 @@
 
     implements(ICodeImportJobWorkflow)
 
-    def newJob(self, code_import, date_due=None):
+    def newJob(self, code_import, interval=None):
         """See `ICodeImportJobWorkflow`."""
         assert code_import.review_status == CodeImportReviewStatus.REVIEWED, (
             "Review status of %s is not REVIEWED: %s" % (
@@ -149,23 +151,22 @@
             "Already associated to a CodeImportJob: %s" % (
             code_import.branch.unique_name))
 
+        if interval is None:
+            interval = code_import.effective_update_interval
+
         job = CodeImportJob(code_import=code_import, date_due=UTC_NOW)
 
-        if date_due is None:
-            # Find the most recent CodeImportResult for this CodeImport. We
-            # sort by date_created because we do not have an index on
-            # date_job_started in the database, and that should give the same
-            # sort order.
-            most_recent_result_list = list(CodeImportResult.selectBy(
-                code_import=code_import).orderBy(['-date_created']).limit(1))
+        # Find the most recent CodeImportResult for this CodeImport. We
+        # sort by date_created because we do not have an index on
+        # date_job_started in the database, and that should give the same
+        # sort order.
+        most_recent_result_list = list(CodeImportResult.selectBy(
+            code_import=code_import).orderBy(['-date_created']).limit(1))
 
-            if len(most_recent_result_list) != 0:
-                [most_recent_result] = most_recent_result_list
-                interval = code_import.effective_update_interval
-                date_due = most_recent_result.date_job_started + interval
-                job.date_due = max(job.date_due, date_due)
-        else:
-            job.date_due = date_due
+        if len(most_recent_result_list) != 0:
+            [most_recent_result] = most_recent_result_list
+            date_due = most_recent_result.date_job_started + interval
+            job.date_due = max(job.date_due, date_due)
 
         return job
 
@@ -281,15 +282,20 @@
         # If the import has failed too many times in a row, mark it as
         # FAILING.
         failure_limit = config.codeimport.consecutive_failure_limit
-        if code_import.consecutive_failure_count >= failure_limit:
+        failure_count = code_import.consecutive_failure_count
+        if failure_count >= failure_limit:
             code_import.updateFromData(
                 dict(review_status=CodeImportReviewStatus.FAILING), None)
+        elif status == CodeImportResultStatus.SUCCESS_PARTIAL:
+            interval = datetime.timedelta(0)
+        elif failure_count > 0:
+            interval = (code_import.effective_update_interval *
+                        (2 ** (failure_count - 1)))
+        else:
+            interval = code_import.effective_update_interval
         # Only start a new one if the import is still in the REVIEWED state.
         if code_import.review_status == CodeImportReviewStatus.REVIEWED:
-            extra = {}
-            if status == CodeImportResultStatus.SUCCESS_PARTIAL:
-                extra['date_due'] = UTC_NOW
-            self.newJob(code_import, **extra)
+            self.newJob(code_import, interval=interval)
         # If the status was successful, update date_last_successful.
         if status in [CodeImportResultStatus.SUCCESS,
                       CodeImportResultStatus.SUCCESS_NOCHANGE]:
@@ -321,7 +327,7 @@
             import_job, CodeImportResultStatus.RECLAIMED, None)
         # 3)
         if code_import.review_status == CodeImportReviewStatus.REVIEWED:
-            self.newJob(code_import, UTC_NOW)
+            self.newJob(code_import, datetime.timedelta(0))
         # 4)
         getUtility(ICodeImportEventSet).newReclaim(
             code_import, machine, job_id)

=== modified file 'lib/lp/code/model/tests/test_codeimportjob.py'
--- lib/lp/code/model/tests/test_codeimportjob.py	2010-03-14 20:15:34 +0000
+++ lib/lp/code/model/tests/test_codeimportjob.py	2010-03-16 01:37:25 +0000
@@ -778,6 +778,31 @@
         self.assertEqual(new_job.machine, None)
         self.assertSqlAttributeEqualsDate(new_job, 'date_due', UTC_NOW)
 
+    def test_failures_back_off(self):
+        # We wait for longer and longer between retrying failing imports, to
+        # make it less likely that an import is marked failing just because
+        # someone's DNS went down for a day.
+        running_job = self.makeRunningJob()
+        intervals = []
+        interval = running_job.code_import.effective_update_interval
+        expected_intervals = []
+        for i in range(config.codeimport.consecutive_failure_limit - 1):
+            expected_intervals.append(interval)
+            interval *= 2
+        # Fail an import a bunch of times and record how far in the future the
+        # next job was scheduled.
+        for i in range(config.codeimport.consecutive_failure_limit - 1):
+            code_import = running_job.code_import
+            getUtility(ICodeImportJobWorkflow).finishJob(
+                running_job, CodeImportResultStatus.FAILURE, None)
+            intervals.append(
+                code_import.import_job.date_due -
+                code_import.results[-1].date_job_started)
+            running_job = code_import.import_job
+            getUtility(ICodeImportJobWorkflow).startJob(
+                running_job, self.machine)
+        self.assertEqual(expected_intervals, intervals)
+
     def test_doesntCreateNewJobIfCodeImportNotReviewed(self):
         # finishJob() creates a new CodeImportJob for the given CodeImport,
         # unless the CodeImport has been suspended or marked invalid.