Thread: Is it bug???

Is it bug???

From
Dinar
Date:
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Hello All,
I'm using postgresql 7.3.2
And noticed strange bahaviour of
explain analyze command.
I use it to see how  pl/pgsql function is executed:

Here is the function:

CREATE or replace FUNCTION flow1() RETURNS setof cidr
      AS 'declare
clientnets refcursor;
i int4;
inc boolean;
rule int4;
srcaddr cidr;
dstaddr cidr;
sprtb int4;
dprtb int4;
sprte int4;
dprte int4;
num int4;
mark int4;
sumoctets int4;
sumpackets int4;
n int4;
begin
select into n count(*) from traffic_temp;
if n=0 then return; end if;
select into num count(*) from rules;
open clientnets for select id,snets,dnets,sportb,dportb,sporte,dporte
from rules;
for i in 0..(num-1) loop
FETCH clientnets INTO rule,srcaddr,dstaddr,sprtb,dprtb,sprte,dprte;
sumpackets:=0;
sumoctets:=0;
select into sumoctets,sumpackets sum(octets),sum(packets) from
traffic_temp where dst<<dstaddr and src<<srcaddr and (dstport between
dprtb and dprte) and (srcport between sprtb and sprte);
select into mark count(*) from traffic where date between
to_date(timeofday(),''Dy Mon DD HH24:MI:SS.US YYYY '') and
to_date(timeofday(),''Dy Mon DD HH24:MI:SS.US YYYY '')||''23:59:59'' and
ruleid=rule;
if mark>0 then
if sumpackets is not null or sumoctets is not null then
RAISE NOTICE ''here is update'';
update traffic set packets=packets+sumpackets,bytes=bytes+sumoctets
where ruleid=rule;
end if;
return next dstaddr;
else
if sumpackets is not null or sumoctets is not null then
RAISE NOTICE ''here is insert'';
insert into traffic(ruleid,packets,bytes) values(rule,sumpackets,sumoctets);
end if;
return next dstaddr;
end if;
end loop;
return;
end;
' LANGUAGE plpgsql;

I create temp table inside of transaction then I copy some data from
file to backend
and I run the function that does some calculations.
After commiting transaction I do
explain analyze verbose to see how the function is executed and how long
it was executing.

But I see strange things first inserts done as it should because there
is no data on target table,
but then there goes update that shouldn't be and the result of
calculations doubles.

I thought that explain analyze doesn't execute query it's only estimate
time and other things.

Here is the output of execution:

BEGIN
                timeofday
- - - -------------------------------------
   Thu Aug 21 16:45:02.165129 2003 MSD
(1 row)

CREATE TABLE
COPY
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
NOTICE:  here is insert
         flow1
- - - -------------------
   217.107.90.32/30
   217.107.90.36/30
   217.107.90.40/30
   217.107.90.44/30
   217.107.90.48/30
   217.107.90.52/30
   217.107.90.56/30
   217.107.90.60/30
   217.107.125.0/24
   217.107.90.104/30
   217.107.90.64/30
   217.107.90.68/30
   217.107.90.76/30
   217.107.90.192/29
   217.107.90.108/30
   217.107.90.96/30
   217.107.90.112/28
   217.107.90.128/26
   217.107.90.0/29
   217.107.93.88/30
(20 rows)

                timeofday
- - - -------------------------------------
   Thu Aug 21 16:45:08.575788 2003 MSD
(1 row)

COMMIT
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
NOTICE:  here is update
                                                    QUERY PLAN

- - -
- -
- --------------------------------------------------------------------------------------------------------------
      { FUNCTIONSCAN
      :startup_cost 0.00
      :total_cost 12.50
      :rows 1000
      :width 32
      :qptargetlist (
         { TARGETENTRY
         :resdom
            { RESDOM
            :resno 1
            :restype 650
            :restypmod -1
            :resname flow1
            :reskey 0
            :reskeyop 0
            :ressortgroupref 0
            :resjunk false
            }

         :expr
            { VAR
            :varno 1
            :varattno 1
            :vartype 650
            :vartypmod -1
            :varlevelsup 0
            :varnoold 1
            :varoattno 1
            }
         }
      )

      :qpqual <>
      :lefttree <>
      :righttree <>
      :extprm ()

      :locprm ()

      :initplan <>
      :nprm 0
      :scanrelid 1
      }

   Function Scan on flow1  (cost=0.00..12.50 rows=1000 width=32) (actual
time=1654.07..1654.11 rows=20 loops=1)
   Total runtime: 1654.16 msec
(46 rows)

Best regards, Dinar






-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.2.1 (GNU/Linux)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org

iD8DBQE/VEAWvJCZ1+6kxnoRAsPCAKCDY69p48kr/AxqfGEzvgzj9a+MeQCfevxd
TsctDuf59fXUtXfiD4gDR0w=
=DYwD
-----END PGP SIGNATURE-----

Re: Is it bug???

From
Tom Lane
Date:
Dinar <dinar@yantel.ru> writes:
> I thought that explain analyze doesn't execute query

You thought wrong.  Is the manual's explanation not clear enough?

            regards, tom lane

Re: Is it bug???

From
"Ringo"
Date:
What a prick..

"Tom Lane" <tgl@sss.pgh.pa.us> wrote in message
news:25792.1062510815@sss.pgh.pa.us...
> Dinar <dinar@yantel.ru> writes:
> > I thought that explain analyze doesn't execute query
>
> You thought wrong.  Is the manual's explanation not clear enough?
>
> regards, tom lane
>
> ---------------------------(end of broadcast)---------------------------
> TIP 9: the planner will ignore your desire to choose an index scan if your
>       joining column's datatypes do not match
>

Re: Is it bug???

From
Bruno Wolff III
Date:
On Wed, Sep 03, 2003 at 23:19:24 -0700,
  Ringo <no@email.com> wrote:
> What a prick..

From observing Tom's responses here, I think this is a real question (not
an RTFM response). If the documentation doesn't make it clear to new readers
that explain analyze does execute the query (though doesn't return the
results), then the documentation needs to get fixed.

>
> "Tom Lane" <tgl@sss.pgh.pa.us> wrote in message
> news:25792.1062510815@sss.pgh.pa.us...
> > Dinar <dinar@yantel.ru> writes:
> > > I thought that explain analyze doesn't execute query
> >
> > You thought wrong.  Is the manual's explanation not clear enough?
> >
> > regards, tom lane
> >
> > ---------------------------(end of broadcast)---------------------------
> > TIP 9: the planner will ignore your desire to choose an index scan if your
> >       joining column's datatypes do not match
> >
>
>
>
>
> ---------------------------(end of broadcast)---------------------------
> TIP 4: Don't 'kill -9' the postmaster

Re: Is it bug???

From
Rod Taylor
Date:
On Fri, 2003-09-05 at 09:18, Bruno Wolff III wrote:
> On Wed, Sep 03, 2003 at 23:19:24 -0700,
>   Ringo <no@email.com> wrote:
> > What a prick..
>=20
> >From observing Tom's responses here, I think this is a real question (not
> an RTFM response). If the documentation doesn't make it clear to new read=
ers
> that explain analyze does execute the query (though doesn't return the
> results), then the documentation needs to get fixed.

I see 3 places on the EXPLAIN page that states ANALYZE queries are
executed. Perhaps it should be noted elsewhere, but it is well described
in the "SQL Commands" section of the docs.

One with the ANALYZE keyword under 'Inputs':
        Flag to carry out the query and show actual run times.

One in the description:
        The ANALYZE option causes the query to be actually executed, not
        only planned. The total elapsed time expended within each plan
        node (in milliseconds) and total number of rows it actually
        returned are added to the display. This is useful for seeing
        whether the planner's estimates are close to reality.

Finally, one in a big CAUTION block near the bottom of the description:

        Keep in mind that the query is actually executed when ANALYZE is
        used. Although EXPLAIN will discard any output that a SELECT
        would return, other side-effects of the query will happen as
        usual. If you wish to use EXPLAIN ANALYZE on an INSERT, UPDATE,
        or DELETE query without letting the query affect your data, use
        this approach:=20
=20=20=20=20=20=20=20=20
        BEGIN;
         EXPLAIN ANALYZE ...;
         ROLLBACK;