Re: repl5_inc_waitfor_async_results

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 

On 01/12/2015 07:18 AM, shardulsk wrote:
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.

By my version query, I wasn't necessarily suggesting that you upgrade, I'm just trying to find out the exact version of 389-ds-base that you are using.

Can you please provide the output of rpm -q 389-ds-base?



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@xxxxxxxxxx> 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 list
389-users@xxxxxxxxxxxxxxxxxxxxxxx
https://admin.fedoraproject.org/mailman/listinfo/389-users


--
389 users mailing list
389-users@xxxxxxxxxxxxxxxxxxxxxxx
https://admin.fedoraproject.org/mailman/listinfo/389-users



--
389 users mailing list
389-users@xxxxxxxxxxxxxxxxxxxxxxx
https://admin.fedoraproject.org/mailman/listinfo/389-users

--
389 users mailing list
389-users@xxxxxxxxxxxxxxxxxxxxxxx
https://admin.fedoraproject.org/mailman/listinfo/389-users
[Index of Archives]     [Fedora User Discussion]     [Older Fedora Users]     [Fedora Announce]     [Fedora Package Announce]     [EPEL Announce]     [Fedora News]     [Fedora Cloud]     [Fedora Advisory Board]     [Fedora Education]     [Fedora Security]     [Fedora Scitech]     [Fedora Robotics]     [Fedora Maintainers]     [Fedora Infrastructure]     [Fedora Websites]     [Anaconda Devel]     [Fedora Devel Java]     [Fedora Legacy]     [Fedora Desktop]     [Fedora Fonts]     [ATA RAID]     [Fedora Marketing]     [Fedora Management Tools]     [Fedora Mentors]     [Fedora Package Review]     [Fedora R Devel]     [Fedora PHP Devel]     [Kickstart]     [Fedora Music]     [Fedora Packaging]     [Centos]     [Fedora SELinux]     [Fedora Legal]     [Fedora Kernel]     [Fedora QA]     [Fedora Triage]     [Fedora OCaml]     [Coolkey]     [Virtualization Tools]     [ET Management Tools]     [Yum Users]     [Tux]     [Yosemite News]     [Yosemite Photos]     [Linux Apps]     [Maemo Users]     [Gnome Users]     [KDE Users]     [Fedora Tools]     [Fedora Art]     [Fedora Docs]     [Maemo Users]     [Asterisk PBX]     [Fedora Sparc]     [Fedora Universal Network Connector]     [Fedora ARM]

  Powered by Linux