[Fedora-directory-users] Winsync and "New Windows User Sync" and "New Windows Group Sync"

[Ivan Ferreira]

Hello all.

I sucessfully installed Fedora Directory Server 1.0.4-1.RHEL4 on RHEL4U5.
Also PassSync-20060330.msi was installed and configured in the Windows 2003
Domain Controller.

SSL connection is working.

Password synchronization works if the user exists on both Directories, but
new users and groups are not created.

I have enabled the "New Windows User Sync" and "New Windows Group
Sync"
checkboxes, but nothing happens in the logs when I create a new user or
group.

Debug is enabled in DS and PassSync.

PassSync log:

06/15/07 19:11:41: There are no entries that match: juancitoperez
06/15/07 19:11:41: Deferring password change for juancitoperez
06/15/07 19:11:41: Backing off for 2048000ms


Directory Server log:

[15/Jun/2007:19:44:25 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): State: wait_for_changes -> wait_for_changes
[15/Jun/2007:19:44:25 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): State: wait_for_changes -> wait_for_changes
[15/Jun/2007:19:44:25 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): No linger to cancel on the connection
[15/Jun/2007:19:44:25 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): Disconnected from the consumer
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): windows_inc_stop: protocol stopped after 1 seconds
[15/Jun/2007:19:44:26 -0400] - acquire_replica, supplier RUV:
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - supplier:
{replicageneration} 46707261000000030000
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - supplier: {replica 3
ldap://infra1.sis.personal.net.py:389} 46714c54000000030000
46730709000100030000 00000000
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - supplier: {replica 4
ldap://infra2.sis.personal.net.py:389}
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - supplier: {replica 1
ldap://infra1.sis.personal.net.py:389} 4673124f000000010000
46731f00000000010000 46731f01
[15/Jun/2007:19:44:26 -0400] - acquire_replica, consumer RUV:
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - consumer:
{replicageneration} 46707261000000030000
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - consumer: {replica 3
ldap://infra1.sis.personal.net.py:389} 46714c54000000030000
46730709000100030000 00000000
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - consumer: {replica 4
ldap://infra2.sis.personal.net.py:389}
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - consumer: {replica 1
ldap://infra1.sis.personal.net.py:389} 4673124f000000010000
467316d4000000010000 00000000
[15/Jun/2007:19:44:26 -0400] - acquire_replica, supplier RUV is newer
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): Trying secure slapi_ldap_init
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): binddn = cn=SSOSync,ou=Service
accounts,ou=Usuarios,dc=personal,dc=com,dc=py,  passwd =
{DES}T4FVTMFnERrR8F1Io6In7Q==
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): No linger to cancel on the connection
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - Beginning total update
of replica "agmt="cn=AD-FDS" (asusis-dc:636)".
[15/Jun/2007:19:44:26 -0400] - Sending dirsync search request
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): windows_process_total_entry: Looking
dn="uid=pgimenez,ou=SSO,dc=sis,dc=personal,dc=net,dc=py" (ours)
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): map_entry_dn_outbound: failed to fetch entry from AD:
dn="uid=pgimenez,ou=SSO,dc=sis,dc=personal,dc=net,dc=py", err=-1
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): windows_replay_update: failed map dn for total update
dn="uid=pgimenez,ou=SSO,dc=sis,dc=personal,dc=net,dc=py"
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): Beginning linger on the connection
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): windows_tot_run: failed to obtain data to send to the
consumer; LDAP error - -1
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): No linger to cancel on the connection
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): Disconnected from the consumer
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): State: start -> ready_to_acquire_replica
[15/Jun/2007:19:44:26 -0400] - acquire_replica, supplier RUV:
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - supplier:
{replicageneration} 46707261000000030000
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - supplier: {replica 3
ldap://infra1.sis.personal.net.py:389} 46714c54000000030000
46730709000100030000 00000000
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - supplier: {replica 4
ldap://infra2.sis.personal.net.py:389}
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - supplier: {replica 1
ldap://infra1.sis.personal.net.py:389} 4673124f000000010000
46731f00000000010000 46731f01
[15/Jun/2007:19:44:26 -0400] - acquire_replica, consumer RUV:
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - consumer:
{replicageneration} 46707261000000030000
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - consumer: {replica 3
ldap://infra1.sis.personal.net.py:389} 46714c54000000030000
46730709000100030000 00000000
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - consumer: {replica 4
ldap://infra2.sis.personal.net.py:389}
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - consumer: {replica 1
ldap://infra1.sis.personal.net.py:389} 4673124f000000010000
467316d4000000010000 00000000
[15/Jun/2007:19:44:26 -0400] - acquire_replica, supplier RUV is newer
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): Trying secure slapi_ldap_init
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): binddn = cn=SSOSync,ou=Service
accounts,ou=Usuarios,dc=personal,dc=com,dc=py,  passwd =
{DES}T4FVTMFnERrR8F1Io6In7Q==
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): No linger to cancel on the connection
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin -
windows_acquire_replica returned success (101)
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): State: ready_to_acquire_replica -> sending_updates
[15/Jun/2007:19:44:26 -0400] - _cl5PositionCursorForReplay
(agmt="cn=AD-FDS" (asusis-dc:636)): Consumer RUV:
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): {replicageneration} 46707261000000030000
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): {replica 3 ldap://infra1.sis.personal.net.py:389}
46714c54000000030000 46730709000100030000 00000000
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): {replica 4 ldap://infra2.sis.personal.net.py:389}
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): {replica 1 ldap://infra1.sis.personal.net.py:389}
4673124f000000010000 467316d4000000010000 00000000
[15/Jun/2007:19:44:26 -0400] - _cl5PositionCursorForReplay
(agmt="cn=AD-FDS" (asusis-dc:636)): Supplier RUV:
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): {replicageneration} 46707261000000030000
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): {replica 3 ldap://infra1.sis.personal.net.py:389}
46714c54000000030000 46730709000100030000 00000000
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): {replica 4 ldap://infra2.sis.personal.net.py:389}
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): {replica 1 ldap://infra1.sis.personal.net.py:389}
4673124f000000010000 46731f00000000010000 46731f01
[15/Jun/2007:19:44:26 -0400] agmt="cn=AD-FDS" (asusis-dc:636) - session
start: anchorcsn=467316d4000000010000
[15/Jun/2007:19:44:26 -0400] agmt="cn=AD-FDS" (asusis-dc:636) - Can't
locate CSN 467316d4000000010000 in the changelog (DB rc=-30990). The
consumer may need to be reinitialized.
[15/Jun/2007:19:44:26 -0400] agmt="cn=AD-FDS" (asusis-dc:636) -
clcache_load_buffer: rc=-30990
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - changelog program -
agmt="cn=AD-FDS" (asusis-dc:636): CSN 467316d4000000010000 found, position
set for replay
[15/Jun/2007:19:44:26 -0400] agmt="cn=AD-FDS" (asusis-dc:636) -
clcache_load_buffer: rc=-30990
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): No more updates to send (cl5GetNextOperationToReplay)
[15/Jun/2007:19:44:26 -0400] agmt="cn=AD-FDS" (asusis-dc:636) - session
end: state=0 load=0 sent=0 skipped=0
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): Beginning linger on the connection
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): State: sending_updates -> wait_for_changes
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): Linger timeout has expired on the connection
[15/Jun/2007:19:44:26 -0400] NSMMReplicationPlugin - agmt="cn=AD-FDS"
(asusis-dc:636): Disconnected from the consumer


This is when I create a new account in AD

[15/Jun/2007:19:58:55 -0400] conn=29 fd=73 slot=73 SSL connection from
10.129.4.176 to 172.20.0.1
[15/Jun/2007:19:58:55 -0400] conn=29 SSL 128-bit RC4
[15/Jun/2007:19:58:55 -0400] conn=29 op=0 BIND dn="cn=sync
manager,cn=config" method=128 version=2
[15/Jun/2007:19:58:55 -0400] conn=29 op=0 RESULT err=0 tag=97 nentries=0
etime=0 dn="cn=sync manager,cn=config"
[15/Jun/2007:19:58:55 -0400] conn=29 op=1 SRCH
base="ou=sso,dc=sis,dc=personal,dc=net,dc=py" scope=2
filter="(ntUserDomainId=pepelin)" attrs=ALL
[15/Jun/2007:19:58:55 -0400] conn=29 op=1 RESULT err=0 tag=101 nentries=0
etime=0
[15/Jun/2007:19:58:55 -0400] conn=29 op=2 UNBIND
[15/Jun/2007:19:58:55 -0400] conn=29 op=2 fd=73 closed - U1
[15/Jun/2007:19:59:00 -0400] conn=13 op=24 SRCH
base="ou=SSO,dc=sis,dc=personal,dc=net,dc=py" scope=1
filter="(objectClass=*)" attrs="objectClass"
[15/Jun/2007:19:59:00 -0400] conn=13 op=24 RESULT err=0 tag=101 nentries=1
etime=0
[15/Jun/2007:19:59:01 -0400] conn=13 op=26 SRCH
base="ou=sudoers,dc=sis,dc=personal,dc=net,dc=py" scope=0
filter="(objectClass=*)" attrs=ALL
[15/Jun/2007:19:59:01 -0400] conn=13 op=26 RESULT err=0 tag=101 nentries=1
etime=0
[15/Jun/2007:19:59:01 -0400] conn=13 op=27 SRCH
base="ou=SSO,dc=sis,dc=personal,dc=net,dc=py" scope=0
filter="(objectClass=*)" attrs=ALL
[15/Jun/2007:19:59:01 -0400] conn=13 op=27 RESULT err=0 tag=101 nentries=1
etime=0
[15/Jun/2007:19:59:01 -0400] conn=13 op=28 SRCH
base="ou=SSO,dc=sis,dc=personal,dc=net,dc=py" scope=1
filter="(objectClass=*)" attrs="objectClass"
[15/Jun/2007:19:59:01 -0400] conn=13 op=28 RESULT err=0 tag=101 nentries=1
etime=0
[15/Jun/2007:19:59:03 -0400] conn=13 op=29 SRCH
base="ou=SSO,dc=sis,dc=personal,dc=net,dc=py" scope=1
filter="(objectClass=*)" attrs="objectClass"
[15/Jun/2007:19:59:03 -0400] conn=13 op=29 RESULT err=0 tag=101 nentries=1
etime=0
[15/Jun/2007:19:59:11 -0400] conn=30 fd=73 slot=73 SSL connection from
10.129.4.176 to 172.20.0.1
[15/Jun/2007:19:59:11 -0400] conn=30 SSL 128-bit RC4
[15/Jun/2007:19:59:11 -0400] conn=30 op=0 BIND dn="cn=sync
manager,cn=config" method=128 version=2
[15/Jun/2007:19:59:11 -0400] conn=30 op=0 RESULT err=0 tag=97 nentries=0
etime=0 dn="cn=sync manager,cn=config"
[15/Jun/2007:19:59:11 -0400] conn=30 op=1 SRCH
base="ou=sso,dc=sis,dc=personal,dc=net,dc=py" scope=2
filter="(ntUserDomainId=pepelin)" attrs=ALL
[15/Jun/2007:19:59:11 -0400] conn=30 op=1 RESULT err=0 tag=101 nentries=0
etime=0
[15/Jun/2007:19:59:11 -0400] conn=30 op=2 UNBIND
[15/Jun/2007:19:59:11 -0400] conn=30 op=2 fd=73 closed - U1


And PassSync:

06/15/07 19:58:44: Password list has 1 entries
06/15/07 19:58:44: Attempting to sync password for pepelin
06/15/07 19:58:44: Searching for (ntuserdomainid=pepelin)
06/15/07 19:58:44: There are no entries that match: pepelin
06/15/07 19:58:44: Deferring password change for pepelin
06/15/07 19:58:44: Backing off for 4000ms
06/15/07 19:58:48: Backoff time expired.  Attempting sync
06/15/07 19:58:48: Password list has 1 entries
06/15/07 19:58:48: Attempting to sync password for pepelin
06/15/07 19:58:48: Searching for (ntuserdomainid=pepelin)
06/15/07 19:58:48: There are no entries that match: pepelin
06/15/07 19:58:48: Deferring password change for pepelin
06/15/07 19:58:48: Backing off for 8000ms
06/15/07 19:58:56: Backoff time expired.  Attempting sync
06/15/07 19:58:56: Password list has 1 entries
06/15/07 19:58:56: Attempting to sync password for pepelin
06/15/07 19:58:56: Searching for (ntuserdomainid=pepelin)
06/15/07 19:58:56: There are no entries that match: pepelin
06/15/07 19:58:56: Deferring password change for pepelin
06/15/07 19:58:56: Backing off for 16000ms
06/15/07 19:59:12: Backoff time expired.  Attempting sync
06/15/07 19:59:12: Password list has 1 entries
06/15/07 19:59:12: Attempting to sync password for pepelin
06/15/07 19:59:12: Searching for (ntuserdomainid=pepelin)
06/15/07 19:59:12: There are no entries that match: pepelin
06/15/07 19:59:12: Deferring password change for pepelin
06/15/07 19:59:12: Backing off for 32000ms
06/15/07 19:59:44: Backoff time expired.  Attempting sync
06/15/07 19:59:44: Password list has 1 entries
06/15/07 19:59:44: Attempting to sync password for pepelin
06/15/07 19:59:44: Searching for (ntuserdomainid=pepelin)
06/15/07 19:59:44: There are no entries that match: pepelin
06/15/07 19:59:44: Deferring password change for pepelin
06/15/07 19:59:44: Backing off for 64000ms


I don't see any attempt to create the accounts.

What could be the problem?
========================================================================================
AVISO LEGAL: Esta información es privada y confidencial y está dirigida
únicamente a su destinatario. Si usted no es el destinatario original de
este mensaje y por este medio pudo  acceder a dicha información por favor
elimine el mensaje. La distribución o copia de este mensaje está
estrictamente prohibida. Esta comunicación es sólo para  propósitos de
información y no debe ser considerada como propuesta, aceptación ni como
una declaración de voluntad oficial de NUCLEO S.A.  La transmisión de
e-mails no garantiza que el correo electrónico sea seguro o libre de error.
Por consiguiente, no manifestamos que esta información sea completa o
precisa.  Toda información está sujeta a alterarse sin previo aviso.

This information is private and confidential and intended for the recipient
only. If you are not the intended recipient of this message you are hereby
notified that any review,  dissemination, distribution or copying of this
message is strictly prohibited. This communication is for information
purposes only and shall not be regarded neither as a proposal,  acceptance
nor as a statement of will or official statement from NUCLEO S.A. . Email
transmission cannot be guaranteed to be secure or error-free. Therefore,
we do not represent that this information is complete or accurate and it
should not be relied upon as such. All information is subject to change
without notice.