0

We are facing an issue with our webapp deployed on Tomcat 7. Users are getting kicked out of the system even when its not under load. This is also happening when we run the application locally within eclipse.

The application uses Spring Security 3.2.5 to authenticate users. After successful login the application throws user out to the login page intermittently.

The logs show the message repeatedly 

2014-12-11 13:05:56 DEBUG ExceptionTranslationFilter:115 - Chain processed normally
2014-12-11 13:05:56 DEBUG SecurityContextPersistenceFilter:97 - SecurityContextHolder now cleared, as request processing completed
2014-12-11 13:06:06 DEBUG FilterChainProxy:337 - /productsearch/landingpage at position 1 of 11 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
2014-12-11 13:06:06 DEBUG HttpSessionSecurityContextRepository:152 - HttpSession returned null object for SPRING_SECURITY_CONTEXT
2014-12-11 13:06:06 DEBUG HttpSessionSecurityContextRepository:91 - No SecurityContext was available from the HttpSession: org.apache.catalina.session.StandardSessionFacade@13f57a03. A new one will be created.

Does this mean that the security context is been cleared all of a sudden which will invalidate the session ? Later on when it tries to recreate the session it does it as a anonymous user after which an access denied Exception is thrown. See Detailed Logs below

I have tried using the solution listed here but it didn't work. Any help regarding this would be great.

Thanks,
Dhananjay

Here are the detailed Logs:

2014-12-11 13:05:56 DEBUG ExceptionTranslationFilter:115 - Chain processed normally
2014-12-11 13:05:56 DEBUG SecurityContextPersistenceFilter:97 - SecurityContextHolder now cleared, as request processing completed
2014-12-11 13:06:06 DEBUG FilterChainProxy:337 - /productsearch/landingpage at position 1 of 11 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
2014-12-11 13:06:06 DEBUG HttpSessionSecurityContextRepository:152 - HttpSession returned null object for SPRING_SECURITY_CONTEXT
2014-12-11 13:06:06 DEBUG HttpSessionSecurityContextRepository:91 - No SecurityContext was available from the HttpSession: org.apache.catalina.session.StandardSessionFacade@13f57a03. A new one will be created.
2014-12-11 13:06:06 DEBUG FilterChainProxy:337 - /productsearch/landingpage at position 2 of 11 in additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
2014-12-11 13:06:06 DEBUG FilterChainProxy:337 - /productsearch/landingpage at position 3 of 11 in additional filter chain; firing Filter: 'LogoutFilter'
2014-12-11 13:06:06 DEBUG FilterChainProxy:337 - /productsearch/landingpage at position 4 of 11 in additional filter chain; firing Filter: 'UsernamePasswordAuthenticationFilter'
2014-12-11 13:06:06 DEBUG FilterChainProxy:337 - /productsearch/landingpage at position 5 of 11 in additional filter chain; firing Filter: 'BasicAuthenticationFilter'
2014-12-11 13:06:06 DEBUG FilterChainProxy:337 - /productsearch/landingpage at position 6 of 11 in additional filter chain; firing Filter: 'RequestCacheAwareFilter'
2014-12-11 13:06:06 DEBUG DefaultSavedRequest:331 - pathInfo: arg1=/productsearch/clearSessionProducts; arg2=/productsearch/landingpage (property not equals)
2014-12-11 13:06:06 DEBUG HttpSessionRequestCache:75 - saved request doesn't match
2014-12-11 13:06:06 DEBUG FilterChainProxy:337 - /productsearch/landingpage at position 7 of 11 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter'
2014-12-11 13:06:06 DEBUG FilterChainProxy:337 - /productsearch/landingpage at position 8 of 11 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
2014-12-11 13:06:06 DEBUG AnonymousAuthenticationFilter:102 - Populated SecurityContextHolder with anonymous token: 'org.springframework.security.authentication.AnonymousAuthenticationToken@6faa3d44: Principal: anonymousUser; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffff4c9c: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: 0EBEF4FC60DFCD59AB3086A0B8185FE6; Granted Authorities: ROLE_ANONYMOUS'
2014-12-11 13:06:06 DEBUG FilterChainProxy:337 - /productsearch/landingpage at position 9 of 11 in additional filter chain; firing Filter: 'SessionManagementFilter'
2014-12-11 13:06:06 DEBUG FilterChainProxy:337 - /productsearch/landingpage at position 10 of 11 in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
2014-12-11 13:06:06 DEBUG FilterChainProxy:337 - /productsearch/landingpage at position 11 of 11 in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/login/view'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/login/forgotpassword'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/login/welcome'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/login/contactus'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/login/getstarted'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/login/getimage'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/login/getfooter'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/login/resetpassword'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/bgx_resources/foundation/js/login/**'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/bgx_resources/foundation/css/**'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/extjs-3.4/**'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/resources/**'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/layout/**'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/images/**'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/files/**'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/home/termsofuse'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/home/privacypolicy'
2014-12-11 13:06:06 DEBUG AntPathRequestMatcher:145 - Checking match of request : '/productsearch/landingpage'; against '/custom-javascript-files/b2b/scroller/**'
2014-12-11 13:06:06 DEBUG FilterSecurityInterceptor:194 - Secure object: FilterInvocation: URL: /productsearch/landingpage; Attributes: [hasRole('ROLE_USER')]
2014-12-11 13:06:06 DEBUG FilterSecurityInterceptor:310 - Previously Authenticated: org.springframework.security.authentication.AnonymousAuthenticationToken@6faa3d44: Principal: anonymousUser; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffff4c9c: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: 0EBEF4FC60DFCD59AB3086A0B8185FE6; Granted Authorities: ROLE_ANONYMOUS
2014-12-11 13:06:06 DEBUG AffirmativeBased:65 - Voter: org.springframework.security.web.access.expression.WebExpressionVoter@144c61b3, returned: -1
2014-12-11 13:06:06 DEBUG ExceptionTranslationFilter:165 - Access is denied (user is anonymous); redirecting to authentication entry point
org.springframework.security.access.AccessDeniedException: Access is denied
    at org.springframework.security.access.vote.AffirmativeBased.decide(AffirmativeBased.java:83)
    at org.springframework.security.access.intercept.AbstractSecurityInterceptor.beforeInvocation(AbstractSecurityInterceptor.java:206)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:115)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:103)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:113)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:154)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilter(BasicAuthenticationFilter.java:150)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:199)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:110)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:50)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192)
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160)
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:344)
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:261)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:503)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:421)
    at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1070)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611)
    at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:745)

Here is the Security Config:

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:security="http://www.springframework.org/schema/security"
    xsi:schemaLocation="
            http://www.springframework.org/schema/beans 
            http://www.springframework.org/schema/beans/spring-beans-3.2.xsd
            http://www.springframework.org/schema/security
            http://www.springframework.org/schema/security/spring-security-3.2.xsd">        
        <bean id="authenticationEntryPoint" class="com.myapp.security.CustomAuthEntryPoint">
            <property name="loginFormUrl" value="/login/view" />
            <property name="redirectURL" value="/login/view" />
        </bean>
    <security:http auto-config="true" entry-point-ref="authenticationEntryPoint" disable-url-rewriting="true" use-expressions="true">
        <!-- All Login Page related resources , Allow all to access this -->
        <security:intercept-url pattern="/login/**" access="permitAll"/>
        <security:intercept-url pattern="/myapp_resources/foundation/js/login/**" access="permitAll"/>
        <security:intercept-url pattern="/myapp_resources/foundation/css/**" access="permitAll"/>
        <security:intercept-url pattern="/extjs-3.4/**" access="permitAll"/>
        <security:intercept-url pattern="/resources/**" access="permitAll"/>
        <security:intercept-url pattern="/layout/**" access="permitAll"/>
        <security:intercept-url pattern="/images/**" access="permitAll"/>

        <!-- Application protected area -->
        <security:intercept-url pattern="/**" access="hasRole('ROLE_USER')" />

        <security:form-login login-page="/login/view" default-target-url="/myapp/v13" always-use-default-target="true"
            authentication-failure-url="/login/view"/>
        <security:logout logout-success-url="/logout"/>
    </security:http>


    <security:authentication-manager alias="authenticationManager">
    <security:authentication-provider
   ref="authenticationProvider"></security:authentication-provider>
 </security:authentication-manager>

 <bean id="authenticationProvider" class="com.myapp.security.CustomAuthenticationProvider">
 </bean>

Update 12/17/2014: Getting the same error when we deploy our application to Jboss6 , so this may not be Tomcat Specific

Community
  • 1
  • 1
Dhananjay
  • 642
  • 6
  • 15
  • Session timeout after x minutes of inactivity? – holmis83 Dec 11 '14 at 20:09
  • Its not timeout. User gets kicked out of the application while browsing and gets redirected to the Login Page. – Dhananjay Dec 11 '14 at 20:35
  • Seems like a hard nut to crack but the security configuration may be relevant. – holmis83 Dec 11 '14 at 21:31
  • @holmis83 I have added the Security Config that I am using. – Dhananjay Dec 11 '14 at 21:43
  • I suspect that you are losing your authentication when the application switches to a new thread. You can check for this by adding the thread ID to your logging output. For example, with log4j you can add "%t to your ConversionPattern. – Bampfer Dec 15 '14 at 23:36
  • @Bampfer The application is switching threads when I turned the debug mode on. Still dont get how can i loose auth. Does this mean I have to tweak http connector settings? – Dhananjay Dec 17 '14 at 15:43
  • I can tell you what fixed it for me, but not why. I installed my web application as ROOT.war instead of something else. Suddenly it all worked! My theory is that the recipes I was following for what config lines to add to web.xml and spring-security.xml were assuming root... I need to understand those settings better, which paths if any are relative to the web app's URL and which are absolute... In the meantime, at least you have a more specific symptom now. Sorry I don't have more. – Bampfer Dec 19 '14 at 03:05
  • Tried installing the application as ROOT.war still no luck :( – Dhananjay Jan 23 '15 at 16:35
  • @DhananjayBakore I'm having same issue. My customers sessions are being kicked out randomly. App specs: JDK 7.0.72, Spring 2.5. Any luck? – Ramiz Uddin Jan 26 '15 at 18:27

1 Answers1

0

It appears it had to do something with the Batch Jobs we had created within the same application. (Using Quartz Scheduler). Disabling the jobs fixed this issue.

It appears that the Quartz scheduler was creating new threads which was making the application switch to newly created threads.

Dhananjay
  • 642
  • 6
  • 15