[HACKERS] total execution time as reported by auto_explain

[Jaime Casanova]

Hi,

I was using auto_explain to log plans (with analyze option on) from
queries that take more than 500ms, something i found i little odd is
that the duration says 779ms but actual time says 269ms (almost 3
times lower), maybe some kind of instrumentation cleanup can explain
this?

2009-11-10 10:32:41 GMTLOG:  duration: 779.938 ms  plan:
        Sort  (cost=1943.99..1967.38 rows=9355 width=466) (actual
time=235.655..269.061 rows=4997 loops=1)

-- 
Atentamente,
Jaime Casanova
Soporte y capacitación de PostgreSQL
Asesoría y desarrollo de sistemas
Guayaquil - Ecuador
Cel. +59387171157

2009-11-10 10:32:41 GMTLOG:  duration: 779.938 ms  plan:
        Sort  (cost=1943.99..1967.38 rows=9355 width=466) (actual 
time=235.655..269.061 rows=4997 loops=1)
          Sort Key: (upper(ltrim((b.nombre)::text)))
          Sort Method:  quicksort  Memory: 3000kB
          ->  Hash Left Join  (cost=8.18..1326.95 rows=9355 width=466) (actual 
time=0.516..161.361 rows=4997 loops=1)
                Hash Cond: (CASE btrim((b.marca)::text) WHEN ''::text THEN 
NULL::bpchar ELSE b.marca END = c.codigo)
                ->  Seq Scan on fcproduc b  (cost=0.00..1130.73 rows=9355 
width=216) (actual time=0.194..65.821 rows=4997 loops=1)
                      Filter: (upper((nombre)::text) ~~ '%1%'::text)
                ->  Hash  (cost=8.16..8.16 rows=2 width=261) (actual 
time=0.153..0.153 rows=1 loops=1)
                      ->  Bitmap Heap Scan on dbtablas c  (cost=3.27..8.16 
rows=2 width=261) (actual time=0.125..0.129 rows=1 loops=1)
                            Recheck Cond: (tipo = 'MAR'::bpchar)
                            ->  Bitmap Index Scan on dbtablas_pkey  
(cost=0.00..3.27 rows=2 width=0) (actual time=0.074..0.074 rows=1 loops=1)
                                  Index Cond: (tipo = 'MAR'::bpchar)
2009-11-10 10:32:41 GMTSTATEMENT:  select 
b.codigo,b.nombre,b.ubicacion,b.grupo,b.P_IVA,b.PRECIO,b.PRECIO_2,b.PRECIO_3,b.PRECIO_4,b.PRECIO_5,c.nombre
 AS marca,b.codigo_a 
          FROM fcproduc b 
               LEFT OUTER JOIN dbtablas c ON c.codigo = case TRIM(b.marca) when 
'' then null else b.marca end and c.tipo = 'MAR'  
         WHERE UPPER(b.NOMBRE) LIKE UPPER('%1%') order by UPPER(LTRIM(b.nombre))

-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers