Fix cmd execution stderr, stdout unicode errors

If we run a command that returns non ascii character on stdout or stderr
using _execute attribute from Executor class or any of the inheriting
classes and we try to use stdout or stderr in the logs without decoding
it first, it will results in an exception like:

 UnicodeDecodeError: 'ascii' codec can't decode byte 0xe2 in position
 19: ordinal not in range(128)

In existing code this can happen in quite a lot of places, and not only
where we are logging an error but also when we are logging progress or
debug information.

For example when running dd we could get in stdout:

 1+0 registros leídos
 1+0 registros escritos
 512 bytes (512 B) copiados, 0,000368406 s, 1,4 MB/s

Instead of decoding stdout and stderr whenever we want to use them, this
patch takes another approach, capturing ProcessExecutionError exceptions
and converting string field to unicode and converting returned values of
the execution as well.  That way we can safely use the exception
contents and returned values anywhere in the code.

Closes-Bug: #1602346
Change-Id: I46d8a47ae4f638dbb4b0dc125008bceb0f29fa15

os_brick/executor.py

@@ -18,6 +18,9 @@
    and root_helper settings, so this provides that hook.
 """
 
+from oslo_concurrency import processutils as putils
+from oslo_utils import encodeutils
+
 from os_brick.privileged import rootwrap as priv_rootwrap
 
 
@@ -29,8 +32,31 @@ class Executor(object):
         self.set_execute(execute)
         self.set_root_helper(root_helper)
 
+    @staticmethod
+    def safe_decode(string):
+        return string and encodeutils.safe_decode(string, errors='ignore')
+
+    @classmethod
+    def make_putils_error_safe(cls, exc):
+        """Converts ProcessExecutionError string attributes to unicode."""
+        for field in ('stderr', 'stdout', 'cmd', 'description'):
+            value = getattr(exc, field, None)
+            if value:
+                setattr(exc, field, cls.safe_decode(value))
+
+    def _execute(self, *args, **kwargs):
+        try:
+            result = self.__execute(*args, **kwargs)
+            if result:
+                result = (self.safe_decode(result[0]),
+                          self.safe_decode(result[1]))
+            return result
+        except putils.ProcessExecutionError as e:
+            self.make_putils_error_safe(e)
+            raise
+
     def set_execute(self, execute):
-        self._execute = execute
+        self.__execute = execute
 
     def set_root_helper(self, helper):
         self._root_helper = helper

os_brick/tests/encryptors/test_base.py

@@ -47,6 +47,15 @@ class VolumeEncryptorTestCase(base.TestCase):
                                       keymgr=fake.fake_api(),
                                       execute=self.mock_execute)
 
+    def assert_exec_has_calls(self, expected_calls, any_order=False):
+        """Check that the root exec mock has calls, excluding child calls."""
+        if any_order:
+            self.assertSetEqual(set(expected_calls),
+                                set(self.mock_execute.call_args_list))
+        else:
+            self.assertListEqual(expected_calls,
+                                 self.mock_execute.call_args_list)
+
     def test_get_encryptors(self):
         root_helper = None
 

os_brick/tests/encryptors/test_cryptsetup.py

@@ -33,6 +33,8 @@ def fake__get_key(context):
     return symmetric_key
 
 
+@mock.patch('os_brick.executor.encodeutils.safe_decode',
+            lambda x, errors=None: x)
 class CryptsetupEncryptorTestCase(test_base.VolumeEncryptorTestCase):
     @mock.patch('os.path.exists', return_value=False)
     def _create(self, mock_exists, root_helper,
@@ -53,14 +55,13 @@ class CryptsetupEncryptorTestCase(test_base.VolumeEncryptorTestCase):
     def test__open_volume(self):
         self.encryptor._open_volume("passphrase")
 
-        self.mock_execute.assert_has_calls([
+        self.assert_exec_has_calls([
             mock.call('cryptsetup', 'create', '--key-file=-', self.dev_name,
                       self.dev_path, process_input='passphrase',
                       run_as_root=True,
                       root_helper=self.root_helper,
                       check_exit_code=True),
         ])
-        self.assertEqual(1, self.mock_execute.call_count)
 
     def test_attach_volume(self):
         self.encryptor._get_key = mock.MagicMock()
@@ -68,7 +69,7 @@ class CryptsetupEncryptorTestCase(test_base.VolumeEncryptorTestCase):
 
         self.encryptor.attach_volume(None)
 
-        self.mock_execute.assert_has_calls([
+        self.assert_exec_has_calls([
             mock.call('cryptsetup', 'create', '--key-file=-', self.dev_name,
                       self.dev_path, process_input='0' * 32,
                       root_helper=self.root_helper,
@@ -78,27 +79,24 @@ class CryptsetupEncryptorTestCase(test_base.VolumeEncryptorTestCase):
                       root_helper=self.root_helper,
                       run_as_root=True, check_exit_code=True),
         ])
-        self.assertEqual(2, self.mock_execute.call_count)
 
     def test__close_volume(self):
         self.encryptor.detach_volume()
 
-        self.mock_execute.assert_has_calls([
+        self.assert_exec_has_calls([
             mock.call('cryptsetup', 'remove', self.dev_name,
                       root_helper=self.root_helper,
                       run_as_root=True, check_exit_code=True),
         ])
-        self.assertEqual(1, self.mock_execute.call_count)
 
     def test_detach_volume(self):
         self.encryptor.detach_volume()
 
-        self.mock_execute.assert_has_calls([
+        self.assert_exec_has_calls([
             mock.call('cryptsetup', 'remove', self.dev_name,
                       root_helper=self.root_helper,
                       run_as_root=True, check_exit_code=True),
         ])
-        self.assertEqual(1, self.mock_execute.call_count)
 
     def test_init_volume_encryption_not_supported(self):
         # Tests that creating a CryptsetupEncryptor fails if there is no

os_brick/tests/encryptors/test_luks.py

@@ -21,6 +21,8 @@ from os_brick.tests.encryptors import test_cryptsetup
 from oslo_concurrency import processutils as putils
 
 
+@mock.patch('os_brick.executor.encodeutils.safe_decode',
+            lambda x, errors=None: x)
 class LuksEncryptorTestCase(test_cryptsetup.CryptsetupEncryptorTestCase):
     def _create(self, root_helper, connection_info, keymgr, execute):
         return luks.LuksEncryptor(root_helper=root_helper,
@@ -31,12 +33,11 @@ class LuksEncryptorTestCase(test_cryptsetup.CryptsetupEncryptorTestCase):
     def test_is_luks(self):
         luks.is_luks(self.root_helper, self.dev_path)
 
-        self.mock_execute.assert_has_calls([
+        self.assert_exec_has_calls([
             mock.call('cryptsetup', 'isLuks', '--verbose', self.dev_path,
                       run_as_root=True, root_helper=self.root_helper,
                       check_exit_code=True),
         ], any_order=False)
-        self.assertEqual(1, self.mock_execute.call_count)
 
     @mock.patch('os_brick.encryptors.luks.LOG')
     def test_is_luks_with_error(self, mock_log):
@@ -47,46 +48,43 @@ class LuksEncryptorTestCase(test_cryptsetup.CryptsetupEncryptorTestCase):
 
         luks.is_luks(self.root_helper, self.dev_path)
 
-        self.mock_execute.assert_has_calls([
+        self.assert_exec_has_calls([
             mock.call('cryptsetup', 'isLuks', '--verbose', self.dev_path,
                       run_as_root=True, root_helper=self.root_helper,
                       check_exit_code=True),
         ])
-        self.assertEqual(1, self.mock_execute.call_count)
 
         self.assertEqual(1, mock_log.warning.call_count)  # warning logged
 
     def test_is_luks_with_execute(self):
         mock_execute = mock.Mock()
         luks.is_luks(self.root_helper, self.dev_path, execute=mock_execute)
-        mock_execute.assert_has_calls([
+        self.assertListEqual(
-            mock.call('cryptsetup', 'isLuks', '--verbose', self.dev_path,
+            [mock.call('cryptsetup', 'isLuks', '--verbose', self.dev_path,
-                      run_as_root=True, root_helper=self.root_helper,
+                       run_as_root=True, root_helper=self.root_helper,
-                      check_exit_code=True),
+                       check_exit_code=True)],
-        ])
+            mock_execute.call_args_list)
 
     def test__format_volume(self):
         self.encryptor._format_volume("passphrase")
 
-        self.mock_execute.assert_has_calls([
+        self.assert_exec_has_calls([
             mock.call('cryptsetup', '--batch-mode', 'luksFormat',
                       '--key-file=-', self.dev_path,
                       process_input='passphrase',
                       root_helper=self.root_helper,
                       run_as_root=True, check_exit_code=True, attempts=3),
         ])
-        self.assertEqual(1, self.mock_execute.call_count)
 
     def test__open_volume(self):
         self.encryptor._open_volume("passphrase")
 
-        self.mock_execute.assert_has_calls([
+        self.assert_exec_has_calls([
             mock.call('cryptsetup', 'luksOpen', '--key-file=-', self.dev_path,
                       self.dev_name, process_input='passphrase',
                       root_helper=self.root_helper,
                       run_as_root=True, check_exit_code=True),
         ])
-        self.assertEqual(1, self.mock_execute.call_count)
 
     def test_attach_volume(self):
         self.encryptor._get_key = mock.MagicMock()
@@ -95,7 +93,7 @@ class LuksEncryptorTestCase(test_cryptsetup.CryptsetupEncryptorTestCase):
 
         self.encryptor.attach_volume(None)
 
-        self.mock_execute.assert_has_calls([
+        self.assert_exec_has_calls([
             mock.call('cryptsetup', 'luksOpen', '--key-file=-', self.dev_path,
                       self.dev_name, process_input='0' * 32,
                       root_helper=self.root_helper,
@@ -105,7 +103,6 @@ class LuksEncryptorTestCase(test_cryptsetup.CryptsetupEncryptorTestCase):
                       root_helper=self.root_helper,
                       run_as_root=True, check_exit_code=True),
         ])
-        self.assertEqual(2, self.mock_execute.call_count)
 
     def test_attach_volume_not_formatted(self):
         self.encryptor._get_key = mock.MagicMock()
@@ -122,7 +119,7 @@ class LuksEncryptorTestCase(test_cryptsetup.CryptsetupEncryptorTestCase):
 
         self.encryptor.attach_volume(None)
 
-        self.mock_execute.assert_has_calls([
+        self.assert_exec_has_calls([
             mock.call('cryptsetup', 'luksOpen', '--key-file=-', self.dev_path,
                       self.dev_name, process_input='0' * 32,
                       root_helper=self.root_helper,
@@ -143,7 +140,6 @@ class LuksEncryptorTestCase(test_cryptsetup.CryptsetupEncryptorTestCase):
                       root_helper=self.root_helper,
                       run_as_root=True, check_exit_code=True),
         ], any_order=False)
-        self.assertEqual(5, self.mock_execute.call_count)
 
     def test_attach_volume_fail(self):
         self.encryptor._get_key = mock.MagicMock()
@@ -158,7 +154,7 @@ class LuksEncryptorTestCase(test_cryptsetup.CryptsetupEncryptorTestCase):
         self.assertRaises(putils.ProcessExecutionError,
                           self.encryptor.attach_volume, None)
 
-        self.mock_execute.assert_has_calls([
+        self.assert_exec_has_calls([
             mock.call('cryptsetup', 'luksOpen', '--key-file=-', self.dev_path,
                       self.dev_name, process_input='0' * 32,
                       root_helper=self.root_helper,
@@ -167,24 +163,21 @@ class LuksEncryptorTestCase(test_cryptsetup.CryptsetupEncryptorTestCase):
                       root_helper=self.root_helper,
                       run_as_root=True, check_exit_code=True),
         ], any_order=False)
-        self.assertEqual(2, self.mock_execute.call_count)
 
     def test__close_volume(self):
         self.encryptor.detach_volume()
 
-        self.mock_execute.assert_has_calls([
+        self.assert_exec_has_calls([
             mock.call('cryptsetup', 'luksClose', self.dev_name,
                       root_helper=self.root_helper,
                       attempts=3, run_as_root=True, check_exit_code=True),
         ])
-        self.assertEqual(1, self.mock_execute.call_count)
 
     def test_detach_volume(self):
         self.encryptor.detach_volume()
 
-        self.mock_execute.assert_has_calls([
+        self.assert_exec_has_calls([
             mock.call('cryptsetup', 'luksClose', self.dev_name,
                       root_helper=self.root_helper,
                       attempts=3, run_as_root=True, check_exit_code=True),
         ])
-        self.assertEqual(1, self.mock_execute.call_count)

os_brick/tests/initiator/connectors/test_rbd.py

@@ -106,7 +106,7 @@ class RBDConnectorTestCase(test_connector.ConnectorTestCase):
         self.assertEqual(conf_path, tmpfile)
         mock_mkstemp.assert_called_once_with()
 
-    @mock.patch.object(priv_rootwrap, 'execute')
+    @mock.patch.object(priv_rootwrap, 'execute', return_value=None)
     def test_connect_local_volume(self, mock_execute):
         rbd_connector = rbd.RBDConnector(None, do_local_attach=True)
         conn = {'name': 'pool/image'}
@@ -131,7 +131,7 @@ class RBDConnectorTestCase(test_connector.ConnectorTestCase):
 
         self.assertEqual(1, volume_close.call_count)
 
-    @mock.patch.object(priv_rootwrap, 'execute')
+    @mock.patch.object(priv_rootwrap, 'execute', return_value=None)
     def test_disconnect_local_volume(self, mock_execute):
         rbd_connector = rbd.RBDConnector(None, do_local_attach=True)
         conn = {'name': 'pool/image'}

os_brick/tests/remotefs/test_remotefs.py

@@ -29,7 +29,8 @@ class RemoteFsClientTestCase(base.TestCase):
 
     def setUp(self):
         super(RemoteFsClientTestCase, self).setUp()
-        self.mock_execute = self.mock_object(priv_rootwrap, 'execute')
+        self.mock_execute = self.mock_object(priv_rootwrap, 'execute',
+                                             return_value=None)
 
     @mock.patch.object(remotefs.RemoteFsClient, '_read_mounts',
                        return_value=[])
@@ -217,7 +218,7 @@ class ScalityRemoteFsClientTestCase(base.TestCase):
             'scality', root_helper='true', scality_mount_point_base='/fake')
         self.assertEqual('/fake/path/00', fsclient.get_mount_point('path'))
 
-    @mock.patch('oslo_concurrency.processutils.execute')
+    @mock.patch('oslo_concurrency.processutils.execute', return_value=None)
     @mock.patch('os_brick.remotefs.remotefs.RemoteFsClient._do_mount')
     def test_mount(self, mock_do_mount, mock_execute):
         fsclient = remotefs.ScalityRemoteFsClient(

os_brick/tests/test_executor.py

@@ -1,3 +1,4 @@
+# encoding=utf8
 # (c) Copyright 2015 Hewlett-Packard Development Company, L.P.
 #
 #    Licensed under the Apache License, Version 2.0 (the "License"); you may
@@ -15,6 +16,9 @@
 # import time
 
 import mock
+from oslo_concurrency import processutils as putils
+import six
+import testtools
 
 from os_brick import executor as brick_executor
 from os_brick.privileged import rootwrap
@@ -24,14 +28,62 @@ from os_brick.tests import base
 class TestExecutor(base.TestCase):
     def test_default_execute(self):
         executor = brick_executor.Executor(root_helper=None)
-        self.assertEqual(rootwrap.execute, executor._execute)
+        self.assertEqual(rootwrap.execute, executor._Executor__execute)
 
     def test_none_execute(self):
         executor = brick_executor.Executor(root_helper=None, execute=None)
-        self.assertEqual(rootwrap.execute, executor._execute)
+        self.assertEqual(rootwrap.execute, executor._Executor__execute)
 
     def test_fake_execute(self):
         mock_execute = mock.Mock()
         executor = brick_executor.Executor(root_helper=None,
                                            execute=mock_execute)
-        self.assertEqual(mock_execute, executor._execute)
+        self.assertEqual(mock_execute, executor._Executor__execute)
+
+    @mock.patch('sys.stdin', encoding='UTF-8')
+    @mock.patch('os_brick.executor.priv_rootwrap.execute')
+    def test_execute_non_safe_str_exception(self, execute_mock, stdin_mock):
+        execute_mock.side_effect = putils.ProcessExecutionError(
+            stdout='España', stderr='Zürich')
+
+        executor = brick_executor.Executor(root_helper=None)
+        exc = self.assertRaises(putils.ProcessExecutionError,
+                                executor._execute)
+        self.assertEqual(u'Espa\xf1a', exc.stdout)
+        self.assertEqual(u'Z\xfcrich', exc.stderr)
+
+    @mock.patch('sys.stdin', encoding='UTF-8')
+    @mock.patch('os_brick.executor.priv_rootwrap.execute')
+    def test_execute_non_safe_str(self, execute_mock, stdin_mock):
+        execute_mock.return_value = ('España', 'Zürich')
+
+        executor = brick_executor.Executor(root_helper=None)
+        stdout, stderr = executor._execute()
+        self.assertEqual(u'Espa\xf1a', stdout)
+        self.assertEqual(u'Z\xfcrich', stderr)
+
+    @testtools.skipUnless(six.PY3, 'Specific test for Python 3')
+    @mock.patch('sys.stdin', encoding='UTF-8')
+    @mock.patch('os_brick.executor.priv_rootwrap.execute')
+    def test_execute_non_safe_bytes_exception(self, execute_mock, stdin_mock):
+        execute_mock.side_effect = putils.ProcessExecutionError(
+            stdout=six.binary_type('España', 'utf-8'),
+            stderr=six.binary_type('Zürich', 'utf-8'))
+
+        executor = brick_executor.Executor(root_helper=None)
+        exc = self.assertRaises(putils.ProcessExecutionError,
+                                executor._execute)
+        self.assertEqual(u'Espa\xf1a', exc.stdout)
+        self.assertEqual(u'Z\xfcrich', exc.stderr)
+
+    @testtools.skipUnless(six.PY3, 'Specific test for Python 3')
+    @mock.patch('sys.stdin', encoding='UTF-8')
+    @mock.patch('os_brick.executor.priv_rootwrap.execute')
+    def test_execute_non_safe_bytes(self, execute_mock, stdin_mock):
+        execute_mock.return_value = (six.binary_type('España', 'utf-8'),
+                                     six.binary_type('Zürich', 'utf-8'))
+
+        executor = brick_executor.Executor(root_helper=None)
+        stdout, stderr = executor._execute()
+        self.assertEqual(u'Espa\xf1a', stdout)
+        self.assertEqual(u'Z\xfcrich', stderr)