Discussion:
389 <=> AD group sync
(too old to reply)
Matti Alho
2012-11-29 11:07:17 UTC
Permalink
Hi,

I'm testing group sync between 389ds and Microsoft AD. It works
otherwise, but incremental updates are not working. Any changes to
groups on 389 side do not get synced to AD unless I do a full manual
update triggered via console. Syncing users works normally. Would
someone have an idea why?

-Matti
Rich Megginson
2012-11-29 14:58:33 UTC
Permalink
Post by Matti Alho
Hi,
I'm testing group sync between 389ds and Microsoft AD. It works
otherwise, but incremental updates are not working. Any changes to
groups on 389 side do not get synced to AD unless I do a full manual
update triggered via console. Syncing users works normally. Would
someone have an idea why?
Can you be more specific? Can you provide your winsync config and an
example of what you are trying to do?
Post by Matti Alho
-Matti
--
389 users mailing list
389-users at lists.fedoraproject.org
https://admin.fedoraproject.org/mailman/listinfo/389-users
Matti Alho
2012-11-30 08:30:03 UTC
Permalink
Post by Rich Megginson
Post by Matti Alho
I'm testing group sync between 389ds and Microsoft AD. It works
otherwise, but incremental updates are not working. Any changes to
groups on 389 side do not get synced to AD unless I do a full manual
update triggered via console. Syncing users works normally. Would
someone have an idea why?
Can you be more specific? Can you provide your winsync config and an
example of what you are trying to do?
Ah sorry, here is an example of a group I'm trying to sync:

dn: cn=wingrouptemp,ou=People,dc=domain,dc=com
ntUniqueId: 9da16bd7236fb04285c419aefb9cb2a5
ntGroupCreateNewGroup: on
objectClass: top
objectClass: groupofuniquenames
objectClass: ntgroup
uniqueMember: uid=test1,ou=People,dc=domain,dc=com
uniqueMember: uid=test2,ou=People,dc=domain,dc=com
ntUserDomainId: wingrouptemp
cn: wingrouptemp

Sync agreement is set for ou=People,dc=domain,dc=com and has "New
Windows User Sync" and "New Windows Group Sync".

-Matti
Rich Megginson
2012-11-30 14:30:51 UTC
Permalink
Post by Matti Alho
Post by Rich Megginson
Post by Matti Alho
I'm testing group sync between 389ds and Microsoft AD. It works
otherwise, but incremental updates are not working. Any changes to
groups on 389 side do not get synced to AD unless I do a full manual
update triggered via console. Syncing users works normally. Would
someone have an idea why?
Can you be more specific? Can you provide your winsync config and an
example of what you are trying to do?
dn: cn=wingrouptemp,ou=People,dc=domain,dc=com
ntUniqueId: 9da16bd7236fb04285c419aefb9cb2a5
ntGroupCreateNewGroup: on
objectClass: top
objectClass: groupofuniquenames
objectClass: ntgroup
uniqueMember: uid=test1,ou=People,dc=domain,dc=com
uniqueMember: uid=test2,ou=People,dc=domain,dc=com
ntUserDomainId: wingrouptemp
cn: wingrouptemp
Sync agreement is set for ou=People,dc=domain,dc=com and has "New
Windows User Sync" and "New Windows Group Sync".
And what change are you making to this group that is not being sent to AD?
Post by Matti Alho
-Matti
--
389 users mailing list
389-users at lists.fedoraproject.org
https://admin.fedoraproject.org/mailman/listinfo/389-users
Matti Alho
2012-11-30 14:47:56 UTC
Permalink
Post by Rich Megginson
Post by Matti Alho
Post by Rich Megginson
Post by Matti Alho
I'm testing group sync between 389ds and Microsoft AD. It works
otherwise, but incremental updates are not working. Any changes to
groups on 389 side do not get synced to AD unless I do a full manual
update triggered via console. Syncing users works normally. Would
someone have an idea why?
Can you be more specific? Can you provide your winsync config and an
example of what you are trying to do?
dn: cn=wingrouptemp,ou=People,dc=domain,dc=com
ntUniqueId: 9da16bd7236fb04285c419aefb9cb2a5
ntGroupCreateNewGroup: on
objectClass: top
objectClass: groupofuniquenames
objectClass: ntgroup
uniqueMember: uid=test1,ou=People,dc=domain,dc=com
uniqueMember: uid=test2,ou=People,dc=domain,dc=com
ntUserDomainId: wingrouptemp
cn: wingrouptemp
Sync agreement is set for ou=People,dc=domain,dc=com and has "New
Windows User Sync" and "New Windows Group Sync".
And what change are you making to this group that is not being sent to AD?
The group itself or any changes. I mean if I create a group like that
via 389 console, it doesn't appear in AD unless I trigger a full sync.
Maybe I'm missing something obvious and/or simple?

PS. thanks for answering!

-Matti
Rich Megginson
2012-11-30 15:25:41 UTC
Permalink
Post by Matti Alho
Post by Rich Megginson
Post by Matti Alho
Post by Rich Megginson
Post by Matti Alho
I'm testing group sync between 389ds and Microsoft AD. It works
otherwise, but incremental updates are not working. Any changes to
groups on 389 side do not get synced to AD unless I do a full manual
update triggered via console. Syncing users works normally. Would
someone have an idea why?
Can you be more specific? Can you provide your winsync config and an
example of what you are trying to do?
dn: cn=wingrouptemp,ou=People,dc=domain,dc=com
ntUniqueId: 9da16bd7236fb04285c419aefb9cb2a5
ntGroupCreateNewGroup: on
objectClass: top
objectClass: groupofuniquenames
objectClass: ntgroup
uniqueMember: uid=test1,ou=People,dc=domain,dc=com
uniqueMember: uid=test2,ou=People,dc=domain,dc=com
ntUserDomainId: wingrouptemp
cn: wingrouptemp
Sync agreement is set for ou=People,dc=domain,dc=com and has "New
Windows User Sync" and "New Windows Group Sync".
And what change are you making to this group that is not being sent to AD?
The group itself or any changes.
So adding the group entry? Or changing the membership?
Post by Matti Alho
I mean if I create a group like that via 389 console, it doesn't
appear in AD unless I trigger a full sync. Maybe I'm missing something
obvious and/or simple?
I don't know. Looks ok to me. I guess the next step would be to
reproduce the problem with the
http://port389.org/wiki/FAQ#Troubleshooting Replication log level
enabled, and then look in the errors log to see why the group add
operation is not being sent to AD.
Post by Matti Alho
PS. thanks for answering!
-Matti
--
389 users mailing list
389-users at lists.fedoraproject.org
https://admin.fedoraproject.org/mailman/listinfo/389-users
Matti Alho
2012-12-03 07:00:14 UTC
Permalink
Post by Rich Megginson
I don't know. Looks ok to me. I guess the next step would be to
reproduce the problem with the
http://port389.org/wiki/FAQ#Troubleshooting Replication log level
enabled, and then look in the errors log to see why the group add
operation is not being sent to AD.
Here are some relevant log entries with replication logging. Any ideas
or should I try to change log level to get more information?

[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Looking at modify operation local
dn="cn=testgroup,ou=People,dc=domain,dc=com" (ours,not user,group)

[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=testgroup,ou=People,dc=domain,dc=com" guid="(null)"

[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=testgroup,ou=People,dc=domain,dc=com" username="testgroup"

[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: entry not found - rc 0

[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Processing modify operation local
dn="cn=testgroup,ou=People,dc=domain,dc=com" remote
dn="cn=testgroup,cn=Users,dc=domain,dc=com"

[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): mod_already_made: AD entry not found

[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Received result code 32 (0000208D: NameErr: DSID-0310020A,
problem 2001 (NO_OBJECT), data 0, best match of:
'CN=Users,dc=domain,dc=com' ) for modify operation

[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Consumer failed to replay change (uniqueid
b469a981-3d1411e2-9418a8cb-3212cedb, CSN 50bc4a4d000000010000): No such
object. Skipping.

[03/Dec/2012:08:44:28 +0200] agmt="cn=winsync" (adtest:636) -
clcache_load_buffer: rc=-30988

[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No more updates to send (cl5GetNextOperationToReplay)

[03/Dec/2012:08:44:28 +0200] agmt="cn=winsync" (adtest:636) - session
end: state=5 load=1 sent=1 skipped=0

[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Beginning linger on the connection

[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: sending_updates -> wait_for_changes

[03/Dec/2012:08:45:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Linger timeout has expired on the connection

[03/Dec/2012:08:45:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Disconnected from the consumer

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: wait_for_changes -> wait_for_changes

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: wait_for_changes -> ready_to_acquire_replica

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Trying secure slapi_ldap_init_ext

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): binddn = cn=replication manager,cn=Users,dc=domain,dc=com,

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Replication bind with SIMPLE auth resumed

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No linger to cancel on the connection

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: ready_to_acquire_replica -> sending_updates

[03/Dec/2012:08:48:11 +0200] - _cl5PositionCursorForReplay
(agmt="cn=winsync" (adtest:636)): Consumer RUV:

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replicageneration} 505ae68e000000010000

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 1 ldap://ldap1.domain.com:389}
505aedad000000010000 50bc4a4d000000010000 50bc4a4c

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 2 ldap://ldap2.domain.com:389}

[03/Dec/2012:08:48:11 +0200] - _cl5PositionCursorForReplay
(agmt="cn=winsync" (adtest:636)): Supplier RUV:

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replicageneration} 505ae68e000000010000

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 1 ldap://ldap1.domain.com:389}
505aedad000000010000 50bc4a4d000000010000 50bc4a4c

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 2 ldap://ldap2.domain.com:389}

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No changes to send

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: looking for local entry matching AD
entry [CN=Administrator,CN=Users,dc=domain,dc=com]

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: looking for local entry by guid
[f9230130d24b3f43b352e77459982c77]

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: problem looking for guid: -1

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: AD entry has no username!

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: looking for local entry matching AD
entry [CN=Administrator,CN=Users,dc=domain,dc=com]

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: looking for local entry by guid
[f9230130d24b3f43b352e77459982c77]

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: problem looking for guid: -1

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: looking for local entry by uid
[Administrator]

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: problem looking for username: -1

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Beginning linger on the connection

[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: sending_updates -> wait_for_changes

[03/Dec/2012:08:49:12 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Linger timeout has expired on the connection

-Matti
Rich Megginson
2012-12-03 20:20:03 UTC
Permalink
Post by Matti Alho
Post by Rich Megginson
I don't know. Looks ok to me. I guess the next step would be to
reproduce the problem with the
http://port389.org/wiki/FAQ#Troubleshooting Replication log level
enabled, and then look in the errors log to see why the group add
operation is not being sent to AD.
Here are some relevant log entries with replication logging. Any ideas
or should I try to change log level to get more information?
Not sure. This looks as though it is attempting to replay a modify
operation made on the 389 entry cn=testgroup,ou=People,dc=domain,dc=com,
but the corresponding AD entry cn=testgroup,cn=Users,dc=domain,dc=com
does not exist. Did the full manual update create the entry
cn=testgroup,cn=Users,dc=domain,dc=com in AD? If not, why not? In your
first message you said
Post by Matti Alho
/Any changes to// groups on 389 side do not get synced to AD unless I do a full manual// update triggered via console/
Can you verify that, after doing a full manual update, you have
cn=testgroup,ou=People,dc=domain,dc=com in 389 and
cn=testgroup,cn=Users,dc=domain,dc=com in AD?
Post by Matti Alho
[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Looking at modify operation local
dn="cn=testgroup,ou=People,dc=domain,dc=com" (ours,not user,group)
[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=testgroup,ou=People,dc=domain,dc=com" guid="(null)"
[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=testgroup,ou=People,dc=domain,dc=com" username="testgroup"
[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: entry not found - rc 0
[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Processing modify operation local
dn="cn=testgroup,ou=People,dc=domain,dc=com" remote
dn="cn=testgroup,cn=Users,dc=domain,dc=com"
[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): mod_already_made: AD entry not found
[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
'CN=Users,dc=domain,dc=com' ) for modify operation
[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Consumer failed to replay change (uniqueid
b469a981-3d1411e2-9418a8cb-3212cedb, CSN 50bc4a4d000000010000): No
such object. Skipping.
[03/Dec/2012:08:44:28 +0200] agmt="cn=winsync" (adtest:636) -
clcache_load_buffer: rc=-30988
[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No more updates to send (cl5GetNextOperationToReplay)
[03/Dec/2012:08:44:28 +0200] agmt="cn=winsync" (adtest:636) - session
end: state=5 load=1 sent=1 skipped=0
[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Beginning linger on the connection
[03/Dec/2012:08:44:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: sending_updates -> wait_for_changes
[03/Dec/2012:08:45:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Linger timeout has expired on the connection
[03/Dec/2012:08:45:28 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Disconnected from the consumer
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: wait_for_changes -> wait_for_changes
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: wait_for_changes -> ready_to_acquire_replica
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Trying secure slapi_ldap_init_ext
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): binddn = cn=replication manager,cn=Users,dc=domain,dc=com,
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Replication bind with SIMPLE auth resumed
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No linger to cancel on the connection
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: ready_to_acquire_replica -> sending_updates
[03/Dec/2012:08:48:11 +0200] - _cl5PositionCursorForReplay
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replicageneration} 505ae68e000000010000
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 1 ldap://ldap1.domain.com:389}
505aedad000000010000 50bc4a4d000000010000 50bc4a4c
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 2 ldap://ldap2.domain.com:389}
[03/Dec/2012:08:48:11 +0200] - _cl5PositionCursorForReplay
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replicageneration} 505ae68e000000010000
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 1 ldap://ldap1.domain.com:389}
505aedad000000010000 50bc4a4d000000010000 50bc4a4c
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 2 ldap://ldap2.domain.com:389}
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No changes to send
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: looking for local entry matching
AD entry [CN=Administrator,CN=Users,dc=domain,dc=com]
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: looking for local entry by guid
[f9230130d24b3f43b352e77459982c77]
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: problem looking for guid: -1
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: AD entry has no username!
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: looking for local entry matching
AD entry [CN=Administrator,CN=Users,dc=domain,dc=com]
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: looking for local entry by guid
[f9230130d24b3f43b352e77459982c77]
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: problem looking for guid: -1
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: looking for local entry by uid
[Administrator]
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_inbound: problem looking for username: -1
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Beginning linger on the connection
[03/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: sending_updates -> wait_for_changes
[03/Dec/2012:08:49:12 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Linger timeout has expired on the connection
-Matti
--
389 users mailing list
389-users at lists.fedoraproject.org
https://admin.fedoraproject.org/mailman/listinfo/389-users
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.fedoraproject.org/pipermail/389-users/attachments/20121203/54f45bc4/attachment.html>
Matti Alho
2012-12-07 10:11:15 UTC
Permalink
Post by Rich Megginson
Post by Matti Alho
Post by Rich Megginson
I don't know. Looks ok to me. I guess the next step would be to
reproduce the problem with the
http://port389.org/wiki/FAQ#Troubleshooting Replication log level
enabled, and then look in the errors log to see why the group add
operation is not being sent to AD.
Here are some relevant log entries with replication logging. Any ideas
or should I try to change log level to get more information?
Not sure. This looks as though it is attempting to replay a modify
operation made on the 389 entry cn=testgroup,ou=People,dc=domain,dc=com,
but the corresponding AD entry cn=testgroup,cn=Users,dc=domain,dc=com
does not exist. Did the full manual update create the entry
cn=testgroup,cn=Users,dc=domain,dc=com in AD? If not, why not? In your
first message you said
Post by Matti Alho
/Any changes to// groups on 389 side do not get synced to AD unless I do a full manual// update triggered via console/
Can you verify that, after doing a full manual update, you have
cn=testgroup,ou=People,dc=domain,dc=com in 389 and
cn=testgroup,cn=Users,dc=domain,dc=com in AD?
Yes after a full manual update entry appears in AD.

Here are log entries after I add another entry and before I do a full
update.

I noticed this:
dn="cn=stilltesting,cn=Users,dc=domain,dc=com" (not present,add not allowed)

What could cause that? Some AD permissions? It's a bit weird since full
update works.


[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - changelog program -
agmt="cn=winsync" (adtest:636): CSN 50c1ba8c000000010000 found, position
set for replay

[07/Dec/2012:12:02:46 +0200] agmt="cn=winsync" (adtest:636) - load=1
rec=1 csn=50c1bec7000000010000

[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Looking at add operation local
dn="cn=stilltesting,ou=People,dc=domain,dc=com" (ours,not user,group)

[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=stilltesting,ou=People,dc=domain,dc=com" guid="(null)"

[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=stilltesting,ou=People,dc=domain,dc=com" username="stilltesting"

[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: entry not found - rc 0

[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Processing add operation local
dn="cn=stilltesting,ou=People,dc=domain,dc=com" remote
dn="cn=stilltesting,cn=Users,dc=domain,dc=com"

[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): process_replay_add:
dn="cn=stilltesting,cn=Users,dc=domain,dc=com" (not present,add not allowed)

[07/Dec/2012:12:02:46 +0200] agmt="cn=winsync" (adtest:636) -
clcache_load_buffer: rc=-30988

[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No more updates to send (cl5GetNextOperationToReplay)

[07/Dec/2012:12:02:46 +0200] agmt="cn=winsync" (adtest:636) - session
end: state=5 load=1 sent=1 skipped=0

[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Beginning linger on the connection

[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: sending_updates -> wait_for_changes

[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: wait_for_changes -> wait_for_changes

[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: wait_for_changes -> ready_to_acquire_replica

[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Cancelling linger on the connection

[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: ready_to_acquire_replica -> sending_updates

[07/Dec/2012:12:03:11 +0200] - _cl5PositionCursorForReplay
(agmt="cn=winsync" (adtest:636)): Consumer RUV:

[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replicageneration} 505ae68e000000010000

[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 1 ldap://ldapnew.domain.com:389}
505aedad000000010000 50c1bec7000000010000 50c1bec6

[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 2 ldap://ldapnew2.domain.com:389}

[07/Dec/2012:12:03:11 +0200] - _cl5PositionCursorForReplay
(agmt="cn=winsync" (adtest:636)): Supplier RUV:

[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replicageneration} 505ae68e000000010000

[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 1 ldap://ldapnew.domain.com:389}
505aedad000000010000 50c1bec7000000010000 50c1bec6

[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 2 ldap://ldapnew2.domain.com:389}

[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No changes to send

[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Beginning linger on the connection

[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: sending_updates -> wait_for_changes

-Matti
Rich Megginson
2012-12-07 19:09:36 UTC
Permalink
Post by Matti Alho
Post by Rich Megginson
Post by Matti Alho
Post by Rich Megginson
I don't know. Looks ok to me. I guess the next step would be to
reproduce the problem with the
http://port389.org/wiki/FAQ#Troubleshooting Replication log level
enabled, and then look in the errors log to see why the group add
operation is not being sent to AD.
Here are some relevant log entries with replication logging. Any ideas
or should I try to change log level to get more information?
Not sure. This looks as though it is attempting to replay a modify
operation made on the 389 entry cn=testgroup,ou=People,dc=domain,dc=com,
but the corresponding AD entry cn=testgroup,cn=Users,dc=domain,dc=com
does not exist. Did the full manual update create the entry
cn=testgroup,cn=Users,dc=domain,dc=com in AD? If not, why not? In your
first message you said
Post by Matti Alho
/Any changes to// groups on 389 side do not get synced to AD unless
I do a full manual// update triggered via console/
Can you verify that, after doing a full manual update, you have
cn=testgroup,ou=People,dc=domain,dc=com in 389 and
cn=testgroup,cn=Users,dc=domain,dc=com in AD?
Yes after a full manual update entry appears in AD.
Here are log entries after I add another entry and before I do a full
update.
dn="cn=stilltesting,cn=Users,dc=domain,dc=com" (not present,add not allowed)
What could cause that? Some AD permissions? It's a bit weird since
full update works.
https://access.redhat.com/knowledge/docs/en-US/Red_Hat_Directory_Server/9.0/html/Administration_Guide/Using_Windows_Sync-Synchronizing_Groups.html

Does cn=stilltesting,cn=Users,dc=domain,dc=com have
ntGroupCreateNewGroup: TRUE

?
Post by Matti Alho
[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - changelog program
- agmt="cn=winsync" (adtest:636): CSN 50c1ba8c000000010000 found,
position set for replay
[07/Dec/2012:12:02:46 +0200] agmt="cn=winsync" (adtest:636) - load=1
rec=1 csn=50c1bec7000000010000
[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Looking at add operation local
dn="cn=stilltesting,ou=People,dc=domain,dc=com" (ours,not user,group)
[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=stilltesting,ou=People,dc=domain,dc=com" guid="(null)"
[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=stilltesting,ou=People,dc=domain,dc=com" username="stilltesting"
[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: entry not found - rc 0
[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Processing add operation local
dn="cn=stilltesting,ou=People,dc=domain,dc=com" remote
dn="cn=stilltesting,cn=Users,dc=domain,dc=com"
[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
dn="cn=stilltesting,cn=Users,dc=domain,dc=com" (not present,add not allowed)
[07/Dec/2012:12:02:46 +0200] agmt="cn=winsync" (adtest:636) -
clcache_load_buffer: rc=-30988
[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No more updates to send (cl5GetNextOperationToReplay)
[07/Dec/2012:12:02:46 +0200] agmt="cn=winsync" (adtest:636) - session
end: state=5 load=1 sent=1 skipped=0
[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Beginning linger on the connection
[07/Dec/2012:12:02:46 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: sending_updates -> wait_for_changes
[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: wait_for_changes -> wait_for_changes
[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: wait_for_changes -> ready_to_acquire_replica
[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Cancelling linger on the connection
[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: ready_to_acquire_replica -> sending_updates
[07/Dec/2012:12:03:11 +0200] - _cl5PositionCursorForReplay
[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replicageneration} 505ae68e000000010000
[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 1 ldap://ldapnew.domain.com:389}
505aedad000000010000 50c1bec7000000010000 50c1bec6
[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 2 ldap://ldapnew2.domain.com:389}
[07/Dec/2012:12:03:11 +0200] - _cl5PositionCursorForReplay
[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replicageneration} 505ae68e000000010000
[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 1 ldap://ldapnew.domain.com:389}
505aedad000000010000 50c1bec7000000010000 50c1bec6
[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 2 ldap://ldapnew2.domain.com:389}
[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No changes to send
[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Beginning linger on the connection
[07/Dec/2012:12:03:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: sending_updates -> wait_for_changes
-Matti
--
389 users mailing list
389-users at lists.fedoraproject.org
https://admin.fedoraproject.org/mailman/listinfo/389-users
Matti Alho
2012-12-10 07:21:18 UTC
Permalink
Post by Rich Megginson
Post by Matti Alho
dn="cn=stilltesting,cn=Users,dc=domain,dc=com" (not present,add not allowed)
What could cause that? Some AD permissions? It's a bit weird since
full update works.
https://access.redhat.com/knowledge/docs/en-US/Red_Hat_Directory_Server/9.0/html/Administration_Guide/Using_Windows_Sync-Synchronizing_Groups.html
Does cn=stilltesting,cn=Users,dc=domain,dc=com have
ntGroupCreateNewGroup: TRUE
Yes, below is the entry. And actually in the guide you linked
ntGroupCreateNewGroup value is "on" in the console section and "true" in
command line section. I guess both are okay. I did try both values.

dn: cn=stilltesting,ou=People,dc=domain,dc=com
ntGroupCreateNewGroup: true
description: stilltesting
objectClass: top
objectClass: groupofuniquenames
objectClass: ntgroup
uniqueMember: uid=btab,ou=People,dc=domain,dc=com
ntUserDomainId: stilltesting
cn: stilltesting

Logs after incremental update (which doesn't work):

[10/Dec/2012:08:45:34 +0200] agmt="cn=winsync" (adtest:636) - session
start: anchorcsn=50c1bec7000000010000
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - changelog program -
agmt="cn=winsync" (adtest:636): CSN 50c1bec7000000010000 found, position
set for replay
[10/Dec/2012:08:45:34 +0200] agmt="cn=winsync" (adtest:636) - load=1
rec=1 csn=50c5850f000000010000
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Looking at modify operation local
dn="cn=stilltesting,ou=People,dc=domain,dc=com" (ours,not user,group)
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=stilltesting,ou=People,dc=domain,dc=com" guid="(null)"
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=stilltesting,ou=People,dc=domain,dc=com" username="stilltesting"
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: entry not found - rc 0
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Processing modify operation local
dn="cn=stilltesting,ou=People,dc=domain,dc=com" remote
dn="cn=stilltesting,cn=Users,dc=domain,dc=com"
[10/Dec/2012:08:45:34 +0200] agmt="cn=winsync" (adtest:636) -
clcache_load_buffer: rc=-30988
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No more updates to send (cl5GetNextOperationToReplay)
[10/Dec/2012:08:45:34 +0200] agmt="cn=winsync" (adtest:636) - session
end: state=5 load=1 sent=1 skipped=0
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Beginning linger on the connection
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: sending_updates -> wait_for_changes
[10/Dec/2012:08:46:35 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Linger timeout has expired on the connection
[10/Dec/2012:08:46:35 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Disconnected from the consumer
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: wait_for_changes -> wait_for_changes
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: wait_for_changes -> ready_to_acquire_replica
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Trying secure slapi_ldap_init_ext
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): binddn = cn=replication manager,cn=Users,dc=domain,dc=com,
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No linger to cancel on the connection
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: ready_to_acquire_replica -> sending_updates
[10/Dec/2012:08:48:11 +0200] - _cl5PositionCursorForReplay
(agmt="cn=winsync" (adtest:636)): Consumer RUV:
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replicageneration} 505ae68e000000010000
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 1 ldap://ldapnew.domain.com:389}
505aedad000000010000 50c5850f000000010000 50c5850e
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 2 ldap://ldapnew2.domain.com:389}
[10/Dec/2012:08:48:11 +0200] - _cl5PositionCursorForReplay
(agmt="cn=winsync" (adtest:636)): Supplier RUV:
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replicageneration} 505ae68e000000010000
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 1 ldap://ldapnew.domain.com:389}
505aedad000000010000 50c5850f000000010000 50c5850e
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 2 ldap://ldapnew2.domain.com:389}
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No changes to send


Logs after full manual update (which works):

[10/Dec/2012:09:12:47 +0200] agmt="cn=winsync" (adtest:636) - load=1
rec=1 csn=50c58b70000000010000
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Looking at rename operation local
dn="cn=stilltesting,ou=People,dc=domain,dc=com" (ours,not user,group)
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=stilltesting-group,ou=People,dc=domain,dc=com"
guid="52dfaf022d5e4b49b8f7899f9e4b5c87"
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: return code 0 from search for AD
entry dn="<GUID=52dfaf022d5e4b49b8f7899f9e4b5c87>" or
dn="CN=stilltesting,CN=Users,dc=domain,dc=com"
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Processing rename operation local
dn="cn=stilltesting,ou=People,dc=domain,dc=com" remote
dn="<GUID=52dfaf022d5e4b49b8f7899f9e4b5c87>"
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Consumer failed to replay change (uniqueid
2adc1381-405511e2-9418a8cb-3212cedb, CSN 50c58b70000000010000): Success.
Skipping.
[10/Dec/2012:09:12:47 +0200] agmt="cn=winsync" (adtest:636) - load=1
rec=2 csn=50c58b70000200010000
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Looking at modify operation local
dn="cn=stilltesting-group,ou=People,dc=domain,dc=com" (ours,not user,group)
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=stilltesting-group,ou=People,dc=domain,dc=com"
guid="52dfaf022d5e4b49b8f7899f9e4b5c87"
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: return code 0 from search for AD
entry dn="<GUID=52dfaf022d5e4b49b8f7899f9e4b5c87>" or
dn="CN=stilltesting,CN=Users,dc=domain,dc=com"
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Processing modify operation local
dn="cn=stilltesting-group,ou=People,dc=domain,dc=com" remote
dn="<GUID=52dfaf022d5e4b49b8f7899f9e4b5c87>"
[10/Dec/2012:09:12:47 +0200] agmt="cn=winsync" (adtest:636) -
clcache_load_buffer: rc=-30988
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No more updates to send (cl5GetNextOperationToReplay)
[10/Dec/2012:09:12:47 +0200] agmt="cn=winsync" (adtest:636) - session
end: state=5 load=1 sent=2 skipped=0
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Beginning linger on the connection
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: sending_updates -> wait_for_changes
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: wait_for_changes -> wait_for_changes
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: wait_for_changes -> ready_to_acquire_replica
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Cancelling linger on the connection
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: ready_to_acquire_replica -> sending_updates
[10/Dec/2012:09:13:11 +0200] - _cl5PositionCursorForReplay
(agmt="cn=winsync" (adtest:636)): Consumer RUV:
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replicageneration} 505ae68e000000010000
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 1 ldap://ldapnew.domain.com:389}
505aedad000000010000 50c58b70000200010000 50c58b6f
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 2 ldap://ldapnew2.domain.com:389}
[10/Dec/2012:09:13:11 +0200] - _cl5PositionCursorForReplay
(agmt="cn=winsync" (adtest:636)): Supplier RUV:
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replicageneration} 505ae68e000000010000
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 1 ldap://ldapnew.domain.com:389}
505aedad000000010000 50c58b70000200010000 50c58b6f
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 2 ldap://ldapnew2.domain.com:389}
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No changes to send
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Beginning linger on the connection
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: sending_updates -> wait_for_changes

-Matti
Rich Megginson
2012-12-10 22:55:18 UTC
Permalink
Post by Matti Alho
Post by Rich Megginson
Post by Matti Alho
dn="cn=stilltesting,cn=Users,dc=domain,dc=com" (not present,add not allowed)
What could cause that? Some AD permissions? It's a bit weird since
full update works.
https://access.redhat.com/knowledge/docs/en-US/Red_Hat_Directory_Server/9.0/html/Administration_Guide/Using_Windows_Sync-Synchronizing_Groups.html
Does cn=stilltesting,cn=Users,dc=domain,dc=com have
ntGroupCreateNewGroup: TRUE
Yes, below is the entry. And actually in the guide you linked
ntGroupCreateNewGroup value is "on" in the console section and "true"
in command line section. I guess both are okay. I did try both values.
dn: cn=stilltesting,ou=People,dc=domain,dc=com
ntGroupCreateNewGroup: true
description: stilltesting
objectClass: top
objectClass: groupofuniquenames
objectClass: ntgroup
uniqueMember: uid=btab,ou=People,dc=domain,dc=com
ntUserDomainId: stilltesting
cn: stilltesting
[10/Dec/2012:08:45:34 +0200] agmt="cn=winsync" (adtest:636) - session
start: anchorcsn=50c1bec7000000010000
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - changelog program
- agmt="cn=winsync" (adtest:636): CSN 50c1bec7000000010000 found,
position set for replay
[10/Dec/2012:08:45:34 +0200] agmt="cn=winsync" (adtest:636) - load=1
rec=1 csn=50c5850f000000010000
start
Post by Matti Alho
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Looking at modify operation local
dn="cn=stilltesting,ou=People,dc=domain,dc=com" (ours,not user,group)
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=stilltesting,ou=People,dc=domain,dc=com" guid="(null)"
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=stilltesting,ou=People,dc=domain,dc=com" username="stilltesting"
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: entry not found - rc 0
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Processing modify operation local
dn="cn=stilltesting,ou=People,dc=domain,dc=com" remote
dn="cn=stilltesting,cn=Users,dc=domain,dc=com"
This sequence looks like it is attempting to replay a modify operation
on the DS entry cn=stilltesting,ou=People,dc=domain,dc=com but it cannot
find the corresponding AD entry. So the operation fails.
Post by Matti Alho
[10/Dec/2012:08:45:34 +0200] agmt="cn=winsync" (adtest:636) -
clcache_load_buffer: rc=-30988
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No more updates to send (cl5GetNextOperationToReplay)
[10/Dec/2012:08:45:34 +0200] agmt="cn=winsync" (adtest:636) - session
end: state=5 load=1 sent=1 skipped=0
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Beginning linger on the connection
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: sending_updates -> wait_for_changes
[10/Dec/2012:08:46:35 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Linger timeout has expired on the connection
[10/Dec/2012:08:46:35 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Disconnected from the consumer
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: wait_for_changes -> wait_for_changes
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: wait_for_changes -> ready_to_acquire_replica
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Trying secure slapi_ldap_init_ext
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): binddn = cn=replication manager,cn=Users,dc=domain,dc=com,
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No linger to cancel on the connection
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: ready_to_acquire_replica -> sending_updates
[10/Dec/2012:08:48:11 +0200] - _cl5PositionCursorForReplay
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replicageneration} 505ae68e000000010000
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 1 ldap://ldapnew.domain.com:389}
505aedad000000010000 50c5850f000000010000 50c5850e
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 2 ldap://ldapnew2.domain.com:389}
[10/Dec/2012:08:48:11 +0200] - _cl5PositionCursorForReplay
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replicageneration} 505ae68e000000010000
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 1 ldap://ldapnew.domain.com:389}
505aedad000000010000 50c5850f000000010000 50c5850e
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 2 ldap://ldapnew2.domain.com:389}
[10/Dec/2012:08:48:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No changes to send
[10/Dec/2012:09:12:47 +0200] agmt="cn=winsync" (adtest:636) - load=1
rec=1 csn=50c58b70000000010000
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Looking at rename operation local
dn="cn=stilltesting,ou=People,dc=domain,dc=com" (ours,not user,group)
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=stilltesting-group,ou=People,dc=domain,dc=com"
guid="52dfaf022d5e4b49b8f7899f9e4b5c87"
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: return code 0 from search for AD
entry dn="<GUID=52dfaf022d5e4b49b8f7899f9e4b5c87>" or
dn="CN=stilltesting,CN=Users,dc=domain,dc=com"
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Processing rename operation local
dn="cn=stilltesting,ou=People,dc=domain,dc=com" remote
dn="<GUID=52dfaf022d5e4b49b8f7899f9e4b5c87>"
winsync doesn't replay simple entry name change operations since the DS
and AD entries use a different naming scheme
Post by Matti Alho
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Consumer failed to replay change (uniqueid
Success. Skipping.
[10/Dec/2012:09:12:47 +0200] agmt="cn=winsync" (adtest:636) - load=1
rec=2 csn=50c58b70000200010000
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Looking at modify operation local
dn="cn=stilltesting-group,ou=People,dc=domain,dc=com" (ours,not user,group)
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=stilltesting-group,ou=People,dc=domain,dc=com"
guid="52dfaf022d5e4b49b8f7899f9e4b5c87"
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: return code 0 from search for AD
entry dn="<GUID=52dfaf022d5e4b49b8f7899f9e4b5c87>" or
dn="CN=stilltesting,CN=Users,dc=domain,dc=com"
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Processing modify operation local
dn="cn=stilltesting-group,ou=People,dc=domain,dc=com" remote
dn="<GUID=52dfaf022d5e4b49b8f7899f9e4b5c87>"
This looks like there were no mods to send, otherwise, it would have
printed the list of modifications.
Post by Matti Alho
[10/Dec/2012:09:12:47 +0200] agmt="cn=winsync" (adtest:636) -
clcache_load_buffer: rc=-30988
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No more updates to send (cl5GetNextOperationToReplay)
[10/Dec/2012:09:12:47 +0200] agmt="cn=winsync" (adtest:636) - session
end: state=5 load=1 sent=2 skipped=0
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Beginning linger on the connection
[10/Dec/2012:09:12:47 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: sending_updates -> wait_for_changes
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: wait_for_changes -> wait_for_changes
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: wait_for_changes -> ready_to_acquire_replica
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Cancelling linger on the connection
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: ready_to_acquire_replica -> sending_updates
[10/Dec/2012:09:13:11 +0200] - _cl5PositionCursorForReplay
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replicageneration} 505ae68e000000010000
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 1 ldap://ldapnew.domain.com:389}
505aedad000000010000 50c58b70000200010000 50c58b6f
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 2 ldap://ldapnew2.domain.com:389}
[10/Dec/2012:09:13:11 +0200] - _cl5PositionCursorForReplay
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replicageneration} 505ae68e000000010000
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 1 ldap://ldapnew.domain.com:389}
505aedad000000010000 50c58b70000200010000 50c58b6f
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): {replica 2 ldap://ldapnew2.domain.com:389}
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): No changes to send
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): Beginning linger on the connection
[10/Dec/2012:09:13:11 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): State: sending_updates -> wait_for_changes
-Matti
--
389 users mailing list
389-users at lists.fedoraproject.org
https://admin.fedoraproject.org/mailman/listinfo/389-users
Matti Alho
2012-12-11 10:51:50 UTC
Permalink
Post by Rich Megginson
Post by Matti Alho
dn: cn=stilltesting,ou=People,dc=domain,dc=com
ntGroupCreateNewGroup: true
description: stilltesting
objectClass: top
objectClass: groupofuniquenames
objectClass: ntgroup
uniqueMember: uid=btab,ou=People,dc=domain,dc=com
ntUserDomainId: stilltesting
cn: stilltesting
[10/Dec/2012:08:45:34 +0200] agmt="cn=winsync" (adtest:636) - session
start: anchorcsn=50c1bec7000000010000
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - changelog program
- agmt="cn=winsync" (adtest:636): CSN 50c1bec7000000010000 found,
position set for replay
[10/Dec/2012:08:45:34 +0200] agmt="cn=winsync" (adtest:636) - load=1
rec=1 csn=50c5850f000000010000
start
Post by Matti Alho
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Looking at modify operation local
dn="cn=stilltesting,ou=People,dc=domain,dc=com" (ours,not user,group)
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=stilltesting,ou=People,dc=domain,dc=com" guid="(null)"
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: looking for AD entry for DS
dn="cn=stilltesting,ou=People,dc=domain,dc=com" username="stilltesting"
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): map_entry_dn_outbound: entry not found - rc 0
[10/Dec/2012:08:45:34 +0200] NSMMReplicationPlugin - agmt="cn=winsync"
(adtest:636): windows_replay_update: Processing modify operation local
dn="cn=stilltesting,ou=People,dc=domain,dc=com" remote
dn="cn=stilltesting,cn=Users,dc=domain,dc=com"
This sequence looks like it is attempting to replay a modify operation
on the DS entry cn=stilltesting,ou=People,dc=domain,dc=com but it cannot
find the corresponding AD entry. So the operation fails.
So any ideas why it's not adding the entry with incremental update?

I guess I need to reproduce this problem with a clean install. Maybe I
notice some simple configuration mistake or file a bug report.

Thanks for helping out anyways!

-Matti

Josh Ellsworth
2012-12-10 16:57:25 UTC
Permalink
We recently rolled out a replacement 389 environment to replace a pair that had gotten corrupted. Ever since we put the new ones in place we have had issues with the server not listening to new requests due to too many open file descriptors. The max is set to 8192 and it gets to that point in about a week.

What can I do to get rid of this problem? It seems we had something like this happen before, but that was an nslcd issue on the clients. The clients config has not changed.

Josh
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.fedoraproject.org/pipermail/389-users/attachments/20121210/ab83af83/attachment.html>
Rich Megginson
2012-12-10 22:45:21 UTC
Permalink
Post by Josh Ellsworth
We recently rolled out a replacement 389 environment to replace a pair
that had gotten corrupted. Ever since we put the new ones in place we
have had issues with the server not listening to new requests due to
too many open file descriptors. The max is set to 8192 and it gets to
that point in about a week.
What can I do to get rid of this problem? It seems we had something
like this happen before, but that was an nslcd issue on the clients.
The clients config has not changed.
What are the clients that are issuing requests and not closing
connections? nslcd? pam ldap?
Post by Josh Ellsworth
Josh
--
389 users mailing list
389-users at lists.fedoraproject.org
https://admin.fedoraproject.org/mailman/listinfo/389-users
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.fedoraproject.org/pipermail/389-users/attachments/20121210/7b498483/attachment.html>
Continue reading on narkive:
Loading...