Links
Home
Oracle DBA Forum
Frequent Oracle Errors
TNS:could not resolve the connect identifier specified
Backtrace message unwound by exceptions
invalid identifier
PL/SQL compilation error
internal error
missing expression
table or view does not exist
end-of-file on communication channel
TNS:listener unknown in connect descriptor
insufficient privileges
PL/SQL: numeric or value error string
TNS:protocol adapter error
ORACLE not available
target host or object does not exist
invalid number
unable to allocate string bytes of shared memory
resource busy and acquire with NOWAIT specified
error occurred at recursive SQL level string
ORACLE initialization or shutdown in progress
archiver error. Connect internal only, until freed
snapshot too old
unable to extend temp segment by string in tablespace
Credential retrieval failed
missing or invalid option
invalid username/password; logon denied
unable to create INITIAL extent for segment
out of process memory when trying to allocate string bytes
shared memory realm does not exist
cannot insert NULL
TNS:unable to connect to destination
remote database not found'>ora-02019
exception encountered: core dump
inconsistent datatypes
no data found
TNS:operation timed out
PL/SQL: could not find program
existing state of packages has been discarded
maximum number of processes exceeded
error signaled in parallel query server
ORACLE instance terminated. Disconnection forced
TNS:packet writer failure
see ORA-12699
missing right parenthesis
name is already used by an existing object
cannot identify/lock data file
invalid file operation
quoted string not properly terminated
A Tale of Two SQLs

A Tale of Two SQLs

2004-05-03       - By Daniel Fink

Reply:     1     2     3     4     5     6     7     8     9     10  

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

EXEC
#10(bad):c=0,e=701,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=746385804872
EXEC
#7(good):c=0,e=536,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=26349629222259

FETCH
#10(bad):c=110000,e=107303,p=0,cr=7699,cu=0,mis=0,r=1,dep=1,og=4,tim=746385912781
FETCH
#7(good):c=0,e=406,p=0,cr=16,cu=0,mis=0,r=1,dep=1,og=4,tim=26349629222976

FETCH
#10(bad):c=0,e=30,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=746385913106
FETCH
#7(good):c=0,e=31,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=26349629223153

BINDS #10(bad):
bind 0: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=96 offset=0
bfp=ffffffff7c4b7c38 bln=32 avl=09 flg=05
value= "104539-08 "
bind 1: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=0 offset=32
bfp=ffffffff7c4b7c58 bln=32 avl=09 flg=01
value= "104539-08 "
bind 2: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=0 offset=64
bfp=ffffffff7c4b7c78 bln=32 avl=09 flg=01
value= "104539-08 "
BINDS #7(good):
bind 0: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=96 offset=0
bfp=ffffffff7c4aeac0 bln=32 avl=09 flg=05
value= "104539-08 "
bind 1: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=0 offset=32
bfp=ffffffff7c4aeae0 bln=32 avl=09 flg=01
value= "104539-08 "
bind 2: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=0 offset=64
bfp=ffffffff7c4aeb00 bln=32 avl=09 flg=01
value= "104539-08 "

EXEC
#10(bad):c=0,e=619,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=746385914651
EXEC
#7(good):c=0,e=496,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=26349629224220

FETCH
#10(bad):c=110000,e=102469,p=0,cr=7698,cu=0,mis=0,r=1,dep=1,og=4,tim=746386017309
FETCH
#7(good):c=0,e=206,p=0,cr=16,cu=0,mis=0,r=1,dep=1,og=4,tim=26349629224499

FETCH
#10(bad):c=0,e=12,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=4,tim=746386017582
FETCH
#7(good):c=0,e=6,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=4,tim=26349629224619

FETCH
#10(bad):c=0,e=8,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=4,tim=746386017774
FETCH
#7(good):c=0,e=5,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=4,tim=26349629224734

FETCH
#10(bad):c=0,e=9,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=4,tim=746386017967
FETCH
#7(good):c=0,e=5,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=4,tim=26349629224849

FETCH
#10(bad):c=0,e=8,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=4,tim=746386018157
FETCH
#7(good):c=0,e=5,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=4,tim=26349629224961

FETCH
#10(bad):c=0,e=26,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=746386018363
FETCH
#7(good):c=0,e=14,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=26349629225081

BINDS #10(bad):
bind 0: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=96 offset=0
bfp=ffffffff7c4b7c38 bln=32 avl=09 flg=05
value= "104539-07 "
bind 1: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=0 offset=32
bfp=ffffffff7c4b7c58 bln=32 avl=09 flg=01
value= "104539-07 "
bind 2: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=0 offset=64
bfp=ffffffff7c4b7c78 bln=32 avl=09 flg=01
value= "104539-07 "
BINDS #7(good):
bind 0: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=96 offset=0
bfp=ffffffff7c4aeac0 bln=32 avl=09 flg=05
value= "104539-07 "
bind 1: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=0 offset=32
bfp=ffffffff7c4aeae0 bln=32 avl=09 flg=01
value= "104539-07 "
bind 2: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=0 offset=64
bfp=ffffffff7c4aeb00 bln=32 avl=09 flg=01
value= "104539-07 "

EXEC
#10(bad):c=0,e=684,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=746386019967
EXEC
#7(good):c=0,e=463,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=26349629226116

FETCH
#10(bad):c=100000,e=101693,p=0,cr=7697,cu=0,mis=0,r=1,dep=1,og=4,tim=746386121784
FETCH
#7(good):c=0,e=186,p=0,cr=16,cu=0,mis=0,r=1,dep=1,og=4,tim=26349629226374

FETCH
#10(bad):c=0,e=12,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=4,tim=746386122056
FETCH
#7(good):c=0,e=6,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=4,tim=26349629226492

FETCH
#10(bad):c=0,e=26,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=746386122263
FETCH
#7(good):c=0,e=14,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=26349629226615

BINDS #10(bad):
bind 0: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=96 offset=0
bfp=ffffffff7c4b7c38 bln=32 avl=09 flg=05
value= "107278-01 "
bind 1: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=0 offset=32
bfp=ffffffff7c4b7c58 bln=32 avl=09 flg=01
value= "107278-01 "
bind 2: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=0 offset=64
bfp=ffffffff7c4b7c78 bln=32 avl=09 flg=01
value= "107278-01 "
BINDS #7(good):
bind 0: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=96 offset=0
bfp=ffffffff7c4aeac0 bln=32 avl=09 flg=05
value= "107278-01 "
bind 1: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=0 offset=32
bfp=ffffffff7c4aeae0 bln=32 avl=09 flg=01
value= "107278-01 "
bind 2: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=0 offset=64
bfp=ffffffff7c4aeb00 bln=32 avl=09 flg=01
value= "107278-01 "

EXEC
#10(bad):c=0,e=686,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=746386123823
EXEC
#7(good):c=0,e=466,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=26349629227628

FETCH
#10(bad):c=200000,e=204295,p=0,cr=15358,cu=0,mis=0,r=1,dep=1,og=4,tim=746386328243
FETCH
#7(good):c=0,e=143,p=0,cr=7,cu=0,mis=0,r=1,dep=1,og=4,tim=26349629227843

FETCH
#10(bad):c=0,e=37,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=746386328513
FETCH
#7(good):c=0,e=13,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=26349629227941

BINDS #10(bad):
bind 0: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=96 offset=0
bfp=ffffffff7c4b7c38 bln=32 avl=09 flg=05
value= "107366-01 "
bind 1: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=0 offset=32
bfp=ffffffff7c4b7c58 bln=32 avl=09 flg=01
value= "107366-01 "
bind 2: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=0 offset=64
bfp=ffffffff7c4b7c78 bln=32 avl=09 flg=01
value= "107366-01 "
BINDS #7(good):
bind 0: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=96 offset=0
bfp=ffffffff7c4aeac0 bln=32 avl=09 flg=05
value= "107366-01 "
bind 1: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=0 offset=32
bfp=ffffffff7c4aeae0 bln=32 avl=09 flg=01
value= "107366-01 "
bind 2: dty=1 mxl=32(09) mal=00 scl=00 pre=00 oacflg=13
oacfl2=1 size=0 offset=64
bfp=ffffffff7c4aeb00 bln=32 avl=09 flg=01
value= "107366-01 "

EXEC
#10(bad):c=0,e=706,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=746386330128
EXEC
#7(good):c=10000,e=493,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=26349629228936

FETCH
#10(bad):c=210000,e=208902,p=0,cr=15673,cu=0,mis=0,r=1,dep=1,og=4,tim=746386539152
FETCH
#7(good):c=0,e=121,p=0,cr=7,cu=0,mis=0,r=1,dep=1,og=4,tim=26349629229130

FETCH
#10(bad):c=0,e=35,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=746386539431
FETCH
#7(good):c=0,e=12,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=26349629229225
-- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ------
Please see the official ORACLE-L FAQ: http://www.orafaq.com
-- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ------
To unsubscribe send email to: oracle-l-request@(protected)
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
-- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- --