From 96a5499ed9c9c37818955ed34671065cd4696b6c Mon Sep 17 00:00:00 2001
From: Christian Kellner <christian@kellner.me>
Date: Wed, 26 Aug 2020 15:01:54 +0200
Subject: [PATCH] buildroot: log bubblewrap's output

In case that bubblewrap fails to, e.g. because it fails to execute
the runner, it will print an error message to stderr. Currently,
this output is not capture and thus not logged. To fix that, the
`BuildRoot.run` method now takes a monitor object and will stream
stdout/stderr to the log via the monitor.
---
 osbuild/buildroot.py       | 24 ++++++++++++++++++++----
 osbuild/pipeline.py        |  2 ++
 test/mod/test_buildroot.py | 12 ++++++------
 3 files changed, 28 insertions(+), 10 deletions(-)

diff --git a/osbuild/buildroot.py b/osbuild/buildroot.py
index 36fae65b..faf593bc 100644
--- a/osbuild/buildroot.py
+++ b/osbuild/buildroot.py
@@ -110,7 +110,7 @@ class BuildRoot(contextlib.AbstractContextManager):
         if self._exitstack:
             self._exitstack.enter_context(api)
 
-    def run(self, argv, binds=None, readonly_binds=None):
+    def run(self, argv, monitor, binds=None, readonly_binds=None):
         """Runs a command in the buildroot.
 
         Takes the command and arguments, as well as bind mounts to mirror
@@ -194,6 +194,22 @@ class BuildRoot(contextlib.AbstractContextManager):
         cmd += ["--", f"/run/osbuild/lib/runners/{self._runner}"]
         cmd += argv
 
-        return subprocess.run(cmd,
-                              check=False,
-                              stdin=subprocess.DEVNULL)
+        proc = subprocess.Popen(cmd,
+                                bufsize=0,
+                                stdin=subprocess.DEVNULL,
+                                stdout=subprocess.PIPE,
+                                stderr=subprocess.STDOUT,
+                                encoding="utf-8",
+                                close_fds=True)
+
+        while True:
+            txt = proc.stdout.read(4096)
+            if not txt:
+                break
+
+            monitor.log(txt)
+
+        txt, _ = proc.communicate()
+        monitor.log(txt)
+
+        return proc
diff --git a/osbuild/pipeline.py b/osbuild/pipeline.py
index 0a6047fa..27357a29 100644
--- a/osbuild/pipeline.py
+++ b/osbuild/pipeline.py
@@ -88,6 +88,7 @@ class Stage:
             build_root.register_api(src)
 
             r = build_root.run([f"/run/osbuild/lib/stages/{self.name}"],
+                               monitor,
                                binds=[os.fspath(tree) + ":/run/osbuild/tree"],
                                readonly_binds=ro_binds)
 
@@ -146,6 +147,7 @@ class Assembler:
             build_root.register_api(rls)
 
             r = build_root.run([f"/run/osbuild/lib/assemblers/{self.name}"],
+                               monitor,
                                binds=binds,
                                readonly_binds=ro_binds)
 
diff --git a/test/mod/test_buildroot.py b/test/mod/test_buildroot.py
index 16f92f16..9cbfa80d 100644
--- a/test/mod/test_buildroot.py
+++ b/test/mod/test_buildroot.py
@@ -37,14 +37,14 @@ class TestBuildRoot(test.TestBase):
             api = osbuild.api.API({}, monitor)
             root.register_api(api)
 
-            r = root.run(["/usr/bin/true"])
+            r = root.run(["/usr/bin/true"], monitor)
             self.assertEqual(r.returncode, 0)
 
             # Test we can use `.run` multiple times
-            r = root.run(["/usr/bin/true"])
+            r = root.run(["/usr/bin/true"], monitor)
             self.assertEqual(r.returncode, 0)
 
-            r = root.run(["/usr/bin/false"])
+            r = root.run(["/usr/bin/false"], monitor)
             self.assertNotEqual(r.returncode, 0)
 
     @unittest.skipUnless(test.TestBase.have_test_data(), "no test-data access")
@@ -70,7 +70,7 @@ class TestBuildRoot(test.TestBase):
                    "/scripts",
                    "ro"]
 
-            r = root.run(cmd, readonly_binds=ro_binds)
+            r = root.run(cmd, monitor, readonly_binds=ro_binds)
             self.assertEqual(r.returncode, 0)
 
             cmd = ["/scripts/mount_flags.py",
@@ -78,7 +78,7 @@ class TestBuildRoot(test.TestBase):
                    "ro"]
 
             binds = [f"{rw_data}:/rw-data"]
-            r = root.run(cmd, binds=binds, readonly_binds=ro_binds)
+            r = root.run(cmd, monitor, binds=binds, readonly_binds=ro_binds)
             self.assertEqual(r.returncode, 1)
 
     @unittest.skipUnless(test.TestBase.have_test_data(), "no test-data access")
@@ -106,5 +106,5 @@ class TestBuildRoot(test.TestBase):
                    "/sys/fs/selinux",
                    "ro"]
 
-            r = root.run(cmd, readonly_binds=ro_binds)
+            r = root.run(cmd, monitor, readonly_binds=ro_binds)
             self.assertEqual(r.returncode, 0)