Skip to Content.
Sympa Menu

grouper-users - RE: [grouper-users] grouper upgrade 2.2.2 to 2.4.0: Problem with ldap connection

Subject: Grouper Users - Open Discussion List

List archive

RE: [grouper-users] grouper upgrade 2.2.2 to 2.4.0: Problem with ldap connection


Chronological Thread 
  • From: "Hyzer, Chris" <>
  • To: Baron Fujimoto <>, Grouper Users <>
  • Subject: RE: [grouper-users] grouper upgrade 2.2.2 to 2.4.0: Problem with ldap connection
  • Date: Fri, 5 Jul 2019 19:38:34 +0000

Did you do this?

https://spaces.at.internet2.edu/display/Grouper/v2.4+Upgrade+Instructions+from+v2.3

the vt-ldap to ldaptive

-----Original Message-----
From:
<> On Behalf Of Baron Fujimoto
Sent: Wednesday, July 03, 2019 5:45 PM
To: Grouper Users <>
Subject: [grouper-users] grouper upgrade 2.2.2 to 2.4.0: Problem with ldap
connection

I'm attempting to upgrade grouper 2.2.2 to 2.4.0 using grouperInstaller. I'm
currently stuck though with some aspect of the converted configs. When I
first tried to run gsh, I encountered the following error:

=====
Subject API error: error with subject source id: UH_core_LDAP, name: UH_LDAP,
problem with getSubject by id, in subject.properties: search searchSubject: ,
edu.internet2.middleware.subject.SourceUnavailableException: Ldap Exception:
Missing property subjectApi.source.UH_core_LDAP.param.ldapServerId.value in
subject.properties. The value of this property should point to your LDAP
configuration in the grouper-loader.properties file. e.g. if your
grouper-loader.properties has ldap.personLdap.url, then the value of this
property would be personLdap
=====

This appeared to be resolved by adding the following to subject.properties as
suggested:

subjectApi.source.UH_core_LDAP.param.ldapServerId.value = personLdap

However, now when I start gsh, I get:

=====
$ ./gsh
Detected Grouper directory structure 'api' (valid is api or webapp)
Using GROUPER_HOME:
/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4
Using GROUPER_CONF:
/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4/conf
Using JAVA: /usr/java/latest/bin/java
Using CLASSPATH:
/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4/conf:/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4/dist/lib/grouper.jar:/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4/lib/grouper/*:/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4/lib/custom/*:/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4/lib/jdbcSamples/*:/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4/lib/ant/*:/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4/lib/test/*:/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4/dist/lib/test/*:/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4/src/resources
using MEMORY: 64m-750m
Grouper starting up: version: 2.4.0, build date: null, env: grouper-dev
grouperPatchStatus read from:
/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4/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
grouper.properties read from:
/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4/conf/grouper.properties
Grouper current directory is:
/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4/bin
log4j.properties read from:
/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4/conf/log4j.properties
Grouper is logging to file:
/home/grouper/grouper/logs/grouper-api_error.log, at min level WARN for
package: edu.internet2.middleware.grouper, based on log4j.properties
grouper.hibernate.properties:
/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4/conf/grouper.hibernate.properties
grouper.hibernate.properties:
grouper@jdbc:mysql://grouper.example.edu:3306/grprdev?CharSet=utf8&useUnicode=true&characterEncoding=utf8&useSSL=false
subject.properties read from:
/home/grouper/grouper/grouper.apiBinary-2.2.2-upgrade-to-2.4/conf/subject.properties
sources configured in: subject.properties
subject.properties groupersource id: g:gsa
subject.properties groupersource id: grouperEntities
subject.properties ldap source id: UH core LDAP: personLdap
Subject API error: error with subject source id: UH core LDAP, name: UH LDAP,
problem with getSubject by id, in subject.properties: search searchSubject: ,
edu.internet2.middleware.subject.SourceUnavailableException: Ldap Exception:
Problem with ldap conection: personLdap,
Error querying ldap server id: personLdap, searchDn: dc=hawaii,dc=edu,
filter: '(& (uhuuid=grouperTestSubjectByIdOnStartupASDFGHJ)
(objectclass=uhEduPerson))', returning attributes:
[Ljava.lang.String;@6f5bd362
at
edu.internet2.middleware.subject.provider.LdapSourceAdapter.getLdapResultsHelper(LdapSourceAdapter.java:541)
at
edu.internet2.middleware.subject.provider.LdapSourceAdapter.getLdapResults(LdapSourceAdapter.java:433)
at
edu.internet2.middleware.subject.provider.LdapSourceAdapter.getLdapUnique(LdapSourceAdapter.java:562)
at
edu.internet2.middleware.subject.provider.LdapSourceAdapter.getSubject(LdapSourceAdapter.java:189)
at
edu.internet2.middleware.subject.SubjectCheckConfig.checkConfig(SubjectCheckConfig.java:114)
at
edu.internet2.middleware.grouper.misc.GrouperCheckConfig$1.callback(GrouperCheckConfig.java:530)
at
edu.internet2.middleware.grouper.GrouperSession.callbackGrouperSession(GrouperSession.java:974)
at
edu.internet2.middleware.grouper.misc.GrouperCheckConfig.checkConfig(GrouperCheckConfig.java:526)
at
edu.internet2.middleware.grouper.misc.GrouperStartup.startup(GrouperStartup.java:313)
at
edu.internet2.middleware.grouper.app.gsh.GrouperShell.main(GrouperShell.java:165)
at
edu.internet2.middleware.grouper.app.gsh.GrouperShellWrapper.main(GrouperShellWrapper.java:31)
Caused by: java.lang.RuntimeException: Problem with ldap conection:
personLdap,
Error querying ldap server id: personLdap, searchDn: dc=hawaii,dc=edu,
filter: '(& (uhuuid=grouperTestSubjectByIdOnStartupASDFGHJ)
(objectclass=uhEduPerson))', returning attributes:
[Ljava.lang.String;@6f5bd362
at
edu.internet2.middleware.grouper.ldap.ldaptive.LdaptiveSessionImpl.callbackLdapSession(LdaptiveSessionImpl.java:381)
at
edu.internet2.middleware.grouper.ldap.ldaptive.LdaptiveSessionImpl.list(LdaptiveSessionImpl.java:601)
at
edu.internet2.middleware.subject.provider.LdapSourceAdapter.getLdapResultsHelper(LdapSourceAdapter.java:538)
... 10 more
Caused by: [org.ldaptive.pool.ValidationException@104803851::resultCode=null,
matchedDn=null, responseControls=null, referralURLs=null, messageId=-1,
message=Validation of connection failed, providerException=null]
at
org.ldaptive.pool.AbstractConnectionPool.activateAndValidateConnection(AbstractConnectionPool.java:671)
at
org.ldaptive.pool.BlockingConnectionPool.getConnection(BlockingConnectionPool.java:150)
at
org.ldaptive.pool.PooledConnectionFactory.getConnection(PooledConnectionFactory.java:68)
at
edu.internet2.middleware.grouper.ldap.ldaptive.LdaptiveSessionImpl.callbackLdapSession(LdaptiveSessionImpl.java:365)
... 12 more

Couldnt startup grouper: error with subject source id: UH core LDAP, name: UH
LDAP, problem with getSubject by id, in subject.properties: search
searchSubject:
java.lang.RuntimeException: error with subject source id: UH core LDAP, name:
UH LDAP, problem with getSubject by id, in subject.properties: search
searchSubject:
at
edu.internet2.middleware.subject.SubjectCheckConfig.checkConfig(SubjectCheckConfig.java:122)
at
edu.internet2.middleware.grouper.misc.GrouperCheckConfig$1.callback(GrouperCheckConfig.java:530)
at
edu.internet2.middleware.grouper.GrouperSession.callbackGrouperSession(GrouperSession.java:974)
at
edu.internet2.middleware.grouper.misc.GrouperCheckConfig.checkConfig(GrouperCheckConfig.java:526)
at
edu.internet2.middleware.grouper.misc.GrouperStartup.startup(GrouperStartup.java:313)
at
edu.internet2.middleware.grouper.app.gsh.GrouperShell.main(GrouperShell.java:165)
at
edu.internet2.middleware.grouper.app.gsh.GrouperShellWrapper.main(GrouperShellWrapper.java:31)
Caused by: edu.internet2.middleware.subject.SourceUnavailableException: Ldap
Exception: Problem with ldap conection: personLdap,
Error querying ldap server id: personLdap, searchDn: dc=hawaii,dc=edu,
filter: '(& (uhuuid=grouperTestSubjectByIdOnStartupASDFGHJ)
(objectclass=uhEduPerson))', returning attributes:
[Ljava.lang.String;@6f5bd362
at
edu.internet2.middleware.subject.provider.LdapSourceAdapter.getLdapResultsHelper(LdapSourceAdapter.java:541)
at
edu.internet2.middleware.subject.provider.LdapSourceAdapter.getLdapResults(LdapSourceAdapter.java:433)
at
edu.internet2.middleware.subject.provider.LdapSourceAdapter.getLdapUnique(LdapSourceAdapter.java:562)
at
edu.internet2.middleware.subject.provider.LdapSourceAdapter.getSubject(LdapSourceAdapter.java:189)
at
edu.internet2.middleware.subject.SubjectCheckConfig.checkConfig(SubjectCheckConfig.java:114)
... 6 more
Caused by: java.lang.RuntimeException: Problem with ldap conection:
personLdap,
Error querying ldap server id: personLdap, searchDn: dc=hawaii,dc=edu,
filter: '(& (uhuuid=grouperTestSubjectByIdOnStartupASDFGHJ)
(objectclass=uhEduPerson))', returning attributes:
[Ljava.lang.String;@6f5bd362
at
edu.internet2.middleware.grouper.ldap.ldaptive.LdaptiveSessionImpl.callbackLdapSession(LdaptiveSessionImpl.java:381)
at
edu.internet2.middleware.grouper.ldap.ldaptive.LdaptiveSessionImpl.list(LdaptiveSessionImpl.java:601)
at
edu.internet2.middleware.subject.provider.LdapSourceAdapter.getLdapResultsHelper(LdapSourceAdapter.java:538)
... 10 more
Caused by: [org.ldaptive.pool.ValidationException@104803851::resultCode=null,
matchedDn=null, responseControls=null, referralURLs=null, messageId=-1,
message=Validation of connection failed, providerException=null]
at
org.ldaptive.pool.AbstractConnectionPool.activateAndValidateConnection(AbstractConnectionPool.java:671)
at
org.ldaptive.pool.BlockingConnectionPool.getConnection(BlockingConnectionPool.java:150)
at
org.ldaptive.pool.PooledConnectionFactory.getConnection(PooledConnectionFactory.java:68)
at
edu.internet2.middleware.grouper.ldap.ldaptive.LdaptiveSessionImpl.callbackLdapSession(LdaptiveSessionImpl.java:365)
... 12 more
Exception in thread "main" java.lang.RuntimeException: error with subject
source id: UH core LDAP, name: UH LDAP, problem with getSubject by id, in
subject.properties: search searchSubject:
at
edu.internet2.middleware.subject.SubjectCheckConfig.checkConfig(SubjectCheckConfig.java:122)
at
edu.internet2.middleware.grouper.misc.GrouperCheckConfig$1.callback(GrouperCheckConfig.java:530)
at
edu.internet2.middleware.grouper.GrouperSession.callbackGrouperSession(GrouperSession.java:974)
at
edu.internet2.middleware.grouper.misc.GrouperCheckConfig.checkConfig(GrouperCheckConfig.java:526)
at
edu.internet2.middleware.grouper.misc.GrouperStartup.startup(GrouperStartup.java:313)
at
edu.internet2.middleware.grouper.app.gsh.GrouperShell.main(GrouperShell.java:165)
at
edu.internet2.middleware.grouper.app.gsh.GrouperShellWrapper.main(GrouperShellWrapper.java:31)
Caused by: edu.internet2.middleware.subject.SourceUnavailableException: Ldap
Exception: Problem with ldap conection: personLdap,
Error querying ldap server id: personLdap, searchDn: dc=hawaii,dc=edu,
filter: '(& (uhuuid=grouperTestSubjectByIdOnStartupASDFGHJ)
(objectclass=uhEduPerson))', returning attributes:
[Ljava.lang.String;@6f5bd362
at
edu.internet2.middleware.subject.provider.LdapSourceAdapter.getLdapResultsHelper(LdapSourceAdapter.java:541)
at
edu.internet2.middleware.subject.provider.LdapSourceAdapter.getLdapResults(LdapSourceAdapter.java:433)
at
edu.internet2.middleware.subject.provider.LdapSourceAdapter.getLdapUnique(LdapSourceAdapter.java:562)
at
edu.internet2.middleware.subject.provider.LdapSourceAdapter.getSubject(LdapSourceAdapter.java:189)
at
edu.internet2.middleware.subject.SubjectCheckConfig.checkConfig(SubjectCheckConfig.java:114)
... 6 more
Caused by: java.lang.RuntimeException: Problem with ldap conection:
personLdap,
Error querying ldap server id: personLdap, searchDn: dc=hawaii,dc=edu,
filter: '(& (uhuuid=grouperTestSubjectByIdOnStartupASDFGHJ)
(objectclass=uhEduPerson))', returning attributes:
[Ljava.lang.String;@6f5bd362
at
edu.internet2.middleware.grouper.ldap.ldaptive.LdaptiveSessionImpl.callbackLdapSession(LdaptiveSessionImpl.java:381)
at
edu.internet2.middleware.grouper.ldap.ldaptive.LdaptiveSessionImpl.list(LdaptiveSessionImpl.java:601)
at
edu.internet2.middleware.subject.provider.LdapSourceAdapter.getLdapResultsHelper(LdapSourceAdapter.java:538)
... 10 more
Caused by: [org.ldaptive.pool.ValidationException@104803851::resultCode=null,
matchedDn=null, responseControls=null, referralURLs=null, messageId=-1,
message=Validation of connection failed, providerException=null]
at
org.ldaptive.pool.AbstractConnectionPool.activateAndValidateConnection(AbstractConnectionPool.java:671)
at
org.ldaptive.pool.BlockingConnectionPool.getConnection(BlockingConnectionPool.java:150)
at
org.ldaptive.pool.PooledConnectionFactory.getConnection(PooledConnectionFactory.java:68)
at
edu.internet2.middleware.grouper.ldap.ldaptive.LdaptiveSessionImpl.callbackLdapSession(LdaptiveSessionImpl.java:365)
... 12 more
=====

Looking at our LDAP logs, the only entries I find are the bind/unbind for our
grouper dn, but no queries that might have part of a connection validation?

=====
[03/Jul/2019:11:27:27 -1000] conn=1521212 fd=203 slot=203 SSL connection from
10.0.0.10 to 10.0.0.20
[03/Jul/2019:11:27:27 -1000] conn=1521212 TLS1.2 128-bit AES-GCM
[03/Jul/2019:11:27:27 -1000] conn=1521212 op=0 BIND
dn="cn=foo,ou=bar,dc=hawaii,dc=edu" method=128 version=3
[03/Jul/2019:11:27:27 -1000] conn=1521212 op=0 RESULT err=0 tag=97 nentries=0
etime=0 dn="cn=foo,ou=bar,dc=hawaii,dc=edu"
[03/Jul/2019:11:27:30 -1000] conn=1521212 op=1 SRCH base="dc=hawaii,dc=edu"
scope=0 filter="(objectClass=*)" attrs="1.1"
[03/Jul/2019:11:27:30 -1000] conn=1521212 op=1 RESULT err=0 tag=101
nentries=0 etime=0
[03/Jul/2019:11:27:30 -1000] conn=1521212 op=2 UNBIND
[03/Jul/2019:11:27:30 -1000] conn=1521212 op=2 fd=203 closed - U1

[03/Jul/2019:11:27:27 -1000] conn=1521213 fd=204 slot=204 SSL connection from
10.0.0.10 to 10.0.0.20
[03/Jul/2019:11:27:27 -1000] conn=1521213 TLS1.2 128-bit AES-GCM
[03/Jul/2019:11:27:27 -1000] conn=1521213 op=0 BIND
dn="cn=foo,ou=bar,dc=hawaii,dc=edu" method=128 version=3
[03/Jul/2019:11:27:27 -1000] conn=1521213 op=0 RESULT err=0 tag=97 nentries=0
etime=0 dn="cn=foo,ou=bar,dc=hawaii,dc=edu"
[03/Jul/2019:11:27:27 -1000] conn=1521213 op=1 SRCH base="dc=hawaii,dc=edu"
scope=0 filter="(objectClass=*)" attrs="1.1"
[03/Jul/2019:11:27:27 -1000] conn=1521213 op=1 RESULT err=0 tag=101
nentries=0 etime=0
[03/Jul/2019:11:27:27 -1000] conn=1521213 op=2 UNBIND
[03/Jul/2019:11:27:27 -1000] conn=1521213 op=2 fd=204 closed - U1
=====

One thing I don't understand is that we weren't even binding with our grouper
user's dn until I added the credentials to grouper-loader.properties. If the
same credentials are only present in subject.properties, then we only see
anonymous binds in our ldap logs. The properties in our subject properties
look like:

subjectApi.source.UH_core_LDAP.id = UH core LDAP
[...]
subjectApi.source.UH_core_LDAP.param.SECURITY_PRINCIPAL.value =
cn=foo,ou=bar,dc=hawaii,dc=edu
subjectApi.source.UH_core_LDAP.param.SECURITY_CREDENTIALS.value = *secret*

=====
[03/Jul/2019:11:31:08 -1000] conn=1521409 fd=210 slot=210 SSL connection from
10.0.0.10 to 10.0.0.20
[03/Jul/2019:11:31:08 -1000] conn=1521409 TLS1.2 128-bit AES-GCM
[03/Jul/2019:11:31:08 -1000] conn=1521409 op=0 BIND dn="" method=128 version=3
[03/Jul/2019:11:31:08 -1000] conn=1521409 op=0 RESULT err=0 tag=97 nentries=0
etime=0 dn=""
[03/Jul/2019:11:31:08 -1000] conn=1521409 op=1 SRCH base="dc=hawaii,dc=edu"
scope=0 filter="(objectClass=*)" attrs="1.1"
[03/Jul/2019:11:31:08 -1000] conn=1521409 op=1 RESULT err=0 tag=101
nentries=0 etime=0
[03/Jul/2019:11:31:08 -1000] conn=1521409 op=2 UNBIND
[03/Jul/2019:11:31:08 -1000] conn=1521409 op=2 fd=210 closed - U1

[03/Jul/2019:11:31:08 -1000] conn=1521410 fd=208 slot=208 SSL connection from
10.0.0.10 to 10.0.0.20
[03/Jul/2019:11:31:08 -1000] conn=1521410 TLS1.2 128-bit AES-GCM
[03/Jul/2019:11:31:08 -1000] conn=1521410 op=0 BIND dn="" method=128 version=3
[03/Jul/2019:11:31:08 -1000] conn=1521410 op=0 RESULT err=0 tag=97 nentries=0
etime=0 dn=""
[03/Jul/2019:11:31:08 -1000] conn=1521410 op=1 SRCH base="dc=hawaii,dc=edu"
scope=0 filter="(objectClass=*)" attrs="1.1"
[03/Jul/2019:11:31:08 -1000] conn=1521410 op=1 RESULT err=0 tag=101
nentries=0 etime=0
[03/Jul/2019:11:31:08 -1000] conn=1521410 op=2 UNBIND
[03/Jul/2019:11:31:08 -1000] conn=1521410 op=2 fd=208 closed - U1
=====

Any ideas or suggestions would be appreciated.

* Minor typo, but stack trace exception says "Problem with ldap conection",
should presumably be "connection".
--
Baron Fujimoto <> :: UH Information Technology Services
minutas cantorum, minutas balorum, minutas carboratum desendus pantorum



Archive powered by MHonArc 2.6.19.

Top of Page