Spring Security: SecurityContextHolder not populating correct user data in production
<p>I am using Spring Boot (version : 1.3.2) along with spring web and security.</p>
<p><strong>Scenario</strong>: I have an external authentication service, that issues OAuth2 tokens to clients trying to access API's of my spring app. To intercept and understand the token I have followed the configuration mentioned in <a href="http://technicalrex.com/2015/02/20/stateless-authentication-with-spring-security-and-jwt" rel="nofollow noreferrer">this</a> tutorial. This is a stateless REST Api JWT Token based authentication for spring security.</p>
<p><strong>Problem</strong>: Things are working for me when I run my app on localhost and try accessing the app from different browsers (incognito) mode. The problem arises when I deploy it to my Ubuntu 12.04 Server. Whenever I am trying to access methods marked @PreAuthorize(&quot;hasAnyRole('ADMIN')&quot;) I am getting a 401 although the user is logged in and authorised to use the API.</p>
<p><strong>Working Case Log from Localhost</strong>:</p>
<pre><code>2016-04-17 10:13:55 - Bound request context to thread: org.apache.catalina.connector.RequestFacade@4d531be5
2016-04-17 10:13:55 - Trying to match using Ant [pattern='/css/**']
2016-04-17 10:13:55 - Checking match of request : '/api/purchaseorders/get'; against '/css/**'
2016-04-17 10:13:55 - Trying to match using Ant [pattern='/js/**']
2016-04-17 10:13:55 - Checking match of request : '/api/purchaseorders/get'; against '/js/**'
2016-04-17 10:13:55 - Trying to match using Ant [pattern='/images/**']
2016-04-17 10:13:55 - Checking match of request : '/api/purchaseorders/get'; against '/images/**'
2016-04-17 10:13:55 - Trying to match using Ant [pattern='/**/favicon.ico']
2016-04-17 10:13:55 - Checking match of request : '/api/purchaseorders/get'; against '/**/favicon.ico'
2016-04-17 10:13:55 - Trying to match using Ant [pattern='/error']
2016-04-17 10:13:55 - Checking match of request : '/api/purchaseorders/get'; against '/error'
2016-04-17 10:13:55 - No matches found
2016-04-17 10:13:55 - /api/purchaseOrders/get at position 1 of 7 in additional filter chain; firing Filter: 'HeaderWriterFilter'
2016-04-17 10:13:55 - Not injecting HSTS header since it did not match the requestMatcher org.springframework.security.web.header.writers.HstsHeaderWriter$SecureRequestMatcher@54d08125
2016-04-17 10:13:55 - /api/purchaseOrders/get at position 2 of 7 in additional filter chain; firing Filter: 'StatelessAuthenticationFilter'
2016-04-17 10:13:55 - /api/purchaseOrders/get at position 3 of 7 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter'
2016-04-17 10:13:55 - /api/purchaseOrders/get at position 4 of 7 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
2016-04-17 10:13:55 - SecurityContextHolder not populated with anonymous token, as it already contained: 'com.mycompany.inventory.helpers.UserAuthentication@55ea85d9'
2016-04-17 10:13:55 - /api/purchaseOrders/get at position 5 of 7 in additional filter chain; firing Filter: 'SessionManagementFilter'
2016-04-17 10:13:55 - Delegating to org.springframework.security.web.authentication.session.ChangeSessionIdAuthenticationStrategy@1d3565e1
2016-04-17 10:13:55 - /api/purchaseOrders/get at position 6 of 7 in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
2016-04-17 10:13:55 - /api/purchaseOrders/get at position 7 of 7 in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
2016-04-17 10:13:55 - Checking match of request : '/api/purchaseorders/get'; against '/'
2016-04-17 10:13:55 - Checking match of request : '/api/purchaseorders/get'; against '/resources/**'
2016-04-17 10:13:55 - Checking match of request : '/api/purchaseorders/get'; against '/app/login/**'
2016-04-17 10:13:55 - Checking match of request : '/api/purchaseorders/get'; against '/api/**'
2016-04-17 10:13:55 - Secure object: FilterInvocation: URL: /api/purchaseOrders/get; Attributes: [fullyAuthenticated]
2016-04-17 10:13:55 - Previously Authenticated: com.mycompany.inventory.helpers.UserAuthentication@55ea85d9
2016-04-17 10:13:55 - Voter: org.springframework.security.web.access.expression.WebExpressionVoter@446e8d44, returned: 1
2016-04-17 10:13:55 - Authorization successful
2016-04-17 10:13:55 - RunAsManager did not change Authentication object
2016-04-17 10:13:55 - /api/purchaseOrders/get reached end of additional filter chain; proceeding with original chain
2016-04-17 10:13:55 - DispatcherServlet with name 'dispatcherServlet' processing GET request for [/api/purchaseOrders/get]
2016-04-17 10:13:55 - Looking up handler method for path /api/purchaseOrders/get
2016-04-17 10:13:55 - Did not find handler method for [/api/purchaseOrders/get]
2016-04-17 10:13:55 - Looking up handler method for path /api/purchaseOrders/get
2016-04-17 10:13:55 - Returning handler method [public org.springframework.http.ResponseEntity&lt;java.util.List&lt;com.mycompany.inventory.dto.PurchaseOrderDTO&gt;&gt; com.mycompany.inventory.rest.controllers.PurchaseOrderApiController.getAllPurchaseOrders()]
2016-04-17 10:13:55 - Returning cached instance of singleton bean 'purchaseOrderApiController'
2016-04-17 10:13:55 - Last-Modified value for [/api/purchaseOrders/get] is: -1
2016-04-17 10:13:55 - Opening JPA EntityManager in OpenEntityManagerInViewInterceptor
2016-04-17 10:13:55 - Secure object: ReflectiveMethodInvocation: public org.springframework.http.ResponseEntity com.mycompany.inventory.rest.controllers.PurchaseOrderApiController.getAllPurchaseOrders(); target is of class [com.mycompany.inventory.rest.controllers.PurchaseOrderApiController]; Attributes: [[authorize: 'hasAnyRole('ADMIN')', filter: 'null', filterTarget: 'null']]
2016-04-17 10:13:55 - Previously Authenticated: com.mycompany.inventory.helpers.UserAuthentication@55ea85d9
2016-04-17 10:13:55 - Voter: org.springframework.security.access.prepost.PreInvocationAuthorizationAdviceVoter@6bb04370, returned: 1
2016-04-17 10:13:55 - Authorization successful
2016-04-17 10:13:55 - RunAsManager did not change Authentication object
2016-04-17 10:13:55 - Found thread-bound EntityManager [org.hibernate.jpa.internal.EntityManagerImpl@64f555b5] for JPA transaction
2016-04-17 10:13:55 - Creating new transaction with name [com.mycompany.inventory.servicesImpl.PurchaseOrderServiceImpl.getPurchaseOrders]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2016-04-17 10:13:55 - Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@3400e582]
2016-04-17 10:13:55 - Found thread-bound EntityManager [org.hibernate.jpa.internal.EntityManagerImpl@64f555b5] for JPA transaction
2016-04-17 10:13:55 - Participating in existing transaction
2016-04-17 10:13:55 - Found thread-bound EntityManager [org.hibernate.jpa.internal.EntityManagerImpl@64f555b5] for JPA transaction
2016-04-17 10:13:55 - Participating in existing transaction
2016-04-17 10:13:55 - Initiating transaction commit
2016-04-17 10:13:55 - Committing JPA transaction on EntityManager [org.hibernate.jpa.internal.EntityManagerImpl@64f555b5]
2016-04-17 10:13:55 - Not closing pre-bound JPA EntityManager after transaction
2016-04-17 10:13:55 - Written [[]] as &quot;application/json;charset=UTF-8&quot; using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@76cde05c]
2016-04-17 10:13:55 - Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling
2016-04-17 10:13:55 - Closing JPA EntityManager in OpenEntityManagerInViewInterceptor
2016-04-17 10:13:55 - Closing JPA EntityManager
2016-04-17 10:13:55 - Successfully completed request
2016-04-17 10:13:55 - Chain processed normally
2016-04-17 10:13:55 - Cleared thread-bound request context: org.apache.catalina.connector.RequestFacade@4d531be5
</code></pre>
<p>As you can see:
<strong>SecurityContextHolder not populated with anonymous token, as it already contained: 'com.mycompany.inventory.helpers.UserAuthentication@55ea85d9'</strong></p>
<p>The security context in working case is reporting the presence of a user authentication already being present. Even though this works, I am wondering if this is the correct behaviour? Since my configuration is for a stateless session, why should the security context find an existing authentication entry in its context? Is this expected?</p>
<p><strong>Non-Working Case Log from Server</strong>:</p>
<pre><code>2016-04-17 04:40:19 - Bound request context to thread: org.apache.catalina.connector.RequestFacade@750475e2
2016-04-17 04:40:19 - Trying to match using Ant [pattern='/css/**']
2016-04-17 04:40:19 - Checking match of request : '/api/purchaseorders/get'; against '/css/**'
2016-04-17 04:40:19 - Trying to match using Ant [pattern='/js/**']
2016-04-17 04:40:19 - Checking match of request : '/api/purchaseorders/get'; against '/js/**'
2016-04-17 04:40:19 - Trying to match using Ant [pattern='/images/**']
2016-04-17 04:40:19 - Checking match of request : '/api/purchaseorders/get'; against '/images/**'
2016-04-17 04:40:19 - Trying to match using Ant [pattern='/**/favicon.ico']
2016-04-17 04:40:19 - Checking match of request : '/api/purchaseorders/get'; against '/**/favicon.ico'
2016-04-17 04:40:19 - Trying to match using Ant [pattern='/error']
2016-04-17 04:40:19 - Checking match of request : '/api/purchaseorders/get'; against '/error'
2016-04-17 04:40:19 - No matches found
2016-04-17 04:40:19 - /api/purchaseOrders/get at position 1 of 7 in additional filter chain; firing Filter: 'HeaderWriterFilter'
2016-04-17 04:40:19 - Not injecting HSTS header since it did not match the requestMatcher org.springframework.security.web.header.writers.HstsHeaderWriter$SecureRequestMatcher@4a77b460
2016-04-17 04:40:19 - /api/purchaseOrders/get at position 2 of 7 in additional filter chain; firing Filter: 'StatelessAuthenticationFilter'
2016-04-17 04:40:19 - /api/purchaseOrders/get at position 3 of 7 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter'
2016-04-17 04:40:19 - /api/purchaseOrders/get at position 4 of 7 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
2016-04-17 04:40:19 - Populated SecurityContextHolder with anonymous token: 'org.springframework.security.authentication.AnonymousAuthenticationToken@905571d8: Principal: anonymousUser; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@0: RemoteIpAddress: 122.171.94.145; SessionId: 4094950BB43FBE280B81842F649BA18E; Granted Authorities: ROLE_ANONYMOUS'
2016-04-17 04:40:19 - /api/purchaseOrders/get at position 5 of 7 in additional filter chain; firing Filter: 'SessionManagementFilter'
2016-04-17 04:40:19 - /api/purchaseOrders/get at position 6 of 7 in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
2016-04-17 04:40:19 - /api/purchaseOrders/get at position 7 of 7 in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
2016-04-17 04:40:19 - Checking match of request : '/api/purchaseorders/get'; against '/'
2016-04-17 04:40:19 - Checking match of request : '/api/purchaseorders/get'; against '/resources/**'
2016-04-17 04:40:19 - Checking match of request : '/api/purchaseorders/get'; against '/app/login/**'
2016-04-17 04:40:19 - Checking match of request : '/api/purchaseorders/get'; against '/api/**'
2016-04-17 04:40:19 - Secure object: FilterInvocation: URL: /api/purchaseOrders/get; Attributes: [fullyAuthenticated]
2016-04-17 04:40:19 - Previously Authenticated: org.springframework.security.authentication.AnonymousAuthenticationToken@905571d8: Principal: anonymousUser; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@0: RemoteIpAddress: 122.171.94.145; SessionId: 4094950BB43FBE280B81842F649BA18E; Granted Authorities: ROLE_ANONYMOUS
2016-04-17 04:40:19 - Voter: org.springframework.security.web.access.expression.WebExpressionVoter@385462f, returned: -1
2016-04-17 04:40:19 - AuditEvent [timestamp=Sun Apr 17 04:40:19 UTC 2016, principal=anonymousUser, type=AUTHORIZATION_FAILURE, data={type=org.springframework.security.access.AccessDeniedException, message=Access is denied}]
2016-04-17 04:40:19 - 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) ~[spring-security-core-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.security.access.intercept.AbstractSecurityInterceptor.beforeInvocation(AbstractSecurityInterceptor.java:232) ~[spring-security-core-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:123) ~[spring-security-web-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:90) ~[spring-security-web-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:114) ~[spring-security-web-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:122) [spring-security-web-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:111) [spring-security-web-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:169) [spring-security-web-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at com.drivojoy.inventory.helpers.StatelessAuthenticationFilter.doFilter(StatelessAuthenticationFilter.java:30) [classes!/:na]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:64) [spring-security-web-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:213) [spring-security-web-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:176) [spring-security-web-4.0.3.RELEASE.jar!/:4.0.3.RELEASE]
        at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346) [spring-web-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
        at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:262) [spring-web-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) [tomcat-embed-core-8.0.30.jar!/:8.0.30]
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [tomcat-embed-core-8.0.30.jar!/:8.0.30]
        at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) [spring-web-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) [tomcat-embed-core-8.0.30.jar!/:8.0.30]
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [tomcat-embed-core-8.0.30.jar!/:8.0.30]
        at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:87) [spring-web-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
</code></pre>
<p>As you can see: <strong>Populated SecurityContextHolder with anonymous token: 'org.springframework.security.authentication.AnonymousAuthenticationToken@905571d8: Principal: anonymousUser; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@0: RemoteIpAddress: 122.171.94.145; SessionId: 4094950BB43FBE280B81842F649BA18E; Granted Authorities: ROLE_ANONYMOUS'</strong></p>
<p>The spring security context is loading an anonymous user in its context. Below is my Filter.</p>
<pre><code>public class StatelessAuthenticationFilter extends GenericFilterBean {
    
        private final TokenAuthenticationService authenticationService;
    
        public StatelessAuthenticationFilter(TokenAuthenticationService authenticationService) {
            this.authenticationService = authenticationService;
        }
    
        @Override
        public void doFilter(ServletRequest request, ServletResponse response, FilterChain filterChain)
                throws IOException, ServletException {
            HttpServletRequest httpRequest = (HttpServletRequest) request;
            Authentication authentication = authenticationService.getAuthentication(httpRequest);
            SecurityContextHolder.getContext().setAuthentication(authentication);
            filterChain.doFilter(request, response);
            SecurityContextHolder.getContext().setAuthentication(null);
        }
    }
</code></pre>
<p>I have debugged till this point and found that in all cases, my security context is set with the correct authenticated and authorised user.</p>
<p>Can anyone please help me understand the root cause of the problem?</p>
<p>Thanks in advance.</p>