[9fans] alarm(2) again, or is it locking ...

[9fans] alarm(2) again, or is it locking ...

[erik quanstrom]

[-- Attachment #1: Type: text/plain, Size: 1585 bytes --]

i was tracking down a locking issue that was showing up
as alarm() returning too late by up to 1/2 a second.  this is
not an issue in stock plan 9, because alarm processing
happens on all processors.  this gets around locking if
you have more than 1 cpu, and at the expense of hammering
the cachelines related to alarm.  i'd be interested in
timings done on 24-core amd machines.

anyway, the problem is due to the suprisingly slow cga
console.

these timings are based on rdtsc() subtractions around the
named areas for the simple test of cat'ing /lib/pci to the
console.  they are huge:

cycles
printing chars		482510340
scrolling			135746656968
total			137112900000

by introducing a frame buffer to avoid reading from the
cga console for scrolling (a guess based on problems with
graphics performance), we get about a 10x improvement:

printing normal chars	1080381568
scrolling			12046340760
total			13610262120

by guessing that any string >40 bytes is likely to induce scrolling,
we can redraw the whole screen once we're done.  this gives us
100/1000x improvment on our hot spots, but just 7x in run time.

printing chars		33186956
scrolling			24111480
total			1854594800

this looks like about all we can do.

by the way, is there a reason to not use the cycle counter on
archtectures that support it, or is there a reason to still maintain
sys->ticks / MACHP(0)->ticks by using the clock interrupt in
the portable code?

the alarm test program is attached.  the results should be interesting.
it does assume that HZ=1000.

- erik

[-- Attachment #2: alarm2.c --]
[-- Type: text/plain, Size: 1793 bytes --]

#include <u.h>
#include <libc.h>

enum{
	Slop	= 100,
	Slop1	= 10,
};

uint	nmiss;
uint	maxmiss;
uint	missmsec;

int
note(void*, char *err)
{
	return strstr(err, "alarm") != nil;
}

void
alarmproc(int ival)
{
	int n;
	long t[2], δt, δ;

	atnotify(note, 1);
	for(n=0;; n++){
		t[0] = nsec()/1000000ull;
		alarm(ival);

		/* evil twist: exit with alarm armed */
		if(n > 150){
			if(nmiss>0)
				fprint(2, 	"nmiss = %d; max = %d; avg = %d\n",
					nmiss, maxmiss, missmsec/nmiss);
			exits("");
		}

		if(sleep(ival*3) != -1){
			print("sleep %d not interrupted: %d\n", n, ival*2);
			continue;
		}
		t[1] = nsec()/1000000ull;
		δt = t[1] - t[0];
	//	if(δt > ival+Slop || δt < ival-Slop)
	//		print("alarm %d inaccurate %ld want %d %ld", n, δt, ival, δt-ival);
		if(δt > ival+Slop1 || δt < ival-Slop1){
			δ = δt-ival;
			print("alarm %d inaccurate %ld want %d %ld\n", n, δt, ival, δ);
			nmiss++;
			δ = abs(δ);
			if(δ > maxmiss)
				maxmiss = δ;
			missmsec += δ;
		}
	}
}

void
main(void)
{
	int i;
	Waitmsg *w;
	static int primes[] = {
		101, 103, 107, 109, 113, 127, 131, 137, 139, 149,
		151, 157, 163, 167, 173, 179, 181, 191, 193, 197,
		199, 211, 223, 227, 229, 233, 239, 241, 251, 257,
		263, 269, 271, 277, 281, 283, 293, 307, 311, 313,
		317, 331, 337, 347, 349, 353, 359, 367, 373, 379,
		383, 389, 397, 401, 409, 419, 421, 431, 433, 439,
		443, 449, 457, 461, 463, 467, 479, 487, 491, 499,
		503, 509, 521, 523, 541, 547, 557, 563, 569, 571,
		577, 587, 593, 599, 601, 607, 613, 617, 619, 631,
		641, 643, 647, 653, 659, 661, 673, 677, 683, 691,
	};

	for(i = 0; i < nelem(primes); i++)
		if(fork() == 0)
			alarmproc(primes[i]);
	while((w = wait()) != nil)
		free(w);
	exits("");
}