search

eclipse-ee4j / jersey

Eclipse Jersey Project - Read our Wiki:
https://github.com/eclipse-ee4j/jersey/wiki
Other
691 stars 357 forks source link

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

Closed sxsubram closed 7 months ago

sxsubram commented 9 months ago

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 commented 9 months ago

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

sxsubram commented 9 months ago

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)

"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)

"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)

"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)

"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)

"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)

"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 commented 9 months ago

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 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 commented 7 months ago

Implemented by #5542