Springboot Webclient throws "An existing connection was forcibly closed by the remote host" error when trying to call rest api in remote server.
When the server loads, the first server request loads fine. When I send the second request after some time (Say 5 mins), I am getting the error.
Webclient creation code:
WebClient webClient() {
TcpClient tcpClient = TcpClient.create()
.option(ChannelOption.CONNECT_TIMEOUT_MILLIS, 30000)
.option(ChannelOption.SO_KEEPALIVE, false)
.doOnConnected { connection ->
connection.addHandlerLast(new LoggingHandler(LogLevel.TRACE))
connection.addHandlerLast(new ReadTimeoutHandler(30))
.addHandlerLast(new WriteTimeoutHandler(30))
.addHandlerLast(new IdleStateHandler(30,30,30))
}
ReactorClientHttpConnector httpConnector = new ReactorClientHttpConnector(HttpClient.from(tcpClient))
return WebClient.builder()
.clientConnector(httpConnector)
.build()
}
Please find the logs below. It looks like the connection is not properly closed.
Could you please let me know how to resolve it?
2019-04-10 15:26:31.534 INFO 235344 --- [nio-8080-exec-2] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet'
2019-04-10 15:26:31.534 INFO 235344 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'
2019-04-10 15:26:31.544 INFO 235344 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Completed initialization in 10 ms
2019-04-10 15:26:31.820 DEBUG 235344 --- [nio-8080-exec-2] reactor.netty.tcp.TcpResources : [tcp] resources will use the default LoopResources: DefaultLoopResources {prefix=reactor-tcp, daemon=true, selectCount=4, workerCount=4}
2019-04-10 15:26:31.821 DEBUG 235344 --- [nio-8080-exec-2] reactor.netty.tcp.TcpResources : [tcp] resources will use the default ConnectionProvider: PooledConnectionProvider {name=tcp, poolFactory=reactor.netty.resources.ConnectionProvider$$Lambda$377/205810452@3af356f}
2019-04-10 15:26:32.127 DEBUG 235344 --- [nio-8080-exec-2] r.netty.resources.DefaultLoopEpoll : Default Epoll support : false
2019-04-10 15:26:32.128 DEBUG 235344 --- [nio-8080-exec-2] r.netty.resources.DefaultLoopKQueue : Default KQueue support : false
2019-04-10 15:26:32.131 DEBUG 235344 --- [nio-8080-exec-2] i.n.channel.MultithreadEventLoopGroup : -Dio.netty.eventLoopThreads: 8
2019-04-10 15:26:32.161 DEBUG 235344 --- [nio-8080-exec-2] io.netty.channel.nio.NioEventLoop : -Dio.netty.noKeySetOptimization: false
2019-04-10 15:26:32.161 DEBUG 235344 --- [nio-8080-exec-2] io.netty.channel.nio.NioEventLoop : -Dio.netty.selectorAutoRebuildThreshold: 512
2019-04-10 15:26:32.165 DEBUG 235344 --- [nio-8080-exec-2] i.netty.util.internal.PlatformDependent : org.jctools-core.MpscChunkedArrayQueue: available
2019-04-10 15:26:32.297 INFO 235344 --- [nio-8080-exec-2] reactor.Mono.SwitchIfEmpty.1 : onSubscribe(FluxSwitchIfEmpty.SwitchIfEmptySubscriber)
2019-04-10 15:26:32.316 INFO 235344 --- [nio-8080-exec-2] reactor.Mono.SwitchIfEmpty.1 : request(unbounded)
2019-04-10 15:26:32.362 DEBUG 235344 --- [nio-8080-exec-2] io.netty.handler.ssl.OpenSsl : netty-tcnative not in the classpath; OpenSslEngine will be unavailable.
2019-04-10 15:26:32.903 DEBUG 235344 --- [nio-8080-exec-2] io.netty.handler.ssl.JdkSslContext : Default protocols (JDK): [TLSv1.2, TLSv1.1, TLSv1]
2019-04-10 15:26:32.903 DEBUG 235344 --- [nio-8080-exec-2] io.netty.handler.ssl.JdkSslContext : Default cipher suites (JDK): [TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_AES_128_GCM_SHA256, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_CBC_SHA]
2019-04-10 15:26:32.929 DEBUG 235344 --- [nio-8080-exec-2] r.n.resources.PooledConnectionProvider : Creating new client pool [tcp] for remoteserver.host.com:443
2019-04-10 15:26:32.945 DEBUG 235344 --- [nio-8080-exec-2] io.netty.channel.DefaultChannelId : -Dio.netty.processId: 235344 (auto-detected)
2019-04-10 15:26:33.242 DEBUG 235344 --- [nio-8080-exec-2] io.netty.channel.DefaultChannelId : -Dio.netty.machineId: 1c:4d:70:ff:fe:a5:c9:6d (auto-detected)
2019-04-10 15:26:33.287 DEBUG 235344 --- [nio-8080-exec-2] io.netty.buffer.ByteBufUtil : -Dio.netty.allocator.type: pooled
2019-04-10 15:26:33.287 DEBUG 235344 --- [nio-8080-exec-2] io.netty.buffer.ByteBufUtil : -Dio.netty.threadLocalDirectBufferSize: 0
2019-04-10 15:26:33.287 DEBUG 235344 --- [nio-8080-exec-2] io.netty.buffer.ByteBufUtil : -Dio.netty.maxThreadLocalCharBufferSize: 16384
2019-04-10 15:26:33.309 DEBUG 235344 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider : [id: 0xb38d8bca] Created new pooled channel, now 0 active connections and 1 inactive connections
2019-04-10 15:26:33.343 DEBUG 235344 --- [ctor-http-nio-4] io.netty.buffer.AbstractByteBuf : -Dio.netty.buffer.checkAccessible: true
2019-04-10 15:26:33.344 DEBUG 235344 --- [ctor-http-nio-4] io.netty.buffer.AbstractByteBuf : -Dio.netty.buffer.checkBounds: true
2019-04-10 15:26:33.346 DEBUG 235344 --- [ctor-http-nio-4] i.n.util.ResourceLeakDetectorFactory : Loaded default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@403ca90
2019-04-10 15:26:33.374 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.tcp.SslProvider : [id: 0xb38d8bca] SSL enabled using engine SSLEngineImpl and SNI remoteserver.host.com:443
2019-04-10 15:26:33.386 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.channel.BootstrapHandlers : [id: 0xb38d8bca] Initialized pipeline DefaultChannelPipeline{(reactor.left.sslHandler = io.netty.handler.ssl.SslHandler), (reactor.left.sslReader = reactor.netty.tcp.SslProvider$SslReadHandler), (BootstrapHandlers$BootstrapInitializerHandler#0 = reactor.netty.channel.BootstrapHandlers$BootstrapInitializerHandler), (SimpleChannelPool$1#0 = io.netty.channel.pool.SimpleChannelPool$1), (reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2019-04-10 15:26:33.617 DEBUG 235344 --- [ctor-http-nio-4] io.netty.util.Recycler : -Dio.netty.recycler.maxCapacityPerThread: 4096
2019-04-10 15:26:33.618 DEBUG 235344 --- [ctor-http-nio-4] io.netty.util.Recycler : -Dio.netty.recycler.maxSharedCapacityFactor: 2
2019-04-10 15:26:33.618 DEBUG 235344 --- [ctor-http-nio-4] io.netty.util.Recycler : -Dio.netty.recycler.linkCapacity: 16
2019-04-10 15:26:33.618 DEBUG 235344 --- [ctor-http-nio-4] io.netty.util.Recycler : -Dio.netty.recycler.ratio: 8
2019-04-10 15:26:33.648 DEBUG 235344 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Registering pool release on close event for channel
2019-04-10 15:26:33.648 DEBUG 235344 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Channel connected, now 1 active connections and 0 inactive connections
2019-04-10 15:26:33.855 DEBUG 235344 --- [ctor-http-nio-4] io.netty.handler.ssl.SslHandler : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] HANDSHAKEN: TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA
2019-04-10 15:26:33.857 DEBUG 235344 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] onStateChange(PooledConnection{channel=[id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443]}, [connected])
2019-04-10 15:26:33.887 DEBUG 235344 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] onStateChange(GET{uri=/, connection=PooledConnection{channel=[id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443]}}, [configured])
2019-04-10 15:26:33.890 DEBUG 235344 --- [ctor-http-nio-4] r.netty.http.client.HttpClientConnect : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Handler is being applied: {uri=https://remoteserver.host.com/api/v1/Test, method=POST}
2019-04-10 15:26:34.014 DEBUG 235344 --- [ctor-http-nio-4] r.n.channel.ChannelOperationsHandler : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Writing object DefaultHttpRequest(decodeResult: success, version: HTTP/1.1)
POST /api/v1/Test HTTP/1.1
user-agent: ReactorNetty/0.8.6.RELEASE
host: remoteserver.host.com
Accept: application/json;charset=UTF-8
Content-Type: application/json
Content-Length: 28
2019-04-10 15:26:34.043 DEBUG 235344 --- [ctor-http-nio-4] r.n.channel.ChannelOperationsHandler : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Writing object
2019-04-10 15:26:34.050 DEBUG 235344 --- [ctor-http-nio-4] r.n.channel.ChannelOperationsHandler : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Writing object EmptyLastHttpContent
2019-04-10 15:26:34.051 DEBUG 235344 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] onStateChange(POST{uri=/api/v1/Test, connection=PooledConnection{channel=[id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443]}}, [request_sent])
2019-04-10 15:26:34.229 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.ReactorNetty : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Added decoder [LoggingHandler] at the end of the user pipeline, full pipeline: [reactor.left.sslHandler, reactor.left.httpCodec, LoggingHandler, reactor.right.reactiveBridge, DefaultChannelPipeline$TailContext#0]
2019-04-10 15:26:34.254 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.ReactorNetty : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Added decoder [ReadTimeoutHandler] at the end of the user pipeline, full pipeline: [reactor.left.sslHandler, reactor.left.httpCodec, LoggingHandler, ReadTimeoutHandler, reactor.right.reactiveBridge, DefaultChannelPipeline$TailContext#0]
2019-04-10 15:26:34.271 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.ReactorNetty : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Added decoder [WriteTimeoutHandler] at the end of the user pipeline, full pipeline: [reactor.left.sslHandler, reactor.left.httpCodec, LoggingHandler, ReadTimeoutHandler, WriteTimeoutHandler, reactor.right.reactiveBridge, DefaultChannelPipeline$TailContext#0]
2019-04-10 15:26:34.274 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.ReactorNetty : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Added decoder [IdleStateHandler] at the end of the user pipeline, full pipeline: [reactor.left.sslHandler, reactor.left.httpCodec, LoggingHandler, ReadTimeoutHandler, WriteTimeoutHandler, IdleStateHandler, reactor.right.reactiveBridge, DefaultChannelPipeline$TailContext#0]
2019-04-10 15:26:34.289 DEBUG 235344 --- [ctor-http-nio-4] r.n.http.client.HttpClientOperations : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Received response (auto-read:false) : [Transfer-Encoding=chunked, Content-Type=application/json; charset=utf-8, Server=Kestrel, Server-Timing=api;desc=dotREZ API;dur=7, cache;desc=Cache read/write;ct=1;dur=1, total;dur=8, X-Powered-By=ASP.NET, Set-Cookie=dtCookie=17$0D7C3AB4BE87B44D72811D72E8C4878F; Path=/; Domain=.test.com, Date=Wed, 10 Apr 2019 21:26:37 GMT, Set-Cookie=dotrez=67235850.20480.0000; path=/; Httponly; Secure]
2019-04-10 15:26:34.289 DEBUG 235344 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] onStateChange(POST{uri=/api/v1/Test, connection=PooledConnection{channel=[id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443]}}, [response_received])
2019-04-10 15:26:34.295 INFO 235344 --- [ctor-http-nio-4] reactor.Mono.SwitchIfEmpty.1 : onNext(org.springframework.web.reactive.function.client.DefaultClientResponse@5119d40e)
2019-04-10 15:26:34.337 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.channel.FluxReceive : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Subscribing inbound receiver [pending: 0, cancelled:false, inboundDone: false]
2019-04-10 15:26:34.338 INFO 235344 --- [ctor-http-nio-4] reactor.Mono.MapFuseable.2 : | onSubscribe([Fuseable] FluxMapFuseable.MapFuseableSubscriber)
2019-04-10 15:26:34.338 INFO 235344 --- [ctor-http-nio-4] reactor.Mono.MapFuseable.2 : | request(unbounded)
2019-04-10 15:26:34.338 INFO 235344 --- [ctor-http-nio-4] reactor.Mono.SwitchIfEmpty.1 : onComplete()
2019-04-10 15:26:34.346 DEBUG 235344 --- [ctor-http-nio-4] r.n.http.client.HttpClientOperations : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Received last HTTP packet
2019-04-10 15:26:34.347 INFO 235344 --- [ctor-http-nio-4] reactor.Mono.MapFuseable.2 : | onNext({"data":{"result"}})
2019-04-10 15:26:34.354 INFO 235344 --- [ctor-http-nio-4] reactor.Mono.MapFuseable.2 : | onComplete()
2019-04-10 15:26:34.355 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.ReactorNetty : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Removed handler: LoggingHandler, pipeline: DefaultChannelPipeline{(reactor.left.sslHandler = io.netty.handler.ssl.SslHandler), (reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (ReadTimeoutHandler = io.netty.handler.timeout.ReadTimeoutHandler), (WriteTimeoutHandler = io.netty.handler.timeout.WriteTimeoutHandler), (IdleStateHandler = io.netty.handler.timeout.IdleStateHandler), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2019-04-10 15:26:34.355 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.ReactorNetty : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Removed handler: ReadTimeoutHandler, pipeline: DefaultChannelPipeline{(reactor.left.sslHandler = io.netty.handler.ssl.SslHandler), (reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (WriteTimeoutHandler = io.netty.handler.timeout.WriteTimeoutHandler), (IdleStateHandler = io.netty.handler.timeout.IdleStateHandler), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2019-04-10 15:26:34.355 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.ReactorNetty : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Removed handler: WriteTimeoutHandler, pipeline: DefaultChannelPipeline{(reactor.left.sslHandler = io.netty.handler.ssl.SslHandler), (reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (IdleStateHandler = io.netty.handler.timeout.IdleStateHandler), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2019-04-10 15:26:34.355 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.ReactorNetty : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Removed handler: IdleStateHandler, pipeline: DefaultChannelPipeline{(reactor.left.sslHandler = io.netty.handler.ssl.SslHandler), (reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2019-04-10 15:26:34.355 DEBUG 235344 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] onStateChange(POST{uri=/api/v1/Test, connection=PooledConnection{channel=[id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443]}}, [disconnecting])
2019-04-10 15:26:34.355 DEBUG 235344 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Releasing channel
2019-04-10 15:26:34.356 DEBUG 235344 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Channel cleaned, now 0 active connections and 1 inactive connections
2019-04-10 15:34:27.178 INFO 235344 --- [nio-8080-exec-5] reactor.Mono.SwitchIfEmpty.3 : onSubscribe(FluxSwitchIfEmpty.SwitchIfEmptySubscriber)
2019-04-10 15:34:27.179 INFO 235344 --- [nio-8080-exec-5] reactor.Mono.SwitchIfEmpty.3 : request(unbounded)
2019-04-10 15:34:27.184 DEBUG 235344 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Channel acquired, now 1 active connections and 0 inactive connections
2019-04-10 15:34:27.184 DEBUG 235344 --- [ctor-http-nio-4] r.netty.http.client.HttpClientConnect : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Handler is being applied: {uri=https://remoteserver.host.com/api/v1/Test, method=POST}
2019-04-10 15:34:27.185 DEBUG 235344 --- [ctor-http-nio-4] r.n.channel.ChannelOperationsHandler : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Writing object DefaultHttpRequest(decodeResult: success, version: HTTP/1.1)
POST /api/v1/Test HTTP/1.1
user-agent: ReactorNetty/0.8.6.RELEASE
host: remoteserver.host.com
Accept: application/json;charset=UTF-8
Content-Type: application/json
Content-Length: 28
2019-04-10 15:34:27.187 DEBUG 235344 --- [ctor-http-nio-4] r.n.channel.ChannelOperationsHandler : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Writing object
2019-04-10 15:34:27.187 DEBUG 235344 --- [ctor-http-nio-4] r.n.channel.ChannelOperationsHandler : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Writing object EmptyLastHttpContent
2019-04-10 15:34:27.188 DEBUG 235344 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] onStateChange(POST{uri=/api/v1/Test, connection=PooledConnection{channel=[id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443]}}, [request_sent])
2019-04-10 15:34:27.188 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.ReactorNetty : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Added decoder [LoggingHandler] at the end of the user pipeline, full pipeline: [reactor.left.sslHandler, reactor.left.httpCodec, LoggingHandler, reactor.right.reactiveBridge, DefaultChannelPipeline$TailContext#0]
2019-04-10 15:34:27.189 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.ReactorNetty : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Added decoder [ReadTimeoutHandler] at the end of the user pipeline, full pipeline: [reactor.left.sslHandler, reactor.left.httpCodec, LoggingHandler, ReadTimeoutHandler, reactor.right.reactiveBridge, DefaultChannelPipeline$TailContext#0]
2019-04-10 15:34:27.189 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.ReactorNetty : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Added decoder [WriteTimeoutHandler] at the end of the user pipeline, full pipeline: [reactor.left.sslHandler, reactor.left.httpCodec, LoggingHandler, ReadTimeoutHandler, WriteTimeoutHandler, reactor.right.reactiveBridge, DefaultChannelPipeline$TailContext#0]
2019-04-10 15:34:27.189 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.ReactorNetty : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Added decoder [IdleStateHandler] at the end of the user pipeline, full pipeline: [reactor.left.sslHandler, reactor.left.httpCodec, LoggingHandler, ReadTimeoutHandler, WriteTimeoutHandler, IdleStateHandler, reactor.right.reactiveBridge, DefaultChannelPipeline$TailContext#0]
2019-04-10 15:34:46.395 WARN 235344 --- [ctor-http-nio-4] r.netty.http.client.HttpClientConnect : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 - R:remoteserver.host.com/xx.xxx.xxx.xxx:443] The connection observed an error
java.io.IOException: An existing connection was forcibly closed by the remote host
at sun.nio.ch.SocketDispatcher.read0(Native Method) ~[na:1.8.0_201]
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:43) ~[na:1.8.0_201]
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223) ~[na:1.8.0_201]
at sun.nio.ch.IOUtil.read(IOUtil.java:192) ~[na:1.8.0_201]
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:380) ~[na:1.8.0_201]
at io.netty.buffer.PooledUnsafeDirectByteBuf.setBytes(PooledUnsafeDirectByteBuf.java:288) ~[netty-buffer-4.1.34.Final.jar:4.1.34.Final]
at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1125) ~[netty-buffer-4.1.34.Final.jar:4.1.34.Final]
at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:347) ~[netty-transport-4.1.34.Final.jar:4.1.34.Final]
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:148) ~[netty-transport-4.1.34.Final.jar:4.1.34.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:677) [netty-transport-4.1.34.Final.jar:4.1.34.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:612) [netty-transport-4.1.34.Final.jar:4.1.34.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:529) [netty-transport-4.1.34.Final.jar:4.1.34.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:491) [netty-transport-4.1.34.Final.jar:4.1.34.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:905) [netty-common-4.1.34.Final.jar:4.1.34.Final]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_201]
2019-04-10 15:34:46.396 ERROR 235344 --- [ctor-http-nio-4] reactor.Mono.SwitchIfEmpty.3 : onError(java.io.IOException: An existing connection was forcibly closed by the remote host)
2019-04-10 15:34:46.397 ERROR 235344 --- [ctor-http-nio-4] reactor.Mono.SwitchIfEmpty.3 :
java.io.IOException: An existing connection was forcibly closed by the remote host
2019-04-10 15:34:46.398 DEBUG 235344 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 ! R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Channel cleaned, now 0 active connections and 1 inactive connections
2019-04-10 15:34:46.399 DEBUG 235344 --- [ctor-http-nio-4] r.n.resources.PooledConnectionProvider : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 ! R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Channel closed, now 0 active connections and 0 inactive connections
2019-04-10 15:34:46.399 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.ReactorNetty : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 ! R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Non Removed handler: LoggingHandler, context: ChannelHandlerContext(LoggingHandler, [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 ! R:remoteserver.host.com/xx.xxx.xxx.xxx:443]), pipeline: DefaultChannelPipeline{(reactor.left.sslHandler = io.netty.handler.ssl.SslHandler), (reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (LoggingHandler = io.netty.handler.logging.LoggingHandler), (ReadTimeoutHandler = io.netty.handler.timeout.ReadTimeoutHandler), (WriteTimeoutHandler = io.netty.handler.timeout.WriteTimeoutHandler), (IdleStateHandler = io.netty.handler.timeout.IdleStateHandler), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2019-04-10 15:34:46.399 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.ReactorNetty : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 ! R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Non Removed handler: ReadTimeoutHandler, context: ChannelHandlerContext(ReadTimeoutHandler, [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 ! R:remoteserver.host.com/xx.xxx.xxx.xxx:443]), pipeline: DefaultChannelPipeline{(reactor.left.sslHandler = io.netty.handler.ssl.SslHandler), (reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (LoggingHandler = io.netty.handler.logging.LoggingHandler), (ReadTimeoutHandler = io.netty.handler.timeout.ReadTimeoutHandler), (WriteTimeoutHandler = io.netty.handler.timeout.WriteTimeoutHandler), (IdleStateHandler = io.netty.handler.timeout.IdleStateHandler), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2019-04-10 15:34:46.399 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.ReactorNetty : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 ! R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Non Removed handler: WriteTimeoutHandler, context: ChannelHandlerContext(WriteTimeoutHandler, [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 ! R:remoteserver.host.com/xx.xxx.xxx.xxx:443]), pipeline: DefaultChannelPipeline{(reactor.left.sslHandler = io.netty.handler.ssl.SslHandler), (reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (LoggingHandler = io.netty.handler.logging.LoggingHandler), (ReadTimeoutHandler = io.netty.handler.timeout.ReadTimeoutHandler), (WriteTimeoutHandler = io.netty.handler.timeout.WriteTimeoutHandler), (IdleStateHandler = io.netty.handler.timeout.IdleStateHandler), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2019-04-10 15:34:46.399 DEBUG 235344 --- [ctor-http-nio-4] reactor.netty.ReactorNetty : [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 ! R:remoteserver.host.com/xx.xxx.xxx.xxx:443] Non Removed handler: IdleStateHandler, context: ChannelHandlerContext(IdleStateHandler, [id: 0xb38d8bca, L:/xx.xxx.x.xxx:55712 ! R:remoteserver.host.com/xx.xxx.xxx.xxx:443]), pipeline: DefaultChannelPipeline{(reactor.left.sslHandler = io.netty.handler.ssl.SslHandler), (reactor.left.httpCodec = io.netty.handler.codec.http.HttpClientCodec), (LoggingHandler = io.netty.handler.logging.LoggingHandler), (ReadTimeoutHandler = io.netty.handler.timeout.ReadTimeoutHandler), (WriteTimeoutHandler = io.netty.handler.timeout.WriteTimeoutHandler), (IdleStateHandler = io.netty.handler.timeout.IdleStateHandler), (reactor.right.reactiveBridge = reactor.netty.channel.ChannelOperationsHandler)}
2019-04-10 15:34:46.414 ERROR 235344 --- [nio-8080-exec-7] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] threw exception
