“Cross Instance call Enqueue”是一种在一个或多个instance实例间调用后台进程行为时用到的队列锁,具体调用的后台进程行为包括检查点checkpoint、日志切换logfile switch、shutdown实例、载入数据文件头等等。需要注意的是这种Enqueue Lock并不仅仅在RAC中使用,即便是单节点也会用到。CI锁的数量取决于并行执行Cross Instance Call调用的进程的总数。
SQL> col ksqsttyp for a20 SQL> col ksqstrsn for a20 SQL> col ksqstexpl for a80 SQL> set linesize 200 pagesize 2000; SQL> select ksqsttyp,ksqstrsn,ksqstexpl from x$ksqst where ksqsttyp='CI'; KSQSTTYP KSQSTRSN KSQSTEXPL -------------------- -------------------- -------------------------------------------------------------------------------- CI contention Coordinates cross-instance function invocations SQL> show parameter cluster_database NAME TYPE VALUE ------------------------------------ ----------- ------------------------------ cluster_database boolean FALSE cluster_database_instances integer 1 SQL> select * from v$enqueue_stat where eq_type='CI'; INST_ID EQ TOTAL_REQ# TOTAL_WAIT# SUCC_REQ# FAILED_REQ# CUM_WAIT_TIME ---------- -- ---------- ----------- ---------- ----------- ------------- 1 CI 595 0 595 0 0
当系统中出现有大量这种跨实例后台进程调用时,将出现CI队列锁的争用。假设在一个RAC场景中,同时有大量的回话开始对不同的数据表执行TRUNCATE截断操作,TRUNCATE的一个前提是在所有实例上(因为对象表的dirty buffer可能分布在多个实例上)发生对象级别的检查点(object level checkpoint),检查点发生时CKPT进程会通知DBWR写出指定对象表相关的脏块,DBWR需要扫描Buffer Cache以找出脏块,而如果Buffer Cache很大那么扫描将花费大量的时间,而在此过程中前台进程将一直排他地持有着本地的CI队列锁,这就将造成CI锁的严重争用。
为了减少CI队列锁地争用,我们第一步所要做的是找出实际的Cross Instance call跨实例调用的类型。这里要另外提一下的是在10g以前不管是v$session_wait或statspack中都不会将enqueue锁等待事件的具体enqueue lock类型写明,一般需要我们从p1/p2/p3列中找出enqueue的具体身份,例如”WAIT #1: nam=’enqueue’ ela= 910796 p1=1128857606 p2=1 p3=4″,这里的p1为1128857606也就是16进制的43490006,高位的’4349’转换为ascii码也就是’CI’,而这里的p2/p3对应为V$lock中的ID1/ID2,ID1=1代表了”Reuse (checkpoint and invalidate) block range”,ID2=4代表了”Mounted excl, use to allocate mechanism”。
具体ID1/ID2代表的含义在不同版本中有所变化,可以参考下表:
Id1, Id2 Combination:
Oracle 10gR1
27 TO 29 *Same as 9i R2
30 process waiters after row cache requeue
31 Active Change Directory extent relocation
32 block change tracking state change
33 kgl mulitversion obsolete
34 set previous resetlogs data
35 set recovery destination pointer
36 fast object reuse request
37 test ksbcic()
38 ASM diskgroup discovery wait
39 ASM diskgroup release
40 ASM push DB updates
41 ASM add ACD chunk
42 ASM map resize message
43 ASM map lock message
44 ASM map unlock message (phase 1)
45 ASM map unlock message (phase 2)
46 ASM generate add disk redo marker
47 ASM check of PST validity
48 ASM offline disk CIC
49 Logical Standby Sync Point SCN
50 update SQL Tuning Base existence bitvector
51 PQ induced Checkpointing
52 ASM F1X0 relocation
53 Scheduler autostart
54 KZS increment grant/revoke counter
55 ASM disk operation message
56 ASM I/O error emulation
57 DB Supp log cursor invalidation
58 Cache global range invalidation
59 Cache global object invalidation
60 ASM Pre-Existing Extent Lock wait
61 Perform a ksk action through DBWR
62 ASM diskgroup refresh wait
Oracle 10gR2
30 to 62 *Same as 10gR1
63 KCBO object checkpoint
64 KCBO object pq checkpoint
65 global health check event
66 Oracle Label Security refresh
67 thread internal enable
68 cross-instance registration
69 KGL purge unused subheaps
70 clear pin instance flag
71 Rolling operations CIC
Oracle 9iR2
Id1 Meaning
~~~ ~~~~~~
25 TO 26 *Same as 9i R1
27 set Database Force Logging mode
28 invalidate cached file address translations
29 Cursor Unauthorize Mode
30 snapshot too old diagnosis
31 process waiters after row cache requeue
Oracle 9iR1
Id1 Meaning
~~~ ~~~~~~~~
18 TO 24 *Same as Oracle 8i
25 Update Dscn Tracking (ktcndt)
26 Purge dictionary Object number Cache
Oracle 8i
Id1 Meaning
~~~ ~~~~~~~
0 TO 17 *Same as Oracle 8(please see "Oracle8*" for the Meaning)
18 Object reuse request
19 Rolling release checks
20 Propagate begin backup scn for a file
21 Refresh top plan (for db scheduler)
22 Clear checkpoint progress record
23 Drop temp file
24 Quiesce database Restricted
Id2 Meaning
~~~ ~~~~~~~
0x01 Used to pass in parameters
0x02 Used to invoke the function in backgroud process
0x03 Used to indicate the foreground has not returned
0x04 Mounted excl, use to allocate mechanism
0x05 Used to queue up interested clients
Oracle 8*
Id1 Meaning
~~~ ~~~~~~~
0 Checkpoint block range
1 Reuse (checkpoint and invalidate) block range
2 LGWR Checkpointing and Hot Backup
3 DBWR syncronization of SGA with control file
4 Log file add/drop/rename notification
5 Write buffer for CR read
6 Test call
7 Invalidate KCK cache in all instances
8 Alter rollback segment optimal
9 Signal Query Servers/coordinator
10 Create Remote parallel query Server
11 Set Global Partitions
12 Stop Disk Writes
13 Drop Sort Segments
14 Release unused space from Sort Segments
15 Instance Recovery for Parallel operation Group
16 Validate parallel slave Lock Value
17 Check transaction state objects
18 Flush blocks in object
19 Rolling release checks
20 Propagate begin backup scn for a file
21 Clear checkpoint progress record
Oracle 7
Id1 Meaning
~~~ ~~~~~~~
0 Flush buffers for reuse as new class
1 LGWR checkpointing and Hot Backup
2 DBWR synchronization of SGA with control file
3 Log file add/drop/rename notification
4 Write buffer for CR read
5 Test Call
6 Invalidate KCK cache in all instances
7 Alter rollback segment optimal
8 Signal Query Servers/coordinator
9 Create Remote Parallel Query Server
10 Set Global Partitions
11 Stop Disk Writes
12 Drop Sort Segments
13 Release unused space from Sort Segments
14 Instance Recovery for Parallel operation Group
15 Validate parallel slave Lock Value
16 Check Transaction State Objects
Id2 Meaning
~~~ ~~~~~~~
1 Pass in Parameters
2 Invoke the call in background process
3 Foreground has not returned yet
4 Used to allocate the CI call
5 Used to queue up interested clients
甲骨文公司怪不得这么强,把问题都这么告诉大家。
注意启用slaves I/O 可能导致额外的CI enqueue争用
SQL> show parameter dbwr
NAME TYPE VALUE
———————————— ———– ——————————
dbwr_io_slaves integer 3
SQL> select vs.sid,vs.program,vl.type,vl.id1,vl.id2,vl.lmode,vl.request,vl.ctime,vl.block from v$lock vl ,v$session vs
2 where
3 vl.sid=vs.sid
4 and
5 vl.type=’CI’
6 ;
SID PROGRAM TY ID1 ID2 LMODE REQUEST CTIME BLOCK
———- ———————————————— — — — —– ——- ———- —–
136 sqlplus@rh2.oracle.com (TNS V1-V3) CI 1 5 6 0 25149 1
165 oracle@rh2.oracle.com (CKPT) CI 1 1 4 0 25215 1
165 oracle@rh2.oracle.com (CKPT) CI 2 1 4 0 25374 0
136 sqlplus@rh2.oracle.com (TNS V1-V3) CI 1 1 0 6 25149 0
164 oracle@rh2.oracle.com (SMON) CI 1 5 0 6 8284 0
SQL> oradebug setmypid;
Statement processed.
SQL> oradebug hanganalyze 3;
Hang Analysis in /s01/admin/G10R2/udump/g10r2_ora_5744.trc
==============
HANG ANALYSIS:
==============
Open chains found:
Chain 1 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<0/165/1/0xdc2f8260/4703/rdbms ipc message>
— <0/136/34/0xdc2fd170/1569/enq: CI – contention>
— <0/164/1/0xdc2f8a48/4705/enq: CI – contention>
— <0/160/1/0xdc2fa9e8/4713/buffer busy waits>
Other chains found:
Chain 2 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<0/138/55/0xdc3000e0/5744/No Wait>
Chain 3 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<0/139/1/0xdc302868/4862/i/o slave wait>
Chain 4 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<0/145/3/0xdc2ff8f8/4840/Streams AQ: waiting for time man>
Chain 5 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<0/146/1981/0xdc2fc988/5308/i/o slave wait>
Chain 6 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<0/149/1/0xdc2ff110/4815/Streams AQ: qmn coordinator idle>
Chain 7 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<0/153/1/0xdc2fe928/4813/i/o slave wait>
Chain 8 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<0/158/10/0xdc302080/4860/Streams AQ: qmn slave idle wait>
Chain 9 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<0/159/255/0xdc2fc1a0/31232/i/o slave wait>
Chain 10 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<0/161/1/0xdc2fa200/4711/buffer busy waits>
Chain 11 : <cnode/sid/sess_srno/proc_ptr/ospid/wait_event> :
<0/167/1/0xdc2f7290/4699/io done>
see enq: CI – contention、i/o slave wait、buffer busy waits
Foreground Process alter system checkpoint
CI 1 5 — Reuse (checkpoint and invalidate) block range |Used to queue up interested clients
CKPT
CI 1 1 — same | Used to pass in parameters
CI 2 1 — LGWR Checkpointing and Hot Backup | Used to pass in parameters
Foreground Process alter system flush buffer_cache
CI 1 1
SMON
CI 1 5
SQL> select * From x$ksqrs where ksqrsidt=’CI’;
ADDR INDX INST_ID KSQRSID1 KSQRSID2 KS KSQRSFLG
—————- ———- ———- ———- ———- — ———-
00000000DC579A48 101 1 2 1 CI 2
00000000DC581910 337 1 1 1 CI 2
00000000DC583FB0 409 1 1 5 CI 2
resource structure , one for unique id1|id2
SELECT ksqlkres,
ksqlkadr,
ksqlkmod,
ksqlkreq,
ksqlkctim,
KSQLKLBLK
FROM x$ksqeq
WHERE ksqlkres IN (SELECT addr
FROM x$ksqrs
WHERE ksqrsidt = ‘CI’);
KSQLKRES KSQLKADR KSQLKMOD KSQLKREQ KSQLKCTIM KSQLKLBLK
—————- —————- ———- ———- ———- ———-
00000000DC583FB0 00000000DC51FDE8 6 0 25923 1
00000000DC581910 00000000DC51FF18 4 0 25989 1
00000000DC579A48 00000000DC51FFB0 4 0 26148 0
00000000DC581910 00000000DC520650 0 6 25923 0
00000000DC583FB0 00000000DC5208B0 0 6 9058 0
00000000DC581910 00000000DC522318 0 0 27369 27369
00000000DC579A48 00000000DC5223B0 0 0 27369 27369
SQL> select sid,serial# from v$session where sid=136;
SID SERIAL#
———- ———-
136 34
SQL> alter system kill session ‘136,34’;
hanging here…………..we KILL process
still hang
SQL> select vs.sid,vs.program,vl.type,vl.id1,vl.id2,vl.lmode,vl.request,vl.ctime,vl.block from v$lock vl ,v$session vs
2 where
3 vl.sid=vs.sid
4 and
5 vl.type=’CI’
6 ;
SID PROGRAM TY ID1 ID2 LMODE REQUEST CTIME BLOCK
———- ———————————————— — — — —– ——- ———- —–
165 oracle@rh2.oracle.com (CKPT) CI 1 1 4 0 26175 1
165 oracle@rh2.oracle.com (CKPT) CI 2 1 4 0 26334 0
164 oracle@rh2.oracle.com (SMON) CI 1 1 0 6 42 0
164 oracle@rh2.oracle.com (SMON) CI 1 5 6 0 42 0
Sun May 29 16:30:30 2011
Errors in file /s01/admin/G10R2/bdump/g10r2_ora_4864.trc:
ORA-00600: internal error code, arguments: [ksfdcko3], [0x0DBED8338], [], [], [], [], [], []
ORA-27041: unable to open file
Linux-x86_64 Error: 2: No such file or directory
Additional information: 3
Sun May 29 16:30:30 2011
Errors in file /s01/admin/G10R2/bdump/g10r2_ora_4866.trc:
ORA-00600: internal error code, arguments: [ksfdcko3], [0x0DBED8338], [], [], [], [], [], []
ORA-27041: unable to open file
ksedmp: internal or fatal error
ORA-00600: internal error code, arguments: [ksfdcko3], [0x0DBED8338], [], [], [], [], [], []
ORA-27041: unable to open file
Linux-x86_64 Error: 2: No such file or directory
Additional information: 3
—– Call Stack Trace —–
calling call entry argument values in hex
location type point (? means dubious value)
——————– ——– ——————– —————————-
ksedst()+31 call ksedst1() 000000000 ? 000000001 ?
7FFFAC32C340 ? 7FFFAC32C3A0 ?
7FFFAC32C2E0 ? 000000000 ?
ksedmp()+610 call ksedst() 000000000 ? 000000001 ?
7FFFAC32C340 ? 7FFFAC32C3A0 ?
7FFFAC32C2E0 ? 000000000 ?
ksfdmp()+21 call ksedmp() 000000003 ? 000000001 ?
7FFFAC32C340 ? 7FFFAC32C3A0 ?
7FFFAC32C2E0 ? 000000000 ?
kgerinv()+161 call ksfdmp() 000000003 ? 000000001 ?
7FFFAC32C340 ? 7FFFAC32C3A0 ?
7FFFAC32C2E0 ? 000000000 ?
kgesinv()+33 call kgerinv() 0068D41C0 ? 006B8ABF0 ?
7FFFAC32C3A0 ? 7FFFAC32C2E0 ?
000000000 ? 000000000 ?
ksesin()+211 call kgesinv() 0068D41C0 ? 006B8ABF0 ?
7FFFAC32C3A0 ? 7FFFAC32C2E0 ?
000000000 ? 000000000 ?
ksfdcko()+1173 call ksesin() 0053F31C4 ? 000000001 ?
000000002 ? 0DBED8338 ?
000000016 ? 0DC303858 ?
ksfvcko()+67 call ksfdcko() 0DBD764A8 ? 000000003 ?
000000002 ? 0DBED8338 ?
000000016 ? 0DC303858 ?
ksfdsubmit()+76 call ksfvcko() 0D8BE81D0 ? 000000002 ?
000000002 ? 0DBED8338 ?
000000016 ? 0DC303858 ?
ksfvdoaio()+373 call ksfdsubmit() 0D8BE81D0 ? 0D8BE8160 ?
000000003 ? 000000001 ?
000000016 ? 0DC303858 ?
ksfvrdp()+6683 call ksfvdoaio() 0D8BE8130 ? 0D8BE8160 ?
000000003 ? 000000001 ?
000000016 ? 0DC303858 ?
opirip()+1157 call ksfvrdp() 0D8BE8130 ? 0D9D1BD18 ?
000000003 ? 0D7AAB568 ?
0068D4340 ? 7FFF00000000 ?
opidrv()+582 call opirip() 000000032 ? 000000004 ?
7FFFAC32E978 ? 0D7AAB568 ?
0068D4340 ? 7FFF00000000 ?
sou2o()+114 call opidrv() 000000032 ? 000000004 ?
7FFFAC32E978 ? 0D7AAB568 ?
0068D4340 ? 7FFF00000000 ?
opimai_real()+317 call sou2o() 7FFFAC32E950 ? 000000032 ?
000000004 ? 7FFFAC32E978 ?
0068D4340 ? 7FFF00000000 ?
main()+116 call opimai_real() 000000003 ? 7FFFAC32E9E0 ?
000000004 ? 7FFFAC32E978 ?
0068D4340 ? 7FFF00000000 ?
__libc_start_main() call main() 000000003 ? 7FFFAC32E9E0 ?
+244 000000004 ? 7FFFAC32E978 ?
0068D4340 ? 7FFF00000000 ?
_start()+41 call __libc_start_main() 000723748 ? 000000001 ?
7FFFAC32EB38 ? 000000000 ?
0068D4340 ? 000000003 ?
RMAN> report schema;
using target database control file instead of recovery catalog
Report of database schema
List of Permanent Datafiles
===========================
File Size(MB) Tablespace RB segs Datafile Name
—- ——– ——————– ——- ————————
hanging here……………
RMAN> restore datafile 9;
Starting restore at 29-MAY-11
using channel ORA_DISK_1
using channel ORA_DISK_2
channel ORA_DISK_1: starting datafile backupset restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
restoring datafile 00009 to /flashcard/wwli.dbf
channel ORA_DISK_1: reading from backup piece /s01/flash_recovery_area/G10R2/backupset/2011_05_29/o1_mf_nnndf_TAG20110529T162547_6y40rd0f_.bkp
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of restore command at 05/29/2011 23:56:23
ORA-19870: error reading backup piece /s01/flash_recovery_area/G10R2/backupset/2011_05_29/o1_mf_nnndf_TAG20110529T162547_6y40rd0f_.bkp
ORA-19573: cannot obtain exclusive enqueue for datafile 9
[oracle@rh2 bdump]$ oerr ora 19573
19573, 00000, "cannot obtain %s enqueue for datafile %s"
// *Cause: The file access enqueue could not be obtained for a file
// specified in a backup, copy or restore operation.
// If the enqueue type shown is ‘shared’, then the file is the
// input file for a backup or copy. If the type is ‘exclusive’, then
// the file is the output file for a datafile copy or restore which
// is attempting to overwrite the currently active version of that
// file – in this case, the file must be offline or the database must
// be closed. If the type is ‘read-only’, then you are attempting
// to back up or copy this file while the database is in NOARCHIVELOG
// mode.
// *Action: Wait until the conflicting operation is complete, then retry
// the copy or backup. If the database is in NOARCHIVELOG mode, then
// all files being backed up must be closed cleanly.
SQL> select vs.sid,vs.program,vl.type,vl.id1,vl.id2,vl.lmode,vl.request,vl.ctime,vl.block from v$lock vl ,v$session vs
2 where
3 vl.sid=vs.sid
4 and
5 vl.type=’MR’ and vl.id1=9;
SID PROGRAM TY ID1 ID2 LMODE REQUEST CTIME BLOCK
—- ———————————————— — — — —– ——- ———- —–
167 oracle@rh2.oracle.com (DBW0) MR 9 0 4 0 269474 0
MR enqueue lock is still taken by DBW0 ,reset dbwr_io_slaves and restart instance
SQL> alter system set dbwr_io_slaves=0 scope=spfile;
System altered.
SQL> shutdown abort;
ORACLE instance shut down.
SQL> startup;
ORACLE instance started.
Total System Global Area 1065353216 bytes
Fixed Size 2089336 bytes
Variable Size 486542984 bytes
Database Buffers 570425344 bytes
Redo Buffers 6295552 bytes
Database mounted.
ORA-01157: cannot identify/lock data file 9 – see DBWR trace file
ORA-01110: data file 9: ‘/flashcard/wwli.dbf’
RMAN> restore datafile 9;
Starting restore at 30-MAY-11
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: sid=155 devtype=DISK
allocated channel: ORA_DISK_2
channel ORA_DISK_2: sid=154 devtype=DISK
channel ORA_DISK_1: starting datafile backupset restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
restoring datafile 00009 to /flashcard/wwli.dbf
channel ORA_DISK_1: reading from backup piece /s01/flash_recovery_area/G10R2/backupset/2011_05_29/o1_mf_nnndf_TAG20110529T162547_6y40rd0f_.bkp
channel ORA_DISK_1: restored backup piece 1
piece handle=/s01/flash_recovery_area/G10R2/backupset/2011_05_29/o1_mf_nnndf_TAG20110529T162547_6y40rd0f_.bkp tag=TAG20110529T162547
channel ORA_DISK_1: restore complete, elapsed time: 00:00:01
Finished restore at 30-MAY-11
RMAN> recover datafile 9;
Starting recover at 30-MAY-11
using channel ORA_DISK_1
using channel ORA_DISK_2
starting media recovery
channel ORA_DISK_2: starting archive log restore to default destination
channel ORA_DISK_2: restoring archive log
archive log thread=1 sequence=710
channel ORA_DISK_1: starting archive log restore to default destination
channel ORA_DISK_2: restoring archive log
archive log thread=1 sequence=711
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=704
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=705
channel ORA_DISK_2: restoring archive log
archive log thread=1 sequence=712
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=706
channel ORA_DISK_2: restoring archive log
archive log thread=1 sequence=713
channel ORA_DISK_2: reading from backup piece /s01/flash_recovery_area/G10R2/backupset/2011_05_29/o1_mf_annnn_TAG20110529T162617_6y40scvo_.bkp
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=707
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=708
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=709
channel ORA_DISK_1: reading from backup piece /s01/flash_recovery_area/G10R2/backupset/2011_05_29/o1_mf_annnn_TAG20110529T162617_6y40sbqg_.bkp
channel ORA_DISK_1: restored backup piece 1
piece handle=/s01/flash_recovery_area/G10R2/backupset/2011_05_29/o1_mf_annnn_TAG20110529T162617_6y40sbqg_.bkp tag=TAG20110529T162617
channel ORA_DISK_1: restore complete, elapsed time: 00:00:01
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_704_6y4vf989_.arc thread=1 sequence=704
channel default: deleting archive log(s)
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_704_6y4vf989_.arc recid=716 stamp=752457641
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_705_6y4vf98w_.arc thread=1 sequence=705
channel default: deleting archive log(s)
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_705_6y4vf98w_.arc recid=718 stamp=752457641
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_706_6y4vf99k_.arc thread=1 sequence=706
channel default: deleting archive log(s)
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_706_6y4vf99k_.arc recid=720 stamp=752457641
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_707_6y4vf9b3_.arc thread=1 sequence=707
channel default: deleting archive log(s)
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_707_6y4vf9b3_.arc recid=721 stamp=752457641
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_708_6y4vf9bn_.arc thread=1 sequence=708
channel default: deleting archive log(s)
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_708_6y4vf9bn_.arc recid=722 stamp=752457641
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_709_6y4vf9cm_.arc thread=1 sequence=709
channel default: deleting archive log(s)
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_709_6y4vf9cm_.arc recid=723 stamp=752457641
channel ORA_DISK_2: restored backup piece 1
piece handle=/s01/flash_recovery_area/G10R2/backupset/2011_05_29/o1_mf_annnn_TAG20110529T162617_6y40scvo_.bkp tag=TAG20110529T162617
channel ORA_DISK_2: restore complete, elapsed time: 00:00:01
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_710_6y4vf976_.arc thread=1 sequence=710
channel default: deleting archive log(s)
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_710_6y4vf976_.arc recid=714 stamp=752457641
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_711_6y4vf97v_.arc thread=1 sequence=711
channel default: deleting archive log(s)
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_711_6y4vf97v_.arc recid=715 stamp=752457641
channel default: deleting archive log(s)
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_712_6y4vf98h_.arc recid=717 stamp=752457641
channel default: deleting archive log(s)
archive log filename=/s01/flash_recovery_area/G10R2/archivelog/2011_05_30/o1_mf_1_713_6y4vf993_.arc recid=719 stamp=752457641
media recovery complete, elapsed time: 00:00:03
Finished recover at 30-MAY-11
SQL> alter database open ;
Database altered.
Never Lost your datafile while the instance is still running ,if you have enabled DBWR slaves IO!!