Revert "Merge remote branch 'cros/upstream' into autotest-rebase"

client/tests/kvm/kvm_test_utils.py

 """
 High-level KVM test utility functions.
 
 This module is meant to reduce code size by performing common test procedures.
 Generally, code here should look like test code.
 More specifically:
     - Functions in this module should raise exceptions if things go wrong
       (unlike functions in kvm_utils.py and kvm_vm.py which report failure via
       their returned values).
     - Functions in this module may use logging.info(), in addition to
       logging.debug() and logging.error(), to log messages the user may be
       interested in (unlike kvm_utils.py and kvm_vm.py which use
       logging.debug() for anything that isn't an error).
     - Functions in this module typically use functions and classes from
       lower-level modules (e.g. kvm_utils.py, kvm_vm.py, kvm_subprocess.py).
     - Functions in this module should not be used by lower-level modules.
     - Functions in this module should be used in the right context.
       For example, a function should not be used where it may display
       misleading or inaccurate info or debug messages.
 
 @copyright: 2008-2009 Red Hat Inc.
 """
 
-import time, os, logging, re, commands, signal, threading
+import time, os, logging, re, commands, signal
 from autotest_lib.client.common_lib import error
 from autotest_lib.client.bin import utils
 import kvm_utils, kvm_vm, kvm_subprocess, scan_results
 
 
 def get_living_vm(env, vm_name):
     """
     Get a VM object from the environment and make sure it's alive.
 
     @param env: Dictionary with test environment.
     @param vm_name: Name of the desired VM object.
     @return: A VM object.
     """
-    vm = env.get_vm(vm_name)
+    vm = kvm_utils.env_get_vm(env, vm_name)
     if not vm:
         raise error.TestError("VM '%s' not found in environment" % vm_name)
     if not vm.is_alive():
         raise error.TestError("VM '%s' seems to be dead; test requires a "
                               "living VM" % vm_name)
     return vm
 
 
-def wait_for_login(vm, nic_index=0, timeout=240, start=0, step=2, serial=None):
+def wait_for_login(vm, nic_index=0, timeout=240, start=0, step=2):
     """
     Try logging into a VM repeatedly.  Stop on success or when timeout expires.
 
     @param vm: VM object.
     @param nic_index: Index of NIC to access in the VM.
     @param timeout: Time to wait before giving up.
-    @param serial: Whether to use a serial connection instead of a remote
-            (ssh, rss) one.
     @return: A shell session object.
     """
-    type = 'remote'
-    if serial:
-        type = 'serial'
-        logging.info("Trying to log into guest %s using serial connection,"
-                     " timeout %ds", vm.name, timeout)
-        session = kvm_utils.wait_for(lambda: vm.serial_login(), timeout,
-                                     start, step)
-    else:
-        logging.info("Trying to log into guest %s using remote connection,"
-                     " timeout %ds", vm.name, timeout)
-        session = kvm_utils.wait_for(lambda: vm.remote_login(
-                  nic_index=nic_index), timeout, start, step)
+    logging.info("Trying to log into guest '%s', timeout %ds", vm.name, timeout)
+    session = kvm_utils.wait_for(lambda: vm.remote_login(nic_index=nic_index),
+                                 timeout, start, step)
     if not session:
-        raise error.TestFail("Could not log into guest %s using %s connection" %
-                             (vm.name, type))
-    logging.info("Logged into guest %s using %s connection", vm.name, type)
+        raise error.TestFail("Could not log into guest '%s'" % vm.name)
+    logging.info("Logged into guest '%s'" % vm.name)
     return session
 
 
 def reboot(vm, session, method="shell", sleep_before_reset=10, nic_index=0,
            timeout=240):
     """
     Reboot the VM and wait for it to come back up by trying to log in until
     timeout expires.
 
     @param vm: VM object.
@@ skipping 42 matching lines @@
                  timeout)
     session = kvm_utils.wait_for(lambda: vm.remote_login(nic_index=nic_index),
                                  timeout, 0, 2)
     if not session:
         raise error.TestFail("Could not log into guest after reboot")
     logging.info("Guest is up again")
     return session
 
 
 def migrate(vm, env=None, mig_timeout=3600, mig_protocol="tcp",
-            mig_cancel=False, offline=False, stable_check=False,
-            clean=False, save_path=None, dest_host='localhost', mig_port=None):
+            mig_cancel=False):
     """
     Migrate a VM locally and re-register it in the environment.
 
     @param vm: The VM to migrate.
     @param env: The environment dictionary.  If omitted, the migrated VM will
             not be registered.
     @param mig_timeout: timeout value for migration.
     @param mig_protocol: migration protocol
     @param mig_cancel: Test migrate_cancel or not when protocol is tcp.
-    @param dest_host: Destination host (defaults to 'localhost').
-    @param mig_port: Port that will be used for migration.
-    @return: The post-migration VM, in case of same host migration, True in
-            case of multi-host migration.
+    @return: The post-migration VM.
     """
     def mig_finished():
         o = vm.monitor.info("migrate")
         if isinstance(o, str):
             return "status: active" not in o
         else:
             return o.get("status") != "active"
 
     def mig_succeeded():
         o = vm.monitor.info("migrate")
@@ skipping 17 matching lines @@
         else:
             return (o.get("status") == "cancelled" or
                     o.get("status") == "canceled")
 
     def wait_for_migration():
         if not kvm_utils.wait_for(mig_finished, mig_timeout, 2, 2,
                                   "Waiting for migration to finish..."):
             raise error.TestFail("Timeout expired while waiting for migration "
                                  "to finish")
 
-    if dest_host == 'localhost':
-        dest_vm = vm.clone()
+    dest_vm = vm.clone()
 
-    if (dest_host == 'localhost') and stable_check:
-        # Pause the dest vm after creation
-        dest_vm.params['extra_params'] = (dest_vm.params.get('extra_params','')
-                                          + ' -S')
+    if mig_protocol == "exec":
+        # Exec is a little different from other migrate methods - first we
+        # ask the monitor the migration, then the vm state is dumped to a
+        # compressed file, then we start the dest vm with -incoming pointing
+        # to it
+        try:
+            exec_file = "/tmp/exec-%s.gz" % kvm_utils.generate_random_string(8)
+            exec_cmd = "gzip -c -d %s" % exec_file
+            uri = '"exec:gzip -c > %s"' % exec_file
+            vm.monitor.cmd("stop")
+            vm.monitor.migrate(uri)
+            wait_for_migration()
 
-    if dest_host == 'localhost':
+            if not dest_vm.create(migration_mode=mig_protocol,
+                                  migration_exec_cmd=exec_cmd, mac_source=vm):
+                raise error.TestError("Could not create dest VM")
+        finally:
+            logging.debug("Removing migration file %s", exec_file)
+            try:
+                os.remove(exec_file)
+            except OSError:
+                pass
+    else:
         if not dest_vm.create(migration_mode=mig_protocol, mac_source=vm):
             raise error.TestError("Could not create dest VM")
-
-    try:
         try:
             if mig_protocol == "tcp":
-                if dest_host == 'localhost':
-                    uri = "tcp:localhost:%d" % dest_vm.migration_port
-                else:
-                    uri = 'tcp:%s:%d' % (dest_host, mig_port)
+                uri = "tcp:localhost:%d" % dest_vm.migration_port
             elif mig_protocol == "unix":
                 uri = "unix:%s" % dest_vm.migration_file
-            elif mig_protocol == "exec":
-                uri = '"exec:nc localhost %s"' % dest_vm.migration_port
-
-            if offline:
-                vm.monitor.cmd("stop")
             vm.monitor.migrate(uri)
 
             if mig_cancel:
                 time.sleep(2)
                 vm.monitor.cmd("migrate_cancel")
                 if not kvm_utils.wait_for(mig_cancelled, 60, 2, 2,
                                           "Waiting for migration "
                                           "cancellation"):
                     raise error.TestFail("Failed to cancel migration")
-                if offline:
-                    vm.monitor.cmd("cont")
-                if dest_host == 'localhost':
-                    dest_vm.destroy(gracefully=False)
+                dest_vm.destroy(gracefully=False)
                 return vm
             else:
                 wait_for_migration()
-                if (dest_host == 'localhost') and stable_check:
-                    save_path = None or "/tmp"
-                    save1 = os.path.join(save_path, "src")
-                    save2 = os.path.join(save_path, "dst")
-
-                    vm.save_to_file(save1)
-                    dest_vm.save_to_file(save2)
-
-                    # Fail if we see deltas
-                    md5_save1 = utils.hash_file(save1)
-                    md5_save2 = utils.hash_file(save2)
-                    if md5_save1 != md5_save2:
-                        raise error.TestFail("Mismatch of VM state before "
-                                             "and after migration")
-
-                if (dest_host == 'localhost') and offline:
-                    dest_vm.monitor.cmd("cont")
         except:
-            if dest_host == 'localhost':
-                dest_vm.destroy()
+            dest_vm.destroy()
             raise
 
-    finally:
-        if (dest_host == 'localhost') and stable_check and clean:
-            logging.debug("Cleaning the state files")
-            if os.path.isfile(save1):
-                os.remove(save1)
-            if os.path.isfile(save2):
-                os.remove(save2)
-
     # Report migration status
     if mig_succeeded():
         logging.info("Migration finished successfully")
     elif mig_failed():
         raise error.TestFail("Migration failed")
     else:
         raise error.TestFail("Migration ended with unknown status")
 
-    if dest_host == 'localhost':
-        if "paused" in dest_vm.monitor.info("status"):
-            logging.debug("Destination VM is paused, resuming it...")
-            dest_vm.monitor.cmd("cont")
+    if "paused" in dest_vm.monitor.info("status"):
+        logging.debug("Destination VM is paused, resuming it...")
+        dest_vm.monitor.cmd("cont")
 
     # Kill the source VM
     vm.destroy(gracefully=False)
 
     # Replace the source VM with the new cloned VM
-    if (dest_host == 'localhost') and (env is not None):
-        env.register_vm(vm.name, dest_vm)
+    if env is not None:
+        kvm_utils.env_register_vm(env, vm.name, dest_vm)
 
     # Return the new cloned VM
-    if dest_host == 'localhost':
-        return dest_vm
-    else:
-        return vm
+    return dest_vm
 
 
 def stop_windows_service(session, service, timeout=120):
     """
     Stop a Windows service using sc.
     If the service is already stopped or is not installed, do nothing.
 
     @param service: The name of the service
     @param timeout: Time duration to wait for service to stop
     @raise error.TestError: Raised if the service can't be stopped
     """
     end_time = time.time() + timeout
     while time.time() < end_time:
-        o = session.cmd_output("sc stop %s" % service, timeout=60)
+        o = session.get_command_output("sc stop %s" % service, timeout=60)
         # FAILED 1060 means the service isn't installed.
         # FAILED 1062 means the service hasn't been started.
         if re.search(r"\bFAILED (1060|1062)\b", o, re.I):
             break
         time.sleep(1)
     else:
         raise error.TestError("Could not stop service '%s'" % service)
 
 
 def start_windows_service(session, service, timeout=120):
     """
     Start a Windows service using sc.
     If the service is already running, do nothing.
     If the service isn't installed, fail.
 
     @param service: The name of the service
     @param timeout: Time duration to wait for service to start
     @raise error.TestError: Raised if the service can't be started
     """
     end_time = time.time() + timeout
     while time.time() < end_time:
-        o = session.cmd_output("sc start %s" % service, timeout=60)
+        o = session.get_command_output("sc start %s" % service, timeout=60)
         # FAILED 1060 means the service isn't installed.
         if re.search(r"\bFAILED 1060\b", o, re.I):
             raise error.TestError("Could not start service '%s' "
                                   "(service not installed)" % service)
         # FAILED 1056 means the service is already running.
         if re.search(r"\bFAILED 1056\b", o, re.I):
             break
         time.sleep(1)
     else:
         raise error.TestError("Could not start service '%s'" % service)
@@ skipping 11 matching lines @@
     @param session: A shell session.
     @param time_command: Command to issue to get the current guest time.
     @param time_filter_re: Regex filter to apply on the output of
             time_command in order to get the current time.
     @param time_format: Format string to pass to time.strptime() with the
             result of the regex filter.
     @return: A tuple containing the host time and guest time.
     """
     if len(re.findall("ntpdate|w32tm", time_command)) == 0:
         host_time = time.time()
-        s = session.cmd_output(time_command)
+        session.sendline(time_command)
+        (match, s) = session.read_up_to_prompt()
+        if not match:
+            raise error.TestError("Could not get guest time")
 
         try:
             s = re.findall(time_filter_re, s)[0]
         except IndexError:
             logging.debug("The time string from guest is:\n%s" % s)
             raise error.TestError("The time string from guest is unexpected.")
         except Exception, e:
             logging.debug("(time_filter_re, time_string): (%s, %s)" %
                            (time_filter_re, s))
             raise e
 
         guest_time = time.mktime(time.strptime(s, time_format))
     else:
-        o = session.cmd(time_command)
+        s , o = session.get_command_status_output(time_command)
+        if s != 0:
+            raise error.TestError("Could not get guest time")
         if re.match('ntpdate', time_command):
             offset = re.findall('offset (.*) sec',o)[0]
             host_main, host_mantissa = re.findall(time_filter_re, o)[0]
             host_time = time.mktime(time.strptime(host_main, time_format)) \
                         + float("0.%s" % host_mantissa)
             guest_time = host_time + float(offset)
         else:
             guest_time =  re.findall(time_filter_re, o)[0]
             offset = re.findall("o:(.*)s", o)[0]
             if re.match('PM', guest_time):
@@ skipping 57 matching lines @@
         """
         Copy a file to a guest if it doesn't exist or if its MD5sum differs.
 
         @param vm: VM object.
         @param local_path: Local path.
         @param remote_path: Remote path.
         """
         copy = False
         local_hash = utils.hash_file(local_path)
         basename = os.path.basename(local_path)
-        output = session.cmd_output("md5sum %s" % remote_path)
+        output = session.get_command_output("md5sum %s" % remote_path)
         if "such file" in output:
             remote_hash = "0"
         elif output:
             remote_hash = output.split()[0]
         else:
             logging.warning("MD5 check for remote path %s did not return.",
                             remote_path)
             # Let's be a little more lenient here and see if it wasn't a
             # temporary problem
             remote_hash = "0"
@@ skipping 11 matching lines @@
         """
         Extract a .tar.bz2 file on the guest.
 
         @param vm: VM object
         @param remote_path: Remote file path
         @param dest_dir: Destination dir for the contents
         """
         basename = os.path.basename(remote_path)
         logging.info("Extracting %s...", basename)
         e_cmd = "tar xjvf %s -C %s" % (remote_path, dest_dir)
-        session.cmd(e_cmd, timeout=120)
+        s, o = session.get_command_status_output(e_cmd, timeout=120)
+        if s != 0:
+            logging.error("Uncompress output:\n%s", o)
+            raise error.TestFail("Failed to extract %s on guest" % basename)
 
 
     def get_results():
         """
         Copy autotest results present on the guest back to the host.
         """
         logging.info("Trying to copy autotest results from guest")
         guest_results_dir = os.path.join(outputdir, "guest_autotest_results")
         if not os.path.exists(guest_results_dir):
             os.mkdir(guest_results_dir)
         if not vm.copy_files_from("%s/results/default/*" % autotest_path,
                                   guest_results_dir):
             logging.error("Could not copy autotest results from guest")
 
 
     def get_results_summary():
         """
         Get the status of the tests that were executed on the host and close
         the session where autotest was being executed.
         """
-        output = session.cmd_output("cat results/*/status")
+        output = session.get_command_output("cat results/*/status")
         try:
             results = scan_results.parse_results(output)
             # Report test results
             logging.info("Results (test, status, duration, info):")
             for result in results:
                 logging.info(str(result))
             session.close()
             return results
         except Exception, e:
             logging.error("Error processing guest autotest results: %s", e)
@@ skipping 28 matching lines @@
     # Extract autotest.tar.bz2
     extract(vm, compressed_autotest_path, "/")
 
     if not vm.copy_files_to(control_path,
                             os.path.join(autotest_path, 'control')):
         raise error.TestFail("Could not copy the test control file to guest")
 
     # Run the test
     logging.info("Running autotest control file %s on guest, timeout %ss",
                  os.path.basename(control_path), timeout)
-    session.cmd("cd %s" % autotest_path)
-    try:
-        session.cmd("rm -f control.state")
-        session.cmd("rm -rf results/*")
-    except kvm_subprocess.ShellError:
-        pass
-    try:
-        try:
-            logging.info("---------------- Test output ----------------")
-            session.cmd_output("bin/autotest control", timeout=timeout,
-                               print_func=logging.info)
-        finally:
-            logging.info("------------- End of test output ------------")
-    except kvm_subprocess.ShellTimeoutError:
-        if vm.is_alive():
-            get_results()
-            get_results_summary()
-            raise error.TestError("Timeout elapsed while waiting for job to "
-                                  "complete")
-        else:
+    session.get_command_output("cd %s" % autotest_path)
+    session.get_command_output("rm -f control.state")
+    session.get_command_output("rm -rf results/*")
+    logging.info("---------------- Test output ----------------")
+    status = session.get_command_status("bin/autotest control",
+                                        timeout=timeout,
+                                        print_func=logging.info)
+    logging.info("------------- End of test output ------------")
+    if status is None:
+        if not vm.is_alive():
             raise error.TestError("Autotest job on guest failed "
                                   "(VM terminated during job)")
-    except kvm_subprocess.ShellProcessTerminatedError:
+        if not session.is_alive():
+            get_results()
+            raise error.TestError("Autotest job on guest failed "
+                                  "(Remote session terminated during job)")
         get_results()
-        raise error.TestError("Autotest job on guest failed "
-                              "(Remote session terminated during job)")
+        get_results_summary()
+        raise error.TestError("Timeout elapsed while waiting for job to "
+                              "complete")
 
     results = get_results_summary()
     get_results()
 
     # Make a list of FAIL/ERROR/ABORT results (make sure FAIL results appear
     # before ERROR results, and ERROR results appear before ABORT results)
     bad_results = [r[0] for r in results if r[1] == "FAIL"]
     bad_results += [r[0] for r in results if r[1] == "ERROR"]
     bad_results += [r[0] for r in results if r[1] == "ABORT"]
 
@@ skipping 41 matching lines @@
         # always get the packet loss ratio even if timeout.
         if process.is_alive():
             kvm_utils.kill_process_tree(process.get_pid(), signal.SIGINT)
 
         status = process.get_status()
         output = process.get_output()
 
         process.close()
         return status, output
     else:
-        try:
-            output = session.cmd_output(command, timeout=timeout,
-                                        print_func=output_func)
-        except kvm_subprocess.ShellTimeoutError:
+        session.sendline(command)
+        status, output = session.read_up_to_prompt(timeout=timeout,
+                                                   print_func=output_func)
+        if not status:
             # Send ctrl+c (SIGINT) through ssh session
             session.send("\003")
-            try:
-                output2 = session.read_up_to_prompt(print_func=output_func)
-                output += output2
-            except kvm_subprocess.ExpectTimeoutError, e:
-                output += e.output
+            status, output2 = session.read_up_to_prompt(print_func=output_func)
+            output += output2
+            if not status:
                 # We also need to use this session to query the return value
                 session.send("\003")
 
         session.sendline(session.status_test_command)
-        try:
-            o2 = session.read_up_to_prompt()
-        except kvm_subprocess.ExpectError:
+        s2, o2 = session.read_up_to_prompt()
+        if not s2:
             status = -1
         else:
             try:
                 status = int(re.findall("\d+", o2)[0])
             except:
                 status = -1
 
         return status, output
 
 
@@ skipping 46 matching lines @@
 
 
 def get_linux_ifname(session, mac_address):
     """
     Get the interface name through the mac address.
 
     @param session: session to the virtual machine
     @mac_address: the macaddress of nic
     """
 
-    output = session.cmd_output("ifconfig -a")
+    output = session.get_command_output("ifconfig -a")
 
     try:
         ethname = re.findall("(\w+)\s+Link.*%s" % mac_address, output,
                              re.IGNORECASE)[0]
         return ethname
     except:
         return None