Weird Pro*C trace file

From: malcolm <malcolmarnold_at_gmail.com>
Date: Wed, 11 Jun 2008 09:31:57 -0700 (PDT)
Message-ID: <a2dd5c3e-5334-497d-80ac-a447e08816d6@d45g2000hsc.googlegroups.com>


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,tim=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. Received on Wed Jun 11 2008 - 11:31:57 CDT

Original text of this message