暂无图片
暂无图片
暂无图片
暂无图片
暂无图片

Oracle tkprof输出问题

askTom 2017-04-03
221

问题描述

最近,我们在一些长时间运行的脚本上运行了10046跟踪,并从该跟踪文件生成tkprof输出。前两个sql如下所示,我正在寻找一些澄清。

1.此查询显示动态采样,但我不确定这意味着好还是坏

SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS IGNORE_WHERE_CLAUSE 
  NO_PARALLEL(SAMPLESUB) opt_param('parallel_execution_enabled', 'false') 
  NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_0"), 
  NVL(SUM(C2),:"SYS_B_1") 
FROM
 (SELECT /*+ IGNORE_WHERE_CLAUSE NO_PARALLEL("EQMIGRATIONTABLELOOKUP") 
  FULL("EQMIGRATIONTABLELOOKUP") NO_PARALLEL_INDEX("EQMIGRATIONTABLELOOKUP") 
  */ :"SYS_B_2" AS C1, CASE WHEN "EQMIGRATIONTABLELOOKUP"."TABLETYPE"=
  :"SYS_B_3" AND "EQMIGRATIONTABLELOOKUP"."ENABLEDTOMIGRATE"=:"SYS_B_4" AND 
  "EQMIGRATIONTABLELOOKUP"."ISTRUNCATENEEDED"=:"SYS_B_5" THEN :"SYS_B_6" ELSE 
  :"SYS_B_7" END AS C2 FROM "ARKMIG_I1CODE"."EQMIGRATIONTABLELOOKUP" 
  "EQMIGRATIONTABLELOOKUP") SAMPLESUB


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        1      0.00       0.00          1          7          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.00       0.00          1          7          0           1

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 283     (recursive depth: 2)
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         1          1          1  SORT AGGREGATE (cr=7 pr=1 pw=0 time=655 us)
        93         93         93   TABLE ACCESS FULL EQMIGRATIONTABLELOOKUP (cr=7 pr=1 pw=0 time=595 us cost=3 size=6544 card=409)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  gc cr grant 2-way                               1        0.00          0.00
  db file sequential read                         1        0.00          0.00
********************************************************************************
复制


首先,我不确定为什么会出现在顶部,因为我看不到长时间的等待事件而不是长时间的解析/执行。这是我应该看的东西吗?此外,类似的输出显示为一堆具有动态采样的sql。这应该是好是坏?我不确定。在确定这一点时需要一些指导。

2.这是另一个顶级sql,我看到它的执行次数很长。

SELECT SYS_GUID() 
FROM
 SYS.DUAL


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        0      0.00       0.00          0          0          0           0
Execute 154714986    456.52     463.16          0          0          0           0
Fetch   154714986    127.85     131.53          0          0          0   154714986
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   309429972    584.37     594.70          0          0          0   154714986

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 283     (recursive depth: 3)
********************************************************************************
复制


我怎么看这个?这甚至不是sql的整个持续时间,而是大约2小时。

提前感谢您的帮助。

专家解答

1.优化器可以选择在执行您的查询时做动态采样。这有几个原因。一个常见的是你的表没有统计数据!例如:

create table t as
  select rownum x from dual connect by level <= 1000;

alter session set sql_trace = true;
set serveroutput off

select count(*) from t;

select * from table(dbms_xplan.display_cursor(null, null, 'BASIC LAST +NOTE'));
PLAN_TABLE_OUTPUT                                        
EXPLAINED SQL STATEMENT:                                 
------------------------                                 
select count(*) from t                                   
                                                         
Plan hash value: 1071362934                              
                                                         
-----------------------------------                      
| Id  | Operation          | Name |                      
-----------------------------------                      
|   0 | SELECT STATEMENT   |      |                      
|   1 |  SORT AGGREGATE    |      |                      
|   2 |   TABLE ACCESS FULL| T    |                      
-----------------------------------                      
                                                         
Note                                                     
-----                                                    
   - dynamic sampling used for this statement (level=2)  
复制


如注释部分所示,Oracle数据库对此查询使用了动态采样。和跟踪文件包含这个查询:

SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS IGNORE_WHERE_CLAUSE
  NO_PARALLEL(SAMPLESUB) opt_param('parallel_execution_enabled', 'false')
  NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_0"),
  NVL(SUM(C2),:"SYS_B_1")
FROM
 (SELECT /*+ NO_PARALLEL("T") FULL("T") NO_PARALLEL_INDEX("T") */ :"SYS_B_2"
  AS C1, :"SYS_B_3" AS C2 FROM "CHRIS"."T" "T") SAMPLESUB
复制


有关不同采样水平的含义以及何时启动的更多详细信息,请参见:

http://docs.oracle.com/cd/E11882_01/server.112/e41573/stats.htm#PFGRF95254

如果您的查询的总体解析时间很小,则不值得担心。但是,如果解析一般情况下,特别是动态采样查询会占用SQL运行时的很大一部分,请进一步查看发生了什么。

2.这告诉你你正在执行

SELECT SYS_GUID() FROM SYS.DUAL
复制


在跟踪期1.54亿次!总运行时间约为600s,小于4 μ s/exec。即每次执行都是快速的。

但是154万个电话对我来说似乎太过分了...所以问自己的问题是:

你为什么这么频繁地调用sys_guid()?你真的用这个来生成154m行的PKs吗?

这对我来说似乎不太可能,但我对你的应用程序或你用来捕获这些数据的时间框架一无所知。
「喜欢这篇文章,您的关注和赞赏是给作者最好的鼓励」
关注作者
【版权声明】本文为墨天轮用户原创内容,转载时必须标注文章的来源(墨天轮),文章链接,文章作者等基本信息,否则作者和墨天轮有权追究责任。如果您发现墨天轮中有涉嫌抄袭或者侵权的内容,欢迎发送邮件至:contact@modb.pro进行举报,并提供相关证据,一经查实,墨天轮将立刻删除相关内容。

评论