持续近7个小时的索引扫描的查询优化分析 (r5笔记第44天)

昨天客户的DBA反映有一个数据抽取的任务持续了很长时间最后超时退出了，让我看看有什么地方可以调优一下。找到了对应的日志，发现在一个大表抽取的时候，抽取持续了将近7个小时，最后超时退出了。对于这个问题，有以下几个方面需要考虑一下。 1）为什么这个问题之前没有发现过 2）是否是由某些变化导致了这个问题 3）这个问题的调优方向这个数据抽取的服务之前一直没有问题，抽取速度都是比较快的，结果这次竟然持续了7个小时还没有抽取完。首先抓取到了对应的日志，把相关的sql语句也抓取到了。同时从系统负载的角度进行分析，查看数据库层，系统级是否发生了某些变化导致了这个问题，结果抓取了详细的awr报告，同时结合系统命令分析查看系统负载，都没有发现任何的异常，而且这些天来一直没有任何数据库层面的参数变更。所以问题的关注点还是到了sql语句上。查看sql语句的执行计划，也没有发现异常，可以很明显看到走的是索引扫描。语句是类似下面的样子，使用了闪回查询，查询条件只有一个customer_id select * FROM "RATED_EVENT" AS OF TIMESTAMP (TIMESTAMP' 2015-05-21 07:33:23.000000000') "RATED_EVENT" WHERE "CUSTOMER_ID"=:1

因为数据抽取为了保证数据一致性，所以使用闪回查询的功能，所以这个问题为了方便排查，可以进一步把sql语句改写为： select count(*) FROM "RATED_EVENT" "RATED_EVENT" WHERE "CUSTOMER_ID"=11727713

执行计划如下：

Plan hash value: 3695503463
----------------------------------------------------------------------------------------------------------------------
| Id  | Operation                          | Name            | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
----------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                   |                 |   432 |   369K|   320   (0)| 00:00:04 |       |       |
|   1 |  PARTITION RANGE ALL               |                 |   432 |   369K|   320   (0)| 00:00:04 |     1 |   961 |
|   2 |   TABLE ACCESS BY LOCAL INDEX ROWID| RATED_EVENT     |   432 |   369K|   320   (0)| 00:00:04 |     1 |   961 |
|*  3 |    INDEX RANGE SCAN                | RATED_EVENT_1UQ |   432 |       |   289   (0)| 00:00:04 |     1 |   961 |
----------------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
   1 - SEL$1
   2 - SEL$1 / RATED_EVENT@SEL$1
   3 - SEL$1 / RATED_EVENT@SEL$1
Predicate Information (identified by operation id):
---------------------------------------------------
   3 - access("CUSTOMER_ID"=11727713)

这样一来，问题就显得更加奇怪了。走了索引扫描，条件也很简单，怎么就查询了那么长的时间呢。这条语句有一个亮点就是看看pstart,pstop的部分，显示为1和961，即表示这个分区表在查询中扫描的分区为1~961个，这个规模还是相当大的。但这个还不是最终的问题原因。这个时候需要结合一下业务来进行诊断。 customer对应有多个subscriber,一般的三户模型中都是一个customer可能就对应一个subscriber，当然一个customer也可以对应多个subscriber,比如一些大客户就是如此。我们来看看这个场景里的customer和subscriber的对应比例。 SQL> select count(*)from subscriber where customer_id=11727713; COUNT(*) ---------- 6168 里面有6000多个subscriber，在近10亿条记录中进行这么大范围的数据扫描，而且扫描的分区是1~961个，难度可想而知。这个数据抽取的部分代码都是灵活配置的，怎么能尽快的提升效率呢。自己尝试了几个方法，一个是使用exp/expdp导出数据，结合使用query条件，这个时候算是脱离了原有的数据抽取工具，因为这个场景里抽取逻辑相对简单，所以不妨一试。 exp xxxxx/xxxxx@xxxxfile=test.dmp tables=rated_event query=' where customer_id= 11727713 ' grants=n indexes=n statistics=none buffer=9102000

但是根据自己的测试发现，效果并不理想。如果要直接修改抽取的配置规则，相对也是比较困难的。如果能够提升抽取速度，同时能从抽取业务上做一些优化但不改变原有的业务就是最好的方法了。明白了这点，自己就开始结合业务来进行分析，因为整个分区表是按照一个类似账期的字段来分区的，一个customer只对应一个账期，customer下的subscriber都是同一个账期，明白了这点。语句就可以相应的修改成下面的形式。 select count(*) FROM "RATED_EVENT" "RATED_EVENT" WHERE "CUSTOMER_ID"=10566068 and cycle_code in (select cycle_code from customer where customer_id=10566068)

这个时候执行计划也有了一些变化。


Plan hash value: 1017421008
-------------------------------------------------------------------------------------------------------------
| Id  | Operation                 | Name            | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
-------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT          |                 |     1 |     9 |    73   (0)| 00:00:01 |       |       |
|   1 |  SORT AGGREGATE           |                 |     1 |     9 |            |          |       |       |
|   2 |   PARTITION RANGE ITERATOR|                 |   303 |  2727 |    73   (0)| 00:00:01 |   241 |   481 |
|*  3 |    INDEX RANGE SCAN       | RATED_EVENT_1UQ |   303 |  2727 |    73   (0)| 00:00:01 |   241 |   481 |
-------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
   1 - SEL$1
   3 - SEL$1 / RATED_EVENT@SEL$1
Predicate Information (identified by operation id):
---------------------------------------------------
   3 - access("CUSTOMER_ID"=10566068 AND "CYCLE_CODE"=2)
       filter("CYCLE_CODE"=2)

可以看到这个时候扫描的分区少了很多，从241~481，相比原来只扫描了四分之一的分区。性能的提升还是很高的。这个时候简单对比一下，结合了分区字段，扫描的速度也快了不少。用了大概4分钟就能够有结果了。 SQL> select count(*)from rated_event where customer_id=11727713 and cycle_code=2 / COUNT(*) ---------- 11757084 Elapsed: 00:04:16.40 而对于select count(*)的操作在之前却要花费将近15分钟。 SQL> select count(*) FROM "RATED_EVENT" "RATED_EVENT" WHERE "CUSTOMER_ID"=11727713 ; COUNT(*) ---------- 11751975 Elapsed: 00:15:05.54 这个时候如果观察足够细致，会发现两个查询的数据条数还是有一些出入，这是因为某些客户做了修改账期的操作，在这个数据抽取中只关注当前账期的操作，所以可以暂时放过。由此可见，看似简单的语句走了索引扫描，看起来合理，但是问题突然发生的时候还得结合具体的场景来分析，不能把问题孤立起来看，在明白了问题的瓶颈之后，如果单纯从数据库层面所做的工作有限时，可以考虑从业务上进行进一步的优化，辅助数据库优化的方向。这个时候DBA的性能调优工作就不单单是一个数据层面的工作了，可能结合业务场景更有针对性，调优的方向也更明确。