def wait(predicate, interval=5, timeout=60, timeout_msg="Waiting timed out"):
"""Wait until predicate will become True.
returns number of seconds that is left or 0 if timeout is None.
Options:
interval - seconds between checks.
timeout - raise error.TimeoutError if predicate won't become True after
this amount of seconds. 'None' disables timeout.
timeout_msg - text of the error.TimeoutError
"""
start_time = time.time()
if not timeout:
return predicate()
while not predicate():
if start_time + timeout < time.time():
msg = ("{msg}\nWaited for pass {cmd}: {spent:0.3f} seconds."
"".format(msg=timeout_msg,
cmd=predicate.func_name,
spent=time.time() - start_time))
logger.debug(msg)
raise error.TimeoutError(timeout_msg)
seconds_to_sleep = max(
0, min(interval, start_time + timeout - time.time()))
time.sleep(seconds_to_sleep)
return timeout + start_time - time.time()
def test_ntp_common(self, logger, wait, time):
remote = Remote()
ntp_init = ntp.NtpInitscript(remote)
remote.reset_mock()
result = ntp_init.set_actual_time()
self.assertTrue(result)
self.assertTrue(ntp_init.is_synchronized)
wait.assert_called_once()
remote.execute.assert_called_once_with("hwclock -w")
wait.reset_mock()
logger.reset_mock()
debug = mock.Mock()
logger.attach_mock(debug, 'debug')
wait.side_effect = error.TimeoutError('E')
result = ntp_init.set_actual_time()
self.assertFalse(result)
self.assertFalse(ntp_init.is_synchronized)
debug.assert_called_once_with('Time sync failed with E')
result = ntp_init.wait_peer(timeout=-1)
self.assertFalse(result)
self.assertFalse(ntp_init.is_connected)
time.assert_has_calls((mock.call(), mock.call()))
def wait_pass(raising_predicate,
expected=Exception,
interval=5,
timeout=60,
timeout_msg="Waiting timed out",
predicate_args=None,
predicate_kwargs=None):
"""Wait for successful return from predicate ignoring expected exception
Options:
:param interval: - seconds between checks.
:param timeout: - raise TimeoutError if predicate still throwing expected
exception after this amount of seconds.
:param timeout_msg: - text of the TimeoutError
:param predicate_args: - positional arguments for given predicate wrapped
in list or tuple
:param predicate_kwargs: - dict with named arguments for the predicate
:param expected_exc: Exception that can be ignored while waiting (its
possible to pass several using list/tuple
"""
predicate_args = predicate_args or []
predicate_kwargs = predicate_kwargs or {}
_check_wait_args(raising_predicate, predicate_args, predicate_kwargs,
interval, timeout)
msg = ("{msg}\nWaited for pass {cmd}: {spent} seconds."
"".format(msg=timeout_msg,
cmd=repr(raising_predicate),
spent="{spent:0.3f}"))
start_time = time.time()
with RunLimit(timeout, msg):
while True:
try:
result = raising_predicate(*predicate_args, **predicate_kwargs)
logger.debug(
"wait_pass() completed with result='{0}'".format(result))
return result
except expected as e:
if start_time + timeout < time.time():
err_msg = msg.format(spent=time.time() - start_time)
logger.error(err_msg)
raise error.TimeoutError(err_msg)
logger.debug("Got expected exception {!r}, continue".format(e))
time.sleep(interval)
def wait(predicate,
interval=5,
timeout=60,
timeout_msg="Waiting timed out",
predicate_args=None,
predicate_kwargs=None):
"""Wait until predicate will become True.
Options:
:param interval: - seconds between checks.
:param timeout: - raise TimeoutError if predicate won't become True after
this amount of seconds.
:param timeout_msg: - text of the TimeoutError
:param predicate_args: - positional arguments for given predicate wrapped
in list or tuple
:param predicate_kwargs: - dict with named arguments for the predicate
"""
predicate_args = predicate_args or []
predicate_kwargs = predicate_kwargs or {}
_check_wait_args(predicate, predicate_args, predicate_kwargs, interval,
timeout)
msg = ("{msg}\nWaited for pass {cmd}: {spent} seconds."
"".format(msg=timeout_msg,
cmd=repr(predicate),
spent="{spent:0.3f}"))
start_time = time.time()
with RunLimit(timeout, msg):
while True:
result = predicate(*predicate_args, **predicate_kwargs)
if result:
logger.debug(
"wait() completed with result='{0}'".format(result))
return result
if start_time + timeout < time.time():
err_msg = msg.format(spent=time.time() - start_time)
logger.error(err_msg)
raise error.TimeoutError(err_msg)
time.sleep(interval)
def __exec_command(cls,
command,
cwd=None,
env=None,
timeout=None,
verbose=False):
"""Command executor helper
:type command: str
:type cwd: str
:type env: dict
:type timeout: int
:rtype: ExecResult
"""
def poll_stream(src, verb_logger=None):
dst = []
try:
for line in src:
dst.append(line)
if verb_logger is not None:
verb_logger(
line.decode('utf-8',
errors='backslashreplace').rstrip())
except IOError:
pass
return dst
def poll_streams(result, stdout, stderr, verbose):
rlist, _, _ = select.select([stdout, stderr], [], [])
if rlist:
if stdout in rlist:
result.stdout += poll_stream(
src=stdout,
verb_logger=logger.info if verbose else logger.debug)
if stderr in rlist:
result.stderr += poll_stream(
src=stderr,
verb_logger=logger.error if verbose else logger.debug)
@decorators.threaded(started=True)
def poll_pipes(proc, result, stop):
"""Polling task for FIFO buffers
:type proc: subprocess.Popen
:type result: ExecResult
:type stop: threading.Event
"""
# Get file descriptors for stdout and stderr streams
fd_stdout = proc.stdout.fileno()
fd_stderr = proc.stderr.fileno()
# Get flags of stdout and stderr streams
fl_stdout = fcntl.fcntl(fd_stdout, fcntl.F_GETFL)
fl_stderr = fcntl.fcntl(fd_stderr, fcntl.F_GETFL)
# Set nonblock mode for stdout and stderr streams
fcntl.fcntl(fd_stdout, fcntl.F_SETFL, fl_stdout | os.O_NONBLOCK)
fcntl.fcntl(fd_stderr, fcntl.F_SETFL, fl_stderr | os.O_NONBLOCK)
while not stop.isSet():
time.sleep(0.1)
poll_streams(result=result,
stdout=proc.stdout,
stderr=proc.stderr,
verbose=verbose)
proc.poll()
if proc.returncode is not None:
result.exit_code = proc.returncode
result.stdout += poll_stream(
src=proc.stdout,
verb_logger=logger.info if verbose else logger.debug)
result.stderr += poll_stream(
src=proc.stderr,
verb_logger=logger.error if verbose else logger.debug)
stop.set()
# 1 Command per run
with cls.__lock:
result = exec_result.ExecResult(cmd=command)
stop_event = threading.Event()
if verbose:
logger.info("\nExecuting command: {!r}".format(
command.rstrip()))
else:
logger.debug("\nExecuting command: {!r}".format(
command.rstrip()))
# Run
process = subprocess.Popen(args=[command],
stdin=subprocess.PIPE,
stdout=subprocess.PIPE,
stderr=subprocess.PIPE,
shell=True,
cwd=cwd,
env=env,
universal_newlines=False)
# Poll output
poll_pipes(process, result, stop_event)
# wait for process close
stop_event.wait(timeout)
# Process closed?
if stop_event.isSet():
stop_event.clear()
return result
# Kill not ended process and wait for close
try:
process.kill() # kill -9
stop_event.wait(5)
except OSError:
# Nothing to kill
logger.warning("{!r} has been completed just after timeout: "
"please validate timeout.".format(command))
wait_err_msg = (
'Wait for {0!r} during {1}s: no return code!\n'.format(
command, timeout))
output_brief_msg = ('\tSTDOUT:\n'
'{0}\n'
'\tSTDERR"\n'
'{1}'.format(result.stdout_brief,
result.stderr_brief))
logger.debug(wait_err_msg)
raise error.TimeoutError(wait_err_msg + output_brief_msg)
def __exec_command(cls,
command,
channel,
stdout,
stderr,
timeout,
verbose=False):
"""Get exit status from channel with timeout
:type command: str
:type channel: paramiko.channel.Channel
:type stdout: paramiko.channel.ChannelFile
:type stderr: paramiko.channel.ChannelFile
:type timeout: int
:type verbose: bool
:rtype: ExecResult
:raises: TimeoutError
"""
def poll_stream(src, verbose):
dst = []
try:
for line in src:
dst.append(line)
if verbose:
print(line.decode('utf-8', errors='backslashreplace'),
end="")
except IOError:
pass
return dst
def poll_streams(result, channel, stdout, stderr, verbose):
if channel.recv_ready():
result.stdout += poll_stream(src=stdout, verbose=verbose)
if channel.recv_stderr_ready():
result.stderr += poll_stream(src=stderr, verbose=verbose)
@decorators.threaded(started=True)
def poll_pipes(stdout, stderr, result, stop, channel):
"""Polling task for FIFO buffers
:type stdout: paramiko.channel.ChannelFile
:type stderr: paramiko.channel.ChannelFile
:type result: ExecResult
:type stop: Event
:type channel: paramiko.channel.Channel
"""
while not stop.isSet():
time.sleep(0.1)
poll_streams(result=result,
channel=channel,
stdout=stdout,
stderr=stderr,
verbose=verbose)
if channel.status_event.is_set():
result.exit_code = result.exit_code = channel.exit_status
result.stdout += poll_stream(src=stdout, verbose=verbose)
result.stderr += poll_stream(src=stderr, verbose=verbose)
stop.set()
# channel.status_event.wait(timeout)
result = exec_result.ExecResult(cmd=command)
stop_event = threading.Event()
if verbose:
print("\nExecuting command: {!r}".format(command.rstrip()))
poll_pipes(stdout=stdout,
stderr=stderr,
result=result,
stop=stop_event,
channel=channel)
stop_event.wait(timeout)
# Process closed?
if stop_event.isSet():
stop_event.clear()
channel.close()
return result
stop_event.set()
channel.close()
status_tmpl = ('Wait for {0!r} during {1}s: no return code!\n'
'\tSTDOUT:\n'
'{2}\n'
'\tSTDERR"\n'
'{3}')
logger.debug(
status_tmpl.format(command, timeout, result.stdout, result.stderr))
raise error.TimeoutError(
status_tmpl.format(command, timeout, result.stdout_brief,
result.stderr_brief))
def __exec_command(
cls, command, channel, stdout, stderr, timeout, verbose=False):
"""Get exit status from channel with timeout
:type command: str
:type channel: paramiko.channel.Channel
:type stdout: paramiko.channel.ChannelFile
:type stderr: paramiko.channel.ChannelFile
:type timeout: int
:type verbose: bool
:rtype: ExecResult
:raises: TimeoutError
"""
def poll_stream(src, verb_logger=None):
dst = []
try:
for line in src:
dst.append(line)
if verb_logger is not None:
verb_logger(
line.decode('utf-8',
errors='backslashreplace').rstrip()
)
except IOError:
pass
return dst
def poll_streams(result, channel, stdout, stderr, verbose):
if channel.recv_ready():
result.stdout += poll_stream(
src=stdout,
verb_logger=logger.info if verbose else logger.debug)
if channel.recv_stderr_ready():
result.stderr += poll_stream(
src=stderr,
verb_logger=logger.error if verbose else logger.debug)
@decorators.threaded(started=True)
def poll_pipes(stdout, stderr, result, stop, channel):
"""Polling task for FIFO buffers
:type stdout: paramiko.channel.ChannelFile
:type stderr: paramiko.channel.ChannelFile
:type result: ExecResult
:type stop: Event
:type channel: paramiko.channel.Channel
"""
while not stop.isSet():
time.sleep(0.1)
poll_streams(
result=result,
channel=channel,
stdout=stdout,
stderr=stderr,
verbose=verbose
)
if channel.status_event.is_set():
result.exit_code = result.exit_code = channel.exit_status
result.stdout += poll_stream(
src=stdout,
verb_logger=logger.info if verbose else logger.debug)
result.stderr += poll_stream(
src=stderr,
verb_logger=logger.error if verbose else logger.debug)
stop.set()
# channel.status_event.wait(timeout)
result = exec_result.ExecResult(cmd=command)
stop_event = threading.Event()
message = log_templates.CMD_EXEC.format(cmd=command.rstrip())
if verbose:
logger.info(message)
else:
logger.debug(message)
poll_pipes(
stdout=stdout,
stderr=stderr,
result=result,
stop=stop_event,
channel=channel
)
stop_event.wait(timeout)
# Process closed?
if stop_event.isSet():
stop_event.clear()
channel.close()
return result
stop_event.set()
channel.close()
wait_err_msg = log_templates.CMD_WAIT_ERROR.format(
cmd=command.rstrip(),
timeout=timeout)
output_brief_msg = ('\tSTDOUT:\n'
'{0}\n'
'\tSTDERR"\n'
'{1}'.format(result.stdout_brief,
result.stderr_brief))
logger.debug(wait_err_msg)
raise error.TimeoutError(wait_err_msg + output_brief_msg)
def handle_timeout(self, signum, frame):
logger.debug("RunLimit.handle_timeout reached!")
raise error.TimeoutError(self.error_message.format(spent=self.seconds))