日志繁忙导致UPDATE语句挂起

某天运行一条很普通的UPDATE语句:

update mbs7_ar.Ys_PackageCashFlow set IsApplyCheck=1 where Id = 72648;

卡在那里半天没运行完
查看该语句的执行计划也是正常:

Execution Plan----------------------------------------------------------Plan hash value: 658896919
--------------------------------------------------------------------------------
| Id  | Operation          | Name                  | Rows  | Bytes | Cost (%CPU)  | Time     |
--------------------------------------------------------------------------------
|   0 | UPDATE STATEMENT   |                       |     1 |     8 |     3   (0)  | 00:00:01 |
|   1 |  UPDATE            | YS_PACKAGECASHFLOW    |       |       ||          |
|*  2 |   INDEX UNIQUE SCAN|  PK_YS_PACKAGECASHFLOW |     1 |     8 |     2   (0) | 00:00:01 |

从计划上来看,也是走索引,而且集势很小,应该问题不是出于这里,重新撤销该update语句,
并进行统计信息更新后执行,问题依旧,那究竟数据库此刻在等待什么呢,进一步分析数据库警告日志,没有发现太大价值的线索,于是检查日志写部分是否有异常状况,进一步分析redo日志状态,发现:

SQL> select * from v$log;   
GROUP#    THREAD#  SEQUENCE#      BYTES  BLOCKSIZE    MEMBERS ARCHIVED STATUS           FIRST_CHANGE# FIRST_TIME  NEXT_CHANGE# NEXT_TIME
---------- ---------- ---------- ---------- ---------- ---------- -------- ---------------- ------------- ----------- ------------ -----------
         1          1        722  314572800        512          2 YES      ACTIVE             438611001 2012/8/29 2    439135903 2012/8/30 0         
         2          1        723  314572800        512          2 NO       CURRENT              439135903 2012/8/30 0 281474976710          
         3          1        721  314572800        512          2 YES      ACTIVE             438554092 2012/8/29 2    438611001 2012/8/29 2         
         4          2        790  314572800        512          2 YES      ACTIVE             439506059 2012/8/30 8    439889110 2012/8/30 1         
         5          2        791  314572800        512          2 NO       CURRENT              439889110 2012/8/30 1 281474976710          
         6          2        789  314572800        512          2 YES      ACTIVE             439135132 2012/8/30 0    439506059 2012/8/30 8

问题到这里就比较清晰了,原因是增量Checkpoint更新比较慢,造成缓冲区数据还来不及写到磁盘上,又有新的REDO产生,造成 active状态的日志文件不能重用,这个时候手工执行完全检查点把数据刷到数据文件里,即可解决:

SQL>alter system checkpoint; 

关于增量检查点的执行频率,是跟实例恢复的时间指导参数有关:fast_start_mttr_target

事后分析:这里虽然最终定位到原因,但有点走弯路了,象遇到这种问题,第一时间应该看v$session_wait视图,通常会得到重要的思路。