Client leaks connections on cancellation

Hello there!

It appears that the `JdkHttpClient` doesn't properly release connections when a request is cancelled, leading to a leak of file descriptors.

Code to reproduce (it's slightly messy, but it does the job):
```scala
//> using dep org.http4s:http4s-jdk-http-client_2.13:0.10.0
//> using dep org.http4s:http4s-dsl_2.13:0.23.30
//> using dep org.http4s:http4s-blaze-server_2.13:0.23.17

import cats.effect._
import cats.effect.std._
import cats.syntax.all._
import org.http4s._
import org.http4s.blaze.server._
import org.http4s.client._
import org.http4s.dsl.io._
import org.http4s.jdkhttpclient._
import org.http4s.syntax.literals._
import scala.concurrent.duration._

object Main extends IOApp {
  val port: Int = 8081

  val app = HttpRoutes
    .of[IO] { case GET -> Root =>
      Ok {
        IO
          .sleep(3.seconds)
          .as("this is a response")
      }
    }
    .orNotFound
  val server =
    BlazeServerBuilder[IO]
      .bindLocal(port)
      .withHttpApp(app)
      .resource

  val request = (client: Client[IO]) =>
    client.expect[String](s"http://localhost:$port/")
  val step = (msg: String) => IO.println(s"---------- $msg ----------")

  val makeClient = JdkHttpClient.simple[IO]

  val leaks = (client: Client[IO]) =>
    step("starting leaking code") >>
      request(client).timeoutTo(1.seconds, IO.println("timed out")) >>
      step("leaking code exited")

  val doesntLeak = (client: Client[IO]) =>
    step("starting non-leaking code") >>
      request(client) >>
      step("non-leaking code exited")

  val init =
    IO.delay(java.lang.ProcessHandle.current().pid())
      .flatMap(IO.println)
      .toResource >> (server, makeClient).tupled

  def run(args: List[String]) =
    init.use { case (_, client) =>
      for {
        _ <- args.take(1) match {
          case List("leak")    => leaks(client)
          case List("no-leak") => doesntLeak(client)
          case Nil             => doesntLeak(client)
          case _ => IO.raiseError(new RuntimeException("bad arguments"))
        }
        _ <- step(
          "keeping alive for 15 seconds (connections will close after 10 s)"
        )
        _ <- IO.sleep(15.seconds)
        _ <- step("closing connections(?)")
      } yield ()
    } >> step("client exited").as(ExitCode.Success)
}
``` 
Run with `-Djdk.httpclient.HttpClient.log=trace` and `-Djdk.httpclient.keepalive.timeout=10`. (Scala CLI command: `scala-cli run --java-opt -Djdk.httpclient.HttpClient.log=trace --java-opt -Djdk.httpclient.keepalive.timeout=10 -S 2.13.16 repro.scala --`)

Run without leaking:
```
% scala-cli run --java-opt -Djdk.httpclient.HttpClient.log=trace --java-opt -Djdk.httpclient.keepalive.timeout=10 -S 2.13.16 repro.scala --
SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
38438
---------- starting non-leaking code ----------
Jun 03, 2025 1:18:48 PM jdk.internal.net.http.MultiExchange requestFilters
INFO: MISC: Applying request filters
Jun 03, 2025 1:18:48 PM jdk.internal.net.http.MultiExchange requestFilters
INFO: MISC: Applying jdk.internal.net.http.AuthenticationFilter@664d031e
Jun 03, 2025 1:18:48 PM jdk.internal.net.http.MultiExchange requestFilters
INFO: MISC: Applying jdk.internal.net.http.RedirectFilter@3df72b50
Jun 03, 2025 1:18:48 PM jdk.internal.net.http.MultiExchange requestFilters
INFO: MISC: All filters applied
Jun 03, 2025 1:18:48 PM jdk.internal.net.http.HttpClientImpl registerTimer
INFO: MISC: Registering timer ConnectTimerEvent, TimeoutEvent[id=1, duration=PT10S, deadline=2025-06-03T13:18:58.464610080Z]
Jun 03, 2025 1:18:48 PM jdk.internal.net.http.HttpClientImpl cancelTimer
INFO: MISC: Canceling timer ConnectTimerEvent, TimeoutEvent[id=1, duration=PT10S, deadline=2025-06-03T13:18:58.464610080Z]
Jun 03, 2025 1:18:51 PM jdk.internal.net.http.MultiExchange responseFilters
INFO: MISC: Applying response filters
Jun 03, 2025 1:18:51 PM jdk.internal.net.http.MultiExchange responseFilters
INFO: MISC: Applying jdk.internal.net.http.RedirectFilter@3df72b50
Jun 03, 2025 1:18:51 PM jdk.internal.net.http.MultiExchange responseFilters
INFO: MISC: Applying jdk.internal.net.http.AuthenticationFilter@664d031e
Jun 03, 2025 1:18:51 PM jdk.internal.net.http.MultiExchange responseFilters
INFO: MISC: All filters applied
Jun 03, 2025 1:18:51 PM jdk.internal.net.http.Http1Response onFinished
INFO: MISC: Attempting to return connection to the pool: PlainHttpConnection: HttpConnection: java.nio.channels.SocketChannel[connected local=/127.0.0.1:41830 remote=localhost/127.0.0.1:8081]
Jun 03, 2025 1:18:51 PM jdk.internal.net.http.HttpConnection closeOrReturnToCache
INFO: MISC: Returning connection to the pool: PlainHttpConnection: HttpConnection: java.nio.channels.SocketChannel[connected local=/127.0.0.1:41830 remote=localhost/127.0.0.1:8081]
---------- non-leaking code exited ----------
---------- keeping alive for 15 seconds (connections will close after 10 s) ----------
Jun 03, 2025 1:19:01 PM jdk.internal.net.http.PlainHttpConnection close
INFO: MISC: Closing: PlainHttpConnection: HttpConnection: java.nio.channels.SocketChannel[connected local=/127.0.0.1:41830 remote=localhost/127.0.0.1:8081]
Jun 03, 2025 1:19:01 PM jdk.internal.net.http.HttpClientImpl cancelTimer
INFO: MISC: Canceling timer ConnectTimerEvent, TimeoutEvent[id=1, duration=PT10S, deadline=2025-06-03T13:18:58.464610080Z]
---------- closing connections(?) ----------
Jun 03, 2025 1:19:06 PM jdk.internal.net.http.HttpClientImpl$SelectorManager run
INFO: MISC: HttpClient-1-SelectorManager: HttpClient finished. Exiting...
Jun 03, 2025 1:19:06 PM jdk.internal.net.http.HttpClientImpl$SelectorManager shutdown
INFO: MISC: HttpClient-1-SelectorManager: shutting down
---------- client exited ----------
```

Run with leaking:
```
% scala-cli run --java-opt -Djdk.httpclient.HttpClient.log=trace --java-opt -Djdk.httpclient.keepalive.timeout=10 -S 2.13.16 repro.scala -- leak
SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
38974
---------- starting leaking code ----------
Jun 03, 2025 1:24:29 PM jdk.internal.net.http.MultiExchange requestFilters
INFO: MISC: Applying request filters
Jun 03, 2025 1:24:29 PM jdk.internal.net.http.MultiExchange requestFilters
INFO: MISC: Applying jdk.internal.net.http.AuthenticationFilter@d1f2aed
Jun 03, 2025 1:24:29 PM jdk.internal.net.http.MultiExchange requestFilters
INFO: MISC: Applying jdk.internal.net.http.RedirectFilter@12e2e860
Jun 03, 2025 1:24:29 PM jdk.internal.net.http.MultiExchange requestFilters
INFO: MISC: All filters applied
Jun 03, 2025 1:24:29 PM jdk.internal.net.http.HttpClientImpl registerTimer
INFO: MISC: Registering timer ConnectTimerEvent, TimeoutEvent[id=1, duration=PT10S, deadline=2025-06-03T13:24:39.919649937Z]
Jun 03, 2025 1:24:29 PM jdk.internal.net.http.HttpClientImpl cancelTimer
INFO: MISC: Canceling timer ConnectTimerEvent, TimeoutEvent[id=1, duration=PT10S, deadline=2025-06-03T13:24:39.919649937Z]
timed out
---------- leaking code exited ----------
---------- keeping alive for 15 seconds (connections will close after 10 s) ----------
Jun 03, 2025 1:24:33 PM jdk.internal.net.http.MultiExchange responseFilters
INFO: MISC: Applying response filters
Jun 03, 2025 1:24:33 PM jdk.internal.net.http.MultiExchange responseFilters
INFO: MISC: Applying jdk.internal.net.http.RedirectFilter@12e2e860
Jun 03, 2025 1:24:33 PM jdk.internal.net.http.MultiExchange responseFilters
INFO: MISC: Applying jdk.internal.net.http.AuthenticationFilter@d1f2aed
Jun 03, 2025 1:24:33 PM jdk.internal.net.http.MultiExchange responseFilters
INFO: MISC: All filters applied
---------- closing connections(?) ----------
# the process hangs here and never exits
```

```
# In a separate terminal
% lsof -p 38974
...
java    38974 rasmus.precenth  93u     IPv6             103576       0t0     TCP localhost:53658->localhost:sunproxyadmin (CLOSE_WAIT)
```
[fiberdump.txt](https://github.com/user-attachments/files/20574713/fiberdump.txt)
[threaddump.txt](https://github.com/user-attachments/files/20574714/threaddump.txt)

In short, cancelling the requests leaves the connection in a stuck state that it never recovers from.

I can see that the code tries its best to juggle cancelable and uncancelable effects, but that seems to not be enough in this case.

Navigation Menu

Uh oh!

Client leaks connections on cancellation #1188

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Uh oh!

Client leaks connections on cancellation #1188

Description

Activity

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions