Markus Bertheau ☭ wrote:
>Hi, I have the following strange situation:
>
>
>
...
>oocms=# explain analyze select count(1) from objects where class = 'Picture';
> QUERY PLAN
>----------------------------------------------------------------------------------------------------------------
> Aggregate (cost=278.16..278.16 rows=1 width=0) (actual time=44.121..44.123 rows=1 loops=1)
> -> Seq Scan on objects (cost=0.00..267.65 rows=4205 width=0) (actual time=0.030..33.325 rows=4308 loops=1)
> Filter: ("class" = 'Picture'::text)
> Total runtime: 44.211 ms
>(записей: 4)
>
>oocms=# explain analyze select class_get_number_of_objects('Picture');
> QUERY PLAN
>--------------------------------------------------------------------------------------
> Result (cost=0.00..0.01 rows=1 width=0) (actual time=27.019..27.022 rows=1 loops=1)
> Total runtime: 27.062 ms
>(записей: 2)
>
>
>I.e. a function takes 27 ms to do what takes an equivalent piece of sql
>43 ms. How can this be explained?
>
>Some more info:
>
>
In explain analyze, there is a per-row overhead of 2 gettimeofday()
calls. This is usually very low and hidden in I/O, but on queries where
you go through a lot of rows, but things are cached in ram, it can show up.
So the explain analyze is going deep into the SQL query.
With a stored procedure, explain analyze only runs the procedure, it
doesn't instrument the actual function. So you don't have that per-row
overhead.
For an alternate accurate view. Try:
# \timing
# explain analyze select count(1) from objects where class = 'Picture';
# explain analyze select class_get_number_of_objects('Picture');
\timing will also give you the time it takes to run the query, but it
doesn't instrument anything.
John
=:->
