Internal Server Error on Successful LDAP Login

[rusty.ross]

I have LDAP external authentication (via Active Directory) working in JRS 5.2.

Users can successfully log in with their external credentials. However, immediately upon login, the user is initially shown a page that says, "Internal server error occured. Please contact your system administrator."

The logged in user can then proceed to click anywhere to which he has been granted access (ie: Library) and from there, JRS functions normally for the logged in user. 

But obviously, I need to eliminate the error page that appears right after login.

Here are the logs that show this happening. I've highlighted what I would guess to be the relevant lines in red:

2013-11-09 16:09:38,368 DEBUG FilterBasedLdapUserSearch,http-bio-80-exec-2:109 - Searching for user 'TESTLDAPUSER', with user search [ searchFilter: '(sAMAccountName={0})', searchBase: 'ou=Users', scope: subtree, searchTimeLimit: 0, derefLinkFlag: false ]

13/11/09 16:09:38 DEBUG search.FilterBasedLdapUserSearch: Searching for user 'TESTLDAPUSER', with user search [ searchFilter: '(sAMAccountName={0})', searchBase: 'ou=Users', scope: subtree, searchTimeLimit: 0, derefLinkFlag: false ]

2013-11-09 16:09:39,062 DEBUG SpringSecurityLdapTemplate,http-bio-80-exec-2:197 - Searching for entry in under DN 'dc=mycompany,dc=com', base = 'ou=Users', filter = '(sAMAccountName={0})'

13/11/09 16:09:39 DEBUG ldap.SpringSecurityLdapTemplate: Searching for entry in under DN 'dc=mycompany,dc=com', base = 'ou=Users', filter = '(sAMAccountName={0})'

2013-11-09 16:09:39,338 DEBUG SpringSecurityLdapTemplate,http-bio-80-exec-2:214 - Found DN: cn=TESTLDAPUSER,ou=Users

13/11/09 16:09:39 DEBUG ldap.SpringSecurityLdapTemplate: Found DN: cn=TESTLDAPUSER,ou=Users

2013-11-09 16:09:40,033 DEBUG DefaultLdapAuthoritiesPopulator,http-bio-80-exec-2:176 - Getting authorities for user cn=TESTLDAPUSER,ou=Users,dc=mycompany,dc=com

13/11/09 16:09:40 DEBUG populator.DefaultLdapAuthoritiesPopulator: Getting authorities for user cn=TESTLDAPUSER,ou=Users,dc=mycompany,dc=com

2013-11-09 16:09:40,035 DEBUG DefaultLdapAuthoritiesPopulator,http-bio-80-exec-2:202 - Searching for roles for user 'TESTLDAPUSER', DN = 'cn=TESTLDAPUSER,ou=Users,dc=mycompany,dc=com', with filter (&(objectClass=group)(member={0})) in search base 'OU=Groups'

13/11/09 16:09:40 DEBUG populator.DefaultLdapAuthoritiesPopulator: Searching for roles for user 'TESTLDAPUSER', DN = 'cn=TESTLDAPUSER,ou=Users,dc=mycompany,dc=com', with filter (&(objectClass=group)(member={0})) in search base 'OU=Groups'

2013-11-09 16:09:40,036 DEBUG SpringSecurityLdapTemplate,http-bio-80-exec-2:148 - Using filter: (&(objectClass=group)(member=cn=TESTLDAPUSER,ou=Users,dc=mycompany,dc=com))

13/11/09 16:09:40 DEBUG ldap.SpringSecurityLdapTemplate: Using filter: (&(objectClass=group)(member=cn=TESTLDAPUSER,ou=Users,dc=mycompany,dc=com))

13/11/09 16:09:40 INFO core.LdapTemplate: The returnObjFlag of supplied SearchControls is not set but a ContextMapper is used - setting flag to true

2013-11-09 16:09:40,710 DEBUG DefaultLdapAuthoritiesPopulator,http-bio-80-exec-2:210 - Roles from search: []

13/11/09 16:09:40 DEBUG populator.DefaultLdapAuthoritiesPopulator: Roles from search: []

13/11/09 16:09:40 WARN authentication.LoggerListener: Authentication event AuthenticationSuccessEvent: TESTLDAPUSER; details: com.jaspersoft.jasperserver.multipleTenancy.MTWebAuthenticationDetails@0: RemoteIpAddress: 10.0.100.105; SessionId: 9926F3819993EAA85F9E8FAA4C353EA0

2013-11-09 16:09:40,730 DEBUG LdapExternalTenantProcessor,http-bio-80-exec-2:39 - LDAP Tenant Setup Processor starting synchronization.

13/11/09 16:09:40 DEBUG ldap.LdapExternalTenantProcessor: LDAP Tenant Setup Processor starting synchronization.

2013-11-09 16:09:40,732  INFO LdapExternalTenantProcessor,http-bio-80-exec-2:47 - LDAP Tenant Setup Processor distinguished name: cn=TESTLDAPUSER,ou=Users,dc=mycompany,dc=com

13/11/09 16:09:40 INFO ldap.LdapExternalTenantProcessor: LDAP Tenant Setup Processor distinguished name: cn=TESTLDAPUSER,ou=Users,dc=mycompany,dc=com

2013-11-09 16:09:41,051 DEBUG UserMultiTenancyContextProvider,http-bio-80-exec-2:64 - Creating multi tenancy context for org.springframework.security.providers.UsernamePasswordAuthenticationToken@4c4fa932: Principal: org.springframework.security.userdetails.ldap.LdapUserDetailsImpl@4e7d6ca2: Username: TESTLDAPUSER; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: ROLE_LDAPUSER; Password: [PROTECTED]; Authenticated: true; Details: com.jaspersoft.jasperserver.multipleTenancy.MTWebAuthenticationDetails@0: RemoteIpAddress: 10.0.100.105; SessionId: 9926F3819993EAA85F9E8FAA4C353EA0; Granted Authorities: ROLE_LDAPUSER

13/11/09 16:09:41 DEBUG multipleTenancy.UserMultiTenancyContextProvider: Creating multi tenancy context for org.springframework.security.providers.UsernamePasswordAuthenticationToken@4c4fa932: Principal: org.springframework.security.userdetails.ldap.LdapUserDetailsImpl@4e7d6ca2: Username: TESTLDAPUSER; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: ROLE_LDAPUSER; Password: [PROTECTED]; Authenticated: true; Details: com.jaspersoft.jasperserver.multipleTenancy.MTWebAuthenticationDetails@0: RemoteIpAddress: 10.0.100.105; SessionId: 9926F3819993EAA85F9E8FAA4C353EA0; Granted Authorities: ROLE_LDAPUSER

2013-11-09 16:09:41,053 DEBUG UserMultiTenancyContextProvider,http-bio-80-exec-2:96 - Context authentication is not a MetadataUserDetails, treating as no tenant

13/11/09 16:09:41 DEBUG multipleTenancy.UserMultiTenancyContextProvider: Context authentication is not a MetadataUserDetails, treating as no tenant

2013-11-09 16:09:41,055  INFO LdapExternalTenantProcessor,http-bio-80-exec-2:70 - User cn=TESTLDAPUSER,ou=Users,dc=mycompany,dc=com parent organization is: organization_1

13/11/09 16:09:41 INFO ldap.LdapExternalTenantProcessor: User cn=TESTLDAPUSER,ou=Users,dc=mycompany,dc=com parent organization is: organization_1

2013-11-09 16:09:41,063 DEBUG MTUserAuthorityServiceImpl,http-bio-80-exec-2:136 - No such user as: TESTLDAPUSER in tenant organization_1

13/11/09 16:09:41 DEBUG multipleTenancy.MTUserAuthorityServiceImpl: No such user as: TESTLDAPUSER in tenant organization_1

13/11/09 16:09:41 WARN processors.ExternalUserSetupProcessor: Created new external user: TESTLDAPUSER

13/11/09 16:09:41 INFO processors.ExternalUserSetupProcessor: Starting align for user: TESTLDAPUSER with remoteExternalUserRoles at size of 1

13/11/09 16:09:41 WARN authentication.LoggerListener: Authentication event InteractiveAuthenticationSuccessEvent: TESTLDAPUSER; details: com.jaspersoft.jasperserver.multipleTenancy.MTWebAuthenticationDetails@0: RemoteIpAddress: 10.0.100.105; SessionId: 9926F3819993EAA85F9E8FAA4C353EA0

2013-11-09 16:09:41,408 DEBUG MTUserAuthorityServiceImpl,http-bio-80-exec-7:136 - No such user as: TESTLDAPUSER in tenant null

13/11/09 16:09:41 DEBUG multipleTenancy.MTUserAuthorityServiceImpl: No such user as: TESTLDAPUSER in tenant null

13/11/09 16:09:41 ERROR control.SystemErrorController: Internal server error

java.lang.NullPointerException

at com.jaspersoft.jasperserver.multipleTenancy.MTUserAuthorityServiceImpl.isPasswordExpired(MTUserAuthorityServiceImpl.java:587)

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:616)

at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:318)

at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)

at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)

at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)

at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)

at sun.proxy.$Proxy31.isPasswordExpired(Unknown Source)

at com.jaspersoft.jasperserver.multipleTenancy.MTUserPreferencesFilter.isPasswordExpired(MTUserPreferencesFilter.java:36)

at com.jaspersoft.jasperserver.war.UserPreferencesFilter.doFilter(UserPreferencesFilter.java:198)

at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:411)

at com.jaspersoft.jasperserver.api.logging.filter.BasicLoggingFilter.doFilter(BasicLoggingFilter.java:53)

at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:411)

at com.jaspersoft.jasperserver.api.security.JSCsrfGuardFilter.doFilter(JSCsrfGuardFilter.java:83)

at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:411)

at com.jaspersoft.jasperserver.api.security.WebAppSecurityFilter.doFilter(WebAppSecurityFilter.java:76)

at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:411)

at com.jaspersoft.jasperserver.war.MultipartRequestWrapperFilter.doFilter(MultipartRequestWrapperFilter.java:90)

at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:411)

at com.jaspersoft.jasperserver.api.security.encryption.EncryptionFilter.doFilter(EncryptionFilter.java:130)

at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:411)

at org.springframework.security.context.HttpSessionContextIntegrationFilter.doFilterHttp(HttpSessionContextIntegrationFilter.java:235)

at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)

at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:411)

at org.springframework.security.util.FilterChainProxy.doFilter(FilterChainProxy.java:188)

at org.springframework.security.util.FilterToBeanProxy.doFilter(FilterToBeanProxy.java:99)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)

at com.jaspersoft.jasperserver.war.util.SessionDecoratorFilter.doFilter(SessionDecoratorFilter.java:43)

at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346)

at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:259)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)

at com.jaspersoft.jasperserver.war.util.CharacterEncodingFilter.doFilter(CharacterEncodingFilter.java:67)

at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346)

at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:259)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)

at com.jaspersoft.jasperserver.war.P3PFilter.doFilter(P3PFilter.java:43)

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:581)

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:953)

at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)

at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)

at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1008)

at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:589)

at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:312)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

at java.lang.Thread.run(Thread.java:679)

 

Here is ldapExternalTenantProcessor from applicationContext-externalAuth-LDAP-mt.xml:

(Note that I am mapping all logins into a single default organization.)

    <bean id="ldapExternalTenantProcessor" class="com.jaspersoft.jasperserver.multipleTenancy.security.externalAuth.processors.ldap.LdapExternalTenantProcessor" parent="abstractExternalProcessor">        <property name="ldapContextSource" ref="ldapContextSource"/>        <property name="multiTenancyService"><ref bean="internalMultiTenancyService"/></property>        <property name="excludeRootDn" value="true"/>        <property name="organizationRDNs"><list /></property>  <property name="rootOrganizationId" value="organization_1" />  <property name="defaultOrganization" value="organization_1"/>    </bean>[/code]

The full applicationContext-externalAuth-LDAP-mt.xml is attached below.

Any insight into what's going on here?

 

Thanks.

 

[rusty.ross]

I can now confirm that I have also tested this in 5.5 with the exact same error and log results.

 

[dlitvak]

After auth happens, what organization do you see the external user TESTLDAPUSER created under? Should be organization_1.

What case does the username have in the database and what username is entered in login form? TESTLDAPUSER? It could be case sensitive depending on configuration. isUsernameCaseSensitive property of UserAuthorityServiceImpl bean is false by default.

Please describe what exact steps you perform to authenticate the user.  Any unusual configs?

A thing to try would be to add orgId=organization_1 parameter to the login.html url.

Please report your findings here.  This might be a bug that we need to address.

Thank you!

 

 

 

[rusty.ross]

"After auth happens, what organization do you see the external user TESTLDAPUSER created under? Should be organization_1."

 

Yes, TESTLDAPUSER is created under organization_1.

 

 

"What case does the username have in the database and what username is entered in login form? TESTLDAPUSER? It could be case sensitive depending on configuration." 

 

TESTLDAPUSER is all caps in the database, and that is what is being entered in the web login. As a test, I also tried using all lowercase in the web login, and the results were the same.

 

"isUsernameCaseSensitive property of UserAuthorityServiceImpl bean is false by default."

 

This property is not set, so I trust the default active.

 

"Please describe what exact steps you perform to authenticate the user.  Any unusual configs?"

 

Nothing unusual. Full config "applicationcontext-externalauth-ldap-mt.xml" is attached to the original post if you want to take a look. No other custom config beyond what is in that document.

 

In terms of the login procedure itself, nothing unusual at all. Simply entering User ID and Password in the web login and pressing Login. I have tried leaving Organization blank and also filling Organization with "organization_1" with the same results for both cases.

 

 

"A thing to try would be to add orgId=organization_1 parameter to the login.html url."

 

Adding this parameter did have the effect of eliminating the Organization field from the web login form, but the error and results were the same after logging in.

 

 

"Please report your findings here.  This might be a bug that we need to address."

 

Please let me know what other info I can provide. Hoping to solve this! Much thanks.

 

 

[dlitvak]

Can I have you verify if allowUserPasswordChange is false in jasperserver-servlet.xml? If not, could you please set it to false and report what you see.

I will try to reproduce the same issue on my side.

The more I look at it, the more it looks like a bug.

[rusty.ross]

Okay, progress...

allowUserPasswordChange was actually set to true. This must be the default, since I hadn't previously touched jasperserver-servlet.xml.

I tried setting this to false, and the results were the same: Internal Server Error.

BUT... I tried again leaving allowUserPasswordChange=false and this time changing passwordExpirationInDays=365 to passwordExpirationInDays=-1, and this time, login succeeded with no Interal Server Error.

 

 

[dlitvak]

Ok, I will log a defect on our side.  Can you work around the issue for now?

 

[rusty.ross]

This does seem to be a workaround, yes.

I guess this would prevent any local (non-LDAP) users from being able to change their passwords, right? If so, for that reason, it is probably not a permanent workaround.

 

No matter what, if you could keep me posted on the status on your end, that would be extrememly helpful.

 

Thanks again for your help. It is much appreciated.

 

 

 

[rusty.ross]

Where would the appropriate place be to set the default login URL to contain the orgId parameter?

 

ie:

 

/login.html?orgId=organization_1

 

[dlitvak]

Actually, passwordExpirationInDays=0 and allowUserPasswordChange=false seem to be the defaults.  What you can do is set allowUserPasswordChange=true.  passwordExpirationInDays at 0 simply means that the password would never expire.

Not very sure how I can keep you posted as our bug db is not public facing.  I will talk to someone here.

 

 

 

[dlitvak]

FYI, the internal bug number is 35242.  The fix should be in the next release  Spring, 2014

[rusty.ross]

Thank you, that is helpful.

 

By the way, did you see my side question from above:

 

Where would the appropriate place be to set the default login URL to contain the orgId parameter?

ie:

/login.html?orgId=organization_1

 

 

[dlitvak]

Sorry, the subscribe feature has not notified me about your question.

I would change login.html in applicationContext-security-web.xml. Everywhere you find it, add orgId parameter.

[dlitvak]

If you plan an update of JRS in the future, it will be painful to remember to update the bean every time. Here is what you can try:

Create your own applicationContext-rusty.xml

<?xml version="1.0" encoding="UTF-8"?>

 

xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"

xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-2.0.xsd">

 

/login.html?orgId=RustyRoss

 

.... Other bean overrides for login.html ....

 

 

 

Drop this into the deployment after every install.

[dlitvak]

This is going to be fixed in 5.6 release. 5.6 has been scheduled for April.