Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jetty Client not Creating a Connection from Multiplex Connection Pool #12781

Open
dev-chirag opened this issue Feb 9, 2025 · 3 comments
Open
Labels

Comments

@dev-chirag
Copy link

dev-chirag commented Feb 9, 2025

Jetty Version
Jetty 12.x

Jetty Environment

Java Version
JDK17.x
Question

I am trying to implement a hot reload of keystore and truststore in Jetty client. I was trying to replicate a corner scenario by deleting my keystore.

When I delete the keystore and SSLContextFactory reload fails, and in this time if a new request is made from the client, it will open a connection from the Multiplex Connection Pool. This Connection exchanges the TCP SYN with the server and receives the ACK. On which it fails here:

    public SSLContext getSslContext()
    {
        if (!isStarted())
            return _setContext;

        try (AutoLock l = _lock.lock())
        {
            if (_factory == null)
                throw new IllegalStateException("SslContextFactory reload failed");
            return _factory._context;
        }

This is because, SSLContextFactory was unloaded during the last failed reload.

Now, even though I have placed the correct Keystore back into the same file location, and SSLContextFactory has been reloaded too, all new requests are failing to create a connection due to the pending connection in the MultiplexConnectionPool. Attaching few logs here:

2-1099-pool]@72816e01{STARTED,8<=9<=200,i=2,r=-1,t=37990ms,q=0}[ReservedThreadExecutor@3feb76e8{reserved=2/8,pending=0}]
2025-02-08 20:24:08.676:WARN :oeju.Scanner:Scanner-1-1: FileVisit failed: /tmp/rest-server-client.jks
java.nio.file.NoSuchFileException: /tmp/rest-server-client.jks
	at java.base/sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:85)
	at java.base/sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:103)
	at java.base/sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:108)
	at java.base/sun.nio.fs.WindowsFileAttributeViews$Basic.readAttributes(WindowsFileAttributeViews.java:53)
	at java.base/sun.nio.fs.WindowsFileAttributeViews$Basic.readAttributes(WindowsFileAttributeViews.java:38)
	at java.base/sun.nio.fs.WindowsFileSystemProvider.readAttributes(WindowsFileSystemProvider.java:199)
	at java.base/java.nio.file.Files.readAttributes(Files.java:1851)
	at java.base/java.nio.file.FileTreeWalker.getAttributes(FileTreeWalker.java:226)
	at java.base/java.nio.file.FileTreeWalker.visit(FileTreeWalker.java:277)
	at java.base/java.nio.file.FileTreeWalker.walk(FileTreeWalker.java:323)
	at java.base/java.nio.file.Files.walkFileTree(Files.java:2804)
	at org.eclipse.jetty.util.Scanner.scanFiles(Scanner.java:724)
	at org.eclipse.jetty.util.Scanner.scan(Scanner.java:708)
	at org.eclipse.jetty.util.Scanner$ScanTask.run(Scanner.java:145)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
	at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:833)
2025-02-08 20:24:08.678:DEBUG:oeju.Scanner:Scanner-1-1: scan accepted /tmp/broker-client.jks mod=1738309290418
2025-02-08 20:24:08.679:DEBUG:oeju.Scanner:Scanner-1-1: scanned [/tmp/rest-server-client.jks, /tmp/broker-client.jks]
2025-02-08 20:24:12.690:DEBUG:oejut.ReservedThreadExecutor:HttpClient@a44fbea-160: ReservedThread@14596c7d{RESERVED,thread=Thread[HttpClient@a44fbea-160,5,main]} task=null ReservedThreadExecutor@7563bb39{reserved=2/8,pending=0}
2025-02-08 20:24:12.690:DEBUG:oejut.ReservedThreadExecutor:HttpClient@a44fbea-160: ReservedThread@14596c7d{IDLE,thread=Thread[HttpClient@a44fbea-160,5,main]} exited ReservedThreadExecutor@7563bb39{reserved=1/8,pending=0}
2025-02-08 20:24:12.690:DEBUG:oejut.QueuedThreadPool:HttpClient@a44fbea-160: ran ReservedThread@14596c7d{IDLE,thread=null} in QueuedThreadPool[HttpClient@a44fbea]@1767a0f9{STARTED,8<=8<=200,i=5,r=-1,t=-24824ms,q=0}[ReservedThreadExecutor@7563bb39{reserved=1/8,pending=0}]
2025-02-08 20:24:12.690:DEBUG:oejut.QueuedThreadPool:HttpClient@a44fbea-160: Evict skipped, no excess threads QueuedThreadPool[HttpClient@a44fbea]@1767a0f9{STARTED,8<=8<=200,i=6,r=-1,t=-24824ms,q=0}[ReservedThreadExecutor@7563bb39{reserved=1/8,pending=0}]
2025-02-08 20:24:12.839:DEBUG:oeji.CyclicTimeouts:JettyClient-scheduler-556843835-1: Timeouts check for org.eclipse.jetty.client.HttpDestination$RequestTimeouts@7bfe8b13
2025-02-08 20:24:12.839:DEBUG:oeji.CyclicTimeouts:JettyClient-scheduler-556843835-1: Entity HttpExchange@2a9569f6{req=HttpRequest[PATCH /nnrf-nfm/v2/nf-instances/21160c3b-dd26-45a6-b826-8eb55cb9bbe0 HTTP/2.0]@30c2422c[PENDING/null] res=HttpResponse[null 0 null]@2499f191[PENDING/null]} expires in -1 ms for org.eclipse.jetty.client.HttpDestination$RequestTimeouts@7bfe8b13
2025-02-08 20:24:12.840:DEBUG:oejc.HttpExchange:JettyClient-scheduler-556843835-1: Failed HttpExchange@2a9569f6{req=HttpRequest[PATCH /nnrf-nfm/v2/nf-instances/21160c3b-dd26-45a6-b826-8eb55cb9bbe0 HTTP/2.0]@30c2422c[COMPLETED/java.util.concurrent.TimeoutException: Total timeout 8000 ms elapsed] res=HttpResponse[null 0 null]@2499f191[COMPLETED/java.util.concurrent.TimeoutException: Total timeout 8000 ms elapsed]}: req=true/rsp=true {}
java.util.concurrent.TimeoutException: Total timeout 8000 ms elapsed
	at org.eclipse.jetty.client.HttpDestination$RequestTimeouts.onExpired(HttpDestination.java:608)
	at org.eclipse.jetty.client.HttpDestination$RequestTimeouts.onExpired(HttpDestination.java:591)
	at org.eclipse.jetty.io.CyclicTimeouts.onTimeoutExpired(CyclicTimeouts.java:106)
	at org.eclipse.jetty.io.CyclicTimeouts$Timeouts.onTimeoutExpired(CyclicTimeouts.java:193)
	at org.eclipse.jetty.io.CyclicTimeout$Wakeup.run(CyclicTimeout.java:294)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
	at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:833)
2025-02-08 20:24:12.840:DEBUG:oejc.HttpExchange:JettyClient-scheduler-556843835-1: Aborting while queued HttpExchange@2a9569f6{req=HttpRequest[PATCH /nnrf-nfm/v2/nf-instances/21160c3b-dd26-45a6-b826-8eb55cb9bbe0 HTTP/2.0]@30c2422c[COMPLETED/java.util.concurrent.TimeoutException: Total timeout 8000 ms elapsed] res=HttpResponse[null 0 null]@2499f191[COMPLETED/java.util.concurrent.TimeoutException: Total timeout 8000 ms elapsed]}: {}
java.util.concurrent.TimeoutException: Total timeout 8000 ms elapsed
	at org.eclipse.jetty.client.HttpDestination$RequestTimeouts.onExpired(HttpDestination.java:608)
	at org.eclipse.jetty.client.HttpDestination$RequestTimeouts.onExpired(HttpDestination.java:591)
	at org.eclipse.jetty.io.CyclicTimeouts.onTimeoutExpired(CyclicTimeouts.java:106)
	at org.eclipse.jetty.io.CyclicTimeouts$Timeouts.onTimeoutExpired(CyclicTimeouts.java:193)
	at org.eclipse.jetty.io.CyclicTimeout$Wakeup.run(CyclicTimeout.java:294)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
	at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:833)
2025-02-08 20:24:12.840:DEBUG:oeji.CyclicTimeouts:JettyClient-scheduler-556843835-1: Entity HttpExchange@2a9569f6{req=HttpRequest[PATCH /nnrf-nfm/v2/nf-instances/21160c3b-dd26-45a6-b826-8eb55cb9bbe0 HTTP/2.0]@30c2422c[COMPLETED/java.util.concurrent.TimeoutException: Total timeout 8000 ms elapsed] res=HttpResponse[null 0 null]@2499f191[COMPLETED/java.util.concurrent.TimeoutException: Total timeout 8000 ms elapsed]} expired, remove=false for org.eclipse.jetty.client.HttpDestination$RequestTimeouts@7bfe8b13
2025-02-08 20:24:17.841:DEBUG:oejc.HttpDestination:Timer-4: Stale check done with result false on HttpDestination[Origin@8135fc1c[https://localhost:1099,tag=null,protocol=Protocol@198cd[proto=[h2],nego=false]]]@224715e6,state=STARTED,queue=0,pool=MultiplexConnectionPool@45870ae8[s=STARTED,c=1/1/3,a=0,i=0,q=0,p=@1a98f878[inUse=0,size=1,max=3,closed=false]],stale=false,idle=-1
2025-02-08 20:24:17.841:DEBUG:oejc.HttpClient:Timer-4: Resolved HttpDestination[Origin@8135fc1c[https://localhost:1099,tag=null,protocol=Protocol@198cd[proto=[h2],nego=false]]]@224715e6,state=STARTED,queue=0,pool=MultiplexConnectionPool@45870ae8[s=STARTED,c=1/1/3,a=0,i=0,q=0,p=@1a98f878[inUse=0,size=1,max=3,closed=false]],stale=false,idle=-1 for HttpRequest[PATCH /nnrf-nfm/v2/nf-instances/21160c3b-dd26-45a6-b826-8eb55cb9bbe0 HTTP/2.0]@5c6da88
2025-02-08 20:24:17.842:DEBUG:oejc.HttpConversation:Timer-4: Exchanges in conversation 1, override=null, listeners=[org.eclipse.jetty.client.util.FutureResponseListener@7f36f44f]
2025-02-08 20:24:17.842:DEBUG:oeji.CyclicTimeouts:Timer-4: Scheduling timeout in 7999 ms for org.eclipse.jetty.client.HttpDestination$RequestTimeouts@7bfe8b13
2025-02-08 20:24:17.842:DEBUG:oeji.CyclicTimeout:Timer-4: Installed timeout in 7999 ms, new wake up in 7999 ms
2025-02-08 20:24:17.842:DEBUG:oejc.HttpDestination:Timer-4: Queued HttpRequest[PATCH /nnrf-nfm/v2/nf-instances/21160c3b-dd26-45a6-b826-8eb55cb9bbe0 HTTP/2.0]@5c6da88 for HttpDestination[Origin@8135fc1c[https://localhost:1099,tag=null,protocol=Protocol@198cd[proto=[h2],nego=false]]]@224715e6,state=STARTED,queue=1,pool=MultiplexConnectionPool@45870ae8[s=STARTED,c=1/1/3,a=0,i=0,q=1,p=@1a98f878[inUse=0,size=1,max=3,closed=false]],stale=false,idle=-1
2025-02-08 20:24:17.842:DEBUG:oejc.AbstractConnectionPool:Timer-4: Acquiring create=true on MultiplexConnectionPool@45870ae8[s=STARTED,c=1/1/3,a=0,i=0,q=1,p=@1a98f878[inUse=0,size=1,max=3,closed=false]]
2025-02-08 20:24:17.842:DEBUG:oejc.AbstractConnectionPool:Timer-4: Try creating connection 1/3 with 1 pending
2025-02-08 20:24:17.842:DEBUG:oejc.AbstractConnectionPool:Timer-4: Try creating(true) connection, pending/demand/supply: 1/2/1024, result=false
2025-02-08 20:24:18.799:DEBUG:oeju.Scanner:Scanner-1-1: scan accepted /tmp/rest-server-client.jks mod=1738310678198
2025-02-08 20:24:18.812:DEBUG:oeju.Scanner:Scanner-1-1: scan accepted /tmp/broker-client.jks mod=1738309290418
2025-02-08 20:24:18.812:DEBUG:oeju.Scanner:Scanner-1-1: scanned [/tmp/rest-server-client.jks, /tmp/broker-client.jks]
2025-02-08 20:24:25.842:DEBUG:oeji.CyclicTimeouts:JettyClient-scheduler-556843835-1: Timeouts check for org.eclipse.jetty.client.HttpDestination$RequestTimeouts@7bfe8b13
2025-02-08 20:24:25.842:DEBUG:oeji.CyclicTimeouts:JettyClient-scheduler-556843835-1: Entity HttpExchange@522083c6{req=HttpRequest[PATCH /nnrf-nfm/v2/nf-instances/21160c3b-dd26-45a6-b826-8eb55cb9bbe0 HTTP/2.0]@5c6da88[PENDING/null] res=HttpResponse[null 0 null]@75e9ba5e[PENDING/null]} expires in 0 ms for org.eclipse.jetty.client.HttpDestination$RequestTimeouts@7bfe8b13
2025-02-08 20:24:25.842:DEBUG:oejc.HttpExchange:JettyClient-scheduler-556843835-1: Failed HttpExchange@522083c6{req=HttpRequest[PATCH /nnrf-nfm/v2/nf-instances/21160c3b-dd26-45a6-b826-8eb55cb9bbe0 HTTP/2.0]@5c6da88[COMPLETED/java.util.concurrent.TimeoutException: Total timeout 8000 ms elapsed] res=HttpResponse[null 0 null]@75e9ba5e[COMPLETED/java.util.concurrent.TimeoutException: Total timeout 8000 ms elapsed]}: req=true/rsp=true {}
java.util.concurrent.TimeoutException: Total timeout 8000 ms elapsed
	at org.eclipse.jetty.client.HttpDestination$RequestTimeouts.onExpired(HttpDestination.java:608)
	at org.eclipse.jetty.client.HttpDestination$RequestTimeouts.onExpired(HttpDestination.java:591)
	at org.eclipse.jetty.io.CyclicTimeouts.onTimeoutExpired(CyclicTimeouts.java:106)
	at org.eclipse.jetty.io.CyclicTimeouts$Timeouts.onTimeoutExpired(CyclicTimeouts.java:193)
	at org.eclipse.jetty.io.CyclicTimeout$Wakeup.run(CyclicTimeout.java:294)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
	at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:833)
2025-02-08 20:24:25.843:DEBUG:oejc.HttpExchange:JettyClient-scheduler-556843835-1: Aborting while queued HttpExchange@522083c6{req=HttpRequest[PATCH /nnrf-nfm/v2/nf-instances/21160c3b-dd26-45a6-b826-8eb55cb9bbe0 HTTP/2.0]@5c6da88[COMPLETED/java.util.concurrent.TimeoutException: Total timeout 8000 ms elapsed] res=HttpResponse[null 0 null]@75e9ba5e[COMPLETED/java.util.concurrent.TimeoutException: Total timeout 8000 ms elapsed]}: {}
java.util.concurrent.TimeoutException: Total timeout 8000 ms elapsed
	at org.eclipse.jetty.client.HttpDestination$RequestTimeouts.onExpired(HttpDestination.java:608)
	at org.eclipse.jetty.client.HttpDestination$RequestTimeouts.onExpired(HttpDestination.java:591)
	at org.eclipse.jetty.io.CyclicTimeouts.onTimeoutExpired(CyclicTimeouts.java:106)
	at org.eclipse.jetty.io.CyclicTimeouts$Timeouts.onTimeoutExpired(CyclicTimeouts.java:193)
	at org.eclipse.jetty.io.CyclicTimeout$Wakeup.run(CyclicTimeout.java:294)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
	at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:833)
2025-02-08 20:24:25.843:DEBUG:oeji.CyclicTimeouts:JettyClient-scheduler-556843835-1: Entity HttpExchange@522083c6{req=HttpRequest[PATCH /nnrf-nfm/v2/nf-instances/21160c3b-dd26-45a6-b826-8eb55cb9bbe0 HTTP/2.0]@5c6da88[COMPLETED/java.util.concurrent.TimeoutException: Total timeout 8000 ms elapsed] res=HttpResponse[null 0 null]@75e9ba5e[COMPLETED/java.util.concurrent.TimeoutException: Total timeout 8000 ms elapsed]} expired, remove=false for org.eclipse.jetty.client.HttpDestination$RequestTimeouts@7bfe8b13
2025-02-08 20:24:28.921:DEBUG:oeju.Scanner:Scanner-1-1: scan accepted /tmp/rest-server-client.jks mod=1738310678198
2025-02-08 20:24:28.923:DEBUG:oeju.Scanner:Scanner-1-1: scan accepted /tmp/broker-client.jks mod=1738309290418
2025-02-08 20:24:28.923:DEBUG:oeju.Scanner:Scanner-1-1: scanned [/tmp/rest-server-client.jks, /tmp/broker-client.jks]
2025-02-08 20:24:28.938:DEBUG:oejus.X509:Scanner-1-1: Certificate CN alias=1 CN=casscluster in X509@40091c7e(1,h=[],a=[],w=[])
2025-02-08 20:24:28.938:INFO :oejus.SslContextFactory:Scanner-1-1: x509=X509@40091c7e(1,h=[casscluster],a=[],w=[]) for Client@49a76c38[provider=null,keyStore=file:///tmp/broker-client.jks]
2025-02-08 20:24:28.943:DEBUG:oejus.SslContextFactory:Scanner-1-1: managers=[sun.security.ssl.SunX509KeyManagerImpl@3544fc8b] for Client@49a76c38[provider=null,keyStore=file:///tmp/broker-client.jks]
2025-02-08 20:24:28.944:DEBUG:oejus.SslContextFactory:Scanner-1-1: Selected Protocols [TLSv1.2, TLSv1.3] of [TLSv1.3, TLSv1.2, TLSv1.1, TLSv1, SSLv3, SSLv2Hello]
2025-02-08 20:24:28.944:DEBUG:oejus.SslContextFactory:Scanner-1-1: Selected Ciphers   [TLS_AES_256_GCM_SHA384, TLS_AES_128_GCM_SHA256, TLS_CHACHA20_POLY1305_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_DHE_RSA_WITH_AES_256_GCM_SHA384, TLS_DHE_RSA_WITH_CHACHA20_POLY1305_SHA256, TLS_DHE_DSS_WITH_AES_256_GCM_SHA384, TLS_DHE_RSA_WITH_AES_128_GCM_SHA256, TLS_DHE_DSS_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_RSA_WITH_AES_256_CBC_SHA256, TLS_DHE_DSS_WITH_AES_256_CBC_SHA256, TLS_DHE_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_DSS_WITH_AES_128_CBC_SHA256, TLS_ECDH_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDH_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256, TLS_EMPTY_RENEGOTIATION_INFO_SCSV] of [TLS_AES_256_GCM_SHA384, TLS_AES_128_GCM_SHA256, TLS_CHACHA20_POLY1305_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_DHE_RSA_WITH_AES_256_GCM_SHA384, TLS_DHE_RSA_WITH_CHACHA20_POLY1305_SHA256, TLS_DHE_DSS_WITH_AES_256_GCM_SHA384, TLS_DHE_RSA_WITH_AES_128_GCM_SHA256, TLS_DHE_DSS_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_RSA_WITH_AES_256_CBC_SHA256, TLS_DHE_DSS_WITH_AES_256_CBC_SHA256, TLS_DHE_RSA_WITH_AES_128_CBC_SHA256, TLS_DHE_DSS_WITH_AES_128_CBC_SHA256, TLS_ECDH_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDH_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_DSS_WITH_AES_256_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA, TLS_ECDH_RSA_WITH_AES_256_CBC_SHA, TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDH_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_GCM_SHA384, TLS_RSA_WITH_AES_128_GCM_SHA256, TLS_RSA_WITH_AES_256_CBC_SHA256, TLS_RSA_WITH_AES_128_CBC_SHA256, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_EMPTY_RENEGOTIATION_INFO_SCSV]
2025-02-08 20:24:30.844:DEBUG:oejc.HttpDestination:Timer-4: Stale check done with result false on HttpDestination[Origin@8135fc1c[https://localhost:1099,tag=null,protocol=Protocol@198cd[proto=[h2],nego=false]]]@224715e6,state=STARTED,queue=0,pool=MultiplexConnectionPool@45870ae8[s=STARTED,c=1/1/3,a=0,i=0,q=0,p=@1a98f878[inUse=0,size=1,max=3,closed=false]],stale=false,idle=-1
2025-02-08 20:24:30.845:DEBUG:oejc.HttpClient:Timer-4: Resolved HttpDestination[Origin@8135fc1c[https://localhost:1099,tag=null,protocol=Protocol@198cd[proto=[h2],nego=false]]]@224715e6,state=STARTED,queue=0,pool=MultiplexConnectionPool@45870ae8[s=STARTED,c=1/1/3,a=0,i=0,q=0,p=@1a98f878[inUse=0,size=1,max=3,closed=false]],stale=false,idle=-1 for HttpRequest[PATCH /nnrf-nfm/v2/nf-instances/21160c3b-dd26-45a6-b826-8eb55cb9bbe0 HTTP/2.0]@2e696389
2025-02-08 20:24:30.845:DEBUG:oejc.HttpConversation:Timer-4: Exchanges in conversation 1, override=null, listeners=[org.eclipse.jetty.client.util.FutureResponseListener@1d48ee56]
2025-02-08 20:24:30.845:DEBUG:oeji.CyclicTimeouts:Timer-4: Scheduling timeout in 7999 ms for org.eclipse.jetty.client.HttpDestination$RequestTimeouts@7bfe8b13
2025-02-08 20:24:30.845:DEBUG:oeji.CyclicTimeout:Timer-4: Installed timeout in 7999 ms, new wake up in 7999 ms
2025-02-08 20:24:30.845:DEBUG:oejc.HttpDestination:Timer-4: Queued HttpRequest[PATCH /nnrf-nfm/v2/nf-instances/21160c3b-dd26-45a6-b826-8eb55cb9bbe0 HTTP/2.0]@2e696389 for HttpDestination[Origin@8135fc1c[https://localhost:1099,tag=null,protocol=Protocol@198cd[proto=[h2],nego=false]]]@224715e6,state=STARTED,queue=1,pool=MultiplexConnectionPool@45870ae8[s=STARTED,c=1/1/3,a=0,i=0,q=1,p=@1a98f878[inUse=0,size=1,max=3,closed=false]],stale=false,idle=-1
2025-02-08 20:24:30.845:DEBUG:oejc.AbstractConnectionPool:Timer-4: Acquiring create=true on MultiplexConnectionPool@45870ae8[s=STARTED,c=1/1/3,a=0,i=0,q=1,p=@1a98f878[inUse=0,size=1,max=3,closed=false]]
2025-02-08 20:24:30.845:DEBUG:oejc.AbstractConnectionPool:Timer-4: Try creating connection 1/3 with 1 pending
2025-02-08 20:24:30.845:DEBUG:oejc.AbstractConnectionPool:Timer-4: Try creating(true) connection, pending/demand/supply: 1/2/1024, result=false
@dev-chirag
Copy link
Author

Also, this pending connection is not honouring the Idle timeout set on the HTTPClient.

My question is - am I missing some configuration for MultiplexConnectionPool? Shouldnt pending connection be closed after the idle timeout setting?

@sbordet
Copy link
Contributor

sbordet commented Feb 9, 2025

It is a pretty extreme use case, and we do not really support it.

Your application, knowing that it will reload the KeyStore, should organize and stop making requests, then close all the connections, then reload the KeyStore, then allow to make requests again.

I think the problem is more in the scanner that it does not seem to have picked up the fact that the KeyStore changed.

@dev-chirag
Copy link
Author

Thanks @sbordet , for now I mitigated this situation by ignoring Scanner notifications of file deletions. This prevented unload() of the SSLContextFactory before it fails to find the Keystore in load(). This way, even if the Server certificates change, the client gracefully closes the pending connection with a "bad certificate" SSL handshake error.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
Status: No status
Development

No branches or pull requests

2 participants