From 66d8e42557a65546af970b03b201dd84da494175 Mon Sep 17 00:00:00 2001 From: Lukas Fittl Date: Wed, 8 Apr 2026 10:11:56 -0700 Subject: [PATCH v24] instrumentation: Show additional TSC clock source info in pg_test_timing In some cases its needed to understand whether TSC frequency data was sourced from CPUID, and which of the registers. This shows this debug information at the end of pg_test_timing, through use of a new pg_timing_tsc_clock_source_info function, replacing the previous pg_tsc_calibrate_frequency export that was only needed for debug info. To help investigate odd TSC frequency observed on buildfarm member drongo. Author: Lukas Fittl Suggested-by: Andres Freund Discussion: https://www.postgresql.org/message-id/flat/jr4hk2sxhqcfpb67ftz5g4vw33nm67cgf7go3wwmqsafu5aclq%405m67ukuhyszz#2fdfd95b6a4a74410196999818e16cfc --- src/bin/pg_test_timing/pg_test_timing.c | 12 ++++--- src/common/instr_time.c | 28 ++++++++++++++-- src/include/port/pg_cpu.h | 2 +- src/include/portability/instr_time.h | 10 +++++- src/port/pg_cpu_x86.c | 44 ++++++++++++++++++++++--- src/tools/pgindent/typedefs.list | 1 + 6 files changed, 83 insertions(+), 14 deletions(-) diff --git a/src/bin/pg_test_timing/pg_test_timing.c b/src/bin/pg_test_timing/pg_test_timing.c index 2afb0e6a410..aa5c2068cac 100644 --- a/src/bin/pg_test_timing/pg_test_timing.c +++ b/src/bin/pg_test_timing/pg_test_timing.c @@ -184,7 +184,7 @@ static void test_tsc_timing(void) { uint64 loop_count; - uint32 calibrated_freq; + TscClockSourceInfo info; printf("\n"); loop_count = test_timing(test_duration, TIMING_CLOCK_SOURCE_TSC, false); @@ -198,11 +198,13 @@ test_tsc_timing(void) output(loop_count); printf("\n"); - printf(_("TSC frequency in use: %u kHz\n"), timing_tsc_frequency_khz); + info = pg_timing_tsc_clock_source_info(); + printf(_("TSC frequency in use: %d kHz\n"), info.frequency_khz); + if (info.frequency_source) + printf(_("TSC frequency source: %s\n"), info.frequency_source); - calibrated_freq = pg_tsc_calibrate_frequency(); - if (calibrated_freq > 0) - printf(_("TSC frequency from calibration: %u kHz\n"), calibrated_freq); + if (info.calibrated_frequency_khz > 0) + printf(_("TSC frequency from calibration: %d kHz\n"), info.calibrated_frequency_khz); else printf(_("TSC calibration did not converge\n")); diff --git a/src/common/instr_time.c b/src/common/instr_time.c index fc6e1852c30..3e7a4d40bdb 100644 --- a/src/common/instr_time.c +++ b/src/common/instr_time.c @@ -70,6 +70,8 @@ static void set_ticks_per_ns(void); static void set_ticks_per_ns_system(void); #if PG_INSTR_TSC_CLOCK +static const char *timing_tsc_frequency_source = NULL; + static bool tsc_use_by_default(void); static void set_ticks_per_ns_for_tsc(void); #endif @@ -166,6 +168,7 @@ set_ticks_per_ns_system(void) #if PG_INSTR_TSC_CLOCK static void tsc_detect_frequency(void); +static uint32 pg_tsc_calibrate_frequency(void); /* * Initialize the TSC clock source by determining its usability and frequency. @@ -202,13 +205,14 @@ static void tsc_detect_frequency(void) { timing_tsc_frequency_khz = 0; + timing_tsc_frequency_source = NULL; /* We require RDTSCP support and an invariant TSC, bail if not available */ if (!x86_feature_available(PG_RDTSCP) || !x86_feature_available(PG_TSC_INVARIANT)) return; /* Determine speed at which the TSC advances */ - timing_tsc_frequency_khz = x86_tsc_frequency_khz(); + timing_tsc_frequency_khz = x86_tsc_frequency_khz(&timing_tsc_frequency_source); if (timing_tsc_frequency_khz > 0) return; @@ -217,6 +221,8 @@ tsc_detect_frequency(void) * frequency by comparing ticks against walltime in a calibration loop. */ timing_tsc_frequency_khz = pg_tsc_calibrate_frequency(); + if (timing_tsc_frequency_khz > 0) + timing_tsc_frequency_source = "x86, calibration"; } /* @@ -282,7 +288,7 @@ tsc_use_by_default(void) #define TSC_CALIBRATION_ITERATIONS 1000000 #define TSC_CALIBRATION_SKIPS 100 #define TSC_CALIBRATION_STABLE_CYCLES 10 -uint32 +static uint32 pg_tsc_calibrate_frequency(void) { instr_time initial_wall; @@ -369,4 +375,22 @@ pg_tsc_calibrate_frequency(void) return (uint32) freq_khz; } +/* + * Returns TSC clock source information for diagnostic purposes. + * + * Note: This always runs the TSC calibration loop which may take up to + * TSC_CALIBRATION_MAX_NS. + */ +TscClockSourceInfo +pg_timing_tsc_clock_source_info(void) +{ + TscClockSourceInfo info; + + info.frequency_khz = timing_tsc_frequency_khz; + info.frequency_source = timing_tsc_frequency_source; + info.calibrated_frequency_khz = pg_tsc_calibrate_frequency(); + + return info; +} + #endif /* PG_INSTR_TSC_CLOCK */ diff --git a/src/include/port/pg_cpu.h b/src/include/port/pg_cpu.h index a5d42f1b68d..8ec68257d25 100644 --- a/src/include/port/pg_cpu.h +++ b/src/include/port/pg_cpu.h @@ -56,7 +56,7 @@ x86_feature_available(X86FeatureId feature) return X86Features[feature]; } -extern uint32 x86_tsc_frequency_khz(void); +extern uint32 x86_tsc_frequency_khz(const char **source); #endif /* defined(USE_SSE2) || defined(__i386__) */ diff --git a/src/include/portability/instr_time.h b/src/include/portability/instr_time.h index 92558e234ac..e46ea0939ec 100644 --- a/src/include/portability/instr_time.h +++ b/src/include/portability/instr_time.h @@ -165,7 +165,15 @@ extern PGDLLIMPORT int32 timing_tsc_frequency_khz; extern void pg_initialize_timing_tsc(void); -extern uint32 pg_tsc_calibrate_frequency(void); +typedef struct TscClockSourceInfo +{ + int32 frequency_khz; /* from CPUID or calibration */ + int32 calibrated_frequency_khz; /* from calibration loop, 0 if did + * not converge */ + const char *frequency_source; /* describes how frequency was determined */ +} TscClockSourceInfo; + +extern TscClockSourceInfo pg_timing_tsc_clock_source_info(void); #endif /* PG_INSTR_TSC_CLOCK */ diff --git a/src/port/pg_cpu_x86.c b/src/port/pg_cpu_x86.c index 32d0cecbe2c..637eaab2c6d 100644 --- a/src/port/pg_cpu_x86.c +++ b/src/port/pg_cpu_x86.c @@ -13,7 +13,11 @@ *------------------------------------------------------------------------- */ -#include "c.h" +#ifndef FRONTEND +#include "postgres.h" +#else +#include "postgres_fe.h" +#endif #if defined(USE_SSE2) || defined(__i386__) @@ -152,7 +156,7 @@ set_x86_features(void) /* TSC (Time-stamp Counter) handling code */ -static uint32 x86_hypervisor_tsc_frequency_khz(void); +static uint32 x86_hypervisor_tsc_frequency_khz(const char **hvname); /* * Determine the TSC frequency of the CPU through CPUID, where supported. @@ -161,13 +165,17 @@ static uint32 x86_hypervisor_tsc_frequency_khz(void); * 0 indicates the frequency information was not accessible via CPUID. */ uint32 -x86_tsc_frequency_khz(void) +x86_tsc_frequency_khz(const char **source) { unsigned int reg[4] = {0}; + const char *hvname = NULL; + + if (source) + *source = NULL; if (x86_feature_available(PG_HYPERVISOR)) { - uint32 freq = x86_hypervisor_tsc_frequency_khz(); + uint32 freq = x86_hypervisor_tsc_frequency_khz(&hvname); /* * If the hypervisor specific logic didn't figure out the frequency, @@ -176,7 +184,12 @@ x86_tsc_frequency_khz(void) * frequency. */ if (freq > 0) + { + if (source) + *source = psprintf("x86, hypervisor (%s), cpuid 0x40000010", + hvname); return freq; + } } /* @@ -210,6 +223,9 @@ x86_tsc_frequency_khz(void) if (reg[EAX] == 0 || reg[EBX] == 0) return 0; + if (source) + *source = hvname ? psprintf("x86, hypervisor (%s), cpuid 0x15", hvname) : "x86, cpuid 0x15"; + return reg[ECX] / 1000 * reg[EBX] / reg[EAX]; } @@ -220,7 +236,12 @@ x86_tsc_frequency_khz(void) */ pg_cpuid(0x16, reg); if (reg[EAX] > 0) + { + if (source) + *source = hvname ? psprintf("x86, hypervisor (%s), cpuid 0x16", hvname) : "x86, cpuid 0x16"; + return reg[EAX] * 1000; + } return 0; } @@ -239,11 +260,13 @@ x86_tsc_frequency_khz(void) #define CPUID_HYPERVISOR_VMWARE(r) (r[EBX] == 0x61774d56 && r[ECX] == 0x4d566572 && r[EDX] == 0x65726177) /* VMwareVMware */ #define CPUID_HYPERVISOR_KVM(r) (r[EBX] == 0x4b4d564b && r[ECX] == 0x564b4d56 && r[EDX] == 0x0000004d) /* KVMKVMKVM */ static uint32 -x86_hypervisor_tsc_frequency_khz(void) +x86_hypervisor_tsc_frequency_khz(const char **hvname) { #if defined(HAVE__CPUIDEX) unsigned int reg[4] = {0}; + Assert(hvname != NULL); + /* * The hypervisor is determined using the 0x40000000 Hypervisor * information leaf, which requires use of __cpuidex to set ECX to 0 to @@ -255,12 +278,23 @@ x86_hypervisor_tsc_frequency_khz(void) */ __cpuidex((int *) reg, 0x40000000, 0); + /* Always identify the hypervisor */ + if (CPUID_HYPERVISOR_VMWARE(reg)) + *hvname = "vmware"; + else if (CPUID_HYPERVISOR_KVM(reg)) + *hvname = "kvm"; + else + *hvname = "other"; + if (reg[EAX] >= 0x40000010 && (CPUID_HYPERVISOR_VMWARE(reg) || CPUID_HYPERVISOR_KVM(reg))) { __cpuidex((int *) reg, 0x40000010, 0); if (reg[EAX] > 0) return reg[EAX]; } +#else + Assert(hvname != NULL); + *hvname = "unknown"; #endif /* HAVE__CPUIDEX */ return 0; diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs.list index ea95e7984bc..2137f1e0cfe 100644 --- a/src/tools/pgindent/typedefs.list +++ b/src/tools/pgindent/typedefs.list @@ -3090,6 +3090,7 @@ TParserStateActionItem TQueueDestReceiver TRGM TSAnyCacheEntry +TscClockSourceInfo TSConfigCacheEntry TSConfigInfo TSDictInfo -- 2.47.1