launchpad-reviewers team mailing list archive

[Colin Watson <cjwatson@xxxxxxxxxxxxx>]

Colin Watson has proposed merging ~cjwatson/launchpad-buildd:runSubProcess-bytes into launchpad-buildd:master.

Commit message:
Fix handling of bytes arguments passed to BuildManager.runSubProcess

Requested reviews:
  Launchpad code reviewers (launchpad-reviewers)

For more details, see:
https://code.launchpad.net/~cjwatson/launchpad-buildd/+git/launchpad-buildd/+merge/391295

This requires some ridiculous contortions to avoid problems with Twisted logging, especially on Python 2.
-- 
Your team Launchpad code reviewers is requested to review the proposed merge of ~cjwatson/launchpad-buildd:runSubProcess-bytes into launchpad-buildd:master.

diff --git a/debian/changelog b/debian/changelog
index 1d3540b..e46111d 100644
--- a/debian/changelog
+++ b/debian/changelog
@@ -1,3 +1,9 @@
+launchpad-buildd (193) UNRELEASED; urgency=medium
+
+  * Fix handling of bytes arguments passed to BuildManager.runSubProcess.
+
+ -- Colin Watson <cjwatson@xxxxxxxxxx>  Thu, 24 Sep 2020 16:45:27 +0100
+
 launchpad-buildd (192) bionic; urgency=medium
 
   * Update Maintainer to launchpad-dev.
diff --git a/lpbuildd/builder.py b/lpbuildd/builder.py
index 4c4135a..5e459be 100644
--- a/lpbuildd/builder.py
+++ b/lpbuildd/builder.py
@@ -16,6 +16,7 @@ import shutil
 import tempfile
 
 import apt
+import six
 from six.moves.urllib.request import (
     build_opener,
     HTTPBasicAuthHandler,
@@ -145,8 +146,11 @@ class BuildManager(object):
         if iterate is None:
             iterate = self.iterate
         self._subprocess = RunCapture(self._builder, iterate, stdin=stdin)
+        text_args = [
+            arg.decode("UTF-8", "replace") if isinstance(arg, bytes) else arg
+            for arg in args[1:]]
         self._builder.log("RUN: %s %s\n" % (
-            command, " ".join(shell_escape(arg) for arg in args[1:])))
+            command, " ".join(shell_escape(arg) for arg in text_args)))
         childfds = {
             0: devnull.fileno() if stdin is None else "w",
             1: "r",
@@ -516,11 +520,24 @@ class Builder(object):
                 data if isinstance(data, bytes) else data.encode("UTF-8"))
             self._log.write(data_bytes)
             self._log.flush()
-        if not isinstance(data, str):
-            data = data.decode("UTF-8", "replace")
-        if data.endswith("\n"):
-            data = data[:-1]
-        log.msg("Build log: " + data)
+        data_text = (
+            data if isinstance(data, six.text_type)
+            else data.decode("UTF-8", "replace"))
+        if six.PY3:
+            data_str = data_text
+        else:
+            # Twisted's logger doesn't handle non-ASCII text very reliably
+            # on Python 2.  This is just for debugging, so replace non-ASCII
+            # characters with the corresponding \u escapes.  We need to go
+            # to ridiculous lengths here to avoid (e.g.) replacing newlines
+            # with "\n".
+            data_str = re.sub(
+                r"([^\x00-\x7f])",
+                lambda match: "\\u%04x" % ord(match.group(0)),
+                data_text).encode("UTF-8")
+        if data_str.endswith("\n"):
+            data_str = data_str[:-1]
+        log.msg("Build log: " + data_str)
 
     def getLogTail(self):
         """Return the tail of the log.
diff --git a/lpbuildd/tests/test_builder.py b/lpbuildd/tests/test_builder.py
new file mode 100644
index 0000000..2048bc6
--- /dev/null
+++ b/lpbuildd/tests/test_builder.py
@@ -0,0 +1,83 @@
+# Copyright 2020 Canonical Ltd.  This software is licensed under the
+# GNU Affero General Public License version 3 (see the file LICENSE).
+
+"""Test BuildManager directly.
+
+Most tests are done on subclasses instead.
+"""
+
+import io
+import re
+
+from fixtures import (
+    FakeLogger,
+    TempDir,
+    )
+import six
+from testtools import TestCase
+from testtools.deferredruntest import AsynchronousDeferredRunTest
+from twisted.internet import defer
+from twisted.python import log
+
+from lpbuildd.builder import (
+    Builder,
+    BuildManager,
+    )
+from lpbuildd.tests.fakebuilder import FakeConfig
+
+
+class TestBuildManager(TestCase):
+
+    run_tests_with = AsynchronousDeferredRunTest.make_factory(timeout=5)
+
+    def setUp(self):
+        super(TestBuildManager, self).setUp()
+        observer = log.PythonLoggingObserver()
+        observer.start()
+        self.addCleanup(observer.stop)
+
+    @defer.inlineCallbacks
+    def test_runSubProcess(self):
+        logger = self.useFixture(FakeLogger())
+        config = FakeConfig()
+        config.set("builder", "filecache", self.useFixture(TempDir()).path)
+        builder = Builder(config)
+        builder._log = io.BytesIO()
+        manager = BuildManager(builder, "123")
+        d = defer.Deferred()
+        manager.iterate = d.callback
+        manager.runSubProcess("echo", ["echo", "hello world"])
+        code = yield d
+        self.assertEqual(0, code)
+        self.assertEqual(
+            b"RUN: echo 'hello world'\n"
+            b"hello world\n",
+            builder._log.getvalue())
+        self.assertEqual(
+            "Build log: RUN: echo 'hello world'\n"
+            "Build log: hello world\n",
+            logger.output)
+
+    @defer.inlineCallbacks
+    def test_runSubProcess_bytes(self):
+        logger = self.useFixture(FakeLogger())
+        config = FakeConfig()
+        config.set("builder", "filecache", self.useFixture(TempDir()).path)
+        builder = Builder(config)
+        builder._log = io.BytesIO()
+        manager = BuildManager(builder, "123")
+        d = defer.Deferred()
+        manager.iterate = d.callback
+        manager.runSubProcess("echo", ["echo", u"\N{SNOWMAN}".encode("UTF-8")])
+        code = yield d
+        self.assertEqual(0, code)
+        self.assertEqual(
+            u"RUN: echo '\N{SNOWMAN}'\n"
+            u"\N{SNOWMAN}\n".encode("UTF-8"),
+            builder._log.getvalue())
+        logged_snowman = '\N{SNOWMAN}' if six.PY3 else '\\u2603'
+        self.assertEqual(
+            ["Build log: RUN: echo '%s'" % logged_snowman,
+             "Build log: %s" % logged_snowman],
+            [re.sub(r".*? \[-\] (.*)", r"\1", line)
+             for line in logger.output.splitlines()])