4 Replies Latest reply: Feb 14, 2011 9:51 AM by 562201 RSS

    db block recovery

    562201
      hi all ;

      i have 10.2.0.2 runs on Redhat 5 .
      2 days ago our application throw error to connect to DB. i search time this time on alert log and i saw ,

      WARNING: inbound connection timed out (ORA-3136)

      and block recovery errors ;

      here is my alert_log at this time ;

      WARNING: inbound connection timed out (ORA-3136)
      Fri Feb 11 22:03:07 2011
      Recovery of Online Redo Log: Thread 1 Group 4 Seq 9406 Reading mem 0
      Mem# 0 errs 0: /ORCL/oracle/oradata/ORCL/redo4_01.dbf
      Mem# 1 errs 0: /ORCL/oracle/oradata/ORCL/redo4_02.dbf
      Block recovery completed at rba 9406.14747.16, scn 41.3352600731
      DEBUG: Restoring block headers for xcb 0x935f2228, pmd 0x926091ac
      DEBUG: Finished replay for xcb 0x935f2228, pmd 0x926091ac for failed op 8
      Fri Feb 11 22:03:49 2011
      DEBUG: Replaying xcb 0x9366b3d0, pmd 0x926091ac for failed op 8
      Reconstructing Uhdr 0x8000b1 for xcb 0x9366b3d0, pmd 0x926091ac
      Doing block recovery for file 2 block 177
      Fri Feb 11 22:03:54 2011
      Flush retried for xcb 0x93487c94, pmd 0x92619dc0
      DEBUG: Restoring block headers for xcb 0x93487c94, pmd 0x92619dc0
      Fri Feb 11 22:03:57 2011
      DEBUG: Replaying xcb 0x9366b3d0, pmd 0x926091ac for failed op 8
      Reconstructing Uhdr 0x8000b1 for xcb 0x9366b3d0, pmd 0x926091ac
      Doing block recovery for file 2 block 177
      Fri Feb 11 22:04:04 2011
      WARNING: inbound connection timed out (ORA-3136)
      Fri Feb 11 22:04:04 2011
      Block recovery from logseq 9405, block 147006 to scn 179446261828
      Fri Feb 11 22:04:04 2011
      Recovery of Online Redo Log: Thread 1 Group 2 Seq 9405 Reading mem 0
      Mem# 0 errs 0: /ORCL/oracle/oradata/ORCL/redo2_01.dbf
      Mem# 1 errs 0: /ORCL/oracle/oradata/ORCL/redo2_02.dbf
      Fri Feb 11 22:04:04 2011
      Recovery of Online Redo Log: Thread 1 Group 4 Seq 9406 Reading mem 0
      Mem# 0 errs 0: /ORCL/oracle/oradata/ORCL/redo4_01.dbf
      Mem# 1 errs 0: /ORCL/oracle/oradata/ORCL/redo4_02.dbf
      Block recovery completed at rba 9406.39203.16, scn 41.3352602694
      DEBUG: Restoring block headers for xcb 0x9366b3d0, pmd 0x926091ac
      Fri Feb 11 22:04:22 2011
      DEBUG: Finished replay for xcb 0x9366b3d0, pmd 0x926091ac for failed op 8
      Fri Feb 11 22:06:08 2011
      DEBUG: Replaying xcb 0x9366c334, pmd 0x925d6d70 for failed op 8
      Reconstructing Uhdr 0x8000d1 for xcb 0x9366c334, pmd 0x925d6d70
      Doing block recovery for file 2 block 209
      Fri Feb 11 22:06:20 2011
      DEBUG: Replaying xcb 0x9366c334, pmd 0x925d6d70 for failed op 8
      Reconstructing Uhdr 0x8000d1 for xcb 0x9366c334, pmd 0x925d6d70
      Doing block recovery for file 2 block 209
      Block recovery from logseq 9405, block 147047 to scn 179446265088
      Fri Feb 11 22:06:28 2011
      Recovery of Online Redo Log: Thread 1 Group 2 Seq 9405 Reading mem 0
      Mem# 0 errs 0: /ORCL/oracle/oradata/ORCL/redo2_01.dbf
      Mem# 1 errs 0: /ORCL/oracle/oradata/ORCL/redo2_02.dbf
      Fri Feb 11 22:06:28 2011
      Recovery of Online Redo Log: Thread 1 Group 4 Seq 9406 Reading mem 0
      Mem# 0 errs 0: /ORCL/oracle/oradata/ORCL/redo4_01.dbf
      Mem# 1 errs 0: /ORCL/oracle/oradata/ORCL/redo4_02.dbf
      Block recovery completed at rba 9406.89181.16, scn 41.3352605953
      DEBUG: Restoring block headers for xcb 0x9366c334, pmd 0x925d6d70
      DEBUG: Finished replay for xcb 0x9366c334, pmd 0x925d6d70 for failed op 8
      Sat Feb 12 01:00:43 2011
      Thread 1 advanced to log sequence 9407
      Current log# 3 seq# 9407 mem# 0: /ORCL/oracle/oradata/ORCL/redo3_01.dbf
      Current log# 3 seq# 9407 mem# 1: /ORCL/oracle/oradata/ORCL/redo3_02.dbf
      Sat Feb 12 03:03:37 2011
      Thread 1 advanced to log sequence 9408
      Current log# 2 seq# 9408 mem# 0: /ORCL/oracle/oradata/ORCL/redo2_01.dbf
      Current log# 2 seq# 9408 mem# 1: /ORCL/oracle/oradata/ORCL/redo2_02.dbf
      Sat Feb 12 03:11:51 2011
      Thread 1 advanced to log sequence 9409
      Current log# 4 seq# 9409 mem# 0: /ORCL/oracle/oradata/ORCL/redo4_01.dbf
      Current log# 4 seq# 9409 mem# 1: /ORCL/oracle/oradata/ORCL/redo4_02.dbf
      Sat Feb 12 03:13:28 2011
      Starting control autobackup

      after 4 - 5 minutes from the start of block recovery our application able to connect to DB . and now there is no problem about block recovery ;

      i check te file 2 which is UNDO in my db with dbv and there is no error.



      DBVERIFY: Release 10.2.0.2.0 - Production on Mon Feb 14 15:51:40 2011

      Copyright (c) 1982, 2005, Oracle. All rights reserved.

      DBVERIFY - Verification starting : FILE = /ORCL/oracle/oradata/ORCL/UNDOTBS1_01.dbf


      DBVERIFY - Verification complete

      Total Pages Examined : 1090560
      Total Pages Processed (Data) : 0
      Total Pages Failing (Data) : 0
      Total Pages Processed (Index): 0
      Total Pages Failing (Index): 0
      Total Pages Processed (Other): 1090560
      Total Pages Processed (Seg) : 0
      Total Pages Failing (Seg) : 0
      Total Pages Empty : 0
      Total Pages Marked Corrupt : 0
      Total Pages Influx : 0
      Highest block SCN : 3812888519 (41.3812888519)



      i have 2 quesiton ?

      1- is this block recovery can be the root cause of error ORA-03136 ?

      2- now there is no error for my UNDO but i wonder what can be the root cause or causes of block recovery especially on UNDO tablespace generally ?

      thanks a lot ....

      Edited by: orakut on Feb 14, 2011 4:42 PM
        • 1. Re: db block recovery
          P.Forstmann
          1. ORA-3136 has nothing to with database storage but has to do with network connection between client and server (listener process or database server process when authenticating the user againt the database):
          $ oerr ora 3136
          03136, 00000, "inbound connection timed out"
          // *Cause:  Inbound connection was timed out by the server because
          //          user authentication was not completed within the given time
          //          specified by SQLNET.INBOUND_CONNECT_TIMEOUT or its default value
          // *Action: 1) Check SQL*NET and RDBMS log for trace of suspicious connections.
          //          2) Configure SQL*NET with a proper inbound connect timeout value
          //             if necessary.
          2. It seems that your database instance was doing some crash recovery or did you restore/recover database/tablespace/datafile ?
          You should post more data form alert log especially since instance startup if instance has just started before block recovery messages.

          Actually if undo tablespace was in recovery mode it is possible that there is a link between ORA-3136 and block recovery mode.

          Edited by: P. Forstmann on 14 févr. 2011 16:16

          Edited by: P. Forstmann on 14 févr. 2011 16:20

          Edited by: P. Forstmann on 14 févr. 2011 16:24
          • 2. Re: db block recovery
            562201
            i didn't make any restore/recover database/tablespace/datafile ?

            database was last started 4 days ago before the block recovery process .

            since the startup there is nothing on the alert log until the block recovery process .

            so you say that block recovery process doesnt cause the ORA-03136 errors ? am i right ?
            i wonder because it gives ORA-03136 error during block recovery . after or before the block recovery there is no ORA-03136 errors.


            thanks...
            • 3. Re: db block recovery
              Jonathan Lewis
              It looks like you've seen a variant on the problem I described in a recent blog and which someone then reported seeing in their system: http://jonathanlewis.wordpress.com/2010/12/31/quiz-night-11/#comment-39469

              Oracle has been able to recover corrupt blocks in "real-time" for many years - but it looks like you got some corrupt blocks in your undo tablespace (undo segment headers, specifically) that needed to be recovered. It's quite possible that the connection timeouts were a side-effect of this if Oracle was (for example) trying to do something like block cleanout on blocks in the aud$ table during connection.


              Regards
              Jonathan Lewis
              http://jonathanlewis.wordpress.com
              http://www.jlcomp.demon.co.uk

              A general reminder about "Forum Etiquette / Reward Points": http://forums.oracle.com/forums/ann.jspa?annID=718

              If you never mark your questions as answered people will eventually decide that it's not worth trying to answer you because they will never know whether or not their answer has been of any use, or whether you even bothered to read it.

              It is also important to mark answers that you thought helpful - again it lets other people know that you appreciate their help, but it also acts as a pointer for other people when they are researching the same question, moreover it means that when you mark a bad or wrong answer as helpful someone may be prompted to tell you (and the rest of the forum) what's so bad or wrong about the answer you found helpful.
              • 4. Re: db block recovery
                562201
                thanks a lot. you clear my mind that you say ;

                " It's quite possible that the connection timeouts were a side-effect of this if Oracle was (for example) trying to do something like block cleanout on blocks in the aud$ table during connection.
                "