A race condition during authentication
Recently one of our applications needed to be integrated with a central authentication service. This application was built with Spring Boot, so we decided to implement this functionality using the Spring Security library that was already being imported anyway. We would call this central authentication service on every request to verify the user authentication token which should be sent on a cookie.
For this we implemented a custom Filter and Provider. The filter would be added to the request filter chain and, when called, should get the user authentication token from the cookie and pass it to the AuthenticationManager that in turn should ask the correct Provider to authenticate the token with the central authentication service.
All was tested and all seemed to work properly, however, after releasing the feature, we started receiving an increasing number of errors on our daily error report.
Alert: Daily Error Digest
Error | Total
------------------
Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception | 10231
On our test environments we could not reproduce the error, although there were users starting to complain about sporadic failed requests and the report showed that as we rolled out the feature to more and more users the error count was increasing.
The error on the production logs was not very descriptive but with this information we started suspecting of some kind of concurrency issue. After coding a small script to make concurrent requests to the service, we were able to reproduce the error on our local environment.
2018-04-20 11:14:33.162 ERROR 3868 --- [p-nio-80-exec-9] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception
java.lang.NullPointerException: null
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.14.jar:8.5.14]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:317) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at ru.asu.edu.studyload.security.AuthFilter.lambda$0(AuthFilter.java:30) ~[bin/:na]
at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.successfulAuthentication(AbstractAuthenticationProcessingFilter.java:326) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:240) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at ru.asu.edu.studyload.security.AuthFilter.doFilter(AuthFilter.java:32) ~[bin/:na]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:170) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:116) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:64) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.3.8.RELEASE.jar:4.3.8.RELEASE]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:56) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.3.8.RELEASE.jar:4.3.8.RELEASE]
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:214) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:177) ~[spring-security-web-4.2.2.RELEASE.jar:4.2.2.RELEASE]
at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346) ~[spring-web-4.3.8.RELEASE.jar:4.3.8.RELEASE]
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:262) ~[spring-web-4.3.8.RELEASE.jar:4.3.8.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.14.jar:8.5.14]
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) ~[spring-web-4.3.8.RELEASE.jar:4.3.8.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.3.8.RELEASE.jar:4.3.8.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.14.jar:8.5.14]
at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:105) ~[spring-web-4.3.8.RELEASE.jar:4.3.8.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.3.8.RELEASE.jar:4.3.8.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.14.jar:8.5.14]
at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:81) ~[spring-web-4.3.8.RELEASE.jar:4.3.8.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.3.8.RELEASE.jar:4.3.8.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.14.jar:8.5.14]
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197) ~[spring-web-4.3.8.RELEASE.jar:4.3.8.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.3.8.RELEASE.jar:4.3.8.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.14.jar:8.5.14]
at org.springframework.boot.actuate.autoconfigure.MetricsFilter.doFilterInternal(MetricsFilter.java:106) ~[spring-boot-actuator-1.5.3.RELEASE.jar:1.5.3.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.3.8.RELEASE.jar:4.3.8.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) ~[tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) [tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:478) [tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) [tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80) [tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) [tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) [tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:799) [tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) [tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861) [tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1455) [tomcat-embed-core-8.5.14.jar:8.5.14]
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-8.5.14.jar:8.5.14]
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [na:1.8.0_131]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [na:1.8.0_131]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-8.5.14.jar:8.5.14]
at java.lang.Thread.run(Unknown Source) [na:1.8.0_131]
To understand what was going on we followed the path of one request since it entered the system.
Spring Boot starters, in our case spring-boot-starter-web, use Tomcat as an embedded container by default and the request goes through all those layers finally getting into the StandardWrapperValve, where the filter chain orchestration is done. Here it:
-
Allocates a servlet instance to process the request.
servlet = wrapper.allocate(); -
Creates an application filter chain for this request.
ApplicationFilterChain filterChain = createFilterChain(request, wrapper, servlet); -
Calls the just created filter chain. filterChain.doFilter(request.getRequest(), response.getResponse());
Which will go through every filter on the chain, including our customSsoidAuthenticationFilterand after reaching the end of the chain, if everything is good, call the servlet instance.
servlet.service(request, response);
class SsoidAuthenticationFilter extends AbstractAuthenticationProcessingFilter {
SsoidAuthenticationFilter() {
super(AnyRequestMatcher.INSTANCE);
}
@Override
public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
final String token = getTokenValue((HttpServletRequest) request);
if (StringUtils.isEmpty(token)) {
chain.doFilter(request, response);
return;
}
// On success keep going on the chain
this.setAuthenticationSuccessHandler((req, res, authentication) -> chain.doFilter(req, res));
this.setAuthenticationFailureHandler((req, res, exception) -> res.setStatus(HttpStatus.UNAUTHORIZED.value()));
super.doFilter(request, response, chain);
}
@Override
public Authentication attemptAuthentication(HttpServletRequest request, HttpServletResponse response) throws AuthenticationException {
final String ssoid = getTokenValue(request);
if (StringUtils.isEmpty(ssoid)) {
return null;
}
SsoidAuthenticationToken token = new SsoidAuthenticationToken(ssoid);
token.setDetails(authenticationDetailsSource.buildDetails(request));
return this.getAuthenticationManager().authenticate(token);
}
private String getTokenValue(HttpServletRequest request) {
return Optional.of(request)
.map(HttpServletRequest::getCookies)
.map(this::extractSsoid)
.orElse("");
}
private String extractSsoid(Cookie[] cookies) {
return Arrays.stream(cookies)
.filter(c -> c.getName().equals("ssoid"))
.findFirst()
.map(Cookie::getValue)
.orElse("");
}
- Releases the filter chain for this request.
filterChain.release();
Note that when this method is called the servlet variable of the chain is set to null.
void release() {
for (int i = 0; i < n; i++) {
filters[i] = null;
}
n = 0;
pos = 0;
servlet = null;
servletSupportsAsync = false;
}
After some debugging we noticed that we were doing something very wrong on our custom authentication filter which was causing a race condition.
[thread-6] SsoidAuthenticationFilter.doFilter(req, res, chain) [chainRef-1]
[thread-7] SsoidAuthenticationFilter.doFilter(req, res, chain) [chainRef-2]
[thread-6] authenticationSuccessHandler => chain.doFilter(req, res) [chainRef-2]
[thread-7] authenticationSuccessHandler => chain.doFilter(req, res) [chainRef-2]
[thread-7] servlet.service(req, resp)
[thread-7] filterChain.release() [chainRef-2]
[thread-6] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception
java.lang.NullPointerException: null
In the example we can see what was happening. We have two threads (6 and 7) handling 2 requests. Both were given two different chain instances, chainRef-1 and chainRef-2 respectively, which were passed to the doFilter method of our SsoidAuthenticationFilter. However, when the authenticationSuccessHandler is called, both threads are using chainRef-2 instance to continue the chain with chain.doFilter(). thread-6 is not using the correct chain instance, the one allocated to it.
This is what was causing the error, once, after going through all of the chain and calling servlet.service(), thread-7 is done with the request so it releases the chain, which later causes a NullPointerException on thread-6 when it tries to run servlet.service() within the same chain, which has now a null servlet instance.
The doFilter method inside the SsoidAuthenticationFilter is not thread safe and we were using the chain function parameter inside a lambda function called after a successful authentication.
this.setAuthenticationSuccessHandler((req, res, auth) -> chain.doFilter(req, res));
The fix was not so difficult. Instead of using an out of scope chain to continue to the next filter in the success handler, we just do it in the overridden successfulAuthentication method that gives us the correct FilterChain instance.
public class SsoidAuthenticationFilter extends AbstractAuthenticationProcessingFilter {
private static final String Ssoid_COOKIE_NAME = "ssoid";
public SsoidAuthenticationFilter() {
super(AnyRequestMatcher.INSTANCE);
this.setAuthenticationSuccessHandler((req, res, authentication) -> { });
}
@Override
public void doFilter(ServletRequest request,
ServletResponse response,
FilterChain chain) throws IOException, ServletException {
final Optional<Cookie> ssoidCookie = getSsoidCookie((HttpServletRequest) request);
if (!ssoidCookie.isPresent()) {
chain.doFilter(request, response);
return;
}
super.doFilter(request, response, chain);
}
@Override
public Authentication attemptAuthentication(HttpServletRequest servletRequest, HttpServletResponse servletResponse) throws AuthenticationException {
final Optional<Cookie> ssoidCookie = getSsoidCookie(servletRequest);
if (!ssoidCookie.isPresent()) {
return null;
}
SsoidAuthenticationToken token = new SsoidAuthenticationToken(ssoidCookie.get().getValue());
token.setDetails(authenticationDetailsSource.buildDetails(servletRequest));
return this.getAuthenticationManager().authenticate(token);
}
private static Optional<Cookie> getSsoidCookie(HttpServletRequest servletRequest) {
return Optional.ofNullable(WebUtils.getCookie(servletRequest, Ssoid_COOKIE_NAME))
.filter(cookie -> StringUtils.isNotEmpty(cookie.getValue()));
}
@Override
protected void successfulAuthentication(HttpServletRequest req,
HttpServletResponse res,
FilterChain chain,
Authentication auth) throws IOException, ServletException {
super.successfulAuthentication(req, res, chain, auth);
// On success keep going on the chain
chain.doFilter(req, res);
}
}