From: Andres Freund Date: Tue, 7 Apr 2026 21:08:32 +0000 (-0400) Subject: pg_test_timing: Also test RDTSC[P] timing, report time source, TSC frequency X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=16fca482548382c8d6255319b1c6e5de4afff7f1;p=thirdparty%2Fpostgresql.git pg_test_timing: Also test RDTSC[P] timing, report time source, TSC frequency This adds support to pg_test_timing for the different timing sources added by 294520c4448. Author: Lukas Fittl Author: David Geier Reviewed-by: Andres Freund Reviewed-by: David Geier Reviewed-by: Zsolt Parragi Reviewed-by: Álvaro Herrera (in an earlier version) Discussion: https://www.postgresql.org/message-id/flat/20200612232810.f46nbqkdhbutzqdg%40alap3.anarazel.de --- diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 8bdbb6db0f9..2c4106ee9ab 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -2595,6 +2595,12 @@ include_dir 'conf.d' advised on systems that utilize an emulated TSC, as it is likely slower than the system clock source. + + To help decide which clock source to use you can run the + utility to check TSC + availability, and perform timing measurements. + + diff --git a/doc/src/sgml/ref/pgtesttiming.sgml b/doc/src/sgml/ref/pgtesttiming.sgml index afe6a12be4b..75fcc58d799 100644 --- a/doc/src/sgml/ref/pgtesttiming.sgml +++ b/doc/src/sgml/ref/pgtesttiming.sgml @@ -32,9 +32,10 @@ PostgreSQL documentation pg_test_timing is a tool to measure the timing overhead on your system and confirm that the system time never - moves backwards. It simply reads the system clock over and over again + moves backwards. It reads supported clock sources over and over again as fast as it can for a specified length of time, and then prints - statistics about the observed differences in successive clock readings. + statistics about the observed differences in successive clock readings, + as well as which clock source will be used. Smaller (but not zero) differences are better, since they imply both @@ -45,7 +46,10 @@ PostgreSQL documentation This tool is also helpful to determine if the track_io_timing configuration parameter is likely - to produce useful results. + to produce useful results, and whether the + TSC clock source (see + ) is available and if it will be + used by default. @@ -151,47 +155,137 @@ PostgreSQL documentation However, the largest observed difference is always shown. - The example results below show that 99.99% of timing loops took between - 8 and 31 nanoseconds, with the worst case somewhere between 32768 and - 65535 nanoseconds. In the second block, we can see that typical loop - time is 16 nanoseconds, and the readings appear to have full nanosecond - precision. + On platforms that support the TSC clock source, + additional output sections are shown for the RDTSCP + instruction (used for general timing needs, such as + track_io_timing) and the RDTSC + instruction (used for EXPLAIN ANALYZE). At the end + of the output, the TSC frequency, which may either be + sourced from CPU information directly, or the alternate calibration + mechanism are shown, as well as whether the TSC clock + source will be used by default. + + + + The example results below show system clock timing where 99.99% of loops + took between 16 and 63 nanoseconds. In the second block, we can see that + the typical loop time is 40 nanoseconds, and the readings appear to have + full nanosecond precision. Following the system clock results, the + TSC clock source results are shown, in the same fashion. + The RDTSCP instruction shows most loops completing in + 20–30 nanoseconds, while the RDTSC instruction is + the fastest with an average loop time of 20 nanoseconds. In this example + the TSC clock source will be used by default, but can be + disabled by setting timing_clock_source to + system. @@ -203,6 +297,7 @@ Observed timing durations up to 99.9900%: + Wiki discussion about timing diff --git a/src/bin/pg_test_timing/pg_test_timing.c b/src/bin/pg_test_timing/pg_test_timing.c index 513ae88cafc..2afb0e6a410 100644 --- a/src/bin/pg_test_timing/pg_test_timing.c +++ b/src/bin/pg_test_timing/pg_test_timing.c @@ -30,14 +30,16 @@ static long long int largest_diff_count; static void handle_args(int argc, char *argv[]); -static uint64 test_timing(unsigned int duration); +static void test_system_timing(void); +#if PG_INSTR_TSC_CLOCK +static void test_tsc_timing(void); +#endif +static uint64 test_timing(unsigned int duration, TimingClockSourceType source, bool fast_timing); static void output(uint64 loop_count); int main(int argc, char *argv[]) { - uint64 loop_count; - set_pglocale_pgservice(argv[0], PG_TEXTDOMAIN("pg_test_timing")); progname = get_progname(argv[0]); @@ -46,9 +48,11 @@ main(int argc, char *argv[]) /* initialize timing infrastructure (required for INSTR_* calls) */ pg_initialize_timing(); - loop_count = test_timing(test_duration); + test_system_timing(); - output(loop_count); +#if PG_INSTR_TSC_CLOCK + test_tsc_timing(); +#endif return 0; } @@ -146,20 +150,99 @@ handle_args(int argc, char *argv[]) exit(1); } - printf(ngettext("Testing timing overhead for %u second.\n", - "Testing timing overhead for %u seconds.\n", + printf(ngettext("Testing timing overhead for %u second.\n\n", + "Testing timing overhead for %u seconds.\n\n", test_duration), test_duration); } +/* + * This tests default (non-fast) timing code. A clock source for that is + * always available. Hence, we can unconditionally output the result. + */ +static void +test_system_timing(void) +{ + uint64 loop_count; + + loop_count = test_timing(test_duration, TIMING_CLOCK_SOURCE_SYSTEM, false); + output(loop_count); +} + +/* + * If on a supported architecture, test the TSC clock source. This clock + * source is not always available. In that case we print an informational + * message indicating as such. + * + * We first emit "slow" timings (RDTSCP on x86), which are used for higher + * precision measurements when the TSC clock source is enabled. We emit + * "fast" timings second (RDTSC on x86), which is used for faster timing + * measurements with lower precision. + */ +#if PG_INSTR_TSC_CLOCK +static void +test_tsc_timing(void) +{ + uint64 loop_count; + uint32 calibrated_freq; + + printf("\n"); + loop_count = test_timing(test_duration, TIMING_CLOCK_SOURCE_TSC, false); + if (loop_count > 0) + { + output(loop_count); + printf("\n"); + + /* Now, emit fast timing measurements */ + loop_count = test_timing(test_duration, TIMING_CLOCK_SOURCE_TSC, true); + output(loop_count); + printf("\n"); + + printf(_("TSC frequency in use: %u kHz\n"), timing_tsc_frequency_khz); + + calibrated_freq = pg_tsc_calibrate_frequency(); + if (calibrated_freq > 0) + printf(_("TSC frequency from calibration: %u kHz\n"), calibrated_freq); + else + printf(_("TSC calibration did not converge\n")); + + pg_set_timing_clock_source(TIMING_CLOCK_SOURCE_AUTO); + if (pg_current_timing_clock_source() == TIMING_CLOCK_SOURCE_TSC) + printf(_("TSC clock source will be used by default, unless timing_clock_source is set to 'system'.\n")); + else + printf(_("TSC clock source will not be used by default, unless timing_clock_source is set to 'tsc'.\n")); + } + else + printf(_("TSC clock source is not usable. Likely unable to determine TSC frequency. Are you running in an unsupported virtualized environment?\n")); +} +#endif + static uint64 -test_timing(unsigned int duration) +test_timing(unsigned int duration, TimingClockSourceType source, bool fast_timing) { uint64 loop_count = 0; instr_time start_time, end_time, prev, cur; + const char *time_source = NULL; + + if (!pg_set_timing_clock_source(source)) + return 0; + + time_source = PG_INSTR_SYSTEM_CLOCK_NAME; + +#if PG_INSTR_TSC_CLOCK + if (pg_current_timing_clock_source() == TIMING_CLOCK_SOURCE_TSC) + time_source = fast_timing ? PG_INSTR_TSC_CLOCK_NAME_FAST : PG_INSTR_TSC_CLOCK_NAME; +#endif + + if (fast_timing) + printf(_("Fast clock source: %s\n"), time_source); + else if (source == TIMING_CLOCK_SOURCE_SYSTEM) + printf(_("System clock source: %s\n"), time_source); + else + printf(_("Clock source: %s\n"), time_source); /* * Pre-zero the statistics data structures. They're already zero by @@ -184,7 +267,11 @@ test_timing(unsigned int duration) instr_time diff_time; prev = cur; - INSTR_TIME_SET_CURRENT(cur); + + if (fast_timing) + INSTR_TIME_SET_CURRENT_FAST(cur); + else + INSTR_TIME_SET_CURRENT(cur); diff_time = cur; INSTR_TIME_SUBTRACT(diff_time, prev); diff --git a/src/include/portability/instr_time.h b/src/include/portability/instr_time.h index 5da5eb2c057..a398c028215 100644 --- a/src/include/portability/instr_time.h +++ b/src/include/portability/instr_time.h @@ -207,10 +207,13 @@ pg_current_timing_clock_source(void) */ #if defined(__darwin__) && defined(CLOCK_MONOTONIC_RAW) #define PG_INSTR_SYSTEM_CLOCK CLOCK_MONOTONIC_RAW +#define PG_INSTR_SYSTEM_CLOCK_NAME "clock_gettime (CLOCK_MONOTONIC_RAW)" #elif defined(CLOCK_MONOTONIC) #define PG_INSTR_SYSTEM_CLOCK CLOCK_MONOTONIC +#define PG_INSTR_SYSTEM_CLOCK_NAME "clock_gettime (CLOCK_MONOTONIC)" #else #define PG_INSTR_SYSTEM_CLOCK CLOCK_REALTIME +#define PG_INSTR_SYSTEM_CLOCK_NAME "clock_gettime (CLOCK_REALTIME)" #endif static inline instr_time @@ -231,6 +234,7 @@ pg_get_ticks_system(void) /* On Windows, use QueryPerformanceCounter() for system clock source */ +#define PG_INSTR_SYSTEM_CLOCK_NAME "QueryPerformanceCounter" static inline instr_time pg_get_ticks_system(void) { @@ -329,6 +333,9 @@ pg_ns_to_ticks(int64 ns) #if PG_INSTR_TSC_CLOCK +#define PG_INSTR_TSC_CLOCK_NAME_FAST "RDTSC" +#define PG_INSTR_TSC_CLOCK_NAME "RDTSCP" + #ifdef _MSC_VER #include #endif /* defined(_MSC_VER) */