feign icon indicating copy to clipboard operation
feign copied to clipboard

Published 20 hours ago • verified publisher icon OpenFeign

Application gets stuck when Feign client is used with virtual threads

Open stsypanov opened this issue 7 months ago • 2 comments

Steps to reproduce:

  1. Checkout https://github.com/stsypanov/concurrency-demo
  2. Run DependencyApplication and then ConcurrencyDemoApplication
  3. When both apps are up run StuckApplicationTest
  4. It will take about 1-2 minutes for the test to complete
  5. Now go to demo-service/application.yml and set spring.threads.virtual.enabled: true (by default it's false).
  6. Restart ConcurrencyDemoApplication
  7. Run StuckApplicationTest again

If you now attach a profile (e.g. YourKit) you'll see there's potential deadlock with this stacktrace

Potential deadlock: frozen threads found

It seems that the following threads have not changed their stack for more than 10 seconds.
These threads are possibly (but not necessarily!) in a deadlock or hung.
+-----------------------------------------------------------------------------------------------------------------------------+
|                                                            Name                                                             |
+-----------------------------------------------------------------------------------------------------------------------------+
|  +---Read-Updater Frozen for at least 10s <Ignore a false positive>                                                         |
|  | +---jdk.internal.misc.Unsafe.park(boolean, long) Unsafe.java (native)                                                    |
|  | +---java.util.concurrent.locks.LockSupport.park() LockSupport.java:371                                                   |
|  | +---java.util.concurrent.LinkedTransferQueue$DualNode.await(Object, long, Object, boolean) LinkedTransferQueue.java:458  |
|  | +---java.util.concurrent.LinkedTransferQueue.xfer(Object, long) LinkedTransferQueue.java:613                             |
|  | +---java.util.concurrent.LinkedTransferQueue.take() LinkedTransferQueue.java:1257                                        |
|  | +---sun.nio.ch.Poller.updateLoop() Poller.java:286                                                                       |
|  | +---sun.nio.ch.Poller$$Lambda.0x0000024081474670.run()                                                                   |
|  | +---java.lang.Thread.runWith(Object, Runnable) Thread.java:1596                                                          |
|  | +---java.lang.Thread.run() Thread.java:1583                                                                              |
|  | +---jdk.internal.misc.InnocuousThread.run() InnocuousThread.java:186                                                     |
|  |                                                                                                                          |
|  +---spring.cloud.inetutils Frozen for at least 10s <Ignore a false positive>                                               |
|  | +---java.net.Inet6AddressImpl.getHostByAddr(byte[]) Inet6AddressImpl.java (native)                                       |
|  | +---java.net.InetAddress$PlatformResolver.lookupByAddress(byte[]) InetAddress.java:1225                                  |
|  | +---java.net.InetAddress.getHostFromNameService(InetAddress, boolean) InetAddress.java:840                               |
|  | +---java.net.InetAddress.getHostName(boolean) InetAddress.java:782                                                       |
|  | +---java.net.InetAddress.getHostName() InetAddress.java:754                                                              |
|  | +---org.springframework.cloud.commons.util.InetUtils$$Lambda.0x0000024081187240.call()                                   |
|  | +---java.util.concurrent.FutureTask.run() FutureTask.java:317                                                            |
|  | +---java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker) ThreadPoolExecutor.java:1144            |
|  | +---java.util.concurrent.ThreadPoolExecutor$Worker.run() ThreadPoolExecutor.java:642                                     |
|  | +---java.lang.Thread.runWith(Object, Runnable) Thread.java:1596                                                          |
|  | +---java.lang.Thread.run() Thread.java:1583                                                                              |
|  |                                                                                                                          |
|  +---Write-Updater Frozen for at least 10s <Ignore a false positive>                                                        |
|    +---jdk.internal.misc.Unsafe.park(boolean, long) Unsafe.java (native)                                                    |
|    +---java.util.concurrent.locks.LockSupport.park() LockSupport.java:371                                                   |
|    +---java.util.concurrent.LinkedTransferQueue$DualNode.await(Object, long, Object, boolean) LinkedTransferQueue.java:458  |
|    +---java.util.concurrent.LinkedTransferQueue.xfer(Object, long) LinkedTransferQueue.java:613                             |
|    +---java.util.concurrent.LinkedTransferQueue.take() LinkedTransferQueue.java:1257                                        |
|    +---sun.nio.ch.Poller.updateLoop() Poller.java:286                                                                       |
|    +---sun.nio.ch.Poller$$Lambda.0x0000024081474670.run()                                                                   |
|    +---java.lang.Thread.runWith(Object, Runnable) Thread.java:1596                                                          |
|    +---java.lang.Thread.run() Thread.java:1583                                                                              |
|    +---jdk.internal.misc.InnocuousThread.run() InnocuousThread.java:186                                                     |
+-----------------------------------------------------------------------------------------------------------------------------+

When the application is run with -XX:+EnableDynamicAgentLoading the JMV shows pinned virtual threads:

VirtualThread[#149,tomcat-handler-35]/runnable@ForkJoinPool-1-worker-20 reason:MONITOR
    java.base/java.lang.VirtualThread$VThreadContinuation.onPinned(VirtualThread.java:199)
    java.base/jdk.internal.vm.Continuation.onPinned0(Continuation.java:393)
    java.base/java.lang.VirtualThread.park(VirtualThread.java:596)
    java.base/java.lang.System$2.parkVirtualThread(System.java:2648)
    java.base/jdk.internal.misc.VirtualThreads.park(VirtualThreads.java:54)
    java.base/java.util.concurrent.locks.LockSupport.park(LockSupport.java:219)
    java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:754)
    java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:990)
    java.base/java.util.concurrent.locks.ReentrantLock$Sync.lock(ReentrantLock.java:153)
    java.base/java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:322)
    org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:319)
    org.apache.http.pool.AbstractConnPool.access$300(AbstractConnPool.java:70)
    org.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:253) <== monitors:1
    org.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:198)
    org.apache.http.impl.conn.PoolingHttpClientConnectionManager.leaseConnection(PoolingHttpClientConnectionManager.java:306)
    org.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:282)
    org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:190)
    org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
    org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
    org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
    org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
    org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
    org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
    org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
    feign.httpclient.ApacheHttpClient.execute(ApacheHttpClient.java:81)
    feign.SynchronousMethodHandler.executeAndDecode(SynchronousMethodHandler.java:100)
    feign.SynchronousMethodHandler.invoke(SynchronousMethodHandler.java:70)
    feign.ReflectiveFeign$FeignInvocationHandler.invoke(ReflectiveFeign.java:99)
    jdk.proxy2/jdk.proxy2.$Proxy71.checkHealth(Unknown Source)
    org.example.concurrencydemo.health.DownstreamServiceHealthIndicator.health(DownstreamServiceHealthIndicator.java:18)
    org.springframework.boot.actuate.health.HealthIndicator.getHealth(HealthIndicator.java:37)
    org.springframework.boot.actuate.health.HealthEndpointWebExtension.getHealth(HealthEndpointWebExtension.java:94)
    org.springframework.boot.actuate.health.HealthEndpointWebExtension.getHealth(HealthEndpointWebExtension.java:47)
    org.springframework.boot.actuate.health.HealthEndpointSupport.getLoggedHealth(HealthEndpointSupport.java:172)
    org.springframework.boot.actuate.health.HealthEndpointSupport.getContribution(HealthEndpointSupport.java:145)
    org.springframework.boot.actuate.health.HealthEndpointSupport.getAggregateContribution(HealthEndpointSupport.java:156)
    org.springframework.boot.actuate.health.HealthEndpointSupport.getContribution(HealthEndpointSupport.java:141)
    org.springframework.boot.actuate.health.HealthEndpointSupport.getHealth(HealthEndpointSupport.java:110)
    org.springframework.boot.actuate.health.HealthEndpointSupport.getHealth(HealthEndpointSupport.java:81)
    org.springframework.boot.actuate.health.HealthEndpointWebExtension.health(HealthEndpointWebExtension.java:80)
    org.springframework.boot.actuate.health.HealthEndpointWebExtension.health(HealthEndpointWebExtension.java:69)
    java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
    java.base/java.lang.reflect.Method.invoke(Method.java:580)
    org.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:281)
    org.springframework.boot.actuate.endpoint.invoke.reflect.ReflectiveOperationInvoker.invoke(ReflectiveOperationInvoker.java:74)
    org.springframework.boot.actuate.endpoint.annotation.AbstractDiscoveredOperation.invoke(AbstractDiscoveredOperation.java:60)
    org.springframework.boot.actuate.endpoint.web.servlet.AbstractWebMvcEndpointHandlerMapping$ServletWebOperationAdapter.handle(AbstractWebMvcEndpointHandlerMapping.java:327)
    org.springframework.boot.actuate.endpoint.web.servlet.AbstractWebMvcEndpointHandlerMapping$OperationHandler.handle(AbstractWebMvcEndpointHandlerMapping.java:434)
    java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
    java.base/java.lang.reflect.Method.invoke(Method.java:580)
    org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:255)
    org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:188)
    org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:118)
    org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:926)
    org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:831)
    org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
    org.springframework.boot.actuate.autoconfigure.web.servlet.CompositeHandlerAdapter.handle(CompositeHandlerAdapter.java:58)
    org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1089)
    org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:979)
    org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014)
    org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:903)
    jakarta.servlet.http.HttpServlet.service(HttpServlet.java:564)
    org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885)
    jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658)
    org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:195)
    org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140)
    org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:167)
    org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90)
    org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:483)
    org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:115)
    org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93)
    org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
    org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344)
    org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:389)
    org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63)
    org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:904)
    org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1741)
    org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52)
    java.base/java.lang.VirtualThread.run(VirtualThread.java:329)
VirtualThread[#156,tomcat-handler-42]/runnable@ForkJoinPool-1-worker-8 reason:MONITOR
    java.base/java.lang.VirtualThread$VThreadContinuation.onPinned(VirtualThread.java:199)
    java.base/jdk.internal.vm.Continuation.onPinned0(Continuation.java:393)
    java.base/java.lang.VirtualThread.park(VirtualThread.java:596)
    java.base/java.lang.System$2.parkVirtualThread(System.java:2648)
    java.base/jdk.internal.misc.VirtualThreads.park(VirtualThreads.java:54)
    java.base/java.util.concurrent.locks.LockSupport.park(LockSupport.java:369)
    java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionNode.block(AbstractQueuedSynchronizer.java:519)
    java.base/java.util.concurrent.ForkJoinPool.unmanagedBlock(ForkJoinPool.java:4011)
    java.base/java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3959)
    java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1707)
    org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:391)
    org.apache.http.pool.AbstractConnPool.access$300(AbstractConnPool.java:70)
    org.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:253) <== monitors:1
    org.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:198)
    org.apache.http.impl.conn.PoolingHttpClientConnectionManager.leaseConnection(PoolingHttpClientConnectionManager.java:306)
    org.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:282)
    org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:190)
    org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
    org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
    org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
    org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
    org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
    org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
    org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
    feign.httpclient.ApacheHttpClient.execute(ApacheHttpClient.java:81)
    feign.SynchronousMethodHandler.executeAndDecode(SynchronousMethodHandler.java:100)
    feign.SynchronousMethodHandler.invoke(SynchronousMethodHandler.java:70)
    feign.ReflectiveFeign$FeignInvocationHandler.invoke(ReflectiveFeign.java:99)
    jdk.proxy2/jdk.proxy2.$Proxy71.checkHealth(Unknown Source)
    org.example.concurrencydemo.health.DownstreamServiceHealthIndicator.health(DownstreamServiceHealthIndicator.java:18)
    org.springframework.boot.actuate.health.HealthIndicator.getHealth(HealthIndicator.java:37)
    org.springframework.boot.actuate.health.HealthEndpointWebExtension.getHealth(HealthEndpointWebExtension.java:94)
    org.springframework.boot.actuate.health.HealthEndpointWebExtension.getHealth(HealthEndpointWebExtension.java:47)
    org.springframework.boot.actuate.health.HealthEndpointSupport.getLoggedHealth(HealthEndpointSupport.java:172)
    org.springframework.boot.actuate.health.HealthEndpointSupport.getContribution(HealthEndpointSupport.java:145)
    org.springframework.boot.actuate.health.HealthEndpointSupport.getAggregateContribution(HealthEndpointSupport.java:156)
    org.springframework.boot.actuate.health.HealthEndpointSupport.getContribution(HealthEndpointSupport.java:141)
    org.springframework.boot.actuate.health.HealthEndpointSupport.getHealth(HealthEndpointSupport.java:110)
    org.springframework.boot.actuate.health.HealthEndpointSupport.getHealth(HealthEndpointSupport.java:81)
    org.springframework.boot.actuate.health.HealthEndpointWebExtension.health(HealthEndpointWebExtension.java:80)
    org.springframework.boot.actuate.health.HealthEndpointWebExtension.health(HealthEndpointWebExtension.java:69)
    java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
    java.base/java.lang.reflect.Method.invoke(Method.java:580)
    org.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:281)
    org.springframework.boot.actuate.endpoint.invoke.reflect.ReflectiveOperationInvoker.invoke(ReflectiveOperationInvoker.java:74)
    org.springframework.boot.actuate.endpoint.annotation.AbstractDiscoveredOperation.invoke(AbstractDiscoveredOperation.java:60)
    org.springframework.boot.actuate.endpoint.web.servlet.AbstractWebMvcEndpointHandlerMapping$ServletWebOperationAdapter.handle(AbstractWebMvcEndpointHandlerMapping.java:327)
    org.springframework.boot.actuate.endpoint.web.servlet.AbstractWebMvcEndpointHandlerMapping$OperationHandler.handle(AbstractWebMvcEndpointHandlerMapping.java:434)
    java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
    java.base/java.lang.reflect.Method.invoke(Method.java:580)
    org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:255)
    org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:188)
    org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:118)
    org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:926)
    org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:831)
    org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
    org.springframework.boot.actuate.autoconfigure.web.servlet.CompositeHandlerAdapter.handle(CompositeHandlerAdapter.java:58)
    org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1089)
    org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:979)
    org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014)
    org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:903)
    jakarta.servlet.http.HttpServlet.service(HttpServlet.java:564)
    org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885)
    jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658)
    org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:195)
    org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140)
    org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:167)
    org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90)
    org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:483)
    org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:115)
    org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93)
    org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
    org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344)
    org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:389)
    org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63)
    org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:904)
    org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1741)
    org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52)
    java.base/java.lang.VirtualThread.run(VirtualThread.java:329)

As far as I understand feign relies on org.apache.httpcomponents:httpcore:4.4.16 which is not ready for virtual threads. Upgrading to httpcore5 might be a solution.

stsypanov avatar Jul 25 '24 12:07 stsypanov