[Freeipa-users] FreeIPA password sync one direction only (Windows DC -> IPA)

Rich Megginson rmeggins at redhat.com
Fri May 17 18:09:52 UTC 2013


On 05/17/2013 12:03 PM, Steve Dainard wrote:
> Thanks for getting me on the right track.
>
> Yes to the Windows sync agreement.
>
> I'm not sure if this is related to password sync'ing, but it looks 
> like a sync operation is triggering (and failing) every 4 seconds on 
> one of my users:
>
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): State: start_backoff -> 
> backoff
> [17/May/2013:13:28:42 -0400] - acquire_replica, supplier RUV:
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - supplier: 
> {replicageneration} 50802036000000030000
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - supplier: 
> {replica 3 ldap://ipa1.miovision.linux:389} 50802036000100030000 
> 51966776000100030000 51966776
> [17/May/2013:13:28:42 -0400] - acquire_replica, consumer RUV:
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - consumer: 
> {replicageneration} 50802036000000030000
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - consumer: 
> {replica 3 ldap://ipa1.miovision.linux:389} 50802036000100030000 
> 515ad91f000000030000 00000000
> [17/May/2013:13:28:42 -0400] - acquire_replica, supplier RUV is newer
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): Cancelling linger on the 
> connection
> [17/May/2013:13:28:42 -0400] - _csngen_adjust_local_time: gen state 
> before 519668c60001:1368811718:0:0
> [17/May/2013:13:28:42 -0400] - _csngen_adjust_local_time: gen state 
> after 519668ca0000:1368811722:0:0
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): State: backoff -> 
> sending_updates
> [17/May/2013:13:28:42 -0400] - csngen_adjust_time: gen state before 
> 519668ca0001:1368811722:0:0
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - changelog program 
> - _cl5GetDBFile: found DB object f6d910 for database 
> /var/lib/dirsrv/slapd-MIOVISION-LINUX/cldb/854fd282-193811e2-9177aa0d-17c9983f_50802036000000030000.db4
> [17/May/2013:13:28:42 -0400] - _cl5PositionCursorForReplay 
> (agmt="cn=meTodc1.miovision.corp" (dc1:389)): Consumer RUV:
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): {replicageneration} 
> 50802036000000030000
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): {replica 3 
> ldap://ipa1.miovision.linux:389} 50802036000100030000 
> 515ad91f000000030000 00000000
> [17/May/2013:13:28:42 -0400] - _cl5PositionCursorForReplay 
> (agmt="cn=meTodc1.miovision.corp" (dc1:389)): Supplier RUV:
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): {replicageneration} 
> 50802036000000030000
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): {replica 3 
> ldap://ipa1.miovision.linux:389} 50802036000100030000 
> 51966776000100030000 51966776
> [17/May/2013:13:28:42 -0400] agmt="cn=meTodc1.miovision.corp" 
> (dc1:389) - clcache_get_buffer: found thread private buffer cache 
> 7f30bc061d00
> [17/May/2013:13:28:42 -0400] agmt="cn=meTodc1.miovision.corp" 
> (dc1:389) - clcache_get_buffer: _pool is 2e7cc10 _pool->pl_busy_lists 
> is 7f30bc050790 _pool->pl_busy_lists->bl_buffers is 7f30bc061d00
> [17/May/2013:13:28:42 -0400] agmt="cn=meTodc1.miovision.corp" 
> (dc1:389) - session start: anchorcsn=515ad91f000000030000
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - changelog program 
> - agmt="cn=meTodc1.miovision.corp" (dc1:389): CSN 515ad91f000000030000 
> found, position set for replay
> [17/May/2013:13:28:42 -0400] agmt="cn=meTodc1.miovision.corp" 
> (dc1:389) - load=1 rec=1 csn=515ae3f4000000030000
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): windows_replay_update: 
> Looking at modify operation local 
> dn="uid=jkeller,cn=users,cn=accounts,dc=miovision,dc=linux" 
> (ours,user,not group)
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): map_entry_dn_outbound: 
> looking for AD entry for DS 
> dn="uid=jkeller,cn=users,cn=accounts,dc=miovision,dc=linux" 
> guid="ba17f9770e0c814cb9eea9df2d4df61a"
> [17/May/2013:13:28:42 -0400] - Calling windows entry search request plugin
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - Could not 
> retrieve entry from Windows using search base 
> [<GUID=ba17f9770e0c814cb9eea9df2d4df61a>] scope [0] filter 
> [(objectclass=*)]: error 1:Operations error
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): map_entry_dn_outbound: 
> return code -1 from search for AD entry 
> dn="<GUID=ba17f9770e0c814cb9eea9df2d4df61a>" or dn="(null)"
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): map_entry_dn_outbound: 
> entry not found - rc -1
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): windows_replay_update: 
> Processing modify operation local 
> dn="uid=jkeller,cn=users,cn=accounts,dc=miovision,dc=linux" remote 
> dn="<GUID=ba17f9770e0c814cb9eea9df2d4df61a>"
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): map_entry_dn_outbound: 
> looking for AD entry for DS 
> dn="uid=jkeller,cn=users,cn=accounts,dc=miovision,dc=linux" 
> guid="ba17f9770e0c814cb9eea9df2d4df61a"
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): map_entry_dn_outbound: 
> looking for AD entry for DS 
> dn="uid=jkeller,cn=users,cn=accounts,dc=miovision,dc=linux" 
> username="jkeller"
> [17/May/2013:13:28:42 -0400] - Calling windows entry search request plugin
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - Could not 
> retrieve entry from Windows using search base [dc=miovision,dc=corp] 
> scope [2] filter [(samAccountName=jkeller)]: error 1:Operations error
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): map_entry_dn_outbound: 
> entry not found - rc -1
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): map_entry_dn_outbound: 
> failed to fetch entry from AD: 
> dn="uid=jkeller,cn=users,cn=accounts,dc=miovision,dc=linux", err=-1
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): windows_replay_update: 
> update password returned 1
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): Consumer failed to replay 
> change (uniqueid cd3be819-21c711e2-96aaaa0d-17c9983f, CSN 
> 515ae3f4000000030000): Operations error. Will retry later.
> [17/May/2013:13:28:42 -0400] agmt="cn=meTodc1.miovision.corp" 
> (dc1:389) - session end: state=0 load=1 sent=1 skipped=0
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): Beginning linger on the 
> connection
> [17/May/2013:13:28:42 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): State: sending_updates -> 
> start_backoff
>
>
>
> Here's the output of an ldapsearch for the user jkeller:
>
> #/usr/bin/ldapsearch -h dc1.miovision.corp -D 
> "ldap-auth at miovision.corp" -W -b "dc=miovision,dc=corp" 
> '(samAccountName=jkeller)' cn samAccountName
>
> # Joel Keller, 01Engineering, miovision.corp
> dn: CN=Joel Keller,OU=01Engineering,DC=miovision,DC=corp
> cn: Joel Keller
> sAMAccountName: jkeller
>
>
>
> When I change my password on the IPA server, it looks like the change 
> is queued:
>
> [17/May/2013:13:53:48 -0400] - _csngen_adjust_local_time: gen state 
> before 51966eab0001:1368813227:0:0
> [17/May/2013:13:53:48 -0400] - _csngen_adjust_local_time: gen state 
> after 51966eac0000:1368813228:0:0
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - 
> ruv_add_csn_inprogress: successfully inserted csn 51966eac000000030000 
> into pending list
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - Purged state 
> information from entry 
> uid=sdainard,cn=users,cn=accounts,dc=miovision,dc=linux up to CSN 
> 518d33f90007000300
> 00
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - changelog program 
> - _cl5GetDBFileByReplicaName: found DB object f6d910 for database 
> /var/lib/dirsrv/slapd-MIOVISION-LINU
> X/cldb/854fd282-193811e2-9177aa0d-17c9983f_50802036000000030000.db4
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - changelog program 
> - _cl5GetDBFileByReplicaName: found DB object f6d910 for database 
> /var/lib/dirsrv/slapd-MIOVISION-LINU
> X/cldb/854fd282-193811e2-9177aa0d-17c9983f_50802036000000030000.db4
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - ruv_update_ruv: 
> successfully committed csn 51966eac000000030000
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - 
> ruv_add_csn_inprogress: successfully inserted csn 51966eac000100030000 
> into pending list
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - Purged state 
> information from entry 
> uid=sdainard,cn=users,cn=accounts,dc=miovision,dc=linux up to CSN 
> 518d342c0000000300
> 00
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - changelog program 
> - _cl5GetDBFileByReplicaName: found DB object f6d910 for database 
> /var/lib/dirsrv/slapd-MIOVISION-LINUX/cldb/854fd282-193811e2-9177aa0d-17c9983f_50802036000000030000.db4
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - changelog program 
> - _cl5GetDBFileByReplicaName: found DB object f6d910 for database 
> /var/lib/dirsrv/slapd-MIOVISION-LINUX/cldb/854fd282-193811e2-9177aa0d-17c9983f_50802036000000030000.db4
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - ruv_update_ruv: 
> successfully committed csn 51966eac000100030000
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): State: start_backoff -> 
> backoff
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - 
> ruv_add_csn_inprogress: successfully inserted csn 51966eac000200030000 
> into pending list
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - Purged state 
> information from entry 
> uid=sdainard,cn=users,cn=accounts,dc=miovision,dc=linux up to CSN 
> 518d342c000100030000
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - changelog program 
> - _cl5GetDBFileByReplicaName: found DB object f6d910 for database 
> /var/lib/dirsrv/slapd-MIOVISION-LINUX/cldb/854fd282-193811e2-9177aa0d-17c9983f_50802036000000030000.db4
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - changelog program 
> - _cl5GetDBFileByReplicaName: found DB object f6d910 for database 
> /var/lib/dirsrv/slapd-MIOVISION-LINUX/cldb/854fd282-193811e2-9177aa0d-17c9983f_50802036000000030000.db4
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - ruv_update_ruv: 
> successfully committed csn 51966eac000200030000
> [17/May/2013:13:53:48 -0400] NSMMReplicationPlugin - 
> agmt="cn=meTodc1.miovision.corp" (dc1:389): State: backoff -> backoff
>
>
>
> Perhaps whatever is causing the sync error with user jkeller is 
> holding up the queued transactions?

Yes.  It is attempting to replay the password change operation.  It 
first tries to find the entry in AD, but that is failing with operations 
error.

Try doing the ldapsearch with the same bind DN and password you 
specified when you set up the winsync agreement.  Or did you use 
"ldap-auth at miovision.corp"?

Another difference is that winsync uses LDAPS - so try this:

LDAPTLS_CACERTDIR=/etc/dirsrv/slapd-YOUR-DOMAIN ldapsearch -H 
ldaps://dc1.miovision.corp -D "ldap-auth at miovision.corp" -W -b 
"dc=miovision,dc=corp" '(samAccountName=jkeller)' cn samAccountName

>
>
>
>
> Steve Dainard
> Infrastructure Manager
> Miovision Technologies Inc.
>
>
> On Fri, May 17, 2013 at 11:39 AM, Rich Megginson <rmeggins at redhat.com 
> <mailto:rmeggins at redhat.com>> wrote:
>
>     On 05/17/2013 09:26 AM, Steve Dainard wrote:
>>     Hello,
>>
>>     We're running a single IPA server (CentOS 6) on our network as a
>>     side project for some testing before we implement.
>>
>>     It had been a significant period of time since I had last logged
>>     into the web interface, so I had to kinit from a client machine
>>     (of which I had logged into successfully with my domain
>>     password), at which point I was requested to change my password.
>>     After the password change I RDP'd into a Windows machine on our
>>     domain and realized the password had not been updated on the
>>     domain controller.
>>
>>     Is the password sync feature with an external source such as
>>     Active Directory supposed to be two-way? If so where can I start
>>     troubleshooting this issue?
>
>     Are you talking about a windows sync agreement you set up with
>     ipa-replica-manage?
>     If so, yes, the password sync is supposed to be two-way.
>     Try this:
>     turn on the replication log level
>     http://port389.org/wiki/FAQ#Troubleshooting
>     change your IPA password
>     turn off the replication log level
>     http://port389.org/wiki/FAQ#Troubleshooting
>     see if you can use your new password in AD
>
>     The 389 errors log in /var/log/dirsrv/slapd-YOUR-DOMAIN/errors may
>     contain a clue.
>
>>
>>     Thanks,
>>
>>
>>
>>     Steve Dainard
>>     Infrastructure Manager
>>     Miovision Technologies Inc.
>>
>>
>>     _______________________________________________
>>     Freeipa-users mailing list
>>     Freeipa-users at redhat.com  <mailto:Freeipa-users at redhat.com>
>>     https://www.redhat.com/mailman/listinfo/freeipa-users
>
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20130517/f58d7ae3/attachment.htm>


More information about the Freeipa-users mailing list