Overhead for stats_command_string et al, take 2

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