| << Back to previous view |
|
[QA-63] ORA-600 [3020] on the standby after adding a datafile on primary Created: 16/Feb/18 Updated: 16/Feb/18 |
|
| Status: | Closed |
| Project: | Questions & Answers |
| Fix Version/s: | None |
| Type: | Oracle - Internals | Priority: | Major |
| Reporter: | ubTools Support | Assignee: | ubTools Support |
| Resolution: | Answered | Votes: | 0 |
| Product Version: | 11.2.0.4 |
| Operating System: | Linux |
| Host Name: | . |
| Database Name: | . |
| Description |
|
Problem:
The customer has added a datafile on the primary database. After the datafile was created on the standby database, ORA-600 [3020] was encountered while applying an archivelog to this datafile on standby. ORA-600 [3020]: This is called a 'STUCK RECOVERY'. There is an inconsistency between the information stored in the redo and the information stored in a database block being recovered. Ref: Doc ID 30866.1 |
| Comments |
| Comment by ubTools Support [ 16/Feb/18 10:36 AM ] |
|
PROBLEM OCCURRENCE:
Adding datafile on the Primary: Tue Feb 13 07:44:52 2018 ALTER TABLESPACE MENKUL2018_DATA ADD DATAFILE '/orassd/orcl/datafile/menkul2018_data02.dbf' SIZE 5G AUTOEXTEND ON NEXT 100M MAXSIZE UNLIMITED Completed: ALTER TABLESPACE MENKUL2018_DATA ADD DATAFILE '/orassd/orcl/datafile/menkul2018_data02.dbf' SIZE 5G AUTOEXTEND ON NEXT 100M MAXSIZE UNLIMITED Tue Feb 13 07:45:38 2018 Applying Archivelogs on the Standby: Tue Feb 13 07:46:55 2018 ALTER DATABASE RECOVER AUTOMATIC STANDBY DATABASE UNTIL CHANGE 69358633799 Media Recovery Start started logmerger process Tue Feb 13 07:46:55 2018 Managed Standby Recovery not using Real Time Apply Parallel Media Recovery started with 24 slaves Media Recovery Log /u01/ORCL/archive/52b86b9a_1_91417_922239972.arc Tue Feb 13 07:47:07 2018 Successfully added datafile 232 to media recovery Datafile #232: '/u01/oracle/app/oradata/ORCL/datafile/ORCL_STBY/datafile/o1_mf_menkul20_f84vg0lt_.dbf' Incomplete Recovery applied until change 69358633799 time 02/13/2018 07:45:38 Tue Feb 13 07:47:08 2018 Media Recovery Complete (ORCL) Completed: ALTER DATABASE RECOVER AUTOMATIC STANDBY DATABASE UNTIL CHANGE 69358633799 ..... Tue Feb 13 08:26:55 2018 ALTER DATABASE RECOVER AUTOMATIC STANDBY DATABASE UNTIL CHANGE 69358697423 Media Recovery Start started logmerger process Tue Feb 13 08:26:55 2018 Managed Standby Recovery not using Real Time Apply Parallel Media Recovery started with 24 slaves Media Recovery Log /u01/ORCL/archive/52b86b9a_1_91425_922239972.arc Tue Feb 13 08:26:57 2018 Errors in file /u01/oracle/app/diag/rdbms/orcl_stby/ORCL/trace/ORCL_pr0i_21945.trc (incident=131897): ORA-00600: internal error code, arguments: [3020], [232], [3], [973078531], [], [], [], [], [], [], [], [] ORA-10567: Redo is inconsistent with data block (file# 232, block# 3, file offset is 24576 bytes) ORA-10564: tablespace MENKUL2018_DATA ORA-01110: data file 232: '/u01/oracle/app/oradata/ORCL/datafile/ORCL_STBY/datafile/o1_mf_menkul20_f84vg0lt_.dbf' ORA-10560: block type '0' Incident details in: /u01/oracle/app/diag/rdbms/orcl_stby/ORCL/incident/incdir_131897/ORCL_pr0i_21945_i131897.trc Tue Feb 13 08:26:59 2018 |
| Comment by ubTools Support [ 16/Feb/18 11:06 AM ] |
|
ANALYSIS of the RESULT: Ref: ORCL_pr0i_21945.trc Data: REDO Dump: KCOX_FUTURE: CHANGE IN FUTURE OF BLOCK *** 2018-02-13 08:26:56.826 RECOVERY STUCK AT BLOCK 3 OF FILE 232 Redo record scn: 0x0010.2619b07d CHANGE #1 TYP:0 CLS:12 AFN:232 DBA:0x3a000003 OBJ:4294967295 SCN:0x0010.2618c0fb SEQ:2 OP:22.5 ENC:0 RBL:0 Buffer read during recovery: ..... The stuck recovery happened at file#232 block#3 with KCOX_FUTURE: CHANGE IN FUTURE OF BLOCK information. Block Dump: buffer tsn: 141 rdba: 0x3a000003 (232/3) scn: 0x0000.00000000 seq: 0x01 flg: 0x05 tail: 0x00000001 frmt: 0x02 chkval: 0x9d03 type: 0x00=unknown on-disk scn: 0x0.0 SCN is 0, type is unknown. flg is 0x05: Where flg: 0x05 contains flag 0x1 (unused,unformatted block). Ref: Oracle Doc ID 17896895.8 Comment: The change vector was expecting SCN:0x0010.2618c0fb on the block. But, the SCN on the block was 0x0000.00000000. Oracle was trying to apply archivelog to an unformatted block. REDO in archivelog is beyond block in datafile. This inconsistency causes stuck recovery. |
| Comment by ubTools Support [ 16/Feb/18 12:12 PM ] |
|
ANALYSIS of the ROOT CAUSE:
Data: The datafile has been created at sequence#91417 and the problem happened at sequence#91425 at file#232 block#3. REDO Dump Commands: SQL> ALTER SYSTEM dump logfile '/u01/ORCL/archive/52b86b9a_1_91417_922239972.arc' dba min 232 3 dba max 232 3; System altered. SQL> ALTER SYSTEM dump logfile '/u01/ORCL/archive/52b86b9a_1_91418_922239972.arc' dba min 232 3 dba max 232 3; System altered. SQL> ALTER SYSTEM dump logfile '/u01/ORCL/archive/52b86b9a_1_91419_922239972.arc' dba min 232 3 dba max 232 3; System altered. SQL> ALTER SYSTEM dump logfile '/u01/ORCL/archive/52b86b9a_1_91420_922239972.arc' dba min 232 3 dba max 232 3; System altered. SQL> ALTER SYSTEM dump logfile '/u01/ORCL/archive/52b86b9a_1_91421_922239972.arc' dba min 232 3 dba max 232 3; System altered. SQL> ALTER SYSTEM dump logfile '/u01/ORCL/archive/52b86b9a_1_91422_922239972.arc' dba min 232 3 dba max 232 3; System altered. SQL> ALTER SYSTEM dump logfile '/u01/ORCL/archive/52b86b9a_1_91423_922239972.arc' dba min 232 3 dba max 232 3; System altered. SQL> ALTER SYSTEM dump logfile '/u01/ORCL/archive/52b86b9a_1_91424_922239972.arc' dba min 232 3 dba max 232 3; System altered. SQL> ALTER SYSTEM dump logfile '/u01/ORCL/archive/52b86b9a_1_91425_922239972.arc' dba min 232 3 dba max 232 3; System altered. SQL> REDO Dumps: DUMP OF REDO FROM FILE '/u01/ORCL/archive/52b86b9a_1_91417_922239972.arc' ..... REDO RECORD - Thread:1 RBA: 0x016519.00000765.01e8 LEN: 0x0058 VLD: 0x01 SCN: 0x0010.2618c0fb SUBSCN: 1 02/13/2018 07:44:59 (LWN RBA: 0x016519.00000763.0010 LEN: 0004 NST: 0002 SCN: 0x0010.2618c0f9) CHANGE #1 TYP:1 CLS:12 AFN:232 DBA:0x3a000003 OBJ:4294967295 SCN:0x0010.2618c0fb SEQ:1 OP:22.4 ENC:0 RBL:0 ktfbbfo - File BitMap Block Format: BitMap Control: RelFno: 232, BeginBlock: 128, Flag: 0, First: 0, Free: 63488 REDO RECORD - Thread:1 RBA: 0x016519.00000763.0010 LEN: 0x0244 VLD: 0x05 SCN: 0x0010.2618c0fb SUBSCN: 1 02/13/2018 07:44:59 CHANGE #1 TYP:0 CLS:69 AFN:3 DBA:0x00c018c0 OBJ:4294967295 SCN:0x0010.2618c0ee SEQ:1 OP:5.4 ENC:0 RBL:0 ktucm redo: slt: 0x0007 sqn: 0x000060e7 srt: 0 sta: 9 flg: 0x2 ktucf redo: uba: 0x3000319f.07d5.06 ext: 2 spc: 7334 fbi: 0 CHANGE #2 MEDIA RECOVERY MARKER SCN:0x0000.00000000 SEQ:0 OP:17.30 ENC:0 Add datafiles to tablespace #141 file #232 relative file #232. '/orassd/orcl/datafile/menkul2018_data02.dbf' flags(reuse): 0x0 Checkpointed at scn: 0x0010.2618c0f0 02/13/2018 07:44:56 ..... DUMP OF REDO FROM FILE '/u01/ORCL/archive/52b86b9a_1_91425_922239972.arc' ..... REDO RECORD - Thread:1 RBA: 0x016521.0001a022.0034 LEN: 0x0040 VLD: 0x01 SCN: 0x0010.2619b07d SUBSCN: 14 02/13/2018 08:23:51 (LWN RBA: 0x016521.00019dca.0010 LEN: 1012 NST: 0002 SCN: 0x0010.2619b069) CHANGE #1 TYP:0 CLS:12 AFN:232 DBA:0x3a000003 OBJ:4294967295 SCN:0x0010.2618c0fb SEQ:2 OP:22.5 ENC:0 RBL:0 ktfbbredo - File BitMap Block Redo: Use Bits: Comment: The datafile has been created at sequence#91417 by REDO OP code 17.30, which means: the OP:17.30 redo which adds the <file#> datafile Ref: Oracle Doc ID 27229389.8 There are some other OP codes 22.4 and 5.4 before adding the datafile. Change Vector for OP Code 22:4: It tries to change absolute file#232 (AFN:232 DBA:0x3a000003). This is the problem that Oracle tries to apply a change vector to a file which was not created yet. Change Vector for OP Code 5:4: It tries to change absolute file#3 (AFN:3 DBA:0x00c018c0). This is a different file. So, it's out of the scope. |
| Comment by ubTools Support [ 16/Feb/18 12:26 PM ] |
|
SOLUTION:
Problem: Oracle tries to apply archivelog to a file which was not created on standby yet. Fix: This is Oracle bug 27229389. Workaround: Copy datafile from primary to standby that doesn't require corrupted archivelogs. |