为什么 Spring Webflux 只能并行接受 256 个请求？答案

【问题标题】：Why does Spring Webflux only accepts 256 requests in parallel?为什么 Spring Webflux 只能并行接受 256 个请求？
【发布时间】：2019-03-27 12:00:54
【问题描述】：

在默认配置中，Spring Webflux 似乎将并行请求数限制为 256。

我的设置有这个非常简单的控制器：

@RestController
public class SimpleRestController {
  private final Log logger = LogFactory.getLog(getClass());

  private AtomicLong countEnter = new AtomicLong(0);
  private AtomicLong countExit = new AtomicLong(0);

  @GetMapping(value = "/delayed")
  public Mono<String> delayed() {
    logger.info("delayed ENTER " + countEnter.incrementAndGet());

    return Mono.just("result").delayElement(Duration.ofSeconds(60))

          .doOnNext(s -> logger.info("delayed EXIT " + countExit.incrementAndGet()));
  }
}

配置只是启用WebFlux：

@SpringBootConfiguration
@EnableWebFlux
public class SearchServiceConfiguration {
}

依赖很少：

  <properties>
    <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
    <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding>
    <java.version>10</java.version>
  </properties>

  <dependencies>
    <dependency>
      <groupId>org.springframework.boot</groupId>
      <artifactId>spring-boot-starter-webflux</artifactId>
    </dependency>

    <dependency>
      <groupId>org.projectlombok</groupId>
      <artifactId>lombok</artifactId>
      <optional>true</optional>
    </dependency>
  </dependencies>

  <build>
    <plugins>
      <plugin>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-maven-plugin</artifactId>
      </plugin>
      <plugin>
        <groupId>org.apache.maven.plugins</groupId>
        <artifactId>maven-compiler-plugin</artifactId>
        <version>3.8.0</version>
        <configuration>
          <source>10</source>
          <target>10</target>
          <encoding>UTF-8</encoding>
        </configuration>
      </plugin>
    </plugins>
  </build>

我用这个脚本并行调用端点：

#!/usr/bin/env bash

for p in `seq 1 1000`;
do
    curl -s http://localhost:8080/delayed &
done

wait
echo "All done"

对于第 257 个请求，返回 Resource temporarily unavailable。

哪个设置限制了并行请求的数量？

这是生成的日志输出：

2018-10-26 14:27:27.253  INFO 23728 --- [           main] s.w.r.r.m.a.RequestMappingHandlerMapping : Mapped "{[/sleep],methods=[GET],produces=[application/stream+json]}" onto public java.lang.String controller.SimpleRestController.sleep() throws java.lang.InterruptedException
2018-10-26 14:27:27.253  INFO 23728 --- [           main] s.w.r.r.m.a.RequestMappingHandlerMapping : Mapped "{[/delayed],methods=[GET]}" onto public reactor.core.publisher.Mono<java.lang.String> controller.SimpleRestController.delayed()
2018-10-26 14:27:27.315  INFO 23728 --- [           main] o.s.w.r.r.m.a.ControllerMethodResolver   : Looking for @ControllerAdvice: org.springframework.boot.web.reactive.context.AnnotationConfigReactiveWebServerApplicationContext@3cdf2c61: startup date [Fri Oct 26 14:27:26 CEST 2018]; root of context hierarchy
2018-10-26 14:27:27.639  INFO 23728 --- [           main] o.s.j.e.a.AnnotationMBeanExporter        : Registering beans for JMX exposure on startup
2018-10-26 14:27:27.938  INFO 23728 --- [ctor-http-nio-1] r.ipc.netty.tcp.BlockingNettyContext     : Started HttpServer on /0:0:0:0:0:0:0:0:8080
2018-10-26 14:27:27.939  INFO 23728 --- [           main] o.s.b.web.embedded.netty.NettyWebServer  : Netty started on port(s): 8080
2018-10-26 14:27:27.943  INFO 23728 --- [           main] d.h.s.s.SimpleApplication                : Started SimpleApplication in 1.548 seconds (JVM running for 2.396)
2018-10-26 14:27:34.295  INFO 23728 --- [ctor-http-nio-5] d.h.s.s.controller.SimpleRestController  : delayed ENTER 2
2018-10-26 14:27:34.295  INFO 23728 --- [ctor-http-nio-3] d.h.s.s.controller.SimpleRestController  : delayed ENTER 1
2018-10-26 14:27:34.295  INFO 23728 --- [ctor-http-nio-4] d.h.s.s.controller.SimpleRestController  : delayed ENTER 4
2018-10-26 14:27:34.295  INFO 23728 --- [ctor-http-nio-2] d.h.s.s.controller.SimpleRestController  : delayed ENTER 3
2018-10-26 14:27:34.324  INFO 23728 --- [ctor-http-nio-6] d.h.s.s.controller.SimpleRestController  : delayed ENTER 5
2018-10-26 14:27:34.351  INFO 23728 --- [ctor-http-nio-7] d.h.s.s.controller.SimpleRestController  : delayed ENTER 6
2018-10-26 14:27:34.381  INFO 23728 --- [ctor-http-nio-8] d.h.s.s.controller.SimpleRestController  : delayed ENTER 7
2018-10-26 14:27:34.413  INFO 23728 --- [ctor-http-nio-1] d.h.s.s.controller.SimpleRestController  : delayed ENTER 8
2018-10-26 14:27:34.438  INFO 23728 --- [ctor-http-nio-2] d.h.s.s.controller.SimpleRestController  : delayed ENTER 9
2018-10-26 14:27:34.466  INFO 23728 --- [ctor-http-nio-3] d.h.s.s.controller.SimpleRestController  : delayed ENTER 10
2018-10-26 14:27:34.497  INFO 23728 --- [ctor-http-nio-4] d.h.s.s.controller.SimpleRestController  : delayed ENTER 11
2018-10-26 14:27:34.526  INFO 23728 --- [ctor-http-nio-5] d.h.s.s.controller.SimpleRestController  : delayed ENTER 12
2018-10-26 14:27:34.561  INFO 23728 --- [ctor-http-nio-6] d.h.s.s.controller.SimpleRestController  : delayed ENTER 13
2018-10-26 14:27:34.594  INFO 23728 --- [ctor-http-nio-7] d.h.s.s.controller.SimpleRestController  : delayed ENTER 14
...
2018-10-26 14:27:42.675  INFO 23728 --- [ctor-http-nio-6] d.h.s.s.controller.SimpleRestController  : delayed ENTER 253
2018-10-26 14:27:42.711  INFO 23728 --- [ctor-http-nio-7] d.h.s.s.controller.SimpleRestController  : delayed ENTER 254
2018-10-26 14:27:42.745  INFO 23728 --- [ctor-http-nio-8] d.h.s.s.controller.SimpleRestController  : delayed ENTER 255
2018-10-26 14:27:42.774  INFO 23728 --- [ctor-http-nio-1] d.h.s.s.controller.SimpleRestController  : delayed ENTER 256
2018-10-26 14:28:04.312  INFO 23728 --- [     parallel-3] d.h.s.s.controller.SimpleRestController  : delayed EXIT 1
2018-10-26 14:28:04.312  INFO 23728 --- [     parallel-2] d.h.s.s.controller.SimpleRestController  : delayed EXIT 2
2018-10-26 14:28:04.321  INFO 23728 --- [     parallel-2] d.h.s.s.controller.SimpleRestController  : delayed EXIT 3
2018-10-26 14:28:04.321  INFO 23728 --- [     parallel-2] d.h.s.s.controller.SimpleRestController  : delayed EXIT 4
2018-10-26 14:28:04.333  INFO 23728 --- [     parallel-4] d.h.s.s.controller.SimpleRestController  : delayed EXIT 5
2018-10-26 14:28:04.359  INFO 23728 --- [     parallel-5] d.h.s.s.controller.SimpleRestController  : delayed EXIT 6
2018-10-26 14:28:04.389  INFO 23728 --- [     parallel-6] d.h.s.s.controller.SimpleRestController  : delayed EXIT 7
2018-10-26 14:28:04.421  INFO 23728 --- [     parallel-7] d.h.s.s.controller.SimpleRestController  : delayed EXIT 8
2018-10-26 14:28:04.446  INFO 23728 --- [     parallel-8] d.h.s.s.controller.SimpleRestController  : delayed EXIT 9
2018-10-26 14:28:04.474  INFO 23728 --- [     parallel-1] d.h.s.s.controller.SimpleRestController  : delayed EXIT 10
2018-10-26 14:28:04.505  INFO 23728 --- [     parallel-2] d.h.s.s.controller.SimpleRestController  : delayed EXIT 11
...
2018-10-26 14:28:12.570  INFO 23728 --- [     parallel-1] d.h.s.s.controller.SimpleRestController  : delayed EXIT 250
2018-10-26 14:28:12.607  INFO 23728 --- [     parallel-2] d.h.s.s.controller.SimpleRestController  : delayed EXIT 251
2018-10-26 14:28:12.643  INFO 23728 --- [     parallel-3] d.h.s.s.controller.SimpleRestController  : delayed EXIT 252
2018-10-26 14:28:12.683  INFO 23728 --- [     parallel-4] d.h.s.s.controller.SimpleRestController  : delayed EXIT 253
2018-10-26 14:28:12.719  INFO 23728 --- [     parallel-5] d.h.s.s.controller.SimpleRestController  : delayed EXIT 254
2018-10-26 14:28:12.752  INFO 23728 --- [     parallel-6] d.h.s.s.controller.SimpleRestController  : delayed EXIT 255
2018-10-26 14:28:12.782  INFO 23728 --- [     parallel-7] d.h.s.s.controller.SimpleRestController  : delayed EXIT 256

【问题讨论】：

听起来很奇怪。 Netty 不应该限制任何东西。这可能与操作系统有关。提供堆栈跟踪/错误/等。
没有堆栈跟踪。我使用 CommonsRequestLoggingFilter 开启了请求日志记录。但是第 257 个请求没有被记录。
你有另一台机器可以试一试吗？
不，我没有其他机器可以尝试。
附带说明，您不需要@EnableWebFlux，因为它覆盖了 Spring Boot 的所有自动配置。您可以安全地删除它。

标签： spring-boot netty spring-webflux reactor

【解决方案1】：

这不是我在本地设置中看到的。将您的控制器更改为以下内容确实会将“onNext 1”打印为“onNext 1000”：

AtomicLong count = new AtomicLong(0);

@GetMapping("/delayed")
public Mono<String> delayed() {
    return Mono.just("result").delayElement(Duration.ofSeconds(30))
            .doOnNext(s -> {
                logger.info("onNext " + count.incrementAndGet());
            });
}

在您的一个 cmets 中，您提到了 CommonsRequestLoggingFilter，它是特定于 Servlet 的。这告诉我你不是在运行 Spring WebFlux 应用程序，而是实际上是一个 Spring MVC 应用程序。如果您正在运行 Spring Boot，并且类路径中有 Spring MVC，Spring Boot will configure a Spring MVC application for you。

默认情况下，Spring MVC 将使用SimpleAsyncTaskExecutor 来调度这些请求的异步处理（Spring MVC 支持响应式返回类型，但会将它们视为@Async 请求，asynchronous but not non-blocking）。我认为SimpleAsyncTaskExecutor 默认没有并发限制。也许您在应用程序中配置了一个将并发限制为 256 的任务执行器？

我尝试使用 Spring MVC 应用程序重现该问题，但仍然处理了 999 个请求，并在日志中解决了一个异常：

.w.s.m.s.DefaultHandlerExceptionResolver : Resolved [org.springframework.web.context.request.async.AsyncRequestTimeoutException]

【讨论】：

其实我并没有明确配置 SimpleAsyncTaskExecutor。那么 256 可以成为 SimpleAsyncTaskExecutor 的默认配置吗？
我将检查您关于 MVC 与 WebFlux 的链接，并查看依赖项中的切换是否会改变行为。
很难用一个小代码sn-p来弄清楚这里发生了什么。甚至 MVC 与 WebFlux 也是来自您的一个 cmets 的有根据的猜测。提供有关您的应用程序的更多信息应该会有所帮助。
@tk，SimpleAsyncTaskExecutor，默认情况下用于 Spring 中的异步处理，为每个任务生成一个新线程。每个线程都需要内存。您专用于 JVM 的内存很可能仅足以创建 256 个线程。您可以减少堆栈大小或增加 JVM 内存来确定是否是问题所在。使用–Xss512k JVM 选项将堆栈大小减少一半，并查看是否有 512 个线程而不是 256 个。
@tkr 请使用构建文件或依赖项列表更新您的问题。在不编辑原始问题的情况下在 cmets 中提供提示会使愿意帮助您的 SO 贡献者更难。

【解决方案2】：

服务器不是您的限制因素。该错误表明由于资源限制，创建后台进程失败。有几个可能的原因：

内存 - 每个进程都需要内存来加载 curl。
进程 - 您可以创建的进程数量可能存在限制
打开文件 - 每个进程打开多个“文件”。那是引号，因为“文件”包括网络连接和 curl 加载的动态库。一次可以打开的数量在系统范围内有限制。

【讨论】：

谢谢。实际上日志资源暂时不可用与服务器无关。 256 个请求的限制是由我非常简单的 shell 脚本造成的。
@tkr 你能否进一步解释一下为什么问题与你的 shell 脚本有关？