Re: What is a typical precision of gettimeofday()? - Mailing list pgsql-hackers

Peter Eisentraut <peter@eisentraut.org> 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);