DelegatingFilterProxy Causes Pinned Virtual Threads

[jwcarman]

I have a Spring Boot 3.3.4 application running with Java 23. I am running my Spring Boot application with virtual threads turned on. I have set the following system property:

-Djdk.tracePinnedThreads=full

When I issue a request, I see a trace printed:

VirtualThread[#74,tomcat-handler-2]/runnable@ForkJoinPool-1-worker-3 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:601)
    java.base/java.lang.System$2.parkVirtualThread(System.java:2735)
    java.base/jdk.internal.misc.VirtualThreads.park(VirtualThreads.java:54)
    java.base/java.util.concurrent.locks.LockSupport.park(LockSupport.java:369)
    java.base/sun.nio.ch.Poller.poll(Poller.java:178)
    java.base/sun.nio.ch.Poller.poll(Poller.java:139)
    java.base/sun.nio.ch.NioSocketImpl.park(NioSocketImpl.java:175)
    java.base/sun.nio.ch.NioSocketImpl.park(NioSocketImpl.java:201)
    java.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:597)
    java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327)
    java.base/java.net.Socket.connect(Socket.java:760)
    java.base/sun.security.ssl.SSLSocketImpl.connect(SSLSocketImpl.java:304)
    java.base/sun.security.ssl.BaseSSLSocketImpl.connect(BaseSSLSocketImpl.java:181)
    java.base/sun.net.NetworkClient.doConnect(NetworkClient.java:183)
    java.base/sun.net.www.http.HttpClient.openServer(HttpClient.java:531)
    java.base/sun.net.www.http.HttpClient.openServer(HttpClient.java:636)
    java.base/sun.net.www.protocol.https.HttpsClient.<init>(HttpsClient.java:264)
    java.base/sun.net.www.protocol.https.HttpsClient.New(HttpsClient.java:377)
    java.base/sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.getNewHttpClient(AbstractDelegateHttpsURLConnection.java:193)
    java.base/sun.net.www.protocol.http.HttpURLConnection.plainConnect0(HttpURLConnection.java:1228)
    java.base/sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.java:1114)
    java.base/sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.connect(AbstractDelegateHttpsURLConnection.java:179)
    java.base/sun.net.www.protocol.https.HttpsURLConnectionImpl.connect(HttpsURLConnectionImpl.java:141)
    org.springframework.http.client.SimpleClientHttpRequest.executeInternal(SimpleClientHttpRequest.java:79)
    org.springframework.http.client.AbstractStreamingClientHttpRequest.executeInternal(AbstractStreamingClientHttpRequest.java:70)
    org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:66)
    org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:889)
    org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:730)
    org.springframework.security.oauth2.jwt.NimbusJwtDecoder$JwkSetUriJwtDecoderBuilder$RestOperationsResourceRetriever.getResponse(NimbusJwtDecoder.java:488)
    org.springframework.security.oauth2.jwt.NimbusJwtDecoder$JwkSetUriJwtDecoderBuilder$RestOperationsResourceRetriever.retrieveResource(NimbusJwtDecoder.java:478)
    com.nimbusds.jose.jwk.source.RemoteJWKSet.updateJWKSetFromURL(RemoteJWKSet.java:307)
    com.nimbusds.jose.jwk.source.RemoteJWKSet.get(RemoteJWKSet.java:439) <== monitors:1
    com.nimbusds.jose.proc.JWSVerificationKeySelector.selectJWSKeys(JWSVerificationKeySelector.java:157)
    com.nimbusds.jwt.proc.DefaultJWTProcessor.selectKeys(DefaultJWTProcessor.java:283)
    com.nimbusds.jwt.proc.DefaultJWTProcessor.process(DefaultJWTProcessor.java:354)
    com.nimbusds.jwt.proc.DefaultJWTProcessor.process(DefaultJWTProcessor.java:303)
    org.springframework.security.oauth2.jwt.NimbusJwtDecoder.createJwt(NimbusJwtDecoder.java:158)
    org.springframework.security.oauth2.jwt.NimbusJwtDecoder.decode(NimbusJwtDecoder.java:138)
    org.springframework.security.oauth2.server.resource.authentication.JwtAuthenticationProvider.getJwt(JwtAuthenticationProvider.java:99)
    org.springframework.security.oauth2.server.resource.authentication.JwtAuthenticationProvider.authenticate(JwtAuthenticationProvider.java:88)
    org.springframework.security.authentication.ProviderManager.authenticate(ProviderManager.java:182)
    org.springframework.security.authentication.ObservationAuthenticationManager.lambda$authenticate$1(ObservationAuthenticationManager.java:54)
    io.micrometer.observation.Observation.observe(Observation.java:565)
    org.springframework.security.authentication.ObservationAuthenticationManager.authenticate(ObservationAuthenticationManager.java:53)
    org.springframework.security.oauth2.server.resource.web.authentication.BearerTokenAuthenticationFilter.doFilterInternal(BearerTokenAuthenticationFilter.java:137)
    org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
    org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240)
    org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227)
    org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137)
    org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:107)
    org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:93)
    org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240)
    org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227)
    org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137)
    org.springframework.security.web.csrf.CsrfFilter.doFilterInternal(CsrfFilter.java:117)
    org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
    org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240)
    org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227)
    org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137)
    org.springframework.web.filter.CorsFilter.doFilterInternal(CorsFilter.java:91)
    org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
    org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240)
    org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227)
    org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137)
    org.springframework.security.web.header.HeaderWriterFilter.doHeadersAfter(HeaderWriterFilter.java:90)
    org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:75)
    org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
    org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240)
    org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227)
    org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137)
    org.springframework.security.web.context.SecurityContextHolderFilter.doFilter(SecurityContextHolderFilter.java:82)
    org.springframework.security.web.context.SecurityContextHolderFilter.doFilter(SecurityContextHolderFilter.java:69)
    org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240)
    org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227)
    org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137)
    org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:62)
    org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
    org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240)
    org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:227)
    org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137)
    org.springframework.security.web.session.DisableEncodeUrlFilter.doFilterInternal(DisableEncodeUrlFilter.java:42)
    org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
    org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.wrapFilter(ObservationFilterChainDecorator.java:240)
    org.springframework.security.web.ObservationFilterChainDecorator$AroundFilterObservation$SimpleAroundFilterObservation.lambda$wrap$0(ObservationFilterChainDecorator.java:323)
    org.springframework.security.web.ObservationFilterChainDecorator$ObservationFilter.doFilter(ObservationFilterChainDecorator.java:224)
    org.springframework.security.web.ObservationFilterChainDecorator$VirtualFilterChain.doFilter(ObservationFilterChainDecorator.java:137)
    org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:233)
    org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:191)
    org.springframework.web.filter.CompositeFilter$VirtualFilterChain.doFilter(CompositeFilter.java:113)
    org.springframework.web.servlet.handler.HandlerMappingIntrospector.lambda$createCacheFilter$3(HandlerMappingIntrospector.java:195)
    org.springframework.web.filter.CompositeFilter$VirtualFilterChain.doFilter(CompositeFilter.java:113)
    org.springframework.web.filter.CompositeFilter.doFilter(CompositeFilter.java:74)
    org.springframework.security.config.annotation.web.configuration.WebMvcSecurityConfiguration$CompositeFilterChainProxy.doFilter(WebMvcSecurityConfiguration.java:230)
    org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:352)
    org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:268) <== monitors:1

The reason I started investigating this is because my application was having issues in Kubernetes with virtual threads enabled. When I turned off virtual threads, the application works fine again. My hunch was that the CPU count being reported to the JVM is 1 and the singular carrier thread was being occupied because of some sort of pinning.

[jwcarman]

Fantastic!