Re: Overhead for stats_command_string et al, take 2

Sorry I am traveling for EnterpriseDB Wednesday and Thursday so I can't
run the tests right now.

Seeing stats_command_string with almost zero overhead is great news!
Should we remove that setting and just have it enabled all
the time?

As far as pg_stat_activity.query_start, I never suspected that column
would show the time of start of IDLE. I think we can just document that
that column is the time of the start of the last query, and avoid the
gettimeofday() call on IDLE start. If we get demand for the old
behavior, we can consider re-adding it, but I bet when they hear the
downside (a second gettimeofday() call for every query), no one will
want the old behavior.

---------------------------------------------------------------------------

Tom Lane wrote:
> I redid my previous measurements after finishing up the weekend's
> hacking. The numbers shown below are elapsed time in seconds for
>
> time psql -f testfile.sql postgres >/dev/null
>
> using CVS HEAD and REL8_1_STABLE branch tip, compiled --enable-debug
> --disable-cassert, no nondefault options except for turning fsync off
> (which doesn't particularly affect read-only tests like these anyway).
> The machines are both running current Fedora Core 5. The older x86
> machine is known to have the slow-gettimeofday problem from previous
> experimentation with EXPLAIN ANALYZE. Each number is the median of 3
> or more tests, rounded off to 0.1 second (I wouldn't put a lot of faith
> in differences of 0.1 sec or so, because of the variance I saw in the
> tests).
>
> x86 x86_64
>
> 8.1 HEAD 8.1 HEAD
>
> 100000 "SELECT 1;" 25.9 27.0 9.2 9.1
> with stats_command_string=1 63.5 27.6 18.7 9.2
> with log_min_duration_statement=100 26.9 27.8 9.6 9.2
> with statement_timeout=100 27.5 28.6 9.6 9.8
> with all 3 features 66.1 29.3 19.5 9.7
>
> BEGIN, 100000 "SELECT 1;", COMMIT 21.2 23.1 8.3 8.4
> with stats_command_string=1 52.3 23.5 15.4 8.5
> with log_min_duration_statement=100 22.1 23.4 8.4 8.4
> with statement_timeout=100 23.7 24.3 8.6 8.8
> with all 3 features 55.2 25.5 16.0 8.8
>
> I chose the log_min_duration_statement and statement_timeout settings
> high enough so that no actual logging or timeout would happen --- the
> point is to measure the measurement overhead.
>
> The good news is that we've pretty much licked the problem of
> stats_command_string costing an unreasonable amount.
>
> The bad news is that except in the stats_command_string cases, HEAD
> is noticeably slower than 8.1 on the machine with slow gettimeofday.
> In the single-transaction test this might be blamed on the addition
> of statement_timestamp support (which requires a gettimeofday per
> statement that wasn't there in 8.1) ... but in the one-transaction-
> per-statement tests that doesn't hold water, because each branch is
> doing a gettimeofday per statement, just in different places.
>
> Can anyone else reproduce this slowdown? It might be only an artifact
> of these particular builds, but it's a bit too consistent in my x86 data
> to just ignore.
>
> BTW, according to "top" the CPU usage percentages in these tests are
> on the order of 55% backend, 45% psql. Methinks psql needs a round
> of performance tuning ...
>
> regards, tom lane
>
> ---------------------------(end of broadcast)---------------------------
> TIP 6: explain analyze is your friend
>

--
Bruce Momjian bruce(at)momjian(dot)us
EnterpriseDB http://www.enterprisedb.com

+ If your life is a hard drive, Christ can be your backup. +