大量redo生成的问题原因及改进(2)

查看时间模型,可以看到DB CPU和sql相关的影响各占了主要的比例。
看到这,自己还是有些犯嘀咕,柑橘这个问题还是有些奇怪,能够关注的一个重点就是sql语句了,但是top 1的sql语句还是有些奇怪。

Elapsed Time (s)ExecutionsElapsed Time per Exec (s)%Total%CPU%IOSQL IdSQL ModuleSQL Text
931.73   14,409   0.06   29.39   99.77   0.00     JDBC Thin Client   update sync_id set ma...  

这条语句执行频率极高,语句也很简单,但是CPU消耗却很高,初步怀疑是走了全表扫描。
语句如下:
update sync_id set max_id = :1 where sync_id_type = :2
简单查看执行计划,发现确实是走了全表扫描,如果碰到这个问题,第一感觉是需要走索引,没有索引可以建个索引,但是当我看到sql by Executions这个部分时,自己感觉到问题其实不是那么简单。
可以看到第2个语句其实就是刚刚提到的top 1的sql,对应的指标还是很不寻常的,一次执行处理的行数近5000度行,执行了1万多次,处理的数据行数近8千万。

ExecutionsRows ProcessedRows per ExecElapsed Time (s)%CPU%IOSQL IdSQL ModuleSQL Text
14,684   14,684   1.00   3.39   94.7   .7     JDBC Thin Client   update sus_log set failed_c...  
14,409   78,329,332   5,436.14   931.73   99.8   0     JDBC Thin Client   update sync_id set ma...  

但是查看这个表,发现数据其实就1万多条,所以这是一个明显的问题。
 我们来进一步分析一下,一个小表1万多的数据,每次更新能够更新5000多行,可以断定数据的分布式是不均匀的。因为这个表结构非常简单,就两个字段,所以分析问题还是很好定位的。
 简单查看了一下数据情况,发现数据主要分布在两个type列值上,基本上占用了99.99%以上的数据
SQL> select max_id,count(*)from SYNC_ID where SYNC_ID_TYPE='SYNC_LOG_ID' group by max_id;
    MAX_ID  COUNT(*)
 ---------- ----------
        38      5558
 SQL> select max_id,count(*)from SYNC_ID where SYNC_ID_TYPE=SYNC_TEST2_LOG_ID' group by max_id;
    MAX_ID  COUNT(*)
 ---------- ----------
        108      5577
从数据的分布情况可以看到,其实表中存在了大量的冗余数据,而且表中没有索引字段和其它约束,在每次更新的时候本来更新一个字段值,结果会修改5000多行数据的值,如果执行频繁,短时间内就会频繁生成大量的redo,从目前的sql运行情况来看,这条语句应该是造成redo频繁切换的主要原因了。
 但是这个环境还是需要做一些确认和沟通之后才能够变更的,目前的也只是建议,我们在这个基础上还是可以简单地测试一下的。
 测试的思路其实很简单,就是把这个表里的数据给导出来,放到其它测试环境中,做频繁的update,然后查看归档的频率即可。
 然后删除冗余的数据,再做频繁的update,然后查看归档的频率就可以比较出来。
 把数据导入到另外一个测试环境中。
 然后使用下面的语句进行频繁更新即可,先更新一百万次,中间可以随时中断。

function test_update
 {
 sqlplus test/test < update sync_id set max_id = 38 where sync_id_type = 'SYNC_LOG_ID';
 commit;
 EOF
 }

for i in {1..1000000}
 do
 test_update

done

在测试开始的时候
Redo Switch times per hour      2015-Sep-05 16:02:55
 MON DA  00  01  02  03  04  05  06  07  08  09  10  11  12  13  14  15  16  17  18  19  20  21  22  23
 --- -- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ----
 09  05    0    0    0    0    0    0    0    1    0    0    1    0    0    0    0    1    0    0    0    0    0    0    0    0
运行了不到3分钟,日志切换就达到了14次,还是很能够说明问题的。
Redo Switch times per hour      2015-Sep-05 16:05:20
 MON DA  00  01  02  03  04  05  06  07  08  09  10  11  12  13  14  15  16  17  18  19  20  21  22  23
 --- -- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ----
 09  05    0    0    0    0    0    0    0    1    0    0    1    0    0    0    0    2  14    0    0    0    0    0    0    0

内容版权声明:除非注明,否则皆为本站原创文章。

转载注明出处:https://www.heiqu.com/bfaed58494bfa3f58a7e87d09f07ca17.html