racle Trace 10046简单范例

1. 环境: oracle 10.2.0.4

2. 测试场景: 通过weblogic提供的数据源连接数据库

   1)weblogic中建立数据源时，初始设定一个连接，以方便确认执行过程中，所产生的trace文件。

   2)确认trace文件生成的路径:

SQL> show parameter user_dump_dest

NAME                                 TYPE        VALUE

------------------------------------ ----------- ------------------------------

user_dump_dest                       string      /oracle/admin/jf/udump

SQL> show parameter background_dump_dest

NAME                                 TYPE        VALUE

------------------------------------ ----------- ------------------------------

background_dump_dest                 string      /oracle/admin/jf/bdump

3)确认用户id

Toad中执行:

SELECT SID, SERIAL#, USER#, USERNAME, STATUS

  FROM V$SESSION T

 WHERE  MACHINE LIKE '本机机器名%';

目前：本机连接数据库有toad连接和Weblogic建立的数据源连接,故返回两条记录，其中Weblogic建立的数据源连接显示status为INACTIVE。

记录该笔资料的SID和SERIAL#值

4)使用sys用户开启Trace

execdbms_monitor.session_trace_enable(93,18096,true,true);;【sid:93;serial: 18096】

PL/SQL procedure successfully completed.

5)进入trace文件的存放路径，此时并未发现今日生成的.trc文件

ls –lrt *

         6)当通过应用程序发生了数据库操作后，查看/oracle/admin/jf/udump目录下生成了jf_ora_8182.trc文件【通过文件生成的时间判断】

         7)通过tkprof命令转化trace文件为txt格式

[200.14]/oracle/admin/jf/udump>tkprof jf_ora_8182.trc/home/bea/app/lihailong/8023_new_03.txt explain=userName/pwdaggregate=no sys=no waits=no;

         8)关闭trace跟踪

SQL> exec dbms_monitor.session_trace_disable(93,18096);

         9)应用程序再发生了数据库操作后，jf_ora_8182.trc文件将不再发生变化。

    10)生成8023_new_03.txt的部分内容:

SELECT BYDATE,OPERATE_ID,SUM(OPERATE_POINT) OPERATE_POINT

FROM

 (SELECT  SUBSTR(A.CREATE_TIME,0,6) BYDATE,A.OPERATE_ID OPERATE_ID,

  TO_NUMBER(A.OPERATE_POINT) OPERATE_POINT FROM BE_POINT_DETAIL A ,be_purse B

  WHERE A.PURSE_ID=B.PURSE_ID AND   ( a.customer_id = :1 or a.customer_id =

  :2 )AND A.CREATE_TIME >= :3 AND B.PURSE_TYPE_ID != '3' AND

  B.PURSE_PROCESS_TYPE = '1' ) GROUP BY BYDATE,OPERATE_ID ORDER BY BYDATE

  DESC

 

 

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.00          0          0          0           0

Execute      1      0.00       0.00          0          0          0           0

Fetch        4      0.01       0.00          0        546          0          30

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        6      0.01       0.01          0        546          0          30

 

Misses in library cache during parse: 1

Misses in library cache during execute: 1

Optimizer mode: ALL_ROWS

Parsing user id: 31  (JF_ISU)

 

Rows     Execution Plan

-------  ---------------------------------------------------

      0  SELECT STATEMENT   MODE: ALL_ROWS

      0   SORT (GROUP BY)

      0    NESTED LOOPS

      0     INLIST ITERATOR

      0      TABLE ACCESS   MODE: ANALYZED (BY INDEX ROWID) OF

                 'BE_POINT_DETAIL' (TABLE)

      0       INDEX   MODE: ANALYZED (RANGE SCAN) OF

                  'IDX_BE_POINT_DETAIL' (INDEX)

      0     TABLE ACCESS   MODE: ANALYZED (BY INDEX ROWID) OF 'BE_PURSE'

                (TABLE)

      0      INDEX   MODE: ANALYZED (UNIQUE SCAN) OF 'PK_BE_PURSE'

                 (INDEX (UNIQUE))

 

 

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total Waited

  ----------------------------------------   Waited  ----------  ------------

  SQL*Net message to client                       5        0.00          0.00

  SQL*Net message from client                     5        0.01          0.04

3.测试场景: 开发过程中，通过Toad工具连接数据库后，测试某SQL语句的执行情况

   1) 在toad的SQL窗口中，执行如下语句:

    开启Trace跟踪： ALTER SESSION SET EVENTS '10046 trace name context forever, level 12';

    关闭Trace 跟踪：ALTER SESSION SET EVENTS '10046 trace name context off';

   2) 开启Trace后，在/oracle/admin/jf/udump目录下存在jf_ora_13297.trc文件

   3) 通过toad执行【同场景1中step10的SQL】

SELECT   bydate, operate_id, SUM (operate_point) operate_point

    FROM (SELECT SUBSTR (a.create_time, 0, 6) bydate, a.operate_id operate_id,

                 TO_NUMBER (a.operate_point) operate_point

            FROM be_point_detail a, be_purse b

           WHERE a.purse_id = b.purse_id

             AND (a.customer_id = :1 OR a.customer_id = :2)

             AND a.create_time >= :3

             AND b.purse_type_id != '3'

             AND b.purse_process_type = '1')

GROUP BY bydate, operate_id

ORDER BY bydate DESC

  4) 多次执行SQL后，通过tkprof产生如下内容：

 

SELECT   bydate, operate_id, SUM (operate_point) operate_point

    FROM (SELECT SUBSTR (a.create_time, 0, 6) bydate, a.operate_id operate_id,

                 TO_NUMBER (a.operate_point) operate_point

            FROM be_point_detail a, be_purse b

           WHERE a.purse_id = b.purse_id

             AND (a.customer_id = :1 OR a.customer_id = :2)

             AND a.create_time >= :3

             AND b.purse_type_id != '3'

             AND b.purse_process_type = '1')

GROUP BY bydate, operate_id

ORDER BY bydate DESC

 

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.00          0          0          0           0

Execute      1      0.00       0.00          0          0          0           0

Fetch        1      0.61      72.67       6742      12092          0           8

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        3      0.61      72.67       6742      12092          0           8

 

Misses in library cache during parse: 0

Optimizer mode: ALL_ROWS

Parsing user id: 31 

 

Rows     Row Source Operation

-------  ---------------------------------------------------

      8  SORT GROUP BY (cr=12092 pr=6742 pw=0 time=72671905 us)

   7989   HASH JOIN  (cr=12092 pr=6742 pw=0 time=14807759 us)

     85    TABLE ACCESS FULL BE_PURSE (cr=7 pr=0 pw=0 time=180 us)

   7989    INLIST ITERATOR  (cr=12085 pr=6742 pw=0 time=14790792 us)

   7989     TABLE ACCESS BY INDEX ROWID BE_POINT_DETAIL (cr=12085 pr=6742 pw=0 time=14789762 us)

  42231      INDEX RANGE SCAN IDX_BE_POINT_DETAIL (cr=269 pr=152 pw=0 time=49272 us)(object id 26977)

 

 

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total Waited

  ----------------------------------------   Waited  ----------  ------------

  SQL*Net message to client                       2        0.00          0.00

  SQL*Net message from client                     2       17.44         17.44

  db file sequential read                      6742        0.12         72.20

        

 

SELECT   bydate, operate_id, SUM (operate_point) operate_point

    FROM (SELECT SUBSTR (a.create_time, 0, 6) bydate, a.operate_id operate_id,

                 TO_NUMBER (a.operate_point) operate_point

            FROM be_point_detail a, be_purse b

           WHERE a.purse_id = b.purse_id

             AND (a.customer_id = :1 OR a.customer_id = :2)

             AND a.create_time >= :3

             AND b.purse_type_id != '3'

             AND b.purse_process_type = '1')

GROUP BY bydate, operate_id

ORDER BY bydate DESC

 

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.00          0          0          0           0

Execute      1      0.00       0.00          0          0          0           0

Fetch        1      0.15       0.15          0      12092          0           8

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        3      0.15       0.15          0      12092          0           8

 

Misses in library cache during parse: 0

Optimizer mode: ALL_ROWS

Parsing user id: 31 

 

Rows     Row Source Operation

-------  ---------------------------------------------------

      8  SORT GROUP BY (cr=12092 pr=0 pw=0 time=151202 us)

   7989   HASH JOIN  (cr=12092 pr=0 pw=0 time=86769 us)

     85    TABLE ACCESS FULL BE_PURSE (cr=7 pr=0 pw=0 time=187 us)

   7989    INLIST ITERATOR  (cr=12085 pr=0 pw=0 time=69778 us)

   7989     TABLE ACCESS BY INDEX ROWID BE_POINT_DETAIL (cr=12085 pr=0 pw=0 time=69809 us)

  42231      INDEX RANGE SCAN IDX_BE_POINT_DETAIL (cr=269 pr=0 pw=0 time=104 us)(object id 26977)

 

 

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total Waited

  ----------------------------------------   Waited  ----------  ------------

  SQL*Net message to client                       2        0.00          0.00

  SQL*Net message from client                     2        2.31          2.31