Grouper Users - Open Discussion List

["Guenther, Dean R." <>]

Thanks Bert for getting back to me. Thanks for the clue. In my grouper-loader.propreties I had “singleGroupSearchFIlter” instead of “singleGroupSearchFilter”. The capital “I” was killing it. Now that I’ve corrected that, I’m past that error and now I am getting an error when it is trying to create a group for me. For example, it tries to create a group:

 

            Creating LDAP object: cn=test:ref:employee:hourly.appointed

 

But it thinks the groupSearchBaseDn OU does not exist. But I’m pretty sure I’ve carefully examined the OU in the config and this time I don’t have any typos. Following is my grouper-loader.properties. Note in the userSearchFilter that I’m referencing wsuExternalSystemID. This is a uniqueID we use here. Its in an AD extended schema attribute. And it is the subject.ID in the loader build for the group.  And the service account “sa” has write/write access to this extended schema attribute.

 

ldap.active_directory.url = "ldaps://dc.tempad.wsu.edu:636/dc=tempad,dc=wsu,dc=edu

ldap.active_directory.user = cn=sa,ou=service accounts,ou=wsu accounts,dc=xxxxad,dc=wsu,dc=edu

ldap.active_directory.pass = *******

 

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 = active_directory

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=xxxxad,dc=wsu,dc=edu

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

changeLog.consumer.pspng_activedirectory.userSearchBaseDn = ou=NIDs,ou=WSU Accounts,dc=xxxxad,dc=wsu,dc=edu

changeLog.consumer.pspng_activedirectory.userSearchFilter = wsuExternalSystemID=${subject.id}

changeLog.consumer.pspng_activedirectory.userSearchScope = SUBTREE

changeLog.consumer.pspng_activedirectory.userSearchAttributes = dn,cn,userprincipalname,wsuexternalsystemid,objectclass

otherJob.pspng_activedirectory_full.class = edu.internet2.middleware.grouper.pspng.FullSyncStarter

otherJob.pspng_activedirectory_full.quartzCron = 0 * * * * ?

 

In the log, it shows pspng attempting to create the group “test:ref:employee:hourly.appointed” and it looks at each OU container and says it does not exist. Which seems odd to me. I also later tried another test with hourly.appointed already being created and that also generates the same error. And I used the same service account to create the group so I know that account has permission to create groups in this OU. But it results in the same thing, says the OU does not exist.

 

2018-07-25 13:16:02,964: [pspng_activedirectory-FullSync-Thread] DEBUG Provisioner.evaluateJexlExpression(538) -  - Evaluated Jexl _expression_: test:ref:employee:hourly.appointed FROM ${group.name} WITH variables {idIndex=10095, userSearchBaseDn=ou=NIDs,ou=WSU Accounts,dc=xxxxad,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=xxxxad,dc=wsu,dc=edu, stemAttributes={}, utils=edu.internet2.middleware.grouper.pspng.PspJexlUtils@e064c5a, groupSearchBaseDn=ou=Grouper Groups,ou=Provisioned Groups,ou=Enterprise Groups,ou=WSU Authorization Groups,dc=xxxxad,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-07-25 13:16:02,966: [pspng_activedirectory-FullSync-Thread] DEBUG LdapGroupProvisioner.createGroup(329) -  - pspng_activedirectory: LDIF for new group (with partial DN): dn: cn=test:ref:employee:hourly.appointed||cn: test:ref:employee:hourly.appointed||objectclass: group

2018-07-25 13:16:02,968: [pspng_activedirectory-FullSync-Thread] DEBUG LdapGroupProvisioner.createGroup(338) -  - pspng_activedirectory: Adding group: [dn=cn=test:ref:employee:hourly.appointed,ou=Grouper Groups,ou=Provisioned Groups,ou=Enterprise Groups,ou=WSU Authorization Groups,dc=xxxxad,dc=wsu,dc=edu[[cn[test:ref:employee:hourly.appointed]], [objectclass[group]]]]

2018-07-25 13:16:02,968: [pspng_activedirectory-FullSync-Thread] INFO  LdapProvisioner.performLdapAdd(722) -  - pspng_activedirectory: Creating LDAP object: cn=test:ref:employee:hourly.appointed,ou=Grouper Groups,ou=Provisioned Groups,ou=Enterprise Groups,ou=WSU Authorization Groups,dc=xxxxad,dc=wsu,dc=edu

2018-07-25 13:16:02,969: [pspng_activedirectory-FullSync-Thread] DEBUG LdapProvisioner.ensureLdapOusExist(677) -  - pspng_activedirectory: Checking to see if ou exists: ou=Grouper Groups,ou=Provisioned Groups,ou=Enterprise Groups,ou=WSU Authorization Groups,dc=xxxxad,dc=wsu,dc=edu

2018-07-25 13:16:02,969: [pspng_activedirectory-FullSync-Thread] DEBUG LdapSystem.performLdapRead(372) -  - Doing ldap read: ou=Grouper Groups,ou=Provisioned Groups,ou=Enterprise Groups,ou=WSU Authorization Groups,dc=xxxxad,dc=wsu,dc=edu

2018-07-25 13:16:02,972: [pspng_activedirectory-FullSync-Thread] WARN  LdapSystem.performLdapRead(403) -  - active_directory: Ldap object does not exist: 'ou=Grouper Groups,ou=Provisioned Groups,ou=Enterprise Groups,ou=WSU Authorization Groups,dc=xxxxad,dc=wsu,dc=edu'

2018-07-25 13:16:02,972: [pspng_activedirectory-FullSync-Thread] DEBUG LdapProvisioner.ensureLdapOusExist(677) -  - pspng_activedirectory: Checking to see if ou exists: ou=Provisioned Groups,ou=Enterprise Groups,ou=WSU Authorization Groups,dc=xxxxad,dc=wsu,dc=edu

2018-07-25 13:16:02,972: [pspng_activedirectory-FullSync-Thread] DEBUG LdapSystem.performLdapRead(372) -  - Doing ldap read: ou=Provisioned Groups,ou=Enterprise Groups,ou=WSU Authorization Groups,dc=xxxxad,dc=wsu,dc=edu

2018-07-25 13:16:02,974: [pspng_activedirectory-FullSync-Thread] WARN  LdapSystem.performLdapRead(403) -  - active_directory: Ldap object does not exist: 'ou=Provisioned Groups,ou=Enterprise Groups,ou=WSU Authorization Groups,dc=xxxxad,dc=wsu,dc=edu'

 

 

I also tried to use gsh to do a lookup of a person, and that failed (below). Note that I can use my service account to lookup the wsuexternalsystemid using ldapsearch, so I don’t think it’s a permission issue with the list.

 

groovy:000> edu.internet2.middleware.grouper.ldap.LdapSession.list(String.class, "active_directory","OU=NIDs,OU=WSU Accounts,dc=xxxxad,dc=wsu,dc=edu",LdapSearchScope.SUBTREE_SCOPE,"(wsuexternalsystemid=9099798451)","cn")

ERROR java.lang.RuntimeException:

Problem with ldap conection: active_directory,

Error querying ldap server id: active_directory, searchDn: OU=NIDs,OU=WSU Accounts,dc=xxxxad,dc=wsu,dc=edu, filter: '(wsuexternalsystemid=9099798451)', 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)

 

2018-07-25 13:38:28,638: [main] DEBUG LdapSession.callbackLdapSession(228) -  - pre-checkout: ldap id: active_directory, pool active: 0, available: 1

2018-07-25 13:38:28,638: [main] WARN  AbstractLdapFactory.validate(165) -  - validate called, but no validator configured

2018-07-25 13:38:28,638: [main] DEBUG LdapSession.callbackLdapSession(234) -  - post-checkout: ldap id: active_directory, pool active: 1, available: 0

2018-07-25 13:38:28,638: [main] DEBUG AbstractLdap.search(193) -  - Search with the following parameters:

2018-07-25 13:38:28,638: [main] DEBUG AbstractLdap.search(194) -  -   dn = OU=NIDs,OU=WSU Accounts,dc=xxxxad,dc=wsu,dc=edu

2018-07-25 13:38:28,638: [main] DEBUG AbstractLdap.search(195) -  -   filter = (wsuexternalsystemid=9099798451)

2018-07-25 13:38:28,639: [main] DEBUG AbstractLdap.search(196) -  -   filterArgs = []

2018-07-25 13:38:28,639: [main] DEBUG AbstractLdap.search(197) -  -   searchControls = javax.naming.directory.SearchControls@2fa50fe

2018-07-25 13:38:28,639: [main] DEBUG AbstractLdap.search(198) -  -   handler = [edu.vt.middleware.ldap.handler.FqdnSearchResultHandler@3e4c107d]

2018-07-25 13:38:28,651: [main] DEBUG GrouperClientLog.debug(92) -  - Cant find text for variable: 'newline'

2018-07-25 13:38:28,651: [main] DEBUG GrouperClientLog.debug(92) -  - Cant find text for variable: 'newline'

2018-07-25 13:38:28,651: [main] DEBUG GrouperClientLog.debug(92) -  - needToCheckIfFilesNeedReloading: true, needToCheckIfFilesNeedReloading2: true, configObjectPropertyCount: 269

 

Where do I start looking? I can send more of the log file if you need it. Thanks – Dean

 

 

From: Bee-Lindgren, Bert [mailto:]
Sent: Wednesday, July 25, 2018 9:33 AM
To: Guenther, Dean R. <>; Hyzer, Chris <>;
Subject: Re: [grouper-users] PSPNG problem accessing group info in AD

 

Hello,

 

Just to confirm, Spaces in the names of Groups, Folders/Stems, Base DNs, everywhere are all supported.

 

The ".singleGroupSearchFilter" property seems to be missing. Can you sanitize and share grouper-loader.properties?

 

Thanks,

  Bert

 

---

From: <> on behalf of Guenther, Dean R. <>
Sent: Monday, July 16, 2018 10:58 AM
To: Hyzer, Chris;
Subject: Re: [grouper-users] PSPNG problem accessing group info in AD

 

Hi Chris, I’m attaching the grouper log. Did I get all of the DEBUG statements added to give you the logging you needed?

 

 

Command I sent was the same:

 

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")

 

 

 

 

 

 

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.url = "ldaps://somehost.wsu.edu:636/dc=tempad,dc=wsu,dc=edu

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