A Portal to a Portal: DB2 HADR - A Clash of Primaries

I had fun with DB2 this afternoon, following an unplanned restart of BOTH of my DB2 servers.

In essence, neither the primary nor the standby wanted to be ... the primary.

This is what I saw for one of the two databases: -

On original primary

db2pd -hadr -db cognos

Database Member 0 -- Database COGNOS -- Standby -- Up 0 days 00:11:28 -- Date 2015-09-02-18.53.28.860276

  HADR_ROLE = STANDBY
  REPLAY_TYPE = PHYSICAL
  HADR_SYNCMODE =
STANDBY_ID = 0
  LOG_STREAM_ID = 0
HADR_STATE = REMOTE_CATCHUP_PENDING
HADR_FLAGS =
  PRIMARY_MEMBER_HOST = NULL
PRIMARY_INSTANCE = NULL
PRIMARY_MEMBER = NULL
  STANDBY_MEMBER_HOST = bpm856
STANDBY_INSTANCE = db2inst1
STANDBY_MEMBER = 0
  HADR_CONNECT_STATUS = DISCONNECTED
HADR_CONNECT_STATUS_TIME = 02/09/2015 18:53:27.015115 (1441216407)
  HEARTBEAT_INTERVAL(seconds) = 15
HEARTBEAT_MISSED = 0
HEARTBEAT_EXPECTED = 0
  HADR_TIMEOUT(seconds) = 60
  TIME_SINCE_LAST_RECV(seconds) = 0
PEER_WAIT_LIMIT(seconds) = 0
LOG_HADR_WAIT_CUR(seconds) = 0.000
  LOG_HADR_WAIT_RECENT_AVG(seconds) = 0.000000
LOG_HADR_WAIT_ACCUMULATED(seconds) = 0.000
  LOG_HADR_WAIT_COUNT = 0
SOCK_SEND_BUF_REQUESTED,ACTUAL(bytes) = 0, 16384
SOCK_RECV_BUF_REQUESTED,ACTUAL(bytes) = 0, 87380
  PRIMARY_LOG_FILE,PAGE,POS = S0000000.LOG, 0, 0
  STANDBY_LOG_FILE,PAGE,POS = S0000004.LOG, 446, 80142794
  HADR_LOG_GAP(bytes) = 0
STANDBY_REPLAY_LOG_FILE,PAGE,POS = S0000004.LOG, 446, 80142794
STANDBY_RECV_REPLAY_GAP(bytes) = 0
PRIMARY_LOG_TIME = NULL
STANDBY_LOG_TIME = 02/09/2015 09:00:32.000000 (1441180832)
  STANDBY_REPLAY_LOG_TIME = 02/09/2015 09:00:32.000000 (1441180832)
STANDBY_RECV_BUF_SIZE(pages) = 16
STANDBY_RECV_BUF_PERCENT = 0
STANDBY_SPOOL_LIMIT(pages) = 25600
  STANDBY_SPOOL_PERCENT = 0
STANDBY_ERROR_TIME = NULL
PEER_WINDOW(seconds) = 0
READS_ON_STANDBY_ENABLED = N

On original standby

db2pd -hadr -db cognos

Database Member 0 -- Database COGNOS -- Standby -- Up 0 days 00:12:52 -- Date 2015-09-02-18.55.07.690822

  HADR_ROLE = STANDBY
  REPLAY_TYPE = PHYSICAL
  HADR_SYNCMODE =
STANDBY_ID = 0
  LOG_STREAM_ID = 0
HADR_STATE = LOCAL_CATCHUP
HADR_FLAGS =
  PRIMARY_MEMBER_HOST = NULL
PRIMARY_INSTANCE = NULL
PRIMARY_MEMBER = NULL
  STANDBY_MEMBER_HOST = db2hadr
STANDBY_INSTANCE = db2inst1
STANDBY_MEMBER = 0
  HADR_CONNECT_STATUS = DISCONNECTED
HADR_CONNECT_STATUS_TIME = 02/09/2015 18:55:06.448385 (1441216506)
  HEARTBEAT_INTERVAL(seconds) = 15
HEARTBEAT_MISSED = 0
HEARTBEAT_EXPECTED = 0
  HADR_TIMEOUT(seconds) = 60
  TIME_SINCE_LAST_RECV(seconds) = 0
PEER_WAIT_LIMIT(seconds) = 0
LOG_HADR_WAIT_CUR(seconds) = 0.000
  LOG_HADR_WAIT_RECENT_AVG(seconds) = 0.000000
LOG_HADR_WAIT_ACCUMULATED(seconds) = 0.000
  LOG_HADR_WAIT_COUNT = 0
SOCK_SEND_BUF_REQUESTED,ACTUAL(bytes) = 0, 16384
SOCK_RECV_BUF_REQUESTED,ACTUAL(bytes) = 0, 87380
  PRIMARY_LOG_FILE,PAGE,POS = S0000000.LOG, 0, 0
  STANDBY_LOG_FILE,PAGE,POS = S0000006.LOG, 18, 86748034
  HADR_LOG_GAP(bytes) = 0
STANDBY_REPLAY_LOG_FILE,PAGE,POS = S0000006.LOG, 18, 86748034
STANDBY_RECV_REPLAY_GAP(bytes) = 0
PRIMARY_LOG_TIME = NULL
STANDBY_LOG_TIME = 02/09/2015 16:22:27.000000 (1441207347)
  STANDBY_REPLAY_LOG_TIME = 02/09/2015 16:22:27.000000 (1441207347)
STANDBY_RECV_BUF_SIZE(pages) = 16
STANDBY_RECV_BUF_PERCENT = 0
STANDBY_SPOOL_LIMIT(pages) = 25600
  STANDBY_SPOOL_PERCENT = 0
STANDBY_ERROR_TIME = NULL
PEER_WINDOW(seconds) = 0
READS_ON_STANDBY_ENABLED = N

with messages such as: -

2015-09-02-18.53.02.766411+060 I15074291E494     LEVEL: Info
PID     : 2497     TID : 139896769472256 PROC : db2sysc 0
INSTANCE: db2inst1     NODE : 000   DB   : COGNOS
HOSTNAME: bpm856.uk.ibm.com
EDUID   : 45     EDUNAME: db2hadrs.0.0 (COGNOS) 0
FUNCTION: DB2 UDB, High Availability Disaster Recovery, hdrSendHsMsgNoDefer, probe:30539
DATA #1 : <preformatted>
A HDR_MSG_NOTPRIMARY message was sent to db2hadr:cognos_hadr (192.168.33.100:60009)

2015-09-02-18.53.02.769628+060 I15074786E502     LEVEL: Info
PID     : 2497     TID : 139896769472256 PROC : db2sysc 0
INSTANCE: db2inst1     NODE : 000   DB   : COGNOS
HOSTNAME: bpm856.uk.ibm.com
EDUID   : 45     EDUNAME: db2hadrs.0.0 (COGNOS) 0
FUNCTION: DB2 UDB, High Availability Disaster Recovery, hdrHandleHsAck, probe:43900
DATA #1 : <preformatted>
Handshake HDR_MSG_NOTPRIMARY message is received from db2hadr:cognos_hadr (192.168.33.100:60009)

2015-09-02-18.53.02.769830+060 I15075289E603     LEVEL: Error
PID     : 2497     TID : 139896769472256 PROC : db2sysc 0
INSTANCE: db2inst1     NODE : 000   DB   : COGNOS
HOSTNAME: bpm856.uk.ibm.com
EDUID   : 45     EDUNAME: db2hadrs.0.0 (COGNOS) 0
FUNCTION: DB2 UDB, High Availability Disaster Recovery, hdrHandleHsAck, probe:43970
MESSAGE : ZRC=0x878001BA=-2021654086=HDR_ZRC_NOT_PRIMARY
  "The database being contacted as primary is not a primary"
DATA #1 : <preformatted>
HADR handshake with db2hadr:cognos_hadr (192.168.33.100:60009) failed.

in db2diag.log.

On "new" primary

db2 deactivate db cognos

DB20000I The DEACTIVATE DATABASE command completed successfully.

db2 stop hadr on db cognos

DB20000I The STOP HADR ON DATABASE command completed successfully.

db2 start hadr on db cognos as primary

SQL1117N A connection to or activation of database "COGNOS" cannot be made because of ROLL-FORWARD PENDING. SQLSTATE=57019

db2 rollforward database cognos to end of logs and complete

Rollforward Status

Input database alias     = cognos
Number of members have returned status = 1

Member ID   = 0
Rollforward status     = DB  working
Next log file to be read     = S0000007.LOG
Log files processed   = S0000005.LOG - S0000006.LOG
Last committed transaction     = 2015-09-02-16.39.40.000000 UTC

DB20000I  The ROLLFORWARD command completed successfully.

db2 start hadr on db cognos as primary

DB20000I The START HADR ON DATABASE command completed successfully.

On "new" standby

db2 deactivate db cognos

DB20000I The DEACTIVATE DATABASE command completed successfully.

db2 stop hadr on db cognos

DB20000I The STOP HADR ON DATABASE command completed successfully.

db2 start hadr on db cognos as standby

DB20000I The START HADR ON DATABASE command completed successfully.

Now things look clean and green .....

New "primary"

db2pd -hadr -db cognos

Database Member 0 -- Database COGNOS -- Active -- Up 0 days 00:00:54 -- Date 2015-09-02-19.25.29.081627

  HADR_ROLE = PRIMARY
  REPLAY_TYPE = PHYSICAL
  HADR_SYNCMODE = SYNC
STANDBY_ID = 1
  LOG_STREAM_ID = 0
HADR_STATE = PEER
HADR_FLAGS =
  PRIMARY_MEMBER_HOST = db2hadr
PRIMARY_INSTANCE = db2inst1
PRIMARY_MEMBER = 0
  STANDBY_MEMBER_HOST = bpm856
STANDBY_INSTANCE = db2inst1
STANDBY_MEMBER = 0
  HADR_CONNECT_STATUS = CONNECTED
HADR_CONNECT_STATUS_TIME = 02/09/2015 19:24:36.897314 (1441218276)
  HEARTBEAT_INTERVAL(seconds) = 15
HEARTBEAT_MISSED = 0
HEARTBEAT_EXPECTED = 3
  HADR_TIMEOUT(seconds) = 60
  TIME_SINCE_LAST_RECV(seconds) = 8
PEER_WAIT_LIMIT(seconds) = 0
LOG_HADR_WAIT_CUR(seconds) = 0.000
  LOG_HADR_WAIT_RECENT_AVG(seconds) = 0.000000
LOG_HADR_WAIT_ACCUMULATED(seconds) = 0.000
  LOG_HADR_WAIT_COUNT = 0
SOCK_SEND_BUF_REQUESTED,ACTUAL(bytes) = 0, 19800
SOCK_RECV_BUF_REQUESTED,ACTUAL(bytes) = 0, 87380
  PRIMARY_LOG_FILE,PAGE,POS = S0000007.LOG, 0, 90845934
  STANDBY_LOG_FILE,PAGE,POS = S0000007.LOG, 0, 90845934
  HADR_LOG_GAP(bytes) = 0
STANDBY_REPLAY_LOG_FILE,PAGE,POS = S0000007.LOG, 0, 90845934
STANDBY_RECV_REPLAY_GAP(bytes) = 0
PRIMARY_LOG_TIME = 02/09/2015 17:39:40.000000 (1441211980)
STANDBY_LOG_TIME = 02/09/2015 17:39:40.000000 (1441211980)
  STANDBY_REPLAY_LOG_TIME = 02/09/2015 17:39:40.000000 (1441211980)
STANDBY_RECV_BUF_SIZE(pages) = 4298
STANDBY_RECV_BUF_PERCENT = 0
STANDBY_SPOOL_LIMIT(pages) = 25600
  STANDBY_SPOOL_PERCENT = 0
STANDBY_ERROR_TIME = NULL
PEER_WINDOW(seconds) = 120
  PEER_WINDOW_END = 02/09/2015 19:27:22.000000 (1441218442)
READS_ON_STANDBY_ENABLED = N

New "standby"

db2pd -hadr -db cognos

Database Member 0 -- Database COGNOS -- Standby -- Up 0 days 00:13:07 -- Date 2015-09-02-19.26.59.577531

  HADR_ROLE = STANDBY
  REPLAY_TYPE = PHYSICAL
  HADR_SYNCMODE = SYNC
STANDBY_ID = 0
  LOG_STREAM_ID = 0
HADR_STATE = PEER
HADR_FLAGS =
  PRIMARY_MEMBER_HOST = db2hadr
PRIMARY_INSTANCE = db2inst1
PRIMARY_MEMBER = 0
  STANDBY_MEMBER_HOST = bpm856
STANDBY_INSTANCE = db2inst1
STANDBY_MEMBER = 0
  HADR_CONNECT_STATUS = CONNECTED
HADR_CONNECT_STATUS_TIME = 02/09/2015 19:24:36.898265 (1441218276)
  HEARTBEAT_INTERVAL(seconds) = 15
HEARTBEAT_MISSED = 0
HEARTBEAT_EXPECTED = 9
  HADR_TIMEOUT(seconds) = 60
  TIME_SINCE_LAST_RECV(seconds) = 8
PEER_WAIT_LIMIT(seconds) = 0
LOG_HADR_WAIT_CUR(seconds) = 0.000
  LOG_HADR_WAIT_RECENT_AVG(seconds) = 0.000000
LOG_HADR_WAIT_ACCUMULATED(seconds) = 0.000
  LOG_HADR_WAIT_COUNT = 0
SOCK_SEND_BUF_REQUESTED,ACTUAL(bytes) = 0, 19800
SOCK_RECV_BUF_REQUESTED,ACTUAL(bytes) = 0, 87380
  PRIMARY_LOG_FILE,PAGE,POS = S0000007.LOG, 0, 90845934
  STANDBY_LOG_FILE,PAGE,POS = S0000007.LOG, 0, 90845934
  HADR_LOG_GAP(bytes) = 0
STANDBY_REPLAY_LOG_FILE,PAGE,POS = S0000007.LOG, 0, 90845934
STANDBY_RECV_REPLAY_GAP(bytes) = 0
PRIMARY_LOG_TIME = 02/09/2015 17:39:40.000000 (1441211980)
STANDBY_LOG_TIME = 02/09/2015 17:39:40.000000 (1441211980)
  STANDBY_REPLAY_LOG_TIME = 02/09/2015 17:39:40.000000 (1441211980)
STANDBY_RECV_BUF_SIZE(pages) = 4298
STANDBY_RECV_BUF_PERCENT = 0
STANDBY_SPOOL_LIMIT(pages) = 25600
  STANDBY_SPOOL_PERCENT = 0
STANDBY_ERROR_TIME = NULL
PEER_WINDOW(seconds) = 120
  PEER_WINDOW_END = 02/09/2015 19:28:52.000000 (1441218532)
READS_ON_STANDBY_ENABLED = N

A Portal to a Portal

Wednesday 2 September 2015

DB2 HADR - A Clash of Primaries

No comments:

Visual Studio Code - Wow 🙀

Search This Blog