webclient не может получить ответ на второй запрос при последовательном вызове - PullRequest
Новая
       42

webclient не может получить ответ на второй запрос при последовательном вызове

0 голосов
/ 22 апреля 2020 
class ServiceA {
  public Mono<String> getResponse() {
    return authService.auth()
             .map(this::setAuth)
             .flatMap(this::callAPI);
  }

  private APIRequest setAuth(String token) {
    return APIRequest.builder
             .token(token)
             .build;
  }

  private Mono<String> callAPI(APIRequest request) {
    return webclient.post()
             .uri(apiUri)
             .header(HttpHeaders.CONTENT_TYPE, MediaType.APPLICATION_JSON_VALUE)
             .body(request)
             .retrieve()
             .bodyToMono(String.class);
  }
}

class AuthService {
  private Mono<String> auth() {
    return webclient.post()
             .uri(authUri)
             .retrive()
             .bodyToMono(String.class);
  }
}

Когда я вызываю getResponse(), первый метод auth() возвращает ответ, но второй вызов callAPI просто отправляет запрос и зависает там до истечения времени ожидания пула соединений. У меня есть прокси, настроенный для tcpConnection при создании веб-клиента. Я был бы признателен, если бы кто-нибудь смог направить меня, где я должен проверить.

вот журнал: 

[04-22-20 16:36:44.336] [reactor-http-nio-4] DEBUG  io.netty.handler.ssl.SslHandler - [id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080] HANDSHAKEN: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
  [04-22-20 16:36:44.336] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080] onStateChange(PooledConnection{channel=[id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080]}, [connected])
  [04-22-20 16:36:44.336] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080] onStateChange(GET{uri=/, connection=PooledConnection{channel=[id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080]}}, [configured])
  [04-22-20 16:36:44.337] [reactor-http-nio-4] DEBUG  r.n.h.client.HttpClientConnect - [id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080] Handler is being applied: {uri=buildfromproduct, method=POST}
  [04-22-20 16:36:44.337] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080] onStateChange(POST{uri=buildpromproduct, connection=PooledConnection{channel=[id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080]}}, [request_prepared])
  [04-22-20 16:36:44.345] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080] onStateChange(POST{uri=buildpromproduct, connection=PooledConnection{channel=[id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080]}}, [request_sent])
  [04-22-20 16:36:45.634] [reactor-http-nio-4] DEBUG  r.n.h.c.HttpClientOperations - [id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080] Received response (auto-read:false) : [Date=Wed, 22 Apr 2020 20:36:46 GMT, Content-Type=application/json, e2etrackingid=34894528-f96d-443d-8bf8-4f6c97373e8d, Transfer-Encoding=chunked]
  [04-22-20 16:36:45.634] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080] onStateChange(POST{uri=buildpromproduct, connection=PooledConnection{channel=[id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080]}}, [response_received])
  [04-22-20 16:36:45.637] [reactor-http-nio-4] DEBUG  r.netty.channel.FluxReceive - [id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080] Subscribing inbound receiver [pending: 0, cancelled:false, inboundDone: false]
  [04-22-20 16:36:45.638] [reactor-http-nio-4] DEBUG  r.n.h.c.HttpClientOperations - [id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080] Received last HTTP packet
  [04-22-20 16:36:45.639] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080] onStateChange(POST{uri=buildpromproduct, connection=PooledConnection{channel=[id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080]}}, [response_completed])
  [04-22-20 16:36:49.450] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0x9eb287f7, L:/2.2.2.2.2:58349 - R:proxy/1.1.1.1:8080] Channel acquired, now 2 active connections and 0 inactive connections
  [04-22-20 16:36:49.452] [reactor-http-nio-4] DEBUG  r.n.h.client.HttpClientConnect - [id: 0x9eb287f7, L:/2.2.2.2.2:58349 - R:proxy/1.1.1.1:8080] Handler is being applied: {uri=https://zu2-api-np.travelport.comworkbench, method=GET}
  [04-22-20 16:36:49.455] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0x9eb287f7, L:/2.2.2.2.2:58349 - R:proxy/1.1.1.1:8080] onStateChange(GET{uri=workbench, connection=PooledConnection{channel=[id: 0x9eb287f7, L:/2.2.2.2.2:58349 - R:proxy/1.1.1.1:8080]}}, [request_prepared])
  [04-22-20 16:36:49.467] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0x9eb287f7, L:/2.2.2.2.2:58349 - R:proxy/1.1.1.1:8080] onStateChange(GET{uri=workbench, connection=PooledConnection{channel=[id: 0x9eb287f7, L:/2.2.2.2.2:58349 - R:proxy/1.1.1.1:8080]}}, [request_sent])
  [04-22-20 16:36:49.468] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080] onStateChange(POST{uri=/buildfromproduct, connection=PooledConnection{channel=[id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080]}}, [disconnecting])
  [04-22-20 16:36:49.468] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080] Releasing channel
  [04-22-20 16:36:49.468] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0x32bf0d45, L:/2.2.2.2.2:58358 - R:proxy/1.1.1.1:8080] Channel cleaned, now 1 active connections and 1 inactive connections
  [04-22-20 16:37:32.402] [Thread-5] INFO   c.utils.MemoryMonitor - Free Memory 243752 KB : Max Memory 4194304 KB : Used Memory 135127 KB
  [04-22-20 16:37:32.403] [Thread-5] INFO   c.utils.MemoryMonitor - gc values G1 Young Generation 12 84 0 0.0 60000
  [04-22-20 16:37:32.404] [Thread-5] INFO   c.utils.MemoryMonitor - gc values G1 Old Generation 0 0 0 0.0 60000
  [04-22-20 16:37:32.405] [Thread-5] INFO   c.utils.MemoryMonitor - cpu time 14079775000 12961594000 60007 12 0.16
  [04-22-20 16:37:32.405] [Thread-5] INFO   c.utils.MemoryMonitor - GCStats GCTimePercent=0.0, GCCPUPercent=0.16, ProcessLoad=0.00, SystemLoad=0.10, SystemLoadAverage=2.68
  [04-22-20 16:37:59.868] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0xcabdbecc, L:/2.2.2.2.2:58286 ! R:proxy/1.1.1.1:8080] Channel closed, now 0 active connections and 1 inactive connections
  [04-22-20 16:37:59.874] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0xcabdbecc, L:/2.2.2.2.2:58286 ! R:proxy/1.1.1.1:8080] onStateChange(PooledConnection{channel=[id: 0xcabdbecc, L:/2.2.2.2.2:58286 ! R:proxy/1.1.1.1:8080]}, [disconnecting])
  [04-22-20 16:37:59.874] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0xcabdbecc, L:/2.2.2.2.2:58286 ! R:proxy/1.1.1.1:8080] Releasing channel
  [04-22-20 16:37:59.874] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0xcabdbecc, L:/2.2.2.2.2:58286 ! R:proxy/1.1.1.1:8080] Channel cleaned, now 0 active connections and 1 inactive connections
  [04-22-20 16:38:32.408] [Thread-5] INFO   c.utils.MemoryMonitor - Free Memory 243752 KB : Max Memory 4194304 KB : Used Memory 135127 KB
  [04-22-20 16:38:32.408] [Thread-5] INFO   c.utils.MemoryMonitor - gc values G1 Young Generation 12 84 0 0.0 60000
  [04-22-20 16:38:32.408] [Thread-5] INFO   c.utils.MemoryMonitor - gc values G1 Old Generation 0 0 0 0.0 60000
  [04-22-20 16:38:32.409] [Thread-5] INFO   c.utils.MemoryMonitor - cpu time 14158539000 14079775000 60005 12 0.01
  [04-22-20 16:38:32.409] [Thread-5] INFO   c.utils.MemoryMonitor - GCStats GCTimePercent=0.0, GCCPUPercent=0.01, ProcessLoad=0.00, SystemLoad=0.06, SystemLoadAverage=3.51
  [04-22-20 16:38:56.864] [reactor-http-nio-4] DEBUG  r.n.h.c.HttpClientOperations - [id: 0x9eb287f7, L:/2.2.2.2.2:58349 - R:proxy/1.1.1.1:8080] Received response (auto-read:false) : [Date=Wed, 22 Apr 2020 20:36:52 GMT, Content-Type=application/json, Content-Length=305, Connection=close]
  [04-22-20 16:38:56.865] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0x9eb287f7, L:/2.2.2.2.2:58349 - R:proxy/1.1.1.1:8080] onStateChange(GET{uri=workbench, connection=PooledConnection{channel=[id: 0x9eb287f7, L:/2.2.2.2.2:58349 - R:proxy/1.1.1.1:8080]}}, [response_received])
  [04-22-20 16:38:56.867] [reactor-http-nio-4] DEBUG  r.netty.channel.FluxReceive - [id: 0x9eb287f7, L:/2.2.2.2.2:58349 - R:proxy/1.1.1.1:8080] Subscribing inbound receiver [pending: 0, cancelled:false, inboundDone: false]
  [04-22-20 16:38:56.868] [reactor-http-nio-4] DEBUG  r.n.h.c.HttpClientOperations - [id: 0x9eb287f7, L:/2.2.2.2.2:58349 - R:proxy/1.1.1.1:8080] Received last HTTP packet
  [04-22-20 16:38:56.868] [reactor-http-nio-4] DEBUG  r.n.r.PooledConnectionProvider - [id: 0x9eb287f7, L:/2.2.2.2.2:58349 - R:proxy/1.1.1.1:8080] onStateChange(GE
...