Para onde vão os dados alterados durante um BACKUP?
Se acontecer um SHUTDOWN ABORT durante USER MANAGED BACKUP, nada de pânico. Não é necessário um RECOVER, mesmo se o BEGIN BACKUP estivesse ativo a muito tempo, e muitos dados foram alterados ou inseridos. Bem, este é pelo menos mais um motivo para parar de utilizar USER MANAGED BACKUP e passar a utilizar RMAN.
Mas o mais importante é que este teste nos prova que durante um BACKUP, os dados não vão para nenhum lugar mágico – continuam indo para os DATAFILEs normalmente, e em seguida para os REDO LOGs e ARCHIVED REDO LOGs, como todos os dados, mas eles já estão nos DATAFILEs, mesmo se estes estiverem sendo copiados para outra máquina.
Veja que após o END BACKUP, o RECOVER feito pelo ALTER DATABASE OPEN não utilizou todos os ARCHIVED REDO LOGs gerados após o BEGIN BACKUP: só o último foi necessário.
Este RECOVER apenas atualiza o CHECKPOINT SCN (que estava congelado desde o BEGIN BACKUP) com HOT BACKUP CHECKPOINT SCN, pois este sim continuava a ser atualizado com a utilização do Banco de Dados pelo processo background CKPT.
Obviamente que se você copia os DATAFILEs para outra máquina ou outro diretório, alguns estarão mais desatualizados do que outros – tanto no HOT BACKUP CHECKPOINT SCN quanto nos dados. Aí sim os ARCHIVED REDO LOGs são necessários tanto para atualização do CHECKPOINT SCN quanto de dados propriamente ditos.
[oracle@CentOS5 ~]$ sqlplus / AS SYSDBA
SQL*Plus: Release 11.2.0.2.0 Production on Tue Feb 22 07:27:15 2011
Copyright (c) 1982, 2010, Oracle. All rights reserved.
Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - Production
With the Partitioning, Oracle Label Security, OLAP, Data Mining,
Oracle Database Vault and Real Application Testing options
SQL> ALTER DATABASE BEGIN BACKUP;
Database altered.
SQL> INSERT INTO T SELECT * FROM T;
2307680 rows created.
SQL> COMMIT;
Commit complete.
SQL> ALTER SYSTEM SWITCH LOGFILE;
System altered.
SQL> ALTER SYSTEM SWITCH LOGFILE;
System altered.
SQL> ALTER SYSTEM SWITCH LOGFILE;
System altered.
SQL> ALTER SYSTEM SWITCH LOGFILE;
System altered.
SQL> SET PAGES 1000
SQL> SET LINES 210
SQL> SELECT * FROM V$LOG;
GROUP# THREAD# SEQUENCE# BYTES BLOCKSIZE MEMBERS ARC STATUS FIRST_CHANGE# FIRST_TIM NEXT_CHANGE# NEXT_TIME
---------- ---------- ---------- ---------- ---------- ---------- --- ---------------- ------------- --------- ------------ ---------
1 1 37 52428800 512 2 YES INACTIVE 1063586 22-FEB-11 1063590 22-FEB-11
2 1 38 52428800 512 2 NO CURRENT 1063590 22-FEB-11 2.8147E+14
3 1 36 52428800 512 2 YES INACTIVE 1063581 22-FEB-11 1063586 22-FEB-11
SQL> SHUTDOWN ABORT;
ORACLE instance shut down.
SQL> STARTUP
ORACLE instance started.
Total System Global Area 535662592 bytes
Fixed Size 1345376 bytes
Variable Size 364906656 bytes
Database Buffers 163577856 bytes
Redo Buffers 5832704 bytes
Database mounted.
ORA-10873: file 1 needs to be either taken out of backup mode or media recovered
ORA-01110: data file 1: '/u01/oradata/ORCL/datafile/o1_mf_system_6ozkzd2c_.dbf'
SQL> ALTER DATABASE END BACKUP;
Database altered.
SQL> ALTER DATABASE OPEN;
Database altered.
SQL>[oracle@CentOS5 ~]$ tail -f /u01/app/oracle/diag/rdbms/orcl/ORCL/trace/alert_ORCL.log
Tue Feb 22 07:27:32 2011
ALTER DATABASE BEGIN BACKUP
Completed: ALTER DATABASE BEGIN BACKUP
Tue Feb 22 07:27:55 2011
Thread 1 advanced to log sequence 27 (LGWR switch)
Current log# 3 seq# 27 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_3_6ozl8v56_.log
Current log# 3 seq# 27 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_3_6ozl8vom_.log
Tue Feb 22 07:28:00 2011
Archived Log entry 24 added for thread 1 sequence 26 ID 0x4bc68de9 dest 1:
Tue Feb 22 07:28:07 2011
Thread 1 advanced to log sequence 28 (LGWR switch)
Current log# 1 seq# 28 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_1_6ozl8fhn_.log
Current log# 1 seq# 28 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_1_6ozl8g3s_.log
Tue Feb 22 07:28:15 2011
Archived Log entry 25 added for thread 1 sequence 27 ID 0x4bc68de9 dest 1:
Tue Feb 22 07:28:23 2011
Thread 1 advanced to log sequence 29 (LGWR switch)
Current log# 2 seq# 29 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_2_6ozl8nxv_.log
Current log# 2 seq# 29 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_2_6ozl8ohd_.log
Tue Feb 22 07:28:29 2011
Archived Log entry 26 added for thread 1 sequence 28 ID 0x4bc68de9 dest 1:
Tue Feb 22 07:28:39 2011
Thread 1 advanced to log sequence 30 (LGWR switch)
Current log# 3 seq# 30 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_3_6ozl8v56_.log
Current log# 3 seq# 30 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_3_6ozl8vom_.log
Tue Feb 22 07:28:46 2011
Archived Log entry 27 added for thread 1 sequence 29 ID 0x4bc68de9 dest 1:
Tue Feb 22 07:28:54 2011
Thread 1 advanced to log sequence 31 (LGWR switch)
Current log# 1 seq# 31 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_1_6ozl8fhn_.log
Current log# 1 seq# 31 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_1_6ozl8g3s_.log
Tue Feb 22 07:28:58 2011
Archived Log entry 28 added for thread 1 sequence 30 ID 0x4bc68de9 dest 1:
Tue Feb 22 07:29:06 2011
Thread 1 advanced to log sequence 32 (LGWR switch)
Current log# 2 seq# 32 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_2_6ozl8nxv_.log
Current log# 2 seq# 32 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_2_6ozl8ohd_.log
Tue Feb 22 07:29:12 2011
Expanded controlfile section 11 from 28 to 79 records
Requested to grow by 51 records; added 2 blocks of records
Archived Log entry 29 added for thread 1 sequence 31 ID 0x4bc68de9 dest 1:
Tue Feb 22 07:29:19 2011
Thread 1 cannot allocate new log, sequence 33
Checkpoint not complete
Current log# 2 seq# 32 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_2_6ozl8nxv_.log
Current log# 2 seq# 32 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_2_6ozl8ohd_.log
Thread 1 advanced to log sequence 33 (LGWR switch)
Current log# 3 seq# 33 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_3_6ozl8v56_.log
Current log# 3 seq# 33 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_3_6ozl8vom_.log
Tue Feb 22 07:29:24 2011
Archived Log entry 30 added for thread 1 sequence 32 ID 0x4bc68de9 dest 1:
Tue Feb 22 07:29:31 2011
Thread 1 cannot allocate new log, sequence 34
Checkpoint not complete
Current log# 3 seq# 33 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_3_6ozl8v56_.log
Current log# 3 seq# 33 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_3_6ozl8vom_.log
Thread 1 advanced to log sequence 34 (LGWR switch)
Current log# 1 seq# 34 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_1_6ozl8fhn_.log
Current log# 1 seq# 34 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_1_6ozl8g3s_.log
Tue Feb 22 07:29:40 2011
Archived Log entry 31 added for thread 1 sequence 33 ID 0x4bc68de9 dest 1:
Tue Feb 22 07:34:00 2011
Thread 1 cannot allocate new log, sequence 35
Checkpoint not complete
Current log# 1 seq# 34 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_1_6ozl8fhn_.log
Current log# 1 seq# 34 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_1_6ozl8g3s_.log
Thread 1 advanced to log sequence 35 (LGWR switch)
Current log# 2 seq# 35 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_2_6ozl8nxv_.log
Current log# 2 seq# 35 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_2_6ozl8ohd_.log
Tue Feb 22 07:34:05 2011
Archived Log entry 32 added for thread 1 sequence 34 ID 0x4bc68de9 dest 1:
Thread 1 cannot allocate new log, sequence 36
Checkpoint not complete
Current log# 2 seq# 35 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_2_6ozl8nxv_.log
Current log# 2 seq# 35 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_2_6ozl8ohd_.log
Thread 1 advanced to log sequence 36 (LGWR switch)
Current log# 3 seq# 36 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_3_6ozl8v56_.log
Current log# 3 seq# 36 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_3_6ozl8vom_.log
Tue Feb 22 07:34:10 2011
Archived Log entry 33 added for thread 1 sequence 35 ID 0x4bc68de9 dest 1:
Tue Feb 22 07:34:15 2011
Thread 1 cannot allocate new log, sequence 37
Checkpoint not complete
Current log# 3 seq# 36 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_3_6ozl8v56_.log
Current log# 3 seq# 36 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_3_6ozl8vom_.log
Thread 1 advanced to log sequence 37 (LGWR switch)
Current log# 1 seq# 37 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_1_6ozl8fhn_.log
Current log# 1 seq# 37 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_1_6ozl8g3s_.log
Tue Feb 22 07:34:16 2011
Archived Log entry 34 added for thread 1 sequence 36 ID 0x4bc68de9 dest 1:
Thread 1 advanced to log sequence 38 (LGWR switch)
Current log# 2 seq# 38 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_2_6ozl8nxv_.log
Current log# 2 seq# 38 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_2_6ozl8ohd_.log
Tue Feb 22 07:34:23 2011
Archived Log entry 35 added for thread 1 sequence 37 ID 0x4bc68de9 dest 1:
Tue Feb 22 07:35:08 2011
Shutting down instance (abort)
License high water mark = 3
USER (ospid: 13389): terminating the instance
Instance terminated by USER, pid = 13389
Tue Feb 22 07:35:10 2011
Instance shutdown complete
Tue Feb 22 07:35:23 2011
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
Picked latch-free SCN scheme 2
Using LOG_ARCHIVE_DEST_1 parameter default value as USE_DB_RECOVERY_FILE_DEST
Autotune of undo retention is turned on.
IMODE=BR
ILAT =27
LICENSE_MAX_USERS = 0
SYS auditing is disabled
Starting up:
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - Production
With the Partitioning, Oracle Label Security, OLAP, Data Mining,
Oracle Database Vault and Real Application Testing options.
Using parameter settings in server-side spfile /u01/app/oracle/product/11.2.0/db_1/dbs/spfileORCL.ora
System parameters with non-default values:
processes = 150
memory_target = 512M
control_files = "/u01/oradata/ORCL/controlfile/o1_mf_6ozl890w_.ctl"
control_files = "/u01/oradata/FRA/ORCL/controlfile/o1_mf_6ozl8b9n_.ctl"
db_block_size = 8192
compatible = "11.2.0.0.0"
log_archive_format = "%t_%s_%r.dbf"
db_create_file_dest = "/u01/oradata"
db_recovery_file_dest = "/u01/oradata/FRA"
db_recovery_file_dest_size= 40000M
undo_tablespace = "UNDOTBS1"
remote_login_passwordfile= "EXCLUSIVE"
db_domain = ""
dispatchers = "(PROTOCOL=TCP) (SERVICE=ORCLXDB)"
audit_file_dest = "/u01/app/oracle/admin/ORCL/adump"
audit_trail = "DB"
db_name = "ORCL"
open_cursors = 300
diagnostic_dest = "/u01/app/oracle"
Tue Feb 22 07:35:30 2011
PMON started with pid=2, OS id=13458
Tue Feb 22 07:35:31 2011
PSP0 started with pid=3, OS id=13460
Tue Feb 22 07:35:32 2011
VKTM started with pid=4, OS id=13462 at elevated priority
VKTM running at (1)millisec precision with DBRM quantum (100)ms
Tue Feb 22 07:35:32 2011
GEN0 started with pid=5, OS id=13466
Tue Feb 22 07:35:33 2011
DIAG started with pid=6, OS id=13468
Tue Feb 22 07:35:33 2011
DBRM started with pid=7, OS id=13470
Tue Feb 22 07:35:33 2011
DIA0 started with pid=8, OS id=13472
Tue Feb 22 07:35:33 2011
MMAN started with pid=9, OS id=13474
Tue Feb 22 07:35:34 2011
LGWR started with pid=11, OS id=13478
Tue Feb 22 07:35:34 2011
DBW0 started with pid=10, OS id=13476
Tue Feb 22 07:35:34 2011
CKPT started with pid=12, OS id=13480
Tue Feb 22 07:35:35 2011
SMON started with pid=13, OS id=13482
Tue Feb 22 07:35:35 2011
RECO started with pid=14, OS id=13484
Tue Feb 22 07:35:35 2011
MMON started with pid=15, OS id=13486
Tue Feb 22 07:35:35 2011
starting up 1 dispatcher(s) for network address '(ADDRESS=(PARTIAL=YES)(PROTOCOL=TCP))'...
Tue Feb 22 07:35:35 2011
MMNL started with pid=16, OS id=13488
starting up 1 shared server(s) ...
ORACLE_BASE from environment = /u01/app/oracle
Tue Feb 22 07:35:37 2011
ALTER DATABASE MOUNT
Successful mount of redo thread 1, with mount id 1271541578
Database mounted in Exclusive Mode
Lost write protection disabled
Completed: ALTER DATABASE MOUNT
Tue Feb 22 07:35:43 2011
ALTER DATABASE OPEN
Errors in file /u01/app/oracle/diag/rdbms/orcl/ORCL/trace/ORCL_ora_13532.trc:
ORA-10873: file 1 needs to be either taken out of backup mode or media recovered
ORA-01110: data file 1: '/u01/oradata/ORCL/datafile/o1_mf_system_6ozkzd2c_.dbf'
ORA-10873 signalled during: ALTER DATABASE OPEN...
ALTER DATABASE END BACKUP
Completed: ALTER DATABASE END BACKUP
Tue Feb 22 07:35:57 2011
ALTER DATABASE OPEN
Beginning crash recovery of 1 threads
Started redo scan
Completed redo scan
read 0 KB redo, 0 data blocks need recovery
Started redo application at
Thread 1: logseq 38, block 2, scn 1063590
Recovery of Online Redo Log: Thread 1 Group 2 Seq 38 Reading mem 0
Mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_2_6ozl8nxv_.log
Mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_2_6ozl8ohd_.log
Completed redo application of 0.00MB
Completed crash recovery at
Thread 1: logseq 38, block 2, scn 1083591
0 data blocks read, 0 data blocks written, 0 redo k-bytes read
Tue Feb 22 07:35:57 2011
LGWR: STARTING ARCH PROCESSES
Tue Feb 22 07:35:57 2011
ARC0 started with pid=20, OS id=13541
ARC0: Archival started
LGWR: STARTING ARCH PROCESSES COMPLETE
ARC0: STARTING ARCH PROCESSES
Thread 1 advanced to log sequence 39 (thread open)
Thread 1 opened at log sequence 39
Current log# 3 seq# 39 mem# 0: /u01/oradata/ORCL/onlinelog/o1_mf_3_6ozl8v56_.log
Current log# 3 seq# 39 mem# 1: /u01/oradata/FRA/ORCL/onlinelog/o1_mf_3_6ozl8vom_.log
Successful open of redo thread 1
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Tue Feb 22 07:35:59 2011
SMON: enabling cache recovery
[13532] Successfully onlined Undo Tablespace 2.
Undo initialization finished serial:0 start:154155234 end:154155544 diff:310 (3 seconds)
Verifying file header compatibility for 11g tablespace encryption..
Verifying 11g file header compatibility for tablespace encryption completed
SMON: enabling tx recovery
Database Characterset is WE8MSWIN1252
No Resource Manager plan active
replication_dependency_tracking turned off (no async multimaster replication found)
Tue Feb 22 07:36:01 2011
ARC1 started with pid=21, OS id=13543
Tue Feb 22 07:36:01 2011
ARC2 started with pid=22, OS id=13545
ARC1: Archival started
ARC2: Archival started
ARC2: Becoming the 'no FAL' ARCH
ARC2: Becoming the 'no SRL' ARCH
Archived Log entry 36 added for thread 1 sequence 38 ID 0x4bc68de9 dest 1:
ARC1: Becoming the heartbeat ARCH
Tue Feb 22 07:36:02 2011
ARC3 started with pid=23, OS id=13547
Starting background process QMNC
ARC3: Archival started
ARC0: STARTING ARCH PROCESSES COMPLETE
Completed: ALTER DATABASE OPEN
Tue Feb 22 07:36:04 2011
QMNC started with pid=24, OS id=13549
Tue Feb 22 07:36:06 2011
db_recovery_file_dest_size of 40000 MB is 2.62% used. This is a
user-specified limit on the amount of space that will be used by this
database for recovery-related files, and does not reflect the amount of
space available in the underlying filesystem or ASM diskgroup.
Tue Feb 22 07:36:08 2011
Starting background process CJQ0
Tue Feb 22 07:36:09 2011
CJQ0 started with pid=26, OS id=13563