Roger that Freek. The other thing to note is that this query is a soft parse (mis=0) and your original one was a hard parse (mis=1). Hard parses do seem to take more exec time then soft parses. But a large amount like you showed before I would think that there would have been a lot of BIND variables, but only 2 would seem very odd for that.
I suspect that there is something going on in the recursive SQL as Cary noted.
-----Original Message-----
From: oracle-l-bounce@xxxxxxxxxxxxx [mailto:oracle-l-bounce@xxxxxxxxxxxxx] On
Behalf Of D'Hooge Freek
Sent: Wednesday, November 04, 2009 10:34 AM
To: tim@xxxxxxxxx; mwf@xxxxxxxx; 'Daniel Fink'; Brandon.Allen@xxxxxxxxxxx
Cc: 'Oracle-L@xxxxxxxxxxxxx'
Subject: RE: what could cause a high elap value for the exec system call (for a
select statement)?
Tim,
I probably need some coffee, but below is an extract of the trace file for a
select statement with a group by and a having clause:
=====================
PARSING IN CURSOR #3 len=62 dep=0 uid=0 oct=3 lid=0 tim=1227795558301877
hv=3632556357 ad='2cef325c'
select veld1 from fdh.test2 group by veld1 having count(*) > 1
END OF STMT
PARSE #3:c=3000,e=3570,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=1227795558301766
EXEC #3:c=0,e=148,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1227795558303089
WAIT #3: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1
p3=0 obj#=-1 tim=1227795558303534
WAIT #3: nam='db file sequential read' ela= 60 file#=5 block#=1699 blocks=1
obj#=64322 tim=1227795558305708
WAIT #3: nam='db file scattered read' ela= 260 file#=5 block#=1700 blocks=5
obj#=64322 tim=1227795558306677
WAIT #3: nam='db file scattered read' ela= 112 file#=5 block#=1705 blocks=8
obj#=64322 tim=1227795558308098
WAIT #3: nam='db file scattered read' ela= 107 file#=5 block#=1714 blocks=7
obj#=64322 tim=1227795558308960
WAIT #3: nam='db file scattered read' ela= 114 file#=5 block#=1721 blocks=8
obj#=64322 tim=1227795558309856
WAIT #3: nam='db file scattered read' ela= 112 file#=5 block#=1730 blocks=7
obj#=64322 tim=1227795558310705
WAIT #3: nam='db file scattered read' ela= 116 file#=5 block#=1737 blocks=8
obj#=64322 tim=1227795558311554
... lots more of db file scattered read
WAIT #3: nam='db file scattered read' ela= 159 file#=5 block#=14589 blocks=12
obj#=64322 tim=1227795558903786
WAIT #3: nam='db file scattered read' ela= 214 file#=5 block#=14617 blocks=16
obj#=64322 tim=1227795558904755
WAIT #3: nam='db file scattered read' ela= 203 file#=5 block#=14649 blocks=16
obj#=64322 tim=1227795558905575
WAIT #3: nam='SQL*Net more data to client' ela= 38 driver id=1413697536
#bytes=2144 p3=0 obj#=64322 tim=1227795558906250
FETCH
#3:c=616906,e=602931,p=8857,cr=8866,cu=0,mis=0,r=1,dep=0,og=1,tim=1227795558906963
WAIT #3: nam='SQL*Net message from client' ela= 679 driver id=1413697536
#bytes=1 p3=0 obj#=64322 tim=1227795558908162
FETCH #3:c=0,e=68,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1227795558908757
WAIT #3: nam='SQL*Net message to client' ela= 1 driver id=1413697536 #bytes=1
p3=0 obj#=64322 tim=1227795558909221
WAIT #3: nam='SQL*Net message from client' ela= 4207 driver id=1413697536
#bytes=1 p3=0 obj#=64322 tim=1227795558913914
=====================
STAT #3 id=1 cnt=1 pid=0 pos=1 obj=0 op='FILTER (cr=8866 pr=8857 pw=0
time=602274 us)'
STAT #3 id=2 cnt=1 pid=1 pos=1 obj=0 op='HASH GROUP BY (cr=8866 pr=8857 pw=0
time=602327 us)'
STAT #3 id=3 cnt=26000 pid=2 pos=1 obj=64322 op='TABLE ACCESS FULL TEST2
(cr=8866 pr=8857 pw=0 time=991080 us)'
Now, as the exec call is placed before the reading of the blocks from disk,
then how can the time needed for the filtration be included in the e value of
the exec call?
Mvg,
Freek D'Hooge
Uptime
Oracle Database Administrator
email: freek.dhooge@xxxxxxxxx
tel +32(0)3 451 23 82
http://www.uptime.be
disclaimer: www.uptime.be/disclaimer
________________________________________
From: Tim Gorman [mailto:tim@xxxxxxxxx]
Sent: woensdag 4 november 2009 15:59
To: D'Hooge Freek; mwf@xxxxxxxx; 'Daniel Fink'; tim@xxxxxxxxx;
Brandon.Allen@xxxxxxxxxxx
Cc: 'Oracle-L@xxxxxxxxxxxxx'
Subject: Re: what could cause a high elap value for the exec system call (for a
select statement)?
D'Hooge,
The answer to your question is largely "yes", except I'd word it as "exec call includes all work (after parse call constructs the cursor) to construct the result set for the cursor".
Rows cannot be retrieved (fetched) at the start of a GROUP BY operation or an ORDER BY operation for example, they can only be retrieved after those operations complete. If there is a HAVING clause then there is additional filtering to perform before the fetch phase can begin, etc. Whether that sorting or hashing occurs in private process memory (PGA) or in temporary segments is only a matter of elapsed time, but the EXEC phase won't complete until any such operations (as well as recursive operations in their entirety, as Cary pointed out) complete.
Hope this helps...
-Tim
-----Original Message-----
From: D'Hooge Freek [mailto:Freek.DHooge@xxxxxxxxx]
Sent: Wednesday, November 4, 2009 07:07 AM
To: mwf@xxxxxxxx, ''Daniel Fink'', tim@xxxxxxxxx, Brandon.Allen@xxxxxxxxxxx
Cc: 'Oracle-L@xxxxxxxxxxxxx'
Subject: RE: what could cause a high elap value for the exec system call (for a
select statement)?
Mark, Am I correct to say that, for a select statement, the exec call includes
all the work (except parsing) that needs to be done to construct the cursor and
that the fetch call includes all the work that needs to be done to retrieve
rows from that cursor? Regards, Freek D'Hooge Uptime Oracle Database
Administrator email: freek.dhooge@xxxxxxxxx tel +32(0)3 451 23 82
http://www.uptime.be disclaimer: www.uptime.be/disclaimer -----Original
Message----- From: oracle-l-bounce@xxxxxxxxxxxxx
[mailto:oracle-l-bounce@xxxxxxxxxxxxx] On Behalf Of Mark W. Farnham Sent:
woensdag 4 november 2009 14:47 To: D'Hooge Freek; 'Daniel Fink'; tim@xxxxxxxxx;
Brandon.Allen@xxxxxxxxxxx Cc: 'Oracle-L@xxxxxxxxxxxxx' Subject: RE: what could
cause a high elap value for the exec system call (for a select statement)? I'm
pretty sure Tim meant that in the context a whole heck of a lotta work must
occur before you know what the first row to return is. Another example is if
you have a union (non-all) and the
source datasets of the parts of the union don't have a provable joint subkey, then you have to do full projection of all the columns in the parts of the queries and sort the resultset for duplicate rejection before you return anything. Something like that with 1000 columns in the select list would be a really bad joke to play on a computer system. Please do correct me if I got that wrong, Tim. mwf
--
//www.freelists.org/webpage/oracle-l
--
//www.freelists.org/webpage/oracle-l
