diff --git a/ironic/drivers/modules/console_utils.py b/ironic/drivers/modules/console_utils.py index 5af5835884..73828e61bc 100644 --- a/ironic/drivers/modules/console_utils.py +++ b/ironic/drivers/modules/console_utils.py @@ -209,6 +209,12 @@ def start_shellinabox_console(node_uuid, port, console_cmd): LOG.warning(error) raise exception.ConsoleSubprocessFailed(error=error) + error_message = _( + "Timeout or error while waiting for console subprocess to start for " + "node: %(node)s.\nCommand: %(command)s.\n") % { + 'node': node_uuid, + 'command': ' '.join(args)} + def _wait(node_uuid, popen_obj): locals['returncode'] = popen_obj.poll() @@ -216,24 +222,22 @@ def start_shellinabox_console(node_uuid, port, console_cmd): # if it is, then the shellinaboxd is invoked successfully as a daemon. # otherwise check the error. if (locals['returncode'] == 0 and os.path.exists(pid_file) - and psutil.pid_exists(_get_console_pid(node_uuid))): + and psutil.pid_exists(_get_console_pid(node_uuid))): raise loopingcall.LoopingCallDone() - if (time.time() > expiration or locals['returncode'] is not None): + if locals['returncode'] is not None: (stdout, stderr) = popen_obj.communicate() - locals['errstr'] = _( - "Timeout or error while waiting for console " - "subprocess to start for node: %(node)s.\n" - "Command: %(command)s.\n" + locals['errstr'] = error_message + _( "Exit code: %(return_code)s.\n" "Stdout: %(stdout)r\n" "Stderr: %(stderr)r") % { - 'node': node_uuid, - 'command': ' '.join(args), 'return_code': locals['returncode'], 'stdout': stdout, 'stderr': stderr} - LOG.warning(locals['errstr']) + raise loopingcall.LoopingCallDone() + + if time.time() > expiration: + locals['errstr'] = error_message raise loopingcall.LoopingCallDone() locals = {'returncode': None, 'errstr': ''} @@ -242,6 +246,7 @@ def start_shellinabox_console(node_uuid, port, console_cmd): timer.start(interval=CONF.console.subprocess_checking_interval).wait() if locals['errstr']: + LOG.warning(locals['errstr']) raise exception.ConsoleSubprocessFailed(error=locals['errstr']) diff --git a/ironic/tests/unit/drivers/modules/test_console_utils.py b/ironic/tests/unit/drivers/modules/test_console_utils.py index 4c83fb169c..f433a15201 100644 --- a/ironic/tests/unit/drivers/modules/test_console_utils.py +++ b/ironic/tests/unit/drivers/modules/test_console_utils.py @@ -331,11 +331,10 @@ class ConsoleUtilsTestCase(db_base.DbTestCase): mock_popen.return_value.poll.return_value = 1 mock_popen.return_value.communicate.return_value = ('output', 'error') - self.assertRaises(exception.ConsoleSubprocessFailed, - console_utils.start_shellinabox_console, - self.info['uuid'], - self.info['port'], - 'ls&') + self.assertRaisesRegex( + exception.ConsoleSubprocessFailed, "Stdout: 'output'", + console_utils.start_shellinabox_console, self.info['uuid'], + self.info['port'], 'ls&') mock_stop.assert_called_once_with(self.info['uuid']) mock_dir_exists.assert_called_once_with() @@ -344,6 +343,29 @@ class ConsoleUtilsTestCase(db_base.DbTestCase): stderr=subprocess.PIPE) mock_popen.return_value.poll.assert_called_with() + @mock.patch.object(subprocess, 'Popen', 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_timeout( + self, mock_stop, mock_dir_exists, mock_popen): + self.config(subprocess_timeout=0, group='console') + self.config(subprocess_checking_interval=0, group='console') + mock_popen.return_value.poll.return_value = None + + self.assertRaisesRegex( + exception.ConsoleSubprocessFailed, 'Timeout or error', + console_utils.start_shellinabox_console, self.info['uuid'], + self.info['port'], 'ls&') + + mock_stop.assert_called_once_with(self.info['uuid']) + mock_dir_exists.assert_called_once_with() + mock_popen.assert_called_once_with(mock.ANY, + stdout=subprocess.PIPE, + stderr=subprocess.PIPE) + mock_popen.return_value.poll.assert_called_with() + self.assertEqual(0, mock_popen.return_value.communicate.call_count) + @mock.patch.object(console_utils, 'open', mock.mock_open(read_data='12345\n')) @mock.patch.object(os.path, 'exists', autospec=True) diff --git a/releasenotes/notes/fix-shellinabox-console-subprocess-timeout-d3eccfe0440013d7.yaml b/releasenotes/notes/fix-shellinabox-console-subprocess-timeout-d3eccfe0440013d7.yaml new file mode 100644 index 0000000000..10a3f09d0e --- /dev/null +++ b/releasenotes/notes/fix-shellinabox-console-subprocess-timeout-d3eccfe0440013d7.yaml @@ -0,0 +1,7 @@ +--- +fixes: + - | + Fixed the `issue `_ + with node being locked for longer than ``[console]subprocess_timeout`` + seconds when shellinabox process fails to start before the specifed timeout + elapses.