Chinaunix首页 | 论坛 | 博客
  • 博客访问: 151291
  • 博文数量: 56
  • 博客积分: 1435
  • 博客等级: 上尉
  • 技术积分: 640
  • 用 户 组: 普通用户
  • 注册时间: 2008-11-26 09:58
文章分类

全部博文(56)

文章存档

2009年(52)

2008年(4)

我的朋友

分类: Oracle

2009-04-03 16:05:30


Tkprof是一个用于分析Oracle跟踪文件并且产生一个更加清晰合理的输出结果的可执行工具。如果一个系统的执行效率比较低,一个比较好的方法是通过跟踪用户的会话并且使用Tkprof工具使用排序功能格式化输出,从而找出有问题的SQL语句。

Tkprof命令后面可以带各种类型的排序选项,具体如下:

Usage: tkprof tracefile outputfile [explain= ] [table= ]

[print= ] [insert= ] [sys= ] [sort= ]

table=schema.tablename Use 'schema.tablename' with 'explain='

option.

explain=user/password Connect to ORACLE and issue EXPLAIN PLAN.

print=integer List only the first 'integer' SQL statements.

aggregate=yes|no

insert=filename List SQL statements and data inside INSERT

statements.

sys=no TKPROF does not list SQL statements run as user SYS.

record=filename Record non-recursive statements found in the

trace file.

waits=yes|no Record summary for any wait events found in the

trace file.

sort=option Set of zero or more of the following sort options:

prscnt number of times parse was called

prscpu cpu time parsing

prsela elapsed time parsing

prsdsk number of disk reads during parse

prsqry number of buffers for consistent read during parse

prscu number of buffers for current read during parse

prsmis number of misses in library cache during parse

execnt number of execute was called

execpu cpu time spent executing

exeela elapsed time executing

exedsk number of disk reads during execute

exeqry number of buffers for consistent read during execute

execu number of buffers for current read during execute

exerow number of rows processed during execute

exemis number of library cache misses during execute

fchcnt number of times fetch was called

fchcpu cpu time spent fetching

fchela elapsed time fetching

fchdsk number of disk reads during fetch

fchqry number of buffers for consistent read during fetch

fchcu number of buffers for current read during fetch

fchrow number of rows fetched

userid userid of user that parsed the cursor

其中比较有用的一个排序选项是fchela,即按照elapsed time fetching来对分析的结果排序(记住要设置初始化参数time_statistics=true),生成的.prf文件将把最消耗时间的sql放在最前面显示。另外一个有用的参数就是sys, 这个参数设置为no可以阻止所有以sys用户执行的sql被显示出来,这样可以减少分析出来的文件的复杂度,便于查看。

Tkprof命令输出的解释:

首先解释输出文件中列的含义:

Ø CALL:每次SQL语句的处理都分成三个部分

Parse:这步将SQL语句转换成执行计划,包括检查是否有正确的授权和所需要用到的表、列以及其他引用到的对象是否存在。

Execute:这步是真正的由Oracle来执行语句。对于insertupdatedelete操作,这步会修改数据,对于select操作,这步就只是确定选择的记录。

Fetch:返回查询语句中所获得的记录,这步只有select语句会被执行。

Ø COUNT:这个语句被parseexecutefetch的次数。

Ø CPU:这个语句对于所有的parseexecutefetch所消耗的cpu的时间,以秒为单位。

Ø ELAPSED:这个语句所有消耗在parseexecutefetch的总的时间。

Ø DISK:从磁盘上的数据文件中物理读取的块的数量。一般来说更想知道的是正在从缓存中读取的数据而不是从磁盘上读取的数据。

Ø QUERY:在一致性读模式下,所有parseexecutefetch所获得的buffer的数量。一致性模式的buffer是用于给一个长时间运行的事务提供一个一致性读的快照,缓存实际上在头部存储了状态。

Ø CURRENT:在current模式下所获得的buffer的数量。一般在current模式下执行insertupdatedelete操作都会获取buffer。在current模式下如果在高速缓存区发现有新的缓存足够给当前的事务使用,则这些buffer都会被读入了缓存区中。

Ø ROWS: 所有SQL语句返回的记录数目,但是不包括子查询中返回的记录数目。对于select语句,返回记录是在fetch这步,对于insertupdatedelete操作,返回记录则是在execute这步。

Tkprof的使用步骤基本上遵循以下几步:

1. 在数据库级别上设置TIMED_STATISTICSTrue

8i数据库需要修改init文件增加TIMED_STATISTICStrue,然后重启数据库使其生效。

9i数据库可以直接修改:

SQL> alter system set timed_statistics=false scope=both;

系统已更改。

2. 使用各种的工具得到你想要查看sessiontrace

Oracle中能够得到一个sessiontrace的方法很多,这里大致的都介绍一下。

方法一:如果需要在数据库级别上设置trace,可以在init.ora文件中加入sql_trace=true,这样在数据库运行的同时会trace所有数据库的活动,一般来说,只有在数据库的所有事务都需要被监控的时候才使用这种方法,使用这种方法会产生大量的trace文件,此参数是需要重启数据库才可以生效的。Trace信息收集完成后,记得去掉这个参数,然后重启数据库。

方法二:如果需要在session级别上设置trace,可以在sqlplus中使用下列语句:

SQL> alter session set sql_trace=true;

会话已更改。

如果要PL/SQL中对session级别上设置trace,可以使用dbms_session这个包:

SQL>exec dbms_system.set_sql_trace_in_session(sid

serial#,true);

PL/SQL 过程已成功完成。

3. 找到生成的正确的trace文件,在init.ora初始化参数文件中 user_dump_dest定义的路径下可以找到。

4. trace文件使用tkprof工具进行分析。

tkprof tracefile outfile [explain=user/password] [options...]

一般来说,使用tkprof得到的输出文件中包含三个部分:

Ø SQL语句本身。

Ø 相关的诊断信息,包括cpu时间、总共消耗的时间、读取磁盘数量、逻辑读的数量、以及查询中返回的记录数目。

Ø 列出这个语句的执行计划。

下面用一个具体的例子来说明如何利用tkprof来分析trace文件。

先从os上利用top命令找到当前占用cpu资源最高的一个进程的PID号:14483

load averages: 1.53, 1.37, 1.39 db2 23:11:15

246 processes: 236 sleeping, 1 running, 2 zombie, 4 stopped, 3 on cpu

CPU states: 68.0% idle, 17.3% user, 3.0% kernel, 11.6% iowait, 0.0% swap

Memory: 16.0G real, 3.4G free, 9.7G swap in use, 11.0G swap free

PID USERNAME THR PR NCE SIZE RES STATE TIME FLTS CPU COMMAND

14483 oracle 1 51 0 8.8G 8.8G sleep 77.1H 1 5.69% oracle

28222 oracle 1 52 0 8.8G 8.8G cpu18 93:55 2742 3.32% oracle

3722 oracle 1 59 0 8.8G 8.8G sleep 157:41 0 0.45% oracle

16077 oracle 1 59 0 8.8G 8.8G sleep 17.1H 0 0.34% oracle

12687 oracle 1 59 0 8.8G 8.8G sleep 0:07 0 0.29% oracle

17781 oracle 1 49 0 8.8G 8.8G run 91:11 8 0.24% oracle

2359 oracle 1 59 0 8.8G 8.8G cpu19 524:53 0 0.12% oracle

6559 oracle 1 59 0 8.8G 8.8G sleep 237:41 0 0.10% oracle

2242 oracle 1 59 0 8.8G 8.8G sleep 980:56 0 0.09% oracle

2356 oracle 1 59 0 8.8G 8.8G sleep 121:31 0 0.08% oracle

16106 oracle 1 59 0 8.8G 8.8G sleep 168:44 0 0.05% oracle

11432 oracle 1 49 0 2576K 1680K cpu11 0:11 0 0.05% top

2333 oracle 1 59 0 8.9G 8.8G sleep 159:03 0 0.05% oracle

2321 oracle 1 59 0 8.8G 8.8G sleep 78:20 0 0.04% oracle

2282 oracle 1 59 0 8.8G 8.8G sleep 424:57 0 0.03% oracle

然后在数据库中根据PID号找到相应的sid号和serial#

SQL> select s.sid,s.serial# from v$session s,v$process p

2 where s.paddr=p.addr and p.spid='14483';

SID SERIAL#

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

101 25695

使用dbms_system.set_sql_trace_in_session包来对这个session进行trace

SQL> exec DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(101,25695,true);

PL/SQL procedure successfully completed.

user_dump_dest定义的路径下查找刚刚最近生成的trace文件,根据时间来排序,找最近的trace文件,接着使用tkprof工具对此trace文件进行格式化分析,生成分析后的trace文件。

$tkprof orcl_ora_14483.trc allan.txt explain=system/manager aggregate=yes sys=no waits=yes sort=fchela

TKPROF: Release 9.2.0.4.0 - Production on Sun Dec 5 22:27:28 2004

Copyright (c) 1982, 2002, Oracle Corporation. All rights reserved.

这里生成的allan.txt文件就是我们最终得到的格式化后的trace文件了,然后打开这个文件进行分析。

一、首先tkprof工具输出的最后总的统计:

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows

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

Parse 20 0.01 0.02 0 58 0 0

Execute 13197 0.81 0.90 17 7436 6316 1484

Fetch 12944 22.86 22.10 20 2205941 0 8972

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

total 26161 23.68 23.02 37 2213435 6316 10456<



需要调整的语句符合以下几点:

(1).CPU占用过多

(2).Parse,Execute,Fetch花费太多时间

(3).DISK读取太多,query/current(SGA)中数据块读取太少

(4).访问许多块,只返回

 
阅读(1946) | 评论(1) | 转发(0) |
0

上一篇:耐心完了总会爆发

下一篇:学习笔记

给主人留下些什么吧!~~

chinaunix网友2009-04-03 17:41:16

1)alter session set timed_statistics=true; /*适用于Oracle 8.1.7以后的版本*/   2)alter session set max_dump_file_size=unlimited ; /*适用于Oracle 9i以后的版本*/   3)alter session set tracefile_identifier='POX20031031a'; /*适用于Oracle 9i以后的版本*/   4)alter session set events '10046 trace name context forever, level 8';   /*在这里编写应用程序的代码*/   5)alter session set events '10046 trace name context off';