Dion Cho – Oracle Performance Storyteller

We are natural born scientists

Posts Tagged ‘callstack

Pure SQL version of ostakprof(from Tanel Poder)

with 8 comments

Have you noticed following post from Tanel Poder? This is a very interesting and practical story even with the depth within it.

Here he introduces how you can do a simple but powerful function call profiling on the process without any serious 3rd party tool. ORADEBUG SHORT_STACK command is the core of the technique. His approach is to use VBscript(on the client-side) to parse the result of ORADEBUG SHORT_STACK.

I tried to implement the same functionality with 100% pure SQL which seems more portable and customizable to me. Following is the dirty example of it.

--------------------------------------------------------------------------------
-- @name: prof_callstack
-- @author: dion cho
-- @note: troubleshoot using oradebug callstack dump
-- @usage: @prof_callstack   
--------------------------------------------------------------------------------
define __SID = &1
define __SLEEP = &2
define __SAMPLE = &3

col spid new_value v_spid

select spid 
from v$process
where addr = (select paddr from v$session where sid = &__SID);

oradebug setospid &v_spid

@make_callstack &__SLEEP &__SAMPLE

@oradebug_callstack

/* -- execute following command before doing profiling.
drop table callstack_temp purge;

create global temporary table 
callstack_temp(seq number, idx number, fname varchar2(20));
*/

declare
	b_start		boolean := false;
	b_first		boolean := false;
	fname			varchar2(20);
	ftype			varchar2(10);
	seq				number := 1;
	idx				number := 1;
begin
	for r in (select * from table(ukja.get_trace_file1(&__SID))) loop
		if instr(r.column_value, 'Call Stack Trace') > 0 then
			b_start := true;
			b_first := true;
		end if;
		
		if instr(r.column_value, 'End of Call Stack Trace') >0 then
			seq := seq+1;
			idx := 1;
			b_start := false;
		end if;
		
		if b_start = true and b_first = false then
			fname := rtrim(substr(r.column_value, 1, 20));
			ftype := rtrim(substr(r.column_value, 22, 8));
			if ftype like 'CALL%' or ftype = 'VIRTUAL' then
				dbms_output.put_line(fname);
				insert into callstack_temp values(seq, idx, fname);
				idx := idx + 1;
			end if;
		end if;
		
		if b_start = true then 
			b_first := false;
		end if;
		
	end loop;
end;
/

spool callstack_result.txt
-- do some reporting
col sample# new_value sample_count
select 
	count(distinct seq) as sample#,
	count(*) as call#,
	max(idx) as max_depth
from callstack_temp
;

-- unique callstack and hit count
select 
	count(*) as hit#,
	100*(count(*)/&sample_count) as ratio,
	stack
from 
(
	select 
		seq,
		ltrim(sys_connect_by_path(fname,'->'),',') stack
	from (
		select 
			seq,
			fname,
			row_number() over (partition by seq order by idx desc) rn,
			count(*) over (partition by seq) cnt
		from callstack_temp
	)
	where level = cnt
	start with rn = 1
	connect by prior seq = seq and prior rn = rn-1
)
group by stack
order by 1 desc
;

spool off
@ed callstack_result.txt
delete from callstack_temp;



Here I use ORADEBUG DUMP CALLSTACK 1 command to store the callstacks to the server-side tracefile.

Following is how to make Oracle automatically invokes ORADEBUG DUMP CALLSTACK 1 command multiple times.

set heading off
set timing off
set feedback off
set verify off
set serveroutput on size 100000

spool oradebug_callstack.sql

begin
	for idx in 1 .. &2 loop
		dbms_output.put_line('oradebug dump callstack 1');
		dbms_output.put_line('exec dbms_lock.sleep(&1);');
	end loop;
end;
/

spool off
set heading on
set timing on
set feedback on
set verify on
set serveroutput off


For simple test case, I make a query which consumes good minutes to be hard-parsed.

set heading off
set timing off
set feedback off
set serveroutput on size 100000

var v_sql clob;

begin
  :v_sql := 'select count(*) from ';
  
  for r in (select t1.table_name
        from user_tables t1, user_tables t2 where rownum <= 500 and
            t1.table_name not like '%$%') loop
    :v_sql := :v_sql || r.table_name || ', ';
    
  end loop;
  
  :v_sql := :v_sql || ' dual where 1 = 0;';
  
end;
/

spool long_parse.sql
exec dbms_output.put_line(:v_sql);
spool off
set heading on
set timing on
set feedback on
set serveroutput off


While getting the session#1 invoke the long-parsing query, let me invoke the prof_callstack.sql as following.

-- session #1
UKJA@ukja102> @long_parse

  COUNT(*)
----------
         0

Elapsed: 00:03:06.53
-- session#2
connect /as sysdba
SYS@ukja10> @prof_callstack 140 0.01 100


Now I get the internal meaning of the long hard-parsing query like following.


   SAMPLE#      CALL#  MAX_DEPTH                                                
---------- ---------- ----------                                                
       100       4198         44                                                

1 row selected.

Elapsed: 00:00:00.06

FNAME                  COUNT(*)                                                 
-------------------- ----------                                                 
_opiodr+1099                200                                                 
7C80B680                    200                                                 
_apadrv+459                 100                                                 
_kksLoadChild+5883          100                                                 
_kglpim+264                 100                                                 
_kksParseCursor+143         100                                                 
_kkorrio+195                100                                                 
_ksdxfdmp+847               100                                                 
_ssthreadsrgruncall         100                                                 
_opimai_real+112            100                                                 
_apafdr+402                 100                                                 
_kpooprx+232                100                                                 
_kksfbc+7232                100                                                 
_apakkoqb+151               100                                                 
_opidrv+819                 100                                                 
_kglpin+1078                100                                                 
_kglobpn+1224               100                                                 
_kglobld+837                100                                                 
_rpiswu2+426                100                                                 
_kkoqbc+1689                100                                                 
_kkspsc0+2094               100                                                 
_kkslod+98                  100                                                
_sou2o+45                   100                                                 
_opitca+1445                100                                                 
_ksdxcb+1481                100                                                 
_opiino+1087                100                                                 
_kpoal8+775                 100                                                 
_opiosq0+1965               100                                                 
_apaqbd+383                 100                                                 
00000000                    100                                                 
_OracleOradebugThre         100                                                 
_ksedst_tracecb+55          100                                                 
_ttcpip+1273                100                                                 
_kkooqb+8292                100                                                 
_kxsGetRuntimeLock+         100                                                 
__PGOSF359__kksFull         100                                                 
_opimai+92                  100                                                 
_opitsk+1017                100                                                 
_OracleThreadStart@         100                                                 
_apafjo+161                  85                                                 
_apafjo+265                   5                                                 
_apafjo+358                   2                                                 
_apacjp+162                   1                                                 
_apafbp+491                   1                                                 
_apafjo+295                   1                                                 
_apafbr+168                   1                                                 
_apafbp+262                   1                                                 
_apafbp+156                   1                                                 

48 rows selected.

Elapsed: 00:00:00.14

       SEQ        IDX FNAME                                                     
---------- ---------- --------------------                                      
         1         42 7C80B680                                                  
         1         41 _OracleThreadStart@                                       
         1         40 _opimai+92                                                
         1         39 _opimai_real+112                                          
         1         38 _sou2o+45                                                 
         1         37 _opidrv+819                                               
         1         36 _opiodr+1099                                              
         1         35 _opiino+1087                                              
         1         34 _opitsk+1017                                              
         1         33 _ttcpip+1273                                              
         1         32 _opiodr+1099                                              
         1         31 _kpoal8+775                                               
         1         30 _kpooprx+232                                              
         1         29 _opiosq0+1965                                             
         1         28 _kksParseCursor+143                                       
         1         27 _kkspsc0+2094                                             
         1         26 _kksfbc+7232                                              
         1         25 _kxsGetRuntimeLock+                                       
         1         24 _kglpin+1078                                              
         1         23 _kglpim+264                                               
         1         22 _kglobpn+1224                                             
         1         21 _kglobld+837                                              
         1         20 _kkslod+98                                                
         1         19 _kksLoadChild+5883                                        
         1         18 _rpiswu2+426                                              
         1         17 __PGOSF359__kksFull                                       
         1         16 _opitca+1445                                              
         1         15 _apadrv+459                                               
         1         14 _apaqbd+383                                               
         1         13 _apakkoqb+151                                             
         1         12 _kkoqbc+1689                                              
         1         11 _kkooqb+8292                                              
         1         10 _kkorrio+195                                              
         1          9 _apafdr+402                                               
         1          8 _apafjo+161                                               
         1          7 00000000                                                  
         1          6 7C80B680                                                  
         1          5 _OracleOradebugThre                                       
         1          4 _ssthreadsrgruncall                                       
         1          3 _ksdxcb+1481                                              
         1          2 _ksdxfdmp+847                                             
         1          1 _ksedst_tracecb+55                                        

42 rows selected.

Elapsed: 00:00:00.14
old   3: 	100*(count(*)/&sample_count) as ratio,
new   3: 	100*(count(*)/       100) as ratio,

      HIT#      RATIO                                                           
---------- ----------                                                           
STACK                                                                           
--------------------------------------------------------------------------------
        85         85                                                           
->7C80B680->_OracleThreadStart@->_opimai+92->_opimai_real+112->_sou2o+45->_opidr
v+819->_opiodr+1099->_opiino+1087->_opitsk+1017->_ttcpip+1273->_opiodr+1099->_kp
oal8+775->_kpooprx+232->_opiosq0+1965->_kksParseCursor+143->_kkspsc0+2094->_kksf
bc+7232->_kxsGetRuntimeLock+->_kglpin+1078->_kglpim+264->_kglobpn+1224->_kglobld
+837->_kkslod+98->_kksLoadChild+5883->_rpiswu2+426->__PGOSF359__kksFull->_opitca
+1445->_apadrv+459->_apaqbd+383->_apakkoqb+151->_kkoqbc+1689->_kkooqb+8292->_kko
rrio+195->_apafdr+402->_apafjo+161->00000000->7C80B680->_OracleOradebugThre->_ss
threadsrgruncall->_ksdxcb+1481->_ksdxfdmp+847->_ksedst_tracecb+55               
                                                                                
         7          7                                                           
->7C80B680->_OracleThreadStart@->_opimai+92->_opimai_real+112->_sou2o+45->_opidr
v+819->_opiodr+1099->_opiino+1087->_opitsk+1017->_ttcpip+1273->_opiodr+1099->_kp
oal8+775->_kpooprx+232->_opiosq0+1965->_kksParseCursor+143->_kkspsc0+2094->_kksf
bc+7232->_kxsGetRuntimeLock+->_kglpin+1078->_kglpim+264->_kglobpn+1224->_kglobld
+837->_kkslod+98->_kksLoadChild+5883->_rpiswu2+426->__PGOSF359__kksFull->_opitca
+1445->_apadrv+459->_apaqbd+383->_apakkoqb+151->_kkoqbc+1689->_kkooqb+8292->_kko
rrio+195->_apafdr+402->00000000->7C80B680->_OracleOradebugThre->_ssthreadsrgrunc
all->_ksdxcb+1481->_ksdxfdmp+847->_ksedst_tracecb+55                            
                                                                                
         2          2                                                           
->7C80B680->_OracleThreadStart@->_opimai+92->_opimai_real+112->_sou2o+45->_opidr
v+819->_opiodr+1099->_opiino+1087->_opitsk+1017->_ttcpip+1273->_opiodr+1099->_kp
oal8+775->_kpooprx+232->_opiosq0+1965->_kksParseCursor+143->_kkspsc0+2094->_kksf
bc+7232->_kxsGetRuntimeLock+->_kglpin+1078->_kglpim+264->_kglobpn+1224->_kglobld
+837->_kkslod+98->_kksLoadChild+5883->_rpiswu2+426->__PGOSF359__kksFull->_opitca
+1445->_apadrv+459->_apaqbd+383->_apakkoqb+151->_kkoqbc+1689->_kkooqb+8292->_kko
rrio+195->_apafdr+402->_apafjo+358->00000000->7C80B680->_OracleOradebugThre->_ss
threadsrgruncall->_ksdxcb+1481->_ksdxfdmp+847->_ksedst_tracecb+55               
                                                                                
         2          2                                                           
->7C80B680->_OracleThreadStart@->_opimai+92->_opimai_real+112->_sou2o+45->_opidr
v+819->_opiodr+1099->_opiino+1087->_opitsk+1017->_ttcpip+1273->_opiodr+1099->_kp
oal8+775->_kpooprx+232->_opiosq0+1965->_kksParseCursor+143->_kkspsc0+2094->_kksf
bc+7232->_kxsGetRuntimeLock+->_kglpin+1078->_kglpim+264->_kglobpn+1224->_kglobld
+837->_kkslod+98->_kksLoadChild+5883->_rpiswu2+426->__PGOSF359__kksFull->_opitca
+1445->_apadrv+459->_apaqbd+383->_apakkoqb+151->_kkoqbc+1689->_kkooqb+8292->_kko
rrio+195->_apafdr+402->_apafjo+265->00000000->7C80B680->_OracleOradebugThre->_ss
threadsrgruncall->_ksdxcb+1481->_ksdxfdmp+847->_ksedst_tracecb+55               
                                                                                
         1          1                                                           
->7C80B680->_OracleThreadStart@->_opimai+92->_opimai_real+112->_sou2o+45->_opidr
v+819->_opiodr+1099->_opiino+1087->_opitsk+1017->_ttcpip+1273->_opiodr+1099->_kp
oal8+775->_kpooprx+232->_opiosq0+1965->_kksParseCursor+143->_kkspsc0+2094->_kksf
bc+7232->_kxsGetRuntimeLock+->_kglpin+1078->_kglpim+264->_kglobpn+1224->_kglobld
+837->_kkslod+98->_kksLoadChild+5883->_rpiswu2+426->__PGOSF359__kksFull->_opitca
+1445->_apadrv+459->_apaqbd+383->_apakkoqb+151->_kkoqbc+1689->_kkooqb+8292->_kko
rrio+195->_apafdr+402->_apafjo+265->_apafbp+262->00000000->7C80B680->_OracleOrad
ebugThre->_ssthreadsrgruncall->_ksdxcb+1481->_ksdxfdmp+847->_ksedst_tracecb+55  
                                                                                
         1          1                                                           
->7C80B680->_OracleThreadStart@->_opimai+92->_opimai_real+112->_sou2o+45->_opidr
v+819->_opiodr+1099->_opiino+1087->_opitsk+1017->_ttcpip+1273->_opiodr+1099->_kp
oal8+775->_kpooprx+232->_opiosq0+1965->_kksParseCursor+143->_kkspsc0+2094->_kksf
bc+7232->_kxsGetRuntimeLock+->_kglpin+1078->_kglpim+264->_kglobpn+1224->_kglobld
+837->_kkslod+98->_kksLoadChild+5883->_rpiswu2+426->__PGOSF359__kksFull->_opitca
+1445->_apadrv+459->_apaqbd+383->_apakkoqb+151->_kkoqbc+1689->_kkooqb+8292->_kko
rrio+195->_apafdr+402->_apafjo+265->_apafbp+491->_apacjp+162->00000000->7C80B680
->_OracleOradebugThre->_ssthreadsrgruncall->_ksdxcb+1481->_ksdxfdmp+847->_ksedst
_tracecb+55                                                                     
                                                                                
         1          1                                                           
->7C80B680->_OracleThreadStart@->_opimai+92->_opimai_real+112->_sou2o+45->_opidr
v+819->_opiodr+1099->_opiino+1087->_opitsk+1017->_ttcpip+1273->_opiodr+1099->_kp
oal8+775->_kpooprx+232->_opiosq0+1965->_kksParseCursor+143->_kkspsc0+2094->_kksf
bc+7232->_kxsGetRuntimeLock+->_kglpin+1078->_kglpim+264->_kglobpn+1224->_kglobld
+837->_kkslod+98->_kksLoadChild+5883->_rpiswu2+426->__PGOSF359__kksFull->_opitca
+1445->_apadrv+459->_apaqbd+383->_apakkoqb+151->_kkoqbc+1689->_kkooqb+8292->_kko
rrio+195->_apafdr+402->_apafjo+265->_apafbp+156->_apafbr+168->00000000->7C80B680
->_OracleOradebugThre->_ssthreadsrgruncall->_ksdxcb+1481->_ksdxfdmp+847->_ksedst
_tracecb+55                                                                     
                                                                                
         1          1                                                           
->7C80B680->_OracleThreadStart@->_opimai+92->_opimai_real+112->_sou2o+45->_opidr
v+819->_opiodr+1099->_opiino+1087->_opitsk+1017->_ttcpip+1273->_opiodr+1099->_kp
oal8+775->_kpooprx+232->_opiosq0+1965->_kksParseCursor+143->_kkspsc0+2094->_kksf
bc+7232->_kxsGetRuntimeLock+->_kglpin+1078->_kglpim+264->_kglobpn+1224->_kglobld
+837->_kkslod+98->_kksLoadChild+5883->_rpiswu2+426->__PGOSF359__kksFull->_opitca
+1445->_apadrv+459->_apaqbd+383->_apakkoqb+151->_kkoqbc+1689->_kkooqb+8292->_kko
rrio+195->_apafdr+402->_apafjo+295->00000000->7C80B680->_OracleOradebugThre->_ss
threadsrgruncall->_ksdxcb+1481->_ksdxfdmp+847->_ksedst_tracecb+55               
                                                                                

8 rows selected.

Elapsed: 00:00:06.95



Here you see that the most frequent functions to be called are “kko”, “kks”(compile) and “kgl”(library cache) related ones which strongly hints the possibility of the hard parse with many LCO being related.

Anyway, the insights given by Tanel Poder are always amazing and technically challenging.





Written by Dion Cho

June 18, 2009 at 3:10 am

Posted in Troubleshooting

Tagged with , ,

Simple and stupid example on troubleshooting using callstack

with 7 comments

Look at this – the simplest query imagineable.

UKJA@ukja102> select * from dual;
...  <-- Hanged!!!



But it’s hanged!

Okay, it’s abnormal hang situation, so I look into the session.

SYS@ukja10> @session_list

  SID SERIAL# PROGRAM    EVENT                SQL_TEXT
----- ------- ---------- -------------------- ------------------------------
  146    6578 sqlplus.ex SQL*Net message from
              e           client
...

SYS@ukja10> exec print_table('select * from v$session where sid = 146');
SADDR                         : 2EB2FDFC
SID                           : 146
SERIAL#                       : 6578
AUDSID                        : 19288
PADDR                         : 2EA4F58C
USER#                         : 61
USERNAME                      : UKJA
COMMAND                       : 0
OWNERID                       : 2147483644
TADDR                         :
LOCKWAIT                      :
STATUS                        : INACTIVE
SERVER                        : DEDICATED
SCHEMA#                       : 61
SCHEMANAME                    : UKJA
OSUSER                        : UKJA\exem
PROCESS                       : 12172:10844
MACHINE                       : EX-EM.COM\UKJA
TERMINAL                      : UKJA
PROGRAM                       : sqlplus.exe
TYPE                          : USER
SQL_ADDRESS                   : 00
SQL_HASH_VALUE                : 0
SQL_ID                        :
SQL_CHILD_NUMBER              :
PREV_SQL_ADDR                 : 27DAB918
PREV_HASH_VALUE               : 96831227
PREV_SQL_ID                   : 7us1frh2wb1rv
PREV_CHILD_NUMBER             : 0
MODULE                        : SQL*Plus
MODULE_HASH                   : 3669949024
ACTION                        :
ACTION_HASH                   : 0
CLIENT_INFO                   :
FIXED_TABLE_SEQUENCE          : 114132657
ROW_WAIT_OBJ#                 : -1
ROW_WAIT_FILE#                : 0
ROW_WAIT_BLOCK#               : 0
ROW_WAIT_ROW#                 : 0
LOGON_TIME                    : 2009/06/11 13:16:42
LAST_CALL_ET                  : 79
PDML_ENABLED                  : NO
FAILOVER_TYPE                 : NONE
FAILOVER_METHOD               : NONE
FAILED_OVER                   : NO
RESOURCE_CONSUMER_GROUP       :
PDML_STATUS                   : DISABLED
PDDL_STATUS                   : ENABLED
PQ_STATUS                     : ENABLED
CURRENT_QUEUE_DURATION        : 0
CLIENT_IDENTIFIER             :
BLOCKING_SESSION_STATUS       : NO HOLDER
BLOCKING_INSTANCE             :
BLOCKING_SESSION              :
SEQ#                          : 29
EVENT#                        : 256
EVENT                         : SQL*Net message from client
P1TEXT                        : driver id
P1                            : 1413697536
P1RAW                         : 54435000
P2TEXT                        : #bytes
P2                            : 1
P2RAW                         : 00000001
P3TEXT                        :
P3                            : 0
P3RAW                         : 00
WAIT_CLASS_ID                 : 2723168908
WAIT_CLASS#                   : 6
WAIT_CLASS                    : Idle
WAIT_TIME                     : 0
SECONDS_IN_WAIT               : 79
STATE                         : WAITING
SERVICE_NAME                  : UKJA10
SQL_TRACE                     : DISABLED
SQL_TRACE_WAITS               : FALSE
SQL_TRACE_BINDS               : FALSE
-----------------



I really see nothing special. It is just in the idle status doing nothing. Now what else can I do?

Oracle provides pretty little feature called short_stack, which prints the minimal callstack information.

SYS@ukja10> oradebug setospid 11744
Oracle pid: 23, Windows thread id: 11744, image: ORACLE.EXE (SHAD)              

SYS@ukja10> oradebug short_stack
_ksdxfstk+14<-_ksdxcb+1481<-_ksdxsus+1037<-_ksdxffrz+50<-_ksdxcb+1481
<-_ssthreadsrgruncallback+428<-_OracleOradebugThreadStart@4+795<-7C80B680
<-00000000<-719857C4<-719E4376<-62985408<-62983266<-60A08BD8<-609CCBB8
<-609AF9CD<-609ACF09<-6097E2C7<-__PGOSF126__opikndf2+781<-_opitsk+540
<-_opiino+1087<-_opiodr+1099<-_opidrv+819<-_sou2o+45<-_opimai_real+112
<-_opimai+92<-_OracleThreadStart@4+708<-7C80B680



Do you see any meaningful information? What makes me curios is following part.

... <-_ksdxsus+1037<-_ksdxffrz+50<- ... 



My interpretation. Flash freeze(ffrz) was invoked and the session was suspended(sus). Resuming the instance from flash freeze would prove my suspicion.

SYS@ukja10> oradebug ffresumeinst
Statement processed.

...
UKJA@ukja102> select * from dual;

D
-
X

Elapsed: 00:09:30.14



If you don’t like the simplicity of short_stack, errorstack would show more information.

SYS@ukja10> oradebug dump errorstack 2
Statement processed.
SYS@ukja10> oradebug tracefile_name
c:\oracle\admin\ukja10\udump\ukja10_ora_11744.trc

----- Call Stack Trace -----
calling              call     entry                argument values in hex      
location             type     point                (? means dubious value)     
-------------------- -------- -------------------- ----------------------------
_ksedst+38           CALLrel  _ksedst1+0           1 1
_ksedmp+898          CALLrel  _ksedst+0            1
_ksdxfdmp+847        CALLreg  00000000             2
_ksdxcb+1481         CALLreg  00000000             D68F43C 11 3 D68F39C D68F3EC
_ksdxsus+1037        CALLrel  _ksdxcb+0            1
_ksdxffrz+50         CALLrel  _ksdxsus+0           1
_ksdxcb+1481         CALLreg  00000000             D68FB20 7 1 D68FA80 D68FAD0
_ssthreadsrgruncall  CALLrel  _ksdxcb+0            1
back+428                                           
_OracleOradebugThre  CALLrel  _ssthreadsrgruncall  D68FF84
adStart@4+795                 back+0               
7C80B680             CALLreg  00000000             
00000000             VIRTUAL  7C93EB94             
719857C4             CALLrel  71983C6B             
719E4376             CALLreg  00000000             
62985408             CALL???  00000000             
62983266             CALLrel  6298530C             F90 AAD779A 810 0
60A08BD8             CALLreg  00000000             AAAF98C AAD779A AAAFB20 0 0
609CCBB8             CALLrel  60A07EF0             AA7FAF0 B83E01C A5FED30
609AF9CD             CALLrel  609CCAF0             AA7FAF0 A5FED30
609ACF09             CALLrel  609ACF48             A5FEC14 55 A5FED30 0 B83E2AC
                                                   0 3
6097E2C7             CALLrel  609ACEF4             A5FEC14 A5FED30 B83E2AC 0
__PGOSF126__opikndf  CALLreg  00000000             
2+781                                              
_opitsk+540          CALLreg  00000000             
_opiino+1087         CALLrel  _opitsk+0            0 0
_opiodr+1099         CALLreg  00000000             3C 4 B83FC8C
_opidrv+819          CALLrel  _opiodr+0            3C 4 B83FC8C 0
_sou2o+45            CALLrel  _opidrv+0            3C 4 B83FC8C
_opimai_real+112     CALLrel  _sou2o+0             B83FC80 3C 4 B83FC8C
_opimai+92           CALLrel  _opimai_real+0       2 B83FCB8
_OracleThreadStart@  CALLrel  _opimai+0            
4+708                                              
7C80B680             CALLreg  00000000             



Very stupid demo, isn’t it? But is a streotypical case which shows the usefullness and uniqueness of callstack analysis.

Tanel Poder shows his uniquesses and real-life approach on callstack analysis (short_stack) here, and you might like to see see following metalink notes which accidentally contain good information on callstack analysis.

  • 175982.1: ORA-600 Lookup Error Categories
  • 453521.1: ORA-04031 “KSFQ Buffers” ksmlgpalloc
  • 558671.1: Getting ORA-01461 while INSERT INTO WWV_THINGS





Written by Dion Cho

June 11, 2009 at 7:00 am

Follow

Get every new post delivered to your Inbox.

Join 59 other followers