Log VM console when Rally fails to connect to VM

Change-Id: Ib7556f9382d9219027ec0651036553c3f33b8295
This commit is contained in:
Piyush Raman Srivastava 2016-02-04 07:25:53 -08:00
parent cc5794c395
commit 9bcdd4d174
5 changed files with 80 additions and 36 deletions

View File

@ -65,21 +65,12 @@ import time
import paramiko
import six
from rally.common.i18n import _
from rally.common import logging
from rally import exceptions
LOG = logging.getLogger(__name__)
class SSHError(Exception):
pass
class SSHTimeout(SSHError):
pass
class SSH(object):
"""Represent ssh connection."""
@ -112,7 +103,7 @@ class SSH(object):
return key_class.from_private_key(key)
except paramiko.SSHException as e:
errors.append(e)
raise SSHError("Invalid pkey: %s" % (errors))
raise exceptions.SSHError("Invalid pkey: %s" % (errors))
def _get_client(self):
if self._client:
@ -126,15 +117,15 @@ class SSH(object):
password=self.password, timeout=1)
return self._client
except Exception as e:
message = _("Exception %(exception_type)s was raised "
"during connect to %(user)s@%(host)s:%(port)s. "
"Exception value is: %(exception)r")
message = ("Exception %(exception_type)s was raised "
"during connect to %(user)s@%(host)s:%(port)s. "
"Exception value is: %(exception)r")
self._client = False
raise SSHError(message % {"exception": e,
"user": self.user,
"host": self.host,
"port": self.port,
"exception_type": type(e)})
raise exceptions.SSHError(message % {"exception": e,
"user": self.user,
"host": self.host,
"port": self.port,
"exception_type": type(e)})
def close(self):
self._client.close()
@ -220,18 +211,19 @@ class SSH(object):
if timeout and (time.time() - timeout) > start_time:
args = {"cmd": cmd, "host": self.host}
raise SSHTimeout(_("Timeout executing command "
"'%(cmd)s' on host %(host)s") % args)
raise exceptions.SSHTimeout("Timeout executing command "
"'%(cmd)s' on host %(host)s"
% args)
if e:
raise SSHError("Socket error.")
raise exceptions.SSHError("Socket error.")
exit_status = session.recv_exit_status()
if 0 != exit_status and raise_on_error:
fmt = _("Command '%(cmd)s' failed with exit_status %(status)d.")
fmt = "Command '%(cmd)s' failed with exit_status %(status)d."
details = fmt % {"cmd": cmd, "status": exit_status}
if stderr_data:
details += _(" Last stderr data: '%s'.") % stderr_data
raise SSHError(details)
details += " Last stderr data: '%s'." % stderr_data
raise exceptions.SSHError(details)
return exit_status
def execute(self, cmd, stdin=None, timeout=3600):
@ -259,11 +251,12 @@ class SSH(object):
while True:
try:
return self.execute("uname")
except (socket.error, SSHError) as e:
except (socket.error, exceptions.SSHError) as e:
LOG.debug("Ssh is still unavailable: %r" % e)
time.sleep(interval)
if time.time() > (start_time + timeout):
raise SSHTimeout(_("Timeout waiting for '%s'") % self.host)
raise exceptions.SSHTimeout("Timeout waiting for '%s'" %
self.host)
def _put_file_sftp(self, localpath, remotepath, mode=None):
client = self._get_client()

View File

@ -238,3 +238,11 @@ class MultipleMatchesFound(RallyException):
class TempestConfigCreationFailure(RallyException):
msg_fmt = _("Unable to create Tempest config file: %(message)s")
class SSHTimeout(RallyException):
pass
class SSHError(RallyException):
pass

View File

@ -23,6 +23,8 @@ from rally.plugins.openstack.scenarios.vm import utils as vm_utils
from rally.task import types
from rally.task import validation
LOG = logging.getLogger(__name__)
class VMTasks(vm_utils.VMScenario):
"""Benchmark scenarios that are to be run inside VM instances."""
@ -56,6 +58,7 @@ class VMTasks(vm_utils.VMScenario):
use_floating_ip=True,
force_delete=False,
wait_for_ping=True,
max_log_length=None,
**kwargs):
"""Boot a server, run a script that outputs JSON, delete the server.
@ -143,6 +146,8 @@ class VMTasks(vm_utils.VMScenario):
:param force_delete: whether to use force_delete for servers
:param wait_for_ping: whether to check connectivity on server creation
:param **kwargs: extra arguments for booting the server
:param max_log_length: The number of tail nova console-log lines user
would like to retrieve
:returns: dictionary with keys `data' and `errors':
data: dict, JSON output from the script
errors: str, raw data from the script's stderr stream
@ -179,6 +184,13 @@ class VMTasks(vm_utils.VMScenario):
"Command %(command)s has not output valid JSON: %(error)s."
" Output: %(output)s" % {
"command": command, "error": str(e), "output": out})
except (exceptions.TimeoutException,
exceptions.SSHTimeout):
console_logs = self._get_server_console_output(server,
max_log_length)
LOG.debug("VM console logs:\n%s", console_logs)
raise
finally:
self._delete_server_with_fip(server, fip,
force_delete=force_delete)

View File

@ -18,6 +18,7 @@ import os
import mock
from rally.common import sshutils
from rally import exceptions
from tests.unit import test
@ -60,7 +61,7 @@ class SSHTestCase(test.TestCase):
dss = mock_paramiko.dsskey.DSSKey
rsa.from_private_key.side_effect = mock_paramiko.SSHException
dss.from_private_key.side_effect = mock_paramiko.SSHException
self.assertRaises(sshutils.SSHError, self.ssh._get_pkey, "key")
self.assertRaises(exceptions.SSHError, self.ssh._get_pkey, "key")
@mock.patch("rally.common.sshutils.six.moves.StringIO")
@mock.patch("rally.common.sshutils.paramiko")
@ -135,17 +136,17 @@ class SSHTestCase(test.TestCase):
@mock.patch("rally.common.sshutils.time")
def test_wait_timeout(self, mock_time):
mock_time.time.side_effect = [1, 50, 150]
self.ssh.execute = mock.Mock(side_effect=[sshutils.SSHError,
sshutils.SSHError,
self.ssh.execute = mock.Mock(side_effect=[exceptions.SSHError,
exceptions.SSHError,
0])
self.assertRaises(sshutils.SSHTimeout, self.ssh.wait)
self.assertRaises(exceptions.SSHTimeout, self.ssh.wait)
self.assertEqual([mock.call("uname")] * 2, self.ssh.execute.mock_calls)
@mock.patch("rally.common.sshutils.time")
def test_wait(self, mock_time):
mock_time.time.side_effect = [1, 50, 100]
self.ssh.execute = mock.Mock(side_effect=[sshutils.SSHError,
sshutils.SSHError,
self.ssh.execute = mock.Mock(side_effect=[exceptions.SSHError,
exceptions.SSHError,
0])
self.ssh.wait()
self.assertEqual([mock.call("uname")] * 3, self.ssh.execute.mock_calls)
@ -212,7 +213,7 @@ class SSHRunTestCase(test.TestCase):
def test_run_nonzero_status(self, mock_select):
mock_select.select.return_value = ([], [], [])
self.fake_session.recv_exit_status.return_value = 1
self.assertRaises(sshutils.SSHError, self.ssh.run, "cmd")
self.assertRaises(exceptions.SSHError, self.ssh.run, "cmd")
self.assertEqual(1, self.ssh.run("cmd", raise_on_error=False))
@mock.patch("rally.common.sshutils.select")
@ -261,7 +262,7 @@ class SSHRunTestCase(test.TestCase):
def test_run_select_error(self, mock_select):
self.fake_session.exit_status_ready.return_value = False
mock_select.select.return_value = ([], [], [True])
self.assertRaises(sshutils.SSHError, self.ssh.run, "cmd")
self.assertRaises(exceptions.SSHError, self.ssh.run, "cmd")
@mock.patch("rally.common.sshutils.time")
@mock.patch("rally.common.sshutils.select")
@ -269,7 +270,7 @@ class SSHRunTestCase(test.TestCase):
mock_time.time.side_effect = [1, 3700]
mock_select.select.return_value = ([], [], [])
self.fake_session.exit_status_ready.return_value = False
self.assertRaises(sshutils.SSHTimeout, self.ssh.run, "cmd")
self.assertRaises(exceptions.SSHTimeout, self.ssh.run, "cmd")
@mock.patch("rally.common.sshutils.open", create=True)
def test__put_file_shell(self, mock_open):

View File

@ -107,6 +107,36 @@ class VMTasksTestCase(test.ScenarioTestCase):
self.scenario._delete_server_with_fip.assert_called_once_with(
"foo_server", self.ip, force_delete=False)
def test_boot_runcommand_delete_command_timeouts(self):
self.scenario._run_command.side_effect = exceptions.SSHTimeout()
self.assertRaises(exceptions.SSHTimeout,
self.scenario.boot_runcommand_delete,
"foo_image", "foo_flavor", "foo_interpreter",
"foo_script", "foo_username")
self.scenario._delete_server_with_fip.assert_called_once_with(
"foo_server", self.ip, force_delete=False)
def test_boot_runcommand_delete_ping_wait_timeouts(self):
self.scenario._wait_for_ping.side_effect = exceptions.TimeoutException(
resource_type="foo_resource",
resource_name="foo_name",
resource_id="foo_id",
desired_status="foo_desired_status",
resource_status="foo_resource_status")
exc = self.assertRaises(exceptions.TimeoutException,
self.scenario.boot_runcommand_delete,
"foo_image", "foo_flavor", "foo_interpreter",
"foo_script", "foo_username",
wait_for_ping=True)
self.assertEqual(exc.kwargs["resource_type"], "foo_resource")
self.assertEqual(exc.kwargs["resource_name"], "foo_name")
self.assertEqual(exc.kwargs["resource_id"], "foo_id")
self.assertEqual(exc.kwargs["desired_status"], "foo_desired_status")
self.assertEqual(exc.kwargs["resource_status"], "foo_resource_status")
self.scenario._delete_server_with_fip.assert_called_once_with(
"foo_server", self.ip, force_delete=False)
@mock.patch("rally.plugins.openstack.scenarios.vm.vmtasks.json")
def test_boot_runcommand_delete_json_fails(self, mock_json):
mock_json.loads.side_effect = ValueError()