Skip site navigation (1)Skip section navigation (2) 
Date:      Mon, 2 Dec 2002 16:18:16 +0100
From:      Stijn Hoop <stijn@win.tue.nl>
To:        freebsd-hackers@freebsd.org
Subject:   [nephtes@openface.ca: [Xmame] Use of usleep() with -sleepidle]
Message-ID:  <20021202151816.GJ83264@pcwin002.win.tue.nl>
next in thread | raw e-mail | index | archive | help 

--MsEL38XAg4rx1uDx
Content-Type: multipart/mixed; boundary="9/GiYV45wF7IL3Iq"
Content-Disposition: inline


--9/GiYV45wF7IL3Iq
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
Content-Transfer-Encoding: quoted-printable

Hi,

Summary: this is going to be a rather long email about the timing of various
_sleep functions, compared to the same on Linux.

I ran across this at the xmame mailing list, and I have seen some
interesting results.

First the original mail which Steve sent, which will explain the question:

----- Forwarded message from Steve Freeland <nephtes@openface.ca> -----

From: Steve Freeland <nephtes@openface.ca>
Date: Sun, 1 Dec 2002 23:17:18 -0500
Subject: [Xmame] Use of usleep() with -sleepidle

	So in the course of testing the next release of NetMAME (Real Soon
Now!) I had a look at how -sleepidle was implemented.  Turns out it works
by calling usleep() in 0.1 ms increments.
	The thing is, usleep() has a (relatively) huge overhead.  I did
some testing (see below) and it turns out that you can't really usleep()
for less than 20 ms, for all practical purposes, at least on my system
(i386 Linux 2.4).  I assumed the difference was due to usleep() being
based on using SIGALM, but nanosleep(), which supposedly isn't,
seems to have exactly the same precision (or lack thereof), so who knows.
	Anyways, one possible alternative is using select() instead (with
no fd sets, just a timeout value), which seems to have a lower overhead --
about 10 ms, which is still large but at least is less than the duration
of one emulated frame.
	I don't know how much this would benefit other platforms --
I tried on an OpenBSD machine (some sort of i386, don't have details
about the hardware) and the minimum overhead is about the same (20 ms) for
both calls.  I've attached the program I used to test this in case anyone
wants to try it out on their systems (I'd be especially curious to see
what the results are for people which some sort of low-latency kernel.)
	So: anyone see a reason why the usleep() calls shouldn't be
replaced by select()s, for benefits where they may be found?

----- End forwarded message -----

Steve attached the program I also attach. Of course I was interested in
running times on FreeBSD so I ran it on my fairly -STABLE box, an
Athlon XP1700+ (I'm assuming CPU speed is the only relevant attribute
here, please correct me if I'm wrong). The result is attached, as
'sleep-bsd-1700.log'. Others on the list did the same, using their
various Linux boxes, and this is where it got interesting. Their logs
are attached as well, as sleep-lnx-*.log based on CPU speed [1].

One had an Athlon 1400XP, and got the following for the select speeds:

%%%
Testing _select_sleep (x 1000), delay 8
Total time: 9999.906000 ms; unit time: 9.999906 ms; estimated overhead: 1.9=
99906 ms
%%%

Someone else had an Athlon Thunderbird 1.2Ghz, and got the following:

%%%
Testing _select_sleep (x 1000), delay 8
Total time: 8276.960000 ms; unit time: 8.276960 ms; estimated overhead: 0.2=
76960 ms
%%%

(admittedly that person had applied some kernel patches).

Compared to my 1700XP, that's a factor 6 slower than the slowest Linux case
on a lesser processor:

%%%
Testing _select_sleep (x 1000), delay 8
Total time: 20000.027000 ms; unit time: 20.000027 ms; estimated overhead: 1=
2.000027 ms
%%%

What's going on here? Is our select really that much slower, or is the prog=
ram
measuring the wrong values, or doesn't this speed make a difference in
'real-world' applications, or what?

--Stijn

[1] Yes I know an Athlon 1400XP isn't 1400 MHz but that's not really releva=
nt
    here. I'm doing a comparison, not a real numbercrunching benchmark.

--=20
SIGSIG -- signature too long (core dumped)

--9/GiYV45wF7IL3Iq
Content-Type: text/plain; charset=us-ascii
Content-Disposition: attachment; filename="sleep.c"

#include <sys/time.h>
#include <unistd.h>
#include <stdio.h>

static int
_tv_subtract(struct timeval *tv1, struct timeval *tv2)
{
    int result;
    result = (tv1->tv_sec - tv2->tv_sec) * 1000000;
    result += (tv1->tv_usec - tv2->tv_usec);
    return result;
}

void
_select_sleep(unsigned usec)
{
    struct timeval delay = { usec / (1000 * 1000), usec % (1000 * 1000) };
    select(0, NULL, NULL, NULL, &delay);
}

void
_usleep_sleep(unsigned usec)
{
    usleep(usec);
}

void
_nanosleep_sleep(unsigned usec)
{
    struct timespec delay = { (usec * 1000) / (1000 * 1000 * 1000),
			      (usec * 1000) % (1000 * 1000 * 1000) };
    nanosleep(&delay, NULL);
}

typedef void (*sleep_fn_t)(unsigned);
#define TEST_COUNT 1000

void
main()
{
    unsigned i, j, k;
    unsigned delays[] = { 3, 8, 13, 18, 23, 28 };  /* milliseconds */
    sleep_fn_t sleep_fn[] = { _select_sleep,
			      _usleep_sleep,
			      _nanosleep_sleep };
    const char *sleep_fn_name[] = { "_select_sleep",
				    "_usleep_sleep",
				    "_nanosleep_sleep" };
    struct timeval start_time, end_time;

    for (i = 0; i < sizeof(delays) / sizeof(delays[0]); i++) {
	for (j = 0; j < sizeof(sleep_fn) / sizeof(sleep_fn[0]); j++) {
	    double total_ms;
	    printf("Testing %s (x %d), delay %d\n",
		   sleep_fn_name[j],
		   TEST_COUNT,
		   delays[i]);
	    gettimeofday(&start_time, NULL);
	    for (k = 0; k < TEST_COUNT; k++) {
		(*sleep_fn[j])(delays[i] * 1000);
	    }
	    gettimeofday(&end_time, NULL);
	    total_ms = (double)_tv_subtract(&end_time, &start_time) / 1000;
	    printf("Total time: %f ms; unit time: %f ms; estimated overhead: %f ms\n\n",
		   (double)total_ms,
		   (double)total_ms / (double)TEST_COUNT,
		   (double)total_ms / (double)TEST_COUNT - (double)(delays[i]));
	}
    }
}

--9/GiYV45wF7IL3Iq
Content-Type: text/plain; charset=us-ascii
Content-Disposition: attachment; filename="sleep-bsd-1700.log"

Script started on Mon Dec  2 10:17:00 2002
Testing _select_sleep (x 1000), delay 3
Total time: 19998.572000 ms; unit time: 19.998572 ms; estimated overhead: 16.998572 ms

Testing _usleep_sleep (x 1000), delay 3
Total time: 20019.964000 ms; unit time: 20.019964 ms; estimated overhead: 17.019964 ms

Testing _nanosleep_sleep (x 1000), delay 3
Total time: 20079.502000 ms; unit time: 20.079502 ms; estimated overhead: 17.079502 ms

Testing _select_sleep (x 1000), delay 8
Total time: 20000.027000 ms; unit time: 20.000027 ms; estimated overhead: 12.000027 ms

Testing _usleep_sleep (x 1000), delay 8
Total time: 20000.026000 ms; unit time: 20.000026 ms; estimated overhead: 12.000026 ms

Testing _nanosleep_sleep (x 1000), delay 8
Total time: 20000.018000 ms; unit time: 20.000018 ms; estimated overhead: 12.000018 ms

Testing _select_sleep (x 1000), delay 13
Total time: 30010.159000 ms; unit time: 30.010159 ms; estimated overhead: 17.010159 ms

Testing _usleep_sleep (x 1000), delay 13
Total time: 30000.072000 ms; unit time: 30.000072 ms; estimated overhead: 17.000072 ms

Testing _nanosleep_sleep (x 1000), delay 13
Total time: 30000.098000 ms; unit time: 30.000098 ms; estimated overhead: 17.000098 ms

Testing _select_sleep (x 1000), delay 18
Total time: 30000.092000 ms; unit time: 30.000092 ms; estimated overhead: 12.000092 ms

Testing _usleep_sleep (x 1000), delay 18
Total time: 30000.119000 ms; unit time: 30.000119 ms; estimated overhead: 12.000119 ms

Testing _nanosleep_sleep (x 1000), delay 18
Total time: 30000.117000 ms; unit time: 30.000117 ms; estimated overhead: 12.000117 ms

Testing _select_sleep (x 1000), delay 23
Total time: 40000.193000 ms; unit time: 40.000193 ms; estimated overhead: 17.000193 ms

Testing _usleep_sleep (x 1000), delay 23
Total time: 40000.180000 ms; unit time: 40.000180 ms; estimated overhead: 17.000180 ms

Testing _nanosleep_sleep (x 1000), delay 23
Total time: 40000.178000 ms; unit time: 40.000178 ms; estimated overhead: 17.000178 ms

Testing _select_sleep (x 1000), delay 28
Total time: 40000.223000 ms; unit time: 40.000223 ms; estimated overhead: 12.000223 ms

Testing _usleep_sleep (x 1000), delay 28
Total time: 40010.165000 ms; unit time: 40.010165 ms; estimated overhead: 12.010165 ms

Testing _nanosleep_sleep (x 1000), delay 28
Total time: 40000.189000 ms; unit time: 40.000189 ms; estimated overhead: 12.000189 ms


Script done on Mon Dec  2 10:26:00 2002

--9/GiYV45wF7IL3Iq
Content-Type: text/plain; charset=us-ascii
Content-Disposition: attachment; filename="sleep-lnx-1200.log"

Testing _select_sleep (x 1000), delay 3
Total time: 3199.437000 ms; unit time: 3.199437 ms; estimated overhead: 0.199437 ms

Testing _usleep_sleep (x 1000), delay 3
Total time: 4031.939000 ms; unit time: 4.031939 ms; estimated overhead: 1.031939 ms

Testing _nanosleep_sleep (x 1000), delay 3
Total time: 4041.959000 ms; unit time: 4.041959 ms; estimated overhead: 1.041959 ms

Testing _select_sleep (x 1000), delay 8
Total time: 8276.960000 ms; unit time: 8.276960 ms; estimated overhead: 0.276960 ms

Testing _usleep_sleep (x 1000), delay 8
Total time: 9238.953000 ms; unit time: 9.238953 ms; estimated overhead: 1.238953 ms

Testing _nanosleep_sleep (x 1000), delay 8
Total time: 9016.961000 ms; unit time: 9.016961 ms; estimated overhead: 1.016961 ms

Testing _select_sleep (x 1000), delay 13
Total time: 13060.955000 ms; unit time: 13.060955 ms; estimated overhead: 0.060955 ms

Testing _usleep_sleep (x 1000), delay 13
Total time: 14000.955000 ms; unit time: 14.000955 ms; estimated overhead: 1.000955 ms

Testing _nanosleep_sleep (x 1000), delay 13
Total time: 14001.957000 ms; unit time: 14.001957 ms; estimated overhead: 1.001957 ms

Testing _select_sleep (x 1000), delay 18
Total time: 18000.959000 ms; unit time: 18.000959 ms; estimated overhead: 0.000959 ms

Testing _usleep_sleep (x 1000), delay 18
Total time: 18999.954000 ms; unit time: 18.999954 ms; estimated overhead: 0.999954 ms

Testing _nanosleep_sleep (x 1000), delay 18
Total time: 18999.957000 ms; unit time: 18.999957 ms; estimated overhead: 0.999957 ms

Testing _select_sleep (x 1000), delay 23
Total time: 23002.957000 ms; unit time: 23.002957 ms; estimated overhead: 0.002957 ms

Testing _usleep_sleep (x 1000), delay 23
Total time: 24000.954000 ms; unit time: 24.000954 ms; estimated overhead: 1.000954 ms

Testing _nanosleep_sleep (x 1000), delay 23
Total time: 23999.961000 ms; unit time: 23.999961 ms; estimated overhead: 0.999961 ms

Testing _select_sleep (x 1000), delay 28
Total time: 28001.033000 ms; unit time: 28.001033 ms; estimated overhead: 0.001033 ms

Testing _usleep_sleep (x 1000), delay 28
Total time: 29020.878000 ms; unit time: 29.020878 ms; estimated overhead: 1.020878 ms

Testing _nanosleep_sleep (x 1000), delay 28
Total time: 29010.958000 ms; unit time: 29.010958 ms; estimated overhead: 1.010958 ms


--9/GiYV45wF7IL3Iq
Content-Type: text/plain; charset=us-ascii
Content-Disposition: attachment; filename="sleep-lnx-1400.log"

Testing _select_sleep (x 1000), delay 3
Total time: 9999.239000 ms; unit time: 9.999239 ms; estimated overhead: 6.999239 ms

Testing _usleep_sleep (x 1000), delay 3
Total time: 19999.934000 ms; unit time: 19.999934 ms; estimated overhead: 16.999934 ms

Testing _nanosleep_sleep (x 1000), delay 3
Total time: 19999.994000 ms; unit time: 19.999994 ms; estimated overhead: 16.999994 ms

Testing _select_sleep (x 1000), delay 8
Total time: 9999.906000 ms; unit time: 9.999906 ms; estimated overhead: 1.999906 ms

Testing _usleep_sleep (x 1000), delay 8
Total time: 19999.982000 ms; unit time: 19.999982 ms; estimated overhead: 11.999982 ms

Testing _nanosleep_sleep (x 1000), delay 8
Total time: 19999.937000 ms; unit time: 19.999937 ms; estimated overhead: 11.999937 ms

Testing _select_sleep (x 1000), delay 13
Total time: 19999.960000 ms; unit time: 19.999960 ms; estimated overhead: 6.999960 ms

Testing _usleep_sleep (x 1000), delay 13
Total time: 29999.991000 ms; unit time: 29.999991 ms; estimated overhead: 16.999991 ms

Testing _nanosleep_sleep (x 1000), delay 13
Total time: 29999.932000 ms; unit time: 29.999932 ms; estimated overhead: 16.999932 ms

Testing _select_sleep (x 1000), delay 18
Total time: 19999.978000 ms; unit time: 19.999978 ms; estimated overhead: 1.999978 ms

Testing _usleep_sleep (x 1000), delay 18
Total time: 29999.942000 ms; unit time: 29.999942 ms; estimated overhead: 11.999942 ms

Testing _nanosleep_sleep (x 1000), delay 18
Total time: 29999.979000 ms; unit time: 29.999979 ms; estimated overhead: 11.999979 ms

Testing _select_sleep (x 1000), delay 23
Total time: 29999.957000 ms; unit time: 29.999957 ms; estimated overhead: 6.999957 ms

Testing _usleep_sleep (x 1000), delay 23
Total time: 39999.938000 ms; unit time: 39.999938 ms; estimated overhead: 16.999938 ms

Testing _nanosleep_sleep (x 1000), delay 23
Total time: 39999.959000 ms; unit time: 39.999959 ms; estimated overhead: 16.999959 ms

Testing _select_sleep (x 1000), delay 28
Total time: 29999.981000 ms; unit time: 29.999981 ms; estimated overhead: 1.999981 ms

Testing _usleep_sleep (x 1000), delay 28
Total time: 40009.937000 ms; unit time: 40.009937 ms; estimated overhead: 12.009937 ms

Testing _nanosleep_sleep (x 1000), delay 28
Total time: 39999.960000 ms; unit time: 39.999960 ms; estimated overhead: 11.999960 ms


--9/GiYV45wF7IL3Iq
Content-Type: text/plain; charset=us-ascii
Content-Disposition: attachment; filename="sleep-lnx-2100.log"

Testing _select_sleep (x 1000), delay 3
Total time: 9992.307000 ms; unit time: 9.992307 ms; estimated
overhead: 6.992307 ms

Testing _usleep_sleep (x 1000), delay 3
Total time: 20000.074000 ms; unit time: 20.000074 ms; estimated
overhead: 17.000074 ms

Testing _nanosleep_sleep (x 1000), delay 3
Total time: 19999.948000 ms; unit time: 19.999948 ms; estimated
overhead: 16.999948 ms

Testing _select_sleep (x 1000), delay 8
Total time: 9999.769000 ms; unit time: 9.999769 ms; estimated
overhead: 1.999769 ms

Testing _usleep_sleep (x 1000), delay 8
Total time: 19999.987000 ms; unit time: 19.999987 ms; estimated
overhead: 11.999987 ms

Testing _nanosleep_sleep (x 1000), delay 8
Total time: 19999.910000 ms; unit time: 19.999910 ms; estimated
overhead: 11.999910 ms

Testing _select_sleep (x 1000), delay 13
Total time: 20000.063000 ms; unit time: 20.000063 ms; estimated
overhead: 7.000063 ms

Testing _usleep_sleep (x 1000), delay 13
Total time: 30000.445000 ms; unit time: 30.000445 ms; estimated
overhead: 17.000445 ms

Testing _nanosleep_sleep (x 1000), delay 13
Total time: 29999.321000 ms; unit time: 29.999321 ms; estimated
overhead: 16.999321 ms

Testing _select_sleep (x 1000), delay 18
Total time: 20000.218000 ms; unit time: 20.000218 ms; estimated
overhead: 2.000218 ms

Testing _usleep_sleep (x 1000), delay 18
Total time: 29999.752000 ms; unit time: 29.999752 ms; estimated
overhead: 11.999752 ms

Testing _nanosleep_sleep (x 1000), delay 18
Total time: 29999.868000 ms; unit time: 29.999868 ms; estimated
overhead: 11.999868 ms

Testing _select_sleep (x 1000), delay 23
Total time: 30000.007000 ms; unit time: 30.000007 ms; estimated
overhead: 7.000007 ms

Testing _usleep_sleep (x 1000), delay 23
Total time: 40050.524000 ms; unit time: 40.050524 ms; estimated
overhead: 17.050524 ms

Testing _nanosleep_sleep (x 1000), delay 23
Total time: 40019.371000 ms; unit time: 40.019371 ms; estimated
overhead: 17.019371 ms

Testing _select_sleep (x 1000), delay 28
Total time: 30000.384000 ms; unit time: 30.000384 ms; estimated
overhead: 2.000384 ms

Testing _usleep_sleep (x 1000), delay 28
Total time: 40019.429000 ms; unit time: 40.019429 ms; estimated
overhead: 12.019429 ms

Testing _nanosleep_sleep (x 1000), delay 28
Total time: 40000.356000 ms; unit time: 40.000356 ms; estimated
overhead: 12.000356 ms

--9/GiYV45wF7IL3Iq--

--MsEL38XAg4rx1uDx
Content-Type: application/pgp-signature
Content-Disposition: inline

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.2.1 (FreeBSD)

iD8DBQE963m4Y3r/tLQmfWcRAmr6AJwPIrPlwlQDSlmJr9+QgwE7WEbthwCgoZ+2
Vq3RmbEu0EUHB4TxsSCfRNY=
=JY1c
-----END PGP SIGNATURE-----

--MsEL38XAg4rx1uDx--

To Unsubscribe: send mail to majordomo@FreeBSD.org
with "unsubscribe freebsd-hackers" in the body of the message

Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20021202151816.GJ83264>