[KVM-AUTOTEST,12/17] KVM test: add simple timedrift test (mainly for Windows)

Commit Message

Michael Goldish July 20, 2009, 3:07 p.m. UTC

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.

Signed-off-by: Michael Goldish <[e-mail]>
---
 client/tests/kvm/kvm.py       |    1 +
 client/tests/kvm/kvm_tests.py |  161 ++++++++++++++++++++++++++++++++++++++++-
 2 files changed, 160 insertions(+), 2 deletions(-)

Comments

Dor Laor July 21, 2009, 9:23 a.m. UTC | #1

On 07/20/2009 06:07 PM, Michael Goldish wrote:
> 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.
>
> Signed-off-by: Michael Goldish<[e-mail]>
> ---
>   client/tests/kvm/kvm.py       |    1 +
>   client/tests/kvm/kvm_tests.py |  161 ++++++++++++++++++++++++++++++++++++++++-
>   2 files changed, 160 insertions(+), 2 deletions(-)
>
> diff --git a/client/tests/kvm/kvm.py b/client/tests/kvm/kvm.py
> index b18b643..070e463 100644
> --- a/client/tests/kvm/kvm.py
> +++ b/client/tests/kvm/kvm.py
> @@ -55,6 +55,7 @@ class kvm(test.test):
>                   "kvm_install":  test_routine("kvm_install", "run_kvm_install"),
>                   "linux_s3":     test_routine("kvm_tests", "run_linux_s3"),
>                   "stress_boot":  test_routine("kvm_tests", "run_stress_boot"),
> +                "timedrift":    test_routine("kvm_tests", "run_timedrift"),
>                   }
>
>           # Make it possible to import modules from the test's bindir
> diff --git a/client/tests/kvm/kvm_tests.py b/client/tests/kvm/kvm_tests.py
> index 5991aed..ca0b8c0 100644
> --- a/client/tests/kvm/kvm_tests.py
> +++ b/client/tests/kvm/kvm_tests.py
> @@ -1,4 +1,4 @@
> -import time, os, logging
> +import time, os, logging, re, commands
>   from autotest_lib.client.common_lib import utils, error
>   import kvm_utils, kvm_subprocess, ppm_utils, scan_results
>
> @@ -529,7 +529,6 @@ def run_stress_boot(tests, params, env):
>       """
>       # boot the first vm
>       vm = kvm_utils.env_get_vm(env, params.get("main_vm"))
> -
>       if not vm:
>           raise error.TestError("VM object not found in environment")
>       if not vm.is_alive():
> @@ -586,3 +585,161 @@ def run_stress_boot(tests, params, env):
>           for se in sessions:
>               se.close()
>           logging.info("Total number booted: %d" % (num -1))
> +
> +
> +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.
> +    """
> +    vm = kvm_utils.env_get_vm(env, params.get("main_vm"))
> +    if not vm:
> +        raise error.TestError("VM object not found in environment")
> +    if not vm.is_alive():
> +        raise error.TestError("VM seems to be dead; Test requires a living VM")
> +
> +    logging.info("Waiting for guest to be up...")
> +
> +    session = kvm_utils.wait_for(vm.ssh_login, 240, 0, 2)
> +    if not session:
> +        raise error.TestFail("Could not log into guest")
> +
> +    logging.info("Logged in")
> +
> +    # 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 = []
> +
> +    # Remember the VM's previous CPU affinity
> +    prev_cpu_mask = commands.getoutput("taskset -p %s" % vm.get_pid())
> +    prev_cpu_mask = prev_cpu_mask.split()[-1]
> +    # Set the VM's CPU affinity
> +    commands.getoutput("taskset -p %s %s" % (cpu_mask, vm.get_pid()))


Need to handle guest smp case where we want to pin the guest to several 
cpus.

Cheers for the test!


> +
> +    try:
> +        # Get time before load
> +        host_time_0 = time.time()
> +        session.sendline(time_command)
> +        (match, s) = session.read_up_to_prompt()
> +        s = re.findall(time_filter_re, s)[0]
> +        guest_time_0 = time.mktime(time.strptime(s, time_format))
> +
> +        # Run some load on the guest
> +        logging.info("Starting load on guest...")
> +        for i in range(guest_load_instances):
> +            load_session = vm.ssh_login()
> +            if not load_session:
> +                raise error.TestFail("Could not log into guest")
> +            load_session.set_output_prefix("(guest load %d) " % i)
> +            load_session.set_output_func(logging.debug)
> +            load_session.sendline(guest_load_command)
> +            guest_load_sessions.append(load_session)
> +
> +        # Run some load on the host
> +        logging.info("Starting load on host...")
> +        for i in range(host_load_instances):
> +            host_load_sessions.append(
> +                kvm_subprocess.run_bg(host_load_command,
> +                                      output_func=logging.debug,
> +                                      output_prefix="(host load %d) " % i,
> +                                      timeout=0.5))
> +            # Set the CPU affinity of the shell running the load process
> +            pid = host_load_sessions[-1].get_shell_pid()
> +            commands.getoutput("taskset -p %s %s" % (cpu_mask, pid))
> +            # Try setting the CPU affinity of the load process itself
> +            pid = host_load_sessions[-1].get_pid()
> +            if pid:
> +                commands.getoutput("taskset -p %s %s" % (cpu_mask, pid))
> +
> +        # Sleep for a while (during load)
> +        logging.info("Sleeping for %s seconds..." % load_duration)
> +        time.sleep(load_duration)
> +
> +        # Get time delta after load
> +        host_time_1 = time.time()
> +        session.sendline(time_command)
> +        (match, s) = session.read_up_to_prompt()
> +        s = re.findall(time_filter_re, s)[0]
> +        guest_time_1 = time.mktime(time.strptime(s, time_format))
> +
> +        # Report results
> +        host_delta = host_time_1 - host_time_0
> +        guest_delta = guest_time_1 - guest_time_0
> +        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
> +        commands.getoutput("taskset -p %s %s" % (prev_cpu_mask, vm.get_pid()))
> +        # Stop the guest load
> +        if guest_load_stop_command:
> +            session.get_command_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
> +    host_time_2 = time.time()
> +    session.sendline(time_command)
> +    (match, s) = session.read_up_to_prompt()
> +    s = re.findall(time_filter_re, s)[0]
> +    guest_time_2 = time.mktime(time.strptime(s, time_format))
> +
> +    # Report results
> +    host_delta_total = host_time_2 - host_time_0
> +    guest_delta_total = guest_time_2 - guest_time_0
> +    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 drift>  drift_threshold:
> +        raise error.TestFail("Time drift too large: %.2f%%" % drift)
> +    if drift>  drift_threshold_after_rest:
> +        raise error.TestFail("Time drift too large after rest period: %.2f%%"
> +                             % drift_total)
> +
> +    session.close()

--
To unsubscribe from this list: send the line "unsubscribe kvm" in
the body of a message to [e-mail]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Michael Goldish July 21, 2009, 9:37 a.m. UTC | #2

----- "Dor Laor" <[e-mail]> wrote:

> On 07/20/2009 06:07 PM, Michael Goldish wrote:
> > 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.
> >
> > Signed-off-by: Michael Goldish<[e-mail]>
> > ---
> >   client/tests/kvm/kvm.py       |    1 +
> >   client/tests/kvm/kvm_tests.py |  161
> ++++++++++++++++++++++++++++++++++++++++-
> >   2 files changed, 160 insertions(+), 2 deletions(-)
> >
> > diff --git a/client/tests/kvm/kvm.py b/client/tests/kvm/kvm.py
> > index b18b643..070e463 100644
> > --- a/client/tests/kvm/kvm.py
> > +++ b/client/tests/kvm/kvm.py
> > @@ -55,6 +55,7 @@ class kvm(test.test):
> >                   "kvm_install":  test_routine("kvm_install",
> "run_kvm_install"),
> >                   "linux_s3":     test_routine("kvm_tests",
> "run_linux_s3"),
> >                   "stress_boot":  test_routine("kvm_tests",
> "run_stress_boot"),
> > +                "timedrift":    test_routine("kvm_tests",
> "run_timedrift"),
> >                   }
> >
> >           # Make it possible to import modules from the test's
> bindir
> > diff --git a/client/tests/kvm/kvm_tests.py
> b/client/tests/kvm/kvm_tests.py
> > index 5991aed..ca0b8c0 100644
> > --- a/client/tests/kvm/kvm_tests.py
> > +++ b/client/tests/kvm/kvm_tests.py
> > @@ -1,4 +1,4 @@
> > -import time, os, logging
> > +import time, os, logging, re, commands
> >   from autotest_lib.client.common_lib import utils, error
> >   import kvm_utils, kvm_subprocess, ppm_utils, scan_results
> >
> > @@ -529,7 +529,6 @@ def run_stress_boot(tests, params, env):
> >       """
> >       # boot the first vm
> >       vm = kvm_utils.env_get_vm(env, params.get("main_vm"))
> > -
> >       if not vm:
> >           raise error.TestError("VM object not found in
> environment")
> >       if not vm.is_alive():
> > @@ -586,3 +585,161 @@ def run_stress_boot(tests, params, env):
> >           for se in sessions:
> >               se.close()
> >           logging.info("Total number booted: %d" % (num -1))
> > +
> > +
> > +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.
> > +    """
> > +    vm = kvm_utils.env_get_vm(env, params.get("main_vm"))
> > +    if not vm:
> > +        raise error.TestError("VM object not found in
> environment")
> > +    if not vm.is_alive():
> > +        raise error.TestError("VM seems to be dead; Test requires a
> living VM")
> > +
> > +    logging.info("Waiting for guest to be up...")
> > +
> > +    session = kvm_utils.wait_for(vm.ssh_login, 240, 0, 2)
> > +    if not session:
> > +        raise error.TestFail("Could not log into guest")
> > +
> > +    logging.info("Logged in")
> > +
> > +    # 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 = []
> > +
> > +    # Remember the VM's previous CPU affinity
> > +    prev_cpu_mask = commands.getoutput("taskset -p %s" %
> vm.get_pid())
> > +    prev_cpu_mask = prev_cpu_mask.split()[-1]
> > +    # Set the VM's CPU affinity
> > +    commands.getoutput("taskset -p %s %s" % (cpu_mask,
> vm.get_pid()))
> 
> 
> Need to handle guest smp case where we want to pin the guest to
> several 
> cpus.
> 
> Cheers for the test!

cpu_mask is user-specified. If the user specifies 5, the VM will be
pinned to CPUs 1 and 3. In smp tests we can set cpu_mask appropriately.
Is this OK or were you referring to something else?

> > +
> > +    try:
> > +        # Get time before load
> > +        host_time_0 = time.time()
> > +        session.sendline(time_command)
> > +        (match, s) = session.read_up_to_prompt()
> > +        s = re.findall(time_filter_re, s)[0]
> > +        guest_time_0 = time.mktime(time.strptime(s, time_format))
> > +
> > +        # Run some load on the guest
> > +        logging.info("Starting load on guest...")
> > +        for i in range(guest_load_instances):
> > +            load_session = vm.ssh_login()
> > +            if not load_session:
> > +                raise error.TestFail("Could not log into guest")
> > +            load_session.set_output_prefix("(guest load %d) " % i)
> > +            load_session.set_output_func(logging.debug)
> > +            load_session.sendline(guest_load_command)
> > +            guest_load_sessions.append(load_session)
> > +
> > +        # Run some load on the host
> > +        logging.info("Starting load on host...")
> > +        for i in range(host_load_instances):
> > +            host_load_sessions.append(
> > +                kvm_subprocess.run_bg(host_load_command,
> > +                                      output_func=logging.debug,
> > +                                      output_prefix="(host load %d)
> " % i,
> > +                                      timeout=0.5))
> > +            # Set the CPU affinity of the shell running the load
> process
> > +            pid = host_load_sessions[-1].get_shell_pid()
> > +            commands.getoutput("taskset -p %s %s" % (cpu_mask,
> pid))
> > +            # Try setting the CPU affinity of the load process
> itself
> > +            pid = host_load_sessions[-1].get_pid()
> > +            if pid:
> > +                commands.getoutput("taskset -p %s %s" % (cpu_mask,
> pid))
> > +
> > +        # Sleep for a while (during load)
> > +        logging.info("Sleeping for %s seconds..." % load_duration)
> > +        time.sleep(load_duration)
> > +
> > +        # Get time delta after load
> > +        host_time_1 = time.time()
> > +        session.sendline(time_command)
> > +        (match, s) = session.read_up_to_prompt()
> > +        s = re.findall(time_filter_re, s)[0]
> > +        guest_time_1 = time.mktime(time.strptime(s, time_format))
> > +
> > +        # Report results
> > +        host_delta = host_time_1 - host_time_0
> > +        guest_delta = guest_time_1 - guest_time_0
> > +        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
> > +        commands.getoutput("taskset -p %s %s" % (prev_cpu_mask,
> vm.get_pid()))
> > +        # Stop the guest load
> > +        if guest_load_stop_command:
> > +            session.get_command_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
> > +    host_time_2 = time.time()
> > +    session.sendline(time_command)
> > +    (match, s) = session.read_up_to_prompt()
> > +    s = re.findall(time_filter_re, s)[0]
> > +    guest_time_2 = time.mktime(time.strptime(s, time_format))
> > +
> > +    # Report results
> > +    host_delta_total = host_time_2 - host_time_0
> > +    guest_delta_total = guest_time_2 - guest_time_0
> > +    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 drift>  drift_threshold:
> > +        raise error.TestFail("Time drift too large: %.2f%%" %
> drift)
> > +    if drift>  drift_threshold_after_rest:
> > +        raise error.TestFail("Time drift too large after rest
> period: %.2f%%"
> > +                             % drift_total)
> > +
> > +    session.close()
--
To unsubscribe from this list: send the line "unsubscribe kvm" in
the body of a message to [e-mail]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Dor Laor July 21, 2009, 9:42 a.m. UTC | #3

On 07/21/2009 12:37 PM, Michael Goldish wrote:
> ----- "Dor Laor"<[e-mail]>  wrote:
>
>> On 07/20/2009 06:07 PM, Michael Goldish wrote:
>>> 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.
>>>
>>> Signed-off-by: Michael Goldish<[e-mail]>
>>> ---
>>>    client/tests/kvm/kvm.py       |    1 +
>>>    client/tests/kvm/kvm_tests.py |  161
>> ++++++++++++++++++++++++++++++++++++++++-
>>>    2 files changed, 160 insertions(+), 2 deletions(-)
>>>
>>> diff --git a/client/tests/kvm/kvm.py b/client/tests/kvm/kvm.py
>>> index b18b643..070e463 100644
>>> --- a/client/tests/kvm/kvm.py
>>> +++ b/client/tests/kvm/kvm.py
>>> @@ -55,6 +55,7 @@ class kvm(test.test):
>>>                    "kvm_install":  test_routine("kvm_install",
>> "run_kvm_install"),
>>>                    "linux_s3":     test_routine("kvm_tests",
>> "run_linux_s3"),
>>>                    "stress_boot":  test_routine("kvm_tests",
>> "run_stress_boot"),
>>> +                "timedrift":    test_routine("kvm_tests",
>> "run_timedrift"),
>>>                    }
>>>
>>>            # Make it possible to import modules from the test's
>> bindir
>>> diff --git a/client/tests/kvm/kvm_tests.py
>> b/client/tests/kvm/kvm_tests.py
>>> index 5991aed..ca0b8c0 100644
>>> --- a/client/tests/kvm/kvm_tests.py
>>> +++ b/client/tests/kvm/kvm_tests.py
>>> @@ -1,4 +1,4 @@
>>> -import time, os, logging
>>> +import time, os, logging, re, commands
>>>    from autotest_lib.client.common_lib import utils, error
>>>    import kvm_utils, kvm_subprocess, ppm_utils, scan_results
>>>
>>> @@ -529,7 +529,6 @@ def run_stress_boot(tests, params, env):
>>>        """
>>>        # boot the first vm
>>>        vm = kvm_utils.env_get_vm(env, params.get("main_vm"))
>>> -
>>>        if not vm:
>>>            raise error.TestError("VM object not found in
>> environment")
>>>        if not vm.is_alive():
>>> @@ -586,3 +585,161 @@ def run_stress_boot(tests, params, env):
>>>            for se in sessions:
>>>                se.close()
>>>            logging.info("Total number booted: %d" % (num -1))
>>> +
>>> +
>>> +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.
>>> +    """
>>> +    vm = kvm_utils.env_get_vm(env, params.get("main_vm"))
>>> +    if not vm:
>>> +        raise error.TestError("VM object not found in
>> environment")
>>> +    if not vm.is_alive():
>>> +        raise error.TestError("VM seems to be dead; Test requires a
>> living VM")
>>> +
>>> +    logging.info("Waiting for guest to be up...")
>>> +
>>> +    session = kvm_utils.wait_for(vm.ssh_login, 240, 0, 2)
>>> +    if not session:
>>> +        raise error.TestFail("Could not log into guest")
>>> +
>>> +    logging.info("Logged in")
>>> +
>>> +    # 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 = []
>>> +
>>> +    # Remember the VM's previous CPU affinity
>>> +    prev_cpu_mask = commands.getoutput("taskset -p %s" %
>> vm.get_pid())
>>> +    prev_cpu_mask = prev_cpu_mask.split()[-1]
>>> +    # Set the VM's CPU affinity
>>> +    commands.getoutput("taskset -p %s %s" % (cpu_mask,
>> vm.get_pid()))
>>
>>
>> Need to handle guest smp case where we want to pin the guest to
>> several
>> cpus.
>>
>> Cheers for the test!
>
> cpu_mask is user-specified. If the user specifies 5, the VM will be
> pinned to CPUs 1 and 3. In smp tests we can set cpu_mask appropriately.
> Is this OK or were you referring to something else?

In that case it is good. Thanks.

>
>>> +
>>> +    try:
>>> +        # Get time before load
>>> +        host_time_0 = time.time()
>>> +        session.sendline(time_command)
>>> +        (match, s) = session.read_up_to_prompt()
>>> +        s = re.findall(time_filter_re, s)[0]
>>> +        guest_time_0 = time.mktime(time.strptime(s, time_format))
>>> +
>>> +        # Run some load on the guest
>>> +        logging.info("Starting load on guest...")
>>> +        for i in range(guest_load_instances):
>>> +            load_session = vm.ssh_login()
>>> +            if not load_session:
>>> +                raise error.TestFail("Could not log into guest")
>>> +            load_session.set_output_prefix("(guest load %d) " % i)
>>> +            load_session.set_output_func(logging.debug)
>>> +            load_session.sendline(guest_load_command)
>>> +            guest_load_sessions.append(load_session)
>>> +
>>> +        # Run some load on the host
>>> +        logging.info("Starting load on host...")
>>> +        for i in range(host_load_instances):
>>> +            host_load_sessions.append(
>>> +                kvm_subprocess.run_bg(host_load_command,
>>> +                                      output_func=logging.debug,
>>> +                                      output_prefix="(host load %d)
>> " % i,
>>> +                                      timeout=0.5))
>>> +            # Set the CPU affinity of the shell running the load
>> process
>>> +            pid = host_load_sessions[-1].get_shell_pid()
>>> +            commands.getoutput("taskset -p %s %s" % (cpu_mask,
>> pid))
>>> +            # Try setting the CPU affinity of the load process
>> itself
>>> +            pid = host_load_sessions[-1].get_pid()
>>> +            if pid:
>>> +                commands.getoutput("taskset -p %s %s" % (cpu_mask,
>> pid))
>>> +
>>> +        # Sleep for a while (during load)
>>> +        logging.info("Sleeping for %s seconds..." % load_duration)
>>> +        time.sleep(load_duration)
>>> +
>>> +        # Get time delta after load
>>> +        host_time_1 = time.time()
>>> +        session.sendline(time_command)
>>> +        (match, s) = session.read_up_to_prompt()
>>> +        s = re.findall(time_filter_re, s)[0]
>>> +        guest_time_1 = time.mktime(time.strptime(s, time_format))
>>> +
>>> +        # Report results
>>> +        host_delta = host_time_1 - host_time_0
>>> +        guest_delta = guest_time_1 - guest_time_0
>>> +        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
>>> +        commands.getoutput("taskset -p %s %s" % (prev_cpu_mask,
>> vm.get_pid()))
>>> +        # Stop the guest load
>>> +        if guest_load_stop_command:
>>> +            session.get_command_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
>>> +    host_time_2 = time.time()
>>> +    session.sendline(time_command)
>>> +    (match, s) = session.read_up_to_prompt()
>>> +    s = re.findall(time_filter_re, s)[0]
>>> +    guest_time_2 = time.mktime(time.strptime(s, time_format))
>>> +
>>> +    # Report results
>>> +    host_delta_total = host_time_2 - host_time_0
>>> +    guest_delta_total = guest_time_2 - guest_time_0
>>> +    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 drift>   drift_threshold:
>>> +        raise error.TestFail("Time drift too large: %.2f%%" %
>> drift)
>>> +    if drift>   drift_threshold_after_rest:
>>> +        raise error.TestFail("Time drift too large after rest
>> period: %.2f%%"
>>> +                             % drift_total)
>>> +
>>> +    session.close()

--
To unsubscribe from this list: send the line "unsubscribe kvm" in
the body of a message to [e-mail]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Yolkfull Chow July 21, 2009, 2:57 p.m. UTC | #4

On Mon, Jul 20, 2009 at 06:07:19PM +0300, Michael Goldish wrote:
> 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.
> 
> Signed-off-by: Michael Goldish <[e-mail]>
> ---
>  client/tests/kvm/kvm.py       |    1 +
>  client/tests/kvm/kvm_tests.py |  161 ++++++++++++++++++++++++++++++++++++++++-
>  2 files changed, 160 insertions(+), 2 deletions(-)
> 
> diff --git a/client/tests/kvm/kvm.py b/client/tests/kvm/kvm.py
> index b18b643..070e463 100644
> --- a/client/tests/kvm/kvm.py
> +++ b/client/tests/kvm/kvm.py
> @@ -55,6 +55,7 @@ class kvm(test.test):
>                  "kvm_install":  test_routine("kvm_install", "run_kvm_install"),
>                  "linux_s3":     test_routine("kvm_tests", "run_linux_s3"),
>                  "stress_boot":  test_routine("kvm_tests", "run_stress_boot"),
> +                "timedrift":    test_routine("kvm_tests", "run_timedrift"),
>                  }
>  
>          # Make it possible to import modules from the test's bindir
> diff --git a/client/tests/kvm/kvm_tests.py b/client/tests/kvm/kvm_tests.py
> index 5991aed..ca0b8c0 100644
> --- a/client/tests/kvm/kvm_tests.py
> +++ b/client/tests/kvm/kvm_tests.py
> @@ -1,4 +1,4 @@
> -import time, os, logging
> +import time, os, logging, re, commands
>  from autotest_lib.client.common_lib import utils, error
>  import kvm_utils, kvm_subprocess, ppm_utils, scan_results
>  
> @@ -529,7 +529,6 @@ def run_stress_boot(tests, params, env):
>      """
>      # boot the first vm
>      vm = kvm_utils.env_get_vm(env, params.get("main_vm"))
> -
>      if not vm:
>          raise error.TestError("VM object not found in environment")
>      if not vm.is_alive():
> @@ -586,3 +585,161 @@ def run_stress_boot(tests, params, env):
>          for se in sessions:
>              se.close()
>          logging.info("Total number booted: %d" % (num -1))
> +
> +
> +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.
> +    """
> +    vm = kvm_utils.env_get_vm(env, params.get("main_vm"))
> +    if not vm:
> +        raise error.TestError("VM object not found in environment")
> +    if not vm.is_alive():
> +        raise error.TestError("VM seems to be dead; Test requires a living VM")
> +
> +    logging.info("Waiting for guest to be up...")
> +
> +    session = kvm_utils.wait_for(vm.ssh_login, 240, 0, 2)
> +    if not session:
> +        raise error.TestFail("Could not log into guest")
> +
> +    logging.info("Logged in")
> +
> +    # 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 = []
> +
> +    # Remember the VM's previous CPU affinity
> +    prev_cpu_mask = commands.getoutput("taskset -p %s" % vm.get_pid())
> +    prev_cpu_mask = prev_cpu_mask.split()[-1]
> +    # Set the VM's CPU affinity
> +    commands.getoutput("taskset -p %s %s" % (cpu_mask, vm.get_pid()))
> +
> +    try:
> +        # Get time before load
> +        host_time_0 = time.time()
> +        session.sendline(time_command)
> +        (match, s) = session.read_up_to_prompt()
> +        s = re.findall(time_filter_re, s)[0]
> +        guest_time_0 = time.mktime(time.strptime(s, time_format))

Hi Machael, this test looks good for me, but I have a little suggestion:
Why not write a common function to get guest time which really save many
duplicate codes here? It could has four parameters and I would also help
write it for you :-)

def get_guest_time(session, time_command, filter_re, format):
    session.sendline(time_command)
    (match, s) = session.read_up_to_prompt()
    s = re.findall(filter_re, s)[0]
    curr_time = time.mktime(time.strptime(s, format))
    return curr_time


> +
> +        # Run some load on the guest
> +        logging.info("Starting load on guest...")
> +        for i in range(guest_load_instances):
> +            load_session = vm.ssh_login()
> +            if not load_session:
> +                raise error.TestFail("Could not log into guest")
> +            load_session.set_output_prefix("(guest load %d) " % i)
> +            load_session.set_output_func(logging.debug)
> +            load_session.sendline(guest_load_command)
> +            guest_load_sessions.append(load_session)
> +
> +        # Run some load on the host
> +        logging.info("Starting load on host...")
> +        for i in range(host_load_instances):
> +            host_load_sessions.append(
> +                kvm_subprocess.run_bg(host_load_command,
> +                                      output_func=logging.debug,
> +                                      output_prefix="(host load %d) " % i,
> +                                      timeout=0.5))
> +            # Set the CPU affinity of the shell running the load process
> +            pid = host_load_sessions[-1].get_shell_pid()
> +            commands.getoutput("taskset -p %s %s" % (cpu_mask, pid))
> +            # Try setting the CPU affinity of the load process itself
> +            pid = host_load_sessions[-1].get_pid()
> +            if pid:
> +                commands.getoutput("taskset -p %s %s" % (cpu_mask, pid))
> +
> +        # Sleep for a while (during load)
> +        logging.info("Sleeping for %s seconds..." % load_duration)
> +        time.sleep(load_duration)
> +
> +        # Get time delta after load
> +        host_time_1 = time.time()
> +        session.sendline(time_command)
> +        (match, s) = session.read_up_to_prompt()
> +        s = re.findall(time_filter_re, s)[0]
> +        guest_time_1 = time.mktime(time.strptime(s, time_format))
> +
> +        # Report results
> +        host_delta = host_time_1 - host_time_0
> +        guest_delta = guest_time_1 - guest_time_0
> +        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
> +        commands.getoutput("taskset -p %s %s" % (prev_cpu_mask, vm.get_pid()))
> +        # Stop the guest load
> +        if guest_load_stop_command:
> +            session.get_command_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
> +    host_time_2 = time.time()
> +    session.sendline(time_command)
> +    (match, s) = session.read_up_to_prompt()
> +    s = re.findall(time_filter_re, s)[0]
> +    guest_time_2 = time.mktime(time.strptime(s, time_format))
> +
> +    # Report results
> +    host_delta_total = host_time_2 - host_time_0
> +    guest_delta_total = guest_time_2 - guest_time_0
> +    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 drift > drift_threshold:
> +        raise error.TestFail("Time drift too large: %.2f%%" % drift)
> +    if drift > drift_threshold_after_rest:
> +        raise error.TestFail("Time drift too large after rest period: %.2f%%"
> +                             % drift_total)
> +
> +    session.close()
> -- 
> 1.5.4.1
> 
> _______________________________________________
> Autotest mailing list
> [e-mail]
> http://test.kernel.org/cgi-bin/mailman/listinfo/autotest
--
To unsubscribe from this list: send the line "unsubscribe kvm" in
the body of a message to [e-mail]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Marcelo Tosatti July 21, 2009, 5:25 p.m. UTC | #5

On Tue, Jul 21, 2009 at 12:23:15PM +0300, Dor Laor wrote:
> On 07/20/2009 06:07 PM, Michael Goldish wrote:
>> 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.
>>
>> Signed-off-by: Michael Goldish<[e-mail]>
>> ---
>>   client/tests/kvm/kvm.py       |    1 +
>>   client/tests/kvm/kvm_tests.py |  161 ++++++++++++++++++++++++++++++++++++++++-
>>   2 files changed, 160 insertions(+), 2 deletions(-)
>>
>> diff --git a/client/tests/kvm/kvm.py b/client/tests/kvm/kvm.py
>> index b18b643..070e463 100644
>> --- a/client/tests/kvm/kvm.py
>> +++ b/client/tests/kvm/kvm.py
>> @@ -55,6 +55,7 @@ class kvm(test.test):
>>                   "kvm_install":  test_routine("kvm_install", "run_kvm_install"),
>>                   "linux_s3":     test_routine("kvm_tests", "run_linux_s3"),
>>                   "stress_boot":  test_routine("kvm_tests", "run_stress_boot"),
>> +                "timedrift":    test_routine("kvm_tests", "run_timedrift"),
>>                   }
>>
>>           # Make it possible to import modules from the test's bindir
>> diff --git a/client/tests/kvm/kvm_tests.py b/client/tests/kvm/kvm_tests.py
>> index 5991aed..ca0b8c0 100644
>> --- a/client/tests/kvm/kvm_tests.py
>> +++ b/client/tests/kvm/kvm_tests.py
>> @@ -1,4 +1,4 @@
>> -import time, os, logging
>> +import time, os, logging, re, commands
>>   from autotest_lib.client.common_lib import utils, error
>>   import kvm_utils, kvm_subprocess, ppm_utils, scan_results
>>
>> @@ -529,7 +529,6 @@ def run_stress_boot(tests, params, env):
>>       """
>>       # boot the first vm
>>       vm = kvm_utils.env_get_vm(env, params.get("main_vm"))
>> -
>>       if not vm:
>>           raise error.TestError("VM object not found in environment")
>>       if not vm.is_alive():
>> @@ -586,3 +585,161 @@ def run_stress_boot(tests, params, env):
>>           for se in sessions:
>>               se.close()
>>           logging.info("Total number booted: %d" % (num -1))
>> +
>> +
>> +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.
>> +    """
>> +    vm = kvm_utils.env_get_vm(env, params.get("main_vm"))
>> +    if not vm:
>> +        raise error.TestError("VM object not found in environment")
>> +    if not vm.is_alive():
>> +        raise error.TestError("VM seems to be dead; Test requires a living VM")
>> +
>> +    logging.info("Waiting for guest to be up...")
>> +
>> +    session = kvm_utils.wait_for(vm.ssh_login, 240, 0, 2)
>> +    if not session:
>> +        raise error.TestFail("Could not log into guest")
>> +
>> +    logging.info("Logged in")
>> +
>> +    # 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 = []
>> +
>> +    # Remember the VM's previous CPU affinity
>> +    prev_cpu_mask = commands.getoutput("taskset -p %s" % vm.get_pid())
>> +    prev_cpu_mask = prev_cpu_mask.split()[-1]
>> +    # Set the VM's CPU affinity
>> +    commands.getoutput("taskset -p %s %s" % (cpu_mask, vm.get_pid()))
>
>
> Need to handle guest smp case where we want to pin the guest to several  
> cpus.
>
> Cheers for the test!

Yes, very nice.

A improvement suggestion: the system load / cpu pin characteristics
should be generic, and not specific to this particular test. Because
other tests also benefit from it (one obvious candidate is migration) ?

Regarding timedrift, it should know if there is an ntp client running on
the guest (now whether ntp configuration should be part of the testcase,
or should belong outside of it, independently somehow, i'm unsure).

Its necessary to measure with/without ntp client.

--
To unsubscribe from this list: send the line "unsubscribe kvm" in
the body of a message to [e-mail]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Patch

diff --git a/client/tests/kvm/kvm.py b/client/tests/kvm/kvm.py
index b18b643..070e463 100644
--- a/client/tests/kvm/kvm.py
+++ b/client/tests/kvm/kvm.py
@@ -55,6 +55,7 @@  class kvm(test.test):
                 "kvm_install":  test_routine("kvm_install", "run_kvm_install"),
                 "linux_s3":     test_routine("kvm_tests", "run_linux_s3"),
                 "stress_boot":  test_routine("kvm_tests", "run_stress_boot"),
+                "timedrift":    test_routine("kvm_tests", "run_timedrift"),
                 }
 
         # Make it possible to import modules from the test's bindir
diff --git a/client/tests/kvm/kvm_tests.py b/client/tests/kvm/kvm_tests.py
index 5991aed..ca0b8c0 100644
--- a/client/tests/kvm/kvm_tests.py
+++ b/client/tests/kvm/kvm_tests.py
@@ -1,4 +1,4 @@ 
-import time, os, logging
+import time, os, logging, re, commands
 from autotest_lib.client.common_lib import utils, error
 import kvm_utils, kvm_subprocess, ppm_utils, scan_results
 
@@ -529,7 +529,6 @@  def run_stress_boot(tests, params, env):
     """
     # boot the first vm
     vm = kvm_utils.env_get_vm(env, params.get("main_vm"))
-
     if not vm:
         raise error.TestError("VM object not found in environment")
     if not vm.is_alive():
@@ -586,3 +585,161 @@  def run_stress_boot(tests, params, env):
         for se in sessions:
             se.close()
         logging.info("Total number booted: %d" % (num -1))
+
+
+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.
+    """
+    vm = kvm_utils.env_get_vm(env, params.get("main_vm"))
+    if not vm:
+        raise error.TestError("VM object not found in environment")
+    if not vm.is_alive():
+        raise error.TestError("VM seems to be dead; Test requires a living VM")
+
+    logging.info("Waiting for guest to be up...")
+
+    session = kvm_utils.wait_for(vm.ssh_login, 240, 0, 2)
+    if not session:
+        raise error.TestFail("Could not log into guest")
+
+    logging.info("Logged in")
+
+    # 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 = []
+
+    # Remember the VM's previous CPU affinity
+    prev_cpu_mask = commands.getoutput("taskset -p %s" % vm.get_pid())
+    prev_cpu_mask = prev_cpu_mask.split()[-1]
+    # Set the VM's CPU affinity
+    commands.getoutput("taskset -p %s %s" % (cpu_mask, vm.get_pid()))
+
+    try:
+        # Get time before load
+        host_time_0 = time.time()
+        session.sendline(time_command)
+        (match, s) = session.read_up_to_prompt()
+        s = re.findall(time_filter_re, s)[0]
+        guest_time_0 = time.mktime(time.strptime(s, time_format))
+
+        # Run some load on the guest
+        logging.info("Starting load on guest...")
+        for i in range(guest_load_instances):
+            load_session = vm.ssh_login()
+            if not load_session:
+                raise error.TestFail("Could not log into guest")
+            load_session.set_output_prefix("(guest load %d) " % i)
+            load_session.set_output_func(logging.debug)
+            load_session.sendline(guest_load_command)
+            guest_load_sessions.append(load_session)
+
+        # Run some load on the host
+        logging.info("Starting load on host...")
+        for i in range(host_load_instances):
+            host_load_sessions.append(
+                kvm_subprocess.run_bg(host_load_command,
+                                      output_func=logging.debug,
+                                      output_prefix="(host load %d) " % i,
+                                      timeout=0.5))
+            # Set the CPU affinity of the shell running the load process
+            pid = host_load_sessions[-1].get_shell_pid()
+            commands.getoutput("taskset -p %s %s" % (cpu_mask, pid))
+            # Try setting the CPU affinity of the load process itself
+            pid = host_load_sessions[-1].get_pid()
+            if pid:
+                commands.getoutput("taskset -p %s %s" % (cpu_mask, pid))
+
+        # Sleep for a while (during load)
+        logging.info("Sleeping for %s seconds..." % load_duration)
+        time.sleep(load_duration)
+
+        # Get time delta after load
+        host_time_1 = time.time()
+        session.sendline(time_command)
+        (match, s) = session.read_up_to_prompt()
+        s = re.findall(time_filter_re, s)[0]
+        guest_time_1 = time.mktime(time.strptime(s, time_format))
+
+        # Report results
+        host_delta = host_time_1 - host_time_0
+        guest_delta = guest_time_1 - guest_time_0
+        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
+        commands.getoutput("taskset -p %s %s" % (prev_cpu_mask, vm.get_pid()))
+        # Stop the guest load
+        if guest_load_stop_command:
+            session.get_command_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
+    host_time_2 = time.time()
+    session.sendline(time_command)
+    (match, s) = session.read_up_to_prompt()
+    s = re.findall(time_filter_re, s)[0]
+    guest_time_2 = time.mktime(time.strptime(s, time_format))
+
+    # Report results
+    host_delta_total = host_time_2 - host_time_0
+    guest_delta_total = guest_time_2 - guest_time_0
+    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 drift > drift_threshold:
+        raise error.TestFail("Time drift too large: %.2f%%" % drift)
+    if drift > drift_threshold_after_rest:
+        raise error.TestFail("Time drift too large after rest period: %.2f%%"
+                             % drift_total)
+
+    session.close()