告警日志中出现ORA-7445[krslvna]错误,随后导致数据库的崩溃。
错误信息为:
Thu Sep 8 04:12:07 2011 Starting ORACLE instance (normal) LICENSE_MAX_SESSION = 0 LICENSE_SESSIONS_WARNING = 0 Interface TYPE 1 lan900 192.168.11.0 configured FROM OCR FOR USE AS a cluster interconnect Interface TYPE 1 lan901 10.142.132.0 configured FROM OCR FOR USE AS a public interface Picked latch-free SCN scheme 3 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.4.0. System parameters WITH non-DEFAULT VALUES: processes = 800 sessions = 885 sga_max_size = 77309411328 __shared_pool_size = 4194304000 __large_pool_size = 16777216 __java_pool_size = 16777216 __streams_pool_size = 0 spfile = /dev/vg1/spfile sga_target = 68719476736 control_files = /dev/vg1/control_01, /dev/vg2/control_02, /dev/vg3/control_03 db_block_size = 8192 __db_cache_size = 64474841088 compatible = 10.2.0.3.0 log_archive_config = DG_CONFIG=(ORCLS,ORCLP) log_archive_dest_1 = LOCATION=/arch1/archive_log log_archive_dest_2 = service=ORCLP LGWR ASYNC valid_for=(online_logfiles,primary_role) db_unique_name=ORCLP log_archive_trace = 12 fal_client = ORCLS fal_server = orclp db_file_multiblock_read_count= 16 cluster_database = TRUE cluster_database_instances= 2 standby_file_management = auto thread = 1 instance_number = 1 undo_management = AUTO undo_tablespace = UNDOTBS1 remote_login_passwordfile= EXCLUSIVE db_domain = service_names = ORCLS dispatchers = (PROTOCOL=TCP) (SERVICE=ORCLSXDB) local_listener = remote_listener = LISTENERS_ORCLS job_queue_processes = 10 background_dump_dest = /oracle/admin/orcls/bdump user_dump_dest = /oracle/admin/orcls/udump core_dump_dest = /oracle/admin/orcls/cdump audit_file_dest = /oracle/admin/orcls/adump db_name = orclp db_unique_name = orcls open_cursors = 300 pga_aggregate_target = 15032385536 Cluster communication IS configured TO USE the following interface(s) FOR this instance 192.168.11.3 Thu Sep 8 04:12:11 2011 cluster interconnect IPC version:Oracle UDP/IP (generic) IPC Vendor 1 proto 2 PMON started WITH pid=2, OS id=4960 DIAG started WITH pid=6, OS id=5290 PSP0 started WITH pid=10, OS id=5292 LMON started WITH pid=14, OS id=5294 LMD0 started WITH pid=18, OS id=5296 LMS0 started WITH pid=22, OS id=5298 LMS1 started WITH pid=26, OS id=5300 LMS2 started WITH pid=30, OS id=5307 LMS3 started WITH pid=34, OS id=5309 LMS4 started WITH pid=38, OS id=5311 MMAN started WITH pid=42, OS id=5313 DBW0 started WITH pid=46, OS id=5320 DBW1 started WITH pid=50, OS id=5322 DBW2 started WITH pid=54, OS id=5327 DBW3 started WITH pid=58, OS id=5334 LGWR started WITH pid=62, OS id=5336 CKPT started WITH pid=66, OS id=5338 SMON started WITH pid=70, OS id=5345 RECO started WITH pid=74, OS id=5347 CJQ0 started WITH pid=78, OS id=5349 MMON started WITH pid=82, OS id=5356 MMNL started WITH pid=86, OS id=5359 Thu Sep 8 04:13:12 2011 starting up 1 dispatcher(s) FOR network address '(ADDRESS=(PARTIAL=YES)(PROTOCOL=TCP))'... starting up 1 shared server(s) ... Thu Sep 8 04:13:22 2011 lmon registered WITH NM - instance id 1 (internal mem no 0) Thu Sep 8 04:13:22 2011 Reconfiguration started (OLD inc 0, NEW inc 2) List OF nodes: 0 Global Resource Directory frozen * allocate DOMAIN 0, invalid = TRUE Communication channels reestablished Master broadcasted resource hash VALUE bitmaps Non-LOCAL Process blocks cleaned OUT Thu Sep 8 04:13:23 2011 LMS 0: 0 GCS shadows cancelled, 0 closed Thu Sep 8 04:13:23 2011 LMS 4: 0 GCS shadows cancelled, 0 closed Thu Sep 8 04:13:23 2011 LMS 2: 0 GCS shadows cancelled, 0 closed Thu Sep 8 04:13:23 2011 LMS 1: 0 GCS shadows cancelled, 0 closed Thu Sep 8 04:13:23 2011 LMS 3: 0 GCS shadows cancelled, 0 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 Thu Sep 8 04:13:23 2011 LMS 0: 0 GCS shadows traversed, 0 replayed Thu Sep 8 04:13:23 2011 LMS 4: 0 GCS shadows traversed, 0 replayed Thu Sep 8 04:13:23 2011 LMS 2: 0 GCS shadows traversed, 0 replayed Thu Sep 8 04:13:23 2011 LMS 1: 0 GCS shadows traversed, 0 replayed Thu Sep 8 04:13:23 2011 LMS 3: 0 GCS shadows traversed, 0 replayed Thu Sep 8 04:13:23 2011 Submitted ALL GCS remote-cache requests Fix WRITE IN gcs resources Reconfiguration complete LCK0 started WITH pid=98, OS id=5462 Thu Sep 8 04:13:23 2011 ALTER DATABASE MOUNT Thu Sep 8 04:13:23 2011 This instance was FIRST TO mount Setting recovery target incarnation TO 2 Thu Sep 8 04:13:28 2011 Successful mount OF redo thread 1, WITH mount id 422802531 Thu Sep 8 04:13:28 2011 DATABASE mounted IN Shared Mode (CLUSTER_DATABASE=TRUE) Completed: ALTER DATABASE MOUNT Thu Sep 8 04:13:28 2011 ALTER DATABASE OPEN Thu Sep 8 04:13:28 2011 This instance was FIRST TO OPEN Picked broadcast ON commit scheme TO generate SCNs Thu Sep 8 04:13:28 2011 LGWR: STARTING ARCH PROCESSES ARC0 started WITH pid=102, OS id=5496 Thu Sep 8 04:13:28 2011 ARC0: Archival started ARC1: Archival started LGWR: STARTING ARCH PROCESSES COMPLETE (orcls1) Thu Sep 8 03:24:29 2011 ARC0: Closing LOCAL archive destination LOG_ARCHIVE_DEST_1: '/arch1/archive_log/1_15995_684332778.dbf' (orcls1) Thu Sep 8 03:24:32 2011 Media Recovery Log /arch1/archive_log/1_15995_684332778.dbf Media Recovery Waiting FOR thread 1 SEQUENCE 15996 Thu Sep 8 03:25:00 2011 Redo Shipping Client Connected AS PUBLIC -- Connected User is Valid RFS[31]: Assigned TO RFS process 15517 RFS[31]: IDENTIFIED DATABASE TYPE AS 'physical standby' RFS[31]: Successfully opened standby log 7: '/dev/vg_3GeSales_01/rlv_186_sdlog1_1_01' Thu Sep 8 03:25:03 2011 ARC1: Creating LOCAL archive destination LOG_ARCHIVE_DEST_1: '/arch1/archive_log/1_15996_684332778.dbf' (thread 1 SEQUENCE 15996) (orcls1) Thu Sep 8 03:25:04 2011 ARC1: Closing LOCAL archive destination LOG_ARCHIVE_DEST_1: '/arch1/archive_log/1_15996_684332778.dbf' (orcls1) Thu Sep 8 03:25:09 2011 Media Recovery Log /arch1/archive_log/1_15996_684332778.dbf Media Recovery Waiting FOR thread 1 SEQUENCE 15997 Thu Sep 8 03:32:59 2011 Redo Shipping Client Connected AS PUBLIC -- Connected User is Valid RFS[32]: Assigned TO RFS process 18698 RFS[32]: IDENTIFIED DATABASE TYPE AS 'physical standby' RFS[32]: Successfully opened standby log 7: '/dev/vg_3GeSales_01/rlv_186_sdlog1_1_01' Thu Sep 8 03:33:10 2011 ARC0: Creating LOCAL archive destination LOG_ARCHIVE_DEST_1: '/arch1/archive_log/1_15997_684332778.dbf' (thread 1 SEQUENCE 15997) (orcls1) Thu Sep 8 03:33:12 2011 ARC0: Closing LOCAL archive destination LOG_ARCHIVE_DEST_1: '/arch1/archive_log/1_15997_684332778.dbf' (orcls1) Thu Sep 8 03:33:16 2011 Media Recovery Log /arch1/archive_log/1_15997_684332778.dbf Media Recovery Waiting FOR thread 1 SEQUENCE 15998 Thu Sep 8 03:43:16 2011 Redo Shipping Client Connected AS PUBLIC -- Connected User is Valid RFS[33]: Assigned TO RFS process 22783 RFS[33]: IDENTIFIED DATABASE TYPE AS 'physical standby' RFS[33]: Successfully opened standby log 7: '/dev/vg_3GeSales_01/rlv_186_sdlog1_1_01' Thu Sep 8 03:43:16 2011 ARC1: Creating LOCAL archive destination LOG_ARCHIVE_DEST_1: '/arch1/archive_log/1_15998_684332778.dbf' (thread 1 SEQUENCE 15998) (orcls1) Thu Sep 8 03:43:16 2011 ARC1: Closing LOCAL archive destination LOG_ARCHIVE_DEST_1: '/arch1/archive_log/1_15998_684332778.dbf' (orcls1) Thu Sep 8 03:43:18 2011 Media Recovery Log /arch1/archive_log/1_15998_684332778.dbf Media Recovery Waiting FOR thread 1 SEQUENCE 15999 Thu Sep 8 03:43:45 2011 ALTER SYSTEM ARCHIVE LOG Thu Sep 8 03:52:03 2011 Redo Shipping Client Connected AS PUBLIC -- Connected User is Valid RFS[34]: Assigned TO RFS process 26342 RFS[34]: IDENTIFIED DATABASE TYPE AS 'physical standby' RFS[34]: Successfully opened standby log 7: '/dev/vg_3GeSales_01/rlv_186_sdlog1_1_01' Thu Sep 8 03:52:03 2011 ARC0: Creating LOCAL archive destination LOG_ARCHIVE_DEST_1: '/arch1/archive_log/1_15999_684332778.dbf' (thread 1 SEQUENCE 15999) (orcls1) Thu Sep 8 03:52:03 2011 ARC0: Closing LOCAL archive destination LOG_ARCHIVE_DEST_1: '/arch1/archive_log/1_15999_684332778.dbf' (orcls1) Thu Sep 8 03:52:03 2011 Media Recovery Log /arch1/archive_log/1_15999_684332778.dbf Media Recovery Waiting FOR thread 1 SEQUENCE 16000 Thu Sep 8 03:58:22 2011 Redo Shipping Client Connected AS PUBLIC -- Connected User is Valid RFS[35]: Assigned TO RFS process 28916 RFS[35]: IDENTIFIED DATABASE TYPE AS 'physical standby' RFS[35]: Successfully opened standby log 7: '/dev/vg_3GeSales_01/rlv_186_sdlog1_1_01' Thu Sep 8 03:58:29 2011 ARC1: Creating LOCAL archive destination LOG_ARCHIVE_DEST_1: '/arch1/archive_log/1_16000_684332778.dbf' (thread 1 SEQUENCE 16000) (orcls1) Thu Sep 8 03:58:30 2011 ARC1: Closing LOCAL archive destination LOG_ARCHIVE_DEST_1: '/arch1/archive_log/1_16000_684332778.dbf' (orcls1) Thu Sep 8 03:58:34 2011 Media Recovery Log /arch1/archive_log/1_16000_684332778.dbf Media Recovery Waiting FOR thread 1 SEQUENCE 16001 Thu Sep 8 04:04:52 2011 Redo Shipping Client Connected AS PUBLIC -- Connected User is Valid RFS[36]: Assigned TO RFS process 1725 RFS[36]: IDENTIFIED DATABASE TYPE AS 'physical standby' RFS[36]: Archived Log: '/arch1/archive_log/1_16001_684332778.dbf' Thu Sep 8 04:05:00 2011 Media Recovery Log /arch1/archive_log/1_16001_684332778.dbf IDENTIFIED End-Of-Redo FOR thread 1 SEQUENCE 16001 Thu Sep 8 04:05:07 2011 Media Recovery End-Of-Redo indicator encountered Thu Sep 8 04:05:08 2011 Media Recovery Applied until CHANGE 10988424928720 Thu Sep 8 04:05:08 2011 MRP0: Media Recovery Complete: End-Of-REDO (orcls1) Resetting standby activation ID 418471684 (0x18f15f04) Thu Sep 8 04:05:13 2011 MRP0: Background Media Recovery process shutdown (orcls1) Thu Sep 8 04:07:17 2011 ALTER DATABASE commit TO switchover TO PRIMARY WITH SESSION shutdown Thu Sep 8 04:07:17 2011 ALTER DATABASE SWITCHOVER TO PRIMARY (orcls1) Thu Sep 8 04:07:17 2011 IF media recovery active, switchover will wait 900 seconds Thu Sep 8 04:10:17 2011 SwitchOver after complete recovery through CHANGE 10988424928720 Thu Sep 8 04:10:40 2011 Standby became PRIMARY SCN: 10988424928718 Converting standby mount TO PRIMARY mount. Thu Sep 8 04:10:40 2011 Switchover: Complete - DATABASE mounted AS PRIMARY (orcls1) Completed: ALTER DATABASE commit TO switchover TO PRIMARY WITH SESSION shutdown Thu Sep 8 04:10:40 2011 ARC0: STARTING ARCH PROCESSES ARC2 started WITH pid=110, OS id=4267 Thu Sep 8 04:10:40 2011 ARC2: Archival started ARC0: STARTING ARCH PROCESSES COMPLETE Thu Sep 8 04:11:02 2011 ALTER DATABASE OPEN Thu Sep 8 04:11:02 2011 This instance was FIRST TO OPEN Picked broadcast ON commit scheme TO generate SCNs Thu Sep 8 04:11:02 2011 Assigning activation ID 422708933 (0x193206c5) LNSb started WITH pid=114, OS id=4419 Error 12541 received logging ON TO the standby CHECK whether the listener IS up AND running. Thu Sep 8 04:11:09 2011 Errors IN file /oracle/admin/orcls/bdump/orcls1_lgwr_10865.trc: ORA-12541: TNS:no listener Thu Sep 8 04:11:09 2011 LGWR: Error 12541 verifying archivelog destination LOG_ARCHIVE_DEST_2 LGWR: Continuing... Thu Sep 8 04:11:09 2011 Errors IN file /oracle/admin/orcls/bdump/orcls1_lgwr_10865.trc: ORA-07445: exception encountered: core dump [krslvna()+5073] [SIGSEGV] [Invalid permissions FOR mapped object] [0x000000254] [] [] Thu Sep 8 04:11:10 2011 Trace dumping IS performing id=[cdmp_20110908041110] Thu Sep 8 04:11:13 2011 Errors IN file /oracle/admin/orcls/bdump/orcls1_pmon_10481.trc: ORA-00470: LGWR process TERMINATED WITH error Thu Sep 8 04:11:13 2011 PMON: terminating instance due TO error 470 Thu Sep 8 04:11:15 2011 Shutting down instance (abort) License high water mark = 49 Thu Sep 8 04:11:23 2011 Termination issued TO instance processes. Waiting FOR the processes TO exit Thu Sep 8 04:11:29 2011 Instance termination failed TO KILL one OR more processes Instance TERMINATED BY PMON, pid = 10481 Thu Sep 8 04:11:39 2011 Termination issued TO instance processes. Waiting FOR the processes TO exit Thu Sep 8 04:11:45 2011 Instance termination failed TO KILL one OR more processes Instance TERMINATED BY USER, pid = 4542 |
其实跟错误相关的信息只有其中一两行,之所以列出这么多的信息,无非是要说明错误发生的具体环境,在错误发生之前做过DATA GUARD的SWITCHOVER,看来这个错误很可能与DATA GUARD有关。
查询结果也确实如此,在文档Bug 6490140 – LGWR may crash the instance [ID 6490140.8]描述了这个问题。当前数据库为主实例,且通过LGWR进程向远端写归档时可能碰到这个错误,而这个错误明显与DATA GUARD配置有关。确认影响的版本就是当前的10.2.0.4版本,Oracle在10.2.0.4 Data Guard Physical Recommended Patch Bundle #1、10.2.0.4.1、10.2.0.5和11.1.0.6中解决了这个问题。
从错误信息看,在这个ORA-7445错误出现之前,Oracle报了一个ORA-12541:no listener的错误,那么不难推测导致问题的原因在于LGWR写远端归档日志却发现远端没有配置监听,从而导致LGWR进程出现ORA-7445异常并退出,而LGWR进程的退出则意味着数据库的CRASH。
对于非DATA GUARD环境一般不会出现LGWR写远端归档的情况,而对于DATA GUARD环境,则要小心这个bug的产生。