def start(domain, startup_timeout=STARTUP_TIMEOUT):
domain.logger.info("starting domain")
# Bring the machine up from scratch.
end_time = time.time() + startup_timeout
# Do not call this when the console is functional!
console = domain.console()
if console:
raise pexpect.TIMEOUT("console should not be open")
first_attempt = True
while console == None:
if time.time() > end_time:
pexpect.TIMEOUT("Trying to get a console")
status, output = domain.start()
if status and first_attempt:
# The first attempt at starting the domain _must_ succeed.
# Failing is a sign that the domain was running. Further
# attempts might fail as things get racey.
raise pexpect.TIMEOUT("failed to start domain: %s" % output)
time.sleep(1)
# try opening the console again
console = domain.console()
first_attempt = False
domain.logger.debug("got console")
# Now wait for it to be usable
_startup(domain, console, timeout=(end_time - time.time()))
return console
def WaitForLogMatch(self, search_re):
"""Blocks until a line containing |line_re| is logged or a timeout occurs.
Args:
search_re: The compiled re to search each line for.
Returns:
The re match object.
"""
if not self._logcat:
self.StartMonitoringLogcat(clear=False)
logging.info('<<< Waiting for logcat:' + str(search_re.pattern))
t0 = time.time()
try:
while True:
# Note this will block for upto the timeout _per log line_, so we need
# to calculate the overall timeout remaining since t0.
time_remaining = t0 + self._logcat.timeout - time.time()
if time_remaining < 0: raise pexpect.TIMEOUT(self._logcat)
self._logcat.expect(PEXPECT_LINE_RE, timeout=time_remaining)
line = self._logcat.match.group(1)
search_match = search_re.search(line)
if search_match:
return search_match
logging.info('<<< Skipped Logcat Line:' + str(line))
except pexpect.TIMEOUT:
raise pexpect.TIMEOUT(
'Timeout (%ds) exceeded waiting for pattern "%s" (tip: use -vv '
'to debug)' % (self._logcat.timeout, search_re.pattern))
def WaitForLogMatch(self, success_re, error_re, clear=False, timeout=10):
"""Blocks until a matching line is logged or a timeout occurs.
Args:
success_re: A compiled re to search each line for.
error_re: A compiled re which, if found, terminates the search for
|success_re|. If None is given, no error condition will be detected.
clear: If True the existing logcat output will be cleared, defaults to
false.
timeout: Timeout in seconds to wait for a log match.
Raises:
pexpect.TIMEOUT after |timeout| seconds without a match for |success_re|
or |error_re|.
Returns:
The re match object if |success_re| is matched first or None if |error_re|
is matched first.
"""
logging.info('<<< Waiting for logcat:' + str(success_re.pattern))
t0 = time.time()
while True:
if not self._logcat:
self.StartMonitoringLogcat(clear)
try:
while True:
# Note this will block for upto the timeout _per log line_, so we need
# to calculate the overall timeout remaining since t0.
time_remaining = t0 + timeout - time.time()
if time_remaining < 0: raise pexpect.TIMEOUT(self._logcat)
self._logcat.expect(PEXPECT_LINE_RE, timeout=time_remaining)
line = self._logcat.match.group(1)
if error_re:
error_match = error_re.search(line)
if error_match:
return None
success_match = success_re.search(line)
if success_match:
return success_match
logging.info('<<< Skipped Logcat Line:' + str(line))
except pexpect.TIMEOUT:
raise pexpect.TIMEOUT(
'Timeout (%ds) exceeded waiting for pattern "%s" (tip: use -vv '
'to debug)' %
(timeout, success_re.pattern))
except pexpect.EOF:
# It seems that sometimes logcat can end unexpectedly. This seems
# to happen during Chrome startup after a reboot followed by a cache
# clean. I don't understand why this happens, but this code deals with
# getting EOF in logcat.
logging.critical('Found EOF in adb logcat. Restarting...')
# Rerun spawn with original arguments. Note that self._logcat.args[0] is
# the path of adb, so we don't want it in the arguments.
self._logcat = pexpect.spawn('adb',
self._logcat.args[1:],
timeout=self._logcat.timeout,
logfile=self._logcat.logfile)
def boot_to_login_prompt(domain,
console,
timeout=(STARTUP_TIMEOUT + LOGIN_TIMEOUT)):
retried = False
while True:
if console:
domain.reboot()
else:
console = _start(domain)
lapsed_time = timing.Lapsed()
domain.logger.info("waiting %s seconds for login prompt", timeout)
if console.expect_exact([pexpect.TIMEOUT, "login: "******"login prompt appeared after %s", lapsed_time)
return console
if retried:
domain.logger.error("domain failed to boot after %s, giving up",
laped_time)
raise pexpect.TIMEOUT("domain %d failed to boot" % domain)
retried = True
domain.logger.error(
"domain failed to boot after %s, waiting %d seconds for it to power down",
lapsed_time, SHUTDOWN_TIMEOUT)
shutdown_time = timing.Lapsed()
domain.shutdown()
if console.expect_exact([pexpect.TIMEOUT, pexpect.EOF],
timeout=SHUTDOWN_TIMEOUT):
domain.logger.info("domain powered down after %s", shutdown_time)
console = None
continue
domain.logger.error(
"domain failed to power down after %s, waiting %d seconds for the power cord to be pulled",
shutdown_time, SHUTDOWN_TIMEOUT)
shutdown_time = timing.Lapsed()
domain.destroy()
if console.expect_exact([pexpect.TIMEOUT, pexpect.EOF],
timeout=SHUTDOWN_TIMEOUT):
domain.logger.info("domain appears to have switched off after %s",
shutdown_time)
console = None
continue
domain.logger.error("domain failed to switch off after %s, giving up",
shutdown_time)
raise pexpect.TIMEOUT("Domain %s is wedged" % domain)
def wait_until_child_is_in_foreground(pexpect_mod, timeout=-1):
"""
This begins a timeout loop that waits for a process id other than that
of the shell (self.pid) to take over the pty. A timeout is raised if the
terminal is not taken over, and the while loop quits if the terminal is
taken over. There is a 10ms sleep to slow the pace of the busy-waiting.
There is a chance that a program could start and finish in those said 10ms,
and as such tests should be designed to not wait for extremely fast
processing commands.
"""
#the default timeout is the timeout from the pexpect module
if timeout == -1:
timeout = pexpect_mod.timeout
if timeout is not None:
end_time = time.time() + pexpect_mod.timeout
#busy wait with a sleep until the pty is taken over by a process
while os.tcgetpgrp(pexpect_mod.child_fd) == pexpect_mod.pid:
time.sleep(0.010)
if timeout is not None:
timeout = end_time - time.time()
if timeout < 0 and timeout is not None:
raise pexpect.TIMEOUT('Timeout exceeded in \
wait_until_child_is_in_foreground().')
process_pid = os.tcgetpgrp(pexpect_mod.child_fd)
assert check_foreground_process(pexpect_mod.pid, process_pid), \
'Error, terminal not taken over by child process properly'
def test_timeout_error(self):
# test timeout error
pexpect.spawn.return_value.expect.side_effect = (
pexpect.TIMEOUT('timeout error'))
# test and verify
self.assertRaises(pkg.PkgTimeout, self.pkg.pkg_install, self.pkgName,
{}, 5000)
def test_timeout_error(self):
# test timeout error
pexpect.spawn.expect = Mock(
side_effect=pexpect.TIMEOUT('timeout error'))
# test and verify
self.assertRaises(pkg.PkgTimeout, self.pkg.pkg_remove, self.pkgName,
5000)
def _login(domain, console, login, password, lapsed_time, timeout):
tries = 0
while True:
if tries > 3:
domain.logger.error(
"giving up after %s and %d attempts at logging in",
lapsed_time, tries)
raise pexpect.TIMEOUT()
tries = tries + 1
match = console.expect([LOGIN_PROMPT, PASSWORD_PROMPT, console.prompt],
timeout=timeout)
if match == 0:
console.sendline(login)
timeout = PASSWORD_TIMEOUT
domain.logger.info(
"got login prompt after %s; sending '%s' and waiting %s seconds for password prompt",
lapsed_time, login, timeout)
continue
elif match == 1:
timeout = SHELL_TIMEOUT
console.sendline(password)
domain.logger.info(
"got password prompt after %s; sending '%s' and waiting %s seconds for shell prompt",
lapsed_time, password, timeout)
continue
elif match == 2:
# shell prompt
domain.logger.info("we're in after %s!", lapsed_time)
break
console.sync()
return console
def establishtrust(ip, hostname):
pexpect.TIMEOUT(5)
#append hosts info to /etc/hosts
hostinfo = pexpect.spawn("/usr/bin/grep %s /etc/hosts" % (hostname))
hostinfo.expect(pexpect.EOF)
#if(not hostinfo.before) :
# hostinfo = pexpect.spawn('/bin/sh -c "echo %s %s >> /etc/hosts"' % (ip,hostname))
#ssh-copy-id
ssh_copy = pexpect.spawn(
'/bin/sh -c "/usr/bin/ssh-copy-id -i /root/.ssh/id_rsa.pub root@%s"' %
(ip),
timeout=5)
index = ssh_copy.expect(['(?i)password:'******'Root@dnt01')
index1 = ssh_copy.expect(['(?i)password:'******'(?i)password')
ssh_copy.sendline('Root_dnt01')
hostinfo.close()
ssh_copy.close()
def read_nonblocking(self, size=1, timeout=None):
"""
This reads at most size characters from the child application.
It includes a timeout. If the read does not complete within the
timeout period then a TIMEOUT exception is raised.
If the end of file is read then an EOF exception will be raised.
If a log file was set using setlog() then all data will
also be written to the log file.
Notice that if this method is called with timeout=None
then it actually may block.
This is a non-blocking wrapper around os.read().
It uses select.select() to implement a timeout.
"""
if self.child_fd == -1:
raise ValueError('I/O operation on closed file')
# Note that some systems like Solaris don't seem to ever give
# an EOF when the child dies. In fact, you can still try to read
# from the child_fd -- it will block forever or until TIMEOUT.
# For this case, I test isalive() before doing any reading.
# If isalive() is false, then I pretend that this is the same as EOF.
if not self.isalive():
r, w, e = select.select([self.child_fd], [], [], 0)
if not r:
self.flag_eof = 1
raise pexpect.EOF(
'End Of File (EOF) in read(). Braindead platform.')
timeout = 5.0
r, w, e = select.select([self.child_fd], [], [], timeout)
if not r:
print('Timeout (%s) exceeded in read().' % str(timeout))
raise pexpect.TIMEOUT('Timeout (%s) exceeded in read().' %
str(timeout))
if self.child_fd in r:
try:
s = self.child_fd.recv(size)
# s = os.read(self.child_fd, size)
except OSError, e:
self.flag_eof = 1
raise pexpect.EOF(
'End Of File (EOF) in read(). Exception style platform.')
if s == '':
self.flag_eof = 1
raise pexpect.EOF(
'End Of File (EOF) in read(). Empty string style platform.'
)
if self.log_file != None:
self.log_file.write(s)
self.log_file.flush()
if hasattr(self, 'console'):
self.console.send(s)
return s
def chat(self, cmd, timeout=chatTimeout, interrupt_on_timeout=False, force=True, expect=None):
self.app.send(cmd)
if not force:
self.app.expect_exact(cmd, timeout=2)
self.app.send('\n')
if expect:
index = self.app.expect(
[expect, pexpect.TIMEOUT],
timeout=timeout
)
else:
index = self.app.expect(
[self.app_prompt, pexpect.TIMEOUT],
timeout=timeout
)
buf = self.app.before
dummy, rest = buf.split('\r\n', 1)
if index == 0:
return rest
elif interrupt_on_timeout:
print "Timeout, sending Ctrl-C"
self.app.sendintr()
self.app.expect(self.app_prompt, timeout=1)
return rest
else:
raise pexpect.TIMEOUT(
"Timeout waiting for response to command '%s'" % cmd
)
def update_vsd_domain(vsc_host, username, password, vsd_domain):
import pexpect
try:
ssh_newkey = 'Are you sure you want to continue connecting'
child = pexpect.spawn('ssh %s@%s -o ConnectTimeout=1500'
' -o ConnectionAttempts=300'
% (username, vsc_host), timeout=1500)
log('ssh %s@%s' % (username, vsc_host))
i = child.expect([ssh_newkey, 'password:'******'yes')
i = child.expect([ssh_newkey, 'password:', pexpect.EOF])
if i == 1:
child.sendline(password)
elif i == 2:
child.close()
raise pexpect.EOF("End of file error")
elif i == 3:
# timeout
child.close()
raise pexpect.TIMEOUT("Got a connection timeout")
child.sendline("\r")
child.sendline("configure vswitch-controller xmpp-server \"{}\""
.format(vsd_domain))
child.sendline("logout")
child.close()
except pexpect.ExceptionPexpect as e:
log("Got an exception: traceback %s" % e.get_trace())
except Exception as e:
log("Got a generic exception: %s" % e.strerror)
else:
log("Failed to update vsd domain in VSD")
finally:
log("Exiting update_vsd_domain")
def establishtrust(ip, hostname):
pexpect.TIMEOUT(5)
#append hosts info to /etc/hosts
logging.info(hostname)
logging.info(ip)
ssh_root = pexpect.spawn('su - root', timeout=5)
index1 = ssh_root.expect(['(?i)password:'******'Root@dnt01')
ssh_root.expect('vq12zdfb01:~ #')
ssh_root.sendline('/bin/sh -c "echo %s %s >> /etc/hosts"' %
(ip, hostname))
ssh_root.expect('vq12zdfb01:~ #')
ssh_root.delaybeforesend = 0.1
ssh_root.sendline(
'/bin/sh -c "/usr/bin/ssh-copy-id -o StrictHostKeyChecking=no -o ConnectTimeout=5 -i /root/.ssh/id_rsa.pub root@%s ";'
% (ip))
try:
index2 = ssh_root.expect(
['(?i)password:'******'vq12zdfb01:~ #', pexpect.TIMEOUT])
logging.info('2' + str(index2))
if (index2 == 0):
ssh_root.sendline('Root@dnt01')
index4 = ssh_root.expect(['(?i)password:'******'vq12zdfb01:~ #'])
logging.info('4' + str(index4))
if (index4 == 0):
ssh_root.sendline('Root_dnt01')
except pexpect.EOF, pexpect.TIMEOUT:
ssh_root.close()
def _check_prompt_group(logger, match, field, expected):
if expected:
found = match.group(field)
if expected.encode() != found:
# Throw TIMEOUT as that is what is expected and what
# would have happened.
raise pexpect.TIMEOUT("incorrect prompt, field '%s' should be '%s but was '%s'" \
% (field, expected, found))
def test_timeout_error(self):
# test timeout error
pexpect.spawn.expect = Mock(
side_effect=pexpect.TIMEOUT('timeout error'))
pexpect.spawn.match = False
# test and verify
self.assertRaises(pkg.PkgTimeout, self.pkg.pkg_install, self.pkgName,
{}, 5000)
def test_timeout_error(self):
# test timeout error
pexpect.spawn.return_value.expect.side_effect = (
pexpect.TIMEOUT('timeout error'))
pexpect.spawn.return_value.match = False
# test and verify
self.assertRaises(pkg.PkgTimeout, self.pkg.pkg_remove, self.pkgName,
5000)
def test_timeout_exception(self):
mocked_process = Mock()
mocked_process.expect.side_effect = pexpect.TIMEOUT('')
c = BaseCommand()
c._build_command_string = lambda: ''
self.assertRaises(CommandTimeoutException, c.execute, mocked_process)
def execute(self, operation='', expect=None, timeout=5):
#print(operation, expect, 'timeout='+str(timeout))
expect_list = [PEXPECT.TIMEOUT, PEXPECT.EOF]
if expect is not None:
expect_list = expect_list+ [expect['success']]
if self.pexpect is None:
#print('New pexpect class')
self.pexpect = PEXPECT.spawn(operation, echo=False)
self.pexpect.logfile = self.logfile
else:
if self.pexpect.command is None:
print('New spawn')
self.pexpect._spawn(operation)
else:
#print('Use existing')
self.pexpect.sendline(operation)
#
# print ("AFTER:>>")
# print (self.pexpect.before)
# print (self.pexpect.after)
# print (self.pexpect.buffer)
#
#print "MATCH:>>"
#print self.pexpect.match
ret_val = -1
if expect is not None:
ret_val = self.pexpect.expect(expect_list, timeout=timeout)
#print('returned '+str(ret_val))
if ret_val is 0:
print ("Got "+str(ret_val))
print('Buffer: {}'.format(self.pexpect.buffer))
print('Before: {}'.format(self.pexpect.before))
print('After:{}'.format(self.pexpect.after))
raise PEXPECT.TIMEOUT("Timed out")
elif ret_val is 1:
print ("Got "+str(ret_val))
print('Buffer: {}'.format(self.pexpect.buffer))
print('Before: {}'.format(self.pexpect.before))
print('After:{}'.format(self.pexpect.after))
raise PEXPECT.TIMEOUT("EOF encountered")
def read_str(self):
ret = self._strcomm.read_str()
modified_ret = self._modified_s(ret)
LOGGER.debug('==== Received: %s, is lost: %d', ret, not modified_ret)
LOGGER.debug('==== Modified return %s', modified_ret)
if not modified_ret:
raise pexpect.TIMEOUT('==== Message is lost: {!r}'.format(ret))
return ret
def check_prompt_group(logger, match, expected, field):
if expected:
found = match.group(field)
logger.debug("prompt field: '%s' expected: '%s' found: '%s'", field, expected, found)
if expected != found:
# Throw TIMEOUT as that is what is expected and what
# would have happened.
pexpect.TIMEOUT("incorrect prompt, field '%s' should be '%s but was '%s'" \
% (field, expected, found))
def test_timeout_error_with_exception(self, mock_call):
# test timeout error
pexpect.spawn.return_value.expect.side_effect = (
pexpect.TIMEOUT('timeout error'))
pexpect.spawn.return_value.close.side_effect = (
pexpect.ExceptionPexpect('error'))
# test and verify
self.assertRaises(pkg.PkgTimeout, self.pkg.pkg_remove, self.pkgName,
5000)
self.assertEqual(1, mock_call.call_count)
def enable_mode(cls):
""" Jump into enable mode if password supplied """
enable_cmd = cls.vendor.enable_mode()
if enable_cmd and cls.enpass:
cls.ssh.sendline(enable_cmd[0])
cls.ssh.expect(enable_cmd[1])
cls.ssh.sendline(cls.enpass)
if not cls.ssh.prompt():
raise pexpect.TIMEOUT()
if cls.debug: return cls.ssh.before
def expect(self, *args, **kwargs):
if self._expect_sequence is None:
raise RuntimeError("No expect_sequence given")
if self._count < len(self._expect_sequence):
res = self._expect_sequence[self._count]
if res is pexpect.TIMEOUT:
raise pexpect.TIMEOUT("")
self._count += 1
return res
raise RuntimeError("State error")
def test_matches_exp_timeout(self):
'''This tests that we can raise and catch TIMEOUT.
'''
try:
raise pexpect.TIMEOUT("TIMEOUT match test")
except pexpect.TIMEOUT:
pass
#print "Correctly caught TIMEOUT when raising TIMEOUT."
else:
self.fail('TIMEOUT not caught by an except TIMEOUT clause.')
def _expect_callback(pattern, timeout=e.timeout):
tstart = time.time()
while time.time() < tstart + timeout:
try:
ret = e.expect_saved(pattern, timeout=1)
return ret
except pexpect.TIMEOUT:
e.expect_user_callback(e)
print("Timed out looking for %s" % pattern)
raise pexpect.TIMEOUT(timeout)
def WaitForLogMatch(self, success_re, error_re, clear=False):
"""Blocks until a matching line is logged or a timeout occurs.
Args:
success_re: A compiled re to search each line for.
error_re: A compiled re which, if found, terminates the search for
|success_re|. If None is given, no error condition will be detected.
clear: If True the existing logcat output will be cleared, defaults to
false.
Raises:
pexpect.TIMEOUT upon the timeout specified by StartMonitoringLogcat().
Returns:
The re match object if |success_re| is matched first or None if |error_re|
is matched first.
"""
if not self._logcat:
self.StartMonitoringLogcat(clear)
logging.info('<<< Waiting for logcat:' + str(success_re.pattern))
t0 = time.time()
try:
while True:
# Note this will block for upto the timeout _per log line_, so we need
# to calculate the overall timeout remaining since t0.
time_remaining = t0 + self._logcat.timeout - time.time()
if time_remaining < 0: raise pexpect.TIMEOUT(self._logcat)
self._logcat.expect(PEXPECT_LINE_RE, timeout=time_remaining)
line = self._logcat.match.group(1)
if error_re:
error_match = error_re.search(line)
if error_match:
return None
success_match = success_re.search(line)
if success_match:
return success_match
logging.info('<<< Skipped Logcat Line:' + str(line))
except pexpect.TIMEOUT:
raise pexpect.TIMEOUT(
'Timeout (%ds) exceeded waiting for pattern "%s" (tip: use -vv '
'to debug)' %
(self._logcat.timeout, success_re.pattern))
def prompt(self, timeout=-1):
if timeout == -1:
timeout = self.timeout
ind = self.expect([self.PROMPT, pexpect.TIMEOUT], timeout=timeout)
if ind == 0:
return True
elif ind == 1:
promptE = pexpect.TIMEOUT('Timeout exceeded.' + '\n' + str(self))
raise promptE
else:
return False
def expect_loop(self, searcher, timeout=-1, searchwindowsize=-1):
'''
Using print_verbose, to get realtime output. Everything else
is from pexpect.expect_loop.
'''
self.searcher = searcher
if timeout == -1:
timeout = self.timeout
if timeout is not None:
end_time = time.time() + timeout
if searchwindowsize == -1:
searchwindowsize = self.searchwindowsize
try:
incoming = self.buffer
freshlen = len(incoming)
while True: # Keep reading until exception or return.
app.print_verbose(incoming[-freshlen:],
self.verbose_level,
new_line=False,
enable_caption=False)
index = searcher.search(incoming, freshlen, searchwindowsize)
if index >= 0:
self.buffer = incoming[searcher.end:]
self.before = incoming[:searcher.start]
self.after = incoming[searcher.start:searcher.end]
self.match = searcher.match
self.match_index = index
return self.match_index
# No match at this point
if timeout < 0 and timeout is not None:
raise pexpect.TIMEOUT('Timeout exceeded in expect_any().')
# Still have time left, so read more data
c = self.read_nonblocking(self.maxread, timeout)
freshlen = len(c)
time.sleep(0.0001)
incoming = incoming + c
if timeout is not None:
timeout = end_time - time.time()
except pexpect.EOF, e:
self.buffer = ''
self.before = incoming
self.after = pexpect.EOF
index = searcher.eof_index
if index >= 0:
self.match = pexpect.EOF
self.match_index = index
return self.match_index
else:
self.match = None
self.match_index = None
raise pexpect.EOF(str(e) + '\n' + str(self))
def _cmd_wrapper(cls, cmd=None, showoutput=True, prompt=None):
""" Wrapper for show commands """
cls.ssh.sendline(cmd)
if prompt:
cls.ssh.expect(prompt)
elif not cls.ssh.prompt():
raise pexpect.TIMEOUT(cmd)
if 'error' in cls.ssh.before.lower():
cls.cmderrors.append(cmd)
if showoutput:
return re.sub(r"^{0}\s+".format(cmd), "", cls.ssh.before)
def prompt_expect(self, timeout=None):
if self.debug: print('Method self.prompt_expect', end=': ')
timeout = timeout or self.timeout
if self.prompt_exact:
if self.debug: print('expecting prompt %s' % self.prompt_exact)
self.connect.expect_exact(self.prompt_exact, timeout=timeout)
elif self.prompt_regex:
if self.debug: print('expecting prompt %s' % self.prompt_regex)
self.connect.expect(self.prompt_regex, timeout=timeout)
else:
if self.debug: print('self.prompt_expect timeout')
raise pexpect.TIMEOUT('Timeout')
