Re: Native compiled code *much* slower??
- From: Dion Cho <ukja.dion@xxxxxxxxx>
- To: stbaldwin@xxxxxxxxxxxxxxxx
- Date: Mon, 4 Jan 2010 19:10:46 +0900
Steve.
It really looks like a bug and/or some misconfigurations, but before the
conclusion, I would try tracing API call.
1. OS process level trace - strace/truss/....
2. 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@xxxxxxxxxxxxxxxx>
> 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@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> @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> @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> @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> @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> @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@xxxxxxxxx>
> 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
>
Other related posts:
