PrematureCloseException: 连接过早关闭

23

我正在使用Web-flux/Reactive和Webclient,在Tomcat和Spring Boot上运行。

一切都运行良好,但我发现使用Webclient时必须返回或使用响应,否则连接会关闭且未被消耗,会产生很多日志消息,显示“连接过早关闭”。如果出现404状态码错误,我可以使用OnStatus并抛出异常,但我的情况是:当上游服务返回404时,我必须手动返回一个空的mono。因此,我不使用Webclient请求的响应,而是使用.exchange()中的ClientResponse来检查状态并处理。我的初始问题是这些日志消息,它们只是“垃圾”,你不想在日志消息中看到很多它们。我曾经读过如果发生这种情况,连接也无法再次使用,所以听起来非常糟糕,但我不确定……只有在未找到时才会收到此消息,如果响应为200,则会返回对象,且日志消息不会打印。

我尝试使用clientResponse.BodyToMono(Void.Class),但它也无效。日志消息仍在出现。

 @Bean
  public WebClient webClient(
      @Value("${http.client.connection-timeout-millis}") final int connectionTimeoutMillis,
      @Value("${http.client.socket-timeout-millis}") final int socketTimeoutMillis,
      @Value("${http.client.wire-tap-enabled}") final boolean wireTapEnabled,
      final ObjectMapper objectMapper) {

    Consumer<Connection> doOnConnectedConsumer = connection ->
        connection
            .addHandler(new ReadTimeoutHandler(socketTimeoutMillis, MILLISECONDS))
            .addHandler(new WriteTimeoutHandler(connectionTimeoutMillis, MILLISECONDS));

    TcpClient tcpClient = TcpClient.newConnection()
        .wiretap(wireTapEnabled)
        .option(CONNECT_TIMEOUT_MILLIS, connectionTimeoutMillis)
        .doOnConnected(doOnConnectedConsumer);

    return WebClient.builder()
        .clientConnector(new ReactorClientHttpConnector(HttpClient.from(tcpClient).compress(true)))
        .exchangeStrategies(customExchangeStrategies(objectMapper))
        .build();
  } 

// ..........

    MultiValueMap<String, String> params = getParams(t1, t2);

    return webClient.get()
        .uri(HttpUtils.buildUrl(serviceUrl, params, name))
        .exchange()
        .flatMap(this::handleClientResponse)
        .onErrorMap(Exception.class, ex -> handleUnexpectedEx(ex, name, params));
  }

日志条目

2019-07-08 11:56:51.972  WARN [-,,,] 1504 --- [ctor-http-nio-3] reactor.netty.channel.FluxReceive        : [id: 0x66c8568c, L:/127.0.0.1:62319 ! R:localhost/127.0.0.1:8990] An exception has been observed post termination

reactor.netty.http.client.PrematureCloseException: Connection prematurely closed DURING response

2019-07-08 11:56:52.013 DEBUG [-,,,] 1504 --- [ctor-http-nio-2] reactor.netty.ReactorNetty               : [id: 0xf50bdf8d, L:/127.0.0.1:62324 ! R:localhost/127.0.0.1:8990] Non Removed handler: ReadTimeoutHandler, context: ChannelHandlerContext(ReadTimeoutHandler, [id: 0xf50bdf8d, L:/127.0.0.1:62324 ! R:localhost/127.0.0.1:8990]), pipeline: DefaultChannelPipeline{(reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (reactor.left.decompressor = io.netty.handler.codec.http.HttpContentDecompressor), (WriteTimeoutHandler = io.netty.handler.timeout.WriteTimeoutHandler), (ReadTimeoutHandler = io.netty.handler.timeout.ReadTimeoutHandler), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2019-07-08 11:56:52.014 DEBUG [-,,,] 1504 --- [ctor-http-nio-2] reactor.netty.ReactorNetty               : [id: 0xf50bdf8d, L:/127.0.0.1:62324 ! R:localhost/127.0.0.1:8990] Non Removed handler: WriteTimeoutHandler, context: ChannelHandlerContext(WriteTimeoutHandler, [id: 0xf50bdf8d, L:/127.0.0.1:62324 ! R:localhost/127.0.0.1:8990]), pipeline: DefaultChannelPipeline{(reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (reactor.left.decompressor = io.netty.handler.codec.http.HttpContentDecompressor), (WriteTimeoutHandler = io.netty.handler.timeout.WriteTimeoutHandler), (ReadTimeoutHandler = io.netty.handler.timeout.ReadTimeoutHandler), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2019-07-08 11:56:52.014 DEBUG [-,,,] 1504 --- [ctor-http-nio-2] r.netty.resources.NewConnectionProvider  : [id: 0xf50bdf8d, L:/127.0.0.1:62324 ! R:localhost/127.0.0.1:8990] onStateChange([response_incomplete], GET{uri=/service/TWFDHF?T1=1.0.0&T2=1, connection=SimpleConnection{channel=[id: 0xf50bdf8d, L:/127.0.0.1:62324 ! R:localhost/127.0.0.1:8990]}})
2019-07-08 11:56:52.014  WARN [-,,,] 1504 --- [ctor-http-nio-2] reactor.netty.channel.FluxReceive        : [id: 0xf50bdf8d, L:/127.0.0.1:62324 ! R:localhost/127.0.0.1:8990] An exception has been observed post termination

启用了窃听功能的日志条目

2019-07-10 14:51:19.295 DEBUG [-,,,] 2940 --- [ctor-http-nio-2] reactor.netty.tcp.TcpClient              : [id: 0x677da0d4, L:/127.0.0.1:62385 ! R:localhost/127.0.0.1:8990] UNREGISTERED
2019-07-10 14:51:19.541 DEBUG [-,,,] 2940 --- [ctor-http-nio-4] reactor.netty.tcp.TcpClient              : [id: 0xa7f41d1e, L:/127.0.0.1:62384 - R:localhost/127.0.0.1:8990] CLOSE
2019-07-10 14:51:19.542 DEBUG [-,,,] 2940 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider   : [id: 0xa7f41d1e, L:/127.0.0.1:62384 ! R:localhost/127.0.0.1:8990] Channel cleaned, now 0 active connections and 9 inactive connections
2019-07-10 14:51:19.542 DEBUG [-,,,] 2940 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider   : [id: 0xa7f41d1e, L:/127.0.0.1:62384 ! R:localhost/127.0.0.1:8990] Channel closed, now 0 active connections and 8 inactive connections
2019-07-10 14:51:19.542 DEBUG [-,,,] 2940 --- [ctor-http-nio-4] reactor.netty.ReactorNetty               : [id: 0xa7f41d1e, L:/127.0.0.1:62384 ! R:localhost/127.0.0.1:8990] Non Removed handler: ReadTimeoutHandler, context: ChannelHandlerContext(ReadTimeoutHandler, [id: 0xa7f41d1e, L:/127.0.0.1:62384 ! R:localhost/127.0.0.1:8990]), pipeline: DefaultChannelPipeline{(reactor.left.loggingHandler = io.netty.handler.logging.LoggingHandler), (reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (WriteTimeoutHandler = io.netty.handler.timeout.WriteTimeoutHandler), (ReadTimeoutHandler = io.netty.handler.timeout.ReadTimeoutHandler), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2019-07-10 14:51:19.543 DEBUG [-,,,] 2940 --- [ctor-http-nio-4] reactor.netty.ReactorNetty               : [id: 0xa7f41d1e, L:/127.0.0.1:62384 ! R:localhost/127.0.0.1:8990] Non Removed handler: WriteTimeoutHandler, context: ChannelHandlerContext(WriteTimeoutHandler, [id: 0xa7f41d1e, L:/127.0.0.1:62384 ! R:localhost/127.0.0.1:8990]), pipeline: DefaultChannelPipeline{(reactor.left.loggingHandler = io.netty.handler.logging.LoggingHandler), (reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (WriteTimeoutHandler = io.netty.handler.timeout.WriteTimeoutHandler), (ReadTimeoutHandler = io.netty.handler.timeout.ReadTimeoutHandler), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2019-07-10 14:51:19.543 DEBUG [-,,,] 2940 --- [ctor-http-nio-4] reactor.netty.tcp.TcpClient              : [id: 0xa7f41d1e, L:/127.0.0.1:62384 ! R:localhost/127.0.0.1:8990] INACTIVE
2019-07-10 14:51:19.544 DEBUG [-,,,] 2940 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider   : [id: 0xa7f41d1e, L:/127.0.0.1:62384 ! R:localhost/127.0.0.1:8990] onStateChange(GET{uri=/dataviews/TWN_EMPLBENINFO_FIXED?version=1.0.0&sequence=1, connection=PooledConnection{channel=[id: 0xa7f41d1e, L:/127.0.0.1:62384 ! R:localhost/127.0.0.1:8990]}}, [response_incomplete])
2019-07-10 14:51:19.544  WARN [-,,,] 2940 --- [ctor-http-nio-4] reactor.netty.channel.FluxReceive        : [id: 0xa7f41d1e, L:/127.0.0.1:62384 ! R:localhost/127.0.0.1:8990] An exception has been observed post termination

和我的处理程序

protected Mono handleClientResponseError(final ClientResponse clientResponse) {
    clientResponse.bodyToMono(Void.class);
    Mono<ErrorResponse> errorResponse = clientResponse.body(BodyExtractors.toMono(ErrorResponse.class));

    return errorResponse.flatMap(err -> {
      log.debug("Received HttpStatusCodeException when calling {} Registry: {}", getGatewayName(),
          err.getErrorEnvelope().getMessage());

      return Mono.error(new UpStreamServiceHttpException(err, clientResponse.rawStatusCode()));
    }).switchIfEmpty(Mono.error(() -> {
      log.debug("Received HttpStatusCodeException when calling {} Registry: {}", getGatewayName());

      return new UpStreamServiceHttpException("Bad Gateway", clientResponse.rawStatusCode());
    }));
  }

我已经尝试使用clientResponse.bodyToMono(Void.class);来完成响应,但它仍然无法正常工作,我需要一种方法来完成Web客户端的响应,然后能够重用连接池并摆脱那些日志消息。

我在GitHub上创建了一个问题,但它已经关闭了,所以我在这里提出这个问题。 https://github.com/spring-projects/spring-framework/issues/23249


我不理解第一段,请您能否更清晰地重写一下? - Dmitrii Sidenko
看起来你可以启用窃听日志记录。查看该响应的完整调试(HTTP网络数据包)将会很有趣。 - Brian Clozel
我编辑了帖子,现在我认为更清晰了,并且我还添加了启用Wiretap的日志条目。 - Douglas Santos
3个回答

19

所以我终于找到了一种完成响应的方法,我将在这里分享给任何遇到这个问题的人

之前我有这样的代码:

 private Mono<Optional<JsonNode>> handleHttpErrorStatus(final ClientResponse clientResponse) {
    if (clientResponse.statusCode().equals(HttpStatus.NOT_FOUND)) {
      clientResponse.bodyToMono(Void.class);
      return Mono.just(Optional.empty());
    } else {
      return handleClientResponseError(clientResponse);
    }
  }

但它没有起作用,显然是因为我没有返回它,所以在深入挖掘后,我尝试了这个:

private Mono<Optional<JsonNode>> handleHttpErrorStatus(final ClientResponse clientResponse) {
    if (clientResponse.statusCode().equals(HttpStatus.NOT_FOUND)) {
      return clientResponse.bodyToMono(Void.class).thenReturn((Optional.empty()));
    } else {
      return handleClientResponseError(clientResponse);
    }
  }

它运行良好,我检查了窃听日志,现在一切看起来都很好。

2019-07-10 16:44:39.096 DEBUG [-,,,] 16260 --- [ctor-http-nio-2] r.n.http.client.HttpClientOperations     : [id: 0x461d8170, L:/127.0.0.1:64298 - R:localhost/127.0.0.1:8990] Received response (auto-read:false) : [Content-Type=application/json;charset=UTF-8, Transfer-Encoding=chunked, Date=Wed, 10 Jul 2019 15:44:38 GMT]
2019-07-10 16:44:39.096 DEBUG [-,,,] 16260 --- [ctor-http-nio-2] r.n.resources.PooledConnectionProvider   : [id: 0x461d8170, L:/127.0.0.1:64298 - R:localhost/127.0.0.1:8990] onStateChange(GET{uri=/dataviews/TWN_EMPLPIM_AVRO?version=1.0.0&sequence=1, connection=PooledConnection{channel=[id: 0x461d8170, L:/127.0.0.1:64298 - R:localhost/127.0.0.1:8990]}}, [response_received])
2019-07-10 16:44:39.098 DEBUG [-,bdd6433efa276f10,bdd6433efa276f10,false] 16260 --- [ctor-http-nio-2] reactor.netty.channel.FluxReceive        : [id: 0x461d8170, L:/127.0.0.1:64298 - R:localhost/127.0.0.1:8990] Subscribing inbound receiver [pending: 0, cancelled:false, inboundDone: false]
2019-07-10 16:44:39.099 DEBUG [-,bdd6433efa276f10,bdd6433efa276f10,false] 16260 --- [ctor-http-nio-2] reactor.netty.tcp.TcpClient              : [id: 0x461d8170, L:/127.0.0.1:64298 - R:localhost/127.0.0.1:8990] CLOSE
2019-07-10 16:44:39.099 DEBUG [-,bdd6433efa276f10,bdd6433efa276f10,false] 16260 --- [ctor-http-nio-2] r.n.resources.PooledConnectionProvider   : [id: 0x461d8170, L:/127.0.0.1:64298 ! R:localhost/127.0.0.1:8990] Channel cleaned, now 1 active connections and 1 inactive connections
2019-07-10 16:44:39.099 DEBUG [-,bdd6433efa276f10,bdd6433efa276f10,false] 16260 --- [ctor-http-nio-2] r.n.resources.PooledConnectionProvider   : [id: 0x461d8170, L:/127.0.0.1:64298 ! R:localhost/127.0.0.1:8990] Channel closed, now 1 active connections and 0 inactive connections
2019-07-10 16:44:39.099 DEBUG [-,bdd6433efa276f10,bdd6433efa276f10,false] 16260 --- [ctor-http-nio-2] reactor.netty.ReactorNetty               : [id: 0x461d8170, L:/127.0.0.1:64298 ! R:localhost/127.0.0.1:8990] Non Removed handler: ReadTimeoutHandler, context: ChannelHandlerContext(ReadTimeoutHandler, [id: 0x461d8170, L:/127.0.0.1:64298 ! R:localhost/127.0.0.1:8990]), pipeline: DefaultChannelPipeline{(reactor.left.loggingHandler = io.netty.handler.logging.LoggingHandler), (reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (WriteTimeoutHandler = io.netty.handler.timeout.WriteTimeoutHandler), (ReadTimeoutHandler = io.netty.handler.timeout.ReadTimeoutHandler), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2019-07-10 16:44:39.099 DEBUG [-,bdd6433efa276f10,bdd6433efa276f10,false] 16260 --- [ctor-http-nio-2] reactor.netty.ReactorNetty               : [id: 0x461d8170, L:/127.0.0.1:64298 ! R:localhost/127.0.0.1:8990] Non Removed handler: WriteTimeoutHandler, context: ChannelHandlerContext(WriteTimeoutHandler, [id: 0x461d8170, L:/127.0.0.1:64298 ! R:localhost/127.0.0.1:8990]), pipeline: DefaultChannelPipeline{(reactor.left.loggingHandler = io.netty.handler.logging.LoggingHandler), (reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (WriteTimeoutHandler = io.netty.handler.timeout.WriteTimeoutHandler), (ReadTimeoutHandler = io.netty.handler.timeout.ReadTimeoutHandler), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2019-07-10 16:44:39.100 DEBUG [-,,,] 16260 --- [ctor-http-nio-2] reactor.netty.tcp.TcpClient              : [id: 0x461d8170, L:/127.0.0.1:64298 ! R:localhost/127.0.0.1:8990] READ COMPLETE
2019-07-10 16:44:39.102 DEBUG [-,,,] 16260 --- [ctor-http-nio-2] reactor.netty.tcp.TcpClient              : [id: 0x461d8170, L:/127.0.0.1:64298 ! R:localhost/127.0.0.1:8990] INACTIVE
2019-07-10 16:44:39.102 DEBUG [-,,,] 16260 --- [ctor-http-nio-2] reactor.netty.tcp.TcpClient              : [id: 0x461d8170, L:/127.0.0.1:64298 ! R:localhost/127.0.0.1:8990] UNREGISTERED
2019-07-10 16:44:39.122 DEBUG [-,,,] 16260 --- [ctor-http-nio-2] reactor.netty.tcp.TcpClient              : [id: 0xbe2cb147, L:/127.0.0.1:64295 - R:localhost/127.0.0.1:8990] READ: 398B

你好,能否帮忙看一下这个问题?我遇到了类似的问题。 https://stackoverflow.com/questions/65129231/webclient-java-lang-outofmemoryerror-direct-buffer-memory/65133879#65133879 - Chandresh Mishra
这是因为bodyToMono本身返回一个Mono。在对其进行操作之前,您需要先消耗掉有效载荷。 - Sebastian J.

1

我曾经也遇到过同样的问题,为了找出我在新功能部署后做错了什么,我一直在苦苦挣扎了五天。最终我恍然大悟。

所以在我的 Dockerfile 文件中,我暴露了默认端口 8080

enter image description here 这意味着我的应用程序镜像中的 Tomcat 服务器将始终在该端口上可用。我的容器还必须在端口 8080 上运行(在我的 .yml 文件中) enter image description here

在应用端口映射之前,我需要应用端口映射指令,将 Linux 主机上的外部端口 9003 映射到容器中的 8080 端口。 enter image description here

我忽略了一点,在使用 docker-compose 文件 部署服务时,我忘记将 application.yml 文件中的 server.port 更改为 8080,以便进行端口映射。我把它留在了 9003 上 (因为我在本地机器上使用 9003 来测试应用程序) 这意味着每次我使用 docker-compose 启动容器时,我的服务端口都会被映射为

0.0.0.0:9003 -> 9003/tcp 而不是 0.0.0.0:9003 -> 8080/tcp

这就是为什么 API 网关一直抛出

PrematureCloseException: Connection prematurely closed

因为实际上在我的微服务容器实例中找不到内部端口 9003,以便将 Linux 主机上的 9003 映射到其中。

我只需要将 application.yml 中的 9003 更改为 8080 就可以了。


-11

我已经通过一个解决方法,在我的测试中解决了这个问题,即在每个方法的结尾添加以下行:

try {
    Thread.sleep(5000);
} catch (InterruptedException e) {
    throw new RuntimeException(e);
}

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接