Merge lp:~cjwatson/launchpad/buildstatus-aborted into lp:launchpad

[Colin Watson]

Add support for ABORTED build slave status, in preparation for using it on slaves.

As discussed at the releng sprint, this branch adds support for an "ABORTED" build slave status, allowing the combination of BuilderStatus.WAITING/BuildStatus.ABORTED on the slave; this makes more sense for cancelling builds than the only other current possibility of BuilderStatus.ABORTED.

After some feedback from William Grant, I also refactored how builder failures are handled, and thereby arranged for an unsolicited ABORTED slave status (i.e. not in response to CANCELLING) to cause the manager to attempt to recover the slave.

I'm not sure we can QA this until the new launchpad-buildd is ready that uses this, at which point we can QA it all at once. However, we should at least check that slave recovery still works in other situations.

[William Grant (wgrant)]

This is too happy to kill non-virtual builders. handleFailure (which is called on eg. a connection failure due to a network glitch) will immediately disable a non-virtual builder, whereas this was previously only done after a guilty judgement by assessFailureCounts. It'll probably also end up double-resetting virtual builders, though that's by no means a critical issue.

review: Needs Fixing (code)

[Colin Watson (cjwatson)]

How's this? I think I misunderstood your earlier comment about consolidating things into handleFailure.

[William Grant (wgrant)]

review: Approve (code)

=== modified file 'lib/lp/buildmaster/interfaces/builder.py'
--- lib/lp/buildmaster/interfaces/builder.py	2013-04-22 06:26:34 +0000
+++ lib/lp/buildmaster/interfaces/builder.py	2013-08-06 15:33:57 +0000
@@ -309,18 +309,27 @@
             explaining what went wrong.
         """
 
-    def handleTimeout(logger, error_message):
-        """Handle buildd slave communication timeout situations.
+    def handleFailure(logger):
+        """Handle buildd slave failures.
+
+        Increment builder and (if possible) job failure counts.
+        """
+
+    def resetOrFail(logger, exception):
+        """Handle "confirmed" build slave failures.
+
+        Call this when there have been multiple failures that are not just
+        the fault of failing jobs, or when the builder has entered an
+        ABORTED state without having been asked to do so.
 
         In case of a virtualized/PPA buildd slave an attempt will be made
-        to reset it first (using `resumeSlaveHost`). Only if that fails
-        will it be (marked as) failed (using `failBuilder`).
+        to reset it (using `resumeSlaveHost`).
 
         Conversely, a non-virtualized buildd slave will be (marked as)
-        failed straightaway.
+        failed straightaway (using `failBuilder`).
 
         :param logger: The logger object to be used for logging.
-        :param error_message: The error message to be used for logging.
+        :param exception: An exception to be used for logging.
         :return: A Deferred that fires after the virtual slave was resumed
             or immediately if it's a non-virtual slave.
         """

=== modified file 'lib/lp/buildmaster/manager.py'
--- lib/lp/buildmaster/manager.py	2013-01-22 00:33:13 +0000
+++ lib/lp/buildmaster/manager.py	2013-08-06 15:33:57 +0000
@@ -161,31 +161,16 @@
                 self.builder_name, failure.getErrorMessage(),
                 failure.getTraceback()))
 
-        # Decide if we need to terminate the job or fail the
-        # builder.
+        # Decide if we need to terminate the job or fail the builder.
+        builder = get_builder(self.builder_name)
         try:
-            builder = get_builder(self.builder_name)
-            builder.gotFailure()
-            if builder.currentjob is not None:
-                build_farm_job = builder.getCurrentBuildFarmJob()
-                build_farm_job.gotFailure()
-                self.logger.info(
-                    "builder %s failure count: %s, "
-                    "job '%s' failure count: %s" % (
-                        self.builder_name,
-                        builder.failure_count,
-                        build_farm_job.title,
-                        build_farm_job.failure_count))
-            else:
-                self.logger.info(
-                    "Builder %s failed a probe, count: %s" % (
-                        self.builder_name, builder.failure_count))
+            builder.handleFailure(self.logger)
             assessFailureCounts(builder, failure.getErrorMessage())
             transaction.commit()
-        except:
+        except Exception:
             # Catastrophic code failure! Not much we can do.
             self.logger.error(
-                "Miserable failure when trying to examine failure counts:\n",
+                "Miserable failure when trying to handle failure:\n",
                 exc_info=True)
             transaction.abort()
 

=== modified file 'lib/lp/buildmaster/model/builder.py'
--- lib/lp/buildmaster/model/builder.py	2013-06-20 05:50:00 +0000
+++ lib/lp/buildmaster/model/builder.py	2013-08-06 15:33:57 +0000
@@ -803,15 +803,33 @@
         d = defer.maybeDeferred(self.startBuild, candidate, logger)
         return d
 
-    def handleTimeout(self, logger, error_message):
-        """See IBuilder."""
+    def handleFailure(self, logger):
+        """See IBuilder."""
+        self.gotFailure()
+        if self.currentjob is not None:
+            build_farm_job = self.getCurrentBuildFarmJob()
+            build_farm_job.gotFailure()
+            logger.info(
+                "Builder %s failure count: %s, job '%s' failure count: %s" % (
+                    self.name, self.failure_count,
+                    build_farm_job.title, build_farm_job.failure_count))
+        else:
+            logger.info(
+                "Builder %s failure count: %s" % (
+                    self.name, self.failure_count))
+
+    def resetOrFail(self, logger, exception):
+        """See IBuilder."""
+        error_message = str(exception)
         if self.virtualized:
-            # Virtualized/PPA builder: attempt a reset.
-            logger.warn(
-                "Resetting builder: %s -- %s" % (self.url, error_message),
-                exc_info=True)
-            d = self.resumeSlaveHost()
-            return d
+            # Virtualized/PPA builder: attempt a reset, unless the failure
+            # was itself a failure to reset.  (In that case, the slave
+            # scanner will try again until we reach the failure threshold.)
+            if not isinstance(exception, CannotResumeHost):
+                logger.warn(
+                    "Resetting builder: %s -- %s" % (self.url, error_message),
+                    exc_info=True)
+                return self.resumeSlaveHost()
         else:
             # XXX: This should really let the failure bubble up to the
             # scan() method that does the failure counting.
@@ -819,7 +837,7 @@
             logger.warn(
                 "Disabling builder: %s -- %s" % (self.url, error_message))
             self.failBuilder(error_message)
-            return defer.succeed(None)
+        return defer.succeed(None)
 
     def findAndStartJob(self):
         """See IBuilder."""

=== modified file 'lib/lp/buildmaster/model/buildfarmjobbehavior.py'
--- lib/lp/buildmaster/model/buildfarmjobbehavior.py	2013-01-23 06:41:24 +0000
+++ lib/lp/buildmaster/model/buildfarmjobbehavior.py	2013-08-06 15:33:57 +0000
@@ -219,7 +219,8 @@
         Buildslave can be WAITING in five situations:
 
         * Build has failed, no filemap is received (PACKAGEFAIL, DEPFAIL,
-                                                    CHROOTFAIL, BUILDERFAIL)
+                                                    CHROOTFAIL, BUILDERFAIL,
+                                                    ABORTED)
 
         * Build has been built successfully (BuildStatus.OK), in this case
           we have a 'filemap', so we can retrieve those files and store in
@@ -415,6 +416,30 @@
         transaction.commit()
 
     @defer.inlineCallbacks
+    def _handleStatus_ABORTED(self, librarian, slave_status, logger,
+                              send_notification):
+        """Handle aborted builds.
+
+        If the build was explicitly cancelled, then mark it as such.
+        Otherwise, the build has failed in some unexpected way.
+        """
+        builder = self.build.buildqueue_record.builder
+        if self.build.status == BuildStatus.CANCELLING:
+            self.build.buildqueue_record.cancel()
+            transaction.commit()
+            yield builder.cleanSlave()
+        else:
+            self.build.buildqueue_record.reset()
+            try:
+                builder.handleFailure(logger)
+                yield builder.resetOrFail(logger, BuildSlaveFailure(
+                    "Builder unexpectedly returned ABORTED"))
+            except Exception as e:
+                # We've already done our best to mark the builder as failed.
+                logger.error("Failed to rescue from ABORTED: %s" % e)
+        transaction.commit()
+
+    @defer.inlineCallbacks
     def _handleStatus_GIVENBACK(self, librarian, slave_status, logger,
                                 send_notification):
         """Handle automatic retry requested by builder.

=== modified file 'lib/lp/buildmaster/tests/test_builder.py'
--- lib/lp/buildmaster/tests/test_builder.py	2013-06-20 05:50:00 +0000
+++ lib/lp/buildmaster/tests/test_builder.py	2013-08-06 15:33:57 +0000
@@ -191,7 +191,13 @@
         d = builder.resumeSlaveHost()
         return assert_fails_with(d, CannotResumeHost)
 
-    def test_handleTimeout_resume_failure(self):
+    def test_handleFailure_increments_failure_count(self):
+        builder = self.factory.makeBuilder(virtualized=False)
+        builder.builderok = True
+        builder.handleFailure(BufferLogger())
+        self.assertEqual(1, builder.failure_count)
+
+    def test_resetOrFail_resume_failure(self):
         reset_fail_config = """
             [builddmaster]
             vm_resume_command: /bin/false"""
@@ -199,7 +205,7 @@
         self.addCleanup(config.pop, 'reset fail')
         builder = self.factory.makeBuilder(virtualized=True, vm_host="pop")
         builder.builderok = True
-        d = builder.handleTimeout(BufferLogger(), 'blah')
+        d = builder.resetOrFail(BufferLogger(), Exception())
         return assert_fails_with(d, CannotResumeHost)
 
     def _setupBuilder(self):

=== modified file 'lib/lp/buildmaster/tests/test_buildfarmjobbehavior.py'
--- lib/lp/buildmaster/tests/test_buildfarmjobbehavior.py	2013-01-30 07:30:10 +0000
+++ lib/lp/buildmaster/tests/test_buildfarmjobbehavior.py	2013-08-06 15:33:57 +0000
@@ -214,10 +214,11 @@
         self.build = self.makeBuild()
         # For the moment, we require a builder for the build so that
         # handleStatus_OK can get a reference to the slave.
-        builder = self.factory.makeBuilder()
-        self.build.buildqueue_record.builder = builder
+        self.builder = self.factory.makeBuilder()
+        self.build.buildqueue_record.builder = self.builder
         self.build.buildqueue_record.setDateStarted(UTC_NOW)
-        self.behavior = removeSecurityProxy(builder.current_build_behavior)
+        self.behavior = removeSecurityProxy(
+            self.builder.current_build_behavior)
         self.slave = WaitingSlave('BuildStatus.OK')
         self.slave.valid_file_hashes.append('test_file_hash')
         self.patch(BuilderSlave, 'makeBuilderSlave', FakeMethod(self.slave))
@@ -321,6 +322,31 @@
     def test_handleStatus_PACKAGEFAIL_notifies(self):
         return self._test_handleStatus_notifies("PACKAGEFAIL")
 
+    def test_handleStatus_ABORTED_cancels_cancelling(self):
+        self.build.updateStatus(BuildStatus.CANCELLING)
+
+        def got_status(ignored):
+            self.assertEqual(
+                0, len(pop_notifications()), "Notifications received")
+            self.assertEqual(BuildStatus.CANCELLED, self.build.status)
+
+        d = self.behavior.handleStatus("ABORTED", None, {})
+        return d.addCallback(got_status)
+
+    def test_handleStatus_ABORTED_recovers_building(self):
+        self.builder.vm_host = "fake_vm_host"
+        self.build.updateStatus(BuildStatus.BUILDING)
+
+        def got_status(ignored):
+            self.assertEqual(
+                0, len(pop_notifications()), "Notifications received")
+            self.assertEqual(BuildStatus.NEEDSBUILD, self.build.status)
+            self.assertEqual(1, self.builder.failure_count)
+            self.assertIn("resume", self.slave.call_log)
+
+        d = self.behavior.handleStatus("ABORTED", None, {})
+        return d.addCallback(got_status)
+
     def test_date_finished_set(self):
         # The date finished is updated during handleStatus_OK.
         self.assertEqual(None, self.build.date_finished)

=== modified file 'lib/lp/buildmaster/tests/test_manager.py'
--- lib/lp/buildmaster/tests/test_manager.py	2013-02-04 06:14:32 +0000
+++ lib/lp/buildmaster/tests/test_manager.py	2013-08-06 15:33:57 +0000
@@ -162,31 +162,6 @@
         self.assertTrue(builder.builderok)
         self.assertTrue(builder.currentjob is None)
 
-    def testNoDispatchForMissingChroots(self):
-        # When a required chroot is not present the `scan` method
-        # should not return any `RecordingSlaves` to be processed
-        # and the builder used should remain active and IDLE.
-
-        # Reset sampledata builder.
-        builder = getUtility(IBuilderSet)[BOB_THE_BUILDER_NAME]
-        self._resetBuilder(builder)
-
-        # Remove hoary/i386 chroot.
-        login('[e-mail]')
-        ubuntu = getUtility(IDistributionSet).getByName('ubuntu')
-        hoary = ubuntu.getSeries('hoary')
-        pocket_chroot = hoary.getDistroArchSeries('i386').getPocketChroot()
-        removeSecurityProxy(pocket_chroot).chroot = None
-        transaction.commit()
-        login(ANONYMOUS)
-
-        # Run 'scan' and check its result.
-        switch_dbuser(config.builddmaster.dbuser)
-        scanner = self._getScanner()
-        d = defer.maybeDeferred(scanner.singleCycle)
-        d.addCallback(self._checkNoDispatch, builder)
-        return d
-
     def _checkJobRescued(self, slave, builder, job):
         """`SlaveScanner.scan` rescued the job.
 

=== modified file 'lib/lp/soyuz/tests/test_binarypackagebuildbehavior.py'
--- lib/lp/soyuz/tests/test_binarypackagebuildbehavior.py	2013-01-24 05:50:23 +0000
+++ lib/lp/soyuz/tests/test_binarypackagebuildbehavior.py	2013-08-06 15:33:57 +0000
@@ -19,6 +19,7 @@
 from zope.security.proxy import removeSecurityProxy
 
 from lp.buildmaster.enums import BuildStatus
+from lp.buildmaster.interfaces.builder import CannotBuild
 from lp.buildmaster.model.builder import BuilderSlave
 from lp.buildmaster.tests.mock_slaves import (
     AbortedSlave,
@@ -264,6 +265,19 @@
             'Attempt to build virtual item on a non-virtual builder.',
             str(e))
 
+    def test_verifyBuildRequest_no_chroot(self):
+        # Don't dispatch a build when the DAS has no chroot.
+        archive = self.factory.makeArchive(purpose=ArchivePurpose.PRIMARY)
+        builder = self.factory.makeBuilder()
+        build = self.factory.makeBinaryPackageBuild(
+            builder=builder, archive=archive)
+        candidate = build.queueBuild()
+        behavior = candidate.required_build_behavior
+        behavior.setBuilder(builder)
+        e = self.assertRaises(
+            CannotBuild, behavior.verifyBuildRequest, BufferLogger())
+        self.assertIn("Missing CHROOT", str(e))
+
     def test_getBuildCookie(self):
         # A build cookie is made up of the job type and record id.
         # The uploadprocessor relies on this format.