*** pg_test_timing.c.orig 2023-01-16 01:09:51.839251695 +0100 --- pg_test_timing.c 2023-01-16 22:24:49.768037225 +0100 *************** *** 11,16 **** --- 11,20 ---- #include "getopt_long.h" #include "portability/instr_time.h" + #define INSTR_TIME_GET_NANOSEC(t) \ + (((uint64) (t).tv_sec * (uint64) 1000000000) + (uint64) ((t).tv_nsec)) + + static const char *progname; static unsigned int test_duration = 3; *************** *** 19,26 **** static uint64 test_timing(unsigned int duration); static void output(uint64 loop_count); ! /* record duration in powers of 2 microseconds */ ! long long int histogram[32]; int main(int argc, char *argv[]) --- 23,30 ---- static uint64 test_timing(unsigned int duration); static void output(uint64 loop_count); ! /* record duration in powers of 2 nanoseconds */ ! long long int histogram[64]; int main(int argc, char *argv[]) *************** *** 124,139 **** uint64 total_time; int64 time_elapsed = 0; uint64 loop_count = 0; uint64 prev, cur; instr_time start_time, end_time, temp; ! total_time = duration > 0 ? duration * INT64CONST(1000000) : 0; INSTR_TIME_SET_CURRENT(start_time); ! cur = INSTR_TIME_GET_MICROSEC(start_time); while (time_elapsed < total_time) { --- 128,145 ---- uint64 total_time; int64 time_elapsed = 0; uint64 loop_count = 0; + uint64 same_count = 0; + uint64 min_diff = UINT64_MAX; uint64 prev, cur; instr_time start_time, end_time, temp; ! total_time = duration > 0 ? duration * INT64CONST(1000000000) : 0; INSTR_TIME_SET_CURRENT(start_time); ! cur = INSTR_TIME_GET_NANOSEC(start_time); while (time_elapsed < total_time) { *************** *** 141,157 **** bits = 0; prev = cur; INSTR_TIME_SET_CURRENT(temp); ! cur = INSTR_TIME_GET_MICROSEC(temp); diff = cur - prev; /* Did time go backwards? */ ! if (diff < 0) { fprintf(stderr, _("Detected clock going backwards in time.\n")); fprintf(stderr, _("Time warp: %d ms\n"), diff); exit(1); } /* What is the highest bit in the time diff? */ while (diff) --- 147,172 ---- bits = 0; prev = cur; + // INSTR_TIME_SET_CURRENT(temp); + // prev = INSTR_TIME_GET_NANOSEC(temp); INSTR_TIME_SET_CURRENT(temp); ! cur = INSTR_TIME_GET_NANOSEC(temp); diff = cur - prev; /* Did time go backwards? */ ! if (unlikely(diff <= 0)) { + if (diff == 0 ) + same_count ++; + else + { fprintf(stderr, _("Detected clock going backwards in time.\n")); fprintf(stderr, _("Time warp: %d ms\n"), diff); exit(1); + } } + if (min_diff > diff) + min_diff = diff; /* What is the highest bit in the time diff? */ while (diff) *************** *** 165,179 **** loop_count++; INSTR_TIME_SUBTRACT(temp, start_time); ! time_elapsed = INSTR_TIME_GET_MICROSEC(temp); } INSTR_TIME_SET_CURRENT(end_time); INSTR_TIME_SUBTRACT(end_time, start_time); ! printf(_("Per loop time including overhead: %0.2f ns\n"), ! INSTR_TIME_GET_DOUBLE(end_time) * 1e9 / loop_count); return loop_count; } --- 180,194 ---- loop_count++; INSTR_TIME_SUBTRACT(temp, start_time); ! time_elapsed = INSTR_TIME_GET_NANOSEC(temp); } INSTR_TIME_SET_CURRENT(end_time); INSTR_TIME_SUBTRACT(end_time, start_time); ! printf(_("Per loop time including overhead: %0.2f ns, min: %ld, same: %ld\n"), ! INSTR_TIME_GET_DOUBLE(end_time) * 1e9 / loop_count, min_diff, same_count); return loop_count; } *************** *** 181,189 **** static void output(uint64 loop_count) { ! int64 max_bit = 31, i; ! char *header1 = _("< us"); char *header2 = /* xgettext:no-c-format */ _("% of total"); char *header3 = _("count"); int len1 = strlen(header1); --- 196,204 ---- static void output(uint64 loop_count) { ! int64 max_bit = 63, i; ! char *header1 = _("< ns"); char *header2 = /* xgettext:no-c-format */ _("% of total"); char *header3 = _("count"); int len1 = strlen(header1); *************** *** 196,208 **** printf(_("Histogram of timing durations:\n")); printf("%*s %*s %*s\n", ! Max(6, len1), header1, Max(10, len2), header2, Max(10, len3), header3); for (i = 0; i <= max_bit; i++) printf("%*ld %*.5f %*lld\n", ! Max(6, len1), 1l << i, Max(10, len2) - 1, (double) histogram[i] * 100 / loop_count, Max(10, len3), histogram[i]); } --- 211,223 ---- printf(_("Histogram of timing durations:\n")); printf("%*s %*s %*s\n", ! Max(7, len1), header1, Max(10, len2), header2, Max(10, len3), header3); for (i = 0; i <= max_bit; i++) printf("%*ld %*.5f %*lld\n", ! Max(7, len1), 1l << i, Max(10, len2) - 1, (double) histogram[i] * 100 / loop_count, Max(10, len3), histogram[i]); }