Merge #139 Log more details when any deliverable fails

pungi/phases/buildinstall.py

@@ -132,10 +132,13 @@ class BuildinstallPhase(PhaseBase):
                 for variant in self.compose.get_variants(arch=arch, types=['variant']):
                     volid = get_volid(self.compose, arch, variant=variant, disc_type="boot")
                     commands.append(
-                        self._get_lorax_cmd(repo_baseurl, output_dir, variant, arch, buildarch, volid)
+                        (variant,
+                         self._get_lorax_cmd(repo_baseurl, output_dir, variant, arch, buildarch, volid))
                     )
             elif buildinstall_method == "buildinstall":
-                commands.append(lorax.get_buildinstall_cmd(product,
+                commands.append(
+                    (None,
+                     lorax.get_buildinstall_cmd(product,
                                                 version,
                                                 release,
                                                 repo_baseurl,
@@ -143,12 +146,13 @@ class BuildinstallPhase(PhaseBase):
                                                 is_final=self.compose.supported,
                                                 buildarch=buildarch,
                                                 volid=volid))
+                )
             else:
                 raise ValueError("Unsupported buildinstall method: %s" % buildinstall_method)
 
-            for cmd in commands:
+            for (variant, cmd) in commands:
                 self.pool.add(BuildinstallThread(self.pool))
-                self.pool.queue_put((self.compose, arch, cmd))
+                self.pool.queue_put((self.compose, arch, variant, cmd))
 
         self.pool.start()
 
@@ -357,22 +361,25 @@ def symlink_boot_iso(compose, arch, variant):
 
 class BuildinstallThread(WorkerThread):
     def process(self, item, num):
-        compose, arch, cmd = item
+        # The variant is None unless lorax is used as buildinstall method.
+        compose, arch, variant, cmd = item
         try:
-            self.worker(compose, arch, cmd, num)
+            self.worker(compose, arch, variant, cmd, num)
-        except Exception:
+        except Exception as exc:
-            if not compose.can_fail(None, arch, 'buildinstall'):
+            if not compose.can_fail(variant, arch, 'buildinstall'):
                 raise
             else:
                 self.pool.log_info(
-                    '[FAIL] Buildinstall for arch %s failed, but going on anyway.' % arch)
+                    '[FAIL] Buildinstall for variant %s arch %s failed, but going on anyway.\n%s'
+                    % (variant.uid if variant else 'None', arch, exc))
 
-    def worker(self, compose, arch, cmd, num):
+    def worker(self, compose, arch, variant, cmd, num):
         runroot = compose.conf.get("runroot", False)
         buildinstall_method = compose.conf["buildinstall_method"]
-        log_file = compose.paths.log.log_file(arch, "buildinstall")
+        log_filename = ('buildinstall-%s' % variant.uid) if variant else 'buildinstall'
+        log_file = compose.paths.log.log_file(arch, log_filename)
 
-        msg = "Runnging buildinstall for arch %s" % arch
+        msg = "Running buildinstall for arch %s" % arch
 
         output_dir = compose.paths.work.buildinstall_dir(arch)
         if os.path.isdir(output_dir):
@@ -399,7 +406,10 @@ class BuildinstallThread(WorkerThread):
             runroot_tag = compose.conf["runroot_tag"]
 
             koji_wrapper = KojiWrapper(compose.conf["koji_profile"])
-            koji_cmd = koji_wrapper.get_runroot_cmd(runroot_tag, arch, cmd, channel=runroot_channel, use_shell=True, task_id=True, packages=packages, mounts=[compose.topdir])
+            koji_cmd = koji_wrapper.get_runroot_cmd(runroot_tag, arch, cmd,
+                                                    channel=runroot_channel,
+                                                    use_shell=True, task_id=True,
+                                                    packages=packages, mounts=[compose.topdir])
 
             # avoid race conditions?
             # Kerberos authentication failed: Permission denied in replay cache code (-1765328215)
@@ -408,13 +418,14 @@ class BuildinstallThread(WorkerThread):
             output = koji_wrapper.run_runroot_cmd(koji_cmd, log_file=log_file)
             task_id = int(output["task_id"])
             if output["retcode"] != 0:
-                raise RuntimeError("Runroot task failed: %s. See %s for more details." % (output["task_id"], log_file))
+                raise RuntimeError("Runroot task failed: %s. See %s for more details."
+                                   % (output["task_id"], log_file))
 
         else:
             # run locally
             run(cmd, show_cmd=True, logfile=log_file)
 
-        log_file = compose.paths.log.log_file(arch, "buildinstall-RPMs")
+        log_file = compose.paths.log.log_file(arch, log_filename + '-RPMs')
         rpms = get_buildroot_rpms(compose, task_id)
         open(log_file, "w").write("\n".join(rpms))
 

pungi/phases/createiso.py

@@ -220,12 +220,12 @@ class CreateIsoThread(WorkerThread):
         compose, cmd, variant, arch = item
         try:
             self.worker(compose, cmd, num)
-        except Exception:
+        except Exception as exc:
             if not compose.can_fail(variant, arch, 'iso'):
                 raise
             else:
-                msg = ('[FAIL] Creating iso for variant %s, arch %s failed, but going on anyway.'
+                msg = ('[FAIL] Creating iso for variant %s, arch %s failed, but going on anyway.\n%s'
-                       % (variant.uid, arch))
+                       % (variant.uid, arch, exc))
                 self.pool.log_info(msg)
 
     def worker(self, compose, cmd, num):

pungi/phases/image_build.py

@@ -144,12 +144,12 @@ class CreateImageBuildThread(WorkerThread):
         compose, cmd = item
         try:
             self.worker(num, compose, cmd)
-        except:
+        except Exception as exc:
             if not compose.can_fail(cmd['image_conf']['variant'], '*', 'image-build'):
                 raise
             else:
-                msg = ('[FAIL] image-build for variant %s failed, but going on anyway.'
+                msg = ('[FAIL] image-build for variant %s failed, but going on anyway.\n%s'
-                       % cmd['image_conf']['variant'])
+                       % (cmd['image_conf']['variant'], exc))
                 self.pool.log_info(msg)
 
     def worker(self, num, compose, cmd):

pungi/phases/live_images.py

@@ -172,12 +172,12 @@ class CreateLiveImageThread(WorkerThread):
         compose, cmd, variant, arch = item
         try:
             self.worker(compose, cmd, variant, arch, num)
-        except:
+        except Exception as exc:
             if not compose.can_fail(variant, arch, 'live'):
                 raise
             else:
-                msg = ('[FAIL] Creating live image for variant %s, arch %s failed, but going on anyway.'
+                msg = ('[FAIL] Creating live image for variant %s, arch %s failed, but going on anyway.\n%s'
-                       % (variant.uid, arch))
+                       % (variant.uid, arch, exc))
                 self.pool.log_info(msg)
 
     def worker(self, compose, cmd, variant, arch, num):

pungi/phases/livemedia_phase.py

@@ -100,12 +100,12 @@ class LiveMediaThread(WorkerThread):
         self.num = num
         try:
             self.worker(compose, variant, config)
-        except:
+        except Exception as exc:
             if not compose.can_fail(variant, '*', 'live-media'):
                 raise
             else:
-                msg = ('[FAIL] live-media for variant %s failed, but going on anyway.'
+                msg = ('[FAIL] live-media for variant %s failed, but going on anyway.\n%s'
-                       % variant.uid)
+                       % (variant.uid, exc))
                 self.pool.log_info(msg)
 
     def _get_log_file(self, compose, variant, config):

pungi/wrappers/kojiwrapper.py

@@ -53,12 +53,10 @@ class KojiWrapper(object):
         if weight:
             cmd.append("--weight=%s" % int(weight))
 
-        if packages:
+        for package in packages or []:
-            for package in packages:
             cmd.append("--package=%s" % package)
 
-        if mounts:
+        for mount in mounts or []:
-            for mount in mounts:
             # directories are *not* created here
             cmd.append("--mount=%s" % mount)
 
@@ -84,19 +82,18 @@ class KojiWrapper(object):
 
         task_id = None
         retcode, output = run(command, can_fail=True, logfile=log_file)
-        if "--task-id" in command:
+        if retcode == 0 and "--task-id" in command:
             task_id = int(output.splitlines()[0])
             output_ends_with_eol = output.endswith("\n")
             output = "\n".join(output.splitlines()[1:])
             if output_ends_with_eol:
                 output += "\n"
 
-        result = {
+        return {
             "retcode": retcode,
             "output": output,
             "task_id": task_id,
         }
-        return result
 
     def get_image_build_cmd(self, config_options, conf_file_dest, wait=True, scratch=False):
         """

tests/test_buildinstall.py

@@ -10,12 +10,14 @@ import sys
 
 sys.path.insert(0, os.path.join(os.path.dirname(__file__), ".."))
 
-from pungi.phases.buildinstall import BuildinstallPhase
+from pungi.phases.buildinstall import BuildinstallPhase, BuildinstallThread
+from pungi.util import get_arch_variant_data
 
 
 class _DummyCompose(object):
     def __init__(self, config):
         self.conf = config
+        self.topdir = '/topdir'
         self.paths = mock.Mock(
             compose=mock.Mock(
                 topdir=mock.Mock(return_value='/a/b'),
@@ -24,6 +26,9 @@ class _DummyCompose(object):
             work=mock.Mock(
                 arch_repo=mock.Mock(return_value='file:///a/b/'),
                 buildinstall_dir=mock.Mock(side_effect=lambda x: '/buildinstall_dir/' + x),
+            ),
+            log=mock.Mock(
+                log_file=mock.Mock(side_effect=lambda arch, filename: '/log/%s.%s.log' % (filename, arch)),
             )
         )
         self._logger = mock.Mock()
@@ -41,6 +46,10 @@ class _DummyCompose(object):
     def get_variants(self, arch, types):
         return self.variants.get(arch, [])
 
+    def can_fail(self, variant, arch, deliverable):
+        failable = get_arch_variant_data(self.conf, 'failable_deliverables', arch, variant)
+        return deliverable in failable
+
 
 class TestBuildinstallPhase(unittest.TestCase):
 
@@ -349,5 +358,165 @@ class TestCopyFiles(unittest.TestCase):
             any_order=True
         )
 
+
+class BuildinstallThreadTestCase(unittest.TestCase):
+
+    @mock.patch('pungi.phases.buildinstall.KojiWrapper')
+    @mock.patch('pungi.phases.buildinstall.get_buildroot_rpms')
+    @mock.patch('pungi.phases.buildinstall.open')
+    @mock.patch('pungi.phases.buildinstall.run')
+    def test_buildinstall_thread_with_lorax_in_runroot(self, run, mock_open,
+                                                       get_buildroot_rpms, KojiWrapperMock):
+        compose = _DummyCompose({
+            'buildinstall_method': 'lorax',
+            'runroot': True,
+            'runroot_tag': 'rrt',
+            'koji_profile': 'koji',
+        })
+
+        get_buildroot_rpms.return_value = ['bash', 'zsh']
+        pool = mock.Mock()
+        cmd = mock.Mock()
+
+        get_runroot_cmd = KojiWrapperMock.return_value.get_runroot_cmd
+
+        run_runroot_cmd = KojiWrapperMock.return_value.run_runroot_cmd
+        run_runroot_cmd.return_value = {
+            'output': 'Foo bar baz',
+            'retcode': 0,
+            'task_id': 1234,
+        }
+
+        t = BuildinstallThread(pool)
+
+        with mock.patch('time.sleep'):
+            t.process((compose, 'x86_64', compose.variants['x86_64'][0], cmd), 0)
+
+        get_runroot_cmd.assert_has_calls([
+            mock.call('rrt', 'x86_64', cmd, channel=None,
+                      use_shell=True, task_id=True,
+                      packages=['strace', 'lorax'], mounts=['/topdir'])
+        ])
+        run_runroot_cmd(get_runroot_cmd.return_value, log_file='/log/buildinstall-Server.x86_64.log')
+        mock_open.return_value.write.assert_has_calls([
+            mock.call('bash\nzsh')
+        ])
+
+    @mock.patch('pungi.phases.buildinstall.KojiWrapper')
+    @mock.patch('pungi.phases.buildinstall.get_buildroot_rpms')
+    @mock.patch('pungi.phases.buildinstall.open')
+    @mock.patch('pungi.phases.buildinstall.run')
+    def test_buildinstall_thread_with_buildinstall_in_runroot(self, run, mock_open,
+                                                              get_buildroot_rpms, KojiWrapperMock):
+        compose = _DummyCompose({
+            'buildinstall_method': 'buildinstall',
+            'runroot': True,
+            'runroot_tag': 'rrt',
+            'koji_profile': 'koji',
+        })
+
+        get_buildroot_rpms.return_value = ['bash', 'zsh']
+        pool = mock.Mock()
+        cmd = mock.Mock()
+
+        get_runroot_cmd = KojiWrapperMock.return_value.get_runroot_cmd
+
+        run_runroot_cmd = KojiWrapperMock.return_value.run_runroot_cmd
+        run_runroot_cmd.return_value = {
+            'output': 'Foo bar baz',
+            'retcode': 0,
+            'task_id': 1234,
+        }
+
+        t = BuildinstallThread(pool)
+
+        with mock.patch('time.sleep'):
+            t.process((compose, 'x86_64', None, cmd), 0)
+
+        get_runroot_cmd.assert_has_calls([
+            mock.call('rrt', 'x86_64', cmd, channel=None,
+                      use_shell=True, task_id=True,
+                      packages=['strace', 'anaconda'], mounts=['/topdir'])
+        ])
+        run_runroot_cmd(get_runroot_cmd.return_value, log_file='/log/buildinstall.x86_64.log')
+        mock_open.return_value.write.assert_has_calls([
+            mock.call('bash\nzsh')
+        ])
+
+    @mock.patch('pungi.phases.buildinstall.KojiWrapper')
+    @mock.patch('pungi.phases.buildinstall.get_buildroot_rpms')
+    @mock.patch('pungi.phases.buildinstall.open')
+    @mock.patch('pungi.phases.buildinstall.run')
+    def test_buildinstall_fail_exit_code(self, run, mock_open,
+                                         get_buildroot_rpms, KojiWrapperMock):
+        compose = _DummyCompose({
+            'buildinstall_method': 'buildinstall',
+            'runroot': True,
+            'runroot_tag': 'rrt',
+            'koji_profile': 'koji',
+            'failable_deliverables': [
+                ('^.+$', {'*': ['buildinstall']})
+            ],
+        })
+
+        get_buildroot_rpms.return_value = ['bash', 'zsh']
+        pool = mock.Mock()
+        cmd = mock.Mock()
+
+        run_runroot_cmd = KojiWrapperMock.return_value.run_runroot_cmd
+        run_runroot_cmd.return_value = {
+            'output': 'Foo bar baz',
+            'retcode': 1,
+            'task_id': 1234,
+        }
+
+        t = BuildinstallThread(pool)
+
+        with mock.patch('time.sleep'):
+            t.process((compose, 'x86_64', None, cmd), 0)
+
+        pool.log_info.assert_has_calls([
+            mock.call('[BEGIN] Running buildinstall for arch x86_64'),
+            mock.call('[FAIL] Buildinstall for variant None arch x86_64 failed, but going on anyway.\nRunroot task failed: 1234. See /log/buildinstall.x86_64.log for more details.')
+        ])
+
+    @mock.patch('pungi.phases.buildinstall.KojiWrapper')
+    @mock.patch('pungi.phases.buildinstall.get_buildroot_rpms')
+    @mock.patch('pungi.phases.buildinstall.open')
+    @mock.patch('pungi.phases.buildinstall.run')
+    def test_lorax_fail_exit_code(self, run, mock_open,
+                                  get_buildroot_rpms, KojiWrapperMock):
+        compose = _DummyCompose({
+            'buildinstall_method': 'lorax',
+            'runroot': True,
+            'runroot_tag': 'rrt',
+            'koji_profile': 'koji',
+            'failable_deliverables': [
+                ('^.+$', {'*': ['buildinstall']})
+            ],
+        })
+
+        get_buildroot_rpms.return_value = ['bash', 'zsh']
+        pool = mock.Mock()
+        cmd = mock.Mock()
+
+        run_runroot_cmd = KojiWrapperMock.return_value.run_runroot_cmd
+        run_runroot_cmd.return_value = {
+            'output': 'Foo bar baz',
+            'retcode': 1,
+            'task_id': 1234,
+        }
+
+        t = BuildinstallThread(pool)
+
+        with mock.patch('time.sleep'):
+            t.process((compose, 'x86_64', compose.variants['x86_64'][0], cmd), 0)
+
+        pool.log_info.assert_has_calls([
+            mock.call('[BEGIN] Running buildinstall for arch x86_64'),
+            mock.call('[FAIL] Buildinstall for variant Server arch x86_64 failed, but going on anyway.\nRunroot task failed: 1234. See /log/buildinstall-Server.x86_64.log for more details.')
+        ])
+
+
 if __name__ == "__main__":
     unittest.main()

tests/test_imagebuildphase.py

@@ -504,6 +504,7 @@ class TestCreateImageBuildThread(unittest.TestCase):
             "image_dir": '/image_dir/Client/%(arch)s',
             "relative_image_dir": 'image_dir/Client/%(arch)s',
             "link_type": 'hardlink-or-copy',
+            'scratch': False,
         }
         koji_wrapper = KojiWrapper.return_value
         koji_wrapper.run_blocking_cmd.return_value = {
@@ -552,6 +553,7 @@ class TestCreateImageBuildThread(unittest.TestCase):
             "image_dir": '/image_dir/Client/%(arch)s',
             "relative_image_dir": 'image_dir/Client/%(arch)s',
             "link_type": 'hardlink-or-copy',
+            'scratch': False,
         }
 
         def boom(*args, **kwargs):

tests/test_koji_wrapper.py

@@ -294,5 +294,77 @@ class LiveMediaTestCase(unittest.TestCase):
                               ['--repo=repo-1', '--repo=repo-2', '--skip-tag', '--scratch', '--wait'])
 
 
+class RunrootKojiWrapperTest(unittest.TestCase):
+
+    def setUp(self):
+        self.koji_profile = mock.Mock()
+        with mock.patch('pungi.wrappers.kojiwrapper.koji') as koji:
+            koji.get_profile_module = mock.Mock(
+                return_value=mock.Mock(
+                    pathinfo=mock.Mock(
+                        work=mock.Mock(return_value='/koji'),
+                        taskrelpath=mock.Mock(side_effect=lambda id: 'task/' + str(id)),
+                        imagebuild=mock.Mock(side_effect=lambda id: '/koji/imagebuild/' + str(id)),
+                    )
+                )
+            )
+            self.koji_profile = koji.get_profile_module.return_value
+            self.koji = KojiWrapper('koji')
+
+    def test_get_cmd_minimal(self):
+        cmd = self.koji.get_runroot_cmd('tgt', 's390x', 'date', use_shell=False, task_id=False)
+        self.assertEqual(len(cmd), 6)
+        self.assertEqual(cmd[0], 'koji')
+        self.assertEqual(cmd[1], 'runroot')
+        self.assertEqual(cmd[-3], 'tgt')
+        self.assertEqual(cmd[-2], 's390x')
+        self.assertEqual(cmd[-1], 'rm -f /var/lib/rpm/__db*; rm -rf /var/cache/yum/*; set -x; date')
+        self.assertItemsEqual(cmd[2:-3],
+                              ['--channel-override=runroot-local'])
+
+    def test_get_cmd_full(self):
+        cmd = self.koji.get_runroot_cmd('tgt', 's390x', ['/bin/echo', '&'],
+                                        quiet=True, channel='chan',
+                                        packages=['strace', 'lorax'],
+                                        mounts=['/tmp'], weight=1000)
+        self.assertEqual(len(cmd), 13)
+        self.assertEqual(cmd[0], 'koji')
+        self.assertEqual(cmd[1], 'runroot')
+        self.assertEqual(cmd[-3], 'tgt')
+        self.assertEqual(cmd[-2], 's390x')
+        self.assertEqual(cmd[-1], 'rm -f /var/lib/rpm/__db*; rm -rf /var/cache/yum/*; set -x; /bin/echo \'&\'')
+        self.assertItemsEqual(cmd[2:-3],
+                              ['--channel-override=chan', '--quiet', '--use-shell',
+                               '--task-id', '--weight=1000', '--package=strace',
+                               '--package=lorax', '--mount=/tmp'])
+
+    @mock.patch('pungi.wrappers.kojiwrapper.run')
+    def test_run_runroot_cmd_no_task_id(self, run):
+        cmd = ['koji', 'runroot']
+        output = 'Output ...'
+        run.return_value = (0, output)
+
+        result = self.koji.run_runroot_cmd(cmd)
+        self.assertDictEqual(result, {'retcode': 0, 'output': output, 'task_id': None})
+
+    @mock.patch('pungi.wrappers.kojiwrapper.run')
+    def test_run_runroot_cmd_with_task_id(self, run):
+        cmd = ['koji', 'runroot', '--task-id']
+        output = 'Output ...\n'
+        run.return_value = (0, '1234\n' + output)
+
+        result = self.koji.run_runroot_cmd(cmd)
+        self.assertDictEqual(result, {'retcode': 0, 'output': output, 'task_id': 1234})
+
+    @mock.patch('pungi.wrappers.kojiwrapper.run')
+    def test_run_runroot_cmd_with_task_id_and_fail(self, run):
+        cmd = ['koji', 'runroot', '--task-id']
+        output = 'You are not authorized to run this\n'
+        run.return_value = (1, output)
+
+        result = self.koji.run_runroot_cmd(cmd)
+        self.assertDictEqual(result, {'retcode': 1, 'output': output, 'task_id': None})
+
+
 if __name__ == "__main__":
     unittest.main()