http4s-jdk-http-client icon indicating copy to clipboard operation
http4s-jdk-http-client copied to clipboard

Published 20 hours ago • verified publisher icon http4s

HTTP body not read to completion. Dropping connection.

Open kamilkloch opened this issue 3 years ago • 17 comments

A batch of POST requests cause connection to be dropped due to unconsumed request body: HTTP body not read to completion. Dropping connection. Full log:

[2022-08-04 11:36:06,274] INFO  [io-compute-7] o.h.b.c.n.NIO1SocketServerGroup:276 - Service bound to address /127.0.0.1:8080
[2022-08-04 11:36:06,286] INFO  [io-compute-7] o.h.b.s.BlazeServerBuilder:422 - 
  _   _   _        _ _
 | |_| |_| |_ _ __| | | ___
 | ' \  _|  _| '_ \_  _(_-<
 |_||_\__|\__| .__/ |_|/__/
             |_|
[2022-08-04 11:36:06,308] INFO  [io-compute-7] o.h.b.s.BlazeServerBuilder:425 - http4s v0.23.14 on blaze v0.23.12 started at http://127.0.0.1:8080/
[2022-08-04 11:36:07,271] INFO  [io-compute-7] o.h.b.s.Http1ServerStage$$anon$1:271 - HTTP body not read to completion. Dropping connection.
0: Response(status=200, httpVersion=HTTP/1.1, headers=Headers(content-length: 0, date: Thu, 04 Aug 2022 09:36:07 GMT))
[2022-08-04 11:36:07,340] INFO  [io-compute-7] o.h.b.s.Http1ServerStage$$anon$1:271 - HTTP body not read to completion. Dropping connection.
1: Response(status=200, httpVersion=HTTP/1.1, headers=Headers(content-length: 0, date: Thu, 04 Aug 2022 09:36:07 GMT))
[2022-08-04 11:36:07,354] INFO  [io-compute-6] o.h.b.s.Http1ServerStage$$anon$1:271 - HTTP body not read to completion. Dropping connection.
2: Response(status=200, httpVersion=HTTP/1.1, headers=Headers(content-length: 0, date: Thu, 04 Aug 2022 09:36:07 GMT))
[2022-08-04 11:36:07,367] INFO  [io-compute-8] o.h.b.s.Http1ServerStage$$anon$1:271 - HTTP body not read to completion. Dropping connection.
....
23: Response(status=200, httpVersion=HTTP/1.1, headers=Headers(content-length: 0, date: Thu, 04 Aug 2022 09:36:07 GMT))
[2022-08-04 11:36:07,638] INFO  [blaze-acceptor-0-0] o.h.b.c.ServerChannel:211 - Closing NIO1 channel /127.0.0.1:8080
[2022-08-04 11:36:07,639] INFO  [io-compute-2] o.h.b.c.n.SelectorLoop:72 - Shutting down SelectorLoop blaze-selector-0
...
java.io.IOException: HTTP/1.1 header parser received no bytes
	at java.net.http/jdk.internal.net.http.common.Utils.wrapWithExtraDetail(Utils.java:348)
	at java.net.http/jdk.internal.net.http.Http1Response$HeadersReader.onReadError(Http1Response.java:675)
	at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.checkForErrors(Http1AsyncReceiver.java:302)
	at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.flush(Http1AsyncReceiver.java:268)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler$LockingRestartableTask.run(SequentialScheduler.java:205)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230)
	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)
	at async_ @ org.http4s.jdkhttpclient.package$.$anonfun$fromCompletableFuture$1(package.scala:39)
	at delay @ org.http4s.jdkhttpclient.JdkHttpClient$.$anonfun$apply$21(JdkHttpClient.scala:243)
	at use @ Caused by: java.io.EOFException: EOF reached while reading
	at java.net.http/jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber.onComplete(Http1AsyncReceiver.java:596)
	at 
...
java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadSubscription.signalCompletion(SocketTube.java:640)
	at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.read(SocketTube.java:845)
	at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowTask.run(SocketTube.java:181)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:303)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:256)
	at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.signalReadable(SocketTube.java:774)
	at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent.signalEvent(SocketTube.java:957)
	at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowEvent.handle(SocketTube.java:253)
	at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.handleEvent(HttpClientImpl.java:979)
	at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.lambda$run$3(HttpClientImpl.java:934)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
	at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:934)

And this - once in a while - makes client request lost on the wire. For this to happen:

  • request should have non-empty body
  • response should be generated before body is consumed;

Checked with blaze and ember servers.

import cats.effect._
import cats.implicits._
import com.comcast.ip4s._
import org.http4s.blaze.server.BlazeServerBuilder
import org.http4s.client.dsl.Http4sClientDsl
import org.http4s.dsl.io._
import org.http4s.ember.server._
import org.http4s.implicits._
import org.http4s.jdkhttpclient.JdkHttpClient
import org.http4s.server.Router
import org.http4s.{HttpRoutes, Uri}

import java.net.http.HttpClient
import java.net.http.HttpClient.Version

object HttpConnectionCloseBodyDrain extends IOApp.Simple {

  def run: IO[Unit] = {
    val routes = HttpRoutes.of[IO] {
      case POST -> Root / "test" / "post" =>
        Ok()
    }

    val client = JdkHttpClient[IO](HttpClient.newBuilder().version(Version.HTTP_1_1).build())

    val postRequests = client.use { client =>
      val clientDsl = Http4sClientDsl[IO]
      import clientDsl._

      val req = POST("dummy body", Uri.fromString("http://localhost:8080/test/post?param=XXX)").toOption.get)
      val reqResource = client.run(req)
      List.from(0 until 100).traverse_ { i =>
        reqResource.use { response =>
          IO.println(s"$i: $response")
        }
      }
    }

    BlazeServerBuilder[IO]
      .bindHttp(8080, "localhost")
      .withHttpApp(Router("/" -> routes).orNotFound)
      .resource
      .use { _ => postRequests }

    /*
    EmberServerBuilder
      .default[IO]
      .withHost(ipv4"127.0.0.1")
      .withPort(port"8080")
      .withHttpApp(Router("/" -> routes).orNotFound)
      .build
      .use { _ => postRequests }
     */
  }
}

kamilkloch avatar Aug 04 '22 09:08 kamilkloch

Thanks for opening the issue! It looks like this is specific to the jdk-http-client? We should transfer to the issue to its dedicated repository. cc @amesgen

https://github.com/http4s/http4s-jdk-http-client

armanbilge avatar Aug 04 '22 13:08 armanbilge

@armanbilge Indeed, I can confirm, that the issue disappears when using OkHttpClient. Should I re-post the issue in https://github.com/http4s/http4s-jdk-http-client or perhaps @amesgen will do the transfer?

kamilkloch avatar Aug 04 '22 14:08 kamilkloch

Thanks for the report, I can reproduce this. This should definitely be fixed, but it should always be possible to work around this by consuming the response body, right?

amesgen avatar Aug 05 '22 21:08 amesgen

Hm, probably yes, but one should not expect such a behavior from the user, what do you think? For what it is worth, I first encountered the error via sttp's synchronous HttpClientSyncBackend, which may suggest the problem might persist even when using a raw Java HttpClient.

kamilkloch avatar Aug 05 '22 22:08 kamilkloch

I think Embers solution may be generic enough to be leveraged here. It keeps track and drains if it wasn't normally so the connection can be preserved.

ChristopherDavenport avatar Aug 05 '22 23:08 ChristopherDavenport

The error persists even when using a vanilla Java client:

object HttpConnectionCloseBodyDrain extends IOApp.Simple {

  def run: IO[Unit] = {
    val routes = HttpRoutes.of[IO] {
      case POST -> Root / "test" / "post" =>
        Ok()
    }

    val javaClient = HttpClient.newBuilder().version(Version.HTTP_1_1).build()

    val req = HttpRequest
      .newBuilder(new URI("http://localhost:8080/test/post?param=XXX)"))
      .POST(HttpRequest.BodyPublishers.ofString("dummy body"))
      .build()

    BlazeServerBuilder[IO]
      .bindHttp(8080, "localhost")
      .withHttpApp(Router("/" -> routes).orNotFound)
      .resource
      .use { _ =>
        IO {
          for (i <- 0 until 100) {
            val response = javaClient.send(req, BodyHandlers.ofString())
            println(s"$i: $response")
          }
        }
      }
  }
}

kamilkloch avatar Aug 08 '22 09:08 kamilkloch

Hi folks, hope you're good.

Any updates on this? I see this error in the scala-steward we operated internally. When it tries to open a PR, it sees the following exception:

java.io.IOException: HTTP/1.1 header parser received no bytes
	at java.net.http/jdk.internal.net.http.common.Utils.wrapWithExtraDetail(Utils.java:327)
	at java.net.http/jdk.internal.net.http.Http1Response$HeadersReader.onReadError(Http1Response.java:673)
	at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.checkForErrors(Http1AsyncReceiver.java:297)
	at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.flush(Http1AsyncReceiver.java:263)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SynchronizedRestartableTask.run(SequentialScheduler.java:175)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:147)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:198)
	at java.net.http/jdk.internal.net.http.HttpClientImpl$DelegatingExecutor.execute(HttpClientImpl.java:153)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:273)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:242)
	at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.onReadError(Http1AsyncReceiver.java:506)
	at java.net.http/jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber.onComplete(Http1AsyncReceiver.java:591)
	at java.net.http/jdk.internal.net.http.common.SSLTube$DelegateWrapper.onComplete(SSLTube.java:268)
	at java.net.http/jdk.internal.net.http.common.SSLTube$SSLSubscriberWrapper.complete(SSLTube.java:432)
	at java.net.http/jdk.internal.net.http.common.SSLTube$SSLSubscriberWrapper.onComplete(SSLTube.java:562)
	at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.checkCompletion(SubscriberWrapper.java:443)
	at java.net.http/jdk.internal.net.http.common.SubscriberWrapper$DownstreamPusher.run1(SubscriberWrapper.java:322)
	at java.net.http/jdk.internal.net.http.common.SubscriberWrapper$DownstreamPusher.run(SubscriberWrapper.java:261)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SynchronizedRestartableTask.run(SequentialScheduler.java:175)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:147)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:198)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:271)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:224)
	at java.net.http/jdk.internal.net.http.common.SubscriberWrapper.outgoing(SubscriberWrapper.java:234)
	at java.net.http/jdk.internal.net.http.common.SSLFlowDelegate$Reader.processData(SSLFlowDelegate.java:468)
	at java.net.http/jdk.internal.net.http.common.SSLFlowDelegate$Reader$ReaderDownstreamPusher.run(SSLFlowDelegate.java:264)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SynchronizedRestartableTask.run(SequentialScheduler.java:175)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:147)
	at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:198)
	at delay @ org.http4s.jdkhttpclient.JdkHttpClient$.$anonfun$apply$23(JdkHttpClient.scala:243)
	at fromCompletableFuture @ org.http4s.jdkhttpclient.JdkHttpClient$.$anonfun$apply$23(JdkHttpClient.scala:243)
	at apply @ org.http4s.jdkhttpclient.JdkHttpClient$.convertResponse$1(JdkHttpClient.scala:178)
	at tupled @ org.http4s.jdkhttpclient.JdkHttpClient$.convertResponse$1(JdkHttpClient.scala:178)
	at tupled @ org.http4s.jdkhttpclient.JdkHttpClient$.convertResponse$1(JdkHttpClient.scala:178)
	at main$ @ org.scalasteward.core.Main$.main(Main.scala:23)
	at main$ @ org.scalasteward.core.Main$.main(Main.scala:23)
	at main$ @ org.scalasteward.core.Main$.main(Main.scala:23)

I'd be happy to fix this if I can get some pointers. This issue tells me a bit about the issue, but I guess some people already tried to fix it to no avail. Maybe there is more information available at this point in time.

daddykotex avatar Feb 24 '23 15:02 daddykotex

but I guess some people already tried to fix it to no avail

I'm not aware of anyone who has worked on it. Chris's suggestion seems good. Also we can fix this in Steward by draining the response bodies.

armanbilge avatar Feb 24 '23 15:02 armanbilge

Looking into implementing https://github.com/http4s/http4s/pull/4348 here I believe

daddykotex avatar Mar 03 '23 16:03 daddykotex

I'm not sure if I'll be able to pull it off.

daddykotex avatar Mar 03 '23 21:03 daddykotex

Feel free to open a draft PR with whatever you have! Even if you are no longer able to work on it, maybe someone else can pick it up.

armanbilge avatar Mar 03 '23 21:03 armanbilge

@armanbilge#6192 wrt to https://github.com/http4s/http4s-jdk-http-client/issues/714

I think the reason I'm not able to fix the issue is that I don't understand the issue properly. I don't understand how this fix in Ember client makes it work.

We send a bunch of requests to a server. These requests have a body, and we use http 1.1 so we're using Connection: keep-alive by default. The client establish a TCP connection to send the first request, then reuse it to send the rest of the requests.

The issue arise when the server sends an early response: the server responds before the client is finished sending the request (this can happen when you don't drain the request body (as we do in this example)).

If I look at the PR, it looks like in a typical exchange, the ember client does this:

  1. write the request in the socket (extracted from the Managed connection retrieved from the pool - reused in keep-alive is present)
  2. when 1) is done, it starts reading from the response (first headers, then the body, see org.http4s.ember.client.internal.Parser.Response#parser). The interesting thing happens in the response body parsing where we keep a handle on a Drain which is an effect to retrieve remainder bytes to be parsed

W/o going into more details here (will pick that up later), I'm unable to understand how 2) can affect the behaviour of a client interacting with a server that does not drain the request body. It should just parse body as they are coming in on the wire.

As such, I'm not sure I understand how the JDK can experience an issue in this situation:

  1. the JDK client writes bytes on the wire
  2. then it reads bytes on the wire

Why does it care if the server has not read the bytes it was suppose to read?

I think it's my understanding of the lower protocols that's wrong or insufficient.

While playing around, I found two issues with Chunked encoding (I was trying to slow down the request writing process - akin to a large payload, so I tried using a fs2.Stream, with metered on it):

https://github.com/daddykotex/scala-scripts/tree/e1ef47f5a3bcae779f4aa879e8f0f6dcb7564637/http4s

daddykotex avatar Mar 06 '23 20:03 daddykotex

Hmm, things seem to be a bit muddied 🤔 and apologies if I haven't looked closely enough at this issue.

I'm unable to understand how 2) can affect the behaviour of a client interacting with a server that does not drain the request body.

My understanding has been that this issue is not related to the server. This issue is related to the fact that the response body sent from the server to the client must be drained on the client. That's why I opened the steward PR adding those drains.

Why does it care if the server has not read the bytes it was suppose to read?

In general, undrained bodies (both request and response) pose a problem. Here's why: ideally a single connection (i.e. a TCP socket) is reused for multiple request/response pairs. If a request/response is not read in its entirety, then its bytes are still sitting in that socket. So if you attempt to send or read new data on that socket (i.e. for the next request/response pair), it will be mixed/corrupted with these undrained bytes, and that poses a problem.

armanbilge avatar Mar 06 '23 21:03 armanbilge

No need to apologies, it's already kind enough of you to support me

the response body sent from the server to the client must be drained on the client

Ok so my understanding is not so messed up after all! At first, after reading the issue description, I thought the problem happened when the server was not draining the issue (so I focused on that, and I still can't understand how that would affect the client). But now that you say that the problem happens because the client is not draining, I tried it and still got an error.

The following snippet, still cause the issue:

//> using scala "2.13.10"

//> using lib "org.http4s::http4s-dsl:0.23.19-RC1"
//> using lib "org.http4s::http4s-jdk-http-client:0.9.0"
//> using lib "org.http4s::http4s-ember-client:0.23.19-RC1"
//> using lib "org.http4s::http4s-ember-server:0.23.19-RC1"

import cats.effect._
import cats.implicits._
import com.comcast.ip4s._
import org.http4s.client.dsl.Http4sClientDsl
import org.http4s.dsl.io._
import org.http4s.ember.server._
import org.http4s.implicits._
import org.http4s.jdkhttpclient.JdkHttpClient
import org.http4s.{HttpRoutes, Uri}

import java.net.http.HttpClient
import java.net.http.HttpClient.Version

// This is a *manual* test for the body leak fixed in #714
object HttpConnectionCloseBodyDrain extends IOApp.Simple {

  def run: IO[Unit] = {
    val routes = HttpRoutes.of[IO] { case POST -> Root / "test" / "post" =>
      Ok()
    }

    val client = JdkHttpClient[IO](
      HttpClient.newBuilder().version(Version.HTTP_1_1).build()
    )

    val postRequests = {
      val clientDsl = Http4sClientDsl[IO]
      import clientDsl._

      val req = POST(
        "dummy body",
        Uri.unsafeFromString("http://localhost:8080/test/post?param=XXX)")
      )
      val reqResource = client.run(req)
      List.from(0 until 100).traverse_ { i =>
        reqResource.use { response =>
          response.body.compile.drain *>
            IO.println(s"$i: $response")
        }
      }
    }

    EmberServerBuilder
      .default[IO]
      .withHost(ipv4"127.0.0.1")
      .withPort(port"8080")
      .withHttpApp(routes.orNotFound)
      .build
      .use(_ => postRequests)
  }
}

29: Response(status=200, httpVersion=HTTP/1.1, headers=Headers(connection: keep-alive, content-length: 0, date: Tue, 07 Mar 2023 02:12:10 GMT))
30: Response(status=200, httpVersion=HTTP/1.1, headers=Headers(connection: keep-alive, content-length: 0, date: Tue, 07 Mar 2023 02:12:10 GMT))
java.io.IOException: HTTP/1.1 header parser received no bytes
        at java.net.http/jdk.internal.net.http.common.Utils.wrapWithExtraDetail(Utils.java:348)
        at java.net.http/jdk.internal.net.http.Http1Response$HeadersReader.onReadError(Http1Response.java:675)
        at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.checkForErrors(Http1AsyncReceiver.java:302)
        at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.flush(Http1AsyncReceiver.java:268)
        at java.net.http/jdk.internal.net.http.common.SequentialScheduler$LockingRestartableTask.run(SequentialScheduler.java:205)
        at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149)
        at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230)
        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)
        at delay @ org.http4s.jdkhttpclient.JdkHttpClient$.$anonfun$apply$21(JdkHttpClient.scala:234)
        at fromCompletableFuture @ org.http4s.jdkhttpclient.JdkHttpClient$.$anonfun$apply$21(JdkHttpClient.scala:234)
        at apply @ org.http4s.ember.server.EmberServerBuilder.$anonfun$build$2(EmberServerBuilder.scala:182)
        at product @ fs2.concurrent.SignallingRef$.of(Signal.scala:242)
        at tupled @ org.http4s.jdkhttpclient.JdkHttpClient$.convertResponse$1(JdkHttpClient.scala:171)
        at main$ @ HttpConnectionCloseBodyDrain$.main(JdkFail.scala:22)
        at main$ @ HttpConnectionCloseBodyDrain$.main(JdkFail.scala:22)
        at main$ @ HttpConnectionCloseBodyDrain$.main(JdkFail.scala:22)
        at map @ org.http4s.jdkhttpclient.JdkHttpClient$.$anonfun$apply$2(JdkHttpClient.scala:64)
        at use @ HttpConnectionCloseBodyDrain$.$anonfun$run$1(JdkFail.scala:43)
Caused by: java.net.SocketException: Connection reset
        at java.base/sun.nio.ch.SocketChannelImpl.throwConnectionReset(SocketChannelImpl.java:394)
        at java.base/sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:426)
        at java.net.http/jdk.internal.net.http.SocketTube.readAvailable(SocketTube.java:1170)
        at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.read(SocketTube.java:833)
        at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowTask.run(SocketTube.java:181)
        at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230)
        at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:303)
        at java.net.http/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:256)
        at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription.signalReadable(SocketTube.java:774)
        at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent.signalEvent(SocketTube.java:957)
        at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowEvent.handle(SocketTube.java:253)
        at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.handleEvent(HttpClientImpl.java:979)
        at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.lambda$run$3(HttpClientImpl.java:934)
        at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
        at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:934)

Side note: can you tell me if what I'm picturing is wrong?

Given a tcp connection involving TCP endpoint A and TCP endpoint B, is fair to say that, from the point of view of one of them, A for example, you basically have access to two things:

  1. a pipe to read data from
  2. a pipe to write data into

And that

  1. 1), and 2) above, are sort of disconnected. Meaning that A could write 5 requests into the pipe before even starting to read from the pipe.
  2. it should not matter to A, if B is not reading the data from socket (or does it?)

daddykotex avatar Mar 07 '23 02:03 daddykotex

The following snippet, still cause the issue

Aha, thanks for this! That is very helpful.

Indeed, in this reproducer, the problem is almost definitely that the server is not draining the request bytes. Does it fix if you do that?

(Also, I realize that this may be what the original reproducer in the issue may have been showing, if that's the case, sorry 😅.)

and I still can't understand how that would affect the client

Did my explanation above not answer your questions? Please let me know how I can clarify it :)

In general, undrained bodies (both request and response) pose a problem. Here's why: ideally a single connection (i.e. a TCP socket) is reused for multiple request/response pairs. If a request/response is not read in its entirety, then its bytes are still sitting in that socket. So if you attempt to send or read new data on that socket (i.e. for the next request/response pair), it will be mixed/corrupted with these undrained bytes, and that poses a problem.

it should not matter to A, if B is not reading the data from socket (or does it?)

Well, it does matter, for two reasons.

  1. When B does not read bytes for too long, it creates backpressure. So A may be prevented from writing further until B reads what's already buffered.
  2. If B has not finished reading the end of the last request, then those bytes will get in the way of the start of the new request. That will make the request appear to be malformed.

armanbilge avatar Mar 07 '23 02:03 armanbilge

Ah okk, that'd make sense. For 2), if that happens the error happens on the B side, right? Thinking it can read a new request, it just reads the leftover from the last one.

But if we're seeing client side error related to parsing headers so I would also think it's related to the response handling on the client side

daddykotex avatar Mar 07 '23 03:03 daddykotex

Exactly! So in (2), on the B side there is an error. So, instead of responding, it closes the connection. Thus, on the A side you get HTTP/1.1 header parser received no bytes ... Connection reset. :)

armanbilge avatar Mar 07 '23 03:03 armanbilge