PARSING IN CURSOR #10(bad) len=295 dep=1 uid=86 oct=3 lid=86 and PARSING IN CURSOR #7(good) len=295 dep=1 uid=63 oct=3 lid=63
They are being owned and parsed by diffrent id 's(63 for bad and 86 for good). Are they refering to diffrent objects by any chance?
Best Regards
Sriram Kumar
-- --Original Message-- --
From: oracle-l-bounce@(protected) on behalf of Daniel Fink
Sent: Tue 5/4/2004 1:35 AM
To: oracle-l@(protected)
Cc:
Subject: A Tale of Two SQLs
It was the best of sql executions; it was the worst of sql
executions.
We have a process that periodically slows down. So far, we have
not been able to pinpoint a root cause, but we continue to
pester the development/application support folks for more info.
I apologize for the limited information, but I 'm hoping that we
are aiming in the right direction.
We are smart enough that we captured a 10046 trace during a good
execution as a baseline. I have tagged the lines from this trace
file as (good). This morning, the query began slowing down
(eventually it will get a 1555 error). We turned on tracing and
those lines are tagged as (bad).
To make sure I am comparing apples to apples, the statements are
identical, even the bind variables are identical. I 'm not going
to post the 2 trace files (almost 500m), so I 'm including the
relevant parts. There are no waits in these execution/fetches
(you read it correctly, no db file waits, no sql*net waits).
I 've also changed the statments to remove any table/column
names.
What I have found is that the first FETCH of the bad execution
is significantly (300 - 700x) slower than the good execution. It
also performs significantly more (500x) consistent reads.
Subsequent FETCHes are nearly identical to each other (in terms
of good = bad). These FETCHes are performed tens of thousands of
times as this query is re-executed with different bind variables
(also note the time difference in the EXECs, but it pales in
comparison).
My theory is that the high number of crs in the first FETCH of
each execution are the result of building a read-consistent
version of the data. Again, we are working with the dev/app
folks to confirm that one of these tables is being modified, but
have not had a response yet.
Comments on my theory?
'Tis a far, far better thing I do...
Daniel
Bad SQL
=====================
PARSING IN CURSOR #10(bad) len=295 dep=1 uid=86 oct=3 lid=86
tim=746385804887 hv=3414111617 ad= '93b1bcf0 '
SELECT t1.col1
from table1 t1, table2 t2
where t2.col2 = :b1 and t2.col2 = t1.col2
union
select max(t3.col3)
from table3 t3
where t3.col4 = substr(:b1, 1, 6) and t3.col3 < :b1
END OF STMT
Good SQL
=====================
PARSING IN CURSOR #7(good) len=295 dep=1 uid=63 oct=3 lid=63
tim=26349629222266 hv=3414111617 ad= '8c9aee70 '
SELECT t1.col1
from table1 t1, table2 t2
where t2.col2 = :b1 and t2.col2 = t1.col2
union
select max(t3.col3)
from table3 t3
where t3.col4 = substr(:b1, 1, 6) and t3.col3 < :b1
END OF STMT
