Peter Eisentraut <[email protected]> writes:
> AFAICT, pg_test_timing doesn't use gettimeofday(), so this doesn't
> really address the original question.
It's not exactly hard to make it do so (see attached).
I tried this on several different machines, and my conclusion is that
gettimeofday() reports full microsecond precision on any platform
anybody is likely to be running PG on today. Even my one surviving
pet dinosaur, NetBSD 10 on PowerPC Mac (mamba), shows results like
this:
$ ./pg_test_timing
Testing timing overhead for 3 seconds.
Per loop time including overhead: 901.41 ns
Histogram of timing durations:
< us % of total count
1 10.46074 348148
2 89.51495 2979181
4 0.00574 191
8 0.00430 143
16 0.00691 230
32 0.00376 125
64 0.00012 4
128 0.00303 101
256 0.00027 9
512 0.00009 3
1024 0.00009 3
I also modified pg_test_timing to measure nanoseconds not
microseconds (second patch attached), and got this:
$ ./pg_test_timing
Testing timing overhead for 3 seconds.
Per loop time including overhead: 805.50 ns
Histogram of timing durations:
< ns % of total count
1 19.84234 739008
2 0.00000 0
4 0.00000 0
8 0.00000 0
16 0.00000 0
32 0.00000 0
64 0.00000 0
128 0.00000 0
256 0.00000 0
512 0.00000 0
1024 80.14013 2984739
2048 0.00078 29
4096 0.00658 245
8192 0.00290 108
16384 0.00252 94
32768 0.00250 93
65536 0.00016 6
131072 0.00185 69
262144 0.00008 3
524288 0.00008 3
1048576 0.00008 3
confirming that when the result changes it generally does so by 1usec.
Applying just the second patch, I find that clock_gettime on this
old hardware seems to be limited to 1us resolution, but on my more
modern machines (mac M1, x86_64) it can tick at 40ns or less.
Even a raspberry pi 4 shows
$ ./pg_test_timing
Testing timing overhead for 3 seconds.
Per loop time including overhead: 69.12 ns
Histogram of timing durations:
< ns % of total count
1 0.00000 0
2 0.00000 0
4 0.00000 0
8 0.00000 0
16 0.00000 0
32 0.00000 0
64 37.59583 16317040
128 62.38568 27076131
256 0.01674 7265
512 0.00002 8
1024 0.00000 0
2048 0.00000 0
4096 0.00153 662
8192 0.00019 83
16384 0.00001 3
32768 0.00001 5
suggesting that the clock_gettime resolution is better than 64 ns.
So I concur with Hannu that it's time to adjust pg_test_timing to
resolve nanoseconds not microseconds. I gather he's created a
patch that does more than mine below, so I'll wait for that.
regards, tom lane
diff --git a/src/include/portability/instr_time.h b/src/include/portability/instr_time.h
index a6fc1922f2..5509d23d2f 100644
--- a/src/include/portability/instr_time.h
+++ b/src/include/portability/instr_time.h
@@ -84,7 +84,7 @@ typedef struct instr_time
/* Use clock_gettime() */
-#include <time.h>
+#include <sys/time.h>
/*
* The best clockid to use according to the POSIX spec is CLOCK_MONOTONIC,
@@ -111,10 +111,10 @@ static inline instr_time
pg_clock_gettime_ns(void)
{
instr_time now;
- struct timespec tmp;
+ struct timeval tmp;
- clock_gettime(PG_INSTR_CLOCK, &tmp);
- now.ticks = tmp.tv_sec * NS_PER_S + tmp.tv_nsec;
+ gettimeofday(&tmp, NULL);
+ now.ticks = tmp.tv_sec * NS_PER_S + tmp.tv_usec * 1000;
return now;
}
diff --git a/src/bin/pg_test_timing/pg_test_timing.c b/src/bin/pg_test_timing/pg_test_timing.c
index c29d6f8762..ea2b565b14 100644
--- a/src/bin/pg_test_timing/pg_test_timing.c
+++ b/src/bin/pg_test_timing/pg_test_timing.c
@@ -133,7 +133,7 @@ test_timing(unsigned int duration)
total_time = duration > 0 ? duration * INT64CONST(1000000) : 0;
INSTR_TIME_SET_CURRENT(start_time);
- cur = INSTR_TIME_GET_MICROSEC(start_time);
+ cur = INSTR_TIME_GET_NANOSEC(start_time);
while (time_elapsed < total_time)
{
@@ -142,7 +142,7 @@ test_timing(unsigned int duration)
prev = cur;
INSTR_TIME_SET_CURRENT(temp);
- cur = INSTR_TIME_GET_MICROSEC(temp);
+ cur = INSTR_TIME_GET_NANOSEC(temp);
diff = cur - prev;
/* Did time go backwards? */
@@ -183,7 +183,7 @@ output(uint64 loop_count)
{
int64 max_bit = 31,
i;
- char *header1 = _("< us");
+ char *header1 = _("< ns");
char *header2 = /* xgettext:no-c-format */ _("% of total");
char *header3 = _("count");
int len1 = strlen(header1);
