Ed,
I think the time descrepancy is due to how the db/os gathers the
timing stats during a trace. From my experience it's just a "blip" and
not a sign of a problem. If cpu was lower than elapsed, then i'd say
your sql was waiting on some resource.
The query seems fast enough, but i'd take a look at those reads, 6600
for 20,000 rows? How big is the table? Are the stats up to date?
What's the performace like using a full scan?
Ed Stevens <nospam_at_noway.nohow> wrote in message news:<k0t9rv0768incjhidb5ear4jmdplrek2da_at_4ax.com>...
> Oracle 9.2 on Solaris 9
>
> In response to a developer's complaint that a query suddenly went
> south, I ran the query w/ sql_trace=true then fed the resulting trace
> file to TKPROF. An interesting result was that on the fetch phase,
> the cpu time was 0.51 seconds, while the elapsed time was 0.44 sec.
> Sonds like a house that's bigger on the inside than on the outside.
>
> Here's the TKPROF report. Sorry about the line wraps. If someone can
> tell me how to prevent that, as well, I'd be grateful. (I'm using Free
> Agent as my newsreader)
>
> The rest of the report, including the access plan, looks pretty good
> to me. If someone wants to disabuse me of that notion, I won't mind
> being further educated.
>
>
> TKPROF: Release 9.2.0.1.0 - Production on Fri Nov 14 08:16:37 2003
>
> Copyright (c) 1982, 2002, Oracle Corporation. All rights reserved.
>
> Trace file: cmdm1240_ora_13714.trc
> Sort options: default
>
> <snip>
> ********************************************************************************
>
> select POSTED_NAME,
> WORK_ORDER_NUMBER,
> SITE_ID,
> GL_ACCOUNT,
> WBS_ELEMENT,
> COST_CENTER,
> SUMMARY_COST,
> TOTAL_COST
> from NMM.POSTED_SUMMARY
> where POSTED_NAME = 'TESTPOST'
> AND POSTED_CODE = 'F'
>
> call count cpu elapsed disk query current
> rows
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> Parse 1 0.00 0.01 0 0 0
> 0
> Execute 1 0.00 0.00 0 0 0
> 0
> Fetch 1335 0.51 0.42 0 6613 0
> 20000
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> total 1337 0.51 0.44 0 6613 0
> 20000
>
> Misses in library cache during parse: 1
> Optimizer goal: CHOOSE
> Parsing user id: 5
>
> Rows Row Source Operation
> ------- ---------------------------------------------------
> 20000 TABLE ACCESS BY INDEX ROWID POSTED_SUMMARY
> 20000 INDEX RANGE SCAN PK_POSTED_SUMMARY (object id 23873)
>
> ********************************************************************************
> <snip>
Received on Fri Nov 14 2003 - 13:25:44 CST
