[Building Sakai] Sakai 2.9.1 and tomcat 7

Fatemeh Asl aa2821 at nyumc.org
Tue Mar 19 09:20:39 PDT 2013


we do have a LDAP server. 
I disabled the CAS part and now only JLDAP is enabled. As long as I enter my
 correct ldap id and password, it logs me in and every things seems OK.
 when I enter some wrong username as well as wrong password, it also
 works as expected and hints wrong credential. But when I enter 'admin'
 (which is an existing username) and rather than entering the correct
 password i enter some wrong password it blows up:


2013-03-19 11:51:08,278 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user
.JLDAPDirectoryProvider - authenticateUser(): [userLogin = admin]
2013-03-19 11:51:08,278 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user
.JLDAPDirectoryProvider - authenticateUser(): allocating connection
 for login [userLogin = admin]
2013-03-19 11:51:08,278 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user
.SimpleLdapConnectionManager - getConnection()
2013-03-19 11:51:08,288 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user
.SimpleLdapConnectionManager - applyConstraints(): values [timeout = 5000]
[follow referrals = true]
2013-03-19 11:51:08,288 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user
.SimpleLdapConnectionManager - connect()
2013-03-19 11:51:08,365 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user
.SimpleLdapConnectionManager - postConnect()
2013-03-19 11:51:08,369 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user
.SimpleLdapConnectionManager - getConnection(): auto-binding
2013-03-19 11:51:08,369 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user
.SimpleLdapConnectionManager - bind(): binding 
[dn = CN=sak29svc01,OU=Service Accounts,
OU=Users,OU=Hospital,DC=unimc,DC=org]
2013-03-19 11:51:08,681 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user
.JLDAPDirectoryProvider - lookupUserEntryDN(): [eid = admin][reusing conn = true]
2013-03-19 11:51:08,681 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user
.JLDAPDirectoryProvider - getUserByEid(): [eid = admin]
2013-03-19 11:51:08,681 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user
.JLDAPDirectoryProvider - getCachedUserEntry(): [eid = admin]
2013-03-19 11:51:08,681 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user
.JLDAPDirectoryProvider - getCachedUserEntry(): cache access
 [found entry = false][entry expired = false]
2013-03-19 11:51:08,681 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user
.JLDAPDirectoryProvider - searchDirectoryForSingleEntry(): 
[filter = cn=admin][reusing conn = true]
2013-03-19 11:51:08,681 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user
.JLDAPDirectoryProvider - searchDirectory(): [filter = cn=admin]
[reusing conn = true]
2013-03-19 11:51:08,682 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user.
JLDAPDirectoryProvider - FATEMEH: ---- 
2013-03-19 11:51:08,682 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user
.JLDAPDirectoryProvider - searchDirectory(): [baseDN = DC=unimc,DC=org]
[filter = cn=admin][return attribs = [cn, distinguishedName, givenName,
 sn, mail, groupMembership]][max results = 1]][search scope = 2]
2013-03-19 11:51:08,965 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user.J
LDAPDirectoryProvider - FATEMEH: ---- before getting the searchResults.next() 
2013-03-19 11:51:08,968 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user.J
LDAPDirectoryProvider - FATEMEH: ---- The LDAPException was 1
2013-03-19 11:51:08,968 DEBUG ajp-bio-9110-exec-8 edu.amc.sakai.user.J
LDAPDirectoryProvider - authenticateUser(): returning connection to
 connection manager
2013-03-19 11:51:08,991  WARN ajp-bio-9110-exec-8 org.
sakaiproject.portal.util.
ErrorReporter - Bug Report bug-id: 2f859646-9a99-4332-8aaf-fa3c76fd74f9
 user: null usage-session: null time: Mar 19, 2013 11:51:08 user comment:
  null stack trace
org.sakaiproject.portal.api.PortalHandlerException: java.lang.RuntimeException:
 authenticateUser(): LDAPException during authentication attempt 
 [userLogin = admin][result code = Operations Error][error message =
  000004DC: LdapErr: DSID-0C0906E8, comment: In order to perform this
   operation a successful bind must be completed on the connection.,
    data 0, v1db1]
    at org.sakaiproject.portal.charon.handlers.XLoginHandler.
    doPost(XLoginHandler.java:50)
caused by: java.lang.RuntimeException: authenticateUser(): 
LDAPException during authentication attempt [userLogin = admin]
[result code = Operations Error][error message = 000004DC: LdapErr:
 DSID-0C0906E8, comment: In order to perform this operation a successful
  bind must be completed on the connection., data 0, v1db1]
    at org.sakaiproject.user.impl.BaseUserDirectoryService.
    getProviderAuthenticatedUser(BaseUserDirectoryService.java:1597)
caused by: LDAPException: Operations Error (1) Operations Error
LDAPException: Server Message: 000004DC: LdapErr: DSID-0C0906E8, 
comment: In order to perform this operation a successful bind must be
 completed on the connection., data 0, v1db1
LDAPException: Matched DN: 
    at com.novell.ldap.LDAPResponse.getResultException(null:-1)
    at com.novell.ldap.LDAPResponse.chkResultCode(null:-1)
    at com.novell.ldap.LDAPSearchResults.next(null:-1)
    at edu.amc.sakai.user.JLDAPDirectoryProvider.searchDirectory
    (JLDAPDirectoryProvider.java:1020)
    at edu.amc.sakai.user.JLDAPDirectoryProvider.
    searchDirectoryForSingleEntry(JLDAPDirectoryProvider.java:895)
    at edu.amc.sakai.user.JLDAPDirectoryProvider.
    getUserByEid(JLDAPDirectoryProvider.java:817)
    at edu.amc.sakai.user.JLDAPDirectoryProvider.
    lookupUserBindDn(JLDAPDirectoryProvider.java:859)
    at edu.amc.sakai.user.JLDAPDirectoryProvider.
    authenticateUser(JLDAPDirectoryProvider.java:424)
    at org.sakaiproject.user.impl.BaseUserDirectoryService.
    getProviderAuthenticatedUser(BaseUserDirectoryService.java:1597)
    at org.sakaiproject.user.impl.BaseUserDirectoryService.
    authenticate(BaseUserDirectoryService.java:1540)
    at org.sakaiproject.user.impl.UserAuthnComponent.
    authenticate(UserAuthnComponent.java:108)
    at org.sakaiproject.login.impl.LoginServiceComponent.
    authenticate(LoginServiceComponent.java:90)
    at org.sakaiproject.login.tool.SkinnableLogin.doPost
    (SkinnableLogin.java:250)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:647)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter
    (ApplicationFilterChain.java:305)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter
(ApplicationFilterChain.java:210)
    at org.sakaiproject.util.RequestFilter.doFilter(RequestFilter.java:634)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter
    (ApplicationFilterChain.java:243)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter
    (ApplicationFilterChain.java:210)
    at org.apache.catalina.core.ApplicationDispatcher.invoke
    (ApplicationDispatcher.java:749)
    at org.apache.catalina.core.ApplicationDispatcher.processRequest
    (ApplicationDispatcher.java:487)
    at org.apache.catalina.core.ApplicationDispatcher.doForward
    (ApplicationDispatcher.java:379)
    at org.apache.catalina.core.ApplicationDispatcher.forward
    (ApplicationDispatcher.java:339)
    at org.sakaiproject.tool.impl.ActiveToolComponent$MyActiveTool.
    help(ActiveToolComponent.java:581)
    at org.sakaiproject.portal.charon.SkinnableCharonPortal.doLogin
    (SkinnableCharonPortal.java:972)
    at org.sakaiproject.portal.charon.handlers.XLoginHandler.doGet
    (XLoginHandler.java:61)
    at org.sakaiproject.portal.charon.handlers.XLoginHandler.doPost
    (XLoginHandler.java:50)
    at org.sakaiproject.portal.charon.SkinnableCharonPortal.doPost
    (SkinnableCharonPortal.java:1260)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:647)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter
    (ApplicationFilterChain.java:305)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter
    (ApplicationFilterChain.java:210)
    at org.sakaiproject.util.RequestFilter.doFilter
    (RequestFilter.java:695)
    at org.apache.catalina.core.ApplicationFilterChain.
    internalDoFilter(ApplicationFilterChain.java:243)
    at org.apache.catalina.core.ApplicationFilterChain.
    doFilter(ApplicationFilterChain.java:210)
    at org.apache.catalina.core.StandardWrapperValve.invoke
    (StandardWrapperValve.java:222)
    at org.apache.catalina.core.StandardContextValve.invoke
    (StandardContextValve.java:123)
    at org.apache.catalina.authenticator.AuthenticatorBase.
    invoke(AuthenticatorBase.java:472)
    at org.apache.catalina.core.StandardHostValve.invoke
    (StandardHostValve.java:171)
    at org.apache.catalina.valves.ErrorReportValve.invoke
    (ErrorReportValve.java:99)
    at org.apache.catalina.valves.AccessLogValve.invoke
    (AccessLogValve.java:936)
    at org.apache.catalina.core.StandardEngineValve.invoke
    (StandardEngineValve.java:118)
    at org.apache.catalina.connector.CoyoteAdapter.service
    (CoyoteAdapter.java:407)
    at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:200)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.
    process(AbstractProtocol.java:589)
    at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.
    run(JIoEndpoint.java:310)
    at java.util.concurrent.ThreadPoolExecutor$Worker.
    runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.
    run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)

Tool Placement:
No Placement

Request:
:    AuthType:null
:    CharEncoding:UTF-8
:    ContentLength:35
:    ContentType:application/x-www-form-urlencoded
:    ContextPath:/portal
:    LocalAddress:sak29dev.med.uni.edu
:    LocalName:sak29dev.med.uni.edu
:    LocalPort:80
:    Method:POST
:    PathInfo:/xlogin
:    Protocol:HTTP/1.1
:    QueryString:null
:    RemoteAddress:10.165.36.62
:    RemoteHost:10.165.36.62
:    RemotePort:55936
:    Requested URL:http://sak29dev.med.uni.edu/portal/xlogin
:    Scheme:http
:    ServerName:sak29dev.med.uni.edu
:    Headers:
:        Header:host:sak29dev.med.uni.edu
:        Header:user-agent:Mozilla/5.0 
(Macintosh; Intel Mac OS X 10.7; rv:19.0)
 Gecko/20100101 Firefox/19.0
:        Header:accept:text/html,application/xhtml+xml,application
/xml;q=0.9,*/*;q=0.8
:        Header:accept-language:en-US,en;q=0.5
:        Header:accept-encoding:gzip, deflate
:        Header:referer:http://sak29dev.med.uni.edu/portal/
:        Header:cookie:---censored---
:        Header:connection:keep-alive
:        Header:content-type:application/x-www-form-urlencoded
:        Header:content-length:35
:    Parameters:
:        Parameter:submit:0:Login
:        Parameter:pw:0:----censored----
:        Parameter:eid:0:----censored----
:    Attributes:
:        Attribute:sakai.character.encoding.done:sakai.character.encoding.done
:        Attribute:sakai.filtered:sakai.filtered
:        Attribute:sakai.session:org.sakaiproject.tool.impl.MySession at 1beb40bd
Session:
:    Created:1363708255945
:    LastAccess:1363708268984
:    MaxInactive:3600
:    Attributes:
:        Attribute:portalskin:neoskin

2013-03-19 11:51:08,994  WARN ajp-bio-9110-exec-8 org.sakaiproject.
email.impl.BasicEmailService - send: javax.mail.internet.AddressException:
 Illegal address in string ``''




I left some marks in the code and I know that it blows right 
exactly after calling searchResults.next():


  LDAPSearchResults searchResults = conn.search(
        searchBaseDn, searchScope, 
	filter, searchResultPhysicalAttributeNames,
        false, constraints);

   while ( searchResults.hasMore() ) {
	LDAPEntry entry = searchResults.next();
	Object mappedResult = mapper.mapLdapEntry(entry, ++resultCnt);
	if ( mappedResult == null ) {
	      continue;
	}
	mappedResults.add((LdapUserData) mappedResult);
	}

which is part of JLDAPDirectoryProvier searchDirectory method.
And I know that the conn instance is bound to the correct ldap server.
Any idea please?

Thanks
Fatemeh



More information about the sakai-dev mailing list