Re: Weird Pro*C trace file

On Jun 12, 2:57 am, malcolm <malcolmarn..._at_gmail.com> wrote:
> 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.

Let me say it's been >decade since I've done any precompiler work, and longer since I've done any c, so my actual knowledge is < 0. But I'm wondering if that error is really ora 162, as your app said it was -162. So I'm wondering if that is perhaps a two's complement of the actual error, perhaps 32767-162?. I notice there can be a lot of prefixes other than ORA, does your app say what? See $ORACLE_HOME/lib/ facility.lis, and see if you have anything in $ORACLE_HOME/precomp/ p*msg.

You are getting errors about java objects when you are trying to format the schema version? Could your zz_dbvr be too short or not really an integer?

>
> 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 schema
> version */
> 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 */
>
>
>
> }

jg

--
@home.com is bogus.  Seen at: http://seriouslyomg.com/?p=8431 :
WordPress database error: [MySQL server has gone away]
SELECT ID, post_title FROM wp_posts WHERE post_date < '2008-06-12
05:32:45' AND post_type = 'post' AND post_status = 'publish' ORDER BY
post_date DESC LIMIT 1

WordPress database error: [MySQL server has gone away]
SELECT ID, post_title FROM wp_posts WHERE post_date > '2008-06-12
05:32:45' AND post_type = 'post' AND post_status = 'publish' AND ID !=
8431 ORDER BY post_date ASC LIMIT 1
WordPress database error: [MySQL server has gone away]
SELECT * FROM wp_users WHERE ID = '2' LIMIT 1