def run(test, params, env): """ Check time offset after hotplug a vcpu. 1) sync host time with ntpserver 2) boot guest with '-rtc base=utc,clock=host,driftfix=slew' 3) stop auto sync service in guest (rhel7 only) 4) sync guest system time with ntpserver 5) hotplug a vcpu by qmp command 6) query guest time offset with ntpserver for several times :param test: QEMU test object. :param params: Dictionary with test parameters. :param env: Dictionary with the test environment. """ os_type = params["os_type"] ntp_cmd = params["ntp_cmd"] ntp_host_cmd = params.get("ntp_host_cmd", ntp_cmd) error_context.context("Sync host system time with ntpserver", logging.info) process.system(ntp_host_cmd, shell=True) vm = env.get_vm(params["main_vm"]) if params["os_type"] == 'windows': utils_time.sync_timezone_win(vm) session = vm.wait_for_login() ntp_query_cmd = params.get("ntp_query_cmd", "") query_times = int(params.get("query_times", "4")) query_internal = float(params.get("query_internal", "600")) drift_threshold = float(params.get("drift_threshold", "3")) error_context.context("Sync time from guest to ntpserver", logging.info) if os_type == "windows": w32time_conf_cmd = params["w32time_conf_cmd"] session.cmd(w32time_conf_cmd) utils_test.start_windows_service(session, "w32time") session.cmd(ntp_cmd) error_context.context("Hotplug a vcpu to guest", logging.info) if int(params["smp"]) < int(params["vcpus_maxcpus"]): vm.hotplug_vcpu_device(params["vcpu_devices"]) time.sleep(1) else: test.error( "Invalid operation, valid index range 0:%d, used range 0:%d" % (int(params["vcpus_maxcpus"]) - 1, int(params["smp"]) - 1)) error_context.context("Check time offset via ntp server", logging.info) for query in range(query_times): output = session.cmd_output(ntp_query_cmd) try: offset = re.findall(r"([+-]*\d+\.\d+)[s sec]", output, re.M)[-1] except IndexError: test.error("Failed to get time offset") if float(offset) >= drift_threshold: test.fail("Uacceptable offset '%s', " % offset + "threshold '%s'" % drift_threshold) time.sleep(query_internal) session.close()
def pre_test(self): """ TODO: step 1: setup private bridge network environment; step 2: sync host time from ntp server; step 3: verify system time drift between host and guest; step 4: verify guest clock source if linux guest; """ self.setup_private_network() self.sync_host_time() vm = self.get_vm(create=True) if self.params["os_type"] == 'windows': utils_time.sync_timezone_win(vm) session = self.get_session(vm) self.check_dirft_before_adjust_time(session) if self.params.get("read_clock_source_cmd"): self.verify_clock_source(session)
def run(test, params, env): """ Timer device boot guest: 1) Check host clock's sync status with chronyd 2) Add some load on host (Optional) 3) Boot the guest with specific clock source 4) Check the clock source currently used on guest 5) Do some file operation on guest (Optional) 6) Check the system time on guest and host (Optional) 7) Check the hardware time on guest (linux only) 8) Sleep period of time before reboot (Optional) 9) Reboot guest (Optional) 10) Check the system time on guest and host (Optional) 11) Check the hardware time on guest (Optional) 12) Restore guest's clock source :param test: QEMU test object. :param params: Dictionary with test parameters. :param env: Dictionary with the test environment. """ def get_hwtime(session): """ Get guest's hardware clock. :param session: VM session. """ hwclock_time_command = params.get("hwclock_time_command", "hwclock -u") hwclock_time_filter_re = params.get("hwclock_time_filter_re", r"(\d+-\d+-\d+ \d+:\d+:\d+)") hwclock_time_format = params.get("hwclock_time_format", "%Y-%m-%d %H:%M:%S") output = session.cmd_output_safe(hwclock_time_command) try: str_time = re.findall(hwclock_time_filter_re, output)[0] guest_time = time.mktime( time.strptime(str_time, hwclock_time_format)) except Exception as err: test.log.debug("(time_format, time_string): (%s, %s)", hwclock_time_format, str_time) raise err return guest_time def verify_timedrift(session, is_hardware=False): """ Verify timedrift between host and guest. :param session: VM session. :param is_hardware: if need to verify guest's hardware time. """ # Command to run to get the current time time_command = params["time_command"] # Filter which should match a string to be passed to time.strptime() time_filter_re = params["time_filter_re"] # Time format for time.strptime() time_format = params["time_format"] timerdevice_drift_threshold = float( params.get("timerdevice_drift_threshold", 3)) time_type = "system" if not is_hardware else "harware" error_context.context("Check the %s time on guest" % time_type, test.log.info) host_time, guest_time = utils_test.get_time(session, time_command, time_filter_re, time_format) if is_hardware: guest_time = get_hwtime(session) drift = abs(float(host_time) - float(guest_time)) if drift > timerdevice_drift_threshold: test.fail("The guest's %s time is different with" " host's system time. Host time: '%s', guest time:" " '%s'" % (time_type, host_time, guest_time)) def get_current_clksrc(session): cmd = "cat /sys/devices/system/clocksource/" cmd += "clocksource0/current_clocksource" current_clksrc = session.cmd_output_safe(cmd) if "kvm-clock" in current_clksrc: return "kvm-clock" elif "tsc" in current_clksrc: return "tsc" elif "timebase" in current_clksrc: return "timebase" elif "acpi_pm" in current_clksrc: return "acpi_pm" return current_clksrc def update_clksrc(session, clksrc): """ Update guest's clocksource, this func can work when not login into guest with ssh. :param session: VM session. :param clksrc: expected guest's clocksource. """ avail_cmd = "cat /sys/devices/system/clocksource/clocksource0/" avail_cmd += "available_clocksource" avail_clksrc = session.cmd_output_safe(avail_cmd) if clksrc in avail_clksrc: clksrc_cmd = "echo %s > /sys/devices/system/clocksource/" % clksrc clksrc_cmd += "clocksource0/current_clocksource" status, output = session.cmd_status_output(clksrc_cmd) if status: test.fail( "fail to update guest's clocksource to %s," "details: %s" % clksrc, output) else: test.error("please check the clocksource you want to set, " "it's not supported by current guest, current " "available clocksources: %s" % avail_clksrc) error_context.context("sync host time with NTP server", test.log.info) clock_sync_command = params["clock_sync_command"] process.system(clock_sync_command, shell=True) timerdevice_host_load_cmd = params.get("timerdevice_host_load_cmd") if timerdevice_host_load_cmd: error_context.context("Add some load on host", test.log.info) host_cpu_cnt_cmd = params["host_cpu_cnt_cmd"] host_cpu_cnt = int( process.system_output(host_cpu_cnt_cmd, shell=True).strip()) if params["os_type"] == "linux": timerdevice_host_load_cmd = timerdevice_host_load_cmd % host_cpu_cnt process.system(timerdevice_host_load_cmd, shell=True, ignore_bg_processes=True) else: timerdevice_host_load_cmd = timerdevice_host_load_cmd % int( host_cpu_cnt / 2) stress_bg = utils_test.HostStress( "stress", params, stress_args=timerdevice_host_load_cmd) stress_bg.load_stress_tool() host_load_stop_cmd = params.get("timerdevice_host_load_stop_cmd", "pkill -f 'do X=1'") funcatexit.register(env, params["type"], _system, host_load_stop_cmd) params["start_vm"] = "yes" env_process.preprocess_vm(test, params, env, params.get("main_vm")) vm = env.get_vm(params["main_vm"]) vm.verify_alive() error_context.context("Sync guest timezone before test", test.log.info) timeout = int(params.get("login_timeout", 360)) if params["os_type"] == 'linux': utils_time.sync_timezone_linux(vm, timeout) else: utils_time.sync_timezone_win(vm, timeout) session = vm.wait_for_serial_login(timeout=timeout) timerdevice_clksource = params.get("timerdevice_clksource") need_restore_clksrc = False if timerdevice_clksource: origin_clksrc = get_current_clksrc(session) test.log.info("guest is booted with %s", origin_clksrc) if timerdevice_clksource != origin_clksrc: update_clksrc(session, timerdevice_clksource) need_restore_clksrc = True error_context.context("check timedrift between guest and host.", test.log.info) verify_timedrift(session) if params["os_type"] == "linux": verify_timedrift(session, is_hardware=True) repeat_nums = params.get_numeric("repeat_nums") if repeat_nums: sleep_time = params["sleep_time"] for index in range(repeat_nums): time.sleep(int(sleep_time)) verify_timedrift(session) if params["os_type"] == "linux": verify_timedrift(session, is_hardware=True) if params.get("timerdevice_reboot_test") == "yes": sleep_time = params.get("timerdevice_sleep_time") if sleep_time: error_context.context("Sleep '%s' secs before reboot" % sleep_time, test.log.info) sleep_time = int(sleep_time) time.sleep(sleep_time) error_context.context( "Check timedrift between guest and host " "after reboot.", test.log.info) vm.reboot(timeout=timeout, serial=True) verify_timedrift(session) if params["os_type"] == "linux": verify_timedrift(session, is_hardware=True) if need_restore_clksrc: update_clksrc(session, origin_clksrc) session.close()
def run(test, params, env): """ Time clock offset check when guest crash/bsod test: 1) boot guest with '-rtc base=utc,clock=host,driftfix=slew'; 2) sync host system time with ntp server; 3) inject nmi to guest/ make linux kernel crash; 4) sleep long time, then reset vm via system_reset; 5) query clock offset from ntp server; :param test: QEMU test object. :param params: Dictionary with test parameters. :param env: Dictionary with the test environment. """ ntp_cmd = params["ntp_cmd"] ntp_query_cmd = params["ntp_query_cmd"] nmi_cmd = params.get("nmi_cmd", "inject-nmi") sleep_time = float(params.get("sleep_time", 1800)) deviation = float(params.get("deviation", 5)) os_type = params["os_type"] ntp_host_cmd = params.get("ntp_host_cmd", ntp_cmd) error_context.context("sync host time with ntp server", logging.info) process.system(ntp_host_cmd, shell=True) error_context.context("start guest", logging.info) params["start_vm"] = "yes" preprocess(test, params, env) vm = env.get_vm(params["main_vm"]) vm.verify_alive() if params["os_type"] == 'windows': utils_time.sync_timezone_win(vm) timeout = int(params.get("login_timeout", 360)) session = vm.wait_for_login(timeout=timeout) error_context.context("sync time in guest", logging.info) if os_type == "windows": w32time_conf_cmd = params["w32time_conf_cmd"] session.cmd(w32time_conf_cmd) utils_test.start_windows_service(session, "w32time") session.cmd(ntp_cmd) error_context.context("inject nmi interrupt in vm", logging.info) target, cmd = re.split(r"\s*:\s*", nmi_cmd) if target == "monitor": vm.monitor.send_args_cmd(cmd) else: session.sendline(cmd) try: session.cmd("dir") except Exception: pass else: test.fail("Guest OS still alive ...") error_context.context("sleep %s seconds" % sleep_time, logging.info) time.sleep(sleep_time) # Autotest parses serial output and could raise VMDeadKernelCrash # we generated using sysrq. Ignore one "BUG:" line vm.resume() try: session = vm.reboot(method="system_reset") except VMDeadKernelCrashError as details: details = str(details) if (re.findall(r"Trigger a crash\s.*BUG:", details, re.M) and details.count("BUG:") != 1): test.fail("Got multiple kernel crashes. Please " "note that one of them was " "intentionally generated by sysrq in " "this test.\n%s" % details) end_time = time.time() + timeout while time.time() < end_time: try: session = vm.wait_for_login(timeout=timeout) except VMDeadKernelCrashError as details: details = str(details) if (re.findall(r"Trigger a crash\s.*BUG:", details, re.M) and details.count("BUG:") != 1): test.fail("Got multiple kernel crashes. " "Please note that one of them was " "intentionally generated by sysrq " "in this test.\n%s" % details) else: break error_context.context("check time offset via ntp", logging.info) output = session.cmd_output(ntp_query_cmd) try: offset = re.findall(r"[+-]?(\d+\.\d+)", output, re.M)[-1] except IndexError: offset = 0.0 if float(offset) > deviation: test.fail("Unacceptable offset '%s', " % offset + "deviation '%s'" % deviation)
def run(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: QEMU 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() boot_option_added = params.get("boot_option_added") boot_option_removed = params.get("boot_option_removed") if boot_option_added or boot_option_removed: utils_test.update_boot_option(vm, args_removed=boot_option_removed, args_added=boot_option_added) if params["os_type"] == 'windows': utils_time.sync_timezone_win(vm) session = vm.wait_for_login(timeout=login_timeout) # Collect test parameters: # Command to run to get the current time time_command = params["time_command"] # Filter which should match a string to be passed to time.strptime() time_filter_re = params["time_filter_re"] # Time format for time.strptime() time_format = params["time_format"] rtc_clock = params.get("rtc_clock", "host") 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)) stop_with_signal = params.get("stop_with_signal") == "yes" # Get guest's pid. pid = vm.get_pid() try: # Get initial time # (ht stands for host time, gt stands for guest time) (ht0, gt0) = utils_test.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_) = utils_test.get_time(session, time_command, time_filter_re, time_format) # Run current iteration test.log.info("Stop %s second: iteration %d of %d...", stop_time, (i + 1), stop_iterations) if stop_with_signal: test.log.debug("Stop guest") os.kill(pid, signal.SIGSTOP) time.sleep(stop_time) test.log.debug("Continue guest") os.kill(pid, signal.SIGCONT) else: vm.pause() time.sleep(stop_time) vm.resume() # Sleep for a while to wait the interrupt to be reinjected test.log.info("Waiting for the interrupt to be reinjected ...") time.sleep(sleep_time) # Get time after current iteration (ht1_, gt1_) = utils_test.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) # kvm guests CLOCK_MONOTONIC not count when guest is paused, # so drift need to subtract stop_time. if not stop_with_signal: drift = abs(drift - stop_time) if params.get("os_type") == "windows" and rtc_clock == "host": drift = abs(host_delta - guest_delta) test.log.info("Host duration (iteration %d): %.2f", (i + 1), host_delta) test.log.info("Guest duration (iteration %d): %.2f", (i + 1), guest_delta) test.log.info("Drift at iteration %d: %.2f seconds", (i + 1), drift) # Fail if necessary if drift > drift_threshold_single: test.fail("Time drift too large at iteration %d: " "%.2f seconds" % (i + 1, drift)) # Get final time (ht1, gt1) = utils_test.get_time(session, time_command, time_filter_re, time_format) finally: if session: session.close() # remove flags add for this test. if boot_option_added or boot_option_removed: utils_test.update_boot_option(vm, args_removed=boot_option_added, args_added=boot_option_removed) # Report results host_delta = ht1 - ht0 guest_delta = gt1 - gt0 drift = abs(host_delta - guest_delta) # kvm guests CLOCK_MONOTONIC not count when guest is paused, # so drift need to subtract stop_time. if not stop_with_signal: drift = abs(drift - stop_time) if params.get("os_type") == "windows" and rtc_clock == "host": drift = abs(host_delta - guest_delta) test.log.info("Host duration (%d stops): %.2f", stop_iterations, host_delta) test.log.info("Guest duration (%d stops): %.2f", stop_iterations, guest_delta) test.log.info("Drift after %d stops: %.2f seconds", stop_iterations, drift) # Fail if necessary if drift > drift_threshold: test.fail("Time drift too large after %d stops: " "%.2f seconds" % (stop_iterations, drift))
def run(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: QEMU 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() boot_option_added = params.get("boot_option_added") boot_option_removed = params.get("boot_option_removed") if boot_option_added or boot_option_removed: utils_test.update_boot_option(vm, args_removed=boot_option_removed, args_added=boot_option_added) if params.get("os_type") == 'linux': utils_time.sync_timezone_linux(vm) else: utils_time.sync_timezone_win(vm) 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["time_command"] # Filter which should match a string to be passed to time.strptime() time_filter_re = params["time_filter_re"] # Time format for time.strptime() time_format = params["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) = utils_test.get_time(session, time_command, time_filter_re, time_format) # Reboot for i in range(reboot_iterations): # Get time before current iteration (ht0_, gt0_) = utils_test.get_time(session, time_command, time_filter_re, time_format) # Run current iteration test.log.info("Rebooting: iteration %d of %d...", (i + 1), reboot_iterations) session = vm.reboot(session, timeout=timeout) # Get time after current iteration (ht1_, gt1_) = utils_test.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) test.log.info("Host duration (iteration %d): %.2f", (i + 1), host_delta) test.log.info("Guest duration (iteration %d): %.2f", (i + 1), guest_delta) test.log.info("Drift at iteration %d: %.2f seconds", (i + 1), drift) # Fail if necessary if drift > drift_threshold_single: test.fail("Time drift too large at iteration %d: " "%.2f seconds" % (i + 1, drift)) # Get final time (ht1, gt1) = utils_test.get_time(session, time_command, time_filter_re, time_format) finally: if session: session.close() # remove flags add for this test. if boot_option_added or boot_option_removed: utils_test.update_boot_option(vm, args_removed=boot_option_added, args_added=boot_option_removed) # Report results host_delta = ht1 - ht0 guest_delta = gt1 - gt0 drift = abs(host_delta - guest_delta) test.log.info("Host duration (%d reboots): %.2f", reboot_iterations, host_delta) test.log.info("Guest duration (%d reboots): %.2f", reboot_iterations, guest_delta) test.log.info("Drift after %d reboots: %.2f seconds", reboot_iterations, drift) # Fail if necessary if drift > drift_threshold: test.fail("Time drift too large after %d reboots: " "%.2f seconds" % (reboot_iterations, drift))
def run(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: QEMU 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 = decode_to_text( process.system_output("ps -L --pid=%s -o lwp=" % pid, verbose=False, ignore_status=True)).split() prev_masks = {} for tid in tids: prev_mask = decode_to_text( process.system_output("taskset -p %s" % tid, verbose=False)).split()[-1] prev_masks[tid] = prev_mask process.system("taskset -p %s %s" % (mask, tid), verbose=False) children = decode_to_text( process.system_output("ps --ppid=%s -o pid=" % pid, verbose=False, ignore_status=True)).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(): process.system("taskset -p %s %s" % (mask, tid), verbose=False, ignore_status=True) vm = env.get_vm(params["main_vm"]) vm.verify_alive() boot_option_added = params.get("boot_option_added") boot_option_removed = params.get("boot_option_removed") if boot_option_added or boot_option_removed: utils_test.update_boot_option(vm, args_removed=boot_option_removed, args_added=boot_option_added) if params["os_type"] == "windows": utils_time.sync_timezone_win(vm) timeout = int(params.get("login_timeout", 360)) session = vm.wait_for_serial_login(timeout=timeout) # Collect test parameters: # Command to run to get the current time time_command = params["time_command"] # Filter which should match a string to be passed to time.strptime() time_filter_re = params["time_filter_re"] # Time format for time.strptime() time_format = params["time_format"] guest_load_command = params["guest_load_command"] guest_load_stop_command = params["guest_load_stop_command"] host_load_command = params["host_load_command"] guest_load_instances = params["guest_load_instances"] host_load_instances = params["host_load_instances"] if not guest_load_instances and not host_load_instances: host_load_instances = cpu.total_cpus_count() guest_load_instances = vm.get_cpu_count() else: host_load_instances = int(host_load_instances) guest_load_instances = int(guest_load_instances) # CPU affinity mask for taskset cpu_mask = int(params.get("cpu_mask", "0xFF"), 16) 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")) test_duration = float(params.get("test_duration", "60")) interval_gettime = float(params.get("interval_gettime", "20")) 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.wait_for_login(timeout=timeout) # 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) = utils_test.get_time(session, time_command, time_filter_re, time_format) # Run some load on the guest if params["os_type"] == "linux": for i, load_session in enumerate(guest_load_sessions): load_session.sendline(guest_load_command % i) else: 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): load_cmd = aexpect.run_bg(host_load_command, output_func=logging.debug, output_prefix="(host load %d) " % i, timeout=0.5) host_load_sessions.append(load_cmd) # Set the CPU affinity of the load process pid = load_cmd.get_pid() set_cpu_affinity(pid, cpu_mask << i) # Sleep for a while (during load) logging.info("Sleeping for %s seconds...", load_duration) time.sleep(load_duration) start_time = time.time() while (time.time() - start_time) < test_duration: # Get time delta after load (ht1, gt1) = utils_test.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) time.sleep(interval_gettime) 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) = utils_test.get_time(session, time_command, time_filter_re, time_format) finally: session.close() # remove flags add for this test. if boot_option_added or boot_option_removed: utils_test.update_boot_option(vm, args_removed=boot_option_added, args_added=boot_option_removed) # 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: test.fail("Time drift too large: %.2f%%" % drift) if abs(drift_total) > drift_threshold_after_rest: test.fail("Time drift too large after rest period: %.2f%%" % drift_total)
def run(test, params, env): """ Check guest time monotonicity during migration: 1) Log into a guest. 2) Take time from guest. 3) Migrate the guest. 4) Keep guest running for a period after migration, and record the time log. 5) Analyse log if it is exist. :param test: QEMU test object. :param params: Dictionary with test parameters. :param env: Dictionary with the test environment. """ def get_time(cmd, test_time, session): if os.path.isfile(host_path): os.remove(host_path) lasttv = "0" cmd_timeout = int(params.get("cmd_timeout")) start_time = time.time() while (time.time() - start_time) < test_time: tv = session.cmd_output(cmd, timeout=cmd_timeout) if params.get("os_type") == 'windows': list = re.split('[:]', tv) tv = str( int(list[0]) * 3600 + int(list[1]) * 60 + float(list[2])) if float(tv) < float(lasttv): p_tv = "time value = " + tv + "\n" p_lasttv = "last time value = " + lasttv + "\n" with open(host_path, 'a') as time_log: time_log.write("time went backwards:\n" + p_tv + p_lasttv) lasttv = tv time.sleep(0.1) vm = env.get_vm(params["main_vm"]) vm.verify_alive() boot_option_added = params.get("boot_option_added") boot_option_removed = params.get("boot_option_removed") if boot_option_added or boot_option_removed: utils_test.update_boot_option(vm, args_removed=boot_option_removed, args_added=boot_option_added) if params["os_type"] == 'windows': utils_time.sync_timezone_win(vm) timeout = int(params.get("login_timeout", 360)) session1 = vm.wait_for_login(timeout=timeout) host_path = params.get("host_path") cmd = params.get("cmd_get_time") test_time = int(params.get("time_linger", "60")) try: # take time test.log.info("Start take guest time") bg = utils_misc.InterruptedThread(get_time, (cmd, test_time, session1)) bg.start() # migration test.log.info("Start migration") vm.migrate() # log in test.log.info("Logging in after migration...") session2 = vm.wait_for_login(timeout=timeout) if not session2: test.fail("Could not log in after migration") test.log.info("Logged in after migration") # linger a while time.sleep(test_time) # analyse the result if os.path.isfile(host_path): log_dir = os.path.join(test.outputdir, "timedrift-monotonicity-result.txt") shutil.copyfile(host_path, log_dir) with open(host_path, 'r') as myfile: for line in myfile: if "time went backwards" in line: test.fail("Failed Time Monotonicity testing, " "Please check log %s" % host_path) finally: session1.close() # remove flags add for this test. if boot_option_added or boot_option_removed: utils_test.update_boot_option(vm, args_removed=boot_option_added, args_added=boot_option_removed)
def run(test, params, env): """ Timer device boot guest: 1) Check host clock's sync status with chronyd 2) Add some load on host (Optional) 3) Boot the guest with specific clock source 4) Check the clock source currently used on guest 5) Do some file operation on guest (Optional) 6) Check the system time on guest and host (Optional) 7) Check the hardware time on guest (linux only) 8) Sleep period of time before reboot (Optional) 9) Reboot guest (Optional) 10) Check the system time on guest and host (Optional) 11) Check the hardware time on guest (Optional) 12) Restore guest's clock source :param test: QEMU test object. :param params: Dictionary with test parameters. :param env: Dictionary with the test environment. """ def get_hwtime(session): """ Get guest's hardware clock. :param session: VM session. """ hwclock_time_command = params.get("hwclock_time_command", "hwclock -u") hwclock_time_filter_re = params.get("hwclock_time_filter_re", r"(\d+-\d+-\d+ \d+:\d+:\d+)") hwclock_time_format = params.get("hwclock_time_format", "%Y-%m-%d %H:%M:%S") output = session.cmd_output_safe(hwclock_time_command) try: str_time = re.findall(hwclock_time_filter_re, output)[0] guest_time = time.mktime(time.strptime(str_time, hwclock_time_format)) except Exception as err: logging.debug( "(time_format, time_string): (%s, %s)", hwclock_time_format, str_time) raise err return guest_time def verify_timedrift(session, is_hardware=False): """ Verify timedrift between host and guest. :param session: VM session. :param is_hardware: if need to verify guest's hardware time. """ # Command to run to get the current time time_command = params["time_command"] # Filter which should match a string to be passed to time.strptime() time_filter_re = params["time_filter_re"] # Time format for time.strptime() time_format = params["time_format"] timerdevice_drift_threshold = float(params.get( "timerdevice_drift_threshold", 3)) time_type = "system" if not is_hardware else "harware" error_context.context("Check the %s time on guest" % time_type, logging.info) host_time, guest_time = utils_test.get_time(session, time_command, time_filter_re, time_format) if is_hardware: guest_time = get_hwtime(session) drift = abs(float(host_time) - float(guest_time)) if drift > timerdevice_drift_threshold: test.fail("The guest's %s time is different with" " host's system time. Host time: '%s', guest time:" " '%s'" % (time_type, host_time, guest_time)) def get_current_clksrc(session): cmd = "cat /sys/devices/system/clocksource/" cmd += "clocksource0/current_clocksource" current_clksrc = session.cmd_output_safe(cmd) if "kvm-clock" in current_clksrc: return "kvm-clock" elif "tsc" in current_clksrc: return "tsc" elif "timebase" in current_clksrc: return "timebase" elif "acpi_pm" in current_clksrc: return "acpi_pm" return current_clksrc def update_clksrc(session, clksrc): """ Update guest's clocksource, this func can work when not login into guest with ssh. :param session: VM session. :param clksrc: expected guest's clocksource. """ avail_cmd = "cat /sys/devices/system/clocksource/clocksource0/" avail_cmd += "available_clocksource" avail_clksrc = session.cmd_output_safe(avail_cmd) if clksrc in avail_clksrc: clksrc_cmd = "echo %s > /sys/devices/system/clocksource/" % clksrc clksrc_cmd += "clocksource0/current_clocksource" status, output = session.cmd_status_output(clksrc_cmd) if status: test.fail("fail to update guest's clocksource to %s," "details: %s" % clksrc, output) else: test.error("please check the clocksource you want to set, " "it's not supported by current guest, current " "available clocksources: %s" % avail_clksrc) error_context.context("sync host time with NTP server", logging.info) clock_sync_command = params["clock_sync_command"] process.system(clock_sync_command, shell=True) timerdevice_host_load_cmd = params.get("timerdevice_host_load_cmd") if timerdevice_host_load_cmd: error_context.context("Add some load on host", logging.info) process.system(timerdevice_host_load_cmd, shell=True, ignore_bg_processes=True) host_load_stop_cmd = params.get("timerdevice_host_load_stop_cmd", "pkill -f 'do X=1'") funcatexit.register(env, params["type"], _system, host_load_stop_cmd) vm = env.get_vm(params["main_vm"]) vm.verify_alive() error_context.context("Sync guest timezone before test", logging.info) if params["os_type"] == 'linux': utils_time.sync_timezone_linux(vm) else: utils_time.sync_timezone_win(vm) timeout = int(params.get("login_timeout", 360)) session = vm.wait_for_serial_login(timeout=timeout) timerdevice_clksource = params.get("timerdevice_clksource") need_restore_clksrc = False if timerdevice_clksource: origin_clksrc = get_current_clksrc(session) logging.info("guest is booted with %s" % origin_clksrc) if timerdevice_clksource != origin_clksrc: update_clksrc(session, timerdevice_clksource) need_restore_clksrc = True error_context.context("check timedrift between guest and host.", logging.info) verify_timedrift(session) if params["os_type"] == "linux": verify_timedrift(session, is_hardware=True) if params.get("timerdevice_reboot_test") == "yes": sleep_time = params.get("timerdevice_sleep_time") if sleep_time: error_context.context("Sleep '%s' secs before reboot" % sleep_time, logging.info) sleep_time = int(sleep_time) time.sleep(sleep_time) error_context.context("Check timedrift between guest and host " "after reboot.", logging.info) vm.reboot(timeout=timeout, serial=True) verify_timedrift(session) if params["os_type"] == "linux": verify_timedrift(session, is_hardware=True) if need_restore_clksrc: update_clksrc(session, origin_clksrc) session.close()
def run(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: QEMU 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() boot_option_added = params.get("boot_option_added") boot_option_removed = params.get("boot_option_removed") if boot_option_added or boot_option_removed: utils_test.update_boot_option(vm, args_removed=boot_option_removed, args_added=boot_option_added) if params.get("os_type") == 'linux': utils_time.sync_timezone_linux(vm) else: utils_time.sync_timezone_win(vm) 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["time_command"] # Filter which should match a string to be passed to time.strptime() time_filter_re = params["time_filter_re"] # Time format for time.strptime() time_format = params["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) = utils_test.get_time(session, time_command, time_filter_re, time_format) # Reboot for i in range(reboot_iterations): # Get time before current iteration (ht0_, gt0_) = utils_test.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, timeout=timeout) # Get time after current iteration (ht1_, gt1_) = utils_test.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: test.fail("Time drift too large at iteration %d: " "%.2f seconds" % (i + 1, drift)) # Get final time (ht1, gt1) = utils_test.get_time(session, time_command, time_filter_re, time_format) finally: if session: session.close() # remove flags add for this test. if boot_option_added or boot_option_removed: utils_test.update_boot_option(vm, args_removed=boot_option_added, args_added=boot_option_removed) # 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: test.fail("Time drift too large after %d reboots: " "%.2f seconds" % (reboot_iterations, drift))