Re: Weird Pro*C trace file
Date: Thu, 12 Jun 2008 02:57:49 -0700 (PDT)
Message-ID: <19f5206f-71aa-4f9e-851f-3f81c5bc0fa5@j22g2000hsf.googlegroups.com>
On Jun 12, 9:45 am, "Neil.W.James" <n..._at_NONSPAM.familyjames.com>
wrote:
> malcolm 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.
>
> Malcolm,
> This syntax is perfectly normal for Pro*C, the second one is the
> Indicator variable.
>
> From the Pro*C manual:
> >>>
> 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
Excellent, thank you Neil.
I read in the documentation that indicator variables are used to indicate nulls. I must say that it's great to sometimes work at a low level (like OCI) to further your understanding. I have never seen this syntax before.
Which leads me to an additional question: how does pl/sql or jdbc know whether an output bind variable is null without using indicator variables?
My questions 1+3 still stand:
1. Why am I getting a ORA-00162?
3. Why are the object ids in the explain plan in the trace incorrect?
Everyone here tells me nothing has changed in this environment, but I don't believe them. I have logged an SR with Oracle. I will update the group with the resolution if I find one.
Thanks for your reply Ed, source for the relevent function is below:
/*
+ lsql_dsv(..) Database schema version functions.
*/
EXEC SQL BEGIN DECLARE SECTION ;
static char zz_dbvr[5]; static short zz_dbvr_i; EXEC SQL END DECLARE SECTION ; extern int wtrc_sv; /* DB schemaversion */
lsql_dsv()
{
int v;
TRC0("lsql_dsv");
EXEC SQL SELECT
zz_dbvr
INTO
:zz_dbvr INDICATOR :zz_dbvr_i
FROM
zz_
WHERE
zz_dbky = '0000'
;
/* ------------------------------------------------*/
fprintf(stdout,"zz_ db schema version query SQLCODE = %d\n",
SQLCA_SQLCODE); // ORA-00162 reported here
/*-------------------------------------------------*/
if (SQLCA_SQLCODE == SQLNOTFOUND) /* if not found */
v = 0;
else if (SQLCA_SQLCODE) /* if error */
v = -1;
else
v = atoi(zz_dbvr);
RETV(v) /*
return result */
} Received on Thu Jun 12 2008 - 04:57:49 CDT