Horton
Menu

Re: Reduce timing overhead of EXPLAIN ANALYZE using rdtsc?

Lukas Fittl <lukas@fittl.com>

View thread
From: Lukas Fittl <lukas@fittl.com>
To: Andres Freund <andres@anarazel.de>
Cc: pgsql-hackers <pgsql-hackers@postgresql.org>, David Geier <geidav.pg@gmail.com>
Date: 2026-04-08T06:33:52Z
Lists: pgsql-hackers

Attachments

On Tue, Apr 7, 2026 at 11:09 PM Lukas Fittl <lukas@fittl.com> wrote:
>
> Hi,
>
> It looks like this recent failure on buildfarm member drongo might be
> related to the timing changes - mainly suspecting it because the
> commits are in the (slightly larger) set that changed, and the error
> is in a timing related module that uses INSTR_TIME_SET_CURRENT.
>
> From https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=drongo&dt=2026-04-08%2001%3A57%3A00
>
> # diff --strip-trailing-cr -U3
> C:/prog/bf/root/HEAD/pgsql/contrib/tsm_system_time/expected/tsm_system_time.out
> C:/prog/bf/root/HEAD/pgsql.build/testrun/tsm_system_time/regress/results/tsm_system_time.out
> # --- C:/prog/bf/root/HEAD/pgsql/contrib/tsm_system_time/expected/tsm_system_time.out
>    2023-01-23 04:39:00.533642000 +0000
> # +++ C:/prog/bf/root/HEAD/pgsql.build/testrun/tsm_system_time/regress/results/tsm_system_time.out
>    2026-04-08 04:03:15.248127800 +0000
> # @@ -15,7 +15,7 @@
> #  SELECT count(*) FROM test_tablesample TABLESAMPLE system_time (100000);
> #   count
> #  -------
> # -    31
> # +    16
> #  (1 row)
> #
> #  -- bad parameters should get through planning, but not execution:
> # 1 of 1 tests failed.
> # The differences that caused some tests to fail can be viewed in the
> file "C:/prog/bf/root/HEAD/pgsql.build/testrun/tsm_system_time/regress/regression.diffs".
> # A copy of the test summary that you see above is saved in the file
> "C:/prog/bf/root/HEAD/pgsql.build/testrun/tsm_system_time/regress/regression.out".
>
> Haven't had a chance to dig through it yet, just noting it to start.
>

I wonder a bit if the problem here could be that
INSTR_TIME_GET_MILLISEC got slightly more computationally expensive
with 0022622c93d9 (due to the logic in pg_ticks_to_ns), and that
module effectively does that in a tight loop. And if I understood
drongo's configuration correctly, it runs under valgrind. Attached a
quick idea how we could rework that to avoid it.

Thoughts?

Thanks,
Lukas

-- 
Lukas Fittl

Commits

Same data as JSON: GET /api/v1/messages/:b64id/commits the thread's linked commits as JSON, with link sources. API reference →

  1. pg_test_timing: Show additional TSC clock source debug info

  2. instrumentation: Avoid CPUID 0x15/0x16 for Hypervisor TSC frequency

  3. pg_test_timing: Also test RDTSC[P] timing, report time source, TSC frequency

  4. Allow retrieving x86 TSC frequency/flags from CPUID

  5. instrumentation: Standardize ticks to nanosecond conversion method

  6. instrumentation: Use Time-Stamp Counter on x86-64 to lower overhead

  7. Check for __cpuidex and __get_cpuid_count separately

  8. pg_test_timing: Reduce per-loop overhead

  9. Refactor handling of x86 CPUID instructions

  10. instrumentation: Drop INSTR_TIME_SET_CURRENT_LAZY macro

  11. Rename pg_crc32c_sse42_choose.c for general purpose

  12. Zero initialize uses of instr_time about to trigger compiler warnings

  13. instr_time: Represent time as an int64 on all platforms

  14. Add 250c8ee07ed to git-blame-ignore-revs