Skip to Content.
Sympa Menu

grouper-users - Re: [grouper-users] PSPNG problem accessing group info in AD

Subject: Grouper Users - Open Discussion List

List archive

Re: [grouper-users] PSPNG problem accessing group info in AD


Chronological Thread 
  • From: Marwan Ali Shaher <>
  • To: "" <>
  • Subject: Re: [grouper-users] PSPNG problem accessing group info in AD
  • Date: Thu, 12 Jul 2018 17:30:07 +0000
  • Accept-language: en-US
  • Authentication-results: spf=none (sender IP is ) ;
  • Ironport-phdr: 9a23:5xC74hzhnhHUFCnXCy+O+j09IxM/srCxBDY+r6Qd2uIWIJqq85mqBkHD//Il1AaPAd2Fraocw8Pt8InYEVQa5piAtH1QOLdtbDQizfssogo7HcSeAlf6JvO5JwYzHcBFSUM3tyrjaRsdF8nxfUDdrWOv5jAOBBr/KRB1JuPoEYLOksi7ze+/94HSbglSmDaxfa55IQmrownWqsQYm5ZpJLwryhvOrHtIeuBWyn1tKFmOgRvy5dq+8YB6/ShItP0v68BPUaPhf6QlVrNYFygpM3o05MLwqxbOSxaE62YGXWUXlhpIBBXF7A3/U5zsvCb2qvZx1S+HNsDwULs6Wymt771zRRHolikJKiI5/m/UhMx+jq1VpxOhqABwzIPPeo6ZKP9+c7ndfd8GR2dMWNtaWSxbAoO7aosCF+0PMvxCr4jzvVQOqwa1CBWoBOPu1zRGm3/20rc60+s/CwHNwQstEdUUv3TOotT6LqESXfqowqnI1zrDb+1Z2S3m5YfUdRAhpfaMXahqfsXMzkkjDR3KgUiNqYH8OT6ey+oDs2+e7+V6VOKvjXYqqg9qojiy3MsjlJTGhp8NxlDf6CV224Q1KsOkR05ne9KkEYZfuieHPIV1WsMvW3xktDo1x7EctpO2fjIGxZokyhLFb/GLb5CE7xPhWeqLPDt1hnBodKihixqu7ESs0O7xWtSs3FZEsCVIkcXAu3UI2hPI9sSIUeZy80Kv2TqT1Q3e7/xILV4umqbGLpMu3rE9moQPvknFAyT4gl/5jLWMeUUh4uWo6/roYrHhppKEL4F5lgbwPrgwlsCmHOk2NBYCU3Gc+eunyrLv50r5QKhWjvItlanZrZbaKtkBqq6hGQ9V1Zoj5AijADe60dQYmn8HIEhCeBKak4jpP1bOIPf7Dfuln1uslzJry+jHPr3nHJrNMmDOnKr9cbty8UJRxwg+wcpR6p9XEL0MJO7/Vlf0tNPCDx85NwK0w/zgCNV4zo4QXniAArWXMazIt1+E/P8hI+mWa48Vpjn9MeMo6OLpjX89nl8dZ7Om0oYQaHyiAPtpPliZbWL2gtgdCWcKohY+TOvyhV2NSz5TYGuyX7oi6TEhEY6mEJzDSZ63gLyaxyq7GpxWZntaClCXD3vkbYSEW/EQaC2MOM9hlCILVaS/R4M7yx6hqRL6mPJbKb+e9TcfqIruzp1o/ODJjjkz8yB5FcKQzzvLQm1p1CtcSCUxwbhyuwlg0VqZyoB5heBVD9pe+6kPXwsnY83y1et/XvX7QB3IeJ+gTFfuedWvATwrBoYUysURakA7INWrjh3Z9yGtB7gPnrCMQpE47/SPjDDKO89hxiOeh+EahF48T54XOA==
  • Spamdiagnosticmetadata: NSPM
  • Spamdiagnosticoutput: 1:99

If you mean spaces in the OU names, then yes, they are allowed. Our groupSearchBaseDn has a space in the name. We specify the value without wrapping it in quotes, and I’m not sure if it would work with quotes around the value. For userSearchBaseDn, and because we want to include other service and admin accounts outside of our People OU, we specify the top level DC and set the userSearchScope to SUBTREE. Here is the relevant parameters and values from our dev environment:

changeLog.consumer.pspng_activedirectory.groupSearchBaseDn = OU=Managed Groups,dc=addev,dc=colorado,dc=edu
changeLog.consumer.pspng_activedirectory.userSearchBaseDn = dc=addev,dc=colorado,dc=edu
changeLog.consumer.pspng_activedirectory.userSearchScope = SUBTREE

Thanks,

- Marwan

On Jul 9, 2018, at 10:38 AM, Guenther, Dean R. <> wrote:

I’ve still been unable to provision groups to AD with PSPNG. I have a newbie question about this, when I’ve looked in the archives, all of the examples have OU’s which do not have a blank in the name. Are blanks allowed in the OU name for PSPNG? thanks – Dean
 
 
 
 
Dean Guenther                          
Washington State University    Phone:    509 335-0433
Pullman, WA. 99164-1222        fax:      509 335-0540
Identity and Access Management Manager
 
 
From: "Hyzer, Chris" <>
Date: Sunday, June 17, 2018 at 7:10 PM
To: "" <>, "" <>
Subject: RE: [grouper-users] PSPNG problem accessing group info in AD
 
This line:
 
2018-06-03 16:08:01,780: [pspng_activedirectory-FullSync-Thread] ERROR Provisioner.prepareGroupCache(736) -  - Problem fetching information on group 'test:ref:employee:hourly.appointed'
 
 
Should have a stacktrace after it.  Are you sending the whole log?  Can you stop the loader.  delete the file.  Start the loader. reproduce the error.  And send the entire log file please?
 
From: Guenther, Dean R. [] 
Sent: Friday, June 15, 2018 1:01 PM
To: Hyzer, Chris <>;
Subject: RE: [grouper-users] PSPNG problem accessing group info in AD
 
Hi Chris, Bert,
 
I can’t say for certain whether the loader is having a problem or PSPNG. But I think its PSPNG because of this error:
 
2018-06-03 16:08:01,780: [pspng_activedirectory-FullSync-Thread] ERROR Provisioner.prepareGroupCache(736) -  - Problem fetching information on group 'test:ref:employee:hourly.appointed'
 
I’ve tried with both the group created in AD and not pre-existing in AD.  My userSearch* config is:
 
changeLog.consumer.pspng_activedirectory.userSearchBaseDn = ou=NIDs,ou=WSU Accounts,dc=tempad,dc=wsu,dc=edu
changeLog.consumer.pspng_activedirectory.userSearchFilter = wsuExternalSystemID=${subject.id}
changeLog.consumer.pspng_activedirectory.userSearchAttributes = dn,cn,userprincipalname,wsuexternalsystemid,objectclass
 
Here is the output from GSH 
 
groovy:000> edu.internet2.middleware.grouper.ldap.LdapSession.list(String.class, "pspng_activedirectory","OU=NIDs,OU=WSU Accounts,dc=tempad,dc=wsu,dc=edu",LdapSearchScope.SUBTREE_SCOPE,"(cn=guenther)","cn")
ERROR java.lang.RuntimeException:
Problem with ldap conection: pspng_activedirectory,
Error querying ldap server id: pspng_activedirectory, searchDn: OU=WSU Accounts,dc=tempad,dc=wsu,dc=edu, filter: '(cn=guenther)', returning attribute: cn
        at edu.internet2.middleware.grouper.ldap.LdapSession.callbackLdapSession (LdapSession.java:249)
        at edu.internet2.middleware.grouper.ldap.LdapSession.list (LdapSession.java:276)
        at edu.internet2.middleware.grouper.ldap.LdapSession$list.call (Unknown Source)
 
I also repeated the gsh command with the filter “(wsuExternalSystemID=9099798451)” and it was essentially the same.
I also tried the path of both “OU=NIDs,OU=WSU Accounts” and the broader “OU=WSU Accounts”. As expected that was the same too.
 
And here is the output from the log:
 
2018-06-15 09:42:55,863: [main] DEBUG GrouperLoaderConfig.retrieveLdapProfile(319) -  - LDAP config for server id: pspng_activedirectory: GrouperLoaderLdapServer [batchSize=-1, configFileFromClasspath: , countLimit=-1, driver=null, expirationTime=-1, maxPoolSize=-1, minPoolSize=-1, pagedResultsSize=1000, pass=XXXXX, pruneTimerPeriod=-1, referral=follow, saslAuthorizationId=null, saslRealm=null, timeLimit=-1, timeout=-1, tls=false, url="ldaps://temp-dc01-pul.tempad.wsu.edu:636/dc=tempad,dc=wsu,dc=edu, user=cn=grouper.writer,ou=service accounts,ou=wsu accounts,dc=tempad,dc=wsu,dc=edu, validateOnCheckIn=false, validateOnCheckOut=true, validatePeriodically=false, validateTimerPeriod=-1, searchResultHandlers=[Ledu.vt.middleware.ldap.handler.SearchResultHandler;@4ccf31e5]
2018-06-15 09:42:55,916: [main] DEBUG LdapSession.callbackLdapSession(228) -  - pre-checkout: ldap id: pspng_activedirectory, pool active: 0, available: 0
2018-06-15 09:42:55,918: [main] DEBUG DefaultConnectionHandler.connectInternal(74) -  - Bind with the following parameters:
2018-06-15 09:42:55,919: [main] DEBUG DefaultConnectionHandler.connectInternal(75) -  -   authtype = simple
2018-06-15 09:42:55,919: [main] DEBUG DefaultConnectionHandler.connectInternal(76) -  -   dn = cn=grouper.writer,ou=service accounts,ou=wsu accounts,dc=tempad,dc=wsu,dc=edu
2018-06-15 09:42:55,919: [main] DEBUG DefaultConnectionHandler.connectInternal(83) -  -   credential = <suppressed>
2018-06-15 09:42:56,185: [main] DEBUG DefaultConnectionHandler.connectInternal(128) -  - Set hostname verifier for ldaps
2018-06-15 09:42:56,365: [main] DEBUG AggregateTrustManager.checkServerTrusted(75) -  - invoking checkServerTrusted for
2018-06-15 09:42:56,470: [main] DEBUG AggregateTrustManager.checkServerTrusted(75) -  - invoking checkServerTrusted for
2018-06-15 09:42:56,470: [main] DEBUG DefaultHostnameVerifier.verify(127) -  - Verify with the following parameters:
2018-06-15 09:42:56,470: [main] DEBUG DefaultHostnameVerifier.verify(128) -  -   hostname = temp-dc01-pul.tempad.wsu.edu
2018-06-15 09:42:56,471: [main] DEBUG DefaultHostnameVerifier.verify(129) -  -   cert = CN=temp-dc01-pul.tempad.wsu.edu, OU=SYS, O=Washington State University, STREET=362 Johnson Tower, L=Pullman, ST=Washington, OID.2.5.4.17=99164, C=US
2018-06-15 09:42:56,473: [main] DEBUG DefaultHostnameVerifier.verifyDNS(202) -  - verifyDNS using subjectAltNames = [temp-dc01-pul.tempad.wsu.edu]
2018-06-15 09:42:56,473: [main] DEBUG DefaultHostnameVerifier.verifyDNS(210) -  - verifyDNS found hostname match: temp-dc01-pul.tempad.wsu.edu
2018-06-15 09:42:56,473: [main] DEBUG AggregateTrustManager.getAcceptedIssuers(90) -  - invoking getAcceptedIssuers invoked for
2018-06-15 09:42:56,474: [main] DEBUG AggregateTrustManager.getAcceptedIssuers(90) -  - invoking getAcceptedIssuers invoked for
2018-06-15 09:42:56,545: [main] WARN  AbstractLdapFactory.validate(165) -  - validate called, but no validator configured
2018-06-15 09:42:56,545: [main] DEBUG LdapSession.callbackLdapSession(234) -  - post-checkout: ldap id: pspng_activedirectory, pool active: 1, available: 0
2018-06-15 09:42:56,547: [main] DEBUG AbstractLdap.pagedSearch(290) -  - Paginated search with the following parameters:
2018-06-15 09:42:56,547: [main] DEBUG AbstractLdap.pagedSearch(291) -  -   dn = OU=WSU Accounts,dc=tempad,dc=wsu,dc=edu
2018-06-15 09:42:56,548: [main] DEBUG AbstractLdap.pagedSearch(292) -  -   filter = (cn=guenther)
2018-06-15 09:42:56,548: [main] DEBUG AbstractLdap.pagedSearch(293) -  -   filterArgs = []
2018-06-15 09:42:56,548: [main] DEBUG AbstractLdap.pagedSearch(294) -  -   searchControls = 
2018-06-15 09:42:56,549: [main] DEBUG AbstractLdap.pagedSearch(295) -  -   handler = [edu.vt.middleware.ldap.handler.FqdnSearchResultHandler@15b7c582,, , ]
2018-06-15 09:42:56,561: [main] DEBUG GrouperClientLog.debug(92) -  - Cant find text for variable: 'newline'
2018-06-15 09:42:56,562: [main] DEBUG GrouperClientLog.debug(92) -  - Cant find text for variable: 'newline'
2018-06-15 09:42:56,562: [main] DEBUG GrouperClientLog.debug(92) -  - needToCheckIfFilesNeedReloading: true, needToCheckIfFilesNeedReloading2: true, configObjectPropertyCount: 269
 
From: Hyzer, Chris [] 
Sent: Friday, June 15, 2018 8:42 AM
To: Guenther, Dean R. <>; 
Subject: RE: [grouper-users] PSPNG problem accessing group info in AD
 
Bert, can you please look at this?
 
The “loader” pulls things from AD, and the “pspng” pushes things to AD.  You are asking about the pspng right?
 
In my example online that I think you have seen I used:
 
changeLog.consumer.pspng_activedirectory.userSearchBaseDn = DC=kite-dev,DC=upenn,DC=edu
changeLog.consumer.pspng_activedirectory.userSearchFilter = employeeID=${subject.id}
changeLog.consumer.pspng_activedirectory.userSearchAttributes = dn,cn,uid,mail,samAccountName, uidNumber,objectclass,employeeID
 
Do you have a similar configuration?  You need to tell grouper how to find subjects and resolve subjects from AD.
 
For this one, please include the output from GSH and the full log for that command:
 
groovy:000> edu.internet2.middleware.grouper.ldap.LdapSession.list(String.class, "pspng_activedirectory","OU=WSU
 
 
 
From:  [] On Behalf Of Guenther, Dean R.
Sent: Thursday, June 14, 2018 11:37 AM
To: 
Subject: Re: [grouper-users] Loader problem accessing group info in AD
 
I hadn’t a response from anybody on this post yet so I thought I’d poke the thread. The error says “problem fetching information on group”. Is it having a problem fetching info from AD?
thanks – Dean
 
 
 
 
Dean Guenther                          
Washington State University    Phone:    509 335-0433
Pullman, WA. 99164-1222        fax:      509 335-0540
Identity and Access Management Manager
 
 
From: <> on behalf of "" <>
Date: Monday, June 4, 2018 at 12:14 PM
To: "" <>
Subject: [grouper-users] Loader problem accessing group info in AD
 
I’ve built a group in AD that I want to provision members to called “test:ref:employee:hourly.appointed”. When the loader attempts to provision it complains that it cannot fetch information on the group:
 
2018-06-03 16:08:01,780: [pspng_activedirectory-FullSync-Thread] ERROR Provisioner.evaluateJexlExpression(556) -  - Jexl _expression_ null could not be evaluated for subject 'null/null' and group 'test:ref:employee:hourly.appointed/null' which used variableMap '{idIndex=10095, userSearchBaseDn=ou=NIDs,ou=WSU Accounts,dc=tempad,dc=wsu,dc=edu, groupAttributes={etc:pspng:provision_to=[pspng_activedirectory]}, groupCreationBaseDn=ou=grouper groups,ou=provisioned groups,ou=enterprise groups,ou=wsu authorization groups,dc=tempad,dc=wsu,dc=edu, stemAttributes={}, , groupSearchBaseDn=ou=grouper groups,ou=provisioned groups,ou=enterprise groups,ou=wsu authorization groups,dc=tempad,dc=wsu,dc=edu, name=test:ref:employee:hourly.appointed, provisionerName=pspng_activedirectory, group=Group[name=test:ref:employee:hourly.appointed,uuid=d4395181f7214efda1be4a8b568ece5d], provisionerType=LdapGroupProvisioner}'
2018-06-03 16:08:01,780: [pspng_activedirectory-FullSync-Thread] ERROR Provisioner.prepareGroupCache(736) -  - Problem fetching information on group 'test:ref:employee:hourly.appointed'
 
I’m not certain what info the loader is trying to fetch. I am able to do an ldapsearch of the group houly.appointed without any problem from the same host where the loader lives. So it seems the group is readable. Then I thought I’d try using LdapSession.list within gsh on a user object and that also gave an error:
 
groovy:000> edu.internet2.middleware.grouper.ldap.LdapSession.list(String.class, "pspng_activedirectory","OU=WSU Accounts,dc=tempad,dc=wsu,dc=edu",LdapSearchScope.SUBTREE_SCOPE,"(cn=guenther)","cn");
ERROR java.lang.RuntimeException:
Problem with ldap conection: pspng_activedirectory,
Error querying ldap server id: pspng_activedirectory, searchDn: OU=WSU Accounts,dc=tempad,dc=wsu,dc=edu, filter: '(cn=guenther)', returning attribute: cn
        at edu.internet2.middleware.grouper.ldap.LdapSession.callbackLdapSession (LdapSession.java:249)
        at edu.internet2.middleware.grouper.ldap.LdapSession.list (LdapSession.java:276)
        at edu.internet2.middleware.grouper.ldap.LdapSession$list.call (Unknown Source)
 
But it does seem odd that it says “Unknown Source”. The ldap bind looks good. So I’m not certain why it thinks its an unknown source. In the log it shows this for the LdapSession.list:
 
2018-06-04 10:11:29,493: [main] DEBUG LdapSession.callbackLdapSession(228) -  - pre-checkout: ldap id: pspng_activedirectory, pool active: 0, available: 1
2018-06-04 10:11:29,494: [main] WARN  AbstractLdapFactory.validate(165) -  - validate called, but no validator configured
2018-06-04 10:11:29,494: [main] DEBUG HibernateSession.<init>(290) -  - grouperTransactionType: READONLY_OR_USE_EXISTING, okToUseHibernate: true, readonlyMode: false, parentSessionExists: true, newHibernateSession: false, hibernateSession: HibernateSession (4eb175a4): notNew, notReadonly, READ_WRITE_NEW, activeTransaction, session (7da056b2)
2018-06-04 10:11:29,494: [main] DEBUG LdapSession.callbackLdapSession(234) -  - post-checkout: ldap id: pspng_activedirectory, pool active: 1, available: 0
2018-06-04 10:11:29,494: [main] DEBUG AbstractLdap.pagedSearch(290) -  - Paginated search with the following parameters:
2018-06-04 10:11:29,494: [main] DEBUG AbstractLdap.pagedSearch(291) -  -   dn = OU=WSU Accounts,dc=tempad,dc=wsu,dc=edu
2018-06-04 10:11:29,494: [main] DEBUG AbstractLdap.pagedSearch(292) -  -   filter = (cn=guenther)
2018-06-04 10:11:29,494: [main] DEBUG AbstractLdap.pagedSearch(293) -  -   filterArgs = []
 
 
Here is the ldaps bind:
 
2018-06-04 10:49:20,719: [DefaultQuartzScheduler_Worker-4] INFO  LdapSystem.test(504) -  - LDAP Url: ldaps://somehost.wsu.edu:636/dc=tempad,dc=wsu,dc=edu
2018-06-04 10:49:20,719: [DefaultQuartzScheduler_Worker-4] INFO  LdapSystem.test(510) -  - Testing SSL before the LDAP test
2018-06-04 10:49:20,719: [DefaultQuartzScheduler_Worker-4] INFO  LdapSystem.test(530) -  -   Making SSL connection to somehost.wsu.edu:636
2018-06-04 10:49:20,886: [DefaultQuartzScheduler_Worker-4] INFO  LdapSystem.test(544) -  - Successfully connected
2018-06-04 10:49:20,887: [DefaultQuartzScheduler_Worker-4] INFO  LdapSystem.buildLdapConnectionPool(89) -  - pspng_activedirectory: Creating LDAP Pool
2018-06-04 10:49:20,940: [DefaultQuartzScheduler_Worker-4] INFO  LdapSystem.performTestLdapRead(178) -  - Performing test read of directory root
2018-06-04 10:49:21,083: [DefaultQuartzScheduler_Worker-1] INFO  LdapSystem.performTestLdapRead(198) -  - Search success: 
2018-06-04 10:49:21,088: [DefaultQuartzScheduler_Worker-4] DEBUG LdapSystem.buildLdapConnectionPool(154) -  - pspng_activedirectory: Using default onCheckOut ldap-connection validation
2018-06-04 10:49:21,362: [DefaultQuartzScheduler_Worker-4] INFO  LdapSystem.performTestLdapRead(178) -  - Performing test read of directory root
2018-06-04 10:49:21,368: [DefaultQuartzScheduler_Worker-4] INFO  LdapSystem.test(553) -  - Success: Ldap pool built
2018-06-04 10:49:21,381: [DefaultQuartzScheduler_Worker-4] INFO  LdapSystem.test(556) -  - Success: Test ldap read
 
And this is what I have configured:
 
ldap.pspng_activedirectory.user = cn=grouper.writer,ou=service accounts ,dc=tempad,dc=wsu,dc=edu
ldap.pspng_activedirectory.pass = *******************
ldap.pspng_activedirectory.pagedResultsSize = 1000
ldap.pspng_activedirectory.referral = follow
ldap.pspng_activedirectory.searchResultHandlers=edu.vt.middleware.ldap.handler.FqdnSearchResultHandler,edu.vt.middleware.ldap.handler.EntryDnSearchResultHandler,edu.vt.middleware.ldap.handler.BinarySearchResultHandler,edu.internet2.middleware.grouper.ldap.handler.RangeSearchResultHandler
changeLog.consumer.pspng_activedirectory.provisionerName = pspng_activedirectory
changeLog.consumer.pspng_activedirectory.class = edu.internet2.middleware.grouper.pspng.PspChangelogConsumerShim
changeLog.consumer.pspng_activedirectory.type = edu.internet2.middleware.grouper.pspng.LdapGroupProvisioner
changeLog.consumer.pspng_activedirectory.quartzCron = 15 * * * * ?
changeLog.consumer.pspng_activedirectory.ldapPoolName = pspng_activedirectory
changeLog.consumer.pspng_activedirectory.isActiveDirectory = true
changeLog.consumer.pspng_activedirectory.memberAttributeName = member
changeLog.consumer.pspng_activedirectory.memberAttributeValueFormat = ${ldapUser.getDn()}
changeLog.consumer.pspng_activedirectory.groupSearchBaseDn = ou=grouper groups,ou=provisioned groups,ou=enterprise groups,ou=wsu authorization groups,dc=tempad,dc=wsu,dc=edu
changeLog.consumer.pspng_activedirectory.groupSearchAttributes = cn,samAccountName,objectclass
changeLog.consumer.pspng_activedirectory.allGroupsSearchFilter = objectclass=group
changeLog.consumer.pspng_activedirectory.singleGroupSearchFIlter = (&(objectclass=group)(cn=${group.name}))
changeLog.consumer.pspng_activedirectory.groupCreationLdifTemplate = dn: cn=${group.name}||cn: ${group.name}||objectclass: group
 
What do I look at next to figure out my problem with loader trying to fetch info from AD? thanks -- Dean
 
 
Dean Guenther                          
Washington State University    Phone:    509 335-0433
Pullman, WA. 99164-1222        fax:      509 335-0540
Identity and Access Management Manager




Archive powered by MHonArc 2.6.19.

Top of Page