HelloDBA [中文]
Search Internet Search HelloDBA
  Oracle Technology Site. email: fuyuncat@gmail.com  MSN: fuyuncat@hotmail.com Add to circle  acoug  acoug 

An Oracle Call Tracer For Windows(32)

[中文]

Author:  fuyuncat

Source:  www.HelloDBA.com

Date:  2010-05-28 08:23:50

Share to  Twitter Facebook GMail Blogger Orkut Google Bookmarks Sina Weibo QQ Renren Tieba Kaixin Douban Taobao

    Warning: This tool is a beta version, it may cause unexpected error. Never play it in any crytical system!

    Base on the my windows threads top CPU usage tool, TopShow, I built another tool, OraTracer, a simple oracle call tracer. You can use this tool to set multiple trace points for known oracle internal calls. And it will log the calling with detected arguments, call stacks corresponding to the trace point setting. The trace could be set in process level or thread level.

    Example 1:
    Capture executing SQLs in whole oracle db instance.

    First, set below trace points in the file "TracePoints.txt", which locate at the same folder of the executable file.

SQL代码
  1. _opiprs 6*1   
  2. _rpisplu 6*2   
  3. _kprbprs 6  

    The number following the call name that splited by a space character is the argument number. If it pluses with "*<num>", means you want treat the DWORD values as a pointer, and the number following "*" is the pointer deep. For the 1st trace point, the call name is "_opiprs", and argument number is 6, with 1 as pointer deep.
    Note: "#" is comment flag.

    Then, Select the ORACLE.EXE in the process, without any thread be selected:

    Finally, click the "Trace" button. If those trace point called in Oracle, you will get the trace log in the log window.

SQL代码
  1. ...   
  2. [2010-5-28 3:53:23.426]User call: _rpisplu (TID: 5276)    
  3.     [Args(6)]:    
  4.         6   
  5.         0   
  6.         0   
  7.         "select privilege#,level from sysauth$ connect by grantee#=prior privilege# and privilege#>0 start with grantee#=:1 and privilege#>0"  
  8.         0x84(=>NULL)   
  9.         0   
  10. [2010-5-28 3:53:23.442]User call: _rpisplu (TID: 5276)    
  11.     [Args(6)]:    
  12.         6   
  13.         0   
  14.         0   
  15.         "alter session set NLS_LANGUAGE='AMERICAN' NLS_TERRITORY='AMERICA' NLS_CURRENCY='$' NLS_ISO_CURRENCY='AMERICA' NLS_NUMERIC_CHARACTERS='.,' NLS_DATE_FORMAT='DD-MON-RR' NLS_DATE_LANGUAGE='AMERICAN' NLS_SORT='BINARY'"  
  16.         0xd4(=>NULL)   
  17.         0   
  18. [2010-5-28 3:53:23.473]User call: _opiprs (TID: 5276)    
  19.     [Args(6)]:    
  20.         0x70cce00(=>0x4000000)   
  21.         "alter session set NLS_LANGUAGE='AMERICAN' NLS_TERRITORY='AMERICA' NLS_CURRENCY='$' NLS_ISO_CURRENCY='AMERICA' NLS_NUMERIC_CHARACTERS='.,' NLS_DATE_FORMAT='DD-MON-RR' NLS_DATE_LANGUAGE='AMERICAN' NLS_SORT='BINARY'"  
  22.         0xd5(=>NULL)   
  23.         0x4bfe214(=>0x18)   
  24.         0   
  25.         6   
  26. [2010-5-28 3:53:23.504]User call: _rpisplu (TID: 5276)    
  27.     [Args(6)]:    
  28.         3   
  29.         0x20(=>NULL)   
  30.         0x20(=>NULL)   
  31.         "select sysdate + 1 / (24 * 60) from dual"  
  32.         0x28(=>NULL)   
  33.         1   
  34. [2010-5-28 3:53:23.520]User call: _rpisplu (TID: 5276)    
  35.     [Args(6)]:    
  36.         5   
  37.         0x20(=>NULL)   
  38.         0x20(=>NULL)   
  39.         "DECLARE job BINARY_INTEGER := :job; next_date DATE := :mydate;  broken BOOLEAN := FALSE; BEGIN EMD_MAINTENANCE.EXECUTE_EM_DBMS_JOB_PROCS(); :mydate := next_date; IF broken THEN :b := 1; ELSE :b := 0; END IF; END; "  
  40.         0xd5(=>NULL)   
  41.         0   
  42. ...  

    If you want to stop tracing, just click the "Stop" button.

    Example 2: 
    Understanding the SQL execution drived by plan.

    As we know, the execution plan is in fact to drive the Source Generator to fetch data via specified functions. We trace those functions to help us understanding the executions plan.

    Download below tracepoint setting file, rename it to "TracePoints.txt", put it in the same folder of OraTracer.exe:
    http://www.HelloDBA.com/Download/TracePoints_ALL_Query_Calls.zip

    Then, get SPID of the session you want to trace.

SQL代码
  1. HELLODBA.COM>select distinct spid from v$mystat m, v$session s, v$process p where s.sid=m.sid and s.paddr=p.addr;   
  2.   
  3. SPID   
  4. ------------   
  5. 11076  

    Select ORACLE.EXE from the processes list => select the TID number 11076 from the threads list => Click "Trace" button.

    And let's execute a SQL in the session we're tracing.

SQL代码
  1. HELLODBA.COM>select * from demo.t_test1 where owner='DEMO' and object_name like 'T_TEST%';   
  2.   
  3. OWNER                          OBJECT_NAME                    SUBOBJECT_NAME                  OBJECT_ID DATA_OBJECT_ID OBJECT_TYPE         CREATED   
  4.        LAST_DDL_TIME       TIMESTAMP           STATUS  T G S   
  5. ------------------------------ ------------------------------ ------------------------------ ---------- -------------- ------------------- -----------   
  6. -------- ------------------- ------------------- ------- - - -   
  7. DEMO                           T_TEST1                        AAA                                 97819          97819 TABLE               2007-06-07   
  8. 13:48:08 2007-06-07 13:48:08 2007-06-07:13:48:08 VALID   N N N  

    Note: to avoid the recursive calls, you'd better execute the SQL before tracing.

    From the log window, we can get the fetch calls be traced.

SQL代码
  1. [2010-5-28 6:28:29.649]User call: _qertbFetchByRowID (TID: 11076)    
  2. [2010-5-28 6:28:29.711]User call: _qerixtFetch (TID: 11076)    
  3. [2010-5-28 6:28:29.727]User call: _qertbFetchByRowID (TID: 11076)    
  4. [2010-5-28 6:28:29.727]User call: _qerixtFetch (TID: 11076)   

    You may try to map the calls to the execution plan:

SQL代码
  1. HELLODBA.COM>select * from demo.t_test1 where owner='DEMO' and object_name like 'T_TEST%';   
  2.   
  3. Execution Plan   
  4. ----------------------------------------------------------   
  5. Plan hash value: 698582444   
  6.   
  7. -------------------------------------------------------------------------------------------   
  8. | Id  | Operation                   | Name        | Rows  | Bytes | Cost (%CPU)| Time     |   
  9. -------------------------------------------------------------------------------------------   
  10. |   0 | SELECT STATEMENT            |             |     5 |   495 |     4   (0)| 00:00:04 |   
  11. |   1 |  TABLE ACCESS BY INDEX ROWID| T_TEST1     |     5 |   495 |     4   (0)| 00:00:04 | ==> _qertbFetchByRowID   
  12. |*  2 |   INDEX RANGE SCAN          | T_TEST_IDX7 |     5 |       |     1   (0)| 00:00:02 | ==> _qerixtFetch   
  13. -------------------------------------------------------------------------------------------  

    Example 3:
    Reading call stacks when specified call be traced.

    我们这里追踪"_kkeAdjSingTabCard"。设置追踪点:

SQL代码
  1. _kkeAdjSingTabCard*-1 6   

    The "*<num>" following the call name is the stack count you want to print, -1 mean no limit.

    Then, get SPID of the session you want to trace.

SQL代码
  1. HELLODBA.COM>select distinct spid from v$mystat m, v$session s, v$process p where s.sid=m.sid and s.paddr=p.addr;   
  2.   
  3. SPID   
  4. ------------   
  5. 11076  

    Select ORACLE.EXE from the processes list => select the TID number 11076 from the threads list => Click "Trace" button.

    And let's explain plan a SQL in the session we're tracing.

SQL代码
  1. HELLODBA.COM>explain plan for select /*+full(t)*/ count(*) from demo.t_test2 t;   
  2.   
  3. Explained.  

    We can get the call stacks from the log window.

SQL代码
  1. [2010-5-28 6:51:55.591]User call: _kkeAdjSingTabCard (TID: 11076)    
  2.     Call Stacks(-1):   
  3.         0x1460029 (ORACLE.EXE!_kkoitbp+757)   
  4.         0x144c44d (ORACLE.EXE!_kkoijbad+8869)   
  5.         0x1445d8b (ORACLE.EXE!_kkoCopyPreds+851)   
  6.         0x143ee0a (ORACLE.EXE!_kkosta+1694)   
  7.         0x1d17f6c (ORACLE.EXE!__PGOSF443__apaRequestBindCapture+156)   
  8.         0x1d18398 (ORACLE.EXE!_apagcp+388)   
  9.         0x1d1683c (ORACLE.EXE!_apafbr+464)   
  10.         0xea6682 (ORACLE.EXE!_opitcaNcp+1450)   
  11.         0x5b4eb0 (ORACLE.EXE!_kksMinimalTypeCheck+20)   
  12.         0x84d939 (ORACLE.EXE!_rpidrus+429)   
  13.         0x5b8ce8 (ORACLE.EXE!_kksSetNLSHandle+5888)   
  14.         0x87732e (ORACLE.EXE!_kxsReleaseRuntimeLock+1366)   
  15.         0x831815 (ORACLE.EXE!_kkscbt+7237)   
  16.         0x82e3cf (ORACLE.EXE!_kksParseCursor+2099)   
  17.         0x82f1b8 (ORACLE.EXE!_kksxsccompat+148)   
  18.         0x201683e (ORACLE.EXE!_opibrp+1970)   
  19.         0x13cd5ed (ORACLE.EXE!_kpodrd+237)   
  20.         0x13cba7c (ORACLE.EXE!_kpocrs+780)   
  21.         0x85174e (ORACLE.EXE!_opirip+1102)   
  22.         0x60feff90 (oracommon10.dll!_ttcpro+1276)   
  23.         0x850a69 (ORACLE.EXE!_opiodr+1017)   
  24.         0x1221350 (ORACLE.EXE!_opiino3+1092)   
  25.         0x85174e (ORACLE.EXE!_opirip+1102)   
  26.         0x420e58 (ORACLE.EXE!_opidcl+824)   
  27.         0x42164a (ORACLE.EXE!_ksdwri+50)   
  28.         0x401171 (ORACLE.EXE!_ssthrnfy+117)   
  29.         0x401061 (ORACLE.EXE!_opimai_init+97)   
  30.         0x401905 (ORACLE.EXE!_osnsoiint+713)   
  31.         0x7c80b729 (KERNEL32.dll!GetModuleFileNameA+442)   
  32.     [Args(6)]:    
  33.         0x81e58d0   
  34.         0x81e5da8   
  35.         0   
  36.         0x40a03000   
  37.         0x8559500   
  38.         0  

    Download the last version of OraTracer at here:
    http://www.HelloDBA.com/Download/OraTracer.zip

    Enjoy!

--- Fuyuncat ---

Top

Copyright ©2005, HelloDBA.Com All reseverd.

Declaration
by fuyuncat