关于奇怪的并行进程分析(三)(r6笔记第47天)

在前两篇的基础上，对于一个环境中存在的奇怪并行进程问题进行了初步的分析。 初步排除了是通过scheduler的job运行导致的，一方面因为运行的时间会有延迟，甚至有很大的差别。所以分析和排查按照scheduler的时间点没有办法抓到任何规律。 排除了scheduler的影响之后，在分析ash之后无果，最后无奈使用了自定义脚本来排查问题。当然这个也确实需要点时间。 通过脚本跟踪的方式还是针对性要强一些，有些明细信息在ash报告中也体现不到，比如启用了多少的并行进程，那些语句走了大量的并行等等。 查看今天早晨的日志，发现竟然还有SYS的用户在做并行查询，先来说说这个问题。 抓取到的日志信息如下： 17 19257 SYS statdb96.cyou.com oracle@statdb96.test.com (P013) oracle INACTIVE 2015-09-02 02:03:01 5vf4b6p4v79rm ENABLED DISABLED ENABLED 29 64027 SYS statdb96.cyou.com oracle@statdb96.test.com (P056) oracle INACTIVE 2015-09-02 02:03:01 5vf4b6p4v79rm ENABLED DISABLED ENABLED 可以读取到SYS在运行sql_id 为5vf4b6p4v79rm 的sql语句，而且走了并行，我们来看看这个语句到底是怎么样的。 因为之前通过v$sql,dba_sql_hist的方式去查找parallel相关的语句，也没有找到让人信服的sql语句，这种守株待兔的方式得到的语句还是值得信任的。 语句内容如下： SELECT SERV_GROUP, CN_GUID, MAX(USER_CLASS) MCLASS, MAX(END_TIME) LASTTIME, MIN(END_TIME) FIRSTTIME FROM TESTUSER.TEST_BILLDETAIL WHERE END_TIME >= :B2 AND END_TIME < :B1 AND CN_GUID > 0 GROUP BY SERV_GROUP,CN_GUID

这个语句中没有任何的并行hint，但是确确实实走了并行，而且并行度还很高。 查看一下执行计划,发现一个很明显的全表扫描。这个表的数据量过亿，这个全表扫描的代价还是很高的。 ------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | ------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1186K| 30M| |* 1 | PX COORDINATOR | | | | | 2 | PX SEND QC (RANDOM) | :TQ10001 | 1186K| 30M| | 3 | HASH GROUP BY | | 1186K| 30M| | 4 | PX RECEIVE | | 1186K| 30M| | 5 | PX SEND HASH | :TQ10000 | 1186K| 30M| |* 6 | FILTER | | | | | 7 | PX BLOCK ITERATOR | | 1186K| 30M| |* 8 | TABLE ACCESS FULL| TEST_BILLDETAIL | 1186K| 30M| -------------------------------------------------------------------

但是查看语句，也不是一个很复杂的语句，我们来看看为什么走了全表扫描，而怎么没有考虑到索引扫描。 INDEX_NAME TABLESPACE INDEX_TYPE UNIQUENES PAR COLUMN_LIST ------------------------------ ---------- ---------- --------- --- -------------- IND_TEST_BILLDETAIL_CN NORMAL NONUNIQUE YES CN IND_TEST_BILLDETAIL_END_TIME NORMAL NONUNIQUE YES END_TIME

这个时候可以很i明显看到有一个索引是在字段END_TIME上的，所以说索引确确实实在哪儿，但是查询却压根没有走索引，而走了一个基于并行的圈全表扫描。 我们来看看索引的情况，这个索引是个分区索引，所以可以查看选择性的查看一部分索引信息。 INDEX_NAME PAR_NAME PAR_POS STATUS -------------------- --------------- ---------- ------- -------- IND_TEST_BILLDETAIL_CN TEST_BILLDETAIL_ 20091201 1 UNUSABLE

IND_TEST_BILLDETAIL_CN TEST_BILLDETAIL_ 20091202 1 UNUSABLE 随便抓取了几条，仔细一看，发现有很多索引都是unusable状态了，这个时候问题似乎有了很大的转机，索引失效导致的索引扫描没有启用，而走了全表扫描。 而对于这个问题的修复相对来说就简单多了,重新做rebuild即可，为了不影响在线业务，可以做一个小的尝试，拿一个数据比较早的分区来做一个测试，看看rebuild index partition之后，是否索引会正常启用。 SQL> alter index ldj.IND_TEST_BILLDETAIL_END_TIME rebuild partition TEST_BILLDETAIL_20091201; Index altered. 这个时候验证语句就类似下面的形式,同时把并行的影响也取消了。 SELECT /*+no_parallel*/ SERV_GROUP, CN_GUID, MAX(USER_CLASS) MCLASS, MAX(END_TIME) LASTTIME, MIN(END_TIME) FIRSTTIME FROM LDJ.SWD_BILLDETAIL partition(TEST_BILLDETAIL_20091201) WHERE END_TIME >= :B2 AND END_TIME < :B1 AND CN_GUID > 0 GROUP BY SERV_GROUP,CN_GUID rebuild index partition之前的执行计划如下： ------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | ------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 57 | 1197 | | 1 | HASH GROUP BY | | 57 | 1197 | |* 2 | FILTER | | | | | 3 | PARTITION RANGE SINGLE| | 57 | 1197 | |* 4 | TABLE ACCESS FULL | TEST_BILLDETAIL | 57 | 1197 | -------------------------------------------------------------------

rebuild index partition之后的执行计划如下： -------------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | -------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 57 | 1197 | | 1 | HASH GROUP BY | | 57 | 1197 | |* 2 | FILTER | | | | | 3 | PARTITION RANGE SINGLE | | 57 | 1197 | |* 4 | TABLE ACCESS BY LOCAL INDEX ROWID| TEST_BILLDETAIL | 57 | 1197 | |* 5 | INDEX RANGE SCAN | IND_TEST_BILLDETAIL_END_TIME | 103 | | --------------------------------------------------------------------------------------------

可以看到索引是能够正常启用的，这个时候并行的影响就可以基本排除了。 最后我们来简单说一说这个并行。 SQL>select degree,table_name,owner from dba_tables where table_name='SWD_BILLDETAIL' DEGREE TABLE_NAME OWNER -------------------- ------------------------------ ------------------------------ DEFAULT TEST_BILLDETAIL TESTDB 这种default的方式其实还有有些奇怪，如果要较真，会发现这个DEFAULT左边还是有一些空格的。 SQL> select degree from dba_tables where degree=' DEFAULT' and rownum<2; DEGREE -------------------- DEFAULT 这个是在对象级开了并行，至于并行度的情况，还是和参数parallel_execution_message_size有一些关系，我们先不细谈。 到此为止，我们发现了奇怪的并行问题其实和一个全表扫描相关，在这个基础上，继续分析发现索引没有启用，再进一步分析，发现对应的分区索引失效了。

这些问题都是一环套一环，缺一不可。 我们之前也分析过ASH报告中没有找到有效的信息，至于这个问题，其实是人为操作误导。

这一点还是需要特别说明一下,可以看看下面的操作结果说明了什么 $ echo $ORACLE_SID testdb1 $ sqlplus testdba/testdba@testdb1 SQL> select count(*)from v$session; COUNT(*) ---------- 39 SQL> conn / as sysdba Connected. SQL> select count(*)from v$session; COUNT(*) ---------- 165 SQL> show parameter uniq NAME TYPE VALUE ------------------------------------ ----------- ------------------------------ db_unique_name string testdb96 这个奇怪问题的原因就在于我们使用原来的db_name连接到的实际上是备库，所以抓取的ash报告中没有任何的有效信息。 而这个问题的根源还是在于之前做了一次主从切换。结果从库变成了主库，使用的原来的Uniq_name也还是保留了原来的样子。tns这边也还是保留了原来的格式，结果在通过tns连接的时候就连接到了备库 当然事后也做了验证，发现ash在问题的时间点内抓取的报告还是很有效的，相关的问题sql都会抓取到。所以ASH报告还是很靠谱的。 通过这个案例我们可以看到对于一个很细小的问题进行深究会发现其实还是存在着一些潜在问题，问题的发生都是有原因的，性能的抖动也是有一些需要我们去关注的细节。 细节决定成败，说的也就是这个意思吧。