系统环境：
操作系统：Linux RH55
Oracle： Oracle 11gR2
模拟案例：
1、查看数据库模式
18:12:36 SYS@ prod>archive log list;
Database log mode No Archive Mode
Automatic archival Disabled
Archive destination /dsk4/arch1
Oldest online log sequence 1
Current log sequence 3
2、创建新的Tablespace
|
1
2
3
|
18
:
13
:
19
SYS@ prod>create tablespace tbs2
18
:
13
:
30
2
datafile
'/u01/app/oracle/oradata/prod/tbs2.dbf'
size 10m;
Tablespace created.
|
3、对数据库进行冷备
|
1
2
3
4
5
6
7
8
9
10
|
[oracle@rh6 ~]$ rman target /
Recovery Manager: Release
11.2.
0.1.
0
- Production
on
Thu Jul
24
18
:
14
:
30
2014
Copyright (c)
1982
,
2009
, Oracle
and
/
or
its affiliates. All rights reserved.
connected to target database: PROD (DBID=
239333010
)
RMAN> run {
2
> shutdown immediate;
3
> startup mount;
4
> backup database format
'/dsk3/bak/%s_%d.bak'
;
5
> alter database open;
6
> }
|
4、备份完成在新的Tablesapce上创建Object
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
|
18
:
19
:
40
SYS@ prod>conn scott/tiger
Connected.
18
:
30
:
13
SCOTT@ prod>create table t1 tablespace tbs2
as
select *
from
emp;
Table created.
Elapsed:
00
:
00
:
01.00
18
:
30
:
45
SCOTT@ prod>select count(*)
from
t1;
COUNT(*)
----------
14
Elapsed:
00
:
00
:
00.02
18
:
30
:
56
SCOTT@ prod>
insert
into
t1 select *
from
t1
where
rownum=
1
;
1
row created.
Elapsed:
00
:
00
:
00.02
18
:
31
:
16
SCOTT@ prod>commit;
Commit complete.
Elapsed:
00
:
00
:
00.04
18
:
31
:
18
SCOTT@ prod>
insert
into
t1 select *
from
t1
where
rownum=
1
;
1
row created.
Elapsed:
00
:
00
:
00.01
18
:
31
:
23
SCOTT@ prod>select count(*)
from
t1;
COUNT(*)
----------
16
|
5、查看Redo Log信息
|
1
2
3
4
5
6
7
|
18
:
32
:
14
SYS@ prod>select group#,sequence# ,status
from
v$log;
GROUP# SEQUENCE# STATUS
---------- ---------- ----------------
1
4
CURRENT
2
2
INACTIVE
3
3
INACTIVE
Elapsed:
00
:
00
:
00.05
|
6、模拟数据文件被破坏
[oracle@rh6 ~]$ rm /u01/app/oracle/oradata/prod/tbs2.dbf
18:32:28 SYS@ prod>shutdown abort
ORACLE instance shut down.
重新启动Instance到mount，查看redo log，日志没有发生switch
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
|
18
:
33
:
06
SYS@ prod>startup mount;
ORACLE instance started.
Total System Global Area
835104768
bytes
Fixed Size
2217952
bytes
Variable Size
775948320
bytes
Database Buffers
54525952
bytes
Redo Buffers
2412544
bytes
Database mounted.
18
:
33
:
42
SYS@ prod>select group#,sequence# ,status
from
v$log;
GROUP# SEQUENCE# STATUS
---------- ---------- ----------------
1
4
CURRENT
3
3
INACTIVE
2
2
INACTIVE
|
Open database出现数据文件丢失错误：
18:34:17 SYS@ prod>alter database open;
alter database open
*
ERROR at line 1:
ORA-01157: cannot identify/lock data file 9 - see DBWR trace file
ORA-01110: data file 9: '/u01/app/oracle/oradata/prod/tbs2.dbf'
7、对Database做Media Recovery（因为没有日志切换，做complete recover）
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
|
[oracle@rh6 ~]$ rman target /
Recovery Manager: Release
11.2.
0.1.
0
- Production
on
Thu Jul
24
18
:
34
:
35
2014
Copyright (c)
1982
,
2009
, Oracle
and
/
or
its affiliates. All rights reserved.
connected to target database: PROD (DBID=
239333010
,
not
open)
RMAN> restore datafile
9
;
Starting restore
at
24
-JUL
-14
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=
18
device type=DISK
channel ORA_DISK_1: starting datafile backup set restore
channel ORA_DISK_1: specifying datafile(s) to restore
from
backup set
channel ORA_DISK_1: restoring datafile
00009
to /u01/app/oracle/oradata/prod/tbs2.dbf
channel ORA_DISK_1: reading
from
backup piece /dsk3/bak/34_PROD.bak
channel ORA_DISK_1: piece handle=/dsk3/bak/34_PROD.bak tag=TAG20140724T181640
channel ORA_DISK_1: restored backup piece
1
channel ORA_DISK_1: restore complete, elapsed time:
00
:
00
:
01
Finished restore
at
24
-JUL
-14
RMAN> recover datafile
9
;
Starting recover
at
24
-JUL
-14
using channel ORA_DISK_1
starting media recovery
media recovery complete, elapsed time:
00
:
00
:
01
Finished recover
at
24
-JUL
-14
|
查看告警日志：
Thu Jul 24 18:34:49 2014
Full restore complete of datafile 9 /u01/app/oracle/oradata/prod/tbs2.dbf. Elapsed time: 0:00:00
checkpoint is 2168258
Thu Jul 24 18:34:57 2014
alter database recover datafile list clear
Completed: alter database recover datafile list clear
alter database recover if needed
datafile 9
Media Recovery Start
Serial Media Recovery started
Recovery of Online Redo Log: Thread 1 Group 3 Seq 3 Reading mem 0
Mem# 0: /dsk1/oradata/prod/redo03a.log
Mem# 1: /dsk2/oradata/prod/redo03b.log
Recovery of Online Redo Log: Thread 1 Group 1 Seq 4 Reading mem 0
Mem# 0: /dsk1/oradata/prod/redo01a.log
Mem# 1: /dsk2/oradata/prod/redo01b.log
Media Recovery Complete (prod)
Completed: alter database recover if needed
datafile 9
通过group1和3，进行了media recovery ！
8、数据库open，发现T1无法访问（出现：ORA-26040）
18:35:36 SYS@ prod>alter database open;
Database altered.
18:35:49 SYS@ prod>select count(*) from scott.t1;
select count(*) from scott.t1
*
ERROR at line 1:
ORA-01578: ORACLE data block corrupted (file # 9, block # 131)
ORA-01110: data file 9: '/u01/app/oracle/oradata/prod/tbs2.dbf'
ORA-26040: Data block was loaded using the NOLOGGING option
查看告警日志：
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
|
alter database open
Beginning crash recovery of
1
threads
Started redo scan
Completed redo scan
read
83
KB redo,
26
data blocks need recovery
Started redo application
at
Thread
1
: logseq
4
, block
117
Recovery of Online Redo Log: Thread
1
Group
1
Seq
4
Reading mem
0
Mem#
0
: /dsk1/oradata/prod/redo01a.log
Mem#
1
: /dsk2/oradata/prod/redo01b.log
Completed redo application of
0.
02MB
Completed crash recovery
at
Thread
1
: logseq
4
, block
284
, scn
2208986
26
data blocks read,
26
data blocks written,
83
redo k-bytes read
Thu Jul
24
18
:
35
:
45
2014
Thread
1
advanced to log sequence
5
(thread open)
Thread
1
opened
at
log sequence
5
Current log#
2
seq#
5
mem#
0
: /dsk1/oradata/prod/redo02a.log
Current log#
2
seq#
5
mem#
1
: /dsk2/oradata/prod/redo02b.log
Successful open of redo thread
1
MTTR advisory is disabled because FAST_START_MTTR_TARGET is
not
set
Thu Jul
24
18
:
35
:
45
2014
SMON: enabling cache recovery
Successfully onlined Undo Tablespace
5.
Verifying file header compatibility
for
11g tablespace encryption..
Verifying 11g file header compatibility
for
tablespace encryption completed
SMON: enabling tx recovery
Database Characterset is ZHS16GBK
No Resource Manager plan active
replication_dependency_tracking turned off (no async multimaster replication found)
Starting background process QMNC
Thu Jul
24
18
:
35
:
48
2014
QMNC started
with
pid=
20
, OS id=
13934
Completed: alter database open
Thu Jul
24
18
:
35
:
54
2014
Starting background process CJQ0
Thu Jul
24
18
:
35
:
54
2014
CJQ0 started
with
pid=
23
, OS id=
13946
Thu Jul
24
18
:
36
:
06
2014
Errors
in
file /u01/app/oracle/diag/rdbms/prod/prod/trace/prod_ora_13932.trc (incident=
139383
):
ORA
-01578
: ORACLE data block corrupted (file #
9
, block #
131
)
ORA
-01110
: data file
9
:
'/u01/app/oracle/oradata/prod/tbs2.dbf'
ORA
-26040
: Data block was loaded using the NOLOGGING option
Incident details
in
: /u01/app/oracle/diag/rdbms/prod/prod/incident/incdir_139383/prod_ora_13932_i139383.trc
Errors
in
file /u01/app/oracle/diag/rdbms/prod/prod/trace/prod_ora_13932.trc (incident=
139384
):
ORA
-01578
: ORACLE data block corrupted (file #
9
, block #
131
)
ORA
-01110
: data file
9
:
'/u01/app/oracle/oradata/prod/tbs2.dbf'
ORA
-26040
: Data block was loaded using the NOLOGGING option
Incident details
in
: /u01/app/oracle/diag/rdbms/prod/prod/incident/incdir_139384/prod_ora_13932_i139384.trc
Thu Jul
24
18
:
36
:
13
2014
Trace dumping is performing id=[cdmp_20140724183613]
Thu Jul
24
18
:
36
:
14
2014
Sweep [inc][
139384
]: completed
Sweep [inc][
139383
]: completed
Sweep [inc2][
139383
]: completed
Trace dumping is performing id=[cdmp_20140724183617]
Thu Jul
24
18
:
37
:
14
2014
Sweep [inc2][
139384
]: completed
|
9、通过DBV验证数据文件
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
|
[oracle@rh6 ~]$ dbv file=/u01/app/oracle/oradata/prod/tbs2.dbf blocksize=
8192
DBVERIFY: Release
11.2.
0.1.
0
- Production
on
Thu Jul
24
18
:
45
:
59
2014
Copyright (c)
1982
,
2009
, Oracle
and
/
or
its affiliates. All rights reserved.
DBVERIFY - Verification starting : FILE = /u01/app/oracle/oradata/prod/tbs2.dbf
DBV
-00201
: Block, DBA
37748867
, marked corrupt
for
invalid redo application
DBVERIFY - Verification complete
Total Pages Examined :
1280
Total Pages Processed (Data) :
4
Total Pages Failing (Data) :
0
Total Pages Processed (Index):
0
Total Pages Failing (Index):
0
Total Pages Processed (Other):
1274
Total Pages Processed (Seg) :
0
Total Pages Failing (Seg) :
0
Total Pages Empty :
2
Total Pages Marked Corrupt :
1
Total Pages Influx :
0
Total Pages Encrypted :
0
Highest block SCN :
2188961
(
0.2188961
)
|
在数据文件9上，出现了逻辑坏块 ！
10、转储数据块
14:35:48 SYS@ prod>alter system dump datafile 9 block 131;
System altered.
数据块转储信息：
[oracle@rh6 ~]$ cat /u01/app/oracle/diag/rdbms/prod/prod/trace/prod_ora_2822.trc|more
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
|
Trace file /u01/app/oracle/diag/rdbms/prod/prod/trace/prod_ora_2822.trc
Oracle Database 11g Enterprise Edition Release
11.2.
0.1.
0
- 64bit Production
With the Partitioning, OLAP, Data Mining
and
Real Application Testing options
ORACLE_HOME = /u01/app/oracle/product/
11.2.
0
/db_1
System name: Linux
Node name: rh6
Release:
2.6.
32
-358.
el6.x86_64
Version: #
1
SMP Tue Jan
29
11
:
47
:
41
EST
2013
Machine: x86_64
Instance name: prod
Redo thread mounted by
this
instance:
1
Oracle process number:
29
Unix process pid:
2822
, image: oracle@rh6 (TNS V1-V3)
***
2014
-07
-25
14
:
37
:
54.634
*** SESSION ID:(
28.16
)
2014
-07
-25
14
:
37
:
54.634
*** CLIENT ID:()
2014
-07
-25
14
:
37
:
54.634
*** SERVICE NAME:(SYS$USERS)
2014
-07
-25
14
:
37
:
54.634
*** MODULE NAME:(sqlplus@rh6 (TNS V1-V3))
2014
-07
-25
14
:
37
:
54.634
*** ACTION NAME:()
2014
-07
-25
14
:
37
:
54.634
|
Start dump data blocks tsn: 9 file#:9 minblk 131 maxblk 131
Block dump from cache:
Dump of buffer cache at level 4 for tsn=9, rdba=37748867
Block dump from disk:
buffer tsn: 9 rdba: 0x02400083 (9/131)
scn: 0x0000.00216666 seq: 0xff flg: 0x04 tail: 0x666600ff
frmt: 0x02 chkval: 0xa4e2 type: 0x00=unknown
Hex dump of block: st=0, typ_found=0
Dump of memory from 0x00007FDEF186CA00 to 0x00007FDEF186EA00
7FDEF186CA00 0000A200 02400083 00216666 04FF0000 [......@.ff!.....]
7FDEF186CA10 0000A4E2 FFFFFFFF FFFFFFFF FFFFFFFF [................]
7FDEF186CA20 FFFFFFFF FFFFFFFF FFFFFFFF FFFFFFFF [................]
Repeat 508 times
7FDEF186E9F0 FFFFFFFF FFFFFFFF FFFFFFFF 666600FF [..............ff]
End dump data blocks tsn: 9 file#: 9 minblk 131 maxblk 131
----可以看出block 131除了头部信息外，剩下的都是‘FFFFFFFF’，应该是一个逻辑坏块！
11、转储对应的logfile
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
|
14
:
35
:
48
SYS@ prod>alter system dump logfile
'/dsk1/oradata/prod/redo01a.log'
；
System altered.
14
:
35
:
53
SYS@ prod>alter system dump logfile
'/dsk1/oradata/prod/redo03a.log'
；
System altered.
[oracle@rh6 ~]$ cat /u01/app/oracle/diag/rdbms/prod/prod/trace/prod_ora_2406.trc
DUMP OF REDO FROM FILE
'/dsk1/oradata/prod/redo01a.log'
Opcodes *.*
RBAs:
0x000000.
00000000.0000
thru
0xffffffff.
ffffffff.ffff
SCNs: scn:
0x0000.
00000000
thru scn:
0xffff.
ffffffff
Times: creation thru eternity
FILE HEADER:
Compatibility Vsn =
186646528
=
0xb200000
Db ID=
239333010
=
0xe43ee92
, Db Name=
'PROD'
Activation ID=
264808982
=
0xfc8aa16
Control Seq=
2747
=
0xabb
, File size=
102400
=
0x19000
File
Number
=
1
, Blksiz=
512
, File Type=
2
LOG
descrip:
"Thread 0001, Seq# 0000000004, SCN 0x000000216562-0x00000021b4dc"
thread:
1
nab:
0x11c
seq:
0x00000004
hws:
0x6
eot:
0
dis:
0
resetlogs count:
0x32d7d50e
scn:
0x0000.
00206c24 (
2124836
)
prev resetlogs count:
0x32d7cc14
scn:
0x0000.
0020680f (
2123791
)
Low scn:
0x0000.
00216562
(
2188642
)
07
/
24
/
2014
18
:
27
:
42
Next scn:
0x0000.
0021b4dc (
2208988
)
07
/
24
/
2014
18
:
35
:
45
Enabled scn:
0x0000.
00206c24 (
2124836
)
07
/
15
/
2014
17
:
59
:
42
Thread closed scn:
0x0000.
0021b4da (
2208986
)
07
/
24
/
2014
18
:
33
:
04
Disk cksum:
0x1af0
Calc cksum:
0x1af0
Terminal recovery stop scn:
0x0000.
00000000
Terminal recovery
01
/
01
/
1988
00
:
00
:
00
Most recent redo scn:
0x0000.
00000000
Largest LWN:
0
blocks
End-of-redo stream : No
Unprotected mode
Miscellaneous flags:
0x800000
Thread internal enable indicator: thr:
0
, seq:
0
scn:
0x0000.
00000000
|
REDO RECORD - Thread:1 RBA: 0x000004.000000c6.0198 LEN: 0x0034 VLD: 0x01
SCN: 0x0000.00216666 SUBSCN: 1 07/24/2014 18:30:45
CHANGE #1 INVLD AFN:9 DBA:0x02400083 BLKS:0x0001 OBJ:75139 SCN:0x0000.00216666 SEQ:1 OP:19.2 ENC:0
Direct Loader invalidate block range redo entry
REDO RECORD - Thread:1 RBA: 0x000006.000007b6.0110 LEN: 0x0034 VLD: 0x01
SCN: 0x0000.00220ad0 SUBSCN: 1 07/25/2014 14:22:51
CHANGE #1 INVLD AFN:2 DBA:0x0080f09c BLKS:0x0001 OBJ:6214 SCN:0x0000.00220ad0 SEQ:1 OP:19.2 ENC:0
Direct Loader invalidate block range redo entry
-在redo日志里记录了“Direct Loader”的动作（OBJ:75139，OBJ:6214）
查看对应的对象：
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
|
14
:
29
:
23
SYS@ prod>select owner,object_id,object_name
from
dba_objects
15
:
18
:
47
2
where
object_id=
75139
;
OWNER OBJECT_ID OBJECT_NAME
------------------------------ ---------- --------------------
SCOTT
75139
T1
Elapsed:
00
:
00
:
00.04
15
:
18
:
51
SYS@ prod>select owner,object_id,object_name
from
dba_objects
15
:
18
:
58
2
where
object_id=
6214
;
OWNER OBJECT_ID OBJECT_NAME
------------------------------ ---------- --------------------
SYS
6214
SYS_LOB0000006213C00
038
$$
Elapsed:
00
:
00
:
00.05
15
:
19
:
07
SYS@ prod>
|
从以上，查看信息可以推断，在Media Recover阶段，create table T1 as select * from 采用了“Direct Loader”，在非归档下应该是采用了‘nologging’方式，以致后续的Insert的数据通过redo log无法被恢复，导致出现逻辑坏块！
备注：（借鉴Maclean Liu博客观点）
http://www.askmaclean.com/archives/nologging-unrecoverable.html
【数据恢复】NOLOGGING UNRECOVERABLE ORA-26040解析
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
|
SQL> select count(*)
from
abc;select count(*)
from
abc*第
1
行出现错误:ORA
-01578
: ORACLE 数据块损坏 (文件号
17
, 块号
131
)ORA
-01110
: 数据文件
17
:‘C:\APP\XIANGBLI\ORADATA\MACLEAN\DATAFILE\O1_MF_NLOGGING_9475OCS5_.DBF’ORA
-26040
: 数据块是使用 NOLOGGING 选项加载的
SQL> select UNRECOVERABLE_CHANGE# , UNRECOVERABLE_time
from
v$datafile
where
file#=
17
;
UNRECOVERABLE_CHANGE# UNRECOVERABLE_——————— ————–
6486756
26
-9
月
-13
把 (文件号
17
, 块号
131
) dump出来看一下
***
2013
-09
-26
10
:
07
:
46.
584Start dump data blocks tsn:
17
file#:
17
minblk
131
maxblk 131Block dump
from
cache:Dump of buffer cache
at
level
4
for
pdb=
0
tsn=
17
rdba=71303299Block dump
from
disk:buffer tsn:
17
rdba:
0
×
04400083
(
17
/
131
)scn:
0
×
0.
62faac seq:
0xff
flg:
0
×
04
tail: 0xfaac00fffrmt:
0
×
02
chkval:
0xa2a1
type:
0
×
00
=unknownHex dump of block: st=
0
, typ_found=0Dump of memory
from
0x000000000BFF2200
to
0x000000000BFF420000BFF2200
0000A200
04400083
0062FAAC 04FF0000 [......@...b.....]00BFF2210 0000A2A1 FFFFFFFF FFFFFFFF FFFFFFFF [................]00BFF2220 FFFFFFFF FFFFFFFF FFFFFFFF FFFFFFFF [................]Repeat
508
times00BFF41F0 FFFFFFFF FFFFFFFF FFFFFFFF FAAC00FF [................]End dump data blocks tsn:
17
file#:
17
minblk
131
maxblk
131
scn:
0
×
0.
62faac seq:
0xff
==》 对应的SCN为
6486700
，可以看到内容除了头部一点外 全是
0XFF
dump 对应redo logfile 可以看到
REDO RECORD – Thread:
1
RBA:
0
×
000074.00015418.
0078
LEN:
0x003c
VLD:
0
×
01
CON_UID: 0SCN:
0
×
0000.
0062faac SUBSCN:
1
09
/
26
/
2013
10
:
04
:39CHANGE #
1
INVLD CON_ID:
0
AFN:
17
DBA:
0
×
04400083
BLKS:
0x000d
OBJ:
123054
SCN:
0
×
0000.
0062faac SEQ:
1
OP:
19.2
ENC:0Direct Loader invalidate block range redo entry
OP:
19.2
=》Layer
19
: Direct Loader Log Blocks – KCOCODLB Opcode
2
: Invalidate range – KCBLCOIR
==》这里在redo里标记了 直接路径加载造成块失效的范围，在redo logfile dump中可以看到大量类似数据
即当recover时读取redo，读到“Direct Loader invalidate block range redo entry”信息时，则将对应的数据块的内容除了kcbh头部外全部记录为
0XFF
当Oracle读取到这些块时就会知道这些块是SOFT Corrupt ，原因是nologging造成的。
Block is marked
as
SOFT Corrupt
and
has
0xff
along the block. This is theformat used by Oracle to mark a block
as
corrupt due to redo invalidation(NOLOGGING).NOLOGGING OPERATION
in
redo:
|
