ssh_host.py: Rename run to run_very_slowly
This CL is the first step to rename SSHHost run to run_very_slowly.
1) Rename run to run_very_slowly.
2) Wrapper 'run' for run_very_slowly to support existing codebase.
3) Warning messages for slow ssh connection.
BUG=chromium:735653
TEST=test_that dut graphics_Sanity
Change-Id: Id44dc2f002df8282054f03dcdbf92ad19448cea0
Reviewed-on: https://chromium-review.googlesource.com/544105
Commit-Ready: Ilja H. Friedel <ihf@chromium.org>
Tested-by: Ilja H. Friedel <ihf@chromium.org>
Reviewed-by: Ilja H. Friedel <ihf@chromium.org>
diff --git a/server/hosts/ssh_host.py b/server/hosts/ssh_host.py
index 85cc876..aec9e05 100644
--- a/server/hosts/ssh_host.py
+++ b/server/hosts/ssh_host.py
@@ -13,6 +13,7 @@
import inspect
import logging
import re
+import warnings
from autotest_lib.client.common_lib import error
from autotest_lib.client.common_lib import pxssh
from autotest_lib.server import utils
@@ -75,6 +76,19 @@
alive_interval=alive_interval)
return "%s %s" % (base_cmd, self.hostname)
+ def _get_server_stack_state(self, lowest_frames=0, highest_frames=None):
+ """ Get the server stack frame status.
+ @param lowest_frames: the lowest frames to start printing.
+ @param highest_frames: the highest frames to print.
+ (None means no restriction)
+ """
+ stack_frames = inspect.stack()
+ stack = ''
+ for frame in stack_frames[lowest_frames:highest_frames]:
+ function_name = inspect.getframeinfo(frame[0]).function
+ stack = '%s|%s' % (function_name, stack)
+ del stack_frames
+ return stack[:-1] # Delete the last '|' character
def _verbose_logger_command(self, command):
"""
@@ -83,16 +97,8 @@
@param command: the ssh command to be executed.
"""
- stack_frames = inspect.stack()
- stack = ''
- # The last 2 frames on the stack are boring. Print 5-2=3 stack frames.
- count = min(5, len(stack_frames))
- if count >= 3:
- stack = inspect.getframeinfo(stack_frames[2][0]).function
- for frame in stack_frames[3:count]:
- function_name = inspect.getframeinfo(frame[0]).function
- stack = '%s|%s' % (function_name, stack)
- del stack_frames
+ # The last 3 frames on the stack are boring. Print 6-3=3 stack frames.
+ stack = self._get_server_stack_state(lowest_frames=3, highest_frames=6)
# If "logger" executable exists on the DUT use it to respew |command|.
# Then regardless of "logger" run |command| as usual.
command = ('if type "logger" > /dev/null 2>&1; then'
@@ -257,12 +263,15 @@
@metrics.SecondsTimerDecorator(
'chromeos/autotest/ssh/master_ssh_time')
- def run(self, command, timeout=3600, ignore_status=False,
+ def run_very_slowly(self, command, timeout=3600, ignore_status=False,
stdout_tee=utils.TEE_TO_LOGS, stderr_tee=utils.TEE_TO_LOGS,
connect_timeout=30, options='', stdin=None, verbose=True, args=(),
ignore_timeout=False, ssh_failure_retry_ok=False):
"""
Run a command on the remote host.
+ This RPC call has an overhead of minimum 40ms and up to 400ms on
+ servers (crbug.com/734887). Each time a run_very_slowly is added for
+ every job - a server core dies in the lab.
@see common_lib.hosts.host.run()
@param timeout: command execution timeout
@@ -282,6 +291,8 @@
@raises AutoservRunError: if the command failed
@raises AutoservSSHTimeout: ssh connection has timed out
"""
+ stack = self._get_server_stack_state()
+ warnings.warn("Caller to run_very_slowly() is %s" % stack)
if verbose:
logging.debug("Running (ssh) '%s'", command)
command = self._verbose_logger_command(command)
@@ -302,6 +313,10 @@
raise error.AutoservRunError(timeout_message, cmderr.args[1])
+ def run(self, *args, **kwargs):
+ return self.run_very_slowly(*args, **kwargs)
+
+
def run_background(self, command, verbose=True):
"""Start a command on the host in the background.
