Re: xen-2.0 20040923 and previous: rpm crash in xenU

[Peri Hankey <mpah@thegreen.co.uk>]

Thanks for sending the test - one point of interest is that my 
/proc/cpuinfo doesn't match your expectations - presumably an AMD 
Athlon(tm) XP 2400+ is running at 2400MHz. The main point however is 
that the results are indeed different in the two domains:

----------------  xen0 ------------------------

[me@xen0 testing]$ ./time-test
find_cpu_speed: error parsing /proc/cpuinfo for cpu MHz. Assume 2400 
MhzCPU speed = 2400 MHz
...........................................................................................................
...........................................................................................................
... (lots of dots)

[me@xen0 testing]$ cat /proc/cpuinfo
processor       : 0
vendor_id       : AuthenticAMD
cpu family      : 6
model           : 8
model name      : AMD Athlon(tm) XP 2400+
stepping        : 1
cache size      : 256 KB
fdiv_bug        : no
hlt_bug         : yes
f00f_bug        : no
coma_bug        : no
fpu             : yes
fpu_exception   : yes
cpuid level     : 1
wp              : yes
flags           : fpu msr pae mce cx8 apic sep mca cmov pat pse36 mmx 
sse syscall mmxext 3dnowext 3dnow
bogomips        : 4010.80

----------------  xenU ------------------------

[me@xenU testing]$ ./time-test
find_cpu_speed: error parsing /proc/cpuinfo for cpu MHz. Assume 2400 
MhzCPU speed = 2400 MHz
nanosleep(20000us): gtod 0
.nanosleep(20000us): gtod 0
.nanosleep(20000us): gtod 0
.nanosleep(20000us): gtod 0
.nanosleep(20000us): gtod 0
.nanosleep(20000us): gtod 0
.nanosleep(20000us): gtod 0
.nanosleep(20000us): gtod 0
... (lots of gtod 0s)

[me@xenU testing]$ cat /proc/cpuinfo
processor       : 0
vendor_id       : AuthenticAMD
cpu family      : 6
model           : 8
model name      : AMD Athlon(tm) XP 2400+
stepping        : 1
cache size      : 256 KB
fdiv_bug        : no
hlt_bug         : yes
f00f_bug        : no
coma_bug        : no
fpu             : yes
fpu_exception   : yes
cpuid level     : 1
wp              : yes
flags           : fpu msr pae mce cx8 apic sep mca cmov pat pse36 mmx 
sse syscall mmxext 3dnowext 3dnow
bogomips        : 3263.69

I hope this will help nail it down - I notice also that the bogomips 
measure is different. No time for more just now - but I have a more 
general question about lvm2 cows and snapshots, which I will put in a 
separate message. 'A snapshot is not a cow' as the liftman said to Babar 
the Elephant. In fact the problem is that snapshots hold on to each 
other's tails.

Thanks for your help.
Peri


Ian Pratt wrote:

>>I have previously mentioned a floating point exception in rpm which 
>>seemed at one point to be connected with block-device handling in xenU 
>>systems, as both problems occurred at the same time. As I now get only 
>>the rpm floating point exception (sporadically), I have examined it further:
>>
>>gettimeofday({1096021305, 741150}, NULL) = 0
>>nanosleep({0, 20000000}, {1076798912, 1075195904}) = 0
>>gettimeofday({1096021305, 741150}, NULL) = 0
>>--- SIGFPE (Floating point exception) @ 0 (0) ---
>>+++ killed by SIGFPE +++
>>
>>    
>>
>
>I've tried hard to reproduce this but failed. It might be worth
>having a look at the rpm source to check that the nanosleep is
>wrapped in a while loop, and where the presumed division by zero
>is really coming from.
>
>Since the strace prints the arguments that gettimeofday is passed
>rather than returns, we can't really tell from the trace what
>gettimeofday is actually returning. If there's a following call
>in the trace using the same struct we can probably deduce it.
>
>I've appended the test program I've used to debug this and other
>time issues. You might want to run it on your system just to
>check.
>
>Thanks,
>Ian
>
>
>#include <stdlib.h>
>#include <stdio.h>
>#include <sys/time.h>
>#include <time.h>
>
>/**************************************************************************/
>
>
>/* rpcc: get full 64-bit Pentium TSC value */
>static __inline__ unsigned long long int rpcc(void) 
>{
>    unsigned int __h, __l;
>    __asm__ __volatile__ ("rdtsc" :"=a" (__l), "=d" (__h));
>    return (((unsigned long long)__h) << 32) + __l;
>}
>
>
>/*
> * find_cpu_speed:
> *   Interrogates /proc/cpuinfo for the processor clock speed.
> * 
> *   Returns: speed of processor in MHz, rounded down to nearest whole MHz.
> */
>#define MAX_LINE_LEN 50
>int find_cpu_speed(void)
>{
>    FILE *f;
>    char s[MAX_LINE_LEN], *a, *b;
>    int mhz = 2400;
>
>    if ( (f = fopen("/proc/cpuinfo", "r")) == NULL ) goto out;
>
>    while ( fgets(s, MAX_LINE_LEN, f) )
>    {
>        if ( strstr(s, "cpu MHz") )
>        {
>            /* Find the start of the speed value, and stop at the dec point. */
>            if ( !(a=strpbrk(s,"0123456789")) || !(b=strpbrk(a,".")) ) break;
>            *b = '\0';
>            fclose(f);
>            return(atoi(a));
>        }
>    }
>
> out:    
>    fprintf(stderr, "find_cpu_speed: error parsing /proc/cpuinfo for cpu MHz. Assume %d Mhz",mhz);
>    return mhz;
>
>}
>
>int mhz;
>
>int looper (int N)
>{
>    int i,a=12345;
>    for(i=0;i<N;i++)
>	a*=a;
>    return a;
>}
>
>
>main()
>{
>    int stride;
>    unsigned long long start=0,stop=0, last=0, now, gt_firsteventtime;
>    unsigned long long xnow, xlast, skip;
>    unsigned long long firsteventtime=0, lasteventtime, lastfirsteventtime = 0;
>    struct timeval a,b;
>    int count=0, okcount=0;
>
>    /* Required in order to print intermediate results at fixed period. */
>    mhz = find_cpu_speed();
>    printf("CPU speed = %d MHz\n", mhz);
>
>
>#define SLEEP (20*1000)
>
>    while(1)
>    {
>	struct timespec z = { 0, SLEEP*1000 };
>
>	gettimeofday(&a, NULL);
>	while(nanosleep(&z,&z)); // loop until success
>	gettimeofday(&b, NULL);
>
>	last = (((long long)a.tv_sec) * 1000000) + a.tv_usec;
>	now  = (((long long)b.tv_sec) * 1000000) + b.tv_usec;
>
>	if ( now - last < SLEEP )
>	{
>	    printf("nanosleep(%dus): gtod %d\n",
>		   SLEEP, now-last );
>	}
>
>	fprintf(stderr,".");	
>    }
>
>
>
>    gettimeofday(&a, NULL);
>    xlast = rpcc();
>    last = (((long long)a.tv_sec) * 1000000) + a.tv_usec;
>    while(1)
>    {
>	struct timespec z = { 0, SLEEP*1000 };
>
>	while(nanosleep(&z,&z)); // loop until success
>	gettimeofday(&a, NULL);
>	xnow = rpcc();
>        now = (((long long)a.tv_sec) * 1000000) + a.tv_usec;
>
>	if ( now - last < SLEEP )
>	{
>	    printf("nanosleep(%d): gtod %d  rpcc %d\n",
>		   SLEEP, now-last, (xnow-xlast)/mhz );
>	}
>
>	last = now;
>	xlast = xnow;
>
>	if((count++ % 64) == 0)fprintf(stderr,".");
>    }
>
>
>    start = rpcc();
>    while(1)
>    {
>	gettimeofday(&a, NULL);
>	xnow = rpcc();
>
>	if(xnow < xlast)
>	    printf("** %lld %lld **\n", xnow, xlast);
>
>        now = (((long long)a.tv_sec) * 1000000) + a.tv_usec;
>
>	if(now<last)
>	{
>	    printf("backwards!\n");
>	    exit(-1);
>	}
>
>	if(now==last) 
>	{
>	    count++;
>	    lasteventtime = rpcc();
>	    if( firsteventtime == 0 ) 
>	    {
>		firsteventtime = lasteventtime;
>		gt_firsteventtime = now;
>		skip = (xnow-xlast)/mhz;
>	    }
>
>	}
>
>	if(now>last)
>	{
>	    if(count>5)
>	    {
>		printf("[%lld.%lld %lld] duplicates= % 5d (% 5lldus)\t prev OK= % 6d\t fe %lldus (d=%lldus) skip = %lld\n",
>		       gt_firsteventtime/1000000,gt_firsteventtime%1000000,
>		       firsteventtime,
>		       count, (lasteventtime-firsteventtime)/mhz,
>		       okcount,(firsteventtime-start)/mhz,
>		       (firsteventtime-lastfirsteventtime)/mhz,
>		       skip);
>		okcount = 0;
>		lastfirsteventtime = firsteventtime;
>	    }
>	    count = 0;
>	    firsteventtime = 0;
>	    okcount++;
>	}
>	
>	last = now;
>	xlast = xnow;
>    }
>
>   
>#if 0
>    while(1)
>    {
>int i;
>        gettimeofday(&a, NULL);
>for(i=0;i<10000;i++);
>	gettimeofday(&b, NULL);
>        start = (((long long)a.tv_sec) * 1000000) + a.tv_usec;
>	stop  = (((long long)b.tv_sec) * 1000000) + b.tv_usec;
>
>        if(1||stop<start) printf("crap : %ld\n",stop-start);
>    }
>	
>    while(1)
>    {
>	gettimeofday(&a, NULL);
>	start = (((long long)a.tv_sec) * 1000000) + a.tv_usec;
>
>	looper(1000000);
>
>	gettimeofday(&a, NULL);
>	stop = (((long long)a.tv_sec) * 1000000) + a.tv_usec;
>
>	printf("%ld\n",stop-start);
>
>    }
>
>
>#endif
> 
>
>
>
>}
>
>
>  
>



-------------------------------------------------------
This SF.Net email is sponsored by: YOU BE THE JUDGE. Be one of 170
Project Admins to receive an Apple iPod Mini FREE for your judgement on
who ports your project to Linux PPC the best. Sponsored by IBM.
Deadline: Sept. 24. Go here: http://sf.net/ppc_contest.php