Grouper Users - Open Discussion List

[Dominique Petitpierre <>]

Hello,

thanks for the suggestion!

On 18.09.20 19:32, Jeffrey Williams wrote:

What do you have ldap.groupLdap1.pagedResultsSize set to?

ldap.groupLdap1.pagedResultsSize  was not set, but setting it to 1000 or 100 did not change the symptoms: The LDAP error ENTRY_ALREADY_EXISTS still occurs.

The effective settings and relevant logs are in annexe below.

I am perlexed:

- why is Jira issue GRP-2343 considered minor?  The problem described seems serious: synchronization does not work.
This might be the same problem: the message logs in the description are similar to the ones in Annex.

- Any other ideas or pointers to tackle this issue are welcome!

Regards.

Annex: effective settings and relevant logs




dn: CN=Default Query Policy,CN=Query-Policies,CN=Directory Service,CN=Windows NT,CN=Services,CN=Configuration,DC=isis-klif,DC=unige,DC=ch
lDAPAdminLimits: MaxValRange=1500
lDAPAdminLimits: MaxPageSize=1000





grep -a '^2020-09-18 22:3.*Setting up LDAP Connection with properties:' grouper_error.log|tail -1 |sed -e 's/[:,] /&\n/g' |sed -E -n -e 's/(url|bindDn|ldapUrl|user|pass)=.*,/\1=***,/g' -e /=/p
{org.ldaptive.pass=***,
org.ldaptive.url="***,"
org.ldaptive.bindDn=***,
org.ldaptive.maxPoolSize=6,
org.ldaptive.minPoolSize=2,
org.ldaptive.bindCredential=**masked**,
org.ldaptive.ldapUrl=***,
org.ldaptive.user=***,
org.ldaptive.pagedResultsSize=100,
org.ldaptive.searchResultHandlers=org.ldaptive.handler.DnAttributeEntryHandler,edu.internet2.middleware.grouper.ldap.ldaptive.GrouperRangeEntryHandler}



sed -n -e '/^2020-09-18 22:3.*Provisioner.* - Setting /s///p' grouper_error.log
properties for activedirectory_student consumer/provisioner.
enabled to true
grouperIsAuthoritative to false
dataCacheTime_secs to 43200
sleepTimeAfterError_ms to 1000
grouperGroupCacheSize to 10000
grouperSubjectCacheSize to 10000
targetSystemGroupCacheSize to 10000
targetSystemUserCacheSize to 10000
createMissingUsers to false
needsTargetSystemUsers to true
needsTargetSystemGroups to true
supportsEmptyGroups to true
groupSelectionExpression to ${utils.containedWithin(provisionerName, stemAttributes['etc:pspng:provision_to'], groupAttributes['etc:pspng:provision_to']) && !utils.containedWithin(provisionerName, stemAttributes['etc:pspng:do_not_provision_to'], groupAttributes['etc:pspng:do_not_provision_to'])}
attributesUsedInGroupSelectionExpression to [etc:pspng:provision_to, etc:pspng:do_not_provision_to]
attributesUsedInGroupSelectionExpressionAreComparedToProvisionerName to true
userSearch_batchSize to 50
groupSearch_batchSize to 50
coordinationTimeout_secs to 300
coordinationUpdateInterval_secs to 10
areChangesToInternalGrouperSubjectsIgnored to true
grouperMessagingSystemName to grouperBuiltinMessaging
numberOfDataFetchingWorkers to 1
missingSubjectsWarningThreshold_percentage to 100
areCacheSizeWarningsEnabled to true
cacheFullnessWarningThreshold_percentage to 95
maxNumberOfTimesToRepeatedlyFullSyncGroup to 3
timeToSleepBetweenRepeatedFullSyncs_ms to 1000
properties for activedirectory_student consumer/provisioner.
isActiveDirectory to true
ldapPoolName to groupLdap1
maxValuesToChangePerOperation to 100
userSearchBaseDn to OU=UsersUnige,OU=_UNIGE,DC=isis-klif,DC=unige,DC=ch
userSearchFilter to (cn=${empty(subject.attributes["unigeChStudentUid"])?"0":subject.attributes["unigeChStudentUid"].iterator().next()})
userSearchAttributes to [dn, cn]
userCreationBaseDn to null
userCreationLdifTemplate to null
ouCreationLdifTemplate to dn: ${dn}||ou: ${ou}||objectclass: organizationalunit
attributesNeededingDnEscaping to [dn, distinguishedname, entrydn, uniquemember, member]
properties for activedirectory_student consumer/provisioner.
memberAttributeName to member
memberAttributeValueFormat to ${ldapUser.getDn()}
groupAttributeName to memberof
groupCreationLdifTemplate to dn: ${utils.bushyDn(name, "cn", "ou")}||cn: ${extension}||objectclass: group||objectclass: top||gidNumber: ${idIndex + 5000000}||description: ${org.apache.commons.lang3.StringUtils.abbreviate(org.apache.commons.lang3.StringUtils.replaceAll((description?:""),"[\r\n]+"," "),900)}||groupType: 4||sAMAccountName: student`${org.apache.commons.lang3.StringUtils.replaceChars(name,':','`').replaceAll("[\"\[\];|=+*?<>/\\, ]","_")}||extensionAttribute7: ${name}||url: ${empty(groupAttributes['etc:pspng:entityId'])?"":(org.apache.commons.lang3.StringUtils.replace(org.apache.commons.lang3.StringUtils.removeEnd(org.apache.commons.lang3.StringUtils.removeStart(groupAttributes['etc:pspng:entityId'].toString(),"["),"]"),", ","\u000aurl: "))}||displayName: ${empty(groupAttributes['etc:pspng:is_member_of_value'])?"":groupAttributes['etc:pspng:is_member_of_value']}
groupSearchBaseDn to OU=student,OU=Grouper,OU=Groups,OU=_UNIGE,DC=isis-klif,DC=unige,DC=ch
groupCreationBaseDn to OU=student,OU=Grouper,OU=Groups,OU=_UNIGE,DC=isis-klif,DC=unige,DC=ch
allGroupsSearchFilter to objectclass=group
singleGroupSearchFilter to (&(objectclass=group)(gidNumber=${group.idIndex + 5000000}))
groupSearchAttributes to [cn, objectclass, sAMAccountName, description, gidNumber, groupType, url, displayName, extensionAttribute7]
ldapGroupCacheTime_secs to 600
ldapGroupCacheSize to 10000
memberAttributeIsCaseSensitive to false
enableBulkGroupSearching to true

sed -n -E -e '/^2020-09-18 22:3.*(\b1502\b|EXISTS)/s/.* -  - //p' grouper_error.log
Fetching subjects Completed (Success): 1502 items in 08.980s (10035.6 items/minute)
activedirectory_student-full/application:bpm-poc:bpm-oracle:workflow1:testgroup/#16234(Existing): 1502 correct member subjects. Sample: [''/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch']...
activedirectory_student-full: Full-sync comparison for application:bpm-poc:bpm-oracle:workflow1:testgroup/#16234(Existing): Target-subject count: Correct/Actual: 1502/0
activedirectory_student-full: Group application:bpm-poc:bpm-oracle:workflow1:testgroup/#16234(Existing) has 1502 missing values
groupLdap1: Performing ldap mod (with retry) Mod Summary: dn=cn=testgroup,ou=workflow1,ou=bpm-oracle,ou=bpm-poc,ou=application,ou=student,ou=grouper,ou=groups,ou=_unige,dc=isis-klif,dc=unige,dc=ch|ADD 1502 member values|
groupLdap1: Problem while modifying ldap system based on grouper expectations. Starting to perform adaptive modifications based on data already on server: cn=testgroup,ou=workflow1,ou=bpm-oracle,ou=bpm-poc,ou=application,ou=student,ou=grouper,ou=groups,ou=_unige,dc=isis-klif,dc=unige,dc=ch: ENTRY_ALREADY_EXISTS
groupLdap1: Data already on ldap server Entry Summary: dn=cn=testgroup,ou=workflow1,ou=bpm-oracle,ou=bpm-poc,ou=application,ou=student,ou=grouper,ou=groups,ou=_unige,dc=isis-klif,dc=unige,dc=ch|1502 member values|
groupLdap1: Summary: Comparing modification of member to what is already in LDAP: ADD/1502 Values
groupLdap1: Comparing Attribute member. #Values on server already 1502. #Values in mod/ADD: 1502
FullSync Item done (Successful: Success). Stats: ins=1502|del=0|upd=0|tot=1502|t=38 secs/ProcTime: 38.330s Timing breakdown: init=0%/ReadGroupFromGrouper=0%/ClearingGroupCache=0%/StartCoordination=0%/StartProvisioning(get group & subject info)=0%/doFullSync=98%/FinishProvisioning=0%/FinishCoordination=0%/: Action="application:bpm-poc:bpm-oracle:workflow1:testgroup|qid=1|Trigger=Scheduled" full sync|ExternalRef=null|AsOf=Sep 18, 2020 10:36:27 PM|QTime=00.001s|Age=38.332s
FullSyncer(activedirectory_student): Full Sync of all groups progress: 1 groups of 1 (100%): ins=1502|del=0|upd=0|tot=1502|t=38 secs
FullSyncer(activedirectory_student): Full Sync of all groups: Finished. Stats: ins=1502|del=0|upd=0|tot=1502|t=0 secs

On Fri, Sep 18, 2020 at 4:21 AM Dominique Petitpierre <> wrote:

Hello,

any advice on how to debug this problem?:

When synchronizing a target group that has more than 1500 members, even if there is nothing to do the PSPNG provisioner tries to replace all the members and fails with a LDAP error ENTRY_ALREADY_EXISTS.
This is with a Microsoft Active Directory target directory. It does not happen with 1500 members or less.
The 1501th member can be added without problem, but a subsequent full sync triggers the problem
This is clearly linked to this Active Directory feature:
3.1.1.3.1.3.3 Range Retrieval of Attribute Values
https://docs.microsoft.com/en-us/openspecs/windows_protocols/ms-adts/e27b48db-6f82-44cd-9038-2e54f790cc1f

dn: CN=Default Query Policy,CN=Query-Policies,CN=Directory Service,CN=Windows NT,CN=Services,CN=Configuration,DC=isis-klif,DC=unige,DC=ch
lDAPAdminLimits: MaxValRange=1500

Adding the searchResultHandler property to the groupLdap1 LDAP connector configuration does not help:

ldap.groupLdap1.searchResultHandlers=org.ldaptive.handler.DnAttributeEntryHandler,edu.internet2.middleware.grouper.ldap.ldaptive.GrouperRangeEntryHandler

cf. vt-ldap to ldaptive migration for LDAP access
https://spaces.at.internet2.edu/display/Grouper/vt-ldap+to+ldaptive+migration+for+LDAP+access#vt-ldaptoldaptivemigrationforLDAPaccess-Configurationoptions

And of course the LdapProvisioner isActiveDirectory property is set:

changeLog.consumer.activedirectory_student.isActiveDirectory = true

A search in grouper-users shows old problems, in particular:

Re: [grouper-users] Active Directory >1500 group members
https://lists.internet2.edu/sympa/arc/grouper-users/2016-11/msg00005.html

Re: [grouper-users] AD Range Attribute support with the PSP
https://lists.internet2.edu/sympa/arc/grouper-users/2017-01/msg00012.html

There is a Jira issue GRP-2343 that shows the same symptom, although it is considered minor and is not fixed:

LdapSystem.performLdapSearchRequest doesn't return any members when group has more than 1500 memberships
https://todos.internet2.edu/browse/GRP-2343

- What could be the problem? Surely PSNG works in other sites with large Active Directory groups!

There must be something obvious I am missing, but I am at loss of ideas.

Thanks in advance for your lights!

Regards.

Annexe: Relevant extract of the logs:

2020-09-18 07:30:06,640: [main] WARN  GrouperStartup.printConfigOnce(232) -  - Grouper starting up: version: 2.4.0, build date: null, env: test_2.4.0_grouper-loader
grouperPatchStatus read from: /usr/local/grouper-loader/grouperPatchStatus.properties
api patches installed:        0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 25, 26, 27, 28, 29, 30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47, 48, 49, 50, 51, 52, 53, 54, 55, 56, 57, 58, 59, 60, 61, 62, 63, 64, 65, 66, 67, 68, 69, 70, 71, 72, 73, 74, 75, 76, 77, 78, 79, 80, 81, 82, 83, 84, 85, 86, 87, 88, 89, 90, 91, 92, 93, 94, 95, 96
pspng patches installed:      0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12
...
2020-09-18 08:23:11,479: [main] DEBUG LdapProvisionerConfiguration.readConfiguration(126) -  - Ldap Provisioner activedirectory_student - Setting isActiveDirectory to true
...
2020-09-18 08:23:21,963: [FullSyncer(activedirectory_student)-Thread] INFO  ProgressMonitor.completelyDone(81) -  - Fetching subjects Completed (Success): 1501 items in 08.833s (10195.9 items/minute)
...
2020-09-18 08:23:21,977: [FullSyncer(activedirectory_student)-Thread] INFO  Provisioner.doFullSync(1591) -  - activedirectory_student-full/application:bpm-poc:bpm-oracle:workflow1:testgroup/#16234(Existing): 1501 correct member subjects. Sample: [''/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch', '674039@u
nige.ch'/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch', ''/'person'/'people-test.unige.ch']...
...
2020-09-18 08:23:22,076: [FullSyncer(activedirectory_student)-Thread] INFO  LdapSystem.performLdapRead(688) -  - Active Directory: Searching with Ldap RangeEntryHandler
...
2020-09-18 08:23:51,589: [FullSyncer(activedirectory_student)-Thread] INFO  LdapGroupProvisioner.doFullSync(194) -  - activedirectory_student-full: Full-sync comparison for application:bpm-poc:bpm-oracle:workflow1:testgroup/#16234(Existing): Target-subject count: Correct/Actual: 1501/0
...
2020-09-18 08:23:51,765: [FullSyncer(activedirectory_student)-Thread] WARN  LdapSystem.performLdapModify(450) -  - groupLdap1: Problem while modifying ldap system based on grouper expectations. Starting to perform adaptive modifications based on data already on server: cn=testgroup,ou=workflow1,ou=bpm-oracle,ou=bpm-poc,ou=application,ou=student,ou=grouper,ou=groups,ou=_unige,dc=isis-klif,dc=unige,dc=ch: ENTRY_ALREADY_EXISTS

-- 
Mr Dominique Petitpierre, user=Dominique.Petitpierre domain=unige.ch
IT Division, University of Geneva, Switzerland