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()
示例#2
0
 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)
示例#3
0
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)
示例#5
0
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))
示例#6
0
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))
示例#7
0
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)
示例#8
0
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)
示例#9
0
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()
示例#10
0
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))