From mboxrd@z Thu Jan  1 00:00:00 1970
From: "David S. Ahern" <daahern@cisco.com>
Subject: microsecond time shifts as vcpu changes
Date: Wed, 20 Aug 2008 22:31:25 -0600
Message-ID: <48ACEF9D.4060309@cisco.com>
Mime-Version: 1.0
Content-Type: multipart/mixed;
 boundary="------------050504040003090103020900"
Cc: Chris Wright <chrisw@redhat.com>
To: Marcelo Tosatti <mtosatti@redhat.com>,
	kvm-devel <kvm@vger.kernel.org>
Return-path: <kvm-owner@vger.kernel.org>
Received: from sj-iport-5.cisco.com ([171.68.10.87]:2518 "EHLO
	sj-iport-5.cisco.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
	with ESMTP id S1751260AbYHUEb3 (ORCPT <rfc822;kvm@vger.kernel.org>);
	Thu, 21 Aug 2008 00:31:29 -0400
Sender: kvm-owner@vger.kernel.org
List-ID: <kvm.vger.kernel.org>

This is a multi-part message in MIME format.
--------------050504040003090103020900
Content-Type: text/plain; charset=ISO-8859-1
Content-Transfer-Encoding: 7bit

Hi Marcelo:

Some time ago I posted a message about time shifts. Since then I changed
my sample code to basically roam the vcpus in sequence, setting affinity
and dumping time. This version better illustrates what I mean by time
shifts.

The following is from within a RHEL3 guest. The numbers are
tv_sec.tv_usec as returned from gettimeofday() with no sleeps are rests
between affinity/gettimeofday calls:

# ./showtime 4 1

cpu 0: 1219292400.275439
cpu 1: 1219292400.667516
cpu 2: 1219292400.381351
cpu 3: 1219292401.942548

cpu 0: 1219292401.288373
cpu 1: 1219292401.678309
cpu 2: 1219292401.392143
cpu 3: 1219292402.953051

cpu 0: 1219292402.296987
cpu 1: 1219292402.686787
cpu 2: 1219292402.400609
cpu 3: 1219292403.961588

cpu 0: 1219292403.305919
cpu 1: 1219292403.695727
cpu 2: 1219292403.409547
cpu 3: 1219292404.970496

cpu 0: 1219292404.315970
cpu 1: 1219292404.705853
cpu 2: 1219292404.419674
cpu 3: 1219292405.980646

...

There are a couple of things concerning here -- the fact that time can
go backward as you shift vcpus, and also the fact that the process has
affinity set to vcpu3, sleeps for 1 second, sets affinity to vcpu0 and
the time delta between vcpu3 and the next vcpu1 is not 1 second. I'm
guessing both are an artifact of the same problem.

This particular host is a DL380 G5 running Fedora 9
(2.6.25.11-97.fc9.x86_64) and kvm-73 unmodified. I have a RHEL4 guest
running on a PowerEdge 2950 and do not see the shifting:

# ./showtime 4 1

cpu 0: 1219292953.320635
cpu 1: 1219292953.321332
cpu 2: 1219292953.321542
cpu 3: 1219292953.334045

cpu 0: 1219292954.336818
cpu 1: 1219292954.336896
cpu 2: 1219292954.337142
cpu 3: 1219292954.337303

cpu 0: 1219292955.339645
cpu 1: 1219292955.345344
cpu 2: 1219292955.345557
cpu 3: 1219292955.345625

cpu 0: 1219292956.348426
cpu 1: 1219292956.348507
cpu 2: 1219292956.348700
cpu 3: 1219292956.348762


Unfortunately I do not have a RHEL4 guest on the DL380 right now. I'll
copy one over when I get the time.


david


--------------050504040003090103020900
Content-Type: text/x-csrc;
 name="showtime.c"
Content-Transfer-Encoding: 7bit
Content-Disposition: inline;
 filename="showtime.c"


#define _GNU_SOURCE
#include <features.h>
#include <sys/time.h>
#include <stdlib.h>
#include <stdio.h>
#include <string.h>
#include <errno.h>
#include <unistd.h>
#include <sched.h>
#include <libgen.h>

int set_affinity(unsigned int cpu)
{
	int rc = 0;
	cpu_set_t set;
	CPU_ZERO(&set);
	CPU_SET(cpu, &set);

#ifdef MAKE_RHEL3
	if (sched_setaffinity(0, &set) != 0)
#else
	if (sched_setaffinity(0, sizeof(set), &set) != 0)
#endif
	{
		rc = 1;
		fprintf(stderr,
		        "failed to set CPU mask to %x: %s\n",
		        cpu, strerror(errno));
	}

	return rc;
}


int main(int argc, char *argv[])
{
	unsigned int tsleep = 0;
	unsigned int i;
	int max_cpu;
	struct timeval tv;

	if (argc < 2) {
		printf("usage: %s ncpus [sleeptime]\n", basename(argv[0]));
		return 1;
	}

	max_cpu = atoi(argv[1]);
	if (max_cpu == 0)
		return 2;

	if (argc > 2)
		tsleep = atoi(argv[2]);

	while(1) {

		printf("\n");
		for (i = 0; i < max_cpu; ++i) {

			if (set_affinity(i) != 0)
				break;

			if (gettimeofday(&tv, NULL) != 0)
				printf("gettimeofday failed\n");
			else
				printf("cpu %d: %ld.%06ld\n", i, tv.tv_sec, tv.tv_usec);
		}

		if (!tsleep)
			break;

		sleep(tsleep);
	}

	return 0;
}

--------------050504040003090103020900--