-
Bug
-
Resolution: Done
-
Major
-
13.0.0.C2
-
None
When the client is trying to use a TLS protocol rejected by the server, Netty completes the createChannel() future with an exception, so ChannelPool decrements the created counter.
But Netty also invokes ActivationHandler.channelActive(), which assumes the channel was connected and registers a listener to decrement the created counter when it's closed (which is, immediately).
The double decrement makes created go below 0.
If an operation then requests another channel and createChannel() fails again, the assert currentCreated >= 0 in ChannelPool.createAndInvoke() fails, the callback isn't cancel, and the operation hangs.
TLSWithoutAuthenticationIT.testForceTLSv13 hits this issue and fails with a timeout every time since ISPN-13264 was integrated.
19:04:04,886 TRACE (testng-Test:[]) [ChannelPool] [localhost:11222] Creating new channel, created = 1, active = 1
19:04:04,981 TRACE (HotRod-client-async-pool-5-1:[]) [ChannelPool] [localhost:11222] Channel could not be created, created = 0, active = 0, connected = 0
19:04:04,983 TRACE (testng-Test:[]) [ChannelPool] [localhost:11322] Creating new channel, created = 1, active = 1
19:04:05,078 TRACE (HotRod-client-async-pool-5-2:[]) [ChannelPool] [localhost:11322] Channel could not be created, created = 0, active = 0, connected = 0
19:04:05,080 TRACE (testng-Test:[]) [RetryOnFailureOperation] Requesting channel for operation AdminOperation{(default), taskName=@@cache@getorcreate, params=[name=[B0x36304331304531423643393130353532..[40], template=[B0x6F72672E696E66696E697370616E2E44..[24]], flags=0}
19:04:05,080 TRACE (testng-Test:[]) [ChannelPool] [localhost:11222] Creating new channel, created = 1, active = 1
19:04:05,174 TRACE (HotRod-client-async-pool-5-3:[]) [ChannelPool] [localhost:11222] Channel could not be created, created = 0, active = 0, connected = 0
19:04:05,175 TRACE (HotRod-client-async-pool-5-3:[]) [RetryOnFailureOperation] Add localhost:11222 to failed servers
19:04:05,175 TRACE (HotRod-client-async-pool-5-3:[]) [RetryOnFailureOperation] Exception encountered in AdminOperation{(default), taskName=@@cache@getorcreate, params=[name=[B0x36304331304531423643393130353532..[40], template=[B0x6F72672E696E66696E697370616E2E44..[24]], flags=0}. Retry 0 out of 10
org.infinispan.client.hotrod.exceptions.TransportException: javax.net.ssl.SSLHandshakeException: No appropriate protocol (protocol is disabled or cipher suites are inappropriate)
19:04:05,176 TRACE (HotRod-client-async-pool-5-3:[]) [ChannelPool] [localhost:11322] Creating new channel, created = 1, active = 1
19:04:05,177 TRACE (HotRod-client-async-pool-5-3:[]) [ChannelPool] [localhost:11222] Closed channel [id: 0xee61f12f, L:/127.0.0.1:39914 ! R:localhost/127.0.0.1:11222], created = -1, idle = false, active = -1, connected = -1
19:04:05,271 TRACE (HotRod-client-async-pool-5-4:[]) [ChannelPool] [localhost:11322] Channel could not be created, created = 0, active = 0, connected = 0
19:04:05,271 TRACE (HotRod-client-async-pool-5-4:[]) [RetryOnFailureOperation] Add localhost:11322 to failed servers
19:04:05,271 TRACE (HotRod-client-async-pool-5-4:[]) [RetryOnFailureOperation] Exception encountered in AdminOperation{(default), taskName=@@cache@getorcreate, params=[name=[B0x36304331304531423643393130353532..[40], template=[B0x6F72672E696E66696E697370616E2E44..[24]], flags=0}. Retry 1 out of 10
org.infinispan.client.hotrod.exceptions.TransportException: javax.net.ssl.SSLHandshakeException: No appropriate protocol (protocol is disabled or cipher suites are inappropriate)
19:04:05,272 TRACE (HotRod-client-async-pool-5-4:[]) [ChannelPool] [localhost:11222] Creating new channel, created = 0, active = 0
19:04:05,273 TRACE (HotRod-client-async-pool-5-4:[]) [ChannelPool] [localhost:11322] Closed channel [id: 0xc3d5860e, L:/127.0.0.1:38412 ! R:localhost/127.0.0.1:11322], created = -1, idle = false, active = -1, connected = -1
19:04:05,367 TRACE (HotRod-client-async-pool-5-5:[]) [ChannelPool] [localhost:11222] Closed channel [id: 0x820f7dfc, L:/127.0.0.1:39916 ! R:localhost/127.0.0.1:11222], created = -1, idle = false, active = -2, connected = -2
19:09:02,018 ERROR (RunningTestsRegistry-Worker:[]) [TestSuiteProgress] Test failed: TLSWithoutAuthenticationIT.testForceTLSv13
java.lang.RuntimeException: Test timed out after 300 seconds
at jdk.internal.misc.Unsafe.park(Native Method) ~[?:?]
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234) ~[?:?]
at java.util.concurrent.CompletableFuture$Signaller.block(CompletableFuture.java:1798) ~[?:?]
at java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3128) ~[?:?]
at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1868) ~[?:?]
at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2021) ~[?:?]
at org.infinispan.client.hotrod.impl.Util.await(Util.java:52) ~[classes/:?]
at org.infinispan.client.hotrod.impl.RemoteCacheManagerAdminImpl.getOrCreateCache(RemoteCacheManagerAdminImpl.java:73) ~[classes/:?]
at org.infinispan.server.test.api.HotRodTestClientDriver.create(HotRodTestClientDriver.java:91) ~[classes/:?]
at org.infinispan.server.security.TLSWithoutAuthenticationIT.lambda$testDisabledProtocol$0(TLSWithoutAuthenticationIT.java:56) ~[test-classes/:?]
at org.infinispan.server.security.TLSWithoutAuthenticationIT$$Lambda$1288/0x000000010097ec40.run(Unknown Source) ~[?:?]
at org.infinispan.commons.test.Exceptions.extractException(Exceptions.java:279) ~[classes/:?]
at org.infinispan.commons.test.Exceptions.expectException(Exceptions.java:125) ~[classes/:?]
at org.infinispan.server.security.TLSWithoutAuthenticationIT.testDisabledProtocol(TLSWithoutAuthenticationIT.java:56) ~[test-classes/:?]