Horton

Re: Reduce timing overhead of EXPLAIN ANALYZE using rdtsc?

Justin Pryzby <pryzby@telsasoft.com>

View thread
From: Justin Pryzby <pryzby@telsasoft.com>
To: Andres Freund <andres@anarazel.de>
Cc: Tom Lane <tgl@sss.pgh.pa.us>, Robert Haas <robertmhaas@gmail.com>, David Geier <geidav.pg@gmail.com>, vignesh C <vignesh21@gmail.com>, Lukas Fittl <lukas@fittl.com>, Michael Paquier <michael@paquier.xyz>, Ibrar Ahmed <ibrar.ahmad@gmail.com>, Maciek Sakrejda <m.sakrejda@gmail.com>, pgsql-hackers@postgresql.org
Date: 2023-01-21T04:50:37Z
Lists: pgsql-hackers

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: Also test RDTSC[P] timing, report time source, TSC frequency

  2. Allow retrieving x86 TSC frequency/flags from CPUID

  3. instrumentation: Standardize ticks to nanosecond conversion method

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

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

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

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

On Fri, Jan 20, 2023 at 04:40:32PM -0800, Andres Freund wrote:
> From 5a458d4584961dedd3f80a07d8faea66e57c5d94 Mon Sep 17 00:00:00 2001
> From: Andres Freund <andres@anarazel.de>
> Date: Mon, 16 Jan 2023 11:19:11 -0800
> Subject: [PATCH v8 4/5] wip: report nanoseconds in pg_test_timing

>    <para>
> -   The i7-860 system measured runs the count query in 9.8 ms while
> -   the <command>EXPLAIN ANALYZE</command> version takes 16.6 ms, each
> -   processing just over 100,000 rows.  That 6.8 ms difference means the timing
> -   overhead per row is 68 ns, about twice what pg_test_timing estimated it
> -   would be.  Even that relatively small amount of overhead is making the fully
> -   timed count statement take almost 70% longer.  On more substantial queries,
> -   the timing overhead would be less problematic.
> +   The i9-9880H system measured shows an execution time of 4.116 ms for the
> +   <literal>TIMING OFF</literal> query, and 6.965 ms for the
> +   <literal>TIMING ON</literal>, each processing 100,000 rows.
> +
> +   That 2.849 ms difference means the timing overhead per row is 28 ns.  As
> +   <literal>TIMING ON</literal> measures timestamps twice per row returned by
> +   an executor node, the overhead is very close to what pg_test_timing
> +   estimated it would be.
> +
> +   more than what pg_test_timing estimated it would be.  Even that relatively
> +   small amount of overhead is making the fully timed count statement take
> +   about 60% longer.  On more substantial queries, the timing overhead would
> +   be less problematic.

I guess you intend to merge these two paragraphs ?