I'm using Data Guard 11g on Windows Server 2012 64 Bit. I recently configured the broker in order to handle switchovers more comfortable.
Unfortunately the switchover doesn't work. Broker confguration seems fine, since I can activate t and redo apply is working perfectly...
Now, the behaviour is the following.... Once I commit the switchover via broker it shows the following:
DGMGRL> switchover to smart_stb
Performing switchover NOW, please wait...
Error: ORA-16665: timeout waiting for the result from a database
Failed.
Unable to switchover, primary database is still "smart"
The switchover itself does happen, there is no restart of the primary database though!! Doesn't seem to be related to a buggy DGMGRL service entry. Actually the database won't even come down. The primary is supending every process while trying to do so. Broker is running in a timeout of course, but the primary remains in a supending state. The primary doesn't seem to be able to cominicate with the standby side or vice versa. Which is odd since redo log shipping and apply is workng fine as mentioned... so does a manual switchover. I have no idea what could cause this kind of behavour... Double checked everything. Once I restart both databases and bring them into the right state the switchover is completed. But no need to say that this isn't the intention of using the broker....
drc.log primary shows the following:
2014-09-10 09:13:01.378 02000000 746441090 DMON: SWITCHOVER TO smart_stb
2014-09-10 09:13:01.378 02000000 746441090 DMON: start task execution: SWITCHOVER
2014-09-10 09:13:01.378 NSV1: Using RFIUPI_DGCI_CDESC
2014-09-10 09:13:01.409 NSV1: Using RFIUPI_DGCI_CDESC
2014-09-10 09:13:01.409 02001000 746441090 Notifying Oracle Clusterware to teardown primary database for SWITCHOVER
2014-09-10 09:13:01.425 CLSR: CRS not configured, config = 2
.
2014-09-10 09:13:01.425 02001000 746441090 DMON: posting primary instances for SWITCHOVER phase 1
2014-09-10 09:13:01.425 02001000 746441090 DMON: status from rfi_post_instances() for CTL_SWITCH = ORA-00000
2014-09-10 09:13:01.425 INSV: Received message for inter-instance publication
2014-09-10 09:13:01.425 02001000 746441090 DMON: dispersing message to standbys for SWITCHOVER phase BEGIN
2014-09-10 09:13:01.425 req ID 1.1.746441090, opcode CTL_SWITCH, phase BEGIN, flags 5
2014-09-10 09:13:01.425 NSV1: Using RFIUPI_DB_INST_CDESC
2014-09-10 09:13:01.425 02001000 746441090 DMON: Entered rfmsoexinst() for phase BEGIN
2014-09-10 09:13:01.425 INSV: Reply received for message with
2014-09-10 09:13:01.425 req ID 1.1.746441090, opcode CTL_SWITCH, phase BEGIN
2014-09-10 09:13:01.425 02001000 746441090 DMON: posting primary instances for SWITCHOVER phase 2
2014-09-10 09:13:01.440 02001000 746441090 DMON: status from rfi_post_instances() for CTL_SWITCH = ORA-00000
2014-09-10 09:13:01.440 INSV: Received message for inter-instance publication
2014-09-10 09:13:01.440 02001000 746441090 DMON: dispersing message to standbys for SWITCHOVER phase TEARDOWN
2014-09-10 09:13:01.440 req ID 1.1.746441090, opcode CTL_SWITCH, phase TEARDOWN, flags 5
2014-09-10 09:13:01.440 02001000 746441090 DMON: Entered rfmsoexinst() for phase TEARDOWN
2014-09-10 09:13:01.440 RSM0: Received Set State Request: rid=0x01041001, sid=0, phid=1, econd=2, sitehndl=0x02001000
2014-09-10 09:13:01.440 Log Transport Resource: SetState OFFLINE, phase TEAR-DOWN, External Cond SWITCH-OVER-PHYS_STBY
2014-09-10 09:13:01.440 RSM0: Received Set State Request: rid=0x01011001, sid=4, phid=1, econd=2, sitehndl=0x02001000
2014-09-10 09:13:01.440 Database Resource[IAM=PRIMARY]: SetState PHYSICAL-APPLY-ON, phase TEAR-DOWN, External Cond SWITCH-OVER-PHYS_STBY, Target Site Handle 0x02001000
2014-09-10 09:13:01.440 RSM0: Executing SQL [ALTER DATABASE COMMIT TO SWITCHOVER TO PHYSICAL STANDBY WITH SESSION SHUTDOWN]
2014-09-10 09:13:06.630 SQL [ALTER DATABASE COMMIT TO SWITCHOVER TO PHYSICAL STANDBY WITH SESSION SHUTDOWN] Executed successfully
2014-09-10 09:13:06.630 RSM: clearing IncarnationTable internal property of site 0x01010000
2014-09-10 09:13:06.630 02001000 746441090 DMON: Broker determines that instance restart is required: Operation = SWITCHOVER status = ORA-16570
2014-09-10 09:13:06.630 02001000 746441090 Resource: smart (01011001) State: PHYSICAL-APPLY-ON
2014-09-10 09:13:06.630 INSV: Reply received for message with
2014-09-10 09:13:06.630 req ID 1.1.746441090, opcode CTL_SWITCH, phase TEARDOWN
2014-09-10 09:13:06.630 02001000 746441090 DMON: Instance "smart" (ID 1) returned ORA-16570
2014-09-10 09:13:06.630 02001000 746441090 for phase TEARDOWN of operation CTL_SWITCH
2014-09-10 09:13:06.646 NSV1: Using RFIUPI_DGCI_CDESC
2014-09-10 09:13:06.646 02001000 746441090 DMON: posting primary instances for SWITCHOVER phase 2
2014-09-10 09:13:06.646 INSV: Received message for inter-instance publication
2014-09-10 09:13:06.646 02001000 746441090 DMON: status from rfi_post_instances() for CTL_SWITCH = ORA-00000
2014-09-10 09:13:06.646 req ID 1.1.746441090, opcode CTL_SWITCH, phase TEARDOWN, flags 5
2014-09-10 09:13:06.646 02001000 746441090 DMON: dispersing message to standbys for SWITCHOVER phase TEARDOWN
2014-09-10 09:13:06.646 02001000 746441090 DMON: Entered rfmsoexinst() for phase TEARDOWN
2014-09-10 09:13:06.646 NSV1: Using RFIUPI_DB_INST_CDESC
2014-09-10 09:13:06.646 INSV: Reply received for message with
2014-09-10 09:13:06.646 req ID 1.1.746441090, opcode CTL_SWITCH, phase TEARDOWN
2014-09-10 09:13:06.646 02001000 746441090 DMON: Instance "smart" (ID 1) returned ORA-16570
2014-09-10 09:13:06.646 02001000 746441090 for phase TEARDOWN of operation CTL_SWITCH
2014-09-10 09:13:28.619 NSV1: Using RFIUPI_DB_INST_CDESC
2014-09-10 09:13:28.619 NSV1: Site smart_stb returned ORA-16665.
2014-09-10 09:13:43.620 NSV1: Using RFIUPI_DB_INST_CDESC
2014-09-10 09:13:43.620 NSV1: Site smart_stb returned ORA-16665.
2014-09-10 09:13:58.639 NSV1: Using RFIUPI_DB_INST_CDESC
2014-09-10 09:13:58.639 NSV1: Site smart_stb returned ORA-16665.
2014-09-10 09:14:13.657 NSV1: Using RFIUPI_DB_INST_CDESC
2014-09-10 09:14:13.657 NSV1: Site smart_stb returned ORA-16665.
2014-09-10 09:14:28.674 NSV1: Using RFIUPI_DB_INST_CDESC
2014-09-10 09:14:28.674 NSV1: Site smart_stb returned ORA-16665.
2014-09-10 09:14:43.676 NSV1: Using RFIUPI_DB_INST_CDESC
2014-09-10 09:14:43.676 NSV1: Site smart_stb returned ORA-16665.
2014-09-10 09:14:58.693 NSV1: Using RFIUPI_DB_INST_CDESC
2014-09-10 09:14:58.693 NSV1: Site smart_stb returned ORA-16665.
2014-09-10 09:15:13.695 NSV1: Using RFIUPI_DB_INST_CDESC
2014-09-10 09:15:13.695 NSV1: Site smart_stb returned ORA-16665.
2014-09-10 09:15:28.707 NSV1: Using RFIUPI_DB_INST_CDESC
2014-09-10 09:15:28.707 NSV1: Site smart_stb returned ORA-16665.
2014-09-10 09:15:43.724 NSV1: Using RFIUPI_DB_INST_CDESC
2014-09-10 09:15:43.724 NSV1: Site smart_stb returned ORA-16665.
2014-09-10 09:15:58.726 NSV1: Using RFIUPI_DB_INST_CDESC
2014-09-10 09:15:58.726 NSV1: Site smart_stb returned ORA-16665.
2014-09-10 09:16:13.727 NSV1: Using RFIUPI_DB_INST_CDESC
2014-09-10 09:16:13.727 NSV1: Site smart_stb returned ORA-16665.
2014-09-10 09:16:28.729 02001000 746441090 DMON: Database smart_stb returned ORA-16665
2014-09-10 09:16:28.729 02001000 746441090 for opcode = CTL_SWITCH, phase = TEARDOWN, req_id = 1.1.746441090
2014-09-10 09:16:28.729 02001000 746441090 Operation CTL_SWITCH canceled during phase 2, error = ORA-16665
2014-09-10 09:16:28.729 02001000 746441090 DMON: Switchover operation failed with status ORA-16665
2014-09-10 09:16:28.729 NSV1: Using RFIUPI_DGCI_CDESC
2014-09-10 09:16:28.744 02001000 746441090 DMON: posting primary instances for SWITCHOVER phase 5
2014-09-10 09:16:28.744 INSV: Received message for inter-instance publication
2014-09-10 09:16:28.744 02001000 746441090 DMON: status from rfi_post_instances() for CTL_SWITCH = ORA-00000
2014-09-10 09:16:28.744 req ID 1.1.746441090, opcode CTL_SWITCH, phase END, flags 5
2014-09-10 09:16:28.744 02001000 746441090 DMON: Switchover Aborted due to errors
2014-09-10 09:16:28.744 02001000 746441090 Site named: smart is still primary
2014-09-10 09:16:28.744 02001000 746441090 error = ORA-16665
drc.log standby shows the following:
2014-09-10 09:13:01.352 02001000 746441090 Notifying Oracle Clusterware to teardown target standby database for SWITCHOVER
2014-09-10 09:13:01.367 CLSR: CRS not configured, config = 2
.
2014-09-10 09:13:01.367 02001000 746441090 DMON: posting standby instances for SWITCHOVER phase 1
2014-09-10 09:13:01.367 INSV: Received message for inter-instance publication
2014-09-10 09:13:01.367 req ID 1.1.746441090, opcode CTL_SWITCH, phase BEGIN, flags 5
2014-09-10 09:13:01.367 02001000 746441090 DMON: Entered rfmsoexinst() for phase BEGIN
2014-09-10 09:13:01.367 INSV: Reply received for message with
2014-09-10 09:13:01.367 req ID 1.1.746441090, opcode CTL_SWITCH, phase BEGIN
2014-09-10 09:13:01.367 02001000 746441090 DMON: Entered rfm_release_chief_lock() for CTL_SWITCH
2014-09-10 09:13:06.571 02001000 746441090 DMON: Entered rfm_get_chief_lock() for CTL_SWITCH, reason 0
2014-09-10 09:13:06.571 02001000 746441090 DMON: start task execution: SWITCHOVER
2014-09-10 09:13:06.586 02001000 746441090 DMON: posting standby instances for SWITCHOVER phase 2
2014-09-10 09:13:06.586 INSV: Received message for inter-instance publication
2014-09-10 09:13:06.586 req ID 1.1.746441090, opcode CTL_SWITCH, phase TEARDOWN, flags 5
2014-09-10 09:13:06.586 02001000 746441090 DMON: Entered rfmsoexinst() for phase TEARDOWN
2014-09-10 09:13:06.586 RSM0: Received Set State Request: rid=0x02031001, sid=0, phid=1, econd=2, sitehndl=0x02001000
2014-09-10 09:13:06.586 Redo Apply Resource: SetState OFFLINE, phase TEAR-DOWN, External Cond SWITCH-OVER-PHYS_STBY
2014-09-10 09:13:06.586 RSM0: Received Set State Request: rid=0x02012001, sid=9, phid=1, econd=2, sitehndl=0x02001000
2014-09-10 09:13:06.586 Database Resource[IAM=PHYSICAL]: SetState READ-WRITE-XPTON, phase TEAR-DOWN, External Cond SWITCH-OVER-PHYS_STBY, Target Site Handle 0x02001000
2014-09-10 09:13:06.586 RSM0: Executing SQL [ALTER DATABASE RECOVER MANAGED STANDBY DATABASE CANCEL]
2014-09-10 09:13:07.602 SQL [ALTER DATABASE RECOVER MANAGED STANDBY DATABASE CANCEL] Executed successfully
2014-09-10 09:13:07.711 RSM0: Executing SQL [ALTER DATABASE RECOVER MANAGED STANDBY DATABASE THROUGH LAST SWITCHOVER NODELAY]
2014-09-10 09:13:09.509 SQL [ALTER DATABASE RECOVER MANAGED STANDBY DATABASE THROUGH LAST SWITCHOVER NODELAY] Executed successfully
2014-09-10 09:13:09.509 RSM0: Executing SQL [ALTER DATABASE COMMIT TO SWITCHOVER TO PRIMARY WAIT WITH SESSION SHUTDOWN]
2014-09-10 09:13:11.345 SQL [ALTER DATABASE COMMIT TO SWITCHOVER TO PRIMARY WAIT WITH SESSION SHUTDOWN] Executed successfully
2014-09-10 09:13:11.345 Database Resource SetState succeeded
2014-09-10 09:13:11.345 INSV: Reply received for message with
2014-09-10 09:13:11.345 req ID 1.1.746441090, opcode CTL_SWITCH, phase TEARDOWN
2014-09-10 09:13:11.345 02001000 746441090 DMON: Entered rfm_release_chief_lock() for CTL_SWITCH
2014-09-10 09:13:28.555 drcx: Found task req_id=1.1.746441090 for PROBE, but the phase is done
2014-09-10 09:13:43.555 drcx: Found task req_id=1.1.746441090 for PROBE, but the phase is done
2014-09-10 09:13:58.571 drcx: Found task req_id=1.1.746441090 for PROBE, but the phase is done
2014-09-10 09:14:13.590 drcx: Found task req_id=1.1.746441090 for PROBE, but the phase is done
2014-09-10 09:14:28.605 drcx: Found task req_id=1.1.746441090 for PROBE, but the phase is done
2014-09-10 09:14:43.606 drcx: Found task req_id=1.1.746441090 for PROBE, but the phase is done
2014-09-10 09:14:58.622 drcx: Found task req_id=1.1.746441090 for PROBE, but the phase is done
2014-09-10 09:15:13.625 drcx: Found task req_id=1.1.746441090 for PROBE, but the phase is done
2014-09-10 09:15:28.641 drcx: Found task req_id=1.1.746441090 for PROBE, but the phase is done
2014-09-10 09:15:43.646 drcx: Found task req_id=1.1.746441090 for PROBE, but the phase is done
2014-09-10 09:15:58.652 drcx: Found task req_id=1.1.746441090 for PROBE, but the phase is done
2014-09-10 09:16:13.653 drcx: Found task req_id=1.1.746441090 for PROBE, but the phase is done
2014-09-10 09:16:27.606 02001000 746441090 DMON: Data Guard Broker terminating NSV0, timed out waiting for a response from database smart
2014-09-10 09:16:27.825 02001000 746441090 DMON: Database smart returned ORA-16662
2014-09-10 09:16:27.825 02001000 746441090 for opcode = CTL_SWITCH, phase = RESYNCH, req_id = 1.1.746441090
2014-09-10 09:16:42.840 02001000 746441090 DMON: Data Guard Broker terminating NSV0, timed out waiting for a response from database smart
2014-09-10 09:16:42.840 02001000 746441090 DMON: Database smart returned ORA-16662
2014-09-10 09:16:42.840 02001000 746441090 for opcode = CTL_SWITCH, phase = RESYNCH, req_id = 1.1.746441090
2014-09-10 09:16:57.861 02001000 746441090 DMON: Data Guard Broker terminating NSV0, timed out waiting for a response from database smart
2014-09-10 09:16:57.861 02001000 746441090 DMON: Database smart returned ORA-16662
2014-09-10 09:16:57.861 02001000 746441090 for opcode = CTL_SWITCH, phase = RESYNCH, req_id = 1.1.746441090
2014-09-10 09:16:58.705 00001000 746441091 DMON: Entered rfm_get_chief_lock() for HEALTH_CHECK, reason 0
2014-09-10 09:16:58.705 00001000 746441091 DMON: Freeing orphaned task 1.1.746441090, opcode=CTL_SWITCH.
2014-09-10 09:16:58.705 00001000 746441091 DMON: start task execution: automatic healthcheck
2014-09-10 09:16:58.720 00001000 746441091 DMON: Start health check
2014-09-10 09:16:58.720 INSV: Received message for inter-instance publication
2014-09-10 09:16:58.720 00001000 746441091 DMON: status from rfi_post_instances() = ORA-00000
2014-09-10 09:16:58.720 req ID 1.1.746441091, opcode HEALTH_CHECK, phase BEGIN, flags 5
2014-09-10 09:16:58.720 00000000 746441091 DMON: Entered rfmhcexinst
2014-09-10 09:16:58.720 00000000 746441091 DMON: rfmhcexinst calling RSMs
2014-09-10 09:16:58.720 RSM0: Received Get Status Request: rid=0x02012001, sid=4
2014-09-10 09:16:58.720 RSM0: HEALTH CHECK ERROR: ORA-16816: incorrect database role
2014-09-10 09:16:58.720 Warning: the given scn 281474976710655 with resetlogs_id = 851952614 is less than the resetlogs_change# 744657 of the same incarnation.
2014-09-10 09:16:58.736 Current IncarnationTable value is:
2014-09-10 09:16:58.736 2,744657,851952614,1,*1,1,851351631,0,#
2014-09-10 09:16:58.736 RSM0: HEALTH CHECK ERROR: ORA-16700: the standby database has diverged from the primary database
2014-09-10 09:16:58.970 00000000 746441091 Operation HEALTH_CHECK canceled during phase 1, error = ORA-16810
2014-09-10 09:16:58.970 RSM0: Received Get Status Request: rid=0x02031001, sid=1
2014-09-10 09:16:58.970 00000000 746441091 DMON: Standby Instance completed health check
2014-09-10 09:16:58.970 INSV: Reply received for message with
2014-09-10 09:16:58.970 req ID 1.1.746441091, opcode HEALTH_CHECK, phase BEGIN
2014-09-10 09:16:58.970 DMON: HEALTH CHECK ERROR: ORA-16766: Redo Apply is stopped
2014-09-10 09:16:58.970 DMON: After H/C aggregation, db 0x02001000 has severity=16501, status=16810
2014-09-10 09:16:58.970 00000000 746441091 Operation HEALTH_CHECK canceled during phase 1, error = ORA-16810
2014-09-10 09:16:58.970 INSV: Received message for inter-instance publication
2014-09-10 09:16:58.970 req ID 1.1.746441091, opcode HEALTH_CHECK, phase BEGIN, flags 20005
2014-09-10 09:16:58.970 DMON: After H/C aggregation, db 0x02001000 has severity=16501, status=16810
2014-09-10 09:16:58.970 INSV: Reply received for message with
2014-09-10 09:16:58.970 req ID 1.1.746441091, opcode HEALTH_CHECK, phase BEGIN
2014-09-10 09:17:02.017 00000000 746441091 DMON: Entered rfm_release_chief_lock() for HEALTH_CHECK
2014-09-10 09:17:13.724 drcx: could not find task req_id=1.1.746441091 for PROBE.
2014-09-10 09:17:28.730 drcx: could not find task req_id=1.1.746441091 for PROBE.
alert.log primary shows the following:
LNS: Standby redo logfile selected for thread 1 sequence 12046 for destination LOG_ARCHIVE_DEST_2
Wed Sep 10 09:13:01 2014
ALTER DATABASE COMMIT TO SWITCHOVER TO PHYSICAL STANDBY WITH SESSION SHUTDOWN
Wed Sep 10 09:13:01 2014
Thread 1 advanced to log sequence 12047 (LGWR switch)
Current log# 2 seq# 12047 mem# 0: X:\SMART\LOG1\SMART_21.LOG
Current log# 2 seq# 12047 mem# 1: Y:\SMART\LOG2\SMART_22.LOG
Stopping background process QMNC
Wed Sep 10 09:13:01 2014
ARC1: Evaluating archive log 1 thread 1 sequence 12046
CLOSE: killing server sessions.
Active process 15708 user 'SYSTEM' program 'ORACLE.EXE (W000)'
Active process 15708 user 'SYSTEM' program 'ORACLE.EXE (W000)'
Active process 13372 user 'SYSTEM' program 'ORACLE.EXE (W001)'
Active process 13372 user 'SYSTEM' program 'ORACLE.EXE (W001)'
Active process 15708 user 'SYSTEM' program 'ORACLE.EXE (W000)'
Active process 15708 user 'SYSTEM' program 'ORACLE.EXE (W000)'
Active process 13372 user 'SYSTEM' program 'ORACLE.EXE (W001)'
Active process 13372 user 'SYSTEM' program 'ORACLE.EXE (W001)'
Active process 15708 user 'SYSTEM' program 'ORACLE.EXE (W000)'
Active process 15708 user 'SYSTEM' program 'ORACLE.EXE (W000)'
Active process 13372 user 'SYSTEM' program 'ORACLE.EXE (W001)'
Active process 13372 user 'SYSTEM' program 'ORACLE.EXE (W001)'
Active process 15708 user 'SYSTEM' program 'ORACLE.EXE (W000)'
Active process 15708 user 'SYSTEM' program 'ORACLE.EXE (W000)'
Active process 13372 user 'SYSTEM' program 'ORACLE.EXE (W001)'
Active process 13372 user 'SYSTEM' program 'ORACLE.EXE (W001)'
Active process 15708 user 'SYSTEM' program 'ORACLE.EXE (W000)'
Active process 15708 user 'SYSTEM' program 'ORACLE.EXE (W000)'
Active process 13372 user 'SYSTEM' program 'ORACLE.EXE (W001)'
Active process 13372 user 'SYSTEM' program 'ORACLE.EXE (W001)'
Active process 15708 user 'SYSTEM' program 'ORACLE.EXE (W000)'
Active process 15708 user 'SYSTEM' program 'ORACLE.EXE (W000)'
Active process 13372 user 'SYSTEM' program 'ORACLE.EXE (W001)'
Active process 13372 user 'SYSTEM' program 'ORACLE.EXE (W001)'
CLOSE: all sessions shutdown successfully.
krss_find_arc: Selecting ARC2 to receive message as last resort
Waiting for all non-current ORLs to be archived...
Waiting for the ORL for thread 1 sequence 12046 to be archived...
Wed Sep 10 09:13:02 2014
ARC0: Evaluating archive log 1 thread 1 sequence 12046
Wed Sep 10 09:13:02 2014
ARC2: Evaluating archive log 1 thread 1 sequence 12046
ARC0: Unable to archive thread 1 sequence 12046
Log actively being archived by another process
ARC2: Unable to archive thread 1 sequence 12046
Log actively being archived by another process
Committing creation of archivelog 'W:\SMART\ARC\SMART_12046_1_851952614.ARC'
Archived Log entry 19372 added for thread 1 sequence 12046 ID 0xab72f94c dest 1:
ORL for thread 1 sequence 12046 has been archived...
All non-current ORLs have been archived.
Waiting for all FAL entries to be archived...
All FAL entries have been archived.
Waiting for dest_id 2 to become synchronized...
OCISessionBegin with PasswordVerifier succeeded
Client pid [12320] attached to RFS pid [3648] at remote instance number [1] at dest 'smart_dg_stb'
Active, synchronized Physical Standby switchover target has been identified
Switchover End-Of-Redo Log thread 1 sequence 12047 has been fixed
Switchover: Primary highest seen SCN set to 0x0.0x22345d2
ARCH: Noswitch archival of thread 1, sequence 12047
ARCH: End-Of-Redo Branch archival of thread 1 sequence 12047
ARCH: Evaluating archive log 2 thread 1 sequence 12047
ARCH: LGWR is actively archiving destination LOG_ARCHIVE_DEST_2
ARCH: Transmitting activation ID 0xab72f94c
OCISessionBegin with PasswordVerifier succeeded
Client pid [12244] attached to RFS pid [9972] at remote instance number [1] at dest 'smart_dg_stb'
ARCH: Standby redo logfile selected for thread 1 sequence 12047 for destination LOG_ARCHIVE_DEST_2
Committing creation of archivelog 'W:\SMART\ARC\SMART_12047_1_851952614.ARC'
Archived Log entry 19373 added for thread 1 sequence 12047 ID 0xab72f94c dest 1:
Archived Log entry 19374 added for thread 1 sequence 12047 ID 0xab72f94c dest 2:
ARCH: Archiving is disabled due to current logfile archival
Primary will check for some target standby to have received alls redo
Final check for a synchronized target standby. Check will be made once.
ARCH: Transmitting activation ID 0xab72f94c
LOG_ARCHIVE_DEST_2 is a potential Physical Standby switchover target
Active, synchronized target has been identified
Target has also received all redo
-----------------------------------------------------------
| Target Standby Status |
| LOG_ARCHIVE_DEST_1 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_2 : HAS RECEIVED ALL DATA |
| LOG_ARCHIVE_DEST_3 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_4 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_5 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_6 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_7 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_8 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_9 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_10 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_11 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_12 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_13 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_14 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_15 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_16 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_17 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_18 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_19 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_20 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_21 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_22 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_23 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_24 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_25 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_26 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_27 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_28 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_29 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_30 : NOT ACTIVE |
| LOG_ARCHIVE_DEST_31 : NOT ACTIVE |
------------------------------------------------------------
Backup controlfile written to trace file D:\ORACLE\ORA_DBA\SMART\TRACE\diag\rdbms\smart\smart\trace\smart_rsm0_12244.trc
Clearing standby activation ID 2876438860 (0xab72f94c)
The primary database controlfile was created using the
'MAXLOGFILES 255' clause.
There is space for up to 251 standby redo logfiles
Use the following SQL commands on the standby database to create
standby redo logfiles that match the primary database:
ALTER DATABASE ADD STANDBY LOGFILE 'srl1.f' SIZE 52428800;
ALTER DATABASE ADD STANDBY LOGFILE 'srl2.f' SIZE 52428800;
ALTER DATABASE ADD STANDBY LOGFILE 'srl3.f' SIZE 52428800;
ALTER DATABASE ADD STANDBY LOGFILE 'srl4.f' SIZE 52428800;
ALTER DATABASE ADD STANDBY LOGFILE 'srl5.f' SIZE 52428800;
Archivelog for thread 1 sequence 12047 required for standby recovery
Switchover: Primary controlfile converted to standby controlfile succesfully.
Switchover: Complete - Database shutdown required
Completed: ALTER DATABASE COMMIT TO SWITCHOVER TO PHYSICAL STANDBY WITH SESSION SHUTDOWN
Wed Sep 10 09:13:20 2014
Process (ospid 12320) is suspended due to switchover to physical standby operation.
Wed Sep 10 09:16:58 2014
Process (ospid 12244) is suspended due to switchover to physical standby operation.
Wed Sep 10 09:17:08 2014
Process (ospid 3080) is suspended due to switchover to physical standby operation.
Wed Sep 10 09:17:09 2014
Process (ospid 12636) is suspended due to switchover to physical standby operation.
Wed Sep 10 09:17:10 2014
Process (ospid 5292) is suspended due to switchover to physical standby operation.
Wed Sep 10 09:17:43 2014
Process RSM0, PID = 12244, will be killed
Wed Sep 10 09:17:44 2014
RSM0 started with pid=27, OS id=16280
Wed Sep 10 09:20:56 2014
minact-scn: got error during useg scan e:12751 usn:6
minact-scn: useg scan erroring out with error e:12751
Wed Sep 10 09:21:19 2014
Process (ospid 16280) is suspended due to switchover to physical standby operation.
Wed Sep 10 09:22:04 2014
Process RSM0, PID = 16280, will be killed
Wed Sep 10 09:22:05 2014
RSM0 started with pid=27, OS id=10528
Wed Sep 10 09:25:39 2014
Process (ospid 10528) is suspended due to switchover to physical standby operation.
Wed Sep 10 09:26:03 2014
minact-scn: got error during useg scan e:12751 usn:6
minact-scn: useg scan erroring out with error e:12751
Wed Sep 10 09:26:24 2014
Process RSM0, PID = 10528, will be killed
Wed Sep 10 09:26:25 2014
RSM0 started with pid=27, OS id=15752
Wed Sep 10 09:29:59 2014
Process (ospid 15752) is suspended due to switchover to physical standby operation.
Wed Sep 10 09:30:44 2014
Process RSM0, PID = 15752, will be killed
Wed Sep 10 09:30:45 2014
RSM0 started with pid=27, OS id=1972
Wed Sep 10 09:31:09 2014
minact-scn: got error during useg scan e:12751 usn:6
minact-scn: useg scan erroring out with error e:12751
Suspending MMON action 'Block Cleanout Optim, Undo Segment Scan' for 82800 seconds
Wed Sep 10 09:34:19 2014
Process (ospid 1972) is suspended due to switchover to physical standby operation.
alert-log standby shows the following:
Wed Sep 10 09:13:01 2014
ARC3: Evaluating archive log 5 thread 1 sequence 12046
Committing creation of archivelog 'W:\SMART\ARC\SMART_12046_1_851952614.ARC'
Archived Log entry 5932 added for thread 1 sequence 12046 ID 0xab72f94c dest 1:
Wed Sep 10 09:13:01 2014
Media Recovery Waiting for thread 1 sequence 12047
Wed Sep 10 09:13:04 2014
Redo Shipping Client Connected as PUBLIC
-- Connected User is Valid
RFS[6]: Assigned to RFS process 3648
RFS[6]: Identified database type as 'physical standby': Client is ARCH pid 12320
Wed Sep 10 09:13:06 2014
Redo Shipping Client Connected as PUBLIC
-- Connected User is Valid
RFS[7]: Assigned to RFS process 9972
RFS[7]: Identified database type as 'physical standby': Client is Foreground pid 12244
RFS[7]: End-Of-Redo archival of thread 1 sequence 12047
RFS[7]: Successfully opened standby log 5: 'Y:\SMART\LOG2\SMART_S_5.LOG'
RFS[7]: Selected log 5 for thread 1 sequence 12047 dbid -1425016497 branch 851952614
Wed Sep 10 09:13:06 2014
ARC1: Evaluating archive log 5 thread 1 sequence 12047
Committing creation of archivelog 'W:\SMART\ARC\SMART_12047_1_851952614.ARC'
Archived Log entry 5933 added for thread 1 sequence 12047 ID 0xab72f94c dest 1:
Wed Sep 10 09:13:06 2014
ALTER DATABASE RECOVER MANAGED STANDBY DATABASE CANCEL
MRP0: Background Media Recovery cancelled with status 16037
Errors in file D:\ORACLE\ORA_DBA\SMART\TRACE\diag\rdbms\smart_stb\smart\trace\smart_pr00_13804.trc:
ORA-16037: user requested cancel of managed recovery operation
Managed Standby Recovery not using Real Time Apply
Recovery interrupted!
Errors in file D:\ORACLE\ORA_DBA\SMART\TRACE\diag\rdbms\smart_stb\smart\trace\smart_pr00_13804.trc:
ORA-16037: user requested cancel of managed recovery operation
Wed Sep 10 09:13:07 2014
Errors in file D:\ORACLE\ORA_DBA\SMART\TRACE\diag\rdbms\smart_stb\smart\trace\smart_mrp0_11168.trc:
ORA-10877: error signaled in parallel recovery slave
Completed: ALTER DATABASE RECOVER MANAGED STANDBY DATABASE CANCEL
Database not available for switchover
End-Of-REDO archived log file has not been recovered
Incomplete recovery SCN:0:35846057 archive SCN:0:35866066
ALTER DATABASE RECOVER MANAGED STANDBY DATABASE THROUGH LAST SWITCHOVER NODELAY
started logmerger process
Wed Sep 10 09:13:07 2014
Managed Standby Recovery not using Real Time Apply
Parallel Media Recovery started with 8 slaves
Media Recovery Log W:\SMART\ARC\SMART_12047_1_851952614.ARC
Identified End-Of-Redo (switchover) for thread 1 sequence 12047 at SCN 0x0.22345d2
Resetting standby activation ID 2876438860 (0xab72f94c)
Media Recovery End-Of-Redo indicator encountered
Media Recovery Applied through change 35866066
Attempt to set limbo arscn 0:35866066 irscn 0:35866066
Completed: ALTER DATABASE RECOVER MANAGED STANDBY DATABASE THROUGH LAST SWITCHOVER NODELAY
ALTER DATABASE COMMIT TO SWITCHOVER TO PRIMARY WAIT WITH SESSION SHUTDOWN
Maximum wait for role transition is 15 minutes.
krsv_proc_kill: Killing 2 processes (all RFS)
Backup controlfile written to trace file D:\ORACLE\ORA_DBA\SMART\TRACE\diag\rdbms\smart_stb\smart\trace\smart_rsm0_14652.trc
SwitchOver after complete recovery through change 35866066
Online log X:\SMART\LOG1\SMART_11.LOG: Thread 1 Group 1 was previously cleared
Online log Y:\SMART\LOG2\SMART_12.LOG: Thread 1 Group 1 was previously cleared
Online log X:\SMART\LOG1\SMART_21.LOG: Thread 1 Group 2 was previously cleared
Online log Y:\SMART\LOG2\SMART_22.LOG: Thread 1 Group 2 was previously cleared
Online log X:\SMART\LOG1\SMART_31.LOG: Thread 1 Group 3 was previously cleared
Online log Y:\SMART\LOG2\SMART_32.LOG: Thread 1 Group 3 was previously cleared
Online log X:\SMART\LOG1\SMART_41.LOG: Thread 1 Group 4 was previously cleared
Online log Y:\SMART\LOG2\SMART_42.LOG: Thread 1 Group 4 was previously cleared
Standby became primary SCN: 35866064
Switchover: Complete - Database mounted as primary
Completed: ALTER DATABASE COMMIT TO SWITCHOVER TO PRIMARY WAIT WITH SESSION SHUTDOWN
Wed Sep 10 09:13:45 2014
ARC0: Becoming the 'no SRL' ARCH
Wed Sep 10 09:13:46 2014
ARC3: Becoming the 'no SRL' ARCH
Wed Sep 10 09:13:46 2014
ARC1: Becoming the 'no SRL' ARCH
Wed Sep 10 09:16:58 2014
NSV0 started with pid=26, OS id=15900
Wed Sep 10 09:21:20 2014
DMON: NSV0 network call timeout. Killing it now.
Setup is the following:
DGMGRL> show configuration;
Configuration - dg_smart
Protection Mode: MaxPerformance
Databases:
smart - Primary database
smart_stb - Physical standby database
Fast-Start Failover: DISABLED
Configuration Status:
SUCCESS
DGMGRL> show database verbose smart
Database - smart
Role: PRIMARY
Intended State: TRANSPORT-ON
Instance(s):
smart
Properties:
DGConnectIdentifier = 'smart_dg_prim'
ObserverConnectIdentifier = ''
LogXptMode = 'ASYNC'
DelayMins = '0'
Binding = 'optional'
MaxFailure = '0'
MaxConnections = '1'
ReopenSecs = '300'
NetTimeout = '30'
RedoCompression = 'DISABLE'
LogShipping = 'ON'
PreferredApplyInstance = ''
ApplyInstanceTimeout = '0'
ApplyParallel = 'AUTO'
StandbyFileManagement = 'AUTO'
ArchiveLagTarget = '300'
LogArchiveMaxProcesses = '4'
LogArchiveMinSucceedDest = '1'
DbFileNameConvert = ''
LogFileNameConvert = 'X:\SMART\LOG1, X:\SMART\LOG1, Y:\SMART\LOG2, Y:\SMART\LOG2'
FastStartFailoverTarget = ''
InconsistentProperties = '(monitor)'
InconsistentLogXptProps = '(monitor)'
SendQEntries = '(monitor)'
LogXptStatus = '(monitor)'
RecvQEntries = '(monitor)'
SidName = 'smart'
StaticConnectIdentifier = '(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=host02)(PORT=1599))(CONNECT_DATA=(SERVICE_NAME=smart_DGMGRL)(INSTANCE_NAME=smart)(SERVER=DEDICATED)))'
StandbyArchiveLocation = 'W:\SMART\arc\'
AlternateLocation = ''
LogArchiveTrace = '8191'
LogArchiveFormat = 'smart_%s_%t_%r.arc'
TopWaitEvents = '(monitor)'
Database Status:
SUCCESS
DGMGRL> show database verbose smart_stb
Database - smart_stb
Role: PHYSICAL STANDBY
Intended State: APPLY-ON
Transport Lag: 0 seconds
Apply Lag: 0 seconds
Real Time Query: OFF
Instance(s):
smart
Properties:
DGConnectIdentifier = 'smart_dg_stb'
ObserverConnectIdentifier = ''
LogXptMode = 'ASYNC'
DelayMins = '0'
Binding = 'optional'
MaxFailure = '0'
MaxConnections = '1'
ReopenSecs = '300'
NetTimeout = '30'
RedoCompression = 'DISABLE'
LogShipping = 'ON'
PreferredApplyInstance = ''
ApplyInstanceTimeout = '0'
ApplyParallel = 'AUTO'
StandbyFileManagement = 'AUTO'
ArchiveLagTarget = '300'
LogArchiveMaxProcesses = '4'
LogArchiveMinSucceedDest = '1'
DbFileNameConvert = ''
LogFileNameConvert = 'X:\SMART\LOG1, X:\SMART\LOG1, Y:\SMART\LOG2, Y:\SMART\LOG2'
FastStartFailoverTarget = ''
InconsistentProperties = '(monitor)'
InconsistentLogXptProps = '(monitor)'
SendQEntries = '(monitor)'
LogXptStatus = '(monitor)'
RecvQEntries = '(monitor)'
SidName = 'smart'
StaticConnectIdentifier = '(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=host01)(PORT=1599))(CONNECT_DATA=(SERVICE_NAME=smart_stb_DGMGRL)(INSTANCE_NAME=smart)(SERVER=DEDICATED)))'
StandbyArchiveLocation = 'W:\SMART\arc\'
AlternateLocation = ''
LogArchiveTrace = '8191'
LogArchiveFormat = 'smart_%s_%t_%r.arc'
TopWaitEvents = '(monitor)'
Database Status:
SUCCESS
tnsnames.ora:
smart_dg_stb=(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=host01)(PORT=1599))(CONNECT_DATA=(SERVER=DEDICATED)(SID=smart)))
smart_dg_prim=(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=host02)(PORT=1599))(CONNECT_DATA=(SERVER=DEDICATED)(SID=smart)))
Listner.ora primary:
LISTENER_REDO_SMART =
(DESCRIPTION_LIST =
(DESCRIPTION =
(ADDRESS = (PROTOCOL = TCP)(HOST = host02)(PORT = 1599))
)
)
SID_LIST_LISTENER_REDO_SMART =
(SID_LIST =
(SID_DESC =
(SID_NAME = CLRExtProc)
(ORACLE_HOME = D:\oracle\11.2.0)
(PROGRAM = extproc)
(ENVS = "EXTPROC_DLLS=ONLY:D:\oracle\11.2.0\bin\oraclr11.dll")
)
(SID_DESC =
(SID_NAME =smart)
(ORACLE_HOME = D:\oracle\11.2.0)
)
(SID_DESC =
(SID_NAME =smart)
(GLOBAL_DBNAME=smart_DGMGRL)
(ORACLE_HOME = D:\oracle\11.2.0)
)
)
Listener.ora standby
LISTENER_REDO_SMART =
(DESCRIPTION_LIST =
(DESCRIPTION =
(ADDRESS = (PROTOCOL = TCP)(HOST = host01)(PORT = 1599))
)
)
SID_LIST_LISTENER_REDO_SMART =
(SID_LIST =
(SID_DESC =
(SID_NAME = CLRExtProc)
(ORACLE_HOME = D:\oracle\11.2.0)
(PROGRAM = extproc)
(ENVS = "EXTPROC_DLLS=ONLY:D:\oracle\11.2.0\bin\oraclr11.dll")
)
(SID_DESC =
(SID_NAME = smart)
(ORACLE_HOME = D:\oracle\11.2.0)
)
(SID_DESC =
(SID_NAME = smart)
(GLOBAL_DBNAME=smart_stb_DGMGRL)
(ORACLE_HOME = D:\oracle\11.2.0)
)
)
LSNRCTL> status listener_redo_smart
Connecting to (DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=host02)(PORT=1599)))
STATUS of the LISTENER
------------------------
Alias LISTENER_REDO_SMART
Version TNSLSNR for 64-bit Windows: Version 11.2.0.3.0 - Production
Start Date 30-AUG-2014 20:46:12
Uptime 10 days 13 hr. 11 min. 15 sec
Trace Level off
Security ON: Local OS Authentication
SNMP OFF
Listener Parameter File D:\oracle\11.2.0\network\admin\listener.ora
Listener Log File D:\oracle\diag\tnslsnr\host02\listener_redo_smart\alert\log.xml
Listening Endpoints Summary...
(DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=host02)(PORT=1599)))
Services Summary...
Service "CLRExtProc" has 1 instance(s).
Instance "CLRExtProc", status UNKNOWN, has 1 handler(s) for this service...
Service "HA_SMART" has 1 instance(s).
Instance "smart", status READY, has 1 handler(s) for this service...
Service "smart" has 2 instance(s).
Instance "smart", status UNKNOWN, has 1 handler(s) for this service...
Instance "smart", status READY, has 1 handler(s) for this service...
Service "smart_DGB" has 1 instance(s).
Instance "smart", status READY, has 1 handler(s) for this service...
Service "smart_DGMGRL" has 1 instance(s).
Instance "smart", status UNKNOWN, has 1 handler(s) for this service...
The command completed successfully
I'd be more than grateful if anybody would have an idea how to solve it!!
Thanks in advance and kind regards....