diff options
author | Vladyslav Drok <vdrok@mirantis.com> | 2019-08-30 14:52:42 +0200 |
---|---|---|
committer | Julia Kreger <juliaashleykreger@gmail.com> | 2019-10-18 17:38:20 +0000 |
commit | 899a0d3784284fb6c2b09e61fe2293eaaa7ac93f (patch) | |
tree | e61c813814d14aae8ee1519ccd7d7264b4ff8ae4 | |
parent | 39196ca9ef042cd056afed08deaa620cc83f58a8 (diff) | |
download | ironic-899a0d3784284fb6c2b09e61fe2293eaaa7ac93f.tar.gz |
Read in non-blocking fashion when starting console
As PID file is created by daemon, it might happen that although the
return code is 0, the PID file does not exist yet. And afterwards,
communicate() call might hang for some reason. As there is no way to
put timeout on communicate call in python2, and in order to make
this change more backportable, this patch uses non-blocking read to
get the values of stdout and stderr of the call.
Story: 2006514
Task: 36511
Change-Id: I0bf38321b0135ea17439d35081b5727fd4d827c8
(cherry picked from commit efc2d5fcd3e4c3d8e24801b45f61f7f747b7f340)
3 files changed, 108 insertions, 23 deletions
diff --git a/ironic/drivers/modules/console_utils.py b/ironic/drivers/modules/console_utils.py index 73828e61b..59e52fb36 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 f433a1520..c010fdef5 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 000000000..c8254218d --- /dev/null +++ b/releasenotes/notes/fix-shellinabox-pipe-not-ready-f860c4b7a1ef71a8.yaml @@ -0,0 +1,7 @@ +--- +fixes: + - | + Fixes a possible + `console lockup issue <https://storyboard.openstack.org/#!/story/2006514>`_ + in case of PID file not being yet created while daemon start has call + already returned success return code. |