Thread: Difference between EXPLAIN ANALYZE SELECT ... total runtime and SELECT ... runtime

Hello,

I have strange problem.

I test/optimize my queries with EXPLAIN ANALYZE. I get for example:

Total runtime: 40.794 ms

But when I run query without EXPLAIN ANALYZE i get, for example:

Time: 539.252 ms

Query returns 33 rows. Why?

I do checks with psql connected using socket to postgresql server. No SSL.

Using PostgreSQL 8.4.4.

--
Piotr Gasidło

W dniu 22 lipca 2010 21:34 użytkownik Szymon Guz <mabewlun@gmail.com> napisał:
> maybe the query waits on a lock or maybe the returned rows are very big.

So shouldn't EXPLAIN ANALYZE be also affected by waiting for lock?

The row has width = 313, so it's not big.

I've reduced it to witdh = 12 (only one column, int4 type), and get
EXPLAIN ANALYZE:

Total runtime: 14.788 ms

And only SELECT returns:

Time: 456,528 ms

Or maybe "Total runtime" it's not what I thought it is, and I should
look at psql \timing result, which form EXPLAIN ANALYZE is nearly the
same like for SELECT:

Time: 402,675 ms

--
Piotr Gasidło

W dniu 22 lipca 2010 21:46 użytkownik Piotr Gasidło
<quaker@barbara.eu.org> napisał:
> W dniu 22 lipca 2010 21:34 użytkownik Szymon Guz <mabewlun@gmail.com> napisał:
> (...)

Something new. The query is run against table which has been
partitioned into a lot of small tables.
When I combine data and put it into one table - the execution of
EXPLAIN ANALYZE compares with real SELECT timeing.

On paritioned:

EXPLAIN ANALYZE SELECT ...
Total runtime: 14.790 ms
Time: 291,637 ms

On one table with data from all partitions and same indexes:

EXPLAIN ANALYZE SELECT ...

Total runtime: 16.418 ms
Time: 17,371 ms

Can someone give me clue why EXPLAIN ANALYZE don't work correctly with
partitions?

--
Piotr Gasidło

In response to Piotr Gasid??o :
> Hello,
>
> I have strange problem.
>
> I test/optimize my queries with EXPLAIN ANALYZE. I get for example:
>
> Total runtime: 40.794 ms
>
> But when I run query without EXPLAIN ANALYZE i get, for example:
>
> Time: 539.252 ms
>
> Query returns 33 rows. Why?

Maybe cheaply or virtuell hardware? There are some issues with functions
like gettimoofday(), see here:

http://archives.postgresql.org/pgsql-general/2007-01/msg01653.php
(and the whole thread)

Regards, Andreas
--
Andreas Kretschmer
Kontakt:  Heynitz: 035242/47150,   D1: 0160/7141639 (mehr: -> Header)
GnuPG: 0x31720C99, 1006 CCB4 A326 1D42 6431  2EB0 389D 1DC2 3172 0C99

2010/7/23 A. Kretschmer <andreas.kretschmer@schollglas.com>:
> Maybe cheaply or virtuell hardware?

Cheap - probably, I known processor, but don't know mainboard. It's
dedicated server. Maybe it has silent problems with time keeping.
Virtual - also yes. Postgresql run in separate vserver, but I've
executed psql also from that vserver, so there should be no
differences. But I'll try to test it without vserver.

> There are some issues with functions
> like gettimoofday(), see here:
>
> http://archives.postgresql.org/pgsql-general/2007-01/msg01653.php
> (and the whole thread)

Thanks, i will look at it.

--
Piotr Gasidło

W dniu 23 lipca 2010 10:51 użytkownik Piotr Gasidło
<quaker@barbara.eu.org> napisał:
> 2010/7/23 A. Kretschmer <andreas.kretschmer@schollglas.com>:
>> Maybe cheaply or virtuell hardware?
> (...)
>> There are some issues with functions
>> like gettimoofday(), see here:
> (..)

Just tested it on my workstation. No vserver. The same result.

EXPLAIN ANALYZE SELECT ...

Total runtime: 72.745 ms
Time: 1916,269 ms

SELECT ...

Time: 2121,198 ms

The table structure is:

ocaches
ocaches_2010_06_0 (inherits ocaches)
ocaches_2010_06_1 (inherits ocaches)
ocaches_2010_06_2 (inherits ocaches)
ocaches_2010_06_3 (inherits ocaches)
ocaches_2010_06_4 (inherits ocaches)
....
ocaches_2013_06_4 (inherits ocaches)

Constraint checks by date on each partition.

\d ocaches
                  Table "ocaches"
        Column         |            Type             | Modifiers
-----------------------+-----------------------------+-----------
 oc_count              | integer                     |
 oc_h_id               | integer                     |
 oc_date_from          | date                        |
 oc_date_to            | date                        |
 oc_duration           | integer                     |
...

Many columns mainly integer and integer[].

Index on column oc_h_id on each paritioned table.

query:

SELECT
oc_h_id,oc_duration,SUM(oc_count) FROM ocaches_joined WHERE
oc_date_from >= '2010-07-22'::date AND oc_date_from >=
'2010-07-24'::date AND oc_h_id =

ANY('{"32842","3095","27929","2229","22769","3098","33433","22559","226","2130","226","2130","2229","3095","3098","22559","22769","27929","32842","33433"}'::int[])
GROUP BY oc_h_id, oc_duration;

--
Piotr Gasidło