Merge remote branch 'cros/upstream' into master

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
+import time, os, logging, re, 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 = kvm_utils.env_get_vm(env, vm_name)
+    vm = env.get_vm(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):
+def wait_for_login(vm, nic_index=0, timeout=240, start=0, step=2, serial=None):
     """
     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.
     """
-    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)
+    end_time = time.time() + timeout
+    session = None
+    if serial:
+        type = 'serial'
+        logging.info("Trying to log into guest %s using serial connection,"
+                     " timeout %ds", vm.name, timeout)
+        time.sleep(start)
+        while time.time() < end_time:
+            try:
+                session = vm.serial_login()
+                break
+            except kvm_utils.LoginError, e:
+                logging.debug(e)
+            time.sleep(step)
+    else:
+        type = 'remote'
+        logging.info("Trying to log into guest %s using remote connection,"
+                     " timeout %ds", vm.name, timeout)
+        time.sleep(start)
+        while time.time() < end_time:
+            try:
+                session = vm.login(nic_index=nic_index)
+                break
+            except (kvm_utils.LoginError, kvm_vm.VMError), e:
+                logging.debug(e)
+            time.sleep(step)
     if not session:
-        raise error.TestFail("Could not log into guest '%s'" % vm.name)
-    logging.info("Logged into guest '%s'" % vm.name)
+        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)
     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 33 matching lines @@
 
     # Wait for the session to become unresponsive and close it
     if not kvm_utils.wait_for(lambda: not session.is_responsive(timeout=30),
                               120, 0, 1):
         raise error.TestFail("Guest refuses to go down")
     session.close()
 
     # Try logging into the guest until timeout expires
     logging.info("Guest is down. Waiting for it to go up again, timeout %ds",
                  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")
+    session = vm.wait_for_login(nic_index, timeout=timeout)
     logging.info("Guest is up again")
     return session
 
 
 def migrate(vm, env=None, mig_timeout=3600, mig_protocol="tcp",
-            mig_cancel=False):
+            mig_cancel=False, offline=False, stable_check=False,
+            clean=False, save_path=None, dest_host='localhost', mig_port=None):
     """
     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.
-    @return: The post-migration VM.
+    @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.
     """
     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")
 
-    dest_vm = vm.clone()
+    if dest_host == 'localhost':
+        dest_vm = vm.clone()
 
-    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') and stable_check:
+        # Pause the dest vm after creation
+        dest_vm.params['extra_params'] = (dest_vm.params.get('extra_params','')
+                                          + ' -S')
 
-            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")
+    if dest_host == 'localhost':
+        dest_vm.create(migration_mode=mig_protocol, mac_source=vm)
+
+    try:
         try:
             if mig_protocol == "tcp":
-                uri = "tcp:localhost:%d" % dest_vm.migration_port
+                if dest_host == 'localhost':
+                    uri = "tcp:localhost:%d" % dest_vm.migration_port
+                else:
+                    uri = 'tcp:%s:%d' % (dest_host, mig_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")
-                dest_vm.destroy(gracefully=False)
+                if offline:
+                    vm.monitor.cmd("cont")
+                if dest_host == 'localhost':
+                    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:
-            dest_vm.destroy()
+            if dest_host == 'localhost':
+                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 "paused" in dest_vm.monitor.info("status"):
-        logging.debug("Destination VM is paused, resuming it...")
-        dest_vm.monitor.cmd("cont")
+    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")
 
     # Kill the source VM
     vm.destroy(gracefully=False)
 
     # Replace the source VM with the new cloned VM
-    if env is not None:
-        kvm_utils.env_register_vm(env, vm.name, dest_vm)
+    if (dest_host == 'localhost') and (env is not None):
+        env.register_vm(vm.name, dest_vm)
 
     # Return the new cloned VM
-    return dest_vm
+    if dest_host == 'localhost':
+        return dest_vm
+    else:
+        return 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.get_command_output("sc stop %s" % service, timeout=60)
+        o = session.cmd_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.get_command_output("sc start %s" % service, timeout=60)
+        o = session.cmd_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()
-        session.sendline(time_command)
-        (match, s) = session.read_up_to_prompt()
-        if not match:
-            raise error.TestError("Could not get guest time")
+        s = session.cmd_output(time_command)
 
         try:
             s = re.findall(time_filter_re, s)[0]
         except IndexError:
-            logging.debug("The time string from guest is:\n%s" % s)
+            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))
+            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:
-        s , o = session.get_command_status_output(time_command)
-        if s != 0:
-            raise error.TestError("Could not get guest time")
+        o = session.cmd(time_command)
         if re.match('ntpdate', time_command):
-            offset = re.findall('offset (.*) sec',o)[0]
+            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)
+            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):
                 hour = re.findall('\d+ (\d+):', guest_time)[0]
                 hour = str(int(hour) + 12)
                 guest_time = re.sub('\d+\s\d+:', "\d+\s%s:" % hour,
                                     guest_time)[:-3]
             else:
@@ skipping 30 matching lines @@
         shm = vm.get_shared_meminfo()
         if shm is None:
             raise error.TestError("Could not get shared meminfo from "
                                   "VM %s" % vm)
         meminfo += "%dM; " % shm
     meminfo = meminfo[0:-2] + "}"
 
     return meminfo
 
 
-def run_autotest(vm, session, control_path, timeout, outputdir):
+def run_autotest(vm, session, control_path, timeout, outputdir, params):
     """
     Run an autotest control file inside a guest (linux only utility).
 
     @param vm: VM object.
     @param session: A shell session on the VM provided.
     @param control_path: A path to an autotest control file.
     @param timeout: Timeout under which the autotest control file must complete.
     @param outputdir: Path on host where we should copy the guest autotest
             results to.
+
+    The following params is used by the migration
+    @param params: Test params used in the migration test
     """
     def copy_if_hash_differs(vm, local_path, remote_path):
         """
         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.get_command_output("md5sum %s" % remote_path)
+        output = session.cmd_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"
-
         if remote_hash != local_hash:
             logging.debug("Copying %s to guest", basename)
-            copy = True
-
-        if copy:
-            if not vm.copy_files_to(local_path, remote_path):
-                raise error.TestFail("Could not copy %s to guest" % local_path)
+            vm.copy_files_to(local_path, remote_path)
 
 
     def extract(vm, remote_path, dest_dir="."):
         """
         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)
-        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)
+        session.cmd(e_cmd, timeout=120)
 
 
     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")
+        vm.copy_files_from("%s/results/default/*" % autotest_path,
+                           guest_results_dir)
 
 
     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.get_command_output("cat results/*/status")
+        output = session.cmd_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)
             return None
 
 
     if not os.path.isfile(control_path):
         raise error.TestError("Invalid path to autotest control file: %s" %
                               control_path)
 
+    migrate_background = params.get("migrate_background") == "yes"
+    if migrate_background:
+        mig_timeout = float(params.get("mig_timeout", "3600"))
+        mig_protocol = params.get("migration_protocol", "tcp")
+
     compressed_autotest_path = "/tmp/autotest.tar.bz2"
 
     # To avoid problems, let's make the test use the current AUTODIR
     # (autotest client path) location
     autotest_path = os.environ['AUTODIR']
 
     # tar the contents of bindir/autotest
     cmd = "tar cvjf %s %s/*" % (compressed_autotest_path, autotest_path)
     # Until we have nested virtualization, we don't need the kvm test :)
     cmd += " --exclude=%s/tests/kvm" % autotest_path
     cmd += " --exclude=%s/results" % autotest_path
     cmd += " --exclude=%s/tmp" % autotest_path
     cmd += " --exclude=%s/control*" % autotest_path
     cmd += " --exclude=*.pyc"
     cmd += " --exclude=*.svn"
     cmd += " --exclude=*.git"
     utils.run(cmd)
 
     # Copy autotest.tar.bz2
     copy_if_hash_differs(vm, compressed_autotest_path, compressed_autotest_path)
 
     # 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")
+    vm.copy_files_to(control_path, os.path.join(autotest_path, 'control'))
 
     # Run the test
     logging.info("Running autotest control file %s on guest, timeout %ss",
                  os.path.basename(control_path), timeout)
-    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():
+    session.cmd("cd %s" % autotest_path)
+    try:
+        session.cmd("rm -f control.state")
+        session.cmd("rm -rf results/*")
+    except kvm_subprocess.ShellError:
+        pass
+    try:
+        bg = None
+        try:
+            logging.info("---------------- Test output ----------------")
+            if migrate_background:
+                mig_timeout = float(params.get("mig_timeout", "3600"))
+                mig_protocol = params.get("migration_protocol", "tcp")
+
+                bg = kvm_utils.Thread(session.cmd_output,
+                                      kwargs={'cmd': "bin/autotest control",
+                                              'timeout': timeout,
+                                              'print_func': logging.info})
+
+                bg.start()
+
+                while bg.is_alive():
+                    logging.info("Tests is not ended, start a round of"
+                                 "migration ...")
+                    vm.migrate(timeout=mig_timeout, protocol=mig_protocol)
+            else:
+                session.cmd_output("bin/autotest control", timeout=timeout,
+                                   print_func=logging.info)
+        finally:
+            logging.info("------------- End of test output ------------")
+            if migrate_background and bg:
+                bg.join()
+    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:
             raise error.TestError("Autotest job on guest failed "
                                   "(VM terminated during job)")
-        if not session.is_alive():
-            get_results()
-            raise error.TestError("Autotest job on guest failed "
-                                  "(Remote session terminated during job)")
+    except kvm_subprocess.ShellProcessTerminatedError:
         get_results()
-        get_results_summary()
-        raise error.TestError("Timeout elapsed while waiting for job to "
-                              "complete")
+        raise error.TestError("Autotest job on guest failed "
+                              "(Remote session terminated during job)")
 
     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:
-        session.sendline(command)
-        status, output = session.read_up_to_prompt(timeout=timeout,
-                                                   print_func=output_func)
-        if not status:
+        output = ""
+        try:
+            output = session.cmd_output(command, timeout=timeout,
+                                        print_func=output_func)
+        except kvm_subprocess.ShellTimeoutError:
             # Send ctrl+c (SIGINT) through ssh session
             session.send("\003")
-            status, output2 = session.read_up_to_prompt(print_func=output_func)
-            output += output2
-            if not status:
+            try:
+                output2 = session.read_up_to_prompt(print_func=output_func)
+                output += output2
+            except kvm_subprocess.ExpectTimeoutError, e:
+                output += e.output
                 # We also need to use this session to query the return value
                 session.send("\003")
 
         session.sendline(session.status_test_command)
-        s2, o2 = session.read_up_to_prompt()
-        if not s2:
+        try:
+            o2 = session.read_up_to_prompt()
+        except kvm_subprocess.ExpectError:
             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.get_command_output("ifconfig -a")
+    output = session.cmd_output("ifconfig -a")
 
     try:
         ethname = re.findall("(\w+)\s+Link.*%s" % mac_address, output,
                              re.IGNORECASE)[0]
         return ethname
     except:
         return None