In some cases its necessary to understand whether TSC frequency data was
sourced from CPUID, and which of the registers. Show this debug info at
the end of pg_test_timing, and rework TSC functions to support that.
This would have helped debug the buildfarm report fixed in
7fc36c5db550
and is likely going to aid in any TSC-related issues reported during the
beta period or later.
Additionally, emit a warning if TSC frequency from calibration differs
by more than 10% from the TSC frequency in use, and suggest the use
of timing_clock_source = 'system'.
In passing, add an explicit early return in the output function if the
loop count is zero. This can't happen in practice, but coverity complained
because we unconditionally call output for the fast TSC measurement.
Author: Lukas Fittl <lukas@fittl.com>
Suggested-by: Andres Freund <andres@anarazel.de>
Reviewed-by: Andres Freund <andres@anarazel.de>
Reviewed-by: Haibo Yan <tristan.yim@gmail.com>
Reviewed-by: Tom Lane <tgl@sss.pgh.pa.us> (coverity fix only)
Discussion: https://postgr.es/m/CAP53Pkw3Gzb+KTF5pu_o7tzbfZ7+qm2m6uDWuGtTJjZpV9yNpg@mail.gmail.com
...
61594291 0.0000 100.0000 1
+TSC frequency source: x86, cpuid 0x15
TSC frequency in use: 2449228 kHz
TSC frequency from calibration: 2448603 kHz
+
TSC clock source will be used by default, unless timing_clock_source is set to 'system'.
]]></screen>
</para>
#include "postgres_fe.h"
#include <limits.h>
+#include <math.h>
#include "getopt_long.h"
#include "port/pg_bitutils.h"
test_tsc_timing(void)
{
uint64 loop_count;
- uint32 calibrated_freq;
+ const TscClockSourceInfo *info;
printf("\n");
loop_count = test_timing(test_duration, TIMING_CLOCK_SOURCE_TSC, false);
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);
+ /*
+ * Report TSC information regardless of whether it was usable, makes
+ * debugging a lot easier.
+ */
+ info = pg_timing_tsc_clock_source_info();
+ if (info->frequency_source[0] != '\0')
+ printf(_("TSC frequency source: %s\n"), info->frequency_source);
+ printf(_("TSC frequency in use: %d kHz\n"), info->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"));
+ if (info->calibrated_frequency_khz > 0)
+ {
+ double diff_pct;
+
+ printf(_("TSC frequency from calibration: %d kHz\n"), info->calibrated_frequency_khz);
+
+ diff_pct = fabs((double) info->calibrated_frequency_khz - info->frequency_khz) /
+ info->frequency_khz * 100.0;
+
+ if (diff_pct > 10.0)
+ {
+ printf(_("WARNING: Calibrated TSC frequency differs by %.1f%% from the TSC frequency in use\n"),
+ diff_pct);
+ printf(_("HINT: Consider setting timing_clock_source to 'system'. Report bugs to <%s>.\n"), PACKAGE_BUGREPORT);
+ exit(1);
+ }
+ }
+ else
+ printf(_("TSC calibration did not converge\n"));
+ /*
+ * Report whether TSC was usable and, if so, whether it will be used
+ * automatically.
+ */
+ if (loop_count > 0)
+ {
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"));
+ printf(_("\nTSC 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"));
+ printf(_("\nTSC 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"));
+ printf(_("\nTSC clock source is not usable. Likely unable to determine TSC frequency. Are you running in an unsupported virtualized environment?\n"));
}
#endif
double rprct;
bool stopped = false;
+ if (loop_count == 0)
+ {
+ printf(_("WARNING: No timing measurements collected. Report this as a bug to <%s>.\n"), PACKAGE_BUGREPORT);
+ return;
+ }
+
/* find highest bit value */
while (max_bit > 0 && histogram[max_bit] == 0)
max_bit--;
static void set_ticks_per_ns_system(void);
#if PG_INSTR_TSC_CLOCK
+static TscClockSourceInfo tsc_info = {.calibrated_frequency_khz = -1};
+
static bool tsc_use_by_default(void);
static void set_ticks_per_ns_for_tsc(void);
#endif
#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.
tsc_detect_frequency(void)
{
timing_tsc_frequency_khz = 0;
+ tsc_info.frequency_khz = 0;
+ tsc_info.frequency_source[0] = '\0';
+
+ strlcat(tsc_info.frequency_source, "x86",
+ sizeof(tsc_info.frequency_source));
/* We require RDTSCP support and an invariant TSC, bail if not available */
- if (!x86_feature_available(PG_RDTSCP) || !x86_feature_available(PG_TSC_INVARIANT))
+ if (!x86_feature_available(PG_RDTSCP))
+ {
+ strlcat(tsc_info.frequency_source, ", no rdtscp",
+ sizeof(tsc_info.frequency_source));
return;
+ }
+
+ if (!x86_feature_available(PG_TSC_INVARIANT))
+ {
+ strlcat(tsc_info.frequency_source, ", not invariant",
+ sizeof(tsc_info.frequency_source));
+ return;
+ }
/* Determine speed at which the TSC advances */
- timing_tsc_frequency_khz = x86_tsc_frequency_khz();
+ timing_tsc_frequency_khz = x86_tsc_frequency_khz(tsc_info.frequency_source,
+ sizeof(tsc_info.frequency_source));
if (timing_tsc_frequency_khz > 0)
+ {
+ tsc_info.frequency_khz = timing_tsc_frequency_khz;
return;
+ }
/*
* CPUID did not give us the TSC frequency. We can instead measure the
* frequency by comparing ticks against walltime in a calibration loop.
*/
- timing_tsc_frequency_khz = pg_tsc_calibrate_frequency();
+ if (tsc_info.calibrated_frequency_khz < 0)
+ tsc_info.calibrated_frequency_khz = pg_tsc_calibrate_frequency();
+
+ timing_tsc_frequency_khz = tsc_info.calibrated_frequency_khz;
+ if (timing_tsc_frequency_khz > 0)
+ {
+ strlcat(tsc_info.frequency_source, ", calibration",
+ sizeof(tsc_info.frequency_source));
+ tsc_info.frequency_khz = timing_tsc_frequency_khz;
+ }
}
/*
#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;
return (uint32) freq_khz;
}
+/*
+ * Returns TSC clock source information for diagnostic purposes.
+ *
+ * On first call, may run the TSC calibration loop (if not already done during
+ * frequency detection) which can take up to TSC_CALIBRATION_MAX_NS.
+ * Subsequent calls return cached results.
+ *
+ * Note: This won't return the right info in EXEC_BACKEND builds if this were
+ * used in the backend (which it currently is not), as tsc_info is not copied
+ * using read_backend_variables - only the TSC frequency is.
+ */
+const TscClockSourceInfo *
+pg_timing_tsc_clock_source_info(void)
+{
+ if (tsc_info.frequency_khz > 0 && tsc_info.calibrated_frequency_khz < 0)
+ tsc_info.calibrated_frequency_khz = pg_tsc_calibrate_frequency();
+
+ return &tsc_info;
+}
+
#endif /* PG_INSTR_TSC_CLOCK */
return X86Features[feature];
}
-extern uint32 x86_tsc_frequency_khz(void);
+extern uint32 x86_tsc_frequency_khz(char *source, size_t source_size);
#endif /* defined(USE_SSE2) || defined(__i386__) */
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 */
+ char frequency_source[128]; /* describes how frequency was
+ * determined */
+} TscClockSourceInfo;
+
+extern const TscClockSourceInfo *pg_timing_tsc_clock_source_info(void);
#endif /* PG_INSTR_TSC_CLOCK */
*-------------------------------------------------------------------------
*/
-#include "c.h"
+#ifndef FRONTEND
+#include "postgres.h"
+#else
+#include "postgres_fe.h"
+#endif
#if defined(USE_SSE2) || defined(__i386__)
*
* Needed to interpret the tick value returned by RDTSC/RDTSCP. Return value of
* 0 indicates the frequency information was not accessible via CPUID.
+ *
+ * The optional source argument may contain a pre-allocated string of capacity
+ * source_size that will be concatenated with info on the TSC frequency source.
*/
uint32
-x86_tsc_frequency_khz(void)
+x86_tsc_frequency_khz(char *source, size_t source_size)
{
unsigned int reg[4] = {0};
* to be wildly incorrect when virtualized.
*/
if (x86_feature_available(PG_HYPERVISOR))
- return x86_hypervisor_tsc_frequency_khz();
+ {
+ uint32 freq = x86_hypervisor_tsc_frequency_khz();
+
+ if (source)
+ {
+ strlcat(source, ", hypervisor", source_size);
+ if (freq > 0)
+ strlcat(source, ", cpuid 0x40000010", source_size);
+ }
+ return freq;
+ }
/*
* On modern Intel CPUs, the TSC is implemented by invariant timekeeping
if (reg[EAX] == 0 || reg[EBX] == 0)
return 0;
+ if (source)
+ strlcat(source, ", cpuid 0x15", source_size);
+
return reg[ECX] / 1000 * reg[EBX] / reg[EAX];
}
*/
pg_cpuid(0x16, reg);
if (reg[EAX] > 0)
+ {
+ if (source)
+ strlcat(source, ", cpuid 0x16", source_size);
+
return reg[EAX] * 1000;
+ }
return 0;
}
TQueueDestReceiver
TRGM
TSAnyCacheEntry
+TscClockSourceInfo
TSConfigCacheEntry
TSConfigInfo
TSDictInfo
projects / thirdparty / postgresql.git / commitdiff
