RE: INSERT...SELECT pegs CPU, but is waiting on scattered read?

From: Jesse, Rich <Rich.Jesse_at_quadtechworld.com>
Date: Thu, 29 Apr 2004 13:12:16 -0500
Message-ID: <FBE1FCA40ECAD41180400050DA2BC54004E938E7@qtiexch2.qgraph.com>

Yeah, I figured I'd need to post more info, but didn't want to scare away folks (or clog their inboxes) with a 4MB trace. :)

Here's an expanded excerpt:

PARSING IN CURSOR #26 len=761 dep=1 uid=105 oct=2 lid=105 tim=951272192 hv=1784939705 ad='e6f44c20'
INSERT INTO part_usage_tmp
SELECT
ph.partno
, DECODE(ph.warehouse,:"SYS_B_00",:"SYS_B_01",NULL,:"SYS_B_02", ph.warehouse) warehouse
, ph.transqty
FROM
QT_PART_HISTORY_24_MONTHS ph,
glxref gl
WHERE
ph.ACCOUNTNO = gl.ACCOUNTNO
AND gl.ENTITY_CODE = :"SYS_B_03"
AND ph.fiscal_year BETWEEN :"SYS_B_04" AND TO_NUMBER(TO_CHAR(TRUNC(SYSDATE), :"SYS_B_05")) AND TO_DATE(SUBSTR(TIME_STAMP,:"SYS_B_06",:"SYS_B_07"),:"SYS_B_08") BETWEEN :"SYS_B_09" AND LAST_DAY(ADD_MONTHS(TRUNC(SYSDATE),-:"SYS_B_10")) AND ph.transtype IN (:"SYS_B_11",:"SYS_B_12",:"SYS_B_13") AND gl.PRICELISTNO LIKE :"SYS_B_14"
END OF STMT
PARSE #26:c=0,e=1,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=0,tim=951272192

WAIT #26: nam='db file scattered read' ela= 3 p1=7 p2=35653 p3=8
WAIT #26: nam='db file scattered read' ela= 0 p1=7 p2=35661 p3=8
WAIT #26: nam='db file scattered read' ela= 1 p1=7 p2=35669 p3=8
WAIT #26: nam='db file scattered read' ela= 0 p1=7 p2=35677 p3=8
WAIT #26: nam='db file scattered read' ela= 0 p1=7 p2=35685 p3=8
WAIT #26: nam='db file scattered read' ela= 1 p1=7 p2=35693 p3=8

...

TIMED_STATISTICS is on. I chose poorly on the example for the first post.

Here's the abbreviated explain plan:

SELECT STATEMENT Cost = 2364
2.1 NESTED LOOPS
3.1 TABLE ACCESS FULL QT_PART_HISTORY_24_MONTHS 3.2 TABLE ACCESS BY INDEX ROWID GLXREF 4.1 INDEX RANGE SCAN GLXREF_PRICELISTNO UNIQUE I agree that what I *should* be seeing is ela's into the hundreds, but I'm not. Each one of the "WAIT" lines above takes a couple of seconds or more to pop into the trace file.

And, yes, we are using the infamous CS=F, which is causing the "SYS" bind names in the statement. One final piece that may be of importance, but I forgot to include on the original post is that each of these statements is dynamically generated and run via EXECUTE IMMEDIATE. There's no COMMIT between the EXECs, but I thought that it was implicit due to the nature of the EXECUTE command.

More thoughts?

Rich

Rich Jesse                        System/Database Administrator
rich.jesse_at_quadtechworld.com      QuadTech, Sussex, WI USA

> -----Original Message-----
> From: Daniel Fink [mailto:Daniel.Fink_at_Sun.COM]
> Sent: Thursday, April 29, 2004 12:13 PM
> To: oracle-l_at_freelists.org
> Subject: Re: INSERT...SELECT pegs CPU, but is waiting on
> scattered read?
>
>
> WAITs (or timed events) are emitted into the trace file upon
> completion. So the
> db file scattered read has completed (with an elapsed time of
> 0, which makes me
> wonder if timed_statistics is turned on). The logical next
> step is that the data
> returned by the scattered read (8 blocks worth) is processed.
> Probably logical
> i/os, sorting, hash joins, etc. all CPU intensive. Once the
> processing is
> completed, another physical i/o call is made and the process
> repeats. If the
> between i/o processing is the real problem, you will see the
> waits separated by
> seconds or minutes.

Please see the official ORACLE-L FAQ: http://www.orafaq.com

To unsubscribe send email to: oracle-l-request_at_freelists.org put 'unsubscribe' in the subject line.

--
Archives are at http://www.freelists.org/archives/oracle-l/
FAQ is at http://www.freelists.org/help/fom-serve/cache/1.html
-----------------------------------------------------------------

Received on Thu Apr 29 2004 - 13:09:38 CDT