Is it bug???

From: Dinar <dinar(at)yantel(dot)ru>
To: pgsql-bugs(at)postgresql(dot)org
Subject: Is it bug???
Date: 2003-09-02 07:00:32
Message-ID: 3F544010.2020308@yantel.ru
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

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

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message sad 2003-09-02 12:29:26 Re: session variable
Previous Message Tom Lane 2003-09-02 04:17:28 Re: Vacuum I/O throttling