Re: Weird Pro*C trace file

From: Ed Prochak <edprochak_at_gmail.com>
Date: Wed, 11 Jun 2008 11:00:48 -0700 (PDT)
Message-ID: <4d9b9b62-9359-4ee3-9481-05fd9a02fa8d@8g2000hse.googlegroups.com>


On Jun 11, 12:31 pm, malcolm <malcolmarn..._at_gmail.com> wrote:
> 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.

What does the Source code look like?
  Ed Received on Wed Jun 11 2008 - 13:00:48 CDT

Original text of this message