Oracle

Server: RHEL6

Oracle DB version: 12.1

In my Primary Alert log i'm seeing RFS messages writing frequently like below

Primary alert log :

RFS[10]: Assigned to RFS process (PID:16586)

RFS[10]: Database mount ID mismatch [0x6666ae9b:0x666707e4] (1718005403:171802260)

RFS[10]: Client instance is standby database instead of primary

Tue Feb 19 16:10:14 2019

RFS[11]: Assigned to RFS process (PID:174682)

RFS[11]: Database mount ID mismatch [0x6666ae9b:0x666707e4] (1718005403:1718028260)

RFS[11]: Client instance is standby database instead of primary

After researching further and according to Oracle (Doc ID 1450132.1)

Cause:

It's due to my Standby database is sending ARCH logs back to my Primary site (RAC exadata machine) (don’t know how this was happening) and causing these messages writing to my Primary alert log and to fix this I’ve to find and remove "dest_" parameter which is pointing back to primary site

On standby site

SQL> sho parameter dest_2

NAME TYPE VALUE

------------------------------------ ----------- ------------------------------

db_create_online_log_dest_2 string

log_archive_dest_2 string service=myprod_prim ARCH SYNC NO

AFFIRM delay=0 OPTIONAL reopen=15 register

SQL> sho parameter dest_state_2

NAME TYPE VALUE

------------------------------------ ----------- ------------------------------

log_archive_dest_state_2 string ENABLE

Yes i see my dest_2 is pointing to Primary and it is ENABLED so remove this parameter (OR) DEFER it

FIX:

SQL> ALTER SYSTEM SET log_archive_dest_2='' scope=both;

System altered.

Now i see NO messages are writing in alert log

GGSCI (myorasrc.domain.com) 1> info all

Program Status Group Lag at Chkpt Time Since Chkpt

MANAGER RUNNING

JAGENT RUNNING

GGSCI (myorasrc.domain.com) 8> add extract EXTMYDEV, INTEGRATED TRANLOG, BEGIN NOW

EXTRACT (Integrated) added.

GGSCI (myorasrc.domain.com) 9> add EXTTRAIL /goldengate/dirdat/devdb/cr, extract EXTMYDEV, MEGABYTES 100

EXTTRAIL added.

GGSCI (myorasrc.domain.com) 10> add extract PMPMYDEV, EXTTRAILSOURCE /goldengate/dirdat/devdb/cr

EXTRACT added.

GGSCI (myorasrc.domain.com) 11> ADD RMTTRAIL /goldengate/dirdat/devdb/CR, extract PMPMYDEV, MEGABYTES 100

RMTTRAIL added.

GGSCI (myorasrc.domain.com) 13> info all

Program Status Group Lag at Chkpt Time Since Chkpt

MANAGER RUNNING

JAGENT RUNNING

EXTRACT STOPPED EXTMYDEV 00:00:00 00:00:10

EXTRACT STARTING PMPMYDEV 00:00:00 00:00:08

It shouldn’t be in STARTING state, it should be STOPPED (Like Extract above)

GGSCI (myorasrc.domain.com) 15> info EXTMYDEV detail

EXTRACT EXTMYDEV Initialized 2019-01-24 10:46 Status STOPPED

Checkpoint Lag 00:00:00 (updated 00:00:17 ago)

Log Read Checkpoint Oracle Integrated Redo Logs

2019-01-24 10:46:57

SCN 0.0 (0)

Target Extract Trails:

Trail Name Seqno RBA Max MB Trail Type

/goldengate/dirdat/devdb/cr 0 0 100 EXTTRAIL

Integrated Extract outbound server first scn: Unavailable.Need DBLOGIN.

Integrated Extract outbound server filtering start scn: Unavailable.Need DBLOGIN.

Extract Source Begin End

Not Available * Initialized * 2019-01-24 10:46

Current directory /goldengate

Report file /goldengate/dirrpt/EXTMYDEV.rpt (does not yet exist)

Parameter file /goldengate/dirprm/EXTMYDEV.prm

Checkpoint file /goldengate/dirchk/EXTMYDEV.cpe

Process file /goldengate/dirpcs/EXTMYDEV.pce

Error log /goldengate/ggserr.log

GG extract looks good, lets check PUMP

GGSCI (myorasrc.domain.com) 13> info PMPMYDEV detail

EXTRACT PMPMYDEV Last Started 2019-01-24 12:18 Status RUNNING

Checkpoint Lag 00:00:00 (updated 00:00:08 ago)

Process ID 130534

Log Read Checkpoint File /goldengate/dirdat/devdb/cr000000000

First Record RBA 1451

Target Extract Trails:

Trail Name Seqno RBA Max MB Trail Type

/goldengate/dirdat/devdb/CR 122 911 100 RMTTRAIL --> Wrong should be “0”

Extract Source Begin End

/goldengate/dirdat/devdb/cr000000000 * Initialized * First Record

Current directory /goldengate

Report file /goldengate/dirrpt/PMPMYDEV.rpt

Parameter file /goldengate/dirprm/PMPMYDEV.prm

Checkpoint file /goldengate/dirchk/PMPMYDEV.cpe

Process file /goldengate/dirpcs/PMPMYDEV.pce

Error log /goldengate/ggserr.log

GGSCI (myorasrc.domain.com) 14> info EXTMYDEV showch

EXTRACT EXTMYDEV Last Started 2019-01-24 11:06 Status RUNNING

Checkpoint Lag 00:00:01 (updated 00:00:05 ago)

Process ID 117568

Log Read Checkpoint Oracle Integrated Redo Logs

2019-01-24 13:55:34

SCN 95.1378716772 (409400609892)

Current Checkpoint Detail:

Read Checkpoint #1

Oracle Integrated Redo Log

Startup Checkpoint (starting position in the data source):

Timestamp: 2019-01-24 10:46:57.000000

SCN: Not available

Recovery Checkpoint (position of oldest unprocessed transaction in the data source):

Timestamp: 2019-01-24 13:55:34.000000

SCN: 95.1378716771 (409400609891)

Current Checkpoint (position of last record read in the data source):

Timestamp: 2019-01-24 13:55:34.000000

SCN: 95.1378716772 (409400609892)

Write Checkpoint #1

GGS Log Trail

Current Checkpoint (current write position):

Sequence #: 122

RBA: 1451

Timestamp: 2019-01-24 13:55:35.651323

Extract Trail: /goldengate/dirdat/devdb/cr

Seqno Length: 9

Flip Seqno Length: No

Trail Type: EXTTRAIL

Header:

Version = 2

Record Source = A

Type = 13

# Input Checkpoints = 1

# Output Checkpoints = 1

File Information:

Block Size = 2048

Max Blocks = 100

Record Length = 2048

Current Offset = 0

Configuration:

Data Source = 3

Transaction Integrity = 1

Task Type = 0

Status:

Start Time = 2019-01-24 11:06:15

Last Update Time = 2019-01-24 13:55:35

Stop Status = A

Last Result = 520

$ ls -lrrth /goldengate/dirdat/devdb/cr*

-rw-r----- 1 oracle dba 1.5K Jan 24 11:06 /goldengate/dirdat/devdb/cr000000000

Trail files on source side starting with number ‘ZERO’ which is Correct as expected

CAUSE :

Issue is due to the TRAIL files NOT deleted on the replciat (TARGET) side so when you start the PUMP on source side it will start writing to same Trail file on target side which follows the same target trail seq number

Target side:

oratgtdev.doamin.com:NOTSET:/goldengate/dirdat/devdb $ ls -lrth

total 16K

-rw-r----- 1 oracle dba 14K Jan 24 15:43 CR000000121

-rw-r----- 1 oracle dba 14K Jan 24 15:43 CR000000122

Solution:

DELETE Trail files on replicat side and recreate PUMP

GGSCI (myorasrc.domain.com) 16> stop PMPMYDEV

Sending STOP request to EXTRACT PMPMYDEV ...

Request processed.

GGSCI (myorasrc.domain.com) 17> delete PMPMYDEV

Deleted EXTRACT PMPMYDEV.

GGSCI (myorasrc.domain.com) 10> add extract PMPMYDEV, EXTTRAILSOURCE /goldengate/dirdat/devdb/cr

EXTRACT added.

GGSCI (myorasrc.domain.com) 11> ADD RMTTRAIL /goldengate/dirdat/devdb/CR, extract PMPMYDEV, MEGABYTES 100

RMTTRAIL added.

GGSCI (myorasrc.domain.com) 16> info PMPMYDEV detail

EXTRACT PMPMYDEV Initialized 2019-01-24 10:46 Status STARTING

Checkpoint Lag 00:00:00 (updated 00:00:16 ago)

Process ID 157497

Log Read Checkpoint File /goldengate/dirdat/devdb/cr000000000

First Record RBA 0

Target Extract Trails:

Trail Name Seqno RBA Max MB Trail Type

/goldengate/dirdat/devdb/CR 0 0 100 RMTTRAIL

Extract Source Begin End

/goldengate/dirdat/devdb/cr000000000 * Initialized * First Record

Current directory /goldengate

Report file /goldengate/dirrpt/PMPMYDEV.rpt (does not yet exist)

Parameter file /goldengate/dirprm/PMPMYDEV.prm

Checkpoint file /goldengate/dirchk/PMPMYDEV.cpe

Process file /goldengate/dirpcs/PMPMYDEV.pce

Error log /goldengate/ggserr.log

Now I see Seq# and RBA reset to ‘ZERO’ values

Trail File Sequence Number Does Not Reset To 0 While Delete And Recreation Of Goldengate Extract. (Doc ID 2316739.1)

Sunday, May 12, 2019

RFS[11]: Client instance is standby database instead of primary

Saturday, March 9, 2019

OGG Trail File Sequence Number Does Not Reset To 0