每次数据库出现问题,都是恨不得跑到数据库里面去看。sql_trace就可以帮助你实现这个目的!
SQL> show parameter user_dump_dest
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
user_dump_dest string /u01/app/oracle/admin/orcl/udump
SQL> alter session set tracefile_identifier = 'mytest';
会话已更改。
SQL> alter session set sql_trace = true;
会话已更改。
SQL> select * from dual;
D
-
X
SQL> alter session set sql_trace = false;
会话已更改。
SQL> select spid from v$process where addr = (select paddr from v$session where sid = (select sid from v$mystat where rownum = 1));
SPID
------------
2608
然后到user_dump_dest目录就可以看见一个名字为“mytest”的trace文件。如果不定义trace文件的名字,还可以根据OS的pid来找到相应的trace文件。
[oracle@linux udump]$ pwd
/u01/app/oracle/admin/orcl/udump
[oracle@linux udump]$ ll | grep mytest
-rw-r----- 1 oracle oinstall 1616 10-29 11:00 orcl_ora_2608_mytest.trc
可以看一下trace文件的内容,一般是读不懂的:
[oracle@linux udump]$ cat orcl_ora_2608_mytest.trc
/u01/app/oracle/admin/orcl/udump/orcl_ora_2608_mytest.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /u01/app/oracle/product/10.2.0/db_1
System name: Linux
Node name: linux
Release: 2.6.18-164.el5
Version: #1 SMP Tue Aug 18 15:51:54 EDT 2009
Machine: i686
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 15
Unix process pid: 2608, image: oracle@linux (TNS V1-V3)
*** 2011-10-29 11:00:09.654
*** ACTION NAME:() 2011-10-29 11:00:09.654
*** MODULE NAME:(SQL*Plus) 2011-10-29 11:00:09.654
*** SERVICE NAME:(SYS$USERS) 2011-10-29 11:00:09.654
*** SESSION ID:(159.7) 2011-10-29 11:00:09.654
=====================
PARSING IN CURSOR #2 len=18 dep=0 uid=65 oct=3 lid=65 tim=1288923056302783 hv=942515969 ad='2993c0f8'
select * from dual
END OF STMT
PARSE #2:c=1000,e=1094,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=1288923056302774
EXEC #2:c=0,e=36,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1288923056303093
FETCH #2:c=2000,e=44416,p=2,cr=3,cu=0,mis=0,r=1,dep=0,og=1,tim=1288923056347551
FETCH #2:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=1288923056348541
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=258 op='TABLE ACCESS FULL DUAL (cr=3 pr=2 pw=0 time=44252 us)'
=====================
PARSING IN CURSOR #3 len=35 dep=0 uid=65 oct=42 lid=65 tim=1288923063019272 hv=310044142 ad='0'
alter session set sql_trace = false
END OF STMT
PARSE #3:c=1000,e=627,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=1288923063019266
EXEC #3:c=0,e=16,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=1288923063019346
但是oracle提供了一个工具tkprof来格式化trace文件的显示:
[oracle@linux udump]$ tkprof orcl_ora_2608_mytest.trc metest explain=u1/u1 sys=no
TKPROF: Release 10.2.0.4.0 - Production on 星期六 10月 29 11:21:16 2011
Copyright (c) 1982, 2007, Oracle. All rights reserved.
[oracle@linux udump]$ cat metest.prf
TKPROF: Release 10.2.0.4.0 - Production on 星期六 10月 29 11:21:16 2011
Copyright (c) 1982, 2007, Oracle. All rights reserved.
Trace file: orcl_ora_2608_mytest.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
********************************************************************************
select *
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 0 0
Fetch 2 0.00 0.04 2 3 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.00 0.04 2 3 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 65 (U1)
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS FULL DUAL (cr=3 pr=2 pw=0 time=44252 us)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT MODE: ALL_ROWS
1 TABLE ACCESS MODE: ANALYZED (FULL) OF 'DUAL' (TABLE)
********************************************************************************
alter session set sql_trace = false
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 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
Parsing user id: 65 (U1)
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.04 2 3 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 0.00 0.04 2 3 0 1
Misses in library cache during parse: 1
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 0 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 0 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
2 user SQL statements in session.
0 internal SQL statements in session.
2 SQL statements in session.
1 statement EXPLAINed in this session.
********************************************************************************
Trace file: orcl_ora_2608_mytest.trc
Trace file compatibility: 10.01.00
Sort options: default
1 session in tracefile.
2 user SQL statements in trace file.
0 internal SQL statements in trace file.
2 SQL statements in trace file.
2 unique SQL statements in trace file.
1 SQL statements EXPLAINed using schema:
U1.prof$plan_table
Default table was used.
Table was created.
Table was dropped.
34 lines in trace file.
6 elapsed seconds in trace file.
说明:
explain=username/password会在trace文件中添加sql的执行计划
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT MODE: ALL_ROWS
1 TABLE ACCESS MODE: ANALYZED (FULL) OF 'DUAL' (TABLE)
explain=user/password 使用给定的连接参数连接到数据库,并为每条语句执行一次explain plan。
aggregate=yes|no 默认情况下,tkprof工具将所有相同的sql在输入文件中做合并,如果设置为no则分别列出每个sql的信息。
sys=no 在执行客户端sql的过程中,可能会引发执行一些sys用户的递归sql。sys=no就不是显示这些sql,这样查看trace文件更清晰。默认是sys=yes。
waits=yes/no 为所有sql语句提供一份等待信息的小结。
sort='(prsela,fchela,exeela)' 按照总体的物理磁盘读来展示SQL语句。