Re: Native compiled code *much* slower??
Date: Mon, 4 Jan 2010 19:10:46 +0900
Message-ID: <43c2e3d61001040210p536da73cj66ebc2530eb5b8c5_at_mail.gmail.com>
Steve.
It really looks like a bug and/or some misconfigurations, but before the conclusion, I would try tracing API call.
- OS process level trace - strace/truss/....
- Oracle call stack trace. For instance, http://dioncho.wordpress.com/2009/06/18/pure-sql-version-of-ostakproffrom-tanel-poder http://blog.tanelpoder.com/2008/10/31/advanced-oracle-troubleshooting-guide-part-9-process-stack-profiling-from-sqlplus-using-ostackprof/
Even if this is a bug, above raw tracing data would be a big help to diagnose your problem.
Dion Cho - Oracle Performance Storyteller
http://dioncho.wordpress.com (english) http://ukja.tistory.com (korean) http://dioncho.blogspot.com (japanese) http://ask.ex-em.com (q&a) ================================
2010/1/4 Steve Baldwin <stbaldwin_at_multiservice.com>
> Thanks to all who replied. I have trimmed this down to a *much*
> simpler test case. There is NO SQL so the opportunity for tuning is
> limited.
>
> I'm pretty sure it must be a bug with 11.1 but I'd be grateful if
> someone also running 11.1 could try my test case ...
>
> [stbaldwin_at_opbld03 ~]$ sqlplus usr/xxx
>
> SQL*Plus: Release 11.1.0.7.0 - Production on Mon Jan 4 03:24:37 2010
>
> Copyright (c) 1982, 2008, Oracle. All rights reserved.
>
>
> Connected to:
> Oracle Database 11g Release 11.1.0.7.0 - 64bit Production
> With the Real Application Clusters option
>
> SQL> set timing on
> SQL> set echo on
> SQL> _at_jproc
> SQL> create or replace procedure junk as
> 2 l_callstack VARCHAR2(4096) :=
> dbms_utility.format_call_stack;
> 3 begin
> 4 null;
> 5 end junk;
> 6 /
>
> Procedure created.
>
> Elapsed: 00:00:00.02
> SQL> _at_interp
> SQL> alter session set plsql_code_type = interpreted;
>
> Session altered.
>
> Elapsed: 00:00:00.00
> SQL> alter procedure junk compile;
>
> Procedure altered.
>
> Elapsed: 00:00:00.01
> SQL> _at_sb8
> SQL> begin
> 2 for i in 1 .. 10000 loop
> 3 junk;
> 4 end loop;
> 5 end;
> 6 /
>
> PL/SQL procedure successfully completed.
>
> Elapsed: 00:00:00.04
> SQL> _at_native
> SQL> alter session set plsql_code_type = native;
>
> Session altered.
>
> Elapsed: 00:00:00.00
> SQL> alter procedure junk compile;
>
> Procedure altered.
>
> Elapsed: 00:00:00.02
> SQL> _at_sb8
> SQL> begin
> 2 for i in 1 .. 10000 loop
> 3 junk;
> 4 end loop;
> 5 end;
> 6 /
>
> PL/SQL procedure successfully completed.
>
> Elapsed: 00:02:03.38
>
> As you can see, it is now a standalone procedure that calls
> dbms_utility.format_call_stack *and nothing else*. I don't know what
> happens in dbms_utility.format_call_stack but all my code is pure
> pl/sql so there is presumably no context switching.
>
> I have tried natively compiling dbms_utility but it makes no
> difference to the results.
>
> Thanks again,
>
> Steve
>
> On Sun, Dec 27, 2009 at 3:32 AM, Andre van Winssen <dreveewee_at_gmail.com>
> wrote:
> >
> >
> > Hi Steve,
> >
> >
> >
> > I ran it against 11.2 multiple times and cannot reproduce the behavior
> you
> > describe. I see following consistent results:
> >
> >
> >
> > plsql_code_type = interpreted => 3.21 secs
> >
> > plsql_code_type = native => 2.9 secs
> >
> >
> >
> > (nr of iterations set to 10000)
> >
> >
> >
> > To be able to test this I had to add a missing table
> db_error_stack_context
> > which is referenced type declarations in msc$log_p (e.g. SUBTYPE stSource
> IS
> > db_error_stack_context.context_at%TYPE):
> >
> >
> >
> > create table db_error_stack_context
> >
> > (context_at varchar2(1024)
> >
> > ,context_value varchar2(1024)
> >
> > ,context_name varchar2(1024)
> >
> > );
> >
> >
> >
> > Regards,
> >
> > Andre
>
-- http://www.freelists.org/webpage/oracle-lReceived on Mon Jan 04 2010 - 04:10:46 CST