Oracle tkprof工具格式化 10046 event trace文件

最新推荐文章于 2021-04-03 03:17:24 发布

SeanData

最新推荐文章于 2021-04-03 03:17:24 发布

阅读量1.1k

点赞数

分类专栏： Oracle 开发 Oracle 性能优化文章标签： oracle tkprof 10046

本文链接：https://blog.csdn.net/Seandba/article/details/73867523

版权

Oracle 开发同时被 2 个专栏收录

25 篇文章 0 订阅

订阅专栏

Oracle 性能优化

9 篇文章 0 订阅

订阅专栏

一、问题

一个500w话单表中，求同一个号码2次通话时间之间间隔大于10s的通话记录id
1、仅比较两次号码都是主叫的通话
2、两次通话之间间隔是指两次通话开始时间的间隔？还是上次通话的结束时间和本次通话的开始时间之间的间隔？假设为前者。
3、此表无索引
4、表结构如下

table T_CALL_QD  
 (  
   id         NUMBER, --递增id,按插入时间(start_time)递增的数字  
   call_nbr   VARCHAR2(11), --主叫号码  
   called_nbr VARCHAR2(11), --被叫号码  
   start_time DATE, --开始时间  
   end_time   DATE, --结束时间,大于开始时间  
   duration   NUMBER --通话时长(秒)  
 )

二、测试数据准备

构造数据说明：
    500w=50w*10
    50w个号码
    10个开始结束时间段
    笛卡尔连接产生500w条记录
    id 是递增的
    同一个号码start_time 是递增的
    最后结果是每个号码都有10条通话记录，前5条通话记录间隔小于10s，后5条间隔大于10s，需求就是把每个号码2次通话间隔大于10s的通话id取出来

create table t_call_qd nologging as
with t_nbr as
(
select cast('15305'||lpad(level,6,'0') as varchar2(11)) nbr from dual connect by level<=500000
)
select rownum id,
    t1.nbr call_nbr,
    cast('15305531836' as varchar2(11)) called_nbr,
    t2.start_time,
    t2.end_time,
    2 duration
from
(select sysdate ＋ numtodsinterval(power(level, 2), 'second') start_time,sysdate ＋ numtodsinterval(power(level, 2) ＋ 2, 'second') end_time
from dual
connect by level <= 10) t2,
t_nbr t1
;

每个号码都有10条通话记录，前4条通话记录间隔小于10s，后6条间隔大于10s

SQL> select * from t_call_qd t where t.call_nbr='15305000001';

        ID CALL_NBR    CALLED_NBR  START_TIM END_TIME    DURATION
---------- ----------- ----------- --------- --------- ----------
         1 15305000001 15305531836 29-JUN-17 29-JUN-17          2
    500001 15305000001 15305531836 29-JUN-17 29-JUN-17          2
   1000001 15305000001 15305531836 29-JUN-17 29-JUN-17          2
   1500001 15305000001 15305531836 29-JUN-17 29-JUN-17          2
   2000001 15305000001 15305531836 29-JUN-17 29-JUN-17          2
   2500001 15305000001 15305531836 29-JUN-17 29-JUN-17          2
   3000001 15305000001 15305531836 29-JUN-17 29-JUN-17          2
   3500001 15305000001 15305531836 29-JUN-17 29-JUN-17          2
   4000001 15305000001 15305531836 29-JUN-17 29-JUN-17          2
   4500001 15305000001 15305531836 29-JUN-17 29-JUN-17          2

10 rows selected.

SQL>  select to_char(t.start_time,'yyyymmdd hh24:mi:ss') start_time from t_call_qd t where t.call_nbr='15305000001';

START_TIME
-----------------
20170629 09:56:35
20170629 09:56:38
20170629 09:56:43
20170629 09:56:50
20170629 09:56:59
20170629 09:57:10
20170629 09:57:23
20170629 09:57:38
20170629 09:57:55
20170629 09:58:14

10 rows selected.

收集统计信息

SQL> exec dbms_stats.gather_table_stats(user,'T_CALL_QD');

PL/SQL procedure successfully completed.

查看表大小

SQL> select segment_name, bytes / 1024 / 1024 mb, blocks
  2    from user_segmentS t
  3   where t.segment_name = 'T_CALL_QD';

SEGMENT_NAME                 MB     BLOCKS
-------------------- ---------- ----------
T_CALL_QD                   296      37888

三、生成10046trace文件

重启库

[oracle@sean ~]$ sqlplus / as sysdba
SQL> shutdown immediate

SQL> startup

SQL> exit 

[oracle@sean ~]$ sqlplus sean/sean

生成trace文件

alter session set events '10046 trace name context forever,level 12';

with tab as (
select t.id,
    t.call_nbr,
    t.start_time,
    lag(t.start_time,1) over(partition by t.call_nbr order by t.start_time) before_time,
    lead(t.start_time,1) over(partition by t.call_nbr order by t.start_time) after_time,
    row_number() over(partition by t.call_nbr order by t.start_time) rn
from t_call_qd t
)
select id from tab t
where (t.after_time-t.start_time>10/(24*60*60) or t.start_time-t.before_time>10/(24*60*60));

alter session set events '10046 trace name context off';

查看trace文件位置

select * from v$diag_info t where t.name = 'Default Trace File';

四、使用tkprof工具格式化trace文件

tkprof /u01/app/oracle/diag/rdbms/sean/sean/trace/sean_ora_3282.trc /tmp/t_call_qd.tkp sys=no waits=yes

五、查看tkprof格式化后的结果

[oracle@sean ~]$ tkprof /u01/app/oracle/diag/rdbms/sean/sean/trace/sean_ora_3282.trc /tmp/t_call_qd.tkp sys=no waits=yes

TKPROF: Release 11.2.0.4.0 - Development on Thu Jun 29 10:16:32 2017

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


[oracle@sean ~]$ cat /tmp/t_call_qd.tkp

TKPROF: Release 11.2.0.4.0 - Development on Thu Jun 29 10:16:32 2017

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

Trace file: /u01/app/oracle/diag/rdbms/sean/sean/trace/sean_ora_3282.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
********************************************************************************

with tab as (
select t.id,
    t.call_nbr,
    t.start_time,
    lag(t.start_time,1) over(partition by t.call_nbr order by t.start_time) before_time,
    lead(t.start_time,1) over(partition by t.call_nbr order by t.start_time) after_time,
    row_number() over(partition by t.call_nbr order by t.start_time) rn
from t_call_qd t
)
select id from tab t
where (t.after_time-t.start_time>10/(24*60*60) or t.start_time-t.before_time>10/(24*60*60))

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          2         34          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch   200001      4.72      22.09      80613      37207         14     3000000
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   200003      4.72      22.09      80615      37241         14     3000000

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

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
   3000000    3000000    3000000  VIEW  (cr=37207 pr=80613 pw=43408 time=26413989 us cost=47594 size=200000000 card=5000000)
   5000000    5000000    5000000   WINDOW SORT (cr=37207 pr=80613 pw=43408 time=14753487 us cost=47594 size=130000000 card=5000000)
   5000000    5000000    5000000    TABLE ACCESS FULL T_CALL_QD (cr=37207 pr=37204 pw=0 time=392697 us cost=10268 size=130000000 card=5000000)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                  200001        0.00          0.08
  Disk file operations I/O                        2        0.00          0.00
  db file sequential read                         2        0.00          0.00
  direct path read                              302        0.00          0.08
  direct path write temp                       2095        0.00          1.35
  direct path read temp                        4206        0.00          0.15
  SQL*Net message from client                200001        0.79        160.54
********************************************************************************

SQL ID: 06nvwn223659v Plan Hash: 0

alter session set events '10046 trace name context off'


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        727          0           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0        727          0           0

Misses in library cache during parse: 0
Parsing user id: 90  



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

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        2      0.00       0.00          2         34          0           0
Execute      2      0.00       0.00          0        727          0           0
Fetch   200001      4.72      22.09      80613      37207         14     3000000
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   200005      4.73      22.09      80615      37968         14     3000000

Misses in library cache during parse: 1

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                  200002        0.00          0.08
  SQL*Net message from client                200002        7.50        168.05
  db file sequential read                         2        0.00          0.00
  Disk file operations I/O                        2        0.00          0.00
  direct path read                              302        0.00          0.08
  direct path write temp                       2095        0.00          1.35
  direct path read temp                        4206        0.00          0.15


OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        2      0.00       0.00          0          0          0           0
Execute     33      0.00       0.00          0          0          0           0
Fetch      381      0.00       0.00          2        761          0         356
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total      416      0.00       0.00          2        761          0         356

Misses in library cache during parse: 2
Misses in library cache during execute: 2

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                         2        0.00          0.00

    2  user  SQL statements in session.
   13  internal SQL statements in session.
   15  SQL statements in session.
********************************************************************************
Trace file: /u01/app/oracle/diag/rdbms/sean/sean/trace/sean_ora_3282.trc
Trace file compatibility: 11.1.0.7
Sort options: default

       1  session in tracefile.
       2  user  SQL statements in trace file.
      13  internal SQL statements in trace file.
      15  SQL statements in trace file.
      15  unique SQL statements in trace file.
  607786  lines in trace file.
     190  elapsed seconds in trace file.