diff --git a/ironic/drivers/modules/console_utils.py b/ironic/drivers/modules/console_utils.py index 73828e61bc..59e52fb369 100644 --- a/ironic/drivers/modules/console_utils.py +++ b/ironic/drivers/modules/console_utils.py @@ -20,6 +20,7 @@ Ironic console utilities. """ import errno +import fcntl import os import signal import subprocess @@ -159,6 +160,41 @@ def get_shellinabox_console_url(port): 'port': port} +class _PopenNonblockingPipe(object): + def __init__(self, source): + self._source = source + self._output = b'' + self._wait = False + self._finished = False + self._set_async() + + def _set_async(self): + flags = fcntl.fcntl(self._source, fcntl.F_GETFL) + fcntl.fcntl(self._source, fcntl.F_SETFL, flags | os.O_NONBLOCK) + + def read(self, num_bytes=4096): + if self._finished: + return + try: + if self._wait: + time.sleep(1) + self._wait = False + data = os.read(self._source.fileno(), num_bytes) + self._output += data + if len(data) < num_bytes: + self._wait = True + except OSError: + self._finished = True + + @property + def output(self): + return self._output + + @property + def finished(self): + return self._finished + + def start_shellinabox_console(node_uuid, port, console_cmd): """Open the serial console for a node. @@ -215,6 +251,9 @@ def start_shellinabox_console(node_uuid, port, console_cmd): 'node': node_uuid, 'command': ' '.join(args)} + stdout_pipe, stderr_pipe = ( + _PopenNonblockingPipe(obj.stdout), _PopenNonblockingPipe(obj.stderr)) + def _wait(node_uuid, popen_obj): locals['returncode'] = popen_obj.poll() @@ -226,14 +265,16 @@ def start_shellinabox_console(node_uuid, port, console_cmd): raise loopingcall.LoopingCallDone() if locals['returncode'] is not None: - (stdout, stderr) = popen_obj.communicate() + watched = (stdout_pipe, stderr_pipe) + while time.time() < expiration and not all( + (i.finished for i in watched)): + for pipe in watched: + pipe.read() locals['errstr'] = error_message + _( - "Exit code: %(return_code)s.\n" - "Stdout: %(stdout)r\n" + "Exit code: %(return_code)s.\nStdout: %(stdout)r\n" "Stderr: %(stderr)r") % { 'return_code': locals['returncode'], - 'stdout': stdout, - 'stderr': stderr} + 'stdout': stdout_pipe.output, 'stderr': stderr_pipe.output} raise loopingcall.LoopingCallDone() if time.time() > expiration: diff --git a/ironic/tests/unit/drivers/modules/test_console_utils.py b/ironic/tests/unit/drivers/modules/test_console_utils.py index f433a15201..c010fdef50 100644 --- a/ironic/tests/unit/drivers/modules/test_console_utils.py +++ b/ironic/tests/unit/drivers/modules/test_console_utils.py @@ -18,12 +18,14 @@ """Test class for console_utils driver module.""" import errno +import fcntl import os import random import signal import string import subprocess import tempfile +import time from ironic_lib import utils as ironic_utils import mock @@ -262,10 +264,11 @@ class ConsoleUtilsTestCase(db_base.DbTestCase): filepath, 'password') + @mock.patch.object(fcntl, 'fcntl', autospec=True) @mock.patch.object(console_utils, 'open', mock.mock_open(read_data='12345\n')) @mock.patch.object(os.path, 'exists', autospec=True) - @mock.patch.object(subprocess, 'Popen', autospec=True) + @mock.patch.object(subprocess, 'Popen') @mock.patch.object(psutil, 'pid_exists', autospec=True) @mock.patch.object(console_utils, '_ensure_console_pid_dir_exists', autospec=True) @@ -274,8 +277,10 @@ class ConsoleUtilsTestCase(db_base.DbTestCase): mock_dir_exists, mock_pid_exists, mock_popen, - mock_path_exists): + mock_path_exists, mock_fcntl): mock_popen.return_value.poll.return_value = 0 + mock_popen.return_value.stdout.return_value.fileno.return_value = 0 + mock_popen.return_value.stderr.return_value.fileno.return_value = 1 mock_pid_exists.return_value = True mock_path_exists.return_value = True @@ -291,10 +296,11 @@ class ConsoleUtilsTestCase(db_base.DbTestCase): stderr=subprocess.PIPE) mock_popen.return_value.poll.assert_called_once_with() + @mock.patch.object(fcntl, 'fcntl', autospec=True) @mock.patch.object(console_utils, 'open', mock.mock_open(read_data='12345\n')) @mock.patch.object(os.path, 'exists', autospec=True) - @mock.patch.object(subprocess, 'Popen', autospec=True) + @mock.patch.object(subprocess, 'Popen') @mock.patch.object(psutil, 'pid_exists', autospec=True) @mock.patch.object(console_utils, '_ensure_console_pid_dir_exists', autospec=True) @@ -303,10 +309,12 @@ class ConsoleUtilsTestCase(db_base.DbTestCase): mock_dir_exists, mock_pid_exists, mock_popen, - mock_path_exists): + mock_path_exists, mock_fcntl): # no existing PID file before starting mock_stop.side_effect = exception.NoConsolePid('/tmp/blah') mock_popen.return_value.poll.return_value = 0 + mock_popen.return_value.stdout.return_value.fileno.return_value = 0 + mock_popen.return_value.stderr.return_value.fileno.return_value = 1 mock_pid_exists.return_value = True mock_path_exists.return_value = True @@ -322,36 +330,54 @@ class ConsoleUtilsTestCase(db_base.DbTestCase): stderr=subprocess.PIPE) mock_popen.return_value.poll.assert_called_once_with() - @mock.patch.object(subprocess, 'Popen', autospec=True) + @mock.patch.object(time, 'sleep', autospec=True) + @mock.patch.object(os, 'read', autospec=True) + @mock.patch.object(fcntl, 'fcntl', autospec=True) + @mock.patch.object(subprocess, 'Popen') @mock.patch.object(console_utils, '_ensure_console_pid_dir_exists', autospec=True) @mock.patch.object(console_utils, '_stop_console', autospec=True) - def test_start_shellinabox_console_fail(self, mock_stop, mock_dir_exists, - mock_popen): + def test_start_shellinabox_console_fail( + self, mock_stop, mock_dir_exists, mock_popen, mock_fcntl, + mock_os_read, mock_sleep): mock_popen.return_value.poll.return_value = 1 - mock_popen.return_value.communicate.return_value = ('output', 'error') + stdout = mock_popen.return_value.stdout + stderr = mock_popen.return_value.stderr + stdout.return_value.fileno.return_value = 0 + stderr.return_value.fileno.return_value = 1 + err_output = b'error output' + mock_os_read.side_effect = [err_output] * 2 + [OSError] * 2 + mock_fcntl.side_effect = [1, mock.Mock()] * 2 self.assertRaisesRegex( - exception.ConsoleSubprocessFailed, "Stdout: 'output'", + exception.ConsoleSubprocessFailed, "Stdout: %r" % err_output, console_utils.start_shellinabox_console, self.info['uuid'], self.info['port'], 'ls&') mock_stop.assert_called_once_with(self.info['uuid']) + mock_sleep.assert_has_calls([mock.call(1), mock.call(1)]) mock_dir_exists.assert_called_once_with() + for obj in (stdout, stderr): + mock_fcntl.assert_has_calls([ + mock.call(obj, fcntl.F_GETFL), + mock.call(obj, fcntl.F_SETFL, 1 | os.O_NONBLOCK)]) mock_popen.assert_called_once_with(mock.ANY, stdout=subprocess.PIPE, stderr=subprocess.PIPE) mock_popen.return_value.poll.assert_called_with() - @mock.patch.object(subprocess, 'Popen', autospec=True) + @mock.patch.object(fcntl, 'fcntl', autospec=True) + @mock.patch.object(subprocess, 'Popen') @mock.patch.object(console_utils, '_ensure_console_pid_dir_exists', autospec=True) @mock.patch.object(console_utils, '_stop_console', autospec=True) def test_start_shellinabox_console_timeout( - self, mock_stop, mock_dir_exists, mock_popen): + self, mock_stop, mock_dir_exists, mock_popen, mock_fcntl): self.config(subprocess_timeout=0, group='console') self.config(subprocess_checking_interval=0, group='console') mock_popen.return_value.poll.return_value = None + mock_popen.return_value.stdout.return_value.fileno.return_value = 0 + mock_popen.return_value.stderr.return_value.fileno.return_value = 1 self.assertRaisesRegex( exception.ConsoleSubprocessFailed, 'Timeout or error', @@ -366,22 +392,28 @@ class ConsoleUtilsTestCase(db_base.DbTestCase): mock_popen.return_value.poll.assert_called_with() self.assertEqual(0, mock_popen.return_value.communicate.call_count) + @mock.patch.object(time, 'sleep', autospec=True) + @mock.patch.object(os, 'read', autospec=True) + @mock.patch.object(fcntl, 'fcntl', autospec=True) @mock.patch.object(console_utils, 'open', mock.mock_open(read_data='12345\n')) @mock.patch.object(os.path, 'exists', autospec=True) - @mock.patch.object(subprocess, 'Popen', autospec=True) + @mock.patch.object(subprocess, 'Popen') @mock.patch.object(psutil, 'pid_exists', autospec=True) @mock.patch.object(console_utils, '_ensure_console_pid_dir_exists', autospec=True) @mock.patch.object(console_utils, '_stop_console', autospec=True) - def test_start_shellinabox_console_fail_no_pid(self, mock_stop, - mock_dir_exists, - mock_pid_exists, - mock_popen, - mock_path_exists): + def test_start_shellinabox_console_fail_no_pid( + self, mock_stop, mock_dir_exists, mock_pid_exists, mock_popen, + mock_path_exists, mock_fcntl, mock_os_read, mock_sleep): mock_popen.return_value.poll.return_value = 0 + stdout = mock_popen.return_value.stdout + stderr = mock_popen.return_value.stderr + stdout.return_value.fileno.return_value = 0 + stderr.return_value.fileno.return_value = 1 mock_pid_exists.return_value = False - mock_popen.return_value.communicate.return_value = ('output', 'error') + mock_os_read.side_effect = [b'error output'] * 2 + [OSError] * 2 + mock_fcntl.side_effect = [1, mock.Mock()] * 2 mock_path_exists.return_value = True self.assertRaises(exception.ConsoleSubprocessFailed, @@ -391,7 +423,12 @@ class ConsoleUtilsTestCase(db_base.DbTestCase): 'ls&') mock_stop.assert_called_once_with(self.info['uuid']) + mock_sleep.assert_has_calls([mock.call(1), mock.call(1)]) mock_dir_exists.assert_called_once_with() + for obj in (stdout, stderr): + mock_fcntl.assert_has_calls([ + mock.call(obj, fcntl.F_GETFL), + mock.call(obj, fcntl.F_SETFL, 1 | os.O_NONBLOCK)]) mock_pid_exists.assert_called_with(12345) mock_popen.assert_called_once_with(mock.ANY, stdout=subprocess.PIPE, diff --git a/releasenotes/notes/fix-shellinabox-pipe-not-ready-f860c4b7a1ef71a8.yaml b/releasenotes/notes/fix-shellinabox-pipe-not-ready-f860c4b7a1ef71a8.yaml new file mode 100644 index 0000000000..c8254218d4 --- /dev/null +++ b/releasenotes/notes/fix-shellinabox-pipe-not-ready-f860c4b7a1ef71a8.yaml @@ -0,0 +1,7 @@ +--- +fixes: + - | + Fixes a possible + `console lockup issue `_ + in case of PID file not being yet created while daemon start has call + already returned success return code.