Обсуждение: Difference between EXPLAIN ANALYZE SELECT ... total runtime and SELECT ... runtime

Поиск
Список
Период
Сортировка

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

От
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?

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

Using PostgreSQL 8.4.4.

--
Piotr Gasidło

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

От
Szymon Guz
Дата:


W dniu 22 lipca 2010 21:24 użytkownik Piotr Gasidło <quaker@barbara.eu.org> napisał:
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.


Hi,
maybe the query waits on a lock or maybe the returned rows are very big.

regards
Szymon Guz

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

От
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

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

От
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

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

От
"A. Kretschmer"
Дата:
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

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

От
Piotr Gasidło
Дата:
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

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

От
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