2)先将timed_statistics参数设置为true,这样可以使TKPROF工具能提供更多的有意义的信息,方便性能诊断 sec@ora10g> alter session set timed_statistics=true;
Session altered.
3)“高级”之所在,我们这里启用10046的level 12对当前会话进行跟踪。 (1)在此,给出10046各level的解释参考: level 1 to enable the standard SQL_TRACE facility (same as SQL_TRACE=TRUE) 等同于标准的SQL_TRACE=TRUE; level 4 to enable SQL_TRACE and also capture bind variable values in the trace file 启用SQL_TRACE,并捕捉跟踪文件中的绑定变量; level 8 to enable SQL_TRACE and also capture wait events into the trace file 启用SQL_TRACE,并捕捉跟踪文件中的等待事件; level 12 to enable standard SQL_TRACE and also capture bind variables and wait events 启用SQL_TRACE,并捕捉跟踪文件中的绑定变量和等待事件(捕获信息能力最强)。
(2)对当前会话启用level 12的跟踪: sec@ora10g> alter session set events '10046 trace name context forever, level 12';
******************************************************************************** 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 ********************************************************************************
BEGIN DBMS_OUTPUT.GET_LINES(:LINES, :NUMLINES); END;
Misses in library cache during parse: 0 Optimizer mode: ALL_ROWS Parsing user id: 51
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 5.60 7.74 ********************************************************************************
Misses in library cache during parse: 0 Optimizer mode: ALL_ROWS Parsing user id: 51
Rows Row Source Operation ------- --------------------------------------------------- 1 SORT AGGREGATE (cr=222957 pr=222186 pw=0 time=10686023 us) 100000000 INDEX FAST FULL SCAN PK_T (cr=222957 pr=222186 pw=0 time=100000562 us)(object id 45619)
Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 3 0.00 0.00 SQL*Net message from client 3 0.00 0.00 db file scattered read 14249 0.00 1.10 db file sequential read 59 0.00 0.00
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 5.60 7.74 db file scattered read 14249 0.00 1.10 db file sequential read 59 0.00 0.00
关于统计表格的标题信息中count、cpu、elapsed、disk、query、current和rows的说明在该trace文件的最前端有一个简要的说明,这里再分别赘述一下。 count :查询在此阶段执行的次数; cpu :该查询在此阶段的CPU时间量,以毫秒为单位; elapsed :花费在此阶段上的挂钟时间,该值比cpu值大的时候,表明存在等待事件; disk :执行物理I/O次数; query :在意一致性检索方式获得块时,执行逻辑I/O次数; current :逻辑I/O次数; rows :此阶段,被处理或受影响的行数。
4)摘录等待事件 Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 3 0.00 0.00 SQL*Net message from client 3 0.00 0.00 db file scattered read 14249 0.00 1.10 db file sequential read 59 0.00 0.00