diff --git a/tobiko/shell/ping/_interface.py b/tobiko/shell/ping/_interface.py index 58703d29b..7c09f21f5 100644 --- a/tobiko/shell/ping/_interface.py +++ b/tobiko/shell/ping/_interface.py @@ -85,10 +85,10 @@ def get_ping_usage(ssh_client): usage = ((result.stdout and str(result.stdout)) or (result.stderr and str(result.stderr)) or "").strip() if usage: - LOG.debug('Got ping usage text:\n%s\n', usage) + LOG.debug('Got ping usage text') else: LOG.warning("Unable to get usage message from ping command:\n" - "%r", result) + "%s", result.details) return usage diff --git a/tobiko/shell/ping/_ping.py b/tobiko/shell/ping/_ping.py index d5701f02e..d0cbfcc3d 100644 --- a/tobiko/shell/ping/_ping.py +++ b/tobiko/shell/ping/_ping.py @@ -274,13 +274,11 @@ def execute_ping(parameters, ssh_client=None, check=True): if stdout: output = str(stdout) - LOG.debug('Received ping STDOUT:\n%s', output) else: output = None if stderr: error = str(stderr) - LOG.info('Received ping STDERR:\n%s', error) if check and result.exit_status: handle_ping_command_error(error=error) diff --git a/tobiko/shell/sh/_execute.py b/tobiko/shell/sh/_execute.py index e927a7a63..33ef3b808 100644 --- a/tobiko/shell/sh/_execute.py +++ b/tobiko/shell/sh/_execute.py @@ -15,10 +15,13 @@ # under the License. from __future__ import absolute_import +import collections +import enum from oslo_log import log import six +import tobiko from tobiko.shell.sh import _exception from tobiko.shell.sh import _process @@ -29,29 +32,85 @@ LOG = log.getLogger(__name__) DATA_TYPES = six.string_types + (six.binary_type, six.text_type) -class ShellExecuteResult(object): +@enum.unique +class ShellExecuteStatus(enum.Enum): + SUCCEEDED = 'SUCCEEDED' + FAILED = 'FAILED' + TIMEDOUT = 'TIMEDOUT' + UNTERMINATED = 'UNTERMINATED' - def __init__(self, command=None, exit_status=None, stdin=None, stdout=None, - stderr=None): - self.command = str(command) - self.exit_status = exit_status - self.stdin = stdin and str(stdin) or None - self.stdout = stdout and str(stdout) or None - self.stderr = stderr and str(stderr) or None + +def execute_result(command, exit_status=None, timeout=None, + status=None, login=None, stdin=None, stdout=None, + stderr=None): + command = str(command) + if exit_status is not None: + exit_status = int(exit_status) + if timeout is not None: + timeout = float(timeout) + if status is not None: + status = ShellExecuteStatus(status) + stdin = _process.str_from_stream(stdin) + stdout = _process.str_from_stream(stdout) + stderr = _process.str_from_stream(stderr) + return ShellExecuteResult(command=command, + exit_status=exit_status, + timeout=timeout, + status=status, + stdin=stdin, + stdout=stdout, + stderr=stderr, + login=login) + + +class ShellExecuteResult(collections.namedtuple( + 'ShellExecuteResult', ['command', 'exit_status', 'timeout', 'status', + 'login', 'stdin', 'stdout', 'stderr'])): + + _details = None + + @property + def details(self): + details = self._details + if details is None: + self._details = details = self.get_details() + return details + + def get_details(self): + details = [] + details.append("command: {!r}".format(self.command)) + + exit_status = self.exit_status + if exit_status is not None: + details.append("exit_status: {!r}".format(exit_status)) + + timeout = self.timeout + if timeout is not None: + details.append("timeout: {!r}".format(timeout)) + + status = self.status + if status is not None: + details.append("status: {!s}".format(status)) + + login = self.login + if login is not None: + details.append("login: {!r}".format(login)) + + stdin = self.stdin + if stdin: + details.append("stdin:\n{!s}".format(_indent(stdin))) + + stdout = self.stdout + if stdout: + details.append("stdout:\n{!s}".format(_indent(stdout))) + + stderr = self.stderr + if stderr: + details.append("stderr:\n{!s}".format(_indent(stderr))) + return '\n'.join(details) def format(self): - text = '' - if self.stdin: - text += '- stdin: >\n' + _indent(self.stdin) + '\n' - if self.stdout: - text += '- stdout: >\n' + _indent(self.stdout) + '\n' - if self.stderr: - text += '- stderr: >\n' + _indent(self.stderr) + '\n' - return ("Shell command result:\n" - "- command: {command}" - "- exit_status: {exit_status}\n" - ).format(command=self.command, - exit_status=self.exit_status) + text + return self.details def _indent(text, space=' ', newline='\n'): @@ -89,25 +148,48 @@ def execute(command, environment=None, timeout=None, shell=None, stderr=stderr, ssh_client=ssh_client, **kwargs) + login = getattr(ssh_client, 'login', None) return execute_process(process=process, stdin=stdin, + login=login, expect_exit_status=expect_exit_status) -def execute_process(process, stdin, expect_exit_status): +def execute_process(process, stdin, expect_exit_status, login=None): + error = None + status = None try: with process: if stdin and isinstance(stdin, DATA_TYPES): process.send_all(data=stdin) except _exception.ShellTimeoutExpired: + status = ShellExecuteStatus.TIMEDOUT if expect_exit_status is not None: - raise + error = tobiko.exc_info() else: if expect_exit_status is not None: - process.check_exit_status(expect_exit_status) + try: + process.check_exit_status(expect_exit_status) + except _exception.ShellCommandFailed: + status = ShellExecuteStatus.FAILED + error = tobiko.exc_info() + except _exception.ShellProcessNotTeriminated: + status = ShellExecuteStatus.UNTERMINATED + else: + status = ShellExecuteStatus.SUCCEEDED - return ShellExecuteResult(command=str(process.command), - exit_status=process.exit_status, - stdin=_process.str_from_stream(process.stdin), - stdout=_process.str_from_stream(process.stdout), - stderr=_process.str_from_stream(process.stderr)) + result = execute_result(command=process.command, + exit_status=process.exit_status, + timeout=process.timeout, + status=status, + login=login, + stdin=process.stdin, + stdout=process.stdout, + stderr=process.stderr) + if error: + LOG.info("Command error:\n%s\n", result.details) + error.result = result + error.reraise() + + LOG.debug("Command executed:\n%s\n", result.details) + return result diff --git a/tobiko/shell/sh/_io.py b/tobiko/shell/sh/_io.py index a37516f91..f6ccdab3e 100644 --- a/tobiko/shell/sh/_io.py +++ b/tobiko/shell/sh/_io.py @@ -159,9 +159,6 @@ def select_files(files, timeout, mode='rw'): read_ready = select_read_ready_files(readable) write_ready = select_write_ready_files(writable) if not write_ready and not read_ready: - if timeout > 0.: - LOG.debug("Calling select with %d files and timeout %f", - len(opened), timeout) rlist, wlist, xlist = select.select(readable, writable, opened, timeout) read_ready = readable & set(rlist + xlist) diff --git a/tobiko/shell/sh/_process.py b/tobiko/shell/sh/_process.py index 08f6749d1..0fc71cc57 100644 --- a/tobiko/shell/sh/_process.py +++ b/tobiko/shell/sh/_process.py @@ -39,6 +39,11 @@ def process(command=None, environment=None, timeout=None, shell=None, kwargs.update(command=command, environment=environment, timeout=timeout, shell=shell, stdin=stdin, stdout=stdout, stderr=stderr, sudo=sudo) + timeout = kwargs['timeout'] + if timeout is not None: + if timeout < 0.: + raise ValueError("Invalid timeout for executing process: " + "{!r}".format(timeout)) try: from tobiko.shell.sh import _ssh from tobiko.shell import ssh @@ -309,8 +314,6 @@ class ShellProcessFixture(tobiko.SharedFixture): read_ready, write_ready = _io.select_files( files=streams, timeout=poll_interval) if read_ready or write_ready: - LOG.debug('Communicating with process (%s): %r', self.command, - read_ready | write_ready) # Avoid waiting for data the next time poll_interval = 0. if self.stdin in write_ready: @@ -337,16 +340,10 @@ class ShellProcessFixture(tobiko.SharedFixture): def _is_communicating(self, streams, send, receive): if send and self.stdin in streams: - LOG.debug('Trying to send data to process (%s): %r', self.command, - streams) return True elif receive and {self.stdout, self.stderr} & streams: - LOG.debug('Trying to receive data from process (%s): %r', - self.command, streams) return True else: - LOG.debug('Stop communicating with process (%s): %r', self.command, - streams) return False def _write_to_stdin(self, data, check=True): @@ -355,8 +352,6 @@ class ShellProcessFixture(tobiko.SharedFixture): self.check_stdin_is_opened() sent_bytes = self.stdin.write(data) if sent_bytes: - LOG.debug("Written %d bytes to STDIN (%s)", sent_bytes, - self.command) return data[sent_bytes:] or None else: LOG.debug("%r closed by peer on %r", self.stdin, self) @@ -368,8 +363,6 @@ class ShellProcessFixture(tobiko.SharedFixture): # Read data from remote stream chunk = self.stdout.read(buffer_size) if chunk: - LOG.debug("Read %d bytes from STDOUT (%s)", len(chunk), - self.command) return chunk else: LOG.debug("%r closed by peer on %r", self.stdout, self) @@ -381,8 +374,6 @@ class ShellProcessFixture(tobiko.SharedFixture): # Read data from remote stream chunk = self.stderr.read(buffer_size) if chunk: - LOG.debug("Read %d bytes from STDERR (%s)", len(chunk), - self.command) return chunk else: LOG.debug("%r closed by peer on %r", self.stderr, self) @@ -398,7 +389,6 @@ class ShellProcessFixture(tobiko.SharedFixture): stdin=str_from_stream(self.stdin), stdout=str_from_stream(self.stdout), stderr=str_from_stream(self.stderr)) - LOG.debug("%s", ex) raise ex return time_left @@ -412,7 +402,6 @@ class ShellProcessFixture(tobiko.SharedFixture): stdin=self.stdin, stdout=self.stdout, stderr=self.stderr) - LOG.debug("%s", ex) raise ex exit_status = int(exit_status) @@ -423,16 +412,8 @@ class ShellProcessFixture(tobiko.SharedFixture): stdin=str_from_stream(self.stdin), stdout=str_from_stream(self.stdout), stderr=str_from_stream(self.stderr)) - LOG.debug("%s", ex) raise ex - LOG.debug("Command '%s' succeeded (exit_status=%d):\n" - "stdin:\n%s\n" - "stdout:\n%s\n" - "stderr:\n%s", - self.command, exit_status, - self.stdin, self.stdout, self.stderr) - def merge_dictionaries(*dictionaries): merged = {} diff --git a/tobiko/shell/sh/_ssh.py b/tobiko/shell/sh/_ssh.py index 9e6984da1..93cf15d4f 100644 --- a/tobiko/shell/sh/_ssh.py +++ b/tobiko/shell/sh/_ssh.py @@ -18,6 +18,7 @@ from __future__ import absolute_import from oslo_log import log import paramiko +import tobiko from tobiko.shell.sh import _exception from tobiko.shell.sh import _execute from tobiko.shell.sh import _io @@ -32,7 +33,7 @@ LOG = log.getLogger(__name__) def ssh_execute(ssh_client, command, environment=None, timeout=None, stdin=None, stdout=None, stderr=None, shell=None, expect_exit_status=0, **kwargs): - """Execute command on local host using local shell""" + """Execute command on remote host using SSH client""" process = ssh_process(command=command, environment=environment, timeout=timeout, @@ -77,18 +78,24 @@ class SSHShellProcessFixture(_process.ShellProcessFixture): def create_process(self): """Execute command on a remote host using SSH client""" - parameters = self.parameters - assert isinstance(parameters, SSHShellProcessParameters) - - ssh_client = self.ssh_client - if isinstance(ssh_client, ssh.SSHClientFixture): - # Connect to SSH server - ssh_client = ssh_client.connect() - command = str(self.command) + ssh_client = self.ssh_client timeout = self.timeout and float(self.timeout) + parameters = self.parameters + + tobiko.check_valid_type(ssh_client, ssh.SSHClientFixture) + tobiko.check_valid_type(parameters, SSHShellProcessParameters) + + LOG.debug("Executing remote command: %r (login=%r, timeout=%r)...", + command, ssh_client.login, timeout) + + # Connect to SSH server + client = ssh_client.connect() + + # Open a new SSH session try: - process = ssh_client.get_transport().open_session(timeout=timeout) + process = client.get_transport().open_session( + timeout=timeout) except paramiko.SSHException as ex: LOG.debug('Error executing command %r', command, exc_info=1) error = str(ex) @@ -101,8 +108,6 @@ class SSHShellProcessFixture(_process.ShellProcessFixture): else: raise _exception.ShellError(error) - LOG.debug("Execute command %r on remote host (timeout=%r)...", - command, self.timeout) if parameters.environment: process.update_environment(parameters.environment) process.exec_command(command) diff --git a/tobiko/shell/ssh/_client.py b/tobiko/shell/ssh/_client.py index a2459d5df..3bedd9093 100644 --- a/tobiko/shell/ssh/_client.py +++ b/tobiko/shell/ssh/_client.py @@ -274,33 +274,18 @@ class SSHClientFixture(tobiko.SharedFixture): gather_parameters(destination=parameters, schema=schema, remove_from_schema=True) - if parameters: - LOG.debug('SSH connect parameters for host %r:\n%r', self.host, - parameters) return parameters def gather_initial_connect_parameters(self, **kwargs): - parameters = gather_ssh_connect_parameters( + return gather_ssh_connect_parameters( source=self._connect_parameters, **kwargs) - if parameters: - LOG.debug('Initial SSH connect parameters for host %r:\n' - '%r', self.host, parameters) - return parameters def gather_host_config_connect_parameters(self, **kwargs): - parameters = gather_ssh_connect_parameters( + return gather_ssh_connect_parameters( source=self.host_config.connect_parameters, **kwargs) - if parameters: - LOG.debug('Host configured SSH connect parameters for host %r:\n' - '%r', self.host, parameters) - return parameters def gather_default_connect_parameters(self, **kwargs): - parameters = gather_ssh_connect_parameters(source=self, **kwargs) - if parameters: - LOG.debug('Default SSH connect parameters for host %r:\n' - '%r', self.host, parameters) - return parameters + return gather_ssh_connect_parameters(source=self, **kwargs) def setup_ssh_client(self): self.client, self.proxy_sock = ssh_connect( @@ -333,6 +318,9 @@ class SSHClientFixture(tobiko.SharedFixture): def connect(self): return tobiko.setup_fixture(self).client + def close(self): + tobiko.cleanup_fixture(self) + def get_ssh_command(self, host=None, username=None, port=None, command=None, config_files=None, host_config=None, proxy_command=None, key_filename=None, **options): @@ -361,6 +349,13 @@ class SSHClientFixture(tobiko.SharedFixture): key_filename=key_filename, **options) + @property + def login(self): + parameters = self.setup_connect_parameters() + return _command.ssh_login(hostname=parameters['hostname'], + username=parameters['username'], + port=parameters['port']) + UNDEFINED_CLIENT = 'UNDEFINED_CLIENT' @@ -449,8 +444,6 @@ def ssh_connect(hostname, username=None, port=None, connection_interval=None, LOG.debug("Error logging in to %r: %s", login, ex) sleep_time = start_time + interval - time.time() if sleep_time > 0.: - LOG.debug("Retrying connecting to %r in %d seconds...", login, - sleep_time) time.sleep(sleep_time) else: diff --git a/tobiko/tests/functional/shell/test_execute.py b/tobiko/tests/functional/shell/test_execute.py index d501a641a..3e8e1f52c 100644 --- a/tobiko/tests/functional/shell/test_execute.py +++ b/tobiko/tests/functional/shell/test_execute.py @@ -32,11 +32,12 @@ class ExecuteTest(testtools.TestCase): shell = '/bin/sh -c' def test_succeed(self, command='true', stdin=None, stdout=None, - stderr=None, **kwargs): + stderr=None, expect_exit_status=0, **kwargs): process = self.execute(command=command, stdin=stdin, stdout=bool(stdout), stderr=bool(stderr), + expect_exit_status=expect_exit_status, **kwargs) self.assertEqual(self.expected_command(command), process.command) if stdin: @@ -51,7 +52,8 @@ class ExecuteTest(testtools.TestCase): self.assertEqual(stderr, str(process.stderr)) else: self.assertIsNone(process.stderr) - self.assertEqual(0, process.exit_status) + if expect_exit_status is not None: + self.assertEqual(0, process.exit_status) def test_succeed_with_command_list(self): self.test_succeed(['echo', 'something'], @@ -73,11 +75,16 @@ class ExecuteTest(testtools.TestCase): def test_succeed_with_timeout(self): self.test_succeed(timeout=30.) + def test_succeed_with_no_exit_status(self): + self.test_succeed(command='false', expect_exit_status=None) + def test_fails(self, command='false', exit_status=None, stdin=None, - stdout=None, stderr=None, **kwargs): + stdout=None, stderr=None, expect_exit_status=0, + **kwargs): ex = self.assertRaises(sh.ShellCommandFailed, self.execute, command=command, + expect_exit_status=expect_exit_status, stdin=stdin, stdout=bool(stdout), stderr=bool(stderr), @@ -95,7 +102,7 @@ class ExecuteTest(testtools.TestCase): self.assertEqual(stderr, ex.stderr) else: self.assertIsNone(ex.stderr) - if exit_status: + if exit_status is not None: self.assertEqual(exit_status, ex.exit_status) else: self.assertTrue(ex.exit_status) @@ -116,6 +123,9 @@ class ExecuteTest(testtools.TestCase): stdin='some input\n', stdout='some input\n') + def test_fails_with_check_exit_status(self): + self.test_fails(command='true', expect_exit_status=1, exit_status=0) + def test_timeout_expires(self, command='sleep 10', timeout=5., stdin=None, stdout=None, stderr=None, **kwargs): ex = self.assertRaises(sh.ShellTimeoutExpired,