最近碰到一个奇怪的问题.某个应用,突然redo log的生成增长了10倍,持续了两天后,自己又正常了.
这事情碰到就郁闷,出问题了,自己好了,最难受,因为会睡不着,不知道那玩意什么时候会出现.
如是,去分析statspack,发现在出问题的时间段和正常的时间段里面.每秒的事务和sql的执行次数都没有什么改变.
只是某些语句执行的时候,要获得的记录条数增加了一个数量级.捕获到这些语句,执行的都是select for update nowait之类的.难道是这些语句引起的redo log激增吗?
继续分析,发现这些语句只要执行,是肯定会引起undo的使用增加,这个是可以理解的,但是应该redo不会增加那么多的,按照常理来说,这些语句我并没有真实的去修改,而只是加了个锁,然后释放.并没有作修改,还是select语句列,虽然说会有itl的改变,产生log,感觉不会那么多.
啥都不说了,测试才是王道.如是用create table as select from创建测试表.然后,一边观察v$mystat中的redo的改变,一边对这个表进行for update nowait的操作.
观察的结果,居然验证了猜测,基本上,我的数据量的大小是6M左右(3600行记录,每行不到200字节),只要作了for update nowait的操作,则立刻会生成接近6M的redo文件.相反,在commit或者rollback命令的时候,倒没有多少日志生成.
再回到那个问题,以前好好的应用,为什么那个时候redo会暴增,statspack中,为什么没有特别明显的异常,原来,在出问题的时候,那个for update nowait锁定的记录,在那个时候,由于应用的问题,增加了一个数量级.这就是表象上为什么事务数没有变,每秒执行的sql次数没有变,可是redo log却暴涨的原因了.因为每个事务变大了.但是由于是select操作,并没有真的作update,所以在statspack中很不容易看到明显的变化.
嗯,最后我想不通的是,oracle能确保在同一个事务中,多次读到的结果是一样的,为什么还要用for update nowait去锁定记录列.难道是sybase中带过来的习惯(sybase中如果想在一个事务中多次读到的结果一致,推荐这么干的.),当然了,这个是推测,无论如何,解决问题是最开心的.
5 Comments to “FOR UPDATE NOWAIT引起REDO LOG激增”
Write a comment
You need tologin.
Redo Layer 11, Opcode 4 = Lock Row Piece
还是老大分析的透彻,下次得好好和你学习学习这个原理问题了.
for update的话，如果有其他应用在访问那些记录
则会生成UNDO记录，UNDO本身会生成REDO
事实上,我们测试的时候,只有一个session进来,绝对干净的环境,也会产生和数据量大致相等的redo
所以,这个玩意还是别用了,害死人
这个周五我也遇到了这事....当时郁闷了...几秒种130M的redo.log满了。.后来加到了512…但是问题还是依然没有解决...后来强制结束了一些LOCK,问题才解决的..到现在也没怎么明白..不知道和你的情况是否一致.幸运的是那个时候业务基本都停了..
Checkpoint not complete
Current log# 10 seq# 16578 mem# 0: /u01/app/oracle/oradata/orcl/redo10.log
Thu Jun 7 18:54:42 2007
Thread 1 advanced to log sequence 16579
Current log# 11 seq# 16579 mem# 0: /u01/app/oracle/oradata/orcl/redo11.log
Thu Jun 7 18:54:42 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 18:54:42 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 18:55:14 2007
Thread 1 cannot allocate new log, sequence 16580
Checkpoint not complete
Current log# 11 seq# 16579 mem# 0: /u01/app/oracle/oradata/orcl/redo11.log
Thu Jun 7 18:56:46 2007
Thread 1 advanced to Current log# 7 seq# 16580 mem# 0: /u01/app/oracle/oradata/orcl/redo7.log
Thu Jun 7 18:57:11 2007
Thread 1 cannot allocate new log, sequence 16581
Checkpoint not complete
Current log# 7 seq# 16580 mem# 0: /u01/app/oracle/oradata/orcl/redo7.log
Thu Jun 7 19:02:00 2007
Thread 1 advanced to log sequence 16581
Current log# 8 seq# 16581 mem# 0: /u01/app/oracle/oradata/orcl/redo8.log
Thu Jun 7 19:02:00 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:02:00 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:02:00 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:02:00 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:02:00 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:02:00 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:02:00 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:02:00 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:02:00 WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:02:00 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:02:13 2007
Thread 1 cannot allocate new log, sequence 16582
Checkpoint not complete
Current log# 8 seq# 16581 mem# 0: /u01/app/oracle/oradata/orcl/redo8.log
Thu Jun 7 19:06:29 2007
Thread 1 advanced to log sequence 16582
Current log# 9 seq# 16582 mem# 0: /u01/app/oracle/oradata/orcl/redo9.log
Thu Jun 7 19:06:40 2007
Thread 1 cannot allocate new log, sequence 16583
Checkpoint not complete
Current log# 9 seq# 16582 mem# 0: /u01/app/oracle/oradata/orcl/redo9.log
Thu Jun 7 19:10:26 2007
Thread 1 advanced to log sequence 16583
Current log# 10 seq# 16583 mem# 0: /u01/app/oracle/oradata/orcl/redo10.log
Thu Jun 7 19:10:26 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:10:26 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:10:26 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:10:26 2007
WAThu Jun 7 19:10:26 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:10:26 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:10:26 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:10:26 2007
WARNING: inbound connection timed out (ORA-3136)
Thu Jun 7 19:10:37 2007
Thread 1 cannot allocate new log, sequence 16584
Checkpoint not complete
Current log# 10 seq# 16583 mem# 0: /u01/app/oracle/oradata/orcl/redo10.log
Thu Jun 7 19:14:55 2007
Thread 1 advanced to log sequence 16584
Current log# 11 seq# 16584 mem# 0: /u01/app/oracle/oradata/orcl/redo11.log
Thu Jun 7 19:15:21 2007
Thread 1 cannot allocate new log, sequence 16585
Checkpoint not complete
Current log# 11 seq# 16584 mem# 0: /u01/app/oracle/oradata/orcl/redo11.log
Thu Jun 7 19:16:39 2007
Thread 1 advanced to log sequence 16585
Current log# 7 seq# 16585 mem# 0: /u01/app/oracle/oradata/orcl/redo7.log
Thu Jun 7 19:17:01 2007
Thread 1 cannot allocate new log, sequence 1658Checkpoint not complete
Current log# 7 seq# 16585 mem# 0: /u01/app/oracle/oradata/orcl/redo7.log
Thu Jun 7 19:17:33 2007
Thread 1 advanced to log sequence 16586
Current log# 8 seq# 16586 mem# 0: /u01/app/oracle/oradata/orcl/redo8.log