jersey-netty-connector - Cancelling the future returned by rx() client does not terminate the request

[sxsubram]

Testing with jersey-netty-connector 2.41 and JDK17

We have a use case in which an executing request needs to be terminated if a processing timeout is reached. In the jersey-netty-connector implementation calling cancel on the future returned by rx() client is a no-op. Response is available even after cancel is invoked.

jersey-netty-connector should either -

1. terminate the request and clean up resources when a cancel is invoked on the future OR
2. provide an option for the client to set a request processing timeout. When this timeout is set executing request is terminated and cleaned up when timeout occurs. (Preferred option)

[jbescos]

Hi @sxsubram, could you provide a thread dump when that happens, please?

[sxsubram]

This is the dump captured after cancel is called
jstack 52836
2024-02-21 09:22:30
Full thread dump Java HotSpot(TM) 64-Bit Server VM (17.0.9+11-LTS-201 mixed mode, sharing):

Threads class SMR info:
_java_thread_list=0x0000600003b18ae0, length=16, elements={
0x00007fe80b024200, 0x00007fe80b024800, 0x00007fe80b02cc00, 0x00007fe809043c00,
0x00007fe80a890e00, 0x00007fe80b02d200, 0x00007fe809044c00, 0x00007fe80a028a00,
0x00007fe80b027000, 0x00007fe809043600, 0x00007fe80a02cc00, 0x00007fe80b035200,
0x00007fe80b027600, 0x00007fe80a1d3e00, 0x00007fe80b084400, 0x00007fe80a140400
}

"Reference Handler" #2 daemon prio=10 os_prio=31 cpu=0.79ms elapsed=315.35s tid=0x00007fe80b024200 nid=0x4803 waiting on condition [0x0000700005206000]
java.lang.Thread.State: RUNNABLE
at java.lang.ref.Reference.waitForReferencePendingList(java.base@17.0.9/Native Method)
at java.lang.ref.Reference.processPendingReferences(java.base@17.0.9/Reference.java:253)
at java.lang.ref.Reference$ReferenceHandler.run(java.base@17.0.9/Reference.java:215)

"Finalizer" #3 daemon prio=8 os_prio=31 cpu=0.27ms elapsed=315.35s tid=0x00007fe80b024800 nid=0x4703 in Object.wait() [0x0000700005309000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(java.base@17.0.9/Native Method)
- waiting on <0x0000000700085a28> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@17.0.9/ReferenceQueue.java:155)
- locked <0x0000000700085a28> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@17.0.9/ReferenceQueue.java:176)
at java.lang.ref.Finalizer$FinalizerThread.run(java.base@17.0.9/Finalizer.java:172)

"Signal Dispatcher" #4 daemon prio=9 os_prio=31 cpu=0.40ms elapsed=315.33s tid=0x00007fe80b02cc00 nid=0x7d03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"Service Thread" #5 daemon prio=9 os_prio=31 cpu=0.22ms elapsed=315.33s tid=0x00007fe809043c00 nid=0x5e03 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"Monitor Deflation Thread" #6 daemon prio=9 os_prio=31 cpu=9.31ms elapsed=315.33s tid=0x00007fe80a890e00 nid=0x5f03 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #7 daemon prio=9 os_prio=31 cpu=756.02ms elapsed=315.33s tid=0x00007fe80b02d200 nid=0x7903 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task

"C1 CompilerThread0" #9 daemon prio=9 os_prio=31 cpu=518.40ms elapsed=315.32s tid=0x00007fe809044c00 nid=0x7803 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
No compile task

"Sweeper thread" #10 daemon prio=9 os_prio=31 cpu=0.07ms elapsed=315.32s tid=0x00007fe80a028a00 nid=0x6203 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"Common-Cleaner" #11 daemon prio=8 os_prio=31 cpu=1.18ms elapsed=315.27s tid=0x00007fe80b027000 nid=0x6303 in Object.wait() [0x0000700005b24000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(java.base@17.0.9/Native Method)
- waiting on <0x000000070007fee8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(java.base@17.0.9/ReferenceQueue.java:155)
- locked <0x000000070007fee8> (a java.lang.ref.ReferenceQueue$Lock)
at jdk.internal.ref.CleanerImpl.run(java.base@17.0.9/CleanerImpl.java:140)
at java.lang.Thread.run(java.base@17.0.9/Thread.java:842)
at jdk.internal.misc.InnocuousThread.run(java.base@17.0.9/InnocuousThread.java:162)

"Monitor Ctrl-Break" #12 daemon prio=5 os_prio=31 cpu=31.41ms elapsed=315.00s tid=0x00007fe809043600 nid=0x7603 runnable [0x0000700005c27000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.SocketDispatcher.read0(java.base@17.0.9/Native Method)
at sun.nio.ch.SocketDispatcher.read(java.base@17.0.9/SocketDispatcher.java:47)
at sun.nio.ch.NioSocketImpl.tryRead(java.base@17.0.9/NioSocketImpl.java:266)
at sun.nio.ch.NioSocketImpl.implRead(java.base@17.0.9/NioSocketImpl.java:317)
at sun.nio.ch.NioSocketImpl.read(java.base@17.0.9/NioSocketImpl.java:355)
at sun.nio.ch.NioSocketImpl$1.read(java.base@17.0.9/NioSocketImpl.java:808)
at java.net.Socket$SocketInputStream.read(java.base@17.0.9/Socket.java:966)
at sun.nio.cs.StreamDecoder.readBytes(java.base@17.0.9/StreamDecoder.java:270)
at sun.nio.cs.StreamDecoder.implRead(java.base@17.0.9/StreamDecoder.java:313)
at sun.nio.cs.StreamDecoder.read(java.base@17.0.9/StreamDecoder.java:188)
- locked <0x000000070008db20> (a java.io.InputStreamReader)
at java.io.InputStreamReader.read(java.base@17.0.9/InputStreamReader.java:177)
at java.io.BufferedReader.fill(java.base@17.0.9/BufferedReader.java:162)
at java.io.BufferedReader.readLine(java.base@17.0.9/BufferedReader.java:329)
- locked <0x000000070008db20> (a java.io.InputStreamReader)
at java.io.BufferedReader.readLine(java.base@17.0.9/BufferedReader.java:396)
at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:53)

"Notification Thread" #13 daemon prio=9 os_prio=31 cpu=0.10ms elapsed=315.00s tid=0x00007fe80a02cc00 nid=0x7503 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"jersey-client-async-executor-0" #15 prio=5 os_prio=31 cpu=159.51ms elapsed=313.44s tid=0x00007fe80b035200 nid=0x6b03 waiting on condition [0x0000700006239000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@17.0.9/Native Method)
- parking to wait for <0x000000070f050818> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@17.0.9/LockSupport.java:341)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionNode.block(java.base@17.0.9/AbstractQueuedSynchronizer.java:506)
at java.util.concurrent.ForkJoinPool.unmanagedBlock(java.base@17.0.9/ForkJoinPool.java:3465)
at java.util.concurrent.ForkJoinPool.managedBlock(java.base@17.0.9/ForkJoinPool.java:3436)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@17.0.9/AbstractQueuedSynchronizer.java:1623)
at java.util.concurrent.LinkedBlockingQueue.take(java.base@17.0.9/LinkedBlockingQueue.java:435)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@17.0.9/ThreadPoolExecutor.java:1062)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@17.0.9/ThreadPoolExecutor.java:1122)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@17.0.9/ThreadPoolExecutor.java:635)
at java.lang.Thread.run(java.base@17.0.9/Thread.java:842)

"DestroyJavaVM" #16 prio=5 os_prio=31 cpu=926.97ms elapsed=313.42s tid=0x00007fe80b027600 nid=0x2803 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"nioEventLoopGroup-2-1" #17 prio=10 os_prio=31 cpu=96.23ms elapsed=313.28s tid=0x00007fe80a1d3e00 nid=0x6f03 runnable [0x000070000633c000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.KQueue.poll(java.base@17.0.9/Native Method)
at sun.nio.ch.KQueueSelectorImpl.doSelect(java.base@17.0.9/KQueueSelectorImpl.java:122)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(java.base@17.0.9/SelectorImpl.java:129)
- locked <0x000000070f04c068> (a io.netty.channel.nio.SelectedSelectionKeySet)
- locked <0x000000070f04d090> (a sun.nio.ch.KQueueSelectorImpl)
at sun.nio.ch.SelectorImpl.select(java.base@17.0.9/SelectorImpl.java:146)
at io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:68)
at io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:879)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:526)
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(java.base@17.0.9/Thread.java:842)

"pool-1-thread-1" #18 prio=5 os_prio=31 cpu=8.05ms elapsed=291.06s tid=0x00007fe80b084400 nid=0x5a07 waiting on condition [0x000070000643f000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base@17.0.9/Native Method)
- parking to wait for <0x000000070f0d1f60> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(java.base@17.0.9/LockSupport.java:341)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionNode.block(java.base@17.0.9/AbstractQueuedSynchronizer.java:506)
at java.util.concurrent.ForkJoinPool.unmanagedBlock(java.base@17.0.9/ForkJoinPool.java:3465)
at java.util.concurrent.ForkJoinPool.managedBlock(java.base@17.0.9/ForkJoinPool.java:3436)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@17.0.9/AbstractQueuedSynchronizer.java:1623)
at java.util.concurrent.LinkedBlockingQueue.take(java.base@17.0.9/LinkedBlockingQueue.java:435)
at java.util.concurrent.ThreadPoolExecutor.getTask(java.base@17.0.9/ThreadPoolExecutor.java:1062)
at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@17.0.9/ThreadPoolExecutor.java:1122)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@17.0.9/ThreadPoolExecutor.java:635)
at java.lang.Thread.run(java.base@17.0.9/Thread.java:842)

"Attach Listener" #19 daemon prio=9 os_prio=31 cpu=1.10ms elapsed=0.10s tid=0x00007fe80a140400 nid=0x6d03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"VM Thread" os_prio=31 cpu=13.18ms elapsed=315.36s tid=0x00007fe808f07970 nid=0x4b03 runnable

"GC Thread#0" os_prio=31 cpu=5.25ms elapsed=315.60

[sxsubram]

Test output

sending request to http://127.0.0.1:8000/
Feb 21, 2024 9:28:07 AM org.glassfish.jersey.client.innate.inject.NonInjectionManager
WARNING: Falling back to injection-less client.
Feb 21, 2024 9:28:07 AM org.glassfish.jersey.message.internal.MessagingBinders$EnabledProvidersBinder bindToBinder
WARNING: A class javax.activation.DataSource for a default provider MessageBodyWriter<javax.activation.DataSource> was not found. The provider is not available.
Thread[main,5,main] cancelling request
Thread[main,5,main] future.isCancelled = true
Exception in thread "main" java.util.concurrent.CancellationException
at java.base/java.util.concurrent.CompletableFuture.cancel(CompletableFuture.java:2478)
at test.FutureCancelTest.main(FutureCancelTest.java:61)
execution completed //this is being printed in the future's callbacks
Thread[pool-1-thread-1,5,main] Got hdrs = {Content-Type=[text/plain], Date=[Wed, 21 Feb 2024 17:28:30 GMT], Connection=[keep-alive], Keep-Alive=[timeout=5], Content-Length=[12]}
Thread[pool-1-thread-1,5,main] Got rsp = Hello World

[jansupol]

Implemented by #5542