Thread: Assessing performance of fetches

Assessing performance of fetches

From
John Rouillard
Date:
Hi all:

An application running against a postgres 8.4.5 database under CentOS
5.5 uses cursors (I think via SqlAlchemy). To look for database
performance issues I log any query that takes > 2 seconds to complete.

I am seeing:

  2011-04-16 00:55:33 UTC user@database(3516): LOG:  duration:
     371954.811 ms  statement: FETCH FORWARD 1 FROM c_2aaaaaaeea50_a08

While I obviously have a problem here, is there any way to log the
actual select associated with the cursor other than logging all
statements?

Also once I have the select statement, does the fact that is is
associated with a fetch/cursor change the steps I should take in
tuning it compared to somebody just issuing a normal select?

Thanks for any ideas.

--
                -- rouilj

John Rouillard       System Administrator
Renesys Corporation  603-244-9084 (cell)  603-643-9300 x 111

Re: Assessing performance of fetches

From
Tom Lane
Date:
John Rouillard <rouilj@renesys.com> writes:
> I am seeing:

>   2011-04-16 00:55:33 UTC user@database(3516): LOG:  duration:
>      371954.811 ms  statement: FETCH FORWARD 1 FROM c_2aaaaaaeea50_a08

> While I obviously have a problem here, is there any way to log the
> actual select associated with the cursor other than logging all
> statements?

Can't think of one :-(

> Also once I have the select statement, does the fact that is is
> associated with a fetch/cursor change the steps I should take in
> tuning it compared to somebody just issuing a normal select?

The planner does treat cursor queries a bit different from plain
queries, putting more emphasis on getting the first rows sooner.
If you want to be sure you're getting the truth about what's happening,
try
    EXPLAIN [ANALYZE] DECLARE c CURSOR FOR SELECT ...
rather than just
    EXPLAIN [ANALYZE] SELECT ...
Other than that, it's the same as tuning a regular query.

            regards, tom lane