[9fans] fossil periodic thread does zero sleep()

[9fans] fossil periodic thread does zero sleep()

[cinap_lenrek]

Just noticed that the fsMetaFlush periodic thread in my fossil
pushes the syscall count in stats for some time now. Here is no
real load on the system and anything else works fine.

The questions are:

How to print double precisition floating point variables in acid?

Can anybody explain this fossil behaviour from the periodic code?

I checked that p->msec is 1000 in acid.

static void
periodicThread(void *a)
{
	Periodic *p = a;
	double t, ct, ts;

	vtThreadSetName("periodic");

	ct = nsec()*1e-6;
	t = ct + p->msec;

	for(;;){
		/* skip missed */
		while(t <= ct)
			t += p->msec;

		ts = t - ct;
		if(ts > 1000)
			ts = 1000;
		sleep(ts);
		ct = nsec()*1e-6;
		vtLock(p->lk);
		if(p->die){
			vtUnlock(p->lk);
			break;
		}
		if(t <= ct){
			p->f(p->a);
			t += p->msec;
		}
		vtUnlock(p->lk);
	}
	periodicFree(p);
}

Here is the stacktrace:

sleep()+0x7 /sys/src/libc/9syscall/sleep.s:5
periodicThread(a=0x8e8a60)+0xc9 /sys/src/cmd/fossil/periodic.c:70
	p=0x8e8a60
	ct=0x6721cc5a
	t=0x67601764
	ts=0x0
vtThread(rock=0x8e8a60,f=0x23291)+0x30 /sys/src/liboventi/plan9-thread.c:63
periodicAlloc(f=0x14933,a=0x7f690,msec=0x3e8)+0x54 /sys/src/cmd/fossil/periodic.c:30
	p=0x8e8a60
fsOpen(mode=0x1,file=0x5ce08,z=0x5ce88,ncache=0x3e8)+0x50f /sys/src/cmd/fossil/fs.c:125
	fd=0x9
	disk=0x7d4d0
	fs=0x7f690
	super=0x1
	b=0x817f0
	oscore=0x7d450
	bs=0x5ce88
fsysOpen(argv=0xdfffee88,argc=0x0,name=0x5ca2d)+0x12b /sys/src/cmd/fossil/9fsys.c:1568
	usage=0x3e219
	ncache=0x3e8
	noventi=0x0
	wstatallow=0x0
	noperm=0x0
	noauth=0x0
	rflag=0x1
	_argc=0xfdf00063
	_args=0x3e244
	p=0x5ca3e
	fsys=0x5aa08
fsysXXX(argv=0xdfffee80,name=0x5ca2d,argc=0x3)+0xec /sys/src/cmd/fossil/9fsys.c:1749
	i=0x2
	r=0x245a8
	fsys=0x2449f
cmdFsys(argc=0x4,argv=0xdfffee78)+0x13c /sys/src/cmd/fossil/9fsys.c:1813
	usage=0x3e399
	_argc=0x54d00005
	_args=0x32b4a
	fsys=0x5
cliExec(buf=0x51190)+0xe0 /sys/src/cmd/fossil/Ccli.c:58
	p=0x5ca28
	argv=0x5ca28
	argc=0x5
	i=0x8
	r=0x1
main(argv=0xdfffef74,argc=0x0)+0x15a /sys/src/cmd/fossil/fossil.c:129
	cmd=0x511d0
	tflag=0x0
	ncmd=0x5
	_argc=0x63
	_args=0x3e7ab
	p=0xdfffefba
	i=0x1
_main+0x31 /sys/src/libc/386/main9.s:16

--
cinap

Re: [9fans] fossil periodic thread does zero sleep()

[erik quanstrom]

> Can anybody explain this fossil behaviour from the periodic code?

what if 0 < t - ct < 1?

wouldn't it be a good idea to replace the doubles with vlongs?
and replace *1e-6 with /1000000?  that would make 0 < t - ct < 1
impossible.

- erik

Re: [9fans] fossil periodic thread does zero sleep()

[cinap_lenrek]

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

This is actualy very interesting. Riped the parts from periodic.c
to play a with the code to see how it reacts to some changes.

The code below reproduces the problem:

sleep()+0x7 /sys/src/libc/9syscall/sleep.s:5
periodicThread(msec=0x3e8)+0xb2 /tmp/a.c:21
	ct=0x47a68e5b
	t=0x47e50e4d
	ts=0x0
main()+0x10 /tmp/a.c:32
_main+0x31 /sys/src/libc/386/main9.s:16


The zerosleeps go away if one uncomments the foo print. It also
goes away if one makes the sleep one milli second longer by
changing ts to ts+1.

I would love if anybody gives a good explaination of this bug
and how to fix it :-)

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

static void
periodicThread(int msec)
{
	double t, ct, ts;

	ct = nsec()*1e-6;
	t = ct + msec;

	for(;;){
		/* skip missed */
		while(t <= ct)
			t += msec;

		ts = t - ct;
		if(ts > 1000)
			ts = 1000;
		sleep(ts);
		ct = nsec()*1e-6;
		if(t <= ct){
//			print("foo!\n");
			t += msec;
		}
	}
}

void
main(int argc, char *argv[])
{
	periodicThread(1000);
}

[-- Attachment #2: Type: message/rfc822, Size: 2176 bytes --]

From: erik quanstrom <quanstro@quanstro.net>
To: 9fans@9fans.net
Subject: Re: [9fans] fossil periodic thread does zero sleep()
Date: Sun, 22 Mar 2009 19:41:24 -0400
Message-ID: <959ad71b3d677ea98c0e6b2ef28db2dd@quanstro.net>

> Can anybody explain this fossil behaviour from the periodic code?

what if 0 < t - ct < 1?

wouldn't it be a good idea to replace the doubles with vlongs?
and replace *1e-6 with /1000000?  that would make 0 < t - ct < 1
impossible.

- erik

Re: [9fans] fossil periodic thread does zero sleep()

[erik quanstrom]

what is your HZ set at?  after chasing a few bugs like this,
i've set HZ=1000.  actually i first saw the idea in sam hopins'
work  there's no performance drag and 1 ms
sleeps do actually sleep.

- erik

Re: [9fans] fossil periodic thread does zero sleep()

[cinap_lenrek]

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

sorry for ignoring your post. avoiding a zero sleep is not the
only problem i think, but the algorythm seems to get in some feedback
loop where it starts sleeping shorter and shorter. i see thousands
of zero sleep calls with this thing and the stats graph for syscalls
makes a big bump and i would really like to understand why :)

--
cinap

[-- Attachment #2: Type: message/rfc822, Size: 2176 bytes --]

From: erik quanstrom <quanstro@quanstro.net>
To: 9fans@9fans.net
Subject: Re: [9fans] fossil periodic thread does zero sleep()
Date: Sun, 22 Mar 2009 19:41:24 -0400
Message-ID: <959ad71b3d677ea98c0e6b2ef28db2dd@quanstro.net>

> Can anybody explain this fossil behaviour from the periodic code?

what if 0 < t - ct < 1?

wouldn't it be a good idea to replace the doubles with vlongs?
and replace *1e-6 with /1000000?  that would make 0 < t - ct < 1
impossible.

- erik

Re: [9fans] fossil periodic thread does zero sleep()

[cinap_lenrek]

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

I have no idea what HZ is used on my kernel, but i think
i understand the problem now.

I still can reproduce it with this:

	double t, ct, ts;

	ct = nsec()*1e-6;
	t = ct + msec;

	for(;;){
		ts = t - ct;
		sleep(ts);
		ct = nsec()*1e-6;
		if(t <= ct){
			t += msec;
		}
	}

The problem is that when sleep is a little bit too fast on every round,
t will never catch up with ct. so it sleeps shorter and shorter until
t - ct < 1.

It all works when changing t += msec to t = ct + msec. It may still
do a zero sleep, but the error will not add up.

making new kernel...

--
cinap

[-- Attachment #2: Type: message/rfc822, Size: 2133 bytes --]

From: erik quanstrom <quanstro@quanstro.net>
To: 9fans@9fans.net
Subject: Re: [9fans] fossil periodic thread does zero sleep()
Date: Sun, 22 Mar 2009 20:24:17 -0400
Message-ID: <fb31fd1a5a64c0bf6f85af88838face3@quanstro.net>

what is your HZ set at?  after chasing a few bugs like this,
i've set HZ=1000.  actually i first saw the idea in sam hopins'
work  there's no performance drag and 1 ms
sleeps do actually sleep.

- erik

Re: [9fans] fossil periodic thread does zero sleep()

[erik quanstrom]

> The problem is that when sleep is a little bit too fast on every round,
> t will never catch up with ct. so it sleeps shorter and shorter until
> t - ct < 1.
>
> It all works when changing t += msec to t = ct + msec. It may still
> do a zero sleep, but the error will not add up.

why not just get rid of the double?  then you will never zero sleep.

- erik

Re: [9fans] fossil periodic thread does zero sleep()

[ron minnich]

This is from mobile so I can not look at code much but if you are
converting nanoseconds to milliseconds you multiply by 1e6 not 1e-6 I
think.

Ron

On 3/22/09, cinap_lenrek@gmx.de <cinap_lenrek@gmx.de> wrote:
> This is actualy very interesting. Riped the parts from periodic.c
> to play a with the code to see how it reacts to some changes.
>
> The code below reproduces the problem:
>
> sleep()+0x7 /sys/src/libc/9syscall/sleep.s:5
> periodicThread(msec=0x3e8)+0xb2 /tmp/a.c:21
> 	ct=0x47a68e5b
> 	t=0x47e50e4d
> 	ts=0x0
> main()+0x10 /tmp/a.c:32
> _main+0x31 /sys/src/libc/386/main9.s:16
>
>
> The zerosleeps go away if one uncomments the foo print. It also
> goes away if one makes the sleep one milli second longer by
> changing ts to ts+1.
>
> I would love if anybody gives a good explaination of this bug
> and how to fix it :-)
>
> #include <u.h>
> #include <libc.h>
>
> static void
> periodicThread(int msec)
> {
> 	double t, ct, ts;
>
> 	ct = nsec()*1e-6;
> 	t = ct + msec;
>
> 	for(;;){
> 		/* skip missed */
> 		while(t <= ct)
> 			t += msec;
>
> 		ts = t - ct;
> 		if(ts > 1000)
> 			ts = 1000;
> 		sleep(ts);
> 		ct = nsec()*1e-6;
> 		if(t <= ct){
> //			print("foo!\n");
> 			t += msec;
> 		}
> 	}
> }
>
> void
> main(int argc, char *argv[])
> {
> 	periodicThread(1000);
> }
>

--
Sent from my mobile device

Re: [9fans] fossil periodic thread does zero sleep()

[ron minnich]

Sigh ... Do not send mail when tired. Was thinking of different problem.

Ron

On 3/22/09, ron minnich <rminnich@gmail.com> wrote:
> This is from mobile so I can not look at code much but if you are
> converting nanoseconds to milliseconds you multiply by 1e6 not 1e-6 I
> think.
>
> Ron
>
> On 3/22/09, cinap_lenrek@gmx.de <cinap_lenrek@gmx.de> wrote:
>> This is actualy very interesting. Riped the parts from periodic.c
>> to play a with the code to see how it reacts to some changes.
>>
>> The code below reproduces the problem:
>>
>> sleep()+0x7 /sys/src/libc/9syscall/sleep.s:5
>> periodicThread(msec=0x3e8)+0xb2 /tmp/a.c:21
>> 	ct=0x47a68e5b
>> 	t=0x47e50e4d
>> 	ts=0x0
>> main()+0x10 /tmp/a.c:32
>> _main+0x31 /sys/src/libc/386/main9.s:16
>>
>>
>> The zerosleeps go away if one uncomments the foo print. It also
>> goes away if one makes the sleep one milli second longer by
>> changing ts to ts+1.
>>
>> I would love if anybody gives a good explaination of this bug
>> and how to fix it :-)
>>
>> #include <u.h>
>> #include <libc.h>
>>
>> static void
>> periodicThread(int msec)
>> {
>> 	double t, ct, ts;
>>
>> 	ct = nsec()*1e-6;
>> 	t = ct + msec;
>>
>> 	for(;;){
>> 		/* skip missed */
>> 		while(t <= ct)
>> 			t += msec;
>>
>> 		ts = t - ct;
>> 		if(ts > 1000)
>> 			ts = 1000;
>> 		sleep(ts);
>> 		ct = nsec()*1e-6;
>> 		if(t <= ct){
>> //			print("foo!\n");
>> 			t += msec;
>> 		}
>> 	}
>> }
>>
>> void
>> main(int argc, char *argv[])
>> {
>> 	periodicThread(1000);
>> }
>>
>
> --
> Sent from my mobile device
>

--
Sent from my mobile device