dbTalk Databases Forums  

Weird Pro*C trace file

comp.databases.oracle.server comp.databases.oracle.server


Discuss Weird Pro*C trace file in the comp.databases.oracle.server forum.



Reply
 
Thread Tools Display Modes
  #1  
Old   
malcolm
 
Posts: n/a

Default Weird Pro*C trace file - 06-11-2008 , 11:31 AM






Hi,

I was wondering if anyone could help me with the below strange
occurance?

We have a Pro*C application running on our DB server (jurassic Oracle
9.2.0.1 on Windows 2003 r2 32-bit) which until very recently was
working without problems. Nothing (as far as I know) has changed in
this environment, but now the application is bombing out on one
particular query.

Below is an extract from a 10046 sql trace of the query in question:

=====================
PARSING IN CURSOR #1 len=57 dep=0 uid=47 oct=3 lid=47 tim=2383911068
hv=1227232938 ad='19e2c4e0'
select zz_dbvr into :b0:b1 from zz_ where zz_dbky='0000'
END OF STMT
PARSE #1:c=0,e=486,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,ti m=2383911063
BINDS #1:
EXEC
#1:c=15625,e=2888,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og =4,tim=2383946705
WAIT #1: nam='SQL*Net message to client' ela= 4 p1=1111838976 p2=1
p3=0
FETCH #1:c=0,e=35,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=4,tim =2383952308
WAIT #1: nam='SQL*Net message from client' ela= 16414 p1=1111838976
p2=1 p3=0
WAIT #1: nam='SQL*Net break/reset to client' ela= 57 p1=1111838976
p2=0 p3=0
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1111838976 p2=1
p3=0
WAIT #1: nam='SQL*Net message from client' ela= 578 p1=1111838976 p2=1
p3=0
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=9602 op='TABLE ACCESS BY INDEX
ROWID OBJ#(9602) (cr=2 r=0 w=0 time=25 us)'
STAT #1 id=2 cnt=1 pid=1 pos=1 obj=9603 op='INDEX UNIQUE SCAN
OBJ#(9603) (cr=1 r=0 w=0 time=13 us)'

You'll notice what looks like incorrect syntax, trying to select into
':b1:b0'. But then, according to the trace file, Oracle goes ahead
with the PARSE, EXECUTE and FETCH steps with no problem. The FETCH
appears to be correctly fetching the one row (r=1). There's even a
query plan when the cursor is closed (the STAT lines).

Our Pro*C application is reporting an error, SQLCODE = -162. This must
be causing the 'SQL*Net break/reset to client' event. But ORA-00162
looks completely irrelevent.

The other weird thing is that the OBJ#(9602) and OBJ#(9603) are not
the OBJECT_IDs of the objects in the plan!

select object_name from dba_objects where object_id=9602;

OBJECT_NAME
-----------------------------------------------------------------
javax/swing/text/rtf/RTFReader

SQL> select object_name from dba_objects where object_id=9603;

OBJECT_NAME
--------------------------------------------------------------------------------
/d5f6a702_RTFGenerator

Has anybody seen this before? An Oracle bug perhaps?

Things that are weird:
1. Error ORA-00162 is "external dbid length string is greater than
maximum (string)" and this does not appear relevent at all.
2. Query has suspicious syntax but appears to parse, execute and fetch
ok. (So can have a : in a bind variable name!?)
3. OBJ#(9602) and OBJ#(9603) in the plan do not correspond to the
OBJECT_IDs of the table and index used in the query

Thanks in advance for any help.

Malcolm.

Reply With Quote
  #2  
Old   
Ed Prochak
 
Posts: n/a

Default Re: Weird Pro*C trace file - 06-11-2008 , 01:00 PM






On Jun 11, 12:31 pm, malcolm <malcolmarn... (AT) gmail (DOT) com> wrote:
Quote:
Hi,

I was wondering if anyone could help me with the below strange
occurance?

We have a Pro*C application running on our DB server (jurassic Oracle
9.2.0.1 on Windows 2003 r2 32-bit) which until very recently was
working without problems. Nothing (as far as I know) has changed in
this environment, but now the application is bombing out on one
particular query.

Below is an extract from a 10046 sql trace of the query in question:

=====================
PARSING IN CURSOR #1 len=57 dep=0 uid=47 oct=3 lid=47 tim=2383911068
hv=1227232938 ad='19e2c4e0'
select zz_dbvr into :b0:b1 from zz_ where zz_dbky='0000'
END OF STMT
PARSE #1:c=0,e=486,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,ti m=2383911063
BINDS #1:
EXEC
#1:c=15625,e=2888,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og =4,tim=2383946705
WAIT #1: nam='SQL*Net message to client' ela= 4 p1=1111838976 p2=1
p3=0
FETCH #1:c=0,e=35,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=4,tim =2383952308
WAIT #1: nam='SQL*Net message from client' ela= 16414 p1=1111838976
p2=1 p3=0
WAIT #1: nam='SQL*Net break/reset to client' ela= 57 p1=1111838976
p2=0 p3=0
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1111838976 p2=1
p3=0
WAIT #1: nam='SQL*Net message from client' ela= 578 p1=1111838976 p2=1
p3=0
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=9602 op='TABLE ACCESS BY INDEX
ROWID OBJ#(9602) (cr=2 r=0 w=0 time=25 us)'
STAT #1 id=2 cnt=1 pid=1 pos=1 obj=9603 op='INDEX UNIQUE SCAN
OBJ#(9603) (cr=1 r=0 w=0 time=13 us)'

You'll notice what looks like incorrect syntax, trying to select into
':b1:b0'. But then, according to the trace file, Oracle goes ahead
with the PARSE, EXECUTE and FETCH steps with no problem. The FETCH
appears to be correctly fetching the one row (r=1). There's even a
query plan when the cursor is closed (the STAT lines).

Our Pro*C application is reporting an error, SQLCODE = -162. This must
be causing the 'SQL*Net break/reset to client' event. But ORA-00162
looks completely irrelevent.

The other weird thing is that the OBJ#(9602) and OBJ#(9603) are not
the OBJECT_IDs of the objects in the plan!

select object_name from dba_objects where object_id=9602;

OBJECT_NAME
-----------------------------------------------------------------
javax/swing/text/rtf/RTFReader

SQL> select object_name from dba_objects where object_id=9603;

OBJECT_NAME
--------------------------------------------------------------------------------
/d5f6a702_RTFGenerator

Has anybody seen this before? An Oracle bug perhaps?

Things that are weird:
1. Error ORA-00162 is "external dbid length string is greater than
maximum (string)" and this does not appear relevent at all.
2. Query has suspicious syntax but appears to parse, execute and fetch
ok. (So can have a : in a bind variable name!?)
3. OBJ#(9602) and OBJ#(9603) in the plan do not correspond to the
OBJECT_IDs of the table and index used in the query

Thanks in advance for any help.

Malcolm.
What does the Source code look like?
Ed


Reply With Quote
  #3  
Old   
Ed Prochak
 
Posts: n/a

Default Re: Weird Pro*C trace file - 06-11-2008 , 01:00 PM



On Jun 11, 12:31 pm, malcolm <malcolmarn... (AT) gmail (DOT) com> wrote:
Quote:
Hi,

I was wondering if anyone could help me with the below strange
occurance?

We have a Pro*C application running on our DB server (jurassic Oracle
9.2.0.1 on Windows 2003 r2 32-bit) which until very recently was
working without problems. Nothing (as far as I know) has changed in
this environment, but now the application is bombing out on one
particular query.

Below is an extract from a 10046 sql trace of the query in question:

=====================
PARSING IN CURSOR #1 len=57 dep=0 uid=47 oct=3 lid=47 tim=2383911068
hv=1227232938 ad='19e2c4e0'
select zz_dbvr into :b0:b1 from zz_ where zz_dbky='0000'
END OF STMT
PARSE #1:c=0,e=486,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,ti m=2383911063
BINDS #1:
EXEC
#1:c=15625,e=2888,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og =4,tim=2383946705
WAIT #1: nam='SQL*Net message to client' ela= 4 p1=1111838976 p2=1
p3=0
FETCH #1:c=0,e=35,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=4,tim =2383952308
WAIT #1: nam='SQL*Net message from client' ela= 16414 p1=1111838976
p2=1 p3=0
WAIT #1: nam='SQL*Net break/reset to client' ela= 57 p1=1111838976
p2=0 p3=0
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1111838976 p2=1
p3=0
WAIT #1: nam='SQL*Net message from client' ela= 578 p1=1111838976 p2=1
p3=0
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=9602 op='TABLE ACCESS BY INDEX
ROWID OBJ#(9602) (cr=2 r=0 w=0 time=25 us)'
STAT #1 id=2 cnt=1 pid=1 pos=1 obj=9603 op='INDEX UNIQUE SCAN
OBJ#(9603) (cr=1 r=0 w=0 time=13 us)'

You'll notice what looks like incorrect syntax, trying to select into
':b1:b0'. But then, according to the trace file, Oracle goes ahead
with the PARSE, EXECUTE and FETCH steps with no problem. The FETCH
appears to be correctly fetching the one row (r=1). There's even a
query plan when the cursor is closed (the STAT lines).

Our Pro*C application is reporting an error, SQLCODE = -162. This must
be causing the 'SQL*Net break/reset to client' event. But ORA-00162
looks completely irrelevent.

The other weird thing is that the OBJ#(9602) and OBJ#(9603) are not
the OBJECT_IDs of the objects in the plan!

select object_name from dba_objects where object_id=9602;

OBJECT_NAME
-----------------------------------------------------------------
javax/swing/text/rtf/RTFReader

SQL> select object_name from dba_objects where object_id=9603;

OBJECT_NAME
--------------------------------------------------------------------------------
/d5f6a702_RTFGenerator

Has anybody seen this before? An Oracle bug perhaps?

Things that are weird:
1. Error ORA-00162 is "external dbid length string is greater than
maximum (string)" and this does not appear relevent at all.
2. Query has suspicious syntax but appears to parse, execute and fetch
ok. (So can have a : in a bind variable name!?)
3. OBJ#(9602) and OBJ#(9603) in the plan do not correspond to the
OBJECT_IDs of the table and index used in the query

Thanks in advance for any help.

Malcolm.
What does the Source code look like?
Ed


Reply With Quote
  #4  
Old   
Ed Prochak
 
Posts: n/a

Default Re: Weird Pro*C trace file - 06-11-2008 , 01:00 PM



On Jun 11, 12:31 pm, malcolm <malcolmarn... (AT) gmail (DOT) com> wrote:
Quote:
Hi,

I was wondering if anyone could help me with the below strange
occurance?

We have a Pro*C application running on our DB server (jurassic Oracle
9.2.0.1 on Windows 2003 r2 32-bit) which until very recently was
working without problems. Nothing (as far as I know) has changed in
this environment, but now the application is bombing out on one
particular query.

Below is an extract from a 10046 sql trace of the query in question:

=====================
PARSING IN CURSOR #1 len=57 dep=0 uid=47 oct=3 lid=47 tim=2383911068
hv=1227232938 ad='19e2c4e0'
select zz_dbvr into :b0:b1 from zz_ where zz_dbky='0000'
END OF STMT
PARSE #1:c=0,e=486,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,ti m=2383911063
BINDS #1:
EXEC
#1:c=15625,e=2888,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og =4,tim=2383946705
WAIT #1: nam='SQL*Net message to client' ela= 4 p1=1111838976 p2=1
p3=0
FETCH #1:c=0,e=35,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=4,tim =2383952308
WAIT #1: nam='SQL*Net message from client' ela= 16414 p1=1111838976
p2=1 p3=0
WAIT #1: nam='SQL*Net break/reset to client' ela= 57 p1=1111838976
p2=0 p3=0
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1111838976 p2=1
p3=0
WAIT #1: nam='SQL*Net message from client' ela= 578 p1=1111838976 p2=1
p3=0
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=9602 op='TABLE ACCESS BY INDEX
ROWID OBJ#(9602) (cr=2 r=0 w=0 time=25 us)'
STAT #1 id=2 cnt=1 pid=1 pos=1 obj=9603 op='INDEX UNIQUE SCAN
OBJ#(9603) (cr=1 r=0 w=0 time=13 us)'

You'll notice what looks like incorrect syntax, trying to select into
':b1:b0'. But then, according to the trace file, Oracle goes ahead
with the PARSE, EXECUTE and FETCH steps with no problem. The FETCH
appears to be correctly fetching the one row (r=1). There's even a
query plan when the cursor is closed (the STAT lines).

Our Pro*C application is reporting an error, SQLCODE = -162. This must
be causing the 'SQL*Net break/reset to client' event. But ORA-00162
looks completely irrelevent.

The other weird thing is that the OBJ#(9602) and OBJ#(9603) are not
the OBJECT_IDs of the objects in the plan!

select object_name from dba_objects where object_id=9602;

OBJECT_NAME
-----------------------------------------------------------------
javax/swing/text/rtf/RTFReader

SQL> select object_name from dba_objects where object_id=9603;

OBJECT_NAME
--------------------------------------------------------------------------------
/d5f6a702_RTFGenerator

Has anybody seen this before? An Oracle bug perhaps?

Things that are weird:
1. Error ORA-00162 is "external dbid length string is greater than
maximum (string)" and this does not appear relevent at all.
2. Query has suspicious syntax but appears to parse, execute and fetch
ok. (So can have a : in a bind variable name!?)
3. OBJ#(9602) and OBJ#(9603) in the plan do not correspond to the
OBJECT_IDs of the table and index used in the query

Thanks in advance for any help.

Malcolm.
What does the Source code look like?
Ed


Reply With Quote
  #5  
Old   
Ed Prochak
 
Posts: n/a

Default Re: Weird Pro*C trace file - 06-11-2008 , 01:00 PM



On Jun 11, 12:31 pm, malcolm <malcolmarn... (AT) gmail (DOT) com> wrote:
Quote:
Hi,

I was wondering if anyone could help me with the below strange
occurance?

We have a Pro*C application running on our DB server (jurassic Oracle
9.2.0.1 on Windows 2003 r2 32-bit) which until very recently was
working without problems. Nothing (as far as I know) has changed in
this environment, but now the application is bombing out on one
particular query.

Below is an extract from a 10046 sql trace of the query in question:

=====================
PARSING IN CURSOR #1 len=57 dep=0 uid=47 oct=3 lid=47 tim=2383911068
hv=1227232938 ad='19e2c4e0'
select zz_dbvr into :b0:b1 from zz_ where zz_dbky='0000'
END OF STMT
PARSE #1:c=0,e=486,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,ti m=2383911063
BINDS #1:
EXEC
#1:c=15625,e=2888,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og =4,tim=2383946705
WAIT #1: nam='SQL*Net message to client' ela= 4 p1=1111838976 p2=1
p3=0
FETCH #1:c=0,e=35,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=4,tim =2383952308
WAIT #1: nam='SQL*Net message from client' ela= 16414 p1=1111838976
p2=1 p3=0
WAIT #1: nam='SQL*Net break/reset to client' ela= 57 p1=1111838976
p2=0 p3=0
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1111838976 p2=1
p3=0
WAIT #1: nam='SQL*Net message from client' ela= 578 p1=1111838976 p2=1
p3=0
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=9602 op='TABLE ACCESS BY INDEX
ROWID OBJ#(9602) (cr=2 r=0 w=0 time=25 us)'
STAT #1 id=2 cnt=1 pid=1 pos=1 obj=9603 op='INDEX UNIQUE SCAN
OBJ#(9603) (cr=1 r=0 w=0 time=13 us)'

You'll notice what looks like incorrect syntax, trying to select into
':b1:b0'. But then, according to the trace file, Oracle goes ahead
with the PARSE, EXECUTE and FETCH steps with no problem. The FETCH
appears to be correctly fetching the one row (r=1). There's even a
query plan when the cursor is closed (the STAT lines).

Our Pro*C application is reporting an error, SQLCODE = -162. This must
be causing the 'SQL*Net break/reset to client' event. But ORA-00162
looks completely irrelevent.

The other weird thing is that the OBJ#(9602) and OBJ#(9603) are not
the OBJECT_IDs of the objects in the plan!

select object_name from dba_objects where object_id=9602;

OBJECT_NAME
-----------------------------------------------------------------
javax/swing/text/rtf/RTFReader

SQL> select object_name from dba_objects where object_id=9603;

OBJECT_NAME
--------------------------------------------------------------------------------
/d5f6a702_RTFGenerator

Has anybody seen this before? An Oracle bug perhaps?

Things that are weird:
1. Error ORA-00162 is "external dbid length string is greater than
maximum (string)" and this does not appear relevent at all.
2. Query has suspicious syntax but appears to parse, execute and fetch
ok. (So can have a : in a bind variable name!?)
3. OBJ#(9602) and OBJ#(9603) in the plan do not correspond to the
OBJECT_IDs of the table and index used in the query

Thanks in advance for any help.

Malcolm.
What does the Source code look like?
Ed


Reply With Quote
  #6  
Old   
Ed Prochak
 
Posts: n/a

Default Re: Weird Pro*C trace file - 06-11-2008 , 01:00 PM



On Jun 11, 12:31 pm, malcolm <malcolmarn... (AT) gmail (DOT) com> wrote:
Quote:
Hi,

I was wondering if anyone could help me with the below strange
occurance?

We have a Pro*C application running on our DB server (jurassic Oracle
9.2.0.1 on Windows 2003 r2 32-bit) which until very recently was
working without problems. Nothing (as far as I know) has changed in
this environment, but now the application is bombing out on one
particular query.

Below is an extract from a 10046 sql trace of the query in question:

=====================
PARSING IN CURSOR #1 len=57 dep=0 uid=47 oct=3 lid=47 tim=2383911068
hv=1227232938 ad='19e2c4e0'
select zz_dbvr into :b0:b1 from zz_ where zz_dbky='0000'
END OF STMT
PARSE #1:c=0,e=486,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,ti m=2383911063
BINDS #1:
EXEC
#1:c=15625,e=2888,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og =4,tim=2383946705
WAIT #1: nam='SQL*Net message to client' ela= 4 p1=1111838976 p2=1
p3=0
FETCH #1:c=0,e=35,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=4,tim =2383952308
WAIT #1: nam='SQL*Net message from client' ela= 16414 p1=1111838976
p2=1 p3=0
WAIT #1: nam='SQL*Net break/reset to client' ela= 57 p1=1111838976
p2=0 p3=0
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1111838976 p2=1
p3=0
WAIT #1: nam='SQL*Net message from client' ela= 578 p1=1111838976 p2=1
p3=0
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=9602 op='TABLE ACCESS BY INDEX
ROWID OBJ#(9602) (cr=2 r=0 w=0 time=25 us)'
STAT #1 id=2 cnt=1 pid=1 pos=1 obj=9603 op='INDEX UNIQUE SCAN
OBJ#(9603) (cr=1 r=0 w=0 time=13 us)'

You'll notice what looks like incorrect syntax, trying to select into
':b1:b0'. But then, according to the trace file, Oracle goes ahead
with the PARSE, EXECUTE and FETCH steps with no problem. The FETCH
appears to be correctly fetching the one row (r=1). There's even a
query plan when the cursor is closed (the STAT lines).

Our Pro*C application is reporting an error, SQLCODE = -162. This must
be causing the 'SQL*Net break/reset to client' event. But ORA-00162
looks completely irrelevent.

The other weird thing is that the OBJ#(9602) and OBJ#(9603) are not
the OBJECT_IDs of the objects in the plan!

select object_name from dba_objects where object_id=9602;

OBJECT_NAME
-----------------------------------------------------------------
javax/swing/text/rtf/RTFReader

SQL> select object_name from dba_objects where object_id=9603;

OBJECT_NAME
--------------------------------------------------------------------------------
/d5f6a702_RTFGenerator

Has anybody seen this before? An Oracle bug perhaps?

Things that are weird:
1. Error ORA-00162 is "external dbid length string is greater than
maximum (string)" and this does not appear relevent at all.
2. Query has suspicious syntax but appears to parse, execute and fetch
ok. (So can have a : in a bind variable name!?)
3. OBJ#(9602) and OBJ#(9603) in the plan do not correspond to the
OBJECT_IDs of the table and index used in the query

Thanks in advance for any help.

Malcolm.
What does the Source code look like?
Ed


Reply With Quote
  #7  
Old   
Ed Prochak
 
Posts: n/a

Default Re: Weird Pro*C trace file - 06-11-2008 , 01:00 PM



On Jun 11, 12:31 pm, malcolm <malcolmarn... (AT) gmail (DOT) com> wrote:
Quote:
Hi,

I was wondering if anyone could help me with the below strange
occurance?

We have a Pro*C application running on our DB server (jurassic Oracle
9.2.0.1 on Windows 2003 r2 32-bit) which until very recently was
working without problems. Nothing (as far as I know) has changed in
this environment, but now the application is bombing out on one
particular query.

Below is an extract from a 10046 sql trace of the query in question:

=====================
PARSING IN CURSOR #1 len=57 dep=0 uid=47 oct=3 lid=47 tim=2383911068
hv=1227232938 ad='19e2c4e0'
select zz_dbvr into :b0:b1 from zz_ where zz_dbky='0000'
END OF STMT
PARSE #1:c=0,e=486,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,ti m=2383911063
BINDS #1:
EXEC
#1:c=15625,e=2888,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og =4,tim=2383946705
WAIT #1: nam='SQL*Net message to client' ela= 4 p1=1111838976 p2=1
p3=0
FETCH #1:c=0,e=35,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=4,tim =2383952308
WAIT #1: nam='SQL*Net message from client' ela= 16414 p1=1111838976
p2=1 p3=0
WAIT #1: nam='SQL*Net break/reset to client' ela= 57 p1=1111838976
p2=0 p3=0
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1111838976 p2=1
p3=0
WAIT #1: nam='SQL*Net message from client' ela= 578 p1=1111838976 p2=1
p3=0
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=9602 op='TABLE ACCESS BY INDEX
ROWID OBJ#(9602) (cr=2 r=0 w=0 time=25 us)'
STAT #1 id=2 cnt=1 pid=1 pos=1 obj=9603 op='INDEX UNIQUE SCAN
OBJ#(9603) (cr=1 r=0 w=0 time=13 us)'

You'll notice what looks like incorrect syntax, trying to select into
':b1:b0'. But then, according to the trace file, Oracle goes ahead
with the PARSE, EXECUTE and FETCH steps with no problem. The FETCH
appears to be correctly fetching the one row (r=1). There's even a
query plan when the cursor is closed (the STAT lines).

Our Pro*C application is reporting an error, SQLCODE = -162. This must
be causing the 'SQL*Net break/reset to client' event. But ORA-00162
looks completely irrelevent.

The other weird thing is that the OBJ#(9602) and OBJ#(9603) are not
the OBJECT_IDs of the objects in the plan!

select object_name from dba_objects where object_id=9602;

OBJECT_NAME
-----------------------------------------------------------------
javax/swing/text/rtf/RTFReader

SQL> select object_name from dba_objects where object_id=9603;

OBJECT_NAME
--------------------------------------------------------------------------------
/d5f6a702_RTFGenerator

Has anybody seen this before? An Oracle bug perhaps?

Things that are weird:
1. Error ORA-00162 is "external dbid length string is greater than
maximum (string)" and this does not appear relevent at all.
2. Query has suspicious syntax but appears to parse, execute and fetch
ok. (So can have a : in a bind variable name!?)
3. OBJ#(9602) and OBJ#(9603) in the plan do not correspond to the
OBJECT_IDs of the table and index used in the query

Thanks in advance for any help.

Malcolm.
What does the Source code look like?
Ed


Reply With Quote
  #8  
Old   
Ed Prochak
 
Posts: n/a

Default Re: Weird Pro*C trace file - 06-11-2008 , 01:00 PM



On Jun 11, 12:31 pm, malcolm <malcolmarn... (AT) gmail (DOT) com> wrote:
Quote:
Hi,

I was wondering if anyone could help me with the below strange
occurance?

We have a Pro*C application running on our DB server (jurassic Oracle
9.2.0.1 on Windows 2003 r2 32-bit) which until very recently was
working without problems. Nothing (as far as I know) has changed in
this environment, but now the application is bombing out on one
particular query.

Below is an extract from a 10046 sql trace of the query in question:

=====================
PARSING IN CURSOR #1 len=57 dep=0 uid=47 oct=3 lid=47 tim=2383911068
hv=1227232938 ad='19e2c4e0'
select zz_dbvr into :b0:b1 from zz_ where zz_dbky='0000'
END OF STMT
PARSE #1:c=0,e=486,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,ti m=2383911063
BINDS #1:
EXEC
#1:c=15625,e=2888,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og =4,tim=2383946705
WAIT #1: nam='SQL*Net message to client' ela= 4 p1=1111838976 p2=1
p3=0
FETCH #1:c=0,e=35,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=4,tim =2383952308
WAIT #1: nam='SQL*Net message from client' ela= 16414 p1=1111838976
p2=1 p3=0
WAIT #1: nam='SQL*Net break/reset to client' ela= 57 p1=1111838976
p2=0 p3=0
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1111838976 p2=1
p3=0
WAIT #1: nam='SQL*Net message from client' ela= 578 p1=1111838976 p2=1
p3=0
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=9602 op='TABLE ACCESS BY INDEX
ROWID OBJ#(9602) (cr=2 r=0 w=0 time=25 us)'
STAT #1 id=2 cnt=1 pid=1 pos=1 obj=9603 op='INDEX UNIQUE SCAN
OBJ#(9603) (cr=1 r=0 w=0 time=13 us)'

You'll notice what looks like incorrect syntax, trying to select into
':b1:b0'. But then, according to the trace file, Oracle goes ahead
with the PARSE, EXECUTE and FETCH steps with no problem. The FETCH
appears to be correctly fetching the one row (r=1). There's even a
query plan when the cursor is closed (the STAT lines).

Our Pro*C application is reporting an error, SQLCODE = -162. This must
be causing the 'SQL*Net break/reset to client' event. But ORA-00162
looks completely irrelevent.

The other weird thing is that the OBJ#(9602) and OBJ#(9603) are not
the OBJECT_IDs of the objects in the plan!

select object_name from dba_objects where object_id=9602;

OBJECT_NAME
-----------------------------------------------------------------
javax/swing/text/rtf/RTFReader

SQL> select object_name from dba_objects where object_id=9603;

OBJECT_NAME
--------------------------------------------------------------------------------
/d5f6a702_RTFGenerator

Has anybody seen this before? An Oracle bug perhaps?

Things that are weird:
1. Error ORA-00162 is "external dbid length string is greater than
maximum (string)" and this does not appear relevent at all.
2. Query has suspicious syntax but appears to parse, execute and fetch
ok. (So can have a : in a bind variable name!?)
3. OBJ#(9602) and OBJ#(9603) in the plan do not correspond to the
OBJECT_IDs of the table and index used in the query

Thanks in advance for any help.

Malcolm.
What does the Source code look like?
Ed


Reply With Quote
  #9  
Old   
Neil.W.James
 
Posts: n/a

Default Re: Weird Pro*C trace file - 06-12-2008 , 03:45 AM



malcolm wrote:
Quote:
Hi,

I was wondering if anyone could help me with the below strange
occurance?

We have a Pro*C application running on our DB server (jurassic Oracle
9.2.0.1 on Windows 2003 r2 32-bit) which until very recently was
working without problems. Nothing (as far as I know) has changed in
this environment, but now the application is bombing out on one
particular query.

Below is an extract from a 10046 sql trace of the query in question:

=====================
PARSING IN CURSOR #1 len=57 dep=0 uid=47 oct=3 lid=47 tim=2383911068
hv=1227232938 ad='19e2c4e0'
select zz_dbvr into :b0:b1 from zz_ where zz_dbky='0000'
END OF STMT
PARSE #1:c=0,e=486,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,ti m=2383911063
BINDS #1:
EXEC
#1:c=15625,e=2888,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og =4,tim=2383946705
WAIT #1: nam='SQL*Net message to client' ela= 4 p1=1111838976 p2=1
p3=0
FETCH #1:c=0,e=35,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=4,tim =2383952308
WAIT #1: nam='SQL*Net message from client' ela= 16414 p1=1111838976
p2=1 p3=0
WAIT #1: nam='SQL*Net break/reset to client' ela= 57 p1=1111838976
p2=0 p3=0
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1111838976 p2=1
p3=0
WAIT #1: nam='SQL*Net message from client' ela= 578 p1=1111838976 p2=1
p3=0
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=9602 op='TABLE ACCESS BY INDEX
ROWID OBJ#(9602) (cr=2 r=0 w=0 time=25 us)'
STAT #1 id=2 cnt=1 pid=1 pos=1 obj=9603 op='INDEX UNIQUE SCAN
OBJ#(9603) (cr=1 r=0 w=0 time=13 us)'

You'll notice what looks like incorrect syntax, trying to select into
':b1:b0'. But then, according to the trace file, Oracle goes ahead
with the PARSE, EXECUTE and FETCH steps with no problem. The FETCH
appears to be correctly fetching the one row (r=1). There's even a
query plan when the cursor is closed (the STAT lines).

Our Pro*C application is reporting an error, SQLCODE = -162. This must
be causing the 'SQL*Net break/reset to client' event. But ORA-00162
looks completely irrelevent.

The other weird thing is that the OBJ#(9602) and OBJ#(9603) are not
the OBJECT_IDs of the objects in the plan!

select object_name from dba_objects where object_id=9602;

OBJECT_NAME
-----------------------------------------------------------------
javax/swing/text/rtf/RTFReader

SQL> select object_name from dba_objects where object_id=9603;

OBJECT_NAME
--------------------------------------------------------------------------------
/d5f6a702_RTFGenerator

Has anybody seen this before? An Oracle bug perhaps?

Things that are weird:
1. Error ORA-00162 is "external dbid length string is greater than
maximum (string)" and this does not appear relevent at all.
2. Query has suspicious syntax but appears to parse, execute and fetch
ok. (So can have a : in a bind variable name!?)
3. OBJ#(9602) and OBJ#(9603) in the plan do not correspond to the
OBJECT_IDs of the table and index used in the query

Thanks in advance for any help.

Malcolm.
Malcolm,
This syntax is perfectly normal for Pro*C, the second one is the
Indicator variable.

From the Pro*C manual:
Quote:
4.3 Indicator Variables

You can associate every host variable with an optional indicator
variable. An indicator variable must be defined as a 2-byte integer and,
in SQL statements, must be prefixed with a colon and immediately follow
its host variable (unless you use the keyword INDICATOR). If you are
using Declare Sections, you must also declare indicator variables inside
the Declare Sections.

[Snip]

4.3.1 The INDICATOR Keyword

To improve readability, you can precede any indicator variable with the
optional keyword INDICATOR. You must still prefix the indicator variable
with a colon. The correct syntax is:

:host_variable INDICATOR :indicator_variable

which is equivalent to

:host_variable:indicator_variable

You can use both forms of expression in your host program.
<<<

Perhaps the module has recompiled with changed settings?

Hope that leads you to the cause,
Neil


Reply With Quote
  #10  
Old   
Neil.W.James
 
Posts: n/a

Default Re: Weird Pro*C trace file - 06-12-2008 , 03:45 AM



malcolm wrote:
Quote:
Hi,

I was wondering if anyone could help me with the below strange
occurance?

We have a Pro*C application running on our DB server (jurassic Oracle
9.2.0.1 on Windows 2003 r2 32-bit) which until very recently was
working without problems. Nothing (as far as I know) has changed in
this environment, but now the application is bombing out on one
particular query.

Below is an extract from a 10046 sql trace of the query in question:

=====================
PARSING IN CURSOR #1 len=57 dep=0 uid=47 oct=3 lid=47 tim=2383911068
hv=1227232938 ad='19e2c4e0'
select zz_dbvr into :b0:b1 from zz_ where zz_dbky='0000'
END OF STMT
PARSE #1:c=0,e=486,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,ti m=2383911063
BINDS #1:
EXEC
#1:c=15625,e=2888,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og =4,tim=2383946705
WAIT #1: nam='SQL*Net message to client' ela= 4 p1=1111838976 p2=1
p3=0
FETCH #1:c=0,e=35,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=4,tim =2383952308
WAIT #1: nam='SQL*Net message from client' ela= 16414 p1=1111838976
p2=1 p3=0
WAIT #1: nam='SQL*Net break/reset to client' ela= 57 p1=1111838976
p2=0 p3=0
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1111838976 p2=1
p3=0
WAIT #1: nam='SQL*Net message from client' ela= 578 p1=1111838976 p2=1
p3=0
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=9602 op='TABLE ACCESS BY INDEX
ROWID OBJ#(9602) (cr=2 r=0 w=0 time=25 us)'
STAT #1 id=2 cnt=1 pid=1 pos=1 obj=9603 op='INDEX UNIQUE SCAN
OBJ#(9603) (cr=1 r=0 w=0 time=13 us)'

You'll notice what looks like incorrect syntax, trying to select into
':b1:b0'. But then, according to the trace file, Oracle goes ahead
with the PARSE, EXECUTE and FETCH steps with no problem. The FETCH
appears to be correctly fetching the one row (r=1). There's even a
query plan when the cursor is closed (the STAT lines).

Our Pro*C application is reporting an error, SQLCODE = -162. This must
be causing the 'SQL*Net break/reset to client' event. But ORA-00162
looks completely irrelevent.

The other weird thing is that the OBJ#(9602) and OBJ#(9603) are not
the OBJECT_IDs of the objects in the plan!

select object_name from dba_objects where object_id=9602;

OBJECT_NAME
-----------------------------------------------------------------
javax/swing/text/rtf/RTFReader

SQL> select object_name from dba_objects where object_id=9603;

OBJECT_NAME
--------------------------------------------------------------------------------
/d5f6a702_RTFGenerator

Has anybody seen this before? An Oracle bug perhaps?

Things that are weird:
1. Error ORA-00162 is "external dbid length string is greater than
maximum (string)" and this does not appear relevent at all.
2. Query has suspicious syntax but appears to parse, execute and fetch
ok. (So can have a : in a bind variable name!?)
3. OBJ#(9602) and OBJ#(9603) in the plan do not correspond to the
OBJECT_IDs of the table and index used in the query

Thanks in advance for any help.

Malcolm.
Malcolm,
This syntax is perfectly normal for Pro*C, the second one is the
Indicator variable.

From the Pro*C manual:
Quote:
4.3 Indicator Variables

You can associate every host variable with an optional indicator
variable. An indicator variable must be defined as a 2-byte integer and,
in SQL statements, must be prefixed with a colon and immediately follow
its host variable (unless you use the keyword INDICATOR). If you are
using Declare Sections, you must also declare indicator variables inside
the Declare Sections.

[Snip]

4.3.1 The INDICATOR Keyword

To improve readability, you can precede any indicator variable with the
optional keyword INDICATOR. You must still prefix the indicator variable
with a colon. The correct syntax is:

:host_variable INDICATOR :indicator_variable

which is equivalent to

:host_variable:indicator_variable

You can use both forms of expression in your host program.
<<<

Perhaps the module has recompiled with changed settings?

Hope that leads you to the cause,
Neil


Reply With Quote
Reply




Thread Tools
Display Modes

Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

vB code is On
Smilies are On
[IMG] code is On
HTML code is Off



Powered by vBulletin Version 3.5.3
Copyright ©2000 - 2012, Jelsoft Enterprises Ltd.