`Re: Stored procedure overhead
True. The CURRENT is only resolved at the time of execution.
David
(Embedded
image moved Irwin Goldstein <irwin @ objectsoft.com> at
to file: WVUS-SMTP
PIC001.PCX) 01/01/97 11:15 PM
To: informix-list @ rmy.emory.edu at WVUS-SMTP@CCMAIL
cc: (bcc: David Coburn/ISG/WVUS/WorldVision)
Subject: Re: Stored procedure overhead
Paul Mailman <pamailman@qed.com> wrote in article
<c1f7cc$10310.7c@www.qed.com>...
> <snip> ... However, some recent experimentation appears to show that
there can be a
> surprisingly large overhead involved in stored procedure execution. I
wonder
> if anyone can provide any insight.
>
> I'd written a stored procedure that took what I thought was surprisingly
long
> to execute. To get a handle on where the performance bottlneck was, I
created
> a table that would log a timestamp and comment, and I wrote a "log"
procedure:
>
> create procedure log(comment char(30))
> insert into logtable
> (sl_stamp,sl_text)
> values(CURRENT,comment);> end procedure
>
> I sprinkled a number of calls to "log" throughout my procedure and then
> executed the following three commands together:
>
> execute procedure log("begin");
> execute procedure myproc();
> execute procedure log("end");>
> Then I looked at the contents of logtable. I was quite surprised to see:
>
> sl_serial sl_stamp sl_text
> 2 15:15:52.6 begin
> 3 15:15:52.8 first log within myproc()
> ...
> 15:15:52.8 all other logs withing myroc()
> ...
> 15 15:15:52.8 last log within myproc() (just before end of
procedure)
> 16 15:16:06.4 end
>
> That is, within the resolution of the clock, the entire stored procedure
> happened essentially instantaneously, yet it took nearly 6 seconds to
return
> from myproc() and execute the "end" log.
> <snip>
I seem to recall someone in this newsgroup mentioning tha the CURRENT
function call in SPL is resolved only ONCE for an entire call to a
procedure. Thus all of your logs within the same procedure will show the
same time, even if the procedure took hours to execute. Can anyone else
verify this? If this IS the case, the bottleneck may be in the procedure
itself rather than the overhead of calling it.
--
Irwin Goldstein
Objective Software Systems, Inc.
http://www.objectsoft.com
The following is an attached File item from cc:Mail. It contains
information that had to be encoded to ensure successful transmission
through various mail systems. To decode the file use the UUDECODE
program.
--------------------------------- Cut Here ---------------------------------
begin 644 PIC001.PCX 01/02/97 09:29 AM
M"@4!"`````!H`"P`````````````````````````````````````````````
M```````````````````````````!:0`!````````````````````````````
M``````````````````````````````````````````````````#U$]L3S1/'
M$\\,3PA/U$]L3S1/'$\\,3PA/U$]L3S1/'$\\,3PA/U$]L3S1/'$\\,3PA/U$]L3
MS1/'$\\,3PA/U$]L3S1/'$\\,3PA/U$]L3S1/'$\\,3PA/U$]L3S1/'$\\,3PA/U
M$]L3S1/'$\\,3PA/P$PS(!@S8$\\P3QA/#$\\(3[A/.!M<3S!/&$\\,3$^P3P@;"
M!P;"$@;"$@;"$L4&UA/+$\\83PQ,3ZA,,P@8'P@+"`P(2P@?$$L,"PP;5$\\L3
MQ1/#$Q/I$\\,&`P<"!P,"PA+#!\\(2P@(2P@+#!M43RA/%$\\,3$^@3P@('`\\("
M$PX##@+#$\\42PP+"$,(&U!/*$\\43PQ,3YQ,"`P<#`@X3#@(3P@(2#\\(2#\\(2
M!1("$<("PP;4$\\H3Q1/"$Q/F$P8"!P,"#@(.P@+#$Q(3$A/"$@\\&Q@+#!M,,
M#`?)$\\03PA,3YA,&PP(3!@,"#A+%$P\\2$\\(2!@(#PA(#$L,&!],#QPP'Q1/#
M$Q/E$P8'`A$2`@\\"PA,/PA,/Q!,/Q1(0P@(#`@,"!M,#QP/$#`?#$\\(3X1,'
MPPS"!@+"$A,"#Q+($\\,2#\\,2PP(0`P(#!@?2#,D#P@/"#`?"$Q/;$P?&#,(#
M#`('$1(3$A,2PQ,/PQ,/PQ/#$@(#`@,"PP,"!@S1$P?'#,8##,(3$]83!\\4,
MR`,&!\\("!A+#`L83$A,2$Q(/PA('`@<"`P40`@81!@?2$\\43!\\0,P@,,PA,3
MTA,'Q`S+`\\(,!L(2#Q$2$Q(3`PX#Q!,2$Q(3PQ("!P/"`L,##,(&!](3R1,'
MPPS"$Q//$P?##,D#Q0P'PA,&!Q(3`A$"$P,.`@[#$Q(3#Q,/PQ(#`@,"!P,"
M#`81!@?2$\\D3PA/"#,(3$\\P3!\\,,QP/$#,('QQ,&Q!+#`@X##@(&P@_($@(#
MP@(#`@P"$,(&!](3R1,'#`<,PA,3RA,'P@S&`\\,,P@?,$P8'PA+"$`(.`@X"
M#A##`A(/QA(%`@7#`@4"$08'TA/'$P?"#`</#,(3$\\@3!\\(,Q0/##`?0$P;#
M$A#$`A`.$`X0P@+&$@<2!A(&!<,"!<(&!]`3!\\4,$P?"#`\\'#PP'PA,3QA,'
MP@S$`\\,,!],3!@?"$A`#$,("#A`.$,("$0(#QQ(&!P;"`@4"$08'RQ,'Q`P'
MPA,'$PS"$P</!P\\,!\\,3$\\43!PS$`\\(,!]83!L02$`,"`\\4"$0(#`@/#$@<2
M!@?"!@40`A#"!@?&$P?$#`?&$\\(-$PS"$P\\'P@P'PQ/"$\\03!PS#`\\(,!]@3
M!@?$$A`"$,8"$0(#`L02!A+#!L("$`+"!@?"$P?##`?*$P?"#1,'PA/"#`?$
M$\\(3$\\,3!PS"`\\(,!]H3#!('PQ+##!$#Q0(#`@/#$@82!@?"!@(0`A`&#`?"
M$PS#$\\,'R1,'PA/"!Q,'Q1/#$Q/#$PS"`PP'W1,&QQ("$0/#`@,"`\\,2!A(&
M!P8,!A`"$`(&#,,3#!/"!\\83PP?'$P?&$\\,3PA/#$PP##`?>$P8'QQ("$0/#
M`@,"PA(&$@8'!@P&$`(0`L(&!\\,3#,83PP?*$PS&$\\,3PA/#$\\(,!]\\3#!+"
M!\\42`@,1Q`(2!\\(2!@<&#`80!A`&$`8,!\\,,!\\D3PP?'$PS&$\\,3PA/#$PP/
MP@S?$P82!\\(2!\\(2`A$"`P(#$@<2!P8'!@P&$`80Q@S##\\('Q1/#!\\D3!PS&
M$\\,3PA/#$PS##\\0,W!/"!A(&PQ(&`A$"`P('!@<&R`S)#Q,'S1,'PPP'QQ/#
M$\\(3PQ,'#,8/QPP'U!,&$@82!A++#,X/PPP3#,<3P@?$#`?)$\\03PA,3Q!,'
MP@S+#]L,TP_&#`?#$PS#$P?$#`?+$\\83PQ,3QA,'Q`SM#\\@,!@?($\\0,!\\X3
MQQ/#$\\(3RA,'QPS;#\\L,$`4,!<(,P@8'U1/*$\\43PQ,3T1,'VPP&$`80!A`"
M!0P%#`4,!@P'!@?6$\\L3Q1/#$Q/N$P8,!A`&$`(&#`8,PP8'UQ/+$\\83PQ,3
M\\!/*!@?8$\\P3QA/#$Q/U$]L3S1/'$\\,3PA/U$]L3S1/'$\\,3PA,,````@```
M`(``@(````"`@`"``("`P,#`P-S`ILKP__OPH*"D@("`_P```/\\`__\\```#_
M_P#_`/______````@````(``@(````"`@`"``("`P,#`P-S`ILKP__OPH*"D
M@("`_P```/\\`__\\```#__P#_`/______````@````(``@(````"`@`"``("`
MP,#`P-S`ILKP__OPH*"D@("`_P```/\\`__\\```#__P#_`/______````@```
M`(``@(````"`@`"``("`P,#`P-S`ILKP__OPH*"D@("`_P```/\\`__\\```#_
M_P#_`/______````@````(``@(````"`@`"``("`P,#`P-S`ILKP__OPH*"D
M@("`_P```/\\`__\\```#__P#_`/______````@````(``@(````"`@`"``("`
MP,#`P-S`ILKP__OPH*"D@("`_P```/\\`__\\```#__P#_`/______````@```
M`(``@(````"`@`"``("`P,#`P-S`ILKP__OPH*"D@("`_P```/\\`__\\```#_
M_P#_`/______````@````(``@(````"`@`"``("`P,#`P-S`ILKP__OPH*"D
M@("`_P```/\\`__\\```#__P#_`/______````@````(``@(````"`@`"``("`
MP,#`P-S`ILKP__OPH*"D@("`_P```/\\`__\\```#__P#_`/______````@```
M`(``@(````"`@`"``("`P,#`P-S`ILKP__OPH*"D@("`_P```/\\`__\\```#_
M_P#_`/______````@````(``@(````"`@`"``("`P,#`P-S`ILKP__OPH*"D
M@("`_P```/\\`__\\```#__P#_`/______````@````(``@(````"`@`"``("`
MP,#`P-S`ILKP__OPH*"D@("`_P```/\\`__\\```#__P#_`/______````@```
J`(``@(````"`@`"`__OPH*"D@("`_P```/\\`__\\```#__P#_`/______
end