使用TKPROF格式化TRACE输出之解剖麻雀.docx

资源描述

使用TKPROF格式化TRACE输出之解剖麻雀.docx

《使用TKPROF格式化TRACE输出之解剖麻雀.docx》由会员分享，可在线阅读，更多相关《使用TKPROF格式化TRACE输出之解剖麻雀.docx（6页珍藏版）》请在冰豆网上搜索。

使用TKPROF格式化TRACE输出之解剖麻雀.docx

使用TKPROF格式化TRACE输出之解剖麻雀

【TKPROF】使用TKPROF格式化TRACE输出之“解剖麻雀”2009-10-2111:

26:

《【SQL_TRACE】SQL优化及性能诊断好帮手》

1.与之上次使用到的SQL_TRACE功能相比，我们这次将使用更高级的trace命令（10046）来做演示。

我们先启用“高级”的10046事件生成一份待格式化的trace文件

1）连接到普通用户sec

sys@ora10g>connsec/sec

Connected.

2）先将timed_statistics参数设置为true，这样可以使TKPROF工具能提供更多的有意义的信息，方便性能诊断

sec@ora10g>altersessionsettimed_statistics=true;

Sessionaltered.

3）“高级”之所在，我们这里启用10046的level12对当前会话进行跟踪。

（1）在此，给出10046各level的解释参考：

level1toenablethestandardSQL_TRACEfacility（sameasSQL_TRACE=TRUE）

等同于标准的SQL_TRACE=TRUE；

level4toenableSQL_TRACEandalsocapturebindvariablevaluesinthetracefile

启用SQL_TRACE，并捕捉跟踪文件中的绑定变量；

level8toenableSQL_TRACEandalsocapturewaiteventsintothetracefile

启用SQL_TRACE，并捕捉跟踪文件中的等待事件；

level12toenablestandardSQL_TRACEandalsocapturebindvariablesandwaitevents

启用SQL_TRACE，并捕捉跟踪文件中的绑定变量和等待事件（捕获信息能力最强）。

（2）对当前会话启用level12的跟踪：

sec@ora10g>altersessionsetevents'10046tracenamecontextforever,level12';

Sessionaltered.

（3）【补充】如果想使用这种高级方法对其他的会话进行跟踪的话，可以使用如下的SQL语句开启和关闭：

开启：

executedbms_system.set_ev（sid,serial#,10046,12,''）;

关闭：

executedbms_system.set_ev（sid,serial#,10046,0,''）;

举例如下：

A.获得sid,serial#的信息

sys@ora10g>selectsid,serial#fromv$session;

B.开启

sys@ora10g>executedbms_system.set_ev（543,1306,10046,12,''）;

C.关闭

sys@ora10g>executedbms_system.set_ev（543,1306,10046,0,''）;

4）在该会话中运行一条具体的SQL语句，此处使用到的实验表t中包含1亿条数据。

该SQL语句的执行情况将被细致的记录到trace文件中。

sec@ora10g>selectcount（*）fromt;

COUNT（*）

----------

100000000

5）关闭当前会话的跟踪

sec@ora10g>altersessionsetevents'10046tracenamecontextoff';

Sessionaltered.

2.在udump目录中找到刚刚生成的trace文件（关于如何快速获得生成的trace文件的方法有很多种，选择一个适合自己的就OK），并使用TKPROF对其进行格式化，然后打印一下全部输出，后面将对每一个输出项做一下“解剖麻雀”:

）

ora10g@secDB/oracle/app/oracle/admin/ora10g/udump$tkprofora10g_ora_21213.trcora10g_ora_21213.prf

TKPROF:

Release10.2.0.3.0-ProductiononWedOct2110:

04:

402009

ora10g@secDB/oracle/app/oracle/admin/ora10g/udump$catora10g_ora_21213.prf

TKPROF:

Release10.2.0.3.0-ProductiononWedOct2110:

05:

432009

Tracefile:

ora10g_ora_21213.trc

Sortoptions:

default

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

count =numberoftimesOCIprocedurewasexecuted

cpu =cputimeinsecondsexecuting

elapsed =elapsedtimeinsecondsexecuting

disk =numberofphysicalreadsofbuffersfromdisk

query =numberofbuffersgottenforconsistentread

current =numberofbuffersgottenincurrentmode（usuallyforupdate）

rows =numberofrowsprocessedbythefetchorexecutecall

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

BEGINDBMS_OUTPUT.GET_LINES（:

LINES,:

NUMLINES）;END;

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 2

Fetch 0 0.00 0.00 0 0 0 0

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

total 4 0.00 0.00 0 0 0 2

Missesinlibrarycacheduringparse:

Optimizermode:

ALL_ROWS

Parsinguserid:

Elapsedtimesincludewaitingonfollowingevents:

Eventwaitedon Times Max.Wait TotalWaited

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

SQL*Netmessagetoclient 2 0.00 0.00

SQL*Netmessagefromclient 2 5.60 7.74

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

selectcount（*）

from

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 10.94 10.68 222186 222957 0 1

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

total 4 10.94 10.68 222186 222957 0 1

Missesinlibrarycacheduringparse:

Optimizermode:

ALL_ROWS

Parsinguserid:

Rows RowSourceOperation

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

1 SO

展开阅读全文