修改时间导致RAC环境的一个实例重启

今天例行巡检，没有问题，过了一会，客户反映业务中断，出问题了，检查告警日志：

rac1

Wed Apr 13 09:07:26 2011
Reconfiguration started (old inc 48, new inc 50)
List of nodes:
 0
 Global Resource Directory frozen
 * dead instance detected - domain 0 invalid = TRUE
 Communication channels reestablished
 Master broadcasted resource hash value bitmaps
 Non-local Process blocks cleaned out
Wed Apr 13 09:07:26 2011
 LMS 0: 0 GCS shadows cancelled, 0 closed
Wed Apr 13 09:07:26 2011
 LMS 1: 1 GCS shadows cancelled, 1 closed
 Set master node info
 Submitted all remote-enqueue requests
 Dwn-cvts replayed, VALBLKs dubious
 All grantable enqueues granted
 Post SMON to start 1st pass IR
Wed Apr 13 09:07:26 2011
 LMS 0: 17778 GCS shadows traversed, 0 replayed
Wed Apr 13 09:07:26 2011
 LMS 1: 17728 GCS shadows traversed, 0 replayed
Wed Apr 13 09:07:26 2011
 Submitted all GCS remote-cache requests
 Post SMON to start 1st pass IR
 Fix write in gcs resources
Wed Apr 13 09:07:26 2011
Instance recovery: looking for dead threads
Wed Apr 13 09:07:26 2011
Beginning instance recovery of 1 threads
Reconfiguration complete
Wed Apr 13 09:07:27 2011
 parallel recovery started with 2 processes
Wed Apr 13 09:07:27 2011
Started redo scan
Wed Apr 13 09:07:27 2011
Completed redo scan
 244 redo blocks read, 65 data blocks need recovery
Wed Apr 13 09:07:27 2011
Started redo application at
 Thread 2: logseq 1696, block 42688
Wed Apr 13 09:07:27 2011
Recovery of Online Redo Log: Thread 2 Group 4 Seq 1696 Reading mem 0
  Mem# 0 errs 0: +DG1/orcl/onlinelog/group_4.266.668253231
Wed Apr 13 09:07:27 2011
Completed redo application
Wed Apr 13 09:07:27 2011
Completed instance recovery at
 Thread 2: logseq 1696, block 42932, scn 716688767
 59 data blocks read, 67 data blocks written, 244 redo blocks read
Switch log for thread 2 to sequence 1697
Wed Apr 13 09:09:40 2011
Reconfiguration started (old inc 50, new inc 52)
List of nodes:
 0 1
 Global Resource Directory frozen
 Communication channels reestablished
 Master broadcasted resource hash value bitmaps
 Non-local Process blocks cleaned out
Wed Apr 13 09:09:41 2011
 LMS 0: 0 GCS shadows cancelled, 0 closed
Wed Apr 13 09:09:41 2011
 LMS 1: 0 GCS shadows cancelled, 0 closed
 Set master node info
 Submitted all remote-enqueue requests
 Dwn-cvts replayed, VALBLKs dubious
 All grantable enqueues granted
Wed Apr 13 09:09:41 2011
 LMS 0: 8705 GCS shadows traversed, 4001 replayed
Wed Apr 13 09:09:41 2011
 LMS 1: 8768 GCS shadows traversed, 4001 replayed
 LMS 1: 8774 GCS shadows traversed, 4001 replayed
Wed Apr 13 09:09:41 2011
 LMS 0: 8664 GCS shadows traversed, 4001 replayed
Wed Apr 13 09:09:41 2011
 LMS 1: 223 GCS shadows traversed, 91 replayed
Wed Apr 13 09:09:41 2011
 LMS 0: 467 GCS shadows traversed, 226 replayed
Wed Apr 13 09:09:41 2011
 Submitted all GCS remote-cache requests
 Post SMON to start 1st pass IR
 Fix write in gcs resources
Reconfiguration complete
Wed Apr 13 09:12:38 2011
Thread 1 advanced to log sequence 8501
  Current log# 2 seq# 8501 mem# 0: +DG1/orcl/onlinelog/group_2.262.668253153

rac2

Tue Apr 12 23:00:23 2011
Thread 2 advanced to log sequence 1696
  Current log# 4 seq# 1696 mem# 0: +DG1/orcl/onlinelog/group_4.266.668253231
Wed Apr 13 09:09:32 2011
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
LICENSE_SESSIONS_WARNING = 0
  WARNING: No cluster interconnect has been specified. Depending on
           the communication driver configured Oracle cluster traffic
           may be directed to the public interface of this machine.
           Oracle recommends that RAC clustered databases be configured
           with a private interconnect for enhanced security and
           performance.
Picked latch-free SCN scheme 3
Using LOG_ARCHIVE_DEST_1 parameter default value as /oracle/product/10.2/db_1/dbs/arch
Autotune of undo retention is turned on.
LICENSE_MAX_USERS = 0
SYS auditing is disabled
ksdpec: called for event 13740 prior to event group initialization
Starting up ORACLE RDBMS Version: 10.2.0.1.0.
System parameters with non-default values:
  processes                = 150
  __shared_pool_size       = 603979776
  __large_pool_size        = 16777216
  __java_pool_size         = 16777216
  __streams_pool_size      = 0
  spfile                   = +DG1/orcl/spfileorcl.ora
  sga_target               = 1258291200
  control_files            = +DG1/orcl/controlfile/current.260.668253151
  db_block_size            = 8192
  __db_cache_size          = 603979776
  compatible               = 10.2.0.1.0
  db_file_multiblock_read_count= 16
  cluster_database         = TRUE
  cluster_database_instances= 2
  db_create_file_dest      = +DG1
  thread                   = 2
  instance_number          = 2
  undo_management          = AUTO
  undo_tablespace          = UNDOTBS2
  remote_login_passwordfile= EXCLUSIVE
  db_domain                =
  dispatchers              = (PROTOCOL=TCP) (SERVICE=orclXDB)
  remote_listener          = LISTENERS_ORCL
  job_queue_processes      = 10
  background_dump_dest     = /oracle/admin/orcl/bdump
  user_dump_dest           = /oracle/admin/orcl/udump
  core_dump_dest           = /oracle/admin/orcl/cdump
  audit_file_dest          = /oracle/admin/orcl/adump
  db_name                  = orcl
  open_cursors             = 300
  pga_aggregate_target     = 418381824
Cluster communication is configured to use the following interface(s) for this instance
  10.10.0.20
Wed Apr 13 09:09:34 2011
cluster interconnect IPC version:Oracle UDP/IP
IPC Vendor 1 proto 2
PMON started with pid=2, OS id=2663
DIAG started with pid=3, OS id=2665
PSP0 started with pid=4, OS id=2671
LMON started with pid=5, OS id=2677
LMD0 started with pid=6, OS id=2680
LMS0 started with pid=7, OS id=2684
LMS1 started with pid=8, OS id=2688
MMAN started with pid=9, OS id=2693
DBW0 started with pid=10, OS id=2695
LGWR started with pid=11, OS id=2707
CKPT started with pid=12, OS id=2709
SMON started with pid=13, OS id=2711
RECO started with pid=14, OS id=2713
CJQ0 started with pid=15, OS id=2715
MMON started with pid=16, OS id=2717
MMNL started with pid=17, OS id=2719
Wed Apr 13 09:09:36 2011
starting up 1 dispatcher(s) for network address '(ADDRESS=(PARTIAL=YES)(PROTOCOL=TCP))'...
starting up 1 shared server(s) ...
Wed Apr 13 09:09:37 2011
lmon registered with NM - instance id 2 (internal mem no 1)
Wed Apr 13 09:09:38 2011
Reconfiguration started (old inc 0, new inc 52)
List of nodes:
 0 1
 Global Resource Directory frozen
* allocate domain 0, invalid = TRUE
 Communication channels reestablished
 * domain 0 valid = 1 according to instance 0
Wed Apr 13 09:09:40 2011
 Master broadcasted resource hash value bitmaps
 Non-local Process blocks cleaned out
Wed Apr 13 09:09:40 2011
 LMS 0: 0 GCS shadows cancelled, 0 closed
Wed Apr 13 09:09:40 2011
 LMS 1: 0 GCS shadows cancelled, 0 closed
 Set master node info
 Submitted all remote-enqueue requests
 Dwn-cvts replayed, VALBLKs dubious
 All grantable enqueues granted
Wed Apr 13 09:09:40 2011
 LMS 0: 0 GCS shadows traversed, 0 replayed
Wed Apr 13 09:09:40 2011
 LMS 1: 0 GCS shadows traversed, 0 replayed
Wed Apr 13 09:09:40 2011
 Submitted all GCS remote-cache requests
 Fix write in gcs resources
Reconfiguration complete
LCK0 started with pid=20, OS id=2812
Wed Apr 13 09:09:41 2011
ALTER DATABASE   MOUNT
Wed Apr 13 09:09:41 2011
Starting background process ASMB
ASMB started with pid=22, OS id=2844
Starting background process RBAL
RBAL started with pid=23, OS id=2848
Wed Apr 13 09:09:50 2011
SUCCESS: diskgroup DG1 was mounted
Wed Apr 13 09:09:54 2011
Setting recovery target incarnation to 2
Wed Apr 13 09:09:54 2011
Successful mount of redo thread 2, with mount id 1268597683
Wed Apr 13 09:09:54 2011
Database mounted in Shared Mode (CLUSTER_DATABASE=TRUE)
Completed: ALTER DATABASE   MOUNT
Wed Apr 13 09:09:55 2011
ALTER DATABASE OPEN
Picked broadcast on commit scheme to generate SCNs
Wed Apr 13 09:10:04 2011
Thread 2 opened at log sequence 1697
  Current log# 3 seq# 1697 mem# 0: +DG1/orcl/onlinelog/group_3.265.668253231
Successful open of redo thread 2
Wed Apr 13 09:10:04 2011
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Wed Apr 13 09:10:04 2011
SMON: enabling cache recovery
Wed Apr 13 09:10:05 2011
Successfully onlined Undo Tablespace 5.
Wed Apr 13 09:10:05 2011
SMON: enabling tx recovery
Wed Apr 13 09:10:05 2011
Database Characterset is ZHS16GBK
replication_dependency_tracking turned off (no async multimaster replication found)
Starting background process QMNC
QMNC started with pid=31, OS id=3588
Wed Apr 13 09:10:11 2011
Completed: ALTER DATABASE OPEN
经询问，是系统管理员调节了两台数据库的时间，导致数据库重启的。

后续解决方法还需要进一步研究，上报领导。

此外，这次检查日志还发现报：

Thread 1 advanced to log sequence 8501
  Current log# 2 seq# 8501 mem# 0: +DG1/orcl/onlinelog/group_2.262.668253153

//正常的日志切换记录

和Wed Apr 13 07:21:36 2011
Thread 1 cannot allocate new log, sequence 8488
Checkpoint not complete
  Current log# 2 seq# 8487 mem# 0: +DG1/orcl/onlinelog/group_2.262.668253153
Thread 1 advanced to log sequence 8488
  Current log# 1 seq# 8488 mem# 0: +DG1/orcl/onlinelog/group_1.261.668253153

//正常的日志切换记录

来自 “ ITPUB博客 ” ，链接：http://blog.itpub.net/14184018/viewspace-692374/，如需转载，请注明出处，否则将追究法律责任。

转载于:http://blog.itpub.net/14184018/viewspace-692374/