From owner-freebsd-hackers Mon Dec 2 7:18:51 2002 Delivered-To: freebsd-hackers@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id EB4BC37B401 for ; Mon, 2 Dec 2002 07:18:40 -0800 (PST) Received: from pcwin002.win.tue.nl (pcwin002.win.tue.nl [131.155.71.72]) by mx1.FreeBSD.org (Postfix) with ESMTP id ED24B43E4A for ; Mon, 2 Dec 2002 07:18:39 -0800 (PST) (envelope-from stijn@pcwin002.win.tue.nl) Received: from pcwin002.win.tue.nl (localhost [127.0.0.1]) by pcwin002.win.tue.nl (8.12.6/8.12.6) with ESMTP id gB2FIH3E093949 for ; Mon, 2 Dec 2002 16:18:17 +0100 (CET) (envelope-from stijn@pcwin002.win.tue.nl) Received: (from stijn@localhost) by pcwin002.win.tue.nl (8.12.6/8.12.6/Submit) id gB2FIGv9093948 for freebsd-hackers@freebsd.org; Mon, 2 Dec 2002 16:18:16 +0100 (CET) Date: Mon, 2 Dec 2002 16:18:16 +0100 From: Stijn Hoop To: freebsd-hackers@freebsd.org Subject: [nephtes@openface.ca: [Xmame] Use of usleep() with -sleepidle] Message-ID: <20021202151816.GJ83264@pcwin002.win.tue.nl> Mime-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha1; protocol="application/pgp-signature"; boundary="MsEL38XAg4rx1uDx" Content-Disposition: inline User-Agent: Mutt/1.4i X-Bright-Idea: Let's abolish HTML mail! Sender: owner-freebsd-hackers@FreeBSD.ORG Precedence: bulk List-ID: List-Archive: (Web Archive) List-Help: (List Instructions) List-Subscribe: List-Unsubscribe: X-Loop: FreeBSD.ORG --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 ----- From: Steve Freeland 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 #include #include 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