pg_test_timing: Reduce per-loop overhead

The pg_test_timing program was previously using INSTR_TIME_GET_NANOSEC on an
absolute instr_time value in order to do a diff, which goes against the spirit
of how the GET_* macros are supposed to be used, and will cause overhead in a
future change that assumes these macros are typically used on intervals only.

Additionally the program was doing unnecessary work in the test loop by
measuring the time elapsed, instead of checking the existing current time
measurement against a target end time. To support that, introduce a new
INSTR_TIME_ADD_NANOSEC macro that allows adding user-defined nanoseconds
to an instr_time variable.

While modifying the relevant code anyway, simplify it by not handling
durations <= 0 in test_timing(), since duration is unsigned and 0 is
disallowed by the caller.

Author: Lukas Fittl <lukas@fittl.com>
Reviewed-by: Andres Freund <andres@anarazel.de>
Discussion: https://postgr.es/m/CAP53Pkyxv3-3gX+aOxC5tX0p2v9RHU+XH0iyvb64+ZnBXj92vg@mail.gmail.com
This commit is contained in:
Andres Freund 2026-04-01 20:02:09 -04:00
parent 6e36930f9a
commit 82c0cb4e67
2 changed files with 22 additions and 14 deletions

View file

@ -152,14 +152,11 @@ handle_args(int argc, char *argv[])
static uint64
test_timing(unsigned int duration)
{
uint64 total_time;
int64 time_elapsed = 0;
uint64 loop_count = 0;
uint64 prev,
cur;
instr_time start_time,
end_time,
temp;
prev,
cur;
/*
* Pre-zero the statistics data structures. They're already zero by
@ -171,20 +168,24 @@ test_timing(unsigned int duration)
largest_diff = 0;
largest_diff_count = 0;
total_time = duration > 0 ? duration * INT64CONST(1000000000) : 0;
INSTR_TIME_SET_CURRENT(start_time);
cur = INSTR_TIME_GET_NANOSEC(start_time);
cur = start_time;
while (time_elapsed < total_time)
end_time = start_time;
INSTR_TIME_ADD_NANOSEC(end_time, duration * NS_PER_S);
while (INSTR_TIME_GT(end_time, cur))
{
int32 diff,
bits;
instr_time diff_time;
prev = cur;
INSTR_TIME_SET_CURRENT(temp);
cur = INSTR_TIME_GET_NANOSEC(temp);
diff = cur - prev;
INSTR_TIME_SET_CURRENT(cur);
diff_time = cur;
INSTR_TIME_SUBTRACT(diff_time, prev);
diff = INSTR_TIME_GET_NANOSEC(diff_time);
/* Did time go backwards? */
if (unlikely(diff < 0))
@ -217,10 +218,9 @@ test_timing(unsigned int duration)
largest_diff_count++;
loop_count++;
INSTR_TIME_SUBTRACT(temp, start_time);
time_elapsed = INSTR_TIME_GET_NANOSEC(temp);
}
/* Refresh end time to be the actual time spent (vs the target end time) */
INSTR_TIME_SET_CURRENT(end_time);
INSTR_TIME_SUBTRACT(end_time, start_time);

View file

@ -22,6 +22,8 @@
*
* INSTR_TIME_ADD(x, y) x += y
*
* INSTR_TIME_ADD_NANOSEC(t, n) x += y in nanoseconds (converts to ticks)
*
* INSTR_TIME_SUBTRACT(x, y) x -= y
*
* INSTR_TIME_ACCUM_DIFF(x, y, z) x += (y - z)
@ -125,6 +127,9 @@ pg_clock_gettime_ns(void)
#define INSTR_TIME_GET_NANOSEC(t) \
((int64) (t).ticks)
#define INSTR_TIME_ADD_NANOSEC(t, n) \
((t).ticks += (n))
#else /* WIN32 */
@ -159,6 +164,9 @@ GetTimerFrequency(void)
#define INSTR_TIME_GET_NANOSEC(t) \
((int64) ((t).ticks * ((double) NS_PER_S / GetTimerFrequency())))
#define INSTR_TIME_ADD_NANOSEC(t, n) \
((t).ticks += ((n) / ((double) NS_PER_S / GetTimerFrequency())))
#endif /* WIN32 */