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

其实最终还是因为在短期内生成了大量的redo,造成了频繁的日志切换，导致归档占用了大量的空间，最后无法登录，从这个层面来说，我

接着上次分享的关于数据库无法登录的原因
其实最终还是因为在短期内生成了大量的redo,造成了频繁的日志切换，导致归档占用了大量的空间，最后无法登录，从这个层面来说，我们可以做一些工作来尽可能长时间的保留近期的归档，但是我们还可以换一个思路，那就是看看到底是什么操作生成了大量的redo,能不能试着减少redo的生成量。
 一般来说，这个问题有点傻，日志肯定是记录尽可能完整的信息，这是做数据恢复的基础，我们还是不要过早下结论，先来分析一下再来做决定。
 查看数据库的redo切换频率，在近几天内的redo切换频率极高，对于一个OLTP的系统来说是很非常高的负载，这种频繁的日志切换我也只在数据迁移的一些场景中碰到过。

 但是奇怪的是查看数据库的DB time，却发现这个值其实并不高，看起来似乎有些矛盾，从这一点来看数据库内的数据变化频率其实并不是很高。
 BEGIN_SNAP  END_SNAP SNAPDATE    DURATION_MINS    DBTIME
  ---------- ---------- ----------------------- ----------
 82560      82561 05 Sep 2015 00:00    30    26
  82561      82562 05 Sep 2015 00:30    30    26
  82562      82563 05 Sep 2015 01:00    29    29
  82563      82564 05 Sep 2015 01:30    30    27
  82564      82565 05 Sep 2015 02:00    30    23
  82565      82566 05 Sep 2015 02:30    30    23
  82566      82567 05 Sep 2015 03:00    30    20
  82567      82568 05 Sep 2015 03:30    30    22
  82568      82569 05 Sep 2015 04:00    30    20
  82569      82570 05 Sep 2015 04:30    30    25
  82570      82571 05 Sep 2015 05:00    30    23
  82571      82572 05 Sep 2015 05:30    30    27
  82572      82573 05 Sep 2015 06:00    30    40
  82573      82574 05 Sep 2015 06:30    30    26
  82574      82575 05 Sep 2015 07:00    30    28
  82575      82576 05 Sep 2015 07:30    30    34
  82576      82577 05 Sep 2015 08:00    29    40
  82577      82578 05 Sep 2015 08:30    30    37
  82578      82579 05 Sep 2015 09:00    30    40
  82579      82580 05 Sep 2015 09:30    30    38
  82580      82581 05 Sep 2015 10:00    30    41
  82581      82582 05 Sep 2015 10:30    30    40
  82582      82583 05 Sep 2015 11:00    30    37
  82583      82584 05 Sep 2015 11:30    30    39
  82584      82585 05 Sep 2015 12:00    30    41
  82585      82586 05 Sep 2015 12:30    30    34
  82586      82587 05 Sep 2015 13:00    30    53
  82587      82588 05 Sep 2015 13:30    30    82
  82588      82589 05 Sep 2015 14:00    30    74
  82589      82590 05 Sep 2015 14:30    30    45

对于这种情况，我们还是抓取一个awr报告来看看。
 在awr报告中，可以看到瓶颈还是主要在DB CPU和IOsh

Top 5 Timed Foreground Events

EventWaitsTime(s)Avg wait (ms)% DB timeWait Class

DB CPU   2,184   68.89  

db file parallel read 6,096 413 68 13.02 User I/O

log file sync 65,199 363 6 11.47 Commit

db file sequential read 46,038 172 4 5.43 User I/O

direct path read 415,685 46 0 1.47 User I/O

查看时间模型，可以看到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...