I want to use an interceptor to manage the number of currently active connections with the server. Besides the usual JSON endpoints, my API also offers endpoints for streaming bytes. I implemented a session manager, that keeps track of the session count, a limiting interceptor and several API endpoints. Below is some exemplary code.
The usual JSON endpoints are running well with the interceptor. However, the streaming endpoint actually calls the interceptor's preHandle method twice, but the afterCompletion only once. The second call to preHandle happens after the first call's response computation was finished. When I remove the session manager from the interceptor, this behavior does not occur anymore.
Minimal working example:
Configuration:
@Configuration
@RequiredArgsConstructor
public class AppConfig implements WebMvcConfigurer {
private final Interceptor interceptor;
@Override
public void addInterceptors(InterceptorRegistry registry) {
registry.addInterceptor(this.interceptor).addPathPatterns("/numbers", "/numbers/*");
}
}
Interceptor:
@Component
@RequiredArgsConstructor
@Slf4j
public class Interceptor implements HandlerInterceptor {
private final SessionManager sessionManager;
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
log.info("Pre-handle {}", this.hashCode());
return this.sessionManager.accept();
}
@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception e) {
log.info("After completion {}", this.hashCode());
this.sessionManager.leave();
}
}
Session manager:
@Component
@Slf4j
public class SessionManager {
private static final int MAX_SESSION_COUNT = 1;
private final AtomicInteger sessionCount = new AtomicInteger(0);
public synchronized boolean accept() {
int sessionCount = this.sessionCount.get();
if (sessionCount >= MAX_SESSION_COUNT) {
log.error("Upper session limit hit! Currently active sessions: {}, maximum allowed active sessions: {}", sessionCount, MAX_SESSION_COUNT);
return false;
}
sessionCount = this.sessionCount.incrementAndGet();
log.debug("Accept new session. Currently active sessions: {}, maximum allowed active sessions: {}", sessionCount, MAX_SESSION_COUNT);
return true;
}
public void leave() {
int sessionCount = this.sessionCount.decrementAndGet();
log.debug("Decrement session count to {}", sessionCount);
}
}
Controller:
@RestController
@RequestMapping("/numbers")
@Slf4j
public class Controller {
private final Random random = new Random();
@PostMapping("")
public ResponseEntity<List<Integer>> number() {
log.info("Generate numbers");
List<Integer> bytes = IntStream.range(0, 1_000)
.map(ignored -> this.random.nextInt(255))
.boxed()
.collect(Collectors.toList());
return ResponseEntity.ok(bytes);
}
@PostMapping("/stream")
public ResponseEntity<StreamingResponseBody> numberStream() {
log.info("Generate stream start");
StreamingResponseBody responseBody = outputStream -> {
for (int i = 0; i < 1_000_000; i ) {
outputStream.write(this.random.nextInt(255));
}
};
return ResponseEntity.ok()
.contentType(MediaType.APPLICATION_OCTET_STREAM)
.body(responseBody);
}
}
I found a similar topic on stackoverflow, but the advice given there does not work in my case. The behavior does not change when removing @Component from my interceptor and instantiating interceptor and session manager manually in the addInterceptors method.
Log (maximum session count = 2):
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.6.1)
2021-12-10 14:21:25.999 INFO 17112 --- [ main] c.e.untitled2.Untitled2Application : Starting Untitled2Application using Java 1.8.0_312 on HOSTNAME with PID 17112 (D:\IntelliJProjects\untitled2\target\classes started by USERNAME in D:\IntelliJProjects\untitled2)
2021-12-10 14:21:26.001 INFO 17112 --- [ main] c.e.untitled2.Untitled2Application : No active profile set, falling back to default profiles: default
2021-12-10 14:21:26.626 INFO 17112 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
2021-12-10 14:21:26.632 INFO 17112 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2021-12-10 14:21:26.632 INFO 17112 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.55]
2021-12-10 14:21:26.701 INFO 17112 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2021-12-10 14:21:26.701 INFO 17112 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 669 ms
2021-12-10 14:21:26.907 INFO 17112 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path ''
2021-12-10 14:21:26.913 INFO 17112 --- [ main] c.e.untitled2.Untitled2Application : Started Untitled2Application in 1.197 seconds (JVM running for 1.84)
#### Call /numbers
2021-12-10 14:21:49.494 INFO 17112 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet'
2021-12-10 14:21:49.494 INFO 17112 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'
2021-12-10 14:21:49.494 INFO 17112 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Completed initialization in 0 ms
2021-12-10 14:21:49.502 INFO 17112 --- [nio-8080-exec-1] com.example.untitled2.Interceptor : Interceptor 1184674729 pre-handles request 1068123396: POST /numbers
2021-12-10 14:21:49.503 INFO 17112 --- [nio-8080-exec-1] com.example.untitled2.SessionManager : Accept new session. Currently active sessions: 1, maximum allowed active sessions: 2
2021-12-10 14:21:49.508 INFO 17112 --- [nio-8080-exec-1] com.example.untitled2.Controller : Generate numbers
2021-12-10 14:21:49.536 INFO 17112 --- [nio-8080-exec-1] com.example.untitled2.Interceptor : After completion 1184674729
2021-12-10 14:21:49.536 INFO 17112 --- [nio-8080-exec-1] com.example.untitled2.SessionManager : Decrement session count to 0
#### Call /numbers again
2021-12-10 14:21:57.054 INFO 17112 --- [nio-8080-exec-3] com.example.untitled2.Interceptor : Interceptor 1184674729 pre-handles request 1068123396: POST /numbers
2021-12-10 14:21:57.054 INFO 17112 --- [nio-8080-exec-3] com.example.untitled2.SessionManager : Accept new session. Currently active sessions: 1, maximum allowed active sessions: 2
2021-12-10 14:21:57.054 INFO 17112 --- [nio-8080-exec-3] com.example.untitled2.Controller : Generate numbers
2021-12-10 14:21:57.055 INFO 17112 --- [nio-8080-exec-3] com.example.untitled2.Interceptor : After completion 1184674729
2021-12-10 14:21:57.055 INFO 17112 --- [nio-8080-exec-3] com.example.untitled2.SessionManager : Decrement session count to 0
#### Call /numbers/stream
2021-12-10 14:22:06.375 INFO 17112 --- [nio-8080-exec-4] com.example.untitled2.Interceptor : Interceptor 1184674729 pre-handles request 1068123396: POST /numbers/stream
2021-12-10 14:22:06.376 INFO 17112 --- [nio-8080-exec-4] com.example.untitled2.SessionManager : Accept new session. Currently active sessions: 1, maximum allowed active sessions: 2
2021-12-10 14:22:06.376 INFO 17112 --- [nio-8080-exec-4] com.example.untitled2.Controller : Generate stream start
2021-12-10 14:22:06.414 INFO 17112 --- [nio-8080-exec-5] com.example.untitled2.Interceptor : Interceptor 1184674729 pre-handles request 317286159: POST /numbers/stream
2021-12-10 14:22:06.414 INFO 17112 --- [nio-8080-exec-5] com.example.untitled2.SessionManager : Accept new session. Currently active sessions: 2, maximum allowed active sessions: 2
2021-12-10 14:22:06.416 INFO 17112 --- [nio-8080-exec-5] com.example.untitled2.Interceptor : After completion 1184674729
2021-12-10 14:22:06.416 INFO 17112 --- [nio-8080-exec-5] com.example.untitled2.SessionManager : Decrement session count to 1
#### Call /numbers/stream again
2021-12-10 14:22:17.857 INFO 17112 --- [nio-8080-exec-6] com.example.untitled2.Interceptor : Interceptor 1184674729 pre-handles request 1068123396: POST /numbers/stream
2021-12-10 14:22:17.857 INFO 17112 --- [nio-8080-exec-6] com.example.untitled2.SessionManager : Accept new session. Currently active sessions: 2, maximum allowed active sessions: 2
2021-12-10 14:22:17.857 INFO 17112 --- [nio-8080-exec-6] com.example.untitled2.Controller : Generate stream start
2021-12-10 14:22:17.889 INFO 17112 --- [nio-8080-exec-7] com.example.untitled2.Interceptor : Interceptor 1184674729 pre-handles request 1473864520: POST /numbers/stream
2021-12-10 14:22:17.889 ERROR 17112 --- [nio-8080-exec-7] com.example.untitled2.SessionManager : Upper session limit hit! Currently active sessions: 2, maximum allowed active sessions: 2
#### Call /numbers/stream again
2021-12-10 14:22:26.443 INFO 17112 --- [nio-8080-exec-8] com.example.untitled2.Interceptor : Interceptor 1184674729 pre-handles request 1068123396: POST /numbers/stream
2021-12-10 14:22:26.443 ERROR 17112 --- [nio-8080-exec-8] com.example.untitled2.SessionManager : Upper session limit hit! Currently active sessions: 2, maximum allowed active sessions: 2
The logs show that preHandle is called twice while afterCompletion is called only once.
CodePudding user response：
From the document
Note: Will only be called if this interceptor's preHandle method has successfully completed and returned true!
afterCompletion() method will be called only if the preHandle() method returns true. In your case, you are incrementing the session count and returning false.
If you want to call sessionManager.leave(); always(irrespective of what the preHandle() returns), use the postHandle() instead of afterCompletion().
CodePudding user response：
So to start with the issue which you are having we need to start with the dispatch types supported by the Servlet environment and particularly the ASYNC dispatch type which was added as part of the Servlet 3.0 specification. In a nutshell, the ASYNC dispatch type was added to support long-running / heavy requests which in older times were blocking the servlet container from handling other requests, as the handler thread was blocked waiting for the heavy/long-running task to be finished. So clever guys out there decided that the long-running and heavy jobs can be executed in a parallel thread and the main worker thread can be released to the pool so new small requests can be handled.
So let's get back to your issue:
So have two endpoints one returning the JSON or a simple object which can be handled by the handler thread and the second one which returns the StreamingResponseBody. For the first one, no special handling is defined, so Spring handles the request as a usual request and just generates a payload and returns it back to the client. For the second one spring has a custom response handler called StreamingResponseBodyReturnValueHandler which basically creates a ASYNC version of the request (coping all of the attributes but changing the dispatch type) and pushes the execution to the new thread via WebAsyncManager.
So why does the preHandle() called twice ? That is because once it is called as part of the first execution based on the REQUEST dispatch and just after pre handle Spring starts handling the request and understands that it should be handled in ASYNC mode as the return type is a stream (basically unsized thing), so a copy of the request is made it it is once again executed in the new thread. So if you look into preHandle() you will notice that it is called from different threads, with the same request data but different dispatch type on request.
So what you can do ?
Your Interceptor should be a bit clever to not blindly call sessionManager.accept(); but check if the request was already handled before.
So very dummy version will look like this
@Component
@RequiredArgsConstructor
@Slf4j
public class Interceptor implements HandlerInterceptor {
private final SessionManager sessionManager;
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
log.info("Pre-handle {}", this.hashCode());
if(BooleanUtils.isTrue(request.getAttribute("accepted")) || DispatcherType.ASYNC == request.getDispatcherType()){
return true;
}
boolean accepted = this.sessionManager.accept();
if (accepted){
request.setAttribute("accepted", true);
}
return accepted;
}
@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception e) {
log.info("After completion {}", this.hashCode());
this.sessionManager.leave();
}
}