[Fedora-directory-users] Active Directory PW sync works for console but not user initiated PW changes

Tue Apr 28 01:07:40 UTC 2009

John A. Sullivan III wrote:
> Hello, all.  This is a sequel to the last email on this subject now that
> we've resolved the shadowLastChange problem.  Fixing that problem did
> not fix the DS 8.0 / AD password synchronization problem.  To reiterate,
> the passwords synchronize if the change is made from idm-console or from
> AD.  But they do not change when our Ubuntu/KDE users change their own
> passwords.  It fails when changed from both the KDE password change
> interface and using passwd at the command line.
>   
Take a look at the directory server access log - I think the change is 
being rejected before it even gets into the replication code, which is 
why the error log output below is not too helpful.
> Windows Event Viewer is not giving me any useful information.  There is
> quite a bit of information in the DS logs but I'm not quite sure what
> they are telling me.  I'll post pertinent snippets below (please pardon
> the left truncation but I'm screen scraping):
>
> icationPlugin - ruv_add_csn_inprogress: successfully inserted csn 49f632dd000000010000 into pending list
> icationPlugin - Purged state information from entry uid=mlap,ou=Desks,o=a0000-0010,o=Internal,dc=ssiservices,dc=biz up to CSN 49ecf604000200010000
> icationPlugin - ruv_add_csn_inprogress: successfully inserted csn 49f632dd000100010000 into pending list
> icationPlugin - Purged state information from entry uid=mlap,ou=Desks,o=a0000-0010,o=Internal,dc=ssiservices,dc=biz up to CSN 49ecf604000200010000
> icationPlugin - ruv_update_ruv: successfully committed csn 49f632dd000100010000
> icationPlugin - ruv_add_csn_inprogress: successfully inserted csn 49f632dd000200010000 into pending list
> icationPlugin - Purged state information from entry uid=mlap,ou=Desks,o=a0000-0010,o=Internal,dc=ssiservices,dc=biz up to CSN 49ecf604000200010000
> icationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): State: wait_for_changes -> wait_for_changes
> icationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): State: wait_for_changes -> ready_to_acquire_replica
> (this seemed to happen immediately upon password change and not in the normal five minute sync routine)
> .
> .
> .
> [27/Apr/2009:18:34:05 -0400] NSMMReplicationPlugin - ruv_update_ruv: successfully committed csn 49f632dd000200010000
> [27/Apr/2009:18:34:05 -0400] - acquire_replica, supplier RUV:
> .
> .
> .
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - ruv_update_ruv: successfully committed csn 49f632dd000000010000
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - supplier: {replicageneration} 49e5ebb3000000010000
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - supplier: {replica 1 ldap://ldap01.ssiservices.biz:389} 49e70122000000010000 49f632dd000200010000 49f632dd
> r/2009:18:34:05 -0400] - acquire_replica, consumer RUV:
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - consumer: {replicageneration} 49e5ebb3000000010000
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - consumer: {replica 1 ldap://ldap01.ssiservices.biz:389} 49e70122000000010000 49f63084000200010000 49f63084
> r/2009:18:34:05 -0400] - acquire_replica, supplier RUV is newer
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): Trying secure slapi_ldap_init
> NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): binddn = cn=Synch Manager,cn=Users,dc=mycompany,dc=com,  passwd = {DES}tOBO
> .
> .
> .
> [27/Apr/2009:18:34:05 -0400] - windows_conn_connect : detected Win2k3 peer
> [27/Apr/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): No linger to cancel on the connection
> [27/Apr/2009:18:34:05 -0400] NSMMReplicationPlugin - windows_acquire_replica returned success (101)
> [27/Apr/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): State: ready_to_acquire_replica -> sending_updates
> [27/Apr/2009:18:34:05 -0400] - _cl5PositionCursorForReplay (agmt="cn=a0000-0010(EBC)" (timberline:636)): Consumer RUV:
> [27/Apr/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): {replicageneration} 49e5ebb3000000010000
> tionPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): {replica 1 ldap://ldap01.ssiservices.biz:389} 49e70122000000010000 49f63084000200010000 49f63084
> [27/Apr/2009:18:34:05 -0400] - _cl5PositionCursorForReplay (agmt="cn=a0000-0010(EBC)" (timberline:636)): Supplier RUV:
> [27/Apr/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): {replicageneration} 49e5ebb3000000010000
> tionPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): {replica 1 ldap://ldap01.ssiservices.biz:389} 49e70122000000010000 49f632dd000200010000 49f632dd
> 05 -0400] agmt="cn=a0000-0010(EBC)" (timberline:636) - session start: anchorcsn=49f63084000200010000
> 05 -0400] NSMMReplicationPlugin - changelog program - agmt="cn=a0000-0010(EBC)" (timberline:636): CSN 49f63084000200010000 found, position set for replay
> 05 -0400] agmt="cn=a0000-0010(EBC)" (timberline:636) - load=1 rec=1 csn=49f632dd000000010000
> 8:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): windows_replay_update: Looking at modify operation local dn="uid=mlap,ou=desks,o=a0000-0010,o=internal,dc=ssiservices,dc=biz" (ours,user,not group)
> 8:34:05 -0400] NSMMReplicationPlugin - agmt="cn=ssiservices.biz ldap01->ldap02" (ldap02:636): No linger to cancel on the connection
> 8:34:05 -0400] - windows_search_entry: recieved 2 messages, 1 entries, 0 references
> 8:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): windows_replay_update: Processing modify operation local dn="uid=mlap,ou=desks,o=a0000-0010,o=internal,dc=ssiservices,dc=biz" remote dn="<GUID=5b0db1b95d6dca44aaef260be70ee31b>"
> 8:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): windows_create_remote_entry: Password is already hashed.  Not syncing.
> **** THIS ENTRY ABOUT NOT SYNCING CERTAINLY JUMPED OUT AT ME BUT I DON'T KNOW WHAT IT MEANS *****
> 8:34:05 -0400] agmt="cn=a0000-0010(EBC)" (timberline:636) - load=1 rec=2 csn=49f632dd000100010000
> NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): windows_replay_update: Looking at modify operation local dn="uid=mlap,ou=desks,o=a0000-0010,o=internal,dc=ssiservices,dc=biz" (ours,user,not group)
> .
> .
> .
> - windows_search_entry: recieved 2 messages, 1 entries, 0 references
> NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): windows_replay_update: Processing modify operation local dn="uid=mlap,ou=desks,,o=a0000-0010,o=internal,dc=ssiservices,dc=biz" remote dn="<GUID=5b0db1b95d6dca44aaef260be70ee31b>"
> agmt="cn=a0000-0010(EBC)" (timberline:636) - load=1 rec=3 csn=49f632dd000200010000
> NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): windows_replay_update: Looking at modify operation local dn="uid=mlap,ou=desks,o=a0000-0010,o=internal,dc=ssiservices,dc=biz" (ours,user,not group)
> .
> .
> .
> [27/Apr/2009:18:34:05 -0400] - repl5_inc_result_threadmain starting
> [27/Apr/2009:18:34:05 -0400] - windows_search_entry: recieved 2 messages, 1 entries, 0 references
> NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): windows_replay_update: Processing modify operation local dn="uid=mlap,ou=desks,,o=a0000-0010,o=internal,dc=ssiservices,dc=biz" remote dn="<GUID=5b0db1b95d6dca44aaef260be70ee31b>"
> - repl5_inc_result_threadmain: read result for message_id 0
> [27/Apr/2009:18:34:05 -0400] - repl5_inc_result_threadmain: read result for message_id 0
> .
> .
> .
> [27/Apr/2009:18:34:05 -0400] - repl5_inc_result_threadmain: read result for message_id 0
> [27/Apr/2009:18:34:05 -0400] agmt="cn=a0000-0010(EBC)" (timberline:636) - clcache_load_buffer: rc=-30989
> [27/Apr/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): No more updates to send (cl5GetNextOperationToReplay)
> [27/Apr/2009:18:34:05 -0400] agmt="cn=a0000-0010(EBC)" (timberline:636) - session end: state=5 load=1 sent=3 skipped=0
> [27/Apr/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): Beginning linger on the connection
> [27/Apr/2009:18:34:05 -0400] - repl5_inc_result_threadmain: read result for message_id 0
> [27/Apr/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): Linger timeout has expired on the connection
> [27/Apr/2009:18:34:05 -0400] - repl5_inc_result_threadmain: read result for message_id 6
> [27/Apr/2009:18:34:05 -0400] - repl5_inc_result_threadmain: result 3, 0, 0, 6, (null)
> [27/Apr/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=ssiservices.biz ldap01->ldap02" (ldap02:636): replay_update: Consumer successfully sent oper
> [27/Apr/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): Disconnected from the consumer
> [27/Apr/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): State: sending_updates -> wait_for_changes
> [27/Apr/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): State: wait_for_changes -> ready_to_acquire_replica
> [27/Apr/2009:18:34:05 -0400] - acquire_replica, supplier RUV:
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - supplier: {replicageneration} 49e5ebb3000000010000
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - supplier: {replica 1 ldap://ldap01.ssiservices.biz:389} 49e70122000000010000 49f632dd000200010000 49f632dd
> r/2009:18:34:05 -0400] - acquire_replica, consumer RUV:
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - consumer: {replicageneration} 49e5ebb3000000010000
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - consumer: {replica 1 ldap://ldap01.ssiservices.biz:389} 49e70122000000010000 49f632dd000200010000 49f632dd
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - windows_acquire_replica returned consumer_was_uptodate (104)
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): State: ready_to_acquire_replica -> wait_for_changes
> .
> .
> .
> .
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - ruv_update_ruv: successfully committed csn 49f632dd000500010000
> r/2009:18:34:05 -0400] - repl5_inc_result_threadmain: read result for message_id 7
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): State: wait_for_changes -> wait_for_changes
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): State: wait_for_changes -> ready_to_acquire_replica
> r/2009:18:34:05 -0400] - acquire_replica, supplier RUV:
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - supplier: {replicageneration} 49e5ebb3000000010000
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - supplier: {replica 1 ldap://ldap01.ssiservices.biz:389} 49e70122000000010000 49f632dd000500010000 49f632dd
> r/2009:18:34:05 -0400] - acquire_replica, consumer RUV:
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - consumer: {replicageneration} 49e5ebb3000000010000
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - consumer: {replica 1 ldap://ldap01.ssiservices.biz:389} 49e70122000000010000 49f632dd000200010000 49f632dd
> r/2009:18:34:05 -0400] - acquire_replica, supplier RUV is newer
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): Trying secure slapi_ldap_init
> r/2009:18:34:05 -0400] - repl5_inc_result_threadmain: read result for message_id 7
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): binddn = cn=SSI Synchronization Manager,cn=Users,dc=ebc-co,dc=c
> r/2009:18:34:05 -0400] - repl5_inc_result_threadmain: read result for message_id 8
> r/2009:18:34:05 -0400] - repl5_inc_result_threadmain: result 3, 0, 0, 8, (null)
> r/2009:18:34:05 -0400] - windows_conn_connect : detected Win2k3 peer
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): No linger to cancel on the connection
> r/2009:18:34:05 -0400] - repl5_inc_result_threadmain: read result for message_id 8
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - windows_acquire_replica returned success (101)
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): State: ready_to_acquire_replica -> sending_updates
> r/2009:18:34:05 -0400] - repl5_inc_result_threadmain: read result for message_id 8
> r/2009:18:34:05 -0400] - _cl5PositionCursorForReplay (agmt="cn=a0000-0010(EBC)" (timberline:636)): Consumer RUV:
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): {replicageneration} 49e5ebb3000000010000
> r/2009:18:34:05 -0400] - repl5_inc_result_threadmain: read result for message_id 8
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): {replica 1 ldap://ldap01.ssiservices.biz:389} 49e70122000000010000 49f632dd000200010000 49f632dd
> r/2009:18:34:05 -0400] - _cl5PositionCursorForReplay (agmt="cn=a0000-0010(EBC)" (timberline:636)): Supplier RUV:
> r/2009:18:34:05 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): {replicageneration} 49e5ebb3000000010000
> tionPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): {replica 1 ldap://ldap01.ssiservices.biz:389} 49e70122000000010000 49f632dd000500010000 49f632dd
> 5 -0400] - repl5_inc_result_threadmain: read result for message_id 8
> 5 -0400] agmt="cn=a0000-0010(EBC)" (timberline:636) - session start: anchorcsn=49f632dd000200010000
> 5 -0400] NSMMReplicationPlugin - changelog program - agmt="cn=a0000-0010(EBC)" (timberline:636): CSN 49f632dd000200010000 found, position set for replay
> 5 -0400] agmt="cn=a0000-0010(EBC)" (timberline:636) - load=1 rec=1 csn=49f632dd000500010000
> 5 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): windows_replay_update: Looking at modify operation local dn="uid=mlap,ou=desks,o=a0000-0010,o=internal,dc=ssiservices,dc=biz" (ours,user,not group)
> 5 -0400] - windows_search_entry: recieved 2 messages, 1 entries, 0 references
> 5 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): windows_replay_update: Processing modify operation local dn="uid=mlap,ou=desks,o=a0000-0010,o=internal,dc=ssiservices,dc=biz" remote dn="<GUID=5b0db1b95d6dca44aaef260be70ee31b>"
> 5 -0400] agmt="cn=a0000-0010(EBC)" (timberline:636) - clcache_load_buffer: rc=-30989
> 5 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): No more updates to send (cl5GetNextOperationToReplay)
> 5 -0400] agmt="cn=a0000-0010(EBC)" (timberline:636) - session end: state=5 load=1 sent=1 skipped=0
> 5 -0400] - repl5_inc_result_threadmain: read result for message_id 8
> 5 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): Beginning linger on the connection
> 5 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): State: sending_updates -> wait_for_changes
> 5 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): Linger timeout has expired on the connection
> 5 -0400] NSMMReplicationPlugin - agmt="cn=a0000-0010(EBC)" (timberline:636): Disconnected from the consumer
> 5 -0400] - repl5_inc_result_threadmain: read result for message_id 8
> 5 -0400] - repl5_inc_result_threadmain: read result for message_id 8
> 5 -0400] - repl5_inc_result_threadmain: read result for message_id 8
> 5 -0400] - repl5_inc_result_threadmain: read result for message_id 8
> 6 -0400] - repl5_inc_result_threadmain: read result for message_id 8
> 6 -0400] - repl5_inc_waitfor_async_results: 8 8
> 6 -0400] - repl5_inc_result_threadmain: read result for message_id 8
> 7 -0400] - repl5_inc_result_threadmain exiting
> .
> .
> .
> .
> 27/Apr/2009:18:34:07 -0400] - repl5_inc_waitfor_async_results: 0 12
> [27/Apr/2009:18:34:07 -0400] - repl5_inc_result_threadmain: read result for message_id 0
> [27/Apr/2009:18:34:07 -0400] - repl5_inc_result_threadmain: read result for message_id 12
> [27/Apr/2009:18:34:07 -0400] - repl5_inc_result_threadmain: result 3, 0, 0, 12, (null)
> [27/Apr/2009:18:34:07 -0400] - repl5_inc_result_threadmain: read result for message_id 12
> [27/Apr/2009:18:34:07 -0400] - repl5_inc_result_threadmain: read result for message_id 12
> [27/Apr/2009:18:34:07 -0400] - repl5_inc_result_threadmain: read result for message_id 12
> [27/Apr/2009:18:34:07 -0400] - repl5_inc_result_threadmain: read result for message_id 12
> [27/Apr/2009:18:34:07 -0400] - repl5_inc_result_threadmain: read result for message_id 12
> [27/Apr/2009:18:34:07 -0400] - repl5_inc_result_threadmain: read result for message_id 12
> [27/Apr/2009:18:34:07 -0400] - repl5_inc_result_threadmain: read result for message_id 12
> [27/Apr/2009:18:34:07 -0400] - repl5_inc_result_threadmain: read result for message_id 12
> [27/Apr/2009:18:34:08 -0400] - repl5_inc_result_threadmain: read result for message_id 12
> [27/Apr/2009:18:34:08 -0400] - repl5_inc_result_threadmain: read result for message_id 12
> [27/Apr/2009:18:34:08 -0400] - repl5_inc_waitfor_async_results: 12 12
> [27/Apr/2009:18:34:08 -0400] - repl5_inc_result_threadmain: read result for message_id 12
> [27/Apr/2009:18:34:09 -0400] - repl5_inc_result_threadmain exiting
> [27/Apr/2009:18:34:09 -0400] agmt="cn=ssiservices.biz ldap01->ldap02" (ldap02:636) - session end: state=5 load=1 sent=1 skipped=0
>
> Does anyone see the problem? How do I get synchronization working when
> the users change their own passwords? Thanks - John
>   

-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/x-pkcs7-signature
Size: 3258 bytes
Desc: S/MIME Cryptographic Signature
URL: <http://lists.fedoraproject.org/pipermail/389-users/attachments/20090427/af3ba84e/attachment.bin>