RE: Two questions about resource profiles

From: Tim Hopkins <oracle-l_at_timothyhopkins.net>
Date: Mon, 13 Mar 2006 15:26:24 -0000 (GMT)
Message-ID: <33578.192.165.213.18.1142263584.squirrel@192.165.213.18>

Hi Gints,

It's expected behaviour to see a FETCH operation even if no rows are found. Think about opening a cursor in PL/SQL - the OPEN (EXEC in the trace file) operation does not attempt to retrieve any rows. It is the first FETCH operation which indicates the existence of any rows.

If you prefer the words of Tom Kyte -

"Bear in mind that Oracle and does not ‘answer’ the query, does not copy the data anywhere when
you open a cursor ... The cursor opens instantly and it answers the query as it goes along. In other words, it would just read data from the table as you fetched from it." [Expert Oracle]

For example, the query below will obviously not return any rows but a fetch is still performed:

		PARSING IN CURSOR #1
		select * from all_objects where rownum > 1
		END OF STMT
		PARSE #1:c=0,e=202,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=152966171
		EXEC #1:c=0,e=2628,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=152983443
		FETCH

#1:c=62500,e=52357,p=0,cr=3398,cu=0,mis=0,r=0,dep=0,og=1,tim=153040767

In regards to your second question and profile limits, it seems that Oracle does run the query each time.

If the above example is rerun in a session with a limit of 2000 logical reads:

		SQL> alter session set events '10046 trace name context forever, level 12';
		Session altered.

		SQL> alter session set events '10200 trace name context forever, level 1';
		Session altered.

		SQL> select * from all_objects where rownum > 1;
		select * from all_objects where rownum > 1
	              *
		ERROR at line 1:
		ORA-02395: exceeded call limit on IO usage

		Elapsed: 00:00:00.60

		SQL> /
		select * from all_objects where rownum > 1
		*
		ERROR at line 1:
		ORA-02395: exceeded call limit on IO usage

		Elapsed: 00:00:00.23

	We can see the following in the trace file:

		*******************************************************************************
		ksudlio1: OER 2395: ksuplres = 7d0, ksupcio = 7d1
		FETCH


#1:c=234375,e=446457,p=6,cr=2001,cu=0,mis=0,r=0,dep=0,og=1,tim=1941539865

		*******************************************************************************
		....
		*******************************************************************************
		ksudlio1: OER 2395: ksuplres = 7d0, ksupcio = 7d1
		FETCH


#1:c=156250,e=171205,p=0,cr=2001,cu=0,mis=0,r=0,dep=0,og=1,tim=2037291875

		*******************************************************************************

	Noting that the consistent reads (CR=) for the second call is still 2001.

Grepping the trace file for "Consistent read started for block" gives a count of 1996 in both instances.

Based on this, I would conclude that Oracle isn't taking any shortcuts and is simply able to reach the limit much faster as the required blocks were already in the buffer cache.

PS: If anyone can explain the discrepancy between the counts from the 10046 and 10200 events, I'd be interested to know.

Cheers,
Tim Hopkins

-----Original Message-----
From: oracle-l-bounce_at_freelists.org [mailto:oracle-l-bounce_at_freelists.org] On Behalf Of Gints Plivna
Sent: 13 March 2006 12:53
To: Oracle Discussion List
Subject: Two questions about resource profiles

Hello!

I'm investigating resource profiles to prevent users from running unreasonably long time queries. And specifically CPU_PER_CALL and LOGICAL_READS_PER_CALL. I'v found few rather interesting and even confusing moments.
1. In the first time select is run, it accesses db and when io or cpu threshold is exceeded it performs a fetch, that can bee seen from trace file below, although there is no data from this particular table that satisfies this particular select.
I.e. sqlplus screen looks like
FROM <table_list>

*
ERROR at line 3:
ORA-02393: exceeded call limit on CPU usage Elapsed: 00:00:19.04

But in the tracefile there are following lines: <many db file sequential read WAITS>
WAIT #1: nam='db file sequential read' ela= 24192 p1=42 p2=216658 p3=1 WAIT #1: nam='db file sequential read' ela= 17370 p1=42 p2=1577793 p3=1 FETCH
#1:c=797878,e=18566294,p=3060,cr=68984,cu=0,mis=0,r=0,dep=0,og=2,tim=1115479481093872
WAIT #1: nam='SQL*Net break/reset to client' ela= 5 p1=1413697536 p2=1

p3=0 WAIT #1: nam='SQL*Net break/reset to client' ela= 334 p1=1413697536
p2=0 p3=0 WAIT #1: nam='SQL*Net message to client' ela= 4 p1=1413697536
p2=1 p3=0

Why FETCH? What is it? It didn't return any rows.

2. In the first time select got exceeded call limit on CPU usage in 19.04 seconds
In the second time it got exceeded call limit on IO usage in 20.06 seconds In the third time it got exceeded call limit on IO usage in 02.00 seconds In the fourth time it got exceeded call limit on IO usage in 00.04 seconds and tracefile showed no 'db file sequential read' WAITS at all like below: FROM <table_list>

*
ERROR at line 3:
ORA-02393: exceeded call limit on CPU usage Elapsed: 00:00:19.04
SQL> /
FROM <table_list>

*
ERROR at line 3:
ORA-02395: exceeded call limit on IO usage Elapsed: 00:00:20.06
SQL> /
SELECT <attribute list>
*
ERROR at line 1:
ORA-02395: exceeded call limit on IO usage Elapsed: 00:00:02.00
SQL> /
SELECT <attribute list>
*
ERROR at line 1:
ORA-02395: exceeded call limit on IO usage Elapsed: 00:00:00.04

So the question in this case is following: Is it right that for the fourth time all necessary blocks were in db cache and nothing has to be read from disk therefore no waits? Or there is a chance that Oracle stores somewhere required IO and CPU values for statements and immediately returns error? ;)

Gints

--
http://www.freelists.org/webpage/oracle-l




--
http://www.freelists.org/webpage/oracle-l

Received on Mon Mar 13 2006 - 09:26:24 CST