Rich,
Updating to current version sounds like a no-brainer but there are
circumstances which won't allow be to do that for the next few weeks
atleast.
Captured a more recent error:
Error logs on Master:
[12/Jan/2015:05:11:30 -0800] - repl5_inc_waitfor_async_results timed out
waiting for responses: 31923 31926
[12/Jan/2015:05:21:31 -0800] NSMMReplicationPlugin - agmt="cn=master ->
hub1.beta" (hub1:2390): Warning: unable to receive endReplication extended
operation response (Timed out)
[12/Jan/2015:05:23:56 -0800] NSMMReplicationPlugin - agmt="cn=master ->
hub1.beta" (hub1:2390): Unable to receive the response for a
startReplication extended operation to consumer (Can't contact LDAP
server). Will re
try later.
[12/Jan/2015:05:24:00 -0800] NSMMReplicationPlugin - agmt="cn=master ->
hub1.beta" (hub1:2390): Simple bind resumed
Error logs on hub1.beta (Around 05:11:30)
[12/Jan/2015:05:06:35 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): State: sending_updates -> wait_for_changes
[12/Jan/2015:05:07:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): Linger timeout has expired on the connection
[12/Jan/2015:05:07:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): Disconnected from the consumer
[12/Jan/2015:05:07:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): Linger timeout has expired on the connection
[12/Jan/2015:05:07:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): Disconnected from the consumer
[12/Jan/2015:05:08:37 -0800] - Trimmed 90 changes from the changelog
[12/Jan/2015:05:11:35 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): State: wait_for_changes -> wait_for_changes
[12/Jan/2015:05:11:35 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): State: wait_for_changes -> wait_for_changes
[12/Jan/2015:05:11:35 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): State: wait_for_changes -> start
[12/Jan/2015:05:11:35 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): State: wait_for_changes -> start
[12/Jan/2015:05:11:35 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): No linger to cancel on the connection
[12/Jan/2015:05:11:35 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): No linger to cancel on the connection
[12/Jan/2015:05:11:35 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): Disconnected from the consumer
[12/Jan/2015:05:11:35 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): Disconnected from the consumer
[12/Jan/2015:05:11:35 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): State: start -> ready_to_acquire_replica
[12/Jan/2015:05:11:35 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): State: start -> ready_to_acquire_replica
[12/Jan/2015:05:11:35 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): State: ready_to_acquire_replica -> wait_for_changes
[12/Jan/2015:05:11:35 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): State: ready_to_acquire_replica -> wait_for_changes
[12/Jan/2015:05:13:37 -0800] - Trimmed 129 changes from the changelog
[12/Jan/2015:05:16:35 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): State: wait_for_changes -> wait_for_changes
[12/Jan/2015:05:16:35 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): State: wait_for_changes -> start
[12/Jan/2015:05:16:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): State: wait_for_changes -> wait_for_changes
[12/Jan/2015:05:16:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): No linger to cancel on the connection
[12/Jan/2015:05:16:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): State: wait_for_changes -> start
[12/Jan/2015:05:16:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): Disconnected from the consumer
[12/Jan/2015:05:16:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): No linger to cancel on the connection
[12/Jan/2015:05:16:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): State: start -> ready_to_acquire_replica
[12/Jan/2015:05:16:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): Disconnected from the consumer
[12/Jan/2015:05:16:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): State: ready_to_acquire_replica -> wait_for_changes
[12/Jan/2015:05:16:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): State: start -> ready_to_acquire_replica
[12/Jan/2015:05:16:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): State: ready_to_acquire_replica -> wait_for_changes
[12/Jan/2015:05:18:37 -0800] - Trimmed 108 changes from the changelog
[12/Jan/2015:05:21:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): State: wait_for_changes -> wait_for_changes
[12/Jan/2015:05:21:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): State: wait_for_changes -> start
[12/Jan/2015:05:21:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): No linger to cancel on the connection
[12/Jan/2015:05:21:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): State: wait_for_changes -> wait_for_changes
[12/Jan/2015:05:21:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): Disconnected from the consumer
[12/Jan/2015:05:21:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): State: wait_for_changes -> start
[12/Jan/2015:05:21:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): State: start -> ready_to_acquire_replica
[12/Jan/2015:05:21:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): No linger to cancel on the connection
[12/Jan/2015:05:21:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): State: ready_to_acquire_replica -> wait_for_changes
[12/Jan/2015:05:21:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): Disconnected from the consumer
[12/Jan/2015:05:21:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): State: start -> ready_to_acquire_replica
[12/Jan/2015:05:21:36 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): State: ready_to_acquire_replica -> wait_for_changes
[12/Jan/2015:05:21:57 -0800] NSMMReplicationPlugin - conn=0 op=-1 repl="o=
xyz.com": Released replica
[12/Jan/2015:05:23:38 -0800] - Trimmed 82 changes from the changelog
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - conn=529 op=3 repl="o=
xyz.com": Begin incremental protocol
[12/Jan/2015:05:24:01 -0800] - csngen_adjust_time: gen state before
54b3c6dc0002:1421067995:0:1
[12/Jan/2015:05:24:01 -0800] - _csngen_adjust_local_time: gen state before
54b3c6dc0002:1421067995:0:1
[12/Jan/2015:05:24:01 -0800] - _csngen_adjust_local_time: gen state after
54b3caf20000:1421069041:0:1
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - conn=529 op=3 repl="o=
xyz.com": Acquired replica
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - conn=529 op=3 repl="o=
xyz.com": StartNSDS50ReplicationRequest: response=0 rc=0
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin -
ruv_master_csn_inprogress: successfully inserted csn 54b3c6cb000000010000
into pending list
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - Purged state
information from entry
cn=z92602g5rmt524klhh1a8,ou=config,ou=577103-1,ou=devices,o=xyz.com up to
CSN 54aa8c4a000000010000
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - ruv_update_ruv:
successfully committed csn 54b3c6cb000000010000
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): State: wait_for_changes -> wait_for_changes
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): State: wait_for_changes -> wait_for_changes
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin -
ruv_master_csn_inprogress: successfully inserted csn 54b3c6cb000100010000
into pending list
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): State: wait_for_changes -> ready_to_acquire_replica
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): State: wait_for_changes -> ready_to_acquire_replica
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - Purged state
information from entry
cn=z9246z2fnl84c22s019i1b,ou=config,ou=airhandlersincorporated-1,ou=devices,o=
xyz.com up to CSN 54aa8c4b0000000100
00
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): Trying non-secure slapi_ldap_init
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): Trying non-secure slapi_ldap_init
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): binddn = cn=repmgr,cn=config, passwd =
{DES}d3Z9PTUacn3yyZ1iK1XQeQ==
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - ruv_update_ruv:
successfully committed csn 54b3c6cb000100010000
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): binddn = cn=repmgr,cn=config, passwd =
{DES}d3Z9PTUacn3yyZ1iK1XQeQ==
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): No linger to cancel on the connection
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin -
ruv_master_csn_inprogress: successfully inserted csn 54b3c6d3000000010000
into pending list
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): No linger to cancel on the connection
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - Purged state
information from entry
cn=z924715jqoaf24kijif88,ou=config,ou=640395-1,ou=devices,o=xyz.com up to
CSN 54aa8c4b000100010000
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): Replica was successfully acquired.
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): Replica was successfully acquired.
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): State: ready_to_acquire_replica -> sending_updates
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - ruv_update_ruv:
successfully committed csn 54b3c6d3000000010000
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): State: ready_to_acquire_replica -> sending_updates
[12/Jan/2015:05:24:01 -0800] - csngen_adjust_time: gen state before
54b3caf20002:1421069041:0:1
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin -
ruv_master_csn_inprogress: successfully inserted csn 54b3c6d6000000010000
into pending list
[12/Jan/2015:05:24:01 -0800] - _cl5PositionCursorForReplay (agmt="cn=hub ->
rep1" (rep1:1390)): Consumer RUV:
[12/Jan/2015:05:24:01 -0800] - csngen_adjust_time: gen state before
54b3caf20002:1421069041:0:1
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - Purged state
information from entry
cn=z926027bn6j4238tld0lo,ou=aliases,ou=542433-1,ou=devices,o=xyz.com up to
CSN 54aa8c53000000010000
[12/Jan/2015:05:24:01 -0800] - _cl5PositionCursorForReplay (agmt="cn=hub ->
rep2" (rep2:1390)): Consumer RUV:
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): {replica 1 ldap://master.xyz.com:9390} 54950fca000000010000
54b3c6ca000000010000 00000000
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): {replicageneration} 549502f5000000010000
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - ruv_update_ruv:
successfully committed csn 54b3c6d6000000010000
[12/Jan/2015:05:24:01 -0800] - _cl5PositionCursorForReplay (agmt="cn=hub ->
rep1" (rep1:1390)): Supplier RUV:
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): {replica 1 ldap://master.xyz.com:9390} 54950fca000000010000
54b3c6ca000000010000 00000000
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin -
ruv_master_csn_inprogress: successfully inserted csn 54b3c6d7000000010000
into pending list
[12/Jan/2015:05:24:01 -0800] - _cl5PositionCursorForReplay (agmt="cn=hub ->
rep2" (rep2:1390)): Supplier RUV:
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): {replicageneration} 549502f5000000010000
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - Purged state
information from entry
cn=z9246z1hhj4a123qjmsp55,ou=config,ou=530501-1,ou=devices,o=xyz.com up to
CSN 54aa8c56000000010000
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): {replicageneration} 549502f5000000010000
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): {replica 1 ldap://master.xyz.com:9390} 54950fca000000010000
54b3c6d6000000010000 54b3caf1
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): {replica 1 ldap://master.xyz.com:9390} 54950fca000000010000
54b3c6d6000000010000 54b3caf1
[12/Jan/2015:05:24:01 -0800] agmt="cn=hub -> rep1" (rep1:1390) - session
start: anchorcsn=54b3c6ca000000010000
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - ruv_update_ruv:
successfully committed csn 54b3c6d7000000010000
[12/Jan/2015:05:24:01 -0800] NSMMReplicationPlugin - changelog program -
agmt="cn=hub -> rep1" (rep1:1390): CSN 54b3c6ca000000010000 found, position
set for replay
[12/Jan/2015:05:24:01 -0800] agmt="cn=hub -> rep2" (rep2:1390) - session
start: anchorcsn=54b3c6ca000000010000
[12/Jan/2015:05:24:02 -0800] NSMMReplicationPlugin -
ruv_master_csn_inprogress: successfully inserted csn 54b3c6d9000100010000
into pending list
[12/Jan/2015:05:24:02 -0800] NSMMReplicationPlugin - Purged state
information from entry
cn=z9260knntrc24bdtqtlf,ou=other,ou=612889-1,ou=devices,o=xyz.com up to CSN
54aa8c57000000010000
[12/Jan/2015:05:24:02 -0800] - repl5_inc_result_threadmain starting
[12/Jan/2015:05:24:02 -0800] NSMMReplicationPlugin - changelog program -
agmt="cn=hub -> rep2" (rep2:1390): CSN 54b3c6ca000000010000 found, position
set for replay
[12/Jan/2015:05:24:02 -0800] agmt="cn=hub -> rep2" (rep2:1390) - load=1
rec=1 csn=54b3c6cb000000010000
[12/Jan/2015:05:24:02 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): replay_update: Sending modify operation
(dn="cn=z92602g5rmt524klhh1a8,ou=config,ou=577103-1,ou=devices,o=xyz.com" c
sn=54b3c6cb000000010000)
[12/Jan/2015:05:24:02 -0800] NSMMReplicationPlugin - ruv_update_ruv:
successfully committed csn 54b3c6d9000100010000
[12/Jan/2015:05:24:02 -0800] agmt="cn=hub -> rep1" (rep1:1390) - load=1
rec=1 csn=54b3c6cb000000010000
[12/Jan/2015:05:24:02 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): replay_update: Sending modify operation
(dn="cn=z92602g5rmt524klhh1a8,ou=config,ou=577103-1,ou=devices,o=xyz.com" c
sn=54b3c6cb000000010000)
[12/Jan/2015:05:24:02 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): replay_update: Consumer successfully sent operation with csn
54b3c6cb000000010000
[12/Jan/2015:05:24:02 -0800] agmt="cn=hub -> rep1" (rep1:1390) - load=1
rec=2 csn=54b3c6cb000100010000
[12/Jan/2015:05:24:02 -0800] NSMMReplicationPlugin -
ruv_master_csn_inprogress: successfully inserted csn 54b3c6d9000200010000
into pending list
[12/Jan/2015:05:24:02 -0800] NSMMReplicationPlugin - Purged state
information from entry
cn=z9260z1bnqgdo21o6dd0t7,ou=config,ou=481913-1,ou=devices,o=xyz.com up to
CSN 54aa8c59000100010000
[12/Jan/2015:05:24:02 -0800] - repl5_inc_result_threadmain: read result for
message_id 0
[12/Jan/2015:05:24:02 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep2"
(rep2:1390): replay_update: Consumer successfully sent operation with csn
54b3c6cb000000010000
[12/Jan/2015:05:24:02 -0800] NSMMReplicationPlugin - agmt="cn=hub -> rep1"
(rep1:1390): replay_update: Sending modify operation
(dn="cn=z9246z2fnl84c22s019i1b,ou=config,ou=airhandlersincorporated-1,ou=devices,o
=xyz.com" csn=54b3c6cb000100010000)
[12/Jan/2015:05:24:02 -0800] - repl5_inc_result_threadmain starting
[12/Jan/2015:05:24:02 -0800] - repl5_inc_result_threadmain: read result for
message_id 5
[12/Jan/2015:05:24:02 -0800] NSMMReplicationPlugin - ruv_update_ruv:
successfully committed csn 54b3c6d9000200010000
Access logs on hub1.beta (Around 05:11:30)
[12/Jan/2015:05:09:32 -0800] conn=468 fd=76 slot=76 connection from
10.1.233.43 to 10.1.235.112
[12/Jan/2015:05:09:32 -0800] conn=468 op=0 BIND dn="" method=128 version=2
[12/Jan/2015:05:09:32 -0800] conn=468 op=0 RESULT err=0 tag=97 nentries=0
etime=0 dn=""
[12/Jan/2015:05:09:32 -0800] conn=468 op=1 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs=ALL
[12/Jan/2015:05:09:32 -0800] conn=468 op=1 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:09:32 -0800] conn=468 op=2 UNBIND
[12/Jan/2015:05:09:32 -0800] conn=468 op=2 fd=76 closed - U1
[12/Jan/2015:05:11:06 -0800] conn=469 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:11:06 -0800] conn=469 op=0 SRCH
base="cn=ServerStatus,o=AccAdmin" scope=0 filter="(objectClass=*)"
attrs="sn"
[12/Jan/2015:05:11:06 -0800] conn=469 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:11:06 -0800] conn=469 op=1 UNBIND
[12/Jan/2015:05:11:06 -0800] conn=469 op=1 fd=76 closed - U1
[12/Jan/2015:05:13:43 -0800] conn=470 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:13:43 -0800] conn=470 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:13:43 -0800] conn=470 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:13:43 -0800] conn=470 op=1 UNBIND
[12/Jan/2015:05:13:43 -0800] conn=470 op=1 fd=76 closed - U1
[12/Jan/2015:05:13:48 -0800] conn=471 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:13:48 -0800] conn=471 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:13:48 -0800] conn=471 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:13:48 -0800] conn=471 op=1 UNBIND
[12/Jan/2015:05:13:48 -0800] conn=471 op=1 fd=76 closed - U1
[12/Jan/2015:05:13:54 -0800] conn=472 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:13:54 -0800] conn=472 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:13:54 -0800] conn=472 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:13:54 -0800] conn=472 op=1 UNBIND
[12/Jan/2015:05:13:54 -0800] conn=472 op=1 fd=76 closed - U1
[12/Jan/2015:05:13:59 -0800] conn=473 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:13:59 -0800] conn=473 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:13:59 -0800] conn=473 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:13:59 -0800] conn=473 op=1 UNBIND
[12/Jan/2015:05:13:59 -0800] conn=473 op=1 fd=76 closed - U1
[12/Jan/2015:05:14:05 -0800] conn=474 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:14:05 -0800] conn=474 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:14:05 -0800] conn=474 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:14:05 -0800] conn=474 op=1 UNBIND
[12/Jan/2015:05:14:05 -0800] conn=474 op=1 fd=76 closed - U1
[12/Jan/2015:05:14:10 -0800] conn=475 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:14:10 -0800] conn=475 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:14:10 -0800] conn=475 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:14:10 -0800] conn=475 op=1 UNBIND
[12/Jan/2015:05:14:10 -0800] conn=475 op=1 fd=76 closed - U1
[12/Jan/2015:05:14:16 -0800] conn=476 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:14:16 -0800] conn=476 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:14:16 -0800] conn=476 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:14:16 -0800] conn=476 op=1 UNBIND
[12/Jan/2015:05:14:16 -0800] conn=476 op=1 fd=76 closed - U1
[12/Jan/2015:05:14:21 -0800] conn=477 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:14:21 -0800] conn=477 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:14:21 -0800] conn=477 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:14:21 -0800] conn=477 op=1 UNBIND
[12/Jan/2015:05:14:21 -0800] conn=477 op=1 fd=76 closed - U1
[12/Jan/2015:05:14:27 -0800] conn=478 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:14:27 -0800] conn=478 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:14:27 -0800] conn=478 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:14:27 -0800] conn=478 op=1 UNBIND
[12/Jan/2015:05:14:27 -0800] conn=478 op=1 fd=76 closed - U1
[12/Jan/2015:05:14:31 -0800] conn=479 fd=76 slot=76 connection from
10.1.233.43 to 10.1.235.112
[12/Jan/2015:05:14:31 -0800] conn=479 op=0 BIND dn="" method=128 version=2
[12/Jan/2015:05:14:31 -0800] conn=479 op=0 RESULT err=0 tag=97 nentries=0
etime=0 dn=""
[12/Jan/2015:05:14:31 -0800] conn=479 op=1 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs=ALL
[12/Jan/2015:05:14:31 -0800] conn=479 op=1 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:14:31 -0800] conn=479 op=2 UNBIND
[12/Jan/2015:05:14:31 -0800] conn=479 op=2 fd=76 closed - U1
[12/Jan/2015:05:14:32 -0800] conn=480 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:14:32 -0800] conn=480 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:14:32 -0800] conn=480 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:14:32 -0800] conn=480 op=1 UNBIND
[12/Jan/2015:05:14:32 -0800] conn=480 op=1 fd=76 closed - U1
[12/Jan/2015:05:14:38 -0800] conn=481 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:14:38 -0800] conn=481 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:14:38 -0800] conn=481 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:14:38 -0800] conn=481 op=1 UNBIND
[12/Jan/2015:05:14:38 -0800] conn=481 op=1 fd=76 closed - U1
[12/Jan/2015:05:14:43 -0800] conn=482 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:14:43 -0800] conn=482 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:14:43 -0800] conn=482 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:14:43 -0800] conn=482 op=1 UNBIND
[12/Jan/2015:05:14:43 -0800] conn=482 op=1 fd=76 closed - U1
[12/Jan/2015:05:14:49 -0800] conn=483 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:14:49 -0800] conn=483 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:14:49 -0800] conn=483 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:14:49 -0800] conn=483 op=1 UNBIND
[12/Jan/2015:05:14:49 -0800] conn=483 op=1 fd=76 closed - U1
[12/Jan/2015:05:14:54 -0800] conn=484 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:14:54 -0800] conn=484 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:14:54 -0800] conn=484 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:14:54 -0800] conn=484 op=1 UNBIND
[12/Jan/2015:05:14:54 -0800] conn=484 op=1 fd=76 closed - U1
[12/Jan/2015:05:15:00 -0800] conn=485 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:15:00 -0800] conn=485 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:15:00 -0800] conn=485 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:15:00 -0800] conn=485 op=1 UNBIND
[12/Jan/2015:05:15:00 -0800] conn=485 op=1 fd=76 closed - U1
[12/Jan/2015:05:15:05 -0800] conn=486 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:15:05 -0800] conn=486 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:15:05 -0800] conn=486 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:15:05 -0800] conn=486 op=1 UNBIND
[12/Jan/2015:05:15:05 -0800] conn=486 op=1 fd=76 closed - U1
[12/Jan/2015:05:15:11 -0800] conn=487 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:15:11 -0800] conn=487 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:15:11 -0800] conn=487 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:15:11 -0800] conn=487 op=1 UNBIND
[12/Jan/2015:05:15:11 -0800] conn=487 op=1 fd=76 closed - U1
[12/Jan/2015:05:15:16 -0800] conn=488 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:15:16 -0800] conn=488 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:15:16 -0800] conn=488 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:15:16 -0800] conn=488 op=1 UNBIND
[12/Jan/2015:05:15:16 -0800] conn=488 op=1 fd=76 closed - U1
[12/Jan/2015:05:15:22 -0800] conn=489 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:15:22 -0800] conn=489 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:15:22 -0800] conn=489 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:15:22 -0800] conn=489 op=1 UNBIND
[12/Jan/2015:05:15:22 -0800] conn=489 op=1 fd=76 closed - U1
[12/Jan/2015:05:15:27 -0800] conn=490 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:15:27 -0800] conn=490 op=0 SRCH
base="cn=ReplicationTest,ou=devices,o=xyz.com" scope=0
filter="(objectClass=*)" attrs="sn"
[12/Jan/2015:05:15:27 -0800] conn=490 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:15:27 -0800] conn=490 op=1 UNBIND
[12/Jan/2015:05:15:27 -0800] conn=490 op=1 fd=76 closed - U1
[12/Jan/2015:05:15:33 -0800] conn=491 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
Access logs on hub1.beta (Around 05:21:31)
[12/Jan/2015:05:21:40 -0800] conn=528 fd=76 slot=76 connection from
10.2.164.55 to 10.1.235.112
[12/Jan/2015:05:21:40 -0800] conn=528 op=0 SRCH
base="cn=ServerStatus,o=AccAdmin" scope=0 filter="(objectClass=*)"
attrs="sn"
[12/Jan/2015:05:21:40 -0800] conn=528 op=0 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:21:40 -0800] conn=528 op=1 UNBIND
[12/Jan/2015:05:21:40 -0800] conn=528 op=1 fd=76 closed - U1
[12/Jan/2015:05:21:57 -0800] conn=3 op=-1 fd=65 closed - B1
[12/Jan/2015:05:24:00 -0800] conn=529 fd=65 slot=65 connection from
64.28.115.86 to 10.1.235.112
[12/Jan/2015:05:24:00 -0800] conn=529 op=0 BIND dn="cn=repmgr,cn=config"
method=128 version=3
[12/Jan/2015:05:24:00 -0800] conn=529 op=0 RESULT err=0 tag=97 nentries=0
etime=0 dn="cn=repmgr,cn=config"
[12/Jan/2015:05:24:00 -0800] conn=529 op=1 SRCH base="" scope=0
filter="(objectClass=*)" attrs="supportedControl supportedExtension"
[12/Jan/2015:05:24:00 -0800] conn=529 op=1 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:24:00 -0800] conn=529 op=2 SRCH base="" scope=0
filter="(objectClass=*)" attrs="supportedControl supportedExtension"
[12/Jan/2015:05:24:00 -0800] conn=529 op=2 RESULT err=0 tag=101 nentries=1
etime=0
[12/Jan/2015:05:24:01 -0800] conn=529 op=3 EXT
oid="2.16.840.1.113730.3.5.3" name="Netscape Replication Start
Session"
[12/Jan/2015:05:24:01 -0800] conn=529 op=3 RESULT err=0 tag=120 nentries=0
etime=0
[12/Jan/2015:05:24:01 -0800] conn=529 op=4 MOD
dn="cn=z92602g5rmt524klhh1a8,ou=config,ou=577103-1,ou=devices,o=xyz.com"
[12/Jan/2015:05:24:01 -0800] conn=529 op=4 RESULT err=0 tag=103 nentries=0
etime=0 csn=54b3c6cb000000010000
[12/Jan/2015:05:24:01 -0800] conn=529 op=5 MOD
dn="cn=z9246z2fnl84c22s019i1b,ou=config,ou=airhandlersincorporated-1,ou=devices,o=
xyz.com"
[12/Jan/2015:05:24:01 -0800] conn=529 op=5 RESULT err=0 tag=103 nentries=0
etime=0 csn=54b3c6cb000100010000
[12/Jan/2015:05:24:01 -0800] conn=529 op=6 MOD
dn="cn=z924715jqoaf24kijif88,ou=config,ou=640395-1,ou=devices,o=xyz.com"
[12/Jan/2015:05:24:01 -0800] conn=529 op=6 RESULT err=0 tag=103 nentries=0
etime=0 csn=54b3c6d3000000010000
[12/Jan/2015:05:24:01 -0800] conn=529 op=7 MOD
dn="cn=z926027bn6j4238tld0lo,ou=aliases,ou=542433-1,ou=devices,o=xyz.com"
[12/Jan/2015:05:24:01 -0800] conn=529 op=7 RESULT err=0 tag=103 nentries=0
etime=0 csn=54b3c6d6000000010000
[12/Jan/2015:05:24:01 -0800] conn=529 op=8 MOD
dn="cn=z9246z1hhj4a123qjmsp55,ou=config,ou=530501-1,ou=devices,o=xyz.com"
[12/Jan/2015:05:24:01 -0800] conn=529 op=8 RESULT err=0 tag=103 nentries=0
etime=0 csn=54b3c6d7000000010000
[12/Jan/2015:05:24:01 -0800] conn=529 op=9 MOD
dn="cn=z9260knntrc24bdtqtlf,ou=other,ou=612889-1,ou=devices,o=xyz.com"
[12/Jan/2015:05:24:02 -0800] conn=529 op=9 RESULT err=0 tag=103 nentries=0
etime=1 csn=54b3c6d9000100010000
[12/Jan/2015:05:24:02 -0800] conn=529 op=10 MOD
dn="cn=z9260z1bnqgdo21o6dd0t7,ou=config,ou=481913-1,ou=devices,o=xyz.com"
[12/Jan/2015:05:24:02 -0800] conn=529 op=10 RESULT err=0 tag=103 nentries=0
etime=0 csn=54b3c6d9000200010000
[12/Jan/2015:05:24:02 -0800] conn=529 op=11 MOD
dn="cn=6266826,ou=people,ou=542433-1,ou=devices,o=xyz.com"
[12/Jan/2015:05:24:02 -0800] conn=529 op=11 RESULT err=0 tag=103 nentries=0
etime=0 csn=54b3c6dc000000010000
[12/Jan/2015:05:24:02 -0800] conn=529 op=12 MOD
dn="cn=z92601pmqore23rf5ihos,ou=config,ou=577103-1,ou=devices,o=xyz.com"
[12/Jan/2015:05:24:02 -0800] conn=529 op=12 RESULT err=0 tag=103 nentries=0
etime=0 csn=54b3c6de000100010000
[12/Jan/2015:05:24:02 -0800] conn=529 op=13 MOD
dn="cn=z9260knntrc24bdtofmg,ou=config,ou=612889-1,ou=devices,o=xyz.com"
[12/Jan/2015:05:24:03 -0800] conn=529 op=13 RESULT err=0 tag=103 nentries=0
etime=1 csn=54b3c6e1000000010000
[12/Jan/2015:05:24:03 -0800] conn=529 op=14 DEL
dn="cn=4617874,ou=config,ou=techsourcetools-1,ou=devices,o=xyz.com"
[12/Jan/2015:05:24:03 -0800] conn=529 op=14 RESULT err=0 tag=107 nentries=0
etime=0 csn=54b3c6e5000000010000
[12/Jan/2015:05:24:03 -0800] conn=529 op=15 DEL
dn="cn=4617898,ou=people,ou=techsourcetools-1,ou=devices,o=xyz.com"
[12/Jan/2015:05:24:03 -0800] conn=529 op=15 RESULT err=0 tag=107 nentries=0
etime=0 csn=54b3c6e5000400010000
[12/Jan/2015:05:24:03 -0800] conn=529 op=16 DEL
dn="cn=5969000,ou=other,ou=techsourcetools-1,ou=devices,o=xyz.com"
[12/Jan/2015:05:24:03 -0800] conn=529 op=16 RESULT err=0 tag=107 nentries=0
etime=0 csn=54b3c6e5000500010000
thanks,
Shardul.
On Fri, Jan 9, 2015 at 7:01 AM, Rich Megginson <rmeggins(a)redhat.com> wrote:
On 01/08/2015 10:21 AM, shardulsk wrote:
Hi,
Running 389-ds 1.1.2 on Centos 5.
rpm -q 389-ds-base
We have suddenly seen repl5_inc_waitfor_async_results errors crop up in
our error log during peak traffic hours.
The Master loses sight of Hubs and replication stalls. Most of the times
it comes right back up after a couple of mins. However we have been
restarting Hubs to make the process quicker.
tail -f errors
[08/Jan/2015:02:42:08 -0800] NSMMReplicationPlugin - agmt="cn=add -> hub1"
(hub1:2390): Simple bind resumed
[08/Jan/2015:09:04:38 -0800] - repl5_inc_waitfor_async_results timed out
waiting for responses: 0 34222
[08/Jan/2015:09:05:18 -0800] - repl5_inc_waitfor_async_results timed out
waiting for responses: 0 33499
[08/Jan/2015:09:05:37 -0800] NSMMReplicationPlugin - agmt="cn=add -> hub2"
(hub1:2390): Warning: unable to receive endReplication extended operation
response (Can't contact LDAP server)
[08/Jan/2015:09:05:37 -0800] NSMMReplicationPlugin - agmt="cn=add -> hub2"
(hub1:2390): Simple bind failed, LDAP sdk error 91 (Can't connect to the
LDAP server), Netscape Portable Runtime error -5961 (TCP connection reset
by peer.)
What is happening on the consumer (hub2?) at this time? That is, take a
look at the access and errors logs from around this time on hub2.
[08/Jan/2015:09:05:59 -0800] NSMMReplicationPlugin - agmt="cn=add ->
hub2" (hub1:2390): Simple bind resumed
[08/Jan/2015:09:07:43 -0800] NSMMReplicationPlugin - agmt="cn=add -> hub1"
(hub1:2390): Warning: unable to receive endReplication extended operation
response (Can't contact LDAP server)
[08/Jan/2015:09:07:43 -0800] NSMMReplicationPlugin - agmt="cn=add -> hub1"
(hub1:2390): Simple bind failed, LDAP sdk error 91 (Can't connect to the
LDAP server), Netscape Portable Runtime error -5961 (TCP connection reset
by peer.)
[08/Jan/2015:09:08:05 -0800] NSMMReplicationPlugin - agmt="cn=add -> hub1"
(hub1:2390): Simple bind resumed
Any idea what is causing this? I checked ADD/DEL operations during the
outage and none of them stand out. No MOD errors and all MODs completed
within a second.
~Shardul
--
389 users mailing
list389-users@lists.fedoraproject.orghttps://admin.fedoraproject.org/mailman/listinfo/389-users
--
389 users mailing list
389-users(a)lists.fedoraproject.org
https://admin.fedoraproject.org/mailman/listinfo/389-users