[Author Prev][Author Next][Thread Prev][Thread Next][Author Index][Thread Index]
Re: [Libevent-users] Strange timeout scheduling in 1.4
On Thu, Aug 4, 2011 at 22:36, Nick Mathewson <nickm@xxxxxxxxxxxxx> wrote:
> * Make no changes in the code, but suggest to people that they should
> be using EVENT_BASE_FLAG_NO_CACHE_TIME if they are running on a
> platform where time checking is very quick and they care about very
> accurate timing.
I've measures gettimeofday and clock_gettime for linux and freebsd
(file was built with -O2), time iis in nanoseconds:
Linux 2.6.24 (openvz):
darkk@kitana:~$ uname -a
Linux kitana 2.6.24-23-openvzyandex #2 SMP Fri Apr 24 18:54:48 MSD
2009 x86_64 GNU/Linux
darkk@kitana:~$ ./gettimeofday-cost
(CLOCK_REALTIME) gtod: 690.867596
(CLOCK_REALTIME) clock(mono): 685.391339
(CLOCK_REALTIME) clock(monoraw): 62.287522
(CLOCK_REALTIME) memcpy: 2.917304
(CLOCK_REALTIME) assign: 1.309508
(CLOCK_MONOTONIC) gtod: 684.626865
(CLOCK_MONOTONIC) clock(mono): 676.373822
(CLOCK_MONOTONIC) clock(monoraw): 62.847293
(CLOCK_MONOTONIC) memcpy: 2.918910
(CLOCK_MONOTONIC) assign: 1.250632
(CLOCK_PROCESS_CPUTIME_ID) gtod: 690.960662
(CLOCK_PROCESS_CPUTIME_ID) clock(mono): 673.605924
(CLOCK_PROCESS_CPUTIME_ID) clock(monoraw): 62.411515
(CLOCK_PROCESS_CPUTIME_ID) memcpy: 2.912745
(CLOCK_PROCESS_CPUTIME_ID) assign: 1.295240
Linux 2.6.32:
darkk@golem-test2:~$ uname -a ; gcc -v 2>&1 | tail -1
Linux golem-test2 2.6.32-31-server #61-Ubuntu SMP Fri Apr 8 19:44:42
UTC 2011 x86_64 GNU/Linux
gcc version 4.4.3 (Ubuntu 4.4.3-4ubuntu5)
darkk@golem-test2:~$ ./gettimeofday-cost
(CLOCK_REALTIME) gtod: 40.447892
(CLOCK_REALTIME) clock(mono): 37.522405
(CLOCK_REALTIME) memcpy: 2.502965
(CLOCK_MONOTONIC) gtod: 40.443445
(CLOCK_MONOTONIC) clock(mono): 37.513386
(CLOCK_MONOTONIC) memcpy: 2.500064
(CLOCK_PROCESS_CPUTIME_ID) gtod: 40.365945
(CLOCK_PROCESS_CPUTIME_ID) clock(mono): 37.450675
(CLOCK_PROCESS_CPUTIME_ID) memcpy: 2.496287
Linux 3.0:
darkk@darkk-ya-thinkpad $ uname -a; gcc -v 2>&1 | tail -1
Linux darkk-ya-thinkpad 3.0.0-7-generic #9-Ubuntu SMP Fri Jul 29
21:27:24 UTC 2011 x86_64 x86_64 x86_64 GNU/Linux
gcc version 4.5.2 (Ubuntu/Linaro 4.5.2-8ubuntu4)
darkk@darkk-ya-thinkpad $ ./gettimeofday-cost
(CLOCK_REALTIME) gtod: 31.854696
(CLOCK_REALTIME) clock(mono): 19.328140
(CLOCK_REALTIME) clock(monoraw): 60.396497
(CLOCK_REALTIME) memcpy: 2.092423
(CLOCK_MONOTONIC) gtod: 21.440780
(CLOCK_MONOTONIC) clock(mono): 20.001421
(CLOCK_MONOTONIC) clock(monoraw): 60.250465
(CLOCK_MONOTONIC) memcpy: 2.198552
(CLOCK_PROCESS_CPUTIME_ID) gtod: 21.392047
(CLOCK_PROCESS_CPUTIME_ID) clock(mono): 19.416045
(CLOCK_PROCESS_CPUTIME_ID) clock(monoraw): 60.534821
(CLOCK_PROCESS_CPUTIME_ID) memcpy: 2.062982
FreeBSD 8.2
[darkk@daisy2 ~]$ uname -a ; gcc -v 2>&1 | tail -1
FreeBSD daisy2 8.2-STABLE FreeBSD 8.2-STABLE #0 r221983M: Mon Jul 11
18:02:06 MSD 2011
root@...:/place/mkdump_workdir/obj/place/GIT-repos/FreeBSD-8-stable/sys/stable8-amd64-dtrace
amd64
gcc version 4.2.2 20070831 prerelease [FreeBSD]
[darkk@daisy2 ~]$ ./gettimeofday-cost
(CLOCK_REALTIME) gtod: 1318.387523
(CLOCK_REALTIME) clock(mono): 1326.159892
(CLOCK_REALTIME) memcpy: 2.132994
(CLOCK_MONOTONIC) gtod: 1305.614699
(CLOCK_MONOTONIC) clock(mono): 1294.905029
(CLOCK_MONOTONIC) memcpy: 2.132156
> * Probe somehow (probably at runtime) to determine whether we're
> someplace that has fast time checking or not.
I think, that libevent may provide some sort of heuristics to check
speed of timing and let the user decide. But I see, that gettimeofday
is still 10 times more expensive than simple memcpy from cached value
(and 40 times more expensive than struct assignment via operator=), so
I don't think, that disabling value caching is the best option for
absolutely every workload.
On the other hand, this microbenchmark may be pointless because of,
for example, CPU caches - I'm not benchmarking guru at all.
2.6.24 result is really surprising me.
--
WBRBW, Leonid Evdokimov
xmpp:leon@xxxxxxxxxxxx && http://darkk.net.ru
tel:+79816800702 && tel:+79050965222
#define _USE_BSD 1 // for timersub() on Linux
#include <stdlib.h>
#include <stdio.h>
#include <assert.h>
#include <sys/time.h>
#include <time.h>
#include <string.h>
#include <stdint.h>
#include <sched.h>
volatile struct timeval reference = { 1312617263, 123456 };
void gettimeofday_memcpy(struct timeval* tv, struct timezone* tz)
{
(void)tz;
memcpy(tv, &reference, sizeof(struct timeval));
}
void test(const char* csname, int clocksource, int count)
{
struct timespec begin, end, ahi;
struct timeval a;
uint64_t scale_nano = 1000 * 1000 * 1000;
uint64_t gtod_cost, monoclock_cost, memcpy_cost, monoraw_cost;
int i;
#define testcase(dest_cost, function, args) do { \
clock_gettime(clocksource, &begin); \
for (i = 0; i < count; ++i) { \
function args; \
} \
clock_gettime(clocksource, &end); \
dest_cost = (end.tv_sec - begin.tv_sec)*scale_nano + (end.tv_nsec - begin.tv_nsec); \
} while (0)
testcase(gtod_cost, gettimeofday, (&a, 0));
testcase(memcpy_cost, gettimeofday_memcpy, (&a, 0));
testcase(monoclock_cost, clock_gettime, (CLOCK_MONOTONIC, &ahi));
#ifdef CLOCK_MONOTONIC_RAW
testcase(monoraw_cost, clock_gettime, (CLOCK_MONOTONIC_RAW, &ahi));
#endif // CLOCK_MONOTONIC_RAW
printf("(%s) gtod: %f\n", csname, (double)1.0 * gtod_cost / count);
printf("(%s) clock(mono): %f\n", csname, (double)1.0 * monoclock_cost / count);
#ifdef CLOCK_MONOTONIC_RAW
printf("(%s) clock(monoraw): %f\n", csname, (double)1.0 * monoraw_cost / count);
#endif
printf("(%s) memcpy: %f\n", csname, (double)1.0 * memcpy_cost / count);
}
#define testmacro(cs, count) test(#cs, cs, count)
int main(int argc, char* argv[]) {
int count = 1000000;
if (argc > 1) {
count = atoi(argv[1]);
}
testmacro(CLOCK_REALTIME, count);
testmacro(CLOCK_MONOTONIC, count);
#ifdef CLOCK_PROCESS_CPUTIME_ID
testmacro(CLOCK_PROCESS_CPUTIME_ID, count);
#endif
return 0;
}