Re: Timing of 'SELECT 1'

Tom Lane wrote:
> Bruce Momjian <pgman@candle.pha.pa.us> writes:
> > I am timing small queries, and found that a PREPARE/EXECUTE of "SELECT
> > 1" takes about 1.2ms on my machine.  A normal SELECT doesn't take much
> > longer, so I am wondering why a simpler query isn't faster.
>
> Define "normal SELECT".  I can think of plenty of people who would be
> overjoyed if their average SELECT was only a couple millisecs.

OK, you asked, so here it is.  I define a simple select as pulling a
single column from a single table using uniquely indexed key.  It takes
1.182 ms on my machine, almost the same time as SELECT 1.

This tells me that the actual table access isn't the issue, it is the
overhead of the query processing itself.  What I want to find out is
where that 1ms is coming from, because it isn't coming from the
executor.  What I might do is to add ResetUsage/ShowUsage calls around
the other parts of the query loop to find who is using the time.

I am using log_duration, so this isn't measuring network time, just time
in the backend (at least I think so).

Run the attached script through psql and you will see the times.

--
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073
\set ECHO all
\timing
DROP TABLE perftest;
CREATE TABLE perftest (col text);

-- prime table with one row
INSERT INTO perftest VALUES ('0.364461265208414');

-- continously double the table size
INSERT INTO perftest SELECT random()::text FROM perftest;
INSERT INTO perftest SELECT random()::text FROM perftest;
INSERT INTO perftest SELECT random()::text FROM perftest;
INSERT INTO perftest SELECT random()::text FROM perftest;
INSERT INTO perftest SELECT random()::text FROM perftest;
INSERT INTO perftest SELECT random()::text FROM perftest;
INSERT INTO perftest SELECT random()::text FROM perftest;
INSERT INTO perftest SELECT random()::text FROM perftest;
INSERT INTO perftest SELECT random()::text FROM perftest;
INSERT INTO perftest SELECT random()::text FROM perftest;
INSERT INTO perftest SELECT random()::text FROM perftest;
INSERT INTO perftest SELECT random()::text FROM perftest;
INSERT INTO perftest SELECT random()::text FROM perftest;
INSERT INTO perftest SELECT random()::text FROM perftest;

-- insert a constant in the middle of the table, for use later
INSERT INTO perftest VALUES ('0.608254158221304');
INSERT INTO perftest SELECT random()::text FROM perftest;
-- 32770 rows

-- vacuum, create index
VACUUM ANALYZE perftest;
CREATE INDEX i_perftest ON perftest (col);
-- reduce chance of checkpoint during tests
CHECKPOINT;

-- turn on logging
SET log_duration = TRUE;
SET client_min_messages = 'log';

-- run normal and prepared queries
SELECT col FROM perftest WHERE col = '0.608254158221304';
SELECT col FROM perftest WHERE col = '0.608254158221304';
SELECT col FROM perftest WHERE col = '0.608254158221304';
SELECT col FROM perftest WHERE col = '0.608254158221304';
SELECT col FROM perftest WHERE col = '0.608254158221304';
PREPARE perftest_prep (text) AS SELECT col FROM perftest WHERE col = $1;
EXECUTE perftest_prep ('0.608254158221304');
EXECUTE perftest_prep ('0.608254158221304');
EXECUTE perftest_prep ('0.608254158221304');
EXECUTE perftest_prep ('0.608254158221304');
EXECUTE perftest_prep ('0.608254158221304');

-- first time the entire statement
SET log_statement_stats = TRUE;

-- run normal and prepared queries
SELECT col FROM perftest WHERE col = '0.608254158221304';
SELECT col FROM perftest WHERE col = '0.608254158221304';
SELECT col FROM perftest WHERE col = '0.608254158221304';
SELECT col FROM perftest WHERE col = '0.608254158221304';
SELECT col FROM perftest WHERE col = '0.608254158221304';
PREPARE perftest_prep (text) AS SELECT col FROM perftest WHERE col = $1;
EXECUTE perftest_prep ('0.608254158221304');
EXECUTE perftest_prep ('0.608254158221304');
EXECUTE perftest_prep ('0.608254158221304');
EXECUTE perftest_prep ('0.608254158221304');
EXECUTE perftest_prep ('0.608254158221304');

-- now log each query stage
SET log_statement_stats = FALSE;
SET log_parser_stats = TRUE;
SET log_planner_stats = TRUE;
SET log_executor_stats = TRUE;

-- run normal and prepared queries
SELECT col FROM perftest WHERE col = '0.608254158221304';
SELECT col FROM perftest WHERE col = '0.608254158221304';
SELECT col FROM perftest WHERE col = '0.608254158221304';
SELECT col FROM perftest WHERE col = '0.608254158221304';
SELECT col FROM perftest WHERE col = '0.608254158221304';
EXECUTE perftest_prep ('0.608254158221304');
EXECUTE perftest_prep ('0.608254158221304');
EXECUTE perftest_prep ('0.608254158221304');
EXECUTE perftest_prep ('0.608254158221304');
EXECUTE perftest_prep ('0.608254158221304');