def run_timedrift(test, params, env): """ Time drift test (mainly for Windows guests): 1) Log into a guest. 2) Take a time reading from the guest and host. 3) Run load on the guest and host. 4) Take a second time reading. 5) Stop the load and rest for a while. 6) Take a third time reading. 7) If the drift immediately after load is higher than a user- specified value (in %), fail. If the drift after the rest period is higher than a user-specified value, fail. @param test: KVM test object. @param params: Dictionary with test parameters. @param env: Dictionary with the test environment. """ # Helper functions def set_cpu_affinity(pid, mask): """ Set the CPU affinity of all threads of the process with PID pid. Do this recursively for all child processes as well. @param pid: The process ID. @param mask: The CPU affinity mask. @return: A dict containing the previous mask for each thread. """ tids = commands.getoutput("ps -L --pid=%s -o lwp=" % pid).split() prev_masks = {} for tid in tids: prev_mask = commands.getoutput("taskset -p %s" % tid).split()[-1] prev_masks[tid] = prev_mask commands.getoutput("taskset -p %s %s" % (mask, tid)) children = commands.getoutput("ps --ppid=%s -o pid=" % pid).split() for child in children: prev_masks.update(set_cpu_affinity(child, mask)) return prev_masks def restore_cpu_affinity(prev_masks): """ Restore the CPU affinity of several threads. @param prev_masks: A dict containing TIDs as keys and masks as values. """ for tid, mask in prev_masks.items(): commands.getoutput("taskset -p %s %s" % (mask, tid)) vm = env.get_vm(params["main_vm"]) vm.verify_alive() timeout = int(params.get("login_timeout", 360)) session = vm.wait_for_login(timeout=timeout) # Collect test parameters: # Command to run to get the current time time_command = params.get("time_command") # Filter which should match a string to be passed to time.strptime() time_filter_re = params.get("time_filter_re") # Time format for time.strptime() time_format = params.get("time_format") guest_load_command = params.get("guest_load_command") guest_load_stop_command = params.get("guest_load_stop_command") host_load_command = params.get("host_load_command") guest_load_instances = int(params.get("guest_load_instances", "1")) host_load_instances = int(params.get("host_load_instances", "0")) # CPU affinity mask for taskset cpu_mask = params.get("cpu_mask", "0xFF") load_duration = float(params.get("load_duration", "30")) rest_duration = float(params.get("rest_duration", "10")) drift_threshold = float(params.get("drift_threshold", "200")) drift_threshold_after_rest = float(params.get("drift_threshold_after_rest", "200")) guest_load_sessions = [] host_load_sessions = [] try: # Set the VM's CPU affinity prev_affinity = set_cpu_affinity(vm.get_shell_pid(), cpu_mask) try: # Open shell sessions with the guest logging.info("Starting load on guest...") for i in range(guest_load_instances): load_session = vm.login() # Set output func to None to stop it from being called so we # can change the callback function and the parameters it takes # with no problems load_session.set_output_func(None) load_session.set_output_params(()) load_session.set_output_prefix("(guest load %d) " % i) load_session.set_output_func(logging.debug) guest_load_sessions.append(load_session) # Get time before load # (ht stands for host time, gt stands for guest time) (ht0, gt0) = virt_test_utils.get_time(session, time_command, time_filter_re, time_format) # Run some load on the guest for load_session in guest_load_sessions: load_session.sendline(guest_load_command) # Run some load on the host logging.info("Starting load on host...") for i in range(host_load_instances): host_load_sessions.append( aexpect.run_bg(host_load_command, output_func=logging.debug, output_prefix="(host load %d) " % i, timeout=0.5)) # Set the CPU affinity of the load process pid = host_load_sessions[-1].get_pid() set_cpu_affinity(pid, cpu_mask) # Sleep for a while (during load) logging.info("Sleeping for %s seconds...", load_duration) time.sleep(load_duration) # Get time delta after load (ht1, gt1) = virt_test_utils.get_time(session, time_command, time_filter_re, time_format) # Report results host_delta = ht1 - ht0 guest_delta = gt1 - gt0 drift = 100.0 * (host_delta - guest_delta) / host_delta logging.info("Host duration: %.2f", host_delta) logging.info("Guest duration: %.2f", guest_delta) logging.info("Drift: %.2f%%", drift) finally: logging.info("Cleaning up...") # Restore the VM's CPU affinity restore_cpu_affinity(prev_affinity) # Stop the guest load if guest_load_stop_command: session.cmd_output(guest_load_stop_command) # Close all load shell sessions for load_session in guest_load_sessions: load_session.close() for load_session in host_load_sessions: load_session.close() # Sleep again (rest) logging.info("Sleeping for %s seconds...", rest_duration) time.sleep(rest_duration) # Get time after rest (ht2, gt2) = virt_test_utils.get_time(session, time_command, time_filter_re, time_format) finally: session.close() # Report results host_delta_total = ht2 - ht0 guest_delta_total = gt2 - gt0 drift_total = 100.0 * (host_delta_total - guest_delta_total) / host_delta logging.info("Total host duration including rest: %.2f", host_delta_total) logging.info("Total guest duration including rest: %.2f", guest_delta_total) logging.info("Total drift after rest: %.2f%%", drift_total) # Fail the test if necessary if abs(drift) > drift_threshold: raise error.TestFail("Time drift too large: %.2f%%" % drift) if abs(drift_total) > drift_threshold_after_rest: raise error.TestFail("Time drift too large after rest period: %.2f%%" % drift_total)
def run_timedrift_with_migration(test, params, env): """ Time drift test with migration: 1) Log into a guest. 2) Take a time reading from the guest and host. 3) Migrate the guest. 4) Take a second time reading. 5) If the drift (in seconds) is higher than a user specified value, fail. @param test: KVM test object. @param params: Dictionary with test parameters. @param env: Dictionary with the test environment. """ vm = env.get_vm(params["main_vm"]) vm.verify_alive() timeout = int(params.get("login_timeout", 360)) session = vm.wait_for_login(timeout=timeout) # Collect test parameters: # Command to run to get the current time time_command = params.get("time_command") # Filter which should match a string to be passed to time.strptime() time_filter_re = params.get("time_filter_re") # Time format for time.strptime() time_format = params.get("time_format") drift_threshold = float(params.get("drift_threshold", "10")) drift_threshold_single = float(params.get("drift_threshold_single", "3")) migration_iterations = int(params.get("migration_iterations", 1)) try: # Get initial time # (ht stands for host time, gt stands for guest time) (ht0, gt0) = virt_test_utils.get_time(session, time_command, time_filter_re, time_format) # Migrate for i in range(migration_iterations): # Get time before current iteration (ht0_, gt0_) = virt_test_utils.get_time(session, time_command, time_filter_re, time_format) session.close() # Run current iteration logging.info("Migrating: iteration %d of %d...", (i + 1), migration_iterations) vm.migrate() # Log in logging.info("Logging in after migration...") session = vm.wait_for_login(timeout=30) logging.info("Logged in after migration") # Get time after current iteration (ht1_, gt1_) = virt_test_utils.get_time(session, time_command, time_filter_re, time_format) # Report iteration results host_delta = ht1_ - ht0_ guest_delta = gt1_ - gt0_ drift = abs(host_delta - guest_delta) logging.info("Host duration (iteration %d): %.2f", (i + 1), host_delta) logging.info("Guest duration (iteration %d): %.2f", (i + 1), guest_delta) logging.info("Drift at iteration %d: %.2f seconds", (i + 1), drift) # Fail if necessary if drift > drift_threshold_single: raise error.TestFail("Time drift too large at iteration %d: " "%.2f seconds" % (i + 1, drift)) # Get final time (ht1, gt1) = virt_test_utils.get_time(session, time_command, time_filter_re, time_format) finally: if session: session.close() # Report results host_delta = ht1 - ht0 guest_delta = gt1 - gt0 drift = abs(host_delta - guest_delta) logging.info("Host duration (%d migrations): %.2f", migration_iterations, host_delta) logging.info("Guest duration (%d migrations): %.2f", migration_iterations, guest_delta) logging.info("Drift after %d migrations: %.2f seconds", migration_iterations, drift) # Fail if necessary if drift > drift_threshold: raise error.TestFail("Time drift too large after %d migrations: " "%.2f seconds" % (migration_iterations, drift))
def run_timedrift_with_stop(test, params, env): """ Time drift test with stop/continue the guest: 1) Log into a guest. 2) Take a time reading from the guest and host. 3) Stop the running of the guest 4) Sleep for a while 5) Continue the guest running 6) Take a second time reading. 7) If the drift (in seconds) is higher than a user specified value, fail. @param test: KVM test object. @param params: Dictionary with test parameters. @param env: Dictionary with the test environment. """ login_timeout = int(params.get("login_timeout", 360)) sleep_time = int(params.get("sleep_time", 30)) vm = env.get_vm(params["main_vm"]) vm.verify_alive() session = vm.wait_for_login(timeout=login_timeout) # Collect test parameters: # Command to run to get the current time time_command = params.get("time_command") # Filter which should match a string to be passed to time.strptime() time_filter_re = params.get("time_filter_re") # Time format for time.strptime() time_format = params.get("time_format") drift_threshold = float(params.get("drift_threshold", "10")) drift_threshold_single = float(params.get("drift_threshold_single", "3")) stop_iterations = int(params.get("stop_iterations", 1)) stop_time = int(params.get("stop_time", 60)) try: # Get initial time # (ht stands for host time, gt stands for guest time) (ht0, gt0) = virt_test_utils.get_time(session, time_command, time_filter_re, time_format) # Stop the guest for i in range(stop_iterations): # Get time before current iteration (ht0_, gt0_) = virt_test_utils.get_time(session, time_command, time_filter_re, time_format) # Run current iteration logging.info("Stop %s second: iteration %d of %d...", stop_time, (i + 1), stop_iterations) vm.monitor.cmd("stop") time.sleep(stop_time) vm.monitor.cmd("cont") # Sleep for a while to wait the interrupt to be reinjected logging.info("Waiting for the interrupt to be reinjected ...") time.sleep(sleep_time) # Get time after current iteration (ht1_, gt1_) = virt_test_utils.get_time(session, time_command, time_filter_re, time_format) # Report iteration results host_delta = ht1_ - ht0_ guest_delta = gt1_ - gt0_ drift = abs(host_delta - guest_delta) logging.info("Host duration (iteration %d): %.2f", (i + 1), host_delta) logging.info("Guest duration (iteration %d): %.2f", (i + 1), guest_delta) logging.info("Drift at iteration %d: %.2f seconds", (i + 1), drift) # Fail if necessary if drift > drift_threshold_single: raise error.TestFail("Time drift too large at iteration %d: " "%.2f seconds" % (i + 1, drift)) # Get final time (ht1, gt1) = virt_test_utils.get_time(session, time_command, time_filter_re, time_format) finally: if session: session.close() # Report results host_delta = ht1 - ht0 guest_delta = gt1 - gt0 drift = abs(host_delta - guest_delta) logging.info("Host duration (%d stops): %.2f", stop_iterations, host_delta) logging.info("Guest duration (%d stops): %.2f", stop_iterations, guest_delta) logging.info("Drift after %d stops: %.2f seconds", stop_iterations, drift) # Fail if necessary if drift > drift_threshold: raise error.TestFail("Time drift too large after %d stops: " "%.2f seconds" % (stop_iterations, drift))
def run_timedrift_with_reboot(test, params, env): """ Time drift test with reboot: 1) Log into a guest. 2) Take a time reading from the guest and host. 3) Reboot the guest. 4) Take a second time reading. 5) If the drift (in seconds) is higher than a user specified value, fail. @param test: KVM test object. @param params: Dictionary with test parameters. @param env: Dictionary with the test environment. """ vm = env.get_vm(params["main_vm"]) vm.verify_alive() timeout = int(params.get("login_timeout", 360)) session = vm.wait_for_login(timeout=timeout) # Collect test parameters: # Command to run to get the current time time_command = params.get("time_command") # Filter which should match a string to be passed to time.strptime() time_filter_re = params.get("time_filter_re") # Time format for time.strptime() time_format = params.get("time_format") drift_threshold = float(params.get("drift_threshold", "10")) drift_threshold_single = float(params.get("drift_threshold_single", "3")) reboot_iterations = int(params.get("reboot_iterations", 1)) try: # Get initial time # (ht stands for host time, gt stands for guest time) (ht0, gt0) = virt_test_utils.get_time(session, time_command, time_filter_re, time_format) # Reboot for i in range(reboot_iterations): # Get time before current iteration (ht0_, gt0_) = virt_test_utils.get_time(session, time_command, time_filter_re, time_format) # Run current iteration logging.info("Rebooting: iteration %d of %d...", (i + 1), reboot_iterations) session = vm.reboot(session) # Get time after current iteration (ht1_, gt1_) = virt_test_utils.get_time(session, time_command, time_filter_re, time_format) # Report iteration results host_delta = ht1_ - ht0_ guest_delta = gt1_ - gt0_ drift = abs(host_delta - guest_delta) logging.info("Host duration (iteration %d): %.2f", (i + 1), host_delta) logging.info("Guest duration (iteration %d): %.2f", (i + 1), guest_delta) logging.info("Drift at iteration %d: %.2f seconds", (i + 1), drift) # Fail if necessary if drift > drift_threshold_single: raise error.TestFail("Time drift too large at iteration %d: " "%.2f seconds" % (i + 1, drift)) # Get final time (ht1, gt1) = virt_test_utils.get_time(session, time_command, time_filter_re, time_format) finally: if session: session.close() # Report results host_delta = ht1 - ht0 guest_delta = gt1 - gt0 drift = abs(host_delta - guest_delta) logging.info("Host duration (%d reboots): %.2f", reboot_iterations, host_delta) logging.info("Guest duration (%d reboots): %.2f", reboot_iterations, guest_delta) logging.info("Drift after %d reboots: %.2f seconds", reboot_iterations, drift) # Fail if necessary if drift > drift_threshold: raise error.TestFail("Time drift too large after %d reboots: " "%.2f seconds" % (reboot_iterations, drift))
def run_time_manage(test, params, env): """ Time manage test: 1) Generate stress in host. 2) Run atleast 15 vms with "driftfix=slew" option 3) Reboot the guest. 4) Repeat the step 3 for all guests and check whether the guest responds properly(not any watchdog reported). 5) TODO: Improve the way of checking the response and run some stress inside guest too. 6) Continue the step 4 for 10 iterations and record the guest/host realtime, calculate drift in time for each iterations. 7) Print the drift values for all sessions 8) TODO: Validate if the drift value has to be within defined value @param test: KVM test object. @param params: Dictionary with test parameters. @param env: Dictionary with the test environment. """ # Checking the main vm is alive vm = env.get_vm(params["main_vm"]) vm.verify_alive() timeout = int(params.get("login_timeout", 360)) session = vm.wait_for_login(timeout=timeout) # Collect test parameters login_timeout = float(params.get("login_timeout", 240)) host_load_command = params.get("host_load_command") host_load_kill_command = params.get("host_load_kill_command") time_command = params.get("time_command") time_filter_re = params.get("time_filter_re") time_format = params.get("time_format") # Intialize the variables itr = 0 num = 2 host_load_sessions = [] sessions = [session] prev_time = [] curr_time = [] timedrift = [] totaldrift = [] vmnames =["vm1"] # Run some load on the host logging.info("Starting load on host.") host_load_sessions.append(aexpect.run_bg(host_load_command, output_func=logging.debug, output_prefix="host load ", timeout=0.5)) # Boot the VMs try: while num <= int(params.get("max_vms")): # Clone vm according to the first one vm_name = "vm%d" % num vmnames.append(vm_name) vm_params = vm.params.copy() curr_vm = vm.clone(vm_name, vm_params) env.register_vm(vm_name, curr_vm) virt_env_process.preprocess_vm(test, vm_params, env, vm_name) params["vms"] += " " + vm_name sessions.append(curr_vm.wait_for_login(timeout=login_timeout)) logging.info("Guest #%d booted up successfully", num) # Check whether all previous shell sessions are responsive error.context("checking responsiveness of the booted guest") for se in sessions: se.cmd(params.get("alive_test_cmd")) num += 1 while itr <= int(params.get("max_itrs")): for vmid,se in enumerate(sessions): # Get the respective vm object vmname = "vm%d" % (vmid +1) vm = env.get_vm(vmname) # Run current iteration logging.info("Rebooting:vm%d iteration %d " % ((vmid + 1), itr)) se = vm.reboot(se ,timeout=timeout) # Remember the current changed session sessions[vmid] = se error.context("checking responsiveness of guest") se.cmd(params.get("alive_test_cmd")) if itr == 0: (ht0, gt0) = virt_test_utils.get_time(se, time_command, time_filter_re, time_format) prev_time.append((ht0, gt0)) else: (ht1, gt1) = virt_test_utils.get_time(se, time_command, time_filter_re, time_format) curr_time.append((ht1, gt1)) if itr != 0: for i in range(int(params.get("max_vms"))): hdelta = curr_time[i][0] - prev_time[i][0] gdelta = curr_time[i][1] - prev_time[i][1] drift = format( 100.0 * (hdelta - gdelta) / hdelta, ".2f" ) timedrift.append(drift) totaldrift.append(timedrift) prev_time = curr_time timedrift = [] curr_time = [] # Wait for some time before next iteration time.sleep(30) itr += 1 logging.info("The time drift values for all VM sessions/iterations") logging.info("VM-Name:%s" % vmnames) for idx,value in enumerate(totaldrift): logging.info("itr-%2d:%s" % (idx+1,value)) finally: for se in sessions: # Closing all the sessions. se.close() logging.info("killing load on host.") host_load_sessions.append(aexpect.run_bg(host_load_kill_command, output_func=logging.debug, output_prefix="host load kill", timeout=0.5))