>Number:         34678
>Category:       kern
>Synopsis:       SA fails to set signotify when returning from sleep
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    kern-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Sun Oct 01 02:15:01 +0000 2006
>Originator:     Bucky Katz
>Release:        NetBSD 4.99.3
>Organization:
Picovex
>Environment:
System: NetBSD katz.picovex.com 4.99.3 NetBSD 4.99.3 (BUCKY) #5: Fri Sep 29 17:38:54 PDT 2006 root@katz.picovex.com:/usr/obj/sys/arch/evbarm/compile/BUCKY evbarm
Architecture: evbarm
Machine: OSK5912
>Description:

>How-To-Repeat:

compile the included sleep_test.c and run it as described

gcc -o a.out sleep_test.c -lpthread


These are test results that show that the SIGEV_SA path for itimerfire() needs
to have a signotify() in it.

The test code sets the RRTIME low enough so that with only two threads, where
the child is infinite looping and the main is calling nanosleep(), the wakeup
latency should never be more than 1*RRTIME rounded up to tick granualarity,
which is 10ms.

Original kernel, child thread loops doing nothing.  The latency is obviously
longer than expected given test setup.  The itimer upcall is not being
delivered to the app process in time.

# ./a.out 1 50000 0
requested nanosleep for 50000 microseconds, really slept 130470 microseconds
# ./a.out 1 50000 0
requested nanosleep for 50000 microseconds, really slept 133530 microseconds
# ./a.out 1 50000 0
requested nanosleep for 50000 microseconds, really slept 109233 microseconds


Original kernel, child thread loops calling gettimeofday().  By having the
child make a system call instead of spinning, the end of the system call has
an AST check and so delivers the itimer upcall on time.

# ./a.out 1 50000 1
requested nanosleep for 50000 microseconds, really slept 54935 microseconds
# ./a.out 1 50000 1
requested nanosleep for 50000 microseconds, really slept 57777 microseconds
# ./a.out 1 50000 1
requested nanosleep for 50000 microseconds, really slept 56876 microseconds


This is with a modified kernel with signotify() change in itimerfire()
SIGEV_SA path.  Notice that the latency values are now always within a RRTIME
interval.


# ./a.out 0 50000 0
requested nanosleep for 50000 microseconds, really slept 51600 microseconds
# ./a.out 0 50000 0
requested nanosleep for 50000 microseconds, really slept 50380 microseconds
# ./a.out 1 50000 0
requested nanosleep for 50000 microseconds, really slept 52114 microseconds
# ./a.out 1 50000 0
requested nanosleep for 50000 microseconds, really slept 56638 microseconds
# ./a.out 1 50000 0
requested nanosleep for 50000 microseconds, really slept 58925 microseconds
# ./a.out 1 50000 0
requested nanosleep for 50000 microseconds, really slept 55740 microseconds
# ./a.out 1 50000 1
requested nanosleep for 50000 microseconds, really slept 53941 microseconds
# ./a.out 1 50000 1
requested nanosleep for 50000 microseconds, really slept 58915 microseconds
# ./a.out 1 50000 1
requested nanosleep for 50000 microseconds, really slept 58624 microseconds

-----     cut here for sleep_test.c     -----

#include <sys/time.h>
#include <pthread.h>
#include <stdio.h>
#include <sys/resource.h>

static int child_threads_call_gettimeofday;

void *th(void *arg)
{
	pthread_setname_np(pthread_self(), "dummy%d", (int)arg);

	for (;;) {
		if (child_threads_call_gettimeofday) {
			/* without the SA fix to call signotify(), an infinite
			   loop by the threads running this function will
			   result in late wakeups to the nanosleep called by
			   the main function.  if the loop makes a system
			   call instead of doing nothing, then the wakeup
			   is not late, showing that the ast is delivered on
			   time because asts are always run after system calls */
			struct timeval tv;
			gettimeofday(&tv,NULL);
		}
	}
}

int main(int argc, char *argv[])
{
	struct timeval tv_before, tv_after;
	uint32_t delta;
	int nrt;
	uint32_t timeout;
	int i;
	struct timespec rqt;

	if (argc!=4) 
	{
		fprintf(stderr,"Usage: %s <number of threads> <timeout (ms)><child threads call gettimeofday()>\n", argv[0]);
		fflush(stderr);
		return -1;
	}

	nrt=atoi(argv[1]);
	timeout=atoi(argv[2]);
	child_threads_call_gettimeofday=atoi(argv[3]);
	rqt.tv_sec = 0;
	rqt.tv_nsec = 1000*timeout;

	// make round robin time short enough that we should get a chance
	// to run again soon after our sleep is over
	setenv("PTHREAD_RRTIME", "10", 1);

	pthread_setname_np(pthread_self(), "main", NULL);

	for (i=0;i<nrt;i++)
	{
		pthread_t tmp;
		pthread_create(&tmp,NULL,th,i);
	}

	gettimeofday(&tv_before,NULL);
	nanosleep(&rqt, NULL);
	gettimeofday(&tv_after,NULL);

	delta = (tv_after.tv_sec - tv_before.tv_sec);
	if (delta > 0) {
		// convert sec to microseconds
		delta *= (1000 * 1000);
	}
	delta += (tv_after.tv_usec - tv_before.tv_usec);
	printf("requested nanosleep for %lu microseconds, really slept %lu microseconds\n",timeout,delta);
}

>Fix:
==== src/sys/kern/kern_time.c#3 - src/sys/kern/kern_time.c ====
@@ -1470,6 +1470,7 @@
        } else if (pt->pt_ev.sigev_notify == SIGEV_SA && (p->p_flag & P_SA)) {
                /* Cause the process to generate an upcall when it returns. */

+               signotify(p);
                if (p->p_userret == NULL) {
                        /*
                         * XXX stop signals can be processed inside tsleep,