Subject: Re: getrusage() problem in hp300 port??
To: None <oster@cs.usask.ca>
From: None <Havard.Eidnes@runit.sintef.no>
List: port-hp300
Date: 11/20/1997 21:09:43
----Next_Part(Thu_Nov_20_21:09:20_1997)--
Content-Type: Text/Plain; charset=iso-8859-1
Content-Transfer-Encoding: quoted-printable

Hi,

I've found at least one explanation to why the ru_utime time
returned by getrusage() isn't monotonically increasing.

The basic problem is that the implementation of getrusage() pretends
to have more resolution in the resource accounting than what is
actually the case...

The process accounting is done in 'ticks', and each tick is counted
as either "user time", "system time" or "interrupt time" (the latter
is always zero on at least NetBSD/i386 and NetBSD/hp300).

calcru() inside /sys/kern/kern_resource.c shows what is going on.
It sums up how much time this process has used, sums up the ticks,
and distributes the total time over the ticks.  Thus, if you get a
clock tick accounted to system time and at the same time not one to
user time and the total time consumed hasn't changed much, the user
time proportion can decrease.

For a while I thought that the sum of the system time and the user
time would monotonically increase, but that appears not to be the
case either, at least on NetBSD/hp300.  I tweaked your original
program and ran it for a while, and suddenly it printed:

0 + 303763
0 + 305256
0 + 306344
0 + 297427
Decreasing time: 0 + 306344 vs 0 + 297427
0 + 299611
0 + 300696
0 + 301752

The tweaked program can be found below.

Strange...  I wonder: can it be that microtime() and thus
gettimeofday() isn't always monotonically increasing? (...)  Yep,
that appears to be the problem.  It appears that NetBSD/hp300's
microtime is slightly broken, I get lots of these from my test
program which I've included below when I run it on one of our
hp433's:

Whoa! Decreasing time: 880054445 + 499972 vs 880054445 + 490000
Whoa! Decreasing time: 880054445 + 529972 vs 880054445 + 520000
Whoa! Decreasing time: 880054446 + 149972 vs 880054446 + 140000
Whoa! Decreasing time: 880054447 + 779972 vs 880054447 + 770000
Whoa! Decreasing time: 880054448 + 279972 vs 880054448 + 270000
Whoa! Decreasing time: 880054448 + 299972 vs 880054448 + 290000

Oh, well, more work for our beloved portmaster, I think... (Yes,
I've UTSL'ed /sys/arch/hp300/hp300/clock.c, but the source isn't
quite with me today, I think...  ;-)

Anyway, this latter problem with gettimeofday() returning non-
monotonically increasing values doesn't appear to exist on either of
NetBSD/sparc, NetBSD/i386, NetBSD/pmax(1.2) or NetBSD/vax.


- H=E5vard

----Next_Part(Thu_Nov_20_21:09:20_1997)--
Content-Type: Text/Plain; charset=us-ascii
Content-Transfer-Encoding: 7bit
Content-Description: "rutest.c"

#include <sys/time.h>
#include <sys/resource.h>
#include <unistd.h>
#define   RUSAGE_SELF     0
main()
{
        struct rusage my_usage;
        int i,j;
	int usec, sec, p_usec, p_sec;

        for(i=0;i<1000;i++) {
                if( getrusage( RUSAGE_SELF, &my_usage ) < 0 ) {
                        perror( "show" );
                        exit( 1 );
                } else {
			usec =  my_usage.ru_utime.tv_usec + 
				my_usage.ru_stime.tv_usec;
			sec =   my_usage.ru_utime.tv_sec + 
				my_usage.ru_stime.tv_sec;
			if (usec >= 1000000) {
				usec -= 1000000;
				sec++;
			}
			printf("%d + %d\n", sec, usec);
			if (i != 0) {
				if (sec == p_sec && /* XXX, good enough... */
				    p_usec > usec) {
					printf(
"Decreasing time: %d + %d vs %d + %d\n", p_sec, p_usec, sec, usec);
				}
			}
			p_sec = sec;
			p_usec = usec;
                }
                sleep( 1 );
        }
}

----Next_Part(Thu_Nov_20_21:09:20_1997)--
Content-Type: Text/Plain; charset=us-ascii
Content-Transfer-Encoding: 7bit
Content-Description: "todtest.c"

#include <sys/time.h>

#define LOOPCOUNT 1000000

main()
{
	struct timeval now, last;
	int i;

	for (i = 0; i<LOOPCOUNT; i++) {
		gettimeofday(&now, NULL);
		if (i != 0 &&
		    now.tv_sec == last.tv_sec &&
		    now.tv_usec < last.tv_usec)
		{
			printf("Whoa! Decreasing time: %d + %d vs %d + %d\n",
				last.tv_sec, last.tv_usec,
				now.tv_sec, now.tv_usec);
		}
		last = now;
	}
	return(0);
}

----Next_Part(Thu_Nov_20_21:09:20_1997)----