SpringBoot:拦截器的 preHandle 在流端点上运行两次

Gre*_*een 0 java streaming spring spring-mvc interceptor

我想使用拦截器来管理当前与服务器的活动连接数。除了常见的 JSON 端点之外,我的 API 还提供流字节的端点。我实现了一个会话管理器,用于跟踪会话计数、一个限制拦截器和几个 API 端点。下面是一些示例代码。

常见的 JSON 端点与拦截器运行良好。然而,流端点实际上调用了拦截器的preHandle方法两次,但afterCompletion只调用了一次。第二次调用preHandle发生在第一个调用的响应计算完成之后。当我从拦截器中删除会话管理器时,这种行为不再发生。

最小工作示例:

配置:

@Configuration
@RequiredArgsConstructor
public class AppConfig implements WebMvcConfigurer {
    private final Interceptor interceptor;

    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(this.interceptor).addPathPatterns("/numbers", "/numbers/*");
    }
}
Run Code Online (Sandbox Code Playgroud)

拦截器:

@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();
    }
}
Run Code Online (Sandbox Code Playgroud)

会话经理:

@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);
    }
}
Run Code Online (Sandbox Code Playgroud)

控制器:

@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);
    }
}
Run Code Online (Sandbox Code Playgroud)

在 stackoverflow 上找到了类似的主题,但那里给出的建议对我来说不起作用。@Component从拦截器中删除并在方法中手动实例化拦截器和会话管理器时,行为不会改变addInterceptors

日志(最大会话数 = 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
Run Code Online (Sandbox Code Playgroud)

日志显示preHandle被调用两次而afterCompletion仅被调用一次。

Bab*_*abl 7

因此,要从您遇到的问题开始,我们需要从 Servlet 环境支持的调度类型开始,特别是作为 Servlet 3.0 规范的一部分添加的 ASYNC 调度类型。简而言之,添加 ASYNC 调度类型是为了支持长时间运行/繁重的请求,在过去,这些请求会阻止 servlet 容器处理其他请求,因为处理程序线程被阻止等待繁重/长时间运行的任务完成。因此,聪明的人决定可以在并行线程中执行长时间运行和繁重的作业,并且可以将主工作线程释放到池中,以便可以处理新的小请求。

那么让我们回到您的问题:因此有两个端点,一个返回 JSON 或一个可以由处理程序线程处理的简单对象,第二个返回StreamingResponseBody. 对于第一个,没有定义特殊处理,因此 Spring 将请求作为普通请求进行处理,只生成有效负载并将其返回给客户端。对于第二个,spring 有一个名为的自定义响应处理程序StreamingResponseBodyReturnValueHandler,它基本上创建请求的异步版本(处理所有属性,但更改调度类型)并通过WebAsyncManager.

那么为什么会preHandle()调用两次呢?这是因为一旦它作为基于REQUEST分派的第一次执行的一部分被调用,并且在预处理之后 Spring 开始处理请求并理解它应该以ASYNC模式处理,因为返回类型是流(基本上是未调整大小的东西),所以如果请求再次在新线程中执行,则会生成请求的副本。因此,如果您仔细观察,preHandle()您会发现它是从不同的线程调用的,具有相同的请求数据,但请求时的调度类型不同。

更多信息请点击这里:

Github 问题

代码

那么你能做什么呢?你Interceptor应该聪明一点,不要盲目调用sessionManager.accept();,而是检查请求是否已经被处理过。

所以非常虚拟的版本看起来像这样

@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();
    }
}
Run Code Online (Sandbox Code Playgroud)

  • 答案中描述的行为在[此 gitthub 问题](https://github.com/spring-projects/spring-framework/issues/17209) 中引用,并记录在[源代码本身](https://github .com/spring-projects/spring-framework/commit/18039785aeacc3ca76c70014b11fb30923a54941)。 (2认同)