oracle 追踪特定sql语句

–新建测试表
create tablespace test
datafile ‘E:\APP\ADMINISTRATOR\ORADATA\ORCL\test01.DBF’
size 500m
autoextend on
next 100m maxsize unlimited
extent management local autoallocate
segment   space management auto;

 

create table t1
(
sid int not null primary key,
sname varchar2(10)
)
tablespace test;

 

 

–循环导入数据
declare
maxrecords constant int:=100000;
i int :=1;
begin
for i in 1..maxrecords loop
insert into t1 values(i,’ocpyang’);
end loop;
dbms_output.put_line(‘ 成功录入数据! ‘);
commit;
end;
/

 

create table t2
as
select * from t1 where rownum<=5000;

 

 

 
oracle 11.1中可以使用增强的SQL跟踪来追逐一条或多条SQL语句.
——————————————————————————————-
案例1:跟踪一组SQL
——————————————————————————————-

–步骤0)初始化参数
—开启timed_statistics 参数

show parameters statistics;

NAME                                 TYPE        VALUE
———————————— ———– ——————————
optimizer_use_pending_statistics     boolean     FALSE
statistics_level                     string      TYPICAL
timed_os_statistics                  integer     0
timed_statistics                     boolean     TRUE  –需要设置为true

—查看所有trace文件路径

select name,value from v$diag_info where name=’Diag Trace’;

E:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl\trace

 
–步骤1).设置追踪标示
alter session set tracefile_identifier=’ocpyang01′;
–步骤2).设置追踪

alter session set events ‘sql_trace level 12’;
–步骤3).执行sql
select count(*) from t1;

select count(*) from t2;

select * from t1 where rownum<=10;

–步骤4).关闭追踪
alter session set events ‘sql_trace off’;
–步骤5)获得跟踪文件名

—方法1:

SELECT    d.VALUE
|| ‘\’
|| LOWER (RTRIM (i.INSTANCE, CHR (0)))
|| ‘_ora_’
|| p.spid
|| ‘.trc’ trace_file_name
FROM (SELECT p.spid
FROM v$mystat m, v$session s, v$process p
WHERE m.statistic# = 1 AND s.SID = m.SID AND p.addr = s.paddr) p,
(SELECT t.INSTANCE
FROM v$thread t, v$parameter v
WHERE v.NAME = ‘thread’
AND (v.VALUE = 0 OR t.thread# = TO_NUMBER (v.VALUE))) i,
(SELECT VALUE
FROM v$parameter
WHERE NAME = ‘user_dump_dest’) d
/
—方法2:
select value from v$diag_info
where name=’Default Trace File’;

 
E:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl\trace\orcl_ora_1328024_ocpyang01.trc
–步骤6)分析跟踪文件
—-方法1:tkprof
tkprof E:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl\trace\orcl_ora_1328024_ocpyang01.trc e:\ocpyang.out sys=yes

 

*******************************************************************************
结果如下:

*******************************************************************************
TKPROF: Release 11.2.0.3.0 – Development on 星期五 4月 26 15:46:50 2013

Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.

Trace file: E:\APP\ADMINISTRATOR\diag\rdbms\orcl\orcl\trace\orcl_ora_1328024_ocpyang01.trc
Sort options: default

********************************************************************************
count    = number of times OCI procedure was executed
cpu      = cpu time in seconds executing
elapsed  = elapsed time in seconds executing
disk     = number of physical reads of buffers from disk
query    = number of buffers gotten for consistent read
current  = number of buffers gotten in current mode (usually for update)
rows     = number of rows processed by the fetch or execute call
********************************************************************************

SQL ID: 5bc0v4my7dvr5 Plan Hash: 3724264953

select count(*)
from
t1
call     count       cpu    elapsed       disk      query    current        rows
——- ——  ——– ———- ———- ———- ———-  ———-
Parse        1      0.01       0.00          0         64          1           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.00          0        289          1           1
——- ——  ——– ———- ———- ———- ———-  ———-
total        4      0.01       0.01          0        353          2           1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
———- ———- ———-  —————————————————
1          1          1  SORT AGGREGATE (cr=289 pr=0 pw=0 time=9600 us)
100000     100000     100000   TABLE ACCESS FULL T1 (cr=289 pr=0 pw=0 time=21518 us cost=2 size=0 card=82)
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        0.00          0.00
********************************************************************************

SQL ID: 4a68b8mrkawav Plan Hash: 3321871023

SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS IGNORE_WHERE_CLAUSE
NO_PARALLEL(SAMPLESUB) opt_param(‘parallel_execution_enabled’, ‘false’)
NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),0), NVL(SUM(C2),0)
FROM
(SELECT /*+ NO_PARALLEL(“T2”) FULL(“T2”) NO_PARALLEL_INDEX(“T2”) */ 1 AS C1,
1 AS C2 FROM “SYS”.”T2″ “T2”) SAMPLESUB
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.00       0.00          0         15          0           1
——- ——  ——– ———- ———- ———- ———-  ———-
total        3      0.00       0.00          0         15          0           1

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: SYS   (recursive depth: 1)
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
———- ———- ———-  —————————————————
1          1          1  SORT AGGREGATE (cr=15 pr=0 pw=0 time=633 us)
5000       5000       5000   TABLE ACCESS FULL T2 (cr=15 pr=0 pw=0 time=906 us cost=5 size=0 card=981)

********************************************************************************

SQL ID: 94dwfa8yd87kw Plan Hash: 3321871023

select count(*)
from
t2
call     count       cpu    elapsed       disk      query    current        rows
——- ——  ——– ———- ———- ———- ———-  ———-
Parse        1      0.00       0.00          0         16          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.00          0         15          0           1
——- ——  ——– ———- ———- ———- ———-  ———-
total        4      0.00       0.00          0         31          0           1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
———- ———- ———-  —————————————————
1          1          1  SORT AGGREGATE (cr=15 pr=0 pw=0 time=400 us)
5000       5000       5000   TABLE ACCESS FULL T2 (cr=15 pr=0 pw=0 time=777 us cost=5 size=0 card=5000)
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        0.96          0.96
********************************************************************************

SQL ID: 2uzqkdqdtkn8p Plan Hash: 1267113925

SELECT signature
FROM
sqllog$ WHERE signature = :1
call     count       cpu    elapsed       disk      query    current        rows
——- ——  ——– ———- ———- ———- ———-  ———-
Parse        3      0.00       0.00          0          0          0           0
Execute      3      0.00       0.00          0          0          0           0
Fetch        3      0.00       0.00          0          6          0           2
——- ——  ——– ———- ———- ———- ———-  ———-
total        9      0.00       0.00          0          6          0           2

Misses in library cache during parse: 0
Optimizer mode: CHOOSE
Parsing user id: SYS   (recursive depth: 1)
Number of plan statistics captured: 2

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
———- ———- ———-  —————————————————
0          1          1  INDEX UNIQUE SCAN SQLLOG$_PKEY (cr=2 pr=0 pw=0 time=22 us cost=1 size=12 card=1)(object id 188)

********************************************************************************

SQL ID: 01zk56t60wvf1 Plan Hash: 1877030569

INSERT INTO sqllog$ SELECT :1, 1+TRUNC(sqllog$_seq.nextval/8192) FROM dual
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          4           1
Fetch        0      0.00       0.00          0          0          0           0
——- ——  ——– ———- ———- ———- ———-  ———-
total        2      0.00       0.00          0          0          4           1

Misses in library cache during parse: 0
Optimizer mode: CHOOSE
Parsing user id: SYS   (recursive depth: 1)
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
———- ———- ———-  —————————————————
0          0          0  LOAD TABLE CONVENTIONAL  (cr=0 pr=0 pw=0 time=185 us)
1          1          1   SEQUENCE  SQLLOG$_SEQ (cr=0 pr=0 pw=0 time=32 us)
1          1          1    FAST DUAL  (cr=0 pr=0 pw=0 time=1 us cost=2 size=0 card=1)

********************************************************************************

SQL ID: 0h4nqj1xgy15r Plan Hash: 3836375644

select *
from
t1 where rownum<=10
call     count       cpu    elapsed       disk      query    current        rows
——- ——  ——– ———- ———- ———- ———-  ———-
Parse        1      0.00       0.00          0          4          1           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.00          0          5          0          10
——- ——  ——– ———- ———- ———- ———-  ———-
total        4      0.00       0.00          0          9          1          10

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
———- ———- ———-  —————————————————
10         10         10  COUNT STOPKEY (cr=5 pr=0 pw=0 time=41 us)
10         10         10   TABLE ACCESS FULL T1 (cr=5 pr=0 pw=0 time=35 us cost=2 size=2081280 card=104064)
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
log file sync                                   1        0.00          0.00
SQL*Net message from client                     2        8.73          8.73
********************************************************************************
—-方法2:oracle追踪分析器即trcanlzr或trca
1)进入到指定路径

cd E:\trca\trca\run
2)登录sqlplus

sqlplus/ as sysdba  –注意:sqlplus 连接的是trace 生成的用户
3)开始分析追踪文件

start trcanlzr.sql orcl_ora_1328024_ocpyang01.trc

–注意:trace名称不包含路径,使用TRCA$INPUT1的目录
4)进入到指定路径分析结果的文件保存路径:

E:\trca\trca\run下

标签