Some cleanup and fixes to the async work.

rida/builder.py

@@ -195,31 +195,21 @@ class KojiModuleBuilder(GenericBuilder):
         return "<KojiModuleBuilder module: %s, tag: %s>" % (
             self.module_str, self.tag_name)
 
-    def buildroot_ready(self, artifacts=None):
+    @rida.utils.retry()
+    def buildroot_ready(self, artifacts):
+        """ Returns True or False if the given artifacts are in the build root.
+        """
         assert self.module_target, "Invalid build target"
-
-        timeout = 120 # minutes see * 60
         tag_id = self.module_target['build_tag']
-        start = time.time()
-        last_repo = None
         repo = self.koji_session.getRepo(tag_id)
-        builds = [ self.koji_session.getBuild(a) for a in artifacts or []]
-
-        while True:
-            if builds and repo and repo != last_repo:
-                if koji.util.checkForBuilds(self.koji_session, tag_id, builds, repo['create_event'], latest=True):
-                    return
-
-            if (time.time() - start) >= (timeout * 60.0):
-                return 1
-
-            time.sleep(60)
-            last_repo = repo
-            repo = self.koji_session.getRepo(tag_id)
-
-            if not builds:
-                if repo != last_repo:
-                    return
+        builds = [ self.koji_session.getBuild(a) for a in artifacts]
+        return bool(koji.util.checkForBuilds(
+            self.koji_session,
+            tag_id,
+            builds,
+            repo['create_event'],
+            latest=True,
+        ))
 
     @staticmethod
     def get_disttag_srpm(disttag):
@@ -327,6 +317,7 @@ chmod 644 %buildroot/%_rpmconfigdir/macros.d/macros.modules
         """
         Resume existing buildroot. Sets __prep=True
         """
+        log.info("%r resuming buildroot." % self)
         chktag = self.koji_session.getTag(self.tag_name)
         if not chktag:
             raise SystemError("Tag %s doesn't exist" % self.tag_name)
@@ -347,6 +338,7 @@ chmod 644 %buildroot/%_rpmconfigdir/macros.d/macros.modules
         :param module_deps_tags: a tag names of our build requires
         :param module_deps_tags: a tag names of our build requires
         """
+        log.info("%r preparing buildroot." % self)
         self.module_tag = self._koji_create_tag(
             self.tag_name, perm="admin") # returns tag obj
         self.module_build_tag = self._koji_create_tag(
@@ -376,17 +368,20 @@ chmod 644 %buildroot/%_rpmconfigdir/macros.d/macros.modules
         :param artifacts - list of artifacts to add to buildroot
         :param install=False - force install artifact (if it's not dragged in as dependency)
         """
-        # TODO: import /usr/bin/koji's TaskWatcher()
         log.info("%r adding artifacts %r" % (self, artifacts))
         dest_tag = self._get_tag(self.module_build_tag)['id']
-        for nvr in artifacts:
-            self.koji_session.tagBuild(dest_tag, nvr, force=True)
-            if install:
-                for group in ('srpm-build', 'build'):
-                    pkg_info = kobo.rpmlib.parse_nvr(nvr)
-                    log.info("%r adding %s to group %s" % (self, pkg_info['name'], group))
-                    self.koji_session.groupPackageListAdd(dest_tag, group, pkg_info['name'])
 
+        for nvr in artifacts:
+            log.info("%r tagging %r into %r" % (self, nvr, dest_tag))
+            self.koji_session.tagBuild(dest_tag, nvr, force=True)
+
+            if not install:
+                continue
+
+            for group in ('srpm-build', 'build'):
+                name = kobo.rpmlib.parse_nvr(nvr)['name']
+                log.info("%r adding %s to group %s" % (self, name, group))
+                self.koji_session.groupPackageListAdd(dest_tag, group, name)
 
     def wait_task(self, task_id):
         """

rida/scheduler/handlers/components.py

@@ -49,16 +49,26 @@ def _finalize(config, session, msg, state):
     component_build.state = state
     session.commit()
 
+    parent = component_build.module_build
+
     if component_build.package == 'module-build-macros':
-        module_name = component_build.module_build.name
-        tag = component_build.module_build.koji_tag
+        if state != koji.BUILD_STATES['COMPLETE']:
+            # If the macro build failed, then the module is doomed.
+            parent.transition(config, state=rida.BUILD_STATES['failed'])
+            session.commit()
+            return
+
+        # Otherwise.. if it didn't fail, then install the macros
+        module_name = parent.name
+        tag = parent.koji_tag
         builder = rida.builder.KojiModuleBuilder(module_name, config, tag_name=tag)
+        builder.buildroot_resume()
         # tag && add to srpm-build group
-        builder.buildroot_add_artifacts([component_build.package,], install=True)
+        nvr = "{name}-{version}-{release}".format(**msg['msg'])
+        builder.buildroot_add_artifacts([nvr,], install=True)
         session.commit()
 
     # Find all of the sibling builds of this particular build.
-    parent = component_build.module_build
     current_batch = parent.current_batch()
 
     # Otherwise, check to see if all failed.  If so, then we cannot continue on

rida/scheduler/handlers/modules.py

@@ -73,7 +73,7 @@ def wait(config, session, msg):
         'release': module_info['release'],
     }
 
-    @rida.utils.retry(interval=60, timeout=60*6, wait_on=ValueError)
+    @rida.utils.retry(interval=10, timeout=30, wait_on=ValueError)
     def _get_deps_and_tag():
         log.info("Getting %s deps from pdc" % module_info['name'])
         dependencies = rida.pdc.get_module_build_dependencies(
@@ -106,6 +106,9 @@ def wait(config, session, msg):
     # inject dist-tag into buildroot
     srpm = builder.get_disttag_srpm(disttag=".%s" % get_rpm_release_from_tag(tag))
 
+    log.debug("Starting build batch 1")
+    build.batch = 1
+
     artifact_name = "module-build-macros"
     task_id = builder.build(artifact_name=artifact_name, source=srpm)
     component_build = rida.database.ComponentBuild(
@@ -114,7 +117,8 @@ def wait(config, session, msg):
         format="rpms",
         scmurl=srpm,
         task_id=task_id,
-        state = koji.BUILD_STATES['BUILDING'],
+        state=koji.BUILD_STATES['BUILDING'],
+        batch=1,
     )
     session.add(component_build)
     build.transition(config, state="build")

rida/scheduler/handlers/repos.py

@@ -60,8 +60,11 @@ def done(config, session, msg):
     # If any in the current batch are still running.. just wait.
     running = [c.state == koji.BUILD_STATES['BUILDING'] for c in current_batch]
     if any(running):
-        log.info("Module build %r has %r of %r components still building" % (
-            module_build, len(running), len(current_batch)))
+        log.info(
+            "%r has %r of %r components still "
+            "building in this batch (%r total)" % (
+                module_build, len(running), len(current_batch),
+                len(module_build.component_builds)))
         return
 
     # Assemble the list of all successful components in the batch.
@@ -75,7 +78,7 @@ def done(config, session, msg):
     if not good:
         module_build.transition(config, rida.BUILD_STATES['failed'])
         session.commit()
-        log.warn("Odd!  All component builds failed for %r." % module_build)
+        log.warn("Odd!  All components in batch failed for %r." % module_build)
         return
 
     builder = rida.builder.KojiModuleBuilder(module_build.name, config, tag_name=tag)

rida/scheduler/main.py

@@ -100,7 +100,7 @@ class MessageWorker(threading.Thread):
 
         # These are our main lookup tables for figuring out what to run in response
         # to what messaging events.
-        NO_OP = lambda config, session, msg: True
+        self.NO_OP = NO_OP = lambda config, session, msg: True
         self.on_build_change = {
             koji.BUILD_STATES["BUILDING"]: NO_OP,
             koji.BUILD_STATES["COMPLETE"]: rida.scheduler.handlers.components.complete,
@@ -172,9 +172,14 @@ class MessageWorker(threading.Thread):
             return
 
         # Execute our chosen handler
-        with rida.database.Database(config) as session:
-            log.info(" %s: %s, %s" % (handler.__name__, msg['topic'], msg['msg_id']))
-            handler(config, session, msg)
+        idx = "%s: %s, %s" % (handler.__name__, msg['topic'], msg['msg_id'])
+        if handler is self.NO_OP:
+            log.debug("Handler is NO_OP: %s" % idx)
+        else:
+            with rida.database.Database(config) as session:
+                log.info("Calling   %s" % idx)
+                handler(config, session, msg)
+                log.info("Done with %s" % idx)
 
 
 class Poller(threading.Thread):

rida/scm.py

@@ -92,8 +92,8 @@ class SCM(object):
         else:
             raise RuntimeError("Unhandled SCM scheme: %s" % self.scheme)
 
-    @rida.utils.retry(wait_on=RuntimeError)
     @staticmethod
+    @rida.utils.retry(wait_on=RuntimeError)
     def _run(cmd, chdir=None):
         proc = sp.Popen(cmd, stdout=sp.PIPE, stderr=sp.PIPE, cwd=chdir)
         stdout, stderr = proc.communicate()

rida/utils.py

@@ -22,9 +22,10 @@
 """ Utility functions for rida. """
 
 import functools
+import logging
 import time
 
-import koji
+log = logging.getLogger(__name__)
 
 
 def retry(timeout=120, interval=30, wait_on=Exception):
@@ -36,11 +37,13 @@ def retry(timeout=120, interval=30, wait_on=Exception):
         def inner(*args, **kwargs):
             start = time.time()
             while True:
-                if (time.time() - start) >= (timeout * 60.0):
+                if (time.time() - start) >= timeout:
                     raise  # This re-raises the last exception.
                 try:
                     return function(*args, **kwargs)
-                except wait_on:
+                except wait_on as e:
+                    log.warn("Exception %r raised from %r.  Retry in %rs" % (
+                        e, function, interval))
                     time.sleep(interval)
         return inner
     return wrapper
@@ -49,6 +52,8 @@ def retry(timeout=120, interval=30, wait_on=Exception):
 def start_next_build_batch(module, session, builder, components=None):
     """ Starts a next round of the build cycle for a module. """
 
+    import koji  # Placed here to avoid py2/py3 conflicts...
+
     if any([c.state == koji.BUILD_STATES['BUILDING']
             for c in module.component_builds ]):
         raise ValueError("Cannot start a batch when another is in flight.")