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

  • From: "Jesse, Rich" <Rich.Jesse@xxxxxxxxxxxxxxxxx>
  • To: "'oracle-l@xxxxxxxxxxxxx'" <oracle-l@xxxxxxxxxxxxx>
  • Date: Thu, 29 Apr 2004 13:12:16 -0500

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@xxxxxxxxxxxxxxxxx      QuadTech, Sussex, WI USA


> -----Original Message-----
> From: Daniel Fink [mailto:Daniel.Fink@xxxxxxx]
> Sent: Thursday, April 29, 2004 12:13 PM
> To: oracle-l@xxxxxxxxxxxxx
> 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@xxxxxxxxxxxxx
put 'unsubscribe' in the subject line.
--
Archives are at //www.freelists.org/archives/oracle-l/
FAQ is at //www.freelists.org/help/fom-serve/cache/1.html
-----------------------------------------------------------------

Other related posts:

  1. Home
  2. oracle-l
  3. Archive
  4. 04-2004