一个SQL性能问题的优化探索(二)(r11笔记第38天)

继续前几天的一个案例一个SQL性能问题的优化探索(一)(r11笔记第33天)

如下的SQL语句存在索引字段CARD_NO,但是执行的时候却走了全表扫描,因为这是一个核心表,数据量很大,导致数据库负载很高。

SQL_FULLTEXT
----------------------------------------------------------------------------------------------------
SELECT ID,CN,CARD_NO,TO_CHAR(CHARGE_DATE,'yyyy-MM-dd HH24:mi:ss') AS CHARGE_DATE ,IP,POINT,PRESENT_P
OINT,SUCCESS,CARD_TYPE,PRODUCTNUM,SALEMETHOD,ITEM_ID,SERVICEID,ORDER_NO,TO_CHAR(EXPIREDATE,'yyyy-MM-
dd HH24:mi:ss') AS EXPIREDATE,REMARK FROM RECHARGE_LOG WHERE CARD_NO = TO_NUMBER(:1)

对于这个问题,苦于无法复现,通过各种途径进行分析,有些信息似乎有些矛盾。如果说是统计信息的问题,但是查看直方图的信息是有的。而且分为了200多个bucket,索引列card_no的统计信息也没有发现什么问题。而且比较奇怪的是问题发生后查看执行计划情况,后面的语句是可以走索引的。这个问题怎么来进一步分析呢。

我们可以化被动为主动,我对这个列对应的索引添加了索引监控,即alter index xxxx monitoring usage;然后有了这个标识之后,就可以随时查看v$object_usage查看索引是否被启用,当然这个视图得到的信息毕竟很有限。我们只能知道索引是否被启用,但是每次启用的时间等这些没法定位,而且因为走了索引本身执行效率就很高,所以在快照中是很可能不会被收编进来的。

这个问题还有一个疑点就是统计信息的收集时间,和同事确认问题发生当天他是没有收集统计信息的,但是查看字段last_analyzed的时间却恰恰是发生收集以后。

问题暂时搁置下来,在这两天问题有了进一步的发现,另外一个报警引起了我的注意。报警是CPU使用率较高,查看数据库层面的负载也突然有了较大的抖动。

定位到相关的语句如下:

   SNAP_ID SQL_ID        EXECUTIONS_DELTA ELAPSED_TI PER_TOTAL
---------- ------------- ---------------- ---------- ----------
    108829 bbtwpb1aamud2                0 1766s      45%
    108829 7zmnkpfaumuk1                1 1141s      29%
    108829 4y30fbyjmrrqr                1 432s       11%
    108829 f7h0xrkw1wy48                1 192s       4%
    108829 63t40nvuuwrdp           258730 116s       2%

可以看到明显有几个SQL执行效率较差。

查看TOP 1的语句发现竟然是一个JOB在运行。

SQL_FULLTEXT
----------------------------------------------------------------------------------------------------
DECLARE job BINARY_INTEGER := :job;  next_date TIMESTAMP WITH TIME ZONE := :mydate;  broken BOOLEAN
:= FALSE;  job_name VARCHAR2(30) := :job_name;  job_subname VARCHAR2(30) := :job_subname;  job_owner
 VARCHAR2(30) := :job_owner;  job_start TIMESTAMP WITH TIME ZONE := :job_start;  job_scheduled_start
 TIMESTAMP WITH TIME ZONE := :job_scheduled_start;  window_start TIMESTAMP WITH TIME ZONE := :window
_start;  window_end TIMESTAMP WITH TIME ZONE := :window_end;  BEGIN  BEGIN
dbms_stats.gather_table_stats(ownname=>'TEST',tabname=>'RECHARGE_LOG',cascade=>true);
END;  :mydate := next_date; IF broken THEN :b := 1; ELSE :b := 0; END IF; END;

语句的核心就是dbms_stats的部分,竟然是收集表recharege_log的统计信息。

后面的几个语句也是收集统计相关的递归SQL,我列举出一个是因为这里面有非常重要的一个信息。先卖个关子。

$sh showsqltext.sh 7zmnkpfaumuk1
insert /*+ append */ into  sys.ora_temp_1_ds_33892 select /*+ no_parallel(t) no_parallel_index(t)  dbms_stats cursor_sharing_exact use_weak_name_resl dy
namic_sampling(0)  no_monitoring */"CHARGE_DATE","SERVICEID","ORDER_NO","EXPIREDATE",  rowid SYS_DS_ALIAS_0 from "TEST"."RECHARGE_LOG" sample ( 12.12452
80643) t

这个时候查看语句的执行计划情况,只有全表扫描的执行计划。

明显不合理嘛。看起来问题又想回到了原点。

这个时候不要气馁,我们重新捋一捋信息,列的统计信息的情况如下:

>  select column_name,histogram from dba_tab_col_statistics 
where table_name='RECHARGE_LOG';
COLUMN_NAME          HISTOGRAM
-------------------- ---------------
ID                   NONE
CN                   HEIGHT BALANCED
CARD_NO              HEIGHT BALANCED
CHARGE_DATE          HEIGHT BALANCED
IP                   HEIGHT BALANCED
POINT                FREQUENCY
PRESENT_POINT        NONE
SUCCESS              FREQUENCY
CARD_TYPE            FREQUENCY
PRODUCTNUM           NONE
SALEMETHOD           FREQUENCY
ITEM_ID              FREQUENCY
SERVICEID            NONE
ORDER_NO             HEIGHT BALANCED
REMARK               NONE
EXPIREDATE           NONE
ID                   NONE
CN                   NONE
CARD_NO              NONE
CHARGE_DATE          NONE
IP                   NONE
POINT                NONE
....

看起来有点不大对劲,因为CARD_NO的直方图信息是空的。

查看另外一个数据字典,发现这个列的直方图信息竟然是存在的,输出有上百行。

select to_char(endpoint_value) value,endpoint_number,column_name ,ENDPOINT_ACTUAL_VALUE from dba_tab_histograms where table_name = 'RECHARGE_LOG' and column_name in ('CARD_NO') ORDER BY endpoint_number

所以这个问题就比较有意思了,存在直方图的列的统计信息,但是两个视图中信息却有些冲突。

由此一来可以推断是这个地方导致全表扫描的一个原因。

我们来看看另外一个潜在的问题,收集统计信息的部分,可以看到是在凌晨3点运行,明显就是一个定时任务。所以同事所说的没有手工收集统计信息是真实的。

select table_name,
        to_char(LAST_ANALYZED,'YYYY-MM-DD HH24:MI:SS') LAST_ANALYZED 
        from dba_tables where TABLE_NAME='RECHARGE_LOG';
TABLE_NAME                     LAST_ANALYZED
------------------------------ -------------------
RECHARGE_LOG                   2017-01-07 03:40:45  

还有一个问题,那就是收集统计信息,怎么会有这些影响呢,我们得看看dbms_stats.gather_table_stats的参数method_opt,因为method_opt:决定histograms信息是怎样被统计的.method_opt的取值(默认值为FOR ALL COLUMNS SIZE AUTO),也就意味着是一个动态的过程。这不card_no摊上事情了,直接忽略了,没收集。

关于这个问题,可以参考一个bug

Bug 5949981 - Bad cardinality with histogram (Doc ID 5949981.8)

而问题原因跟进一步,为什么列card_no没有收集统计信息。可以参考一条SQL语句的执行计划变化探究(r10笔记第9天) 原因也是大同小异。

问题的一种解决思路就是收集统计信息时,不收集直方图的信息即可,不使用默认的auto选项。

原文发布于微信公众号 - 杨建荣的学习笔记(jianrong-notes)

原文发表时间:2017-01-08

本文参与腾讯云自媒体分享计划,欢迎正在阅读的你也加入,一起分享。

发表于

我来说两句

0 条评论
登录 后参与评论

相关文章

来自专栏数据和云

触类旁通:那些关于 TBL$OR$IDX$PART$NUM 的诡异案例和知识

你是否留意过数据库中有一个奇怪的函数 TBL$OR$IDX$PART$NUM ,你是否留意过很多场景下都出现过它的身影?

1414
来自专栏杨建荣的学习笔记

merge语句导致的CPU使用率过高的优化(r7笔记第4天)

今天有一个数据库有点反常,早上的时候报出了CPU使用率的警告。 警告内容如下: ZABBIX-监控系统: -----------------------...

3255
来自专栏杨建荣的学习笔记

ORA-01427问题的分析和解决(r6笔记第51天)

前几天开发的同事反馈一个问题,说前台系统报出了ORA错误,希望我们能看看是什么原因。 java.sql.SQLException: ORA-01427: sin...

2754
来自专栏乐沙弥的世界

Oracle 联机重做日志文件(ONLINE LOG FILE)

--=========================================

1102
来自专栏「3306 Pai」社区

《那些年,我在乙方的日子 -- 神谕篇NO1》

某个夏日的午后,窗外知了在大声鸣叫。而我却在睡梦中跟基友一起吃鸡,正准备抢空投时 。手机突然铃声响起,惊醒后一看是领导电话,一下子回到了现实中。心想又得去公司吃...

1502
来自专栏杨建荣的学习笔记

深度解析dba_segments和sys.seg$中的细节差异(上) (r5笔记第27天)

今天在查看系统空间使用情况的时候,发现一个细节的问题,自己死磕了一把,还是发现了不少有价值的东西。 事情的起因是我在使用脚本在某个环境中查看每个用户所占有的空间...

3548
来自专栏乐沙弥的世界

RAC环境下的阻塞(blocking blocked)

      RAC环境下的阻塞不同于单实例情形,因为我们需要考虑到位于不同实例的session。也就是说之前查询的v$session,v$lock相应的应变化为...

1202
来自专栏Jerry的SAP技术分享

使用ABAP代码创建S/4HANA里的Sales Order

其中红色区域的值是我代码里硬编码的,而蓝色是函数SD_SALESDOCUMENT_CREATE自己创建的。

1066
来自专栏沃趣科技

应用示例荟萃 | performance_schema全方位介绍(上)

经过前面6个篇幅的学习,相信大家对什么是performance_schema,已经初步形成了一个整体认识,但我想很多同行看完之前的文章之后可能还是一脸懵逼,今天...

2143
来自专栏杨建荣的学习笔记

生产环境sql语句调优实战第六篇(r2笔记91天)

生产环境中有大量的sql语句在运行,尽管有awr,ash做数据的收集统计,但是dba的调优工作大多数情况都是在问题已经发生后做排查的,有些sql语句可能执行的时...

2774

扫码关注云+社区

领取腾讯云代金券