utils: run() handle unicode decode failure

probert/tests/test_utils.py

@@ -5,7 +5,7 @@
 import tempfile
 import testtools
 import textwrap
-# import unittest
+import unittest
 
 from probert import utils
 from probert.tests.helpers import random_string, simple_mocked_open
@@ -180,3 +180,24 @@ def test_run_failure(self):
             )]
             self.assertIsNone(actual)
             self.assertEqual(expected, m_logs.output)
+
+    def test_run_nonunicode_out(self):
+        with self.assertLogs('probert.utils', level=logging.DEBUG) as m_logs:
+            with unittest.mock.patch('subprocess.run') as m_run:
+                m_run.return_value = unittest.mock.Mock()
+                m_run.return_value.returncode = 0
+                m_run.return_value.stdout = b'r\xe9serv\xe9e'
+                m_run.return_value.stderr = b''
+                actual = utils.run(['cmd'])
+        expected = [self.leader + line for line in (
+            'Command `cmd` exited with result: 0',
+            'UnicodeDecodeError on stdout: '
+            "'utf-8' codec can't decode byte 0xe9 in position 1: "
+            'invalid continuation byte',
+            'stdout: ------------------------------------------',
+            'r\\xe9serv\\xe9e',
+            '<empty stderr>',
+            '--------------------------------------------------',
+        )]
+        self.assertIsNone(actual)
+        self.assertEqual(expected, m_logs.output)

probert/utils.py

@@ -42,29 +42,37 @@ def _clean_env(env):
     return env
 
 
-def _log_stream(stream, name):
+def _decode_stream(stream, name):
     if stream:
+        try:
+            log_input = text = stream.decode('utf-8')
+        except UnicodeDecodeError as ude:
+            log.debug(f'UnicodeDecodeError on {name}: {ude}')
+            text = None
+            log_input = stream.decode('utf-8', 'backslashreplace')
         log.debug(f'{name}: ------------------------------------------')
-        for line in stream.splitlines():
+        for line in log_input.splitlines():
             log.debug(line)
+        return text
     else:
         log.debug(f'<empty {name}>')
+        return ''
 
 
 def run(cmdarr, env=None, **kw):
-    """Run the given, with stdout, stderr, and return code always logged.
+    """Run the given command with stdout, stderr, return code always logged.
     Returns the stdout on command success, or None on command failure."""
     env = _clean_env(env)
-    sp = subprocess.run(cmdarr, text=True, env=env,
+    sp = subprocess.run(cmdarr, text=False, env=env,
                         stdout=PIPE, stderr=PIPE, **kw)
     display_cmd = shlex.join(cmdarr)
     rc = sp.returncode
     log.debug(f'Command `{display_cmd}` exited with result: {rc}')
-    _log_stream(sp.stdout, 'stdout')
-    _log_stream(sp.stderr, 'stderr')
+    stdout = _decode_stream(sp.stdout, 'stdout')
+    _decode_stream(sp.stderr, 'stderr')
     log.debug('--------------------------------------------------')
-    if sp.returncode == 0:
-        return sp.stdout
+    if stdout is not None and sp.returncode == 0:
+        return stdout
     return None