search

wiremock / wiremock

A tool for mocking HTTP services
https://wiremock.org/
Apache License 2.0
6.39k stars 1.44k forks source link

Stub fails for Inputstream-Body and HTTP/2 #2461

Closed Lolf1010 closed 1 year ago

Lolf1010 commented 1 year ago

Proposal

It should work with both HTTP-Versions? Or can these Exception come from another place other than Wiremock ? If i create a "real" server using com.sun.net.httpserver.HttpServer then it works 🤷 If i dont send a stream but a byteArray of the stream (inefficient) then it works

Exceptions:

Reproduction steps

In JUnit5-Test regular WireMock.stubFor(...) without RequestBody-Matcher and then build HTTPClient using HTTPClient causes Exception with HTTP/2 but not HTTP/1.1 no additional headers specified

@WireMockTest
public class Http2Test {

    @Test
    public void test(WireMockRuntimeInfo info) throws Exception {
        // arrange mock
        WireMock.stubFor(WireMock.post("/test123")
                .withRequestBody(WireMock.equalTo("abc"))
                .willReturn(WireMock.ok()));

        // arrange client
        String url = "http://localhost:" + info.getHttpPort() + "/test123";
        InputStream stream = IOUtils.toInputStream("abc", StandardCharsets.UTF_8);
        HttpClient client = HttpClient.newBuilder()
                .version(HttpClient.Version.HTTP_2)
                .build();
        HttpRequest request = HttpRequest.newBuilder()
                .uri(URI.create(url))
                .POST(HttpRequest.BodyPublishers.ofInputStream(() -> stream))
                .build();

        // act
        // --> exception, see below
        HttpResponse<String> response = client.send(request, HttpResponse.BodyHandlers.ofString());
    }
}

Debug-Log

[main] INFO org.eclipse.jetty.server.Server - jetty-11.0.15; built: 2023-04-11T18:37:53.775Z; git: 5bc5e562c8d05c5862505aebe5cf83a61bdbcb96; jvm 11.0.11+9-LTS
[main] INFO org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@398474a2{/__admin,null,AVAILABLE}
[main] INFO org.eclipse.jetty.server.handler.ContextHandler.ROOT - RequestHandlerClass from context returned com.github.tomakehurst.wiremock.http.StubRequestHandler. Normalized mapped under returned 'null'
[main] INFO org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@250b236d{/,null,AVAILABLE}
[main] INFO org.eclipse.jetty.server.AbstractConnector - Started NetworkTrafficServerConnector@16423501{HTTP/1.1, (http/1.1, h2c)}{0.0.0.0:51393}
[main] INFO org.eclipse.jetty.server.Server - Started Server@5d1e09bc{STARTING}[11.0.15,sto=1000] @899ms
DEBUG: [main] [4ms] HttpClientImpl(1) proxySelector is sun.net.spi.DefaultProxySelector@7965a51c (user-supplied=false)
DEBUG: [main] [12ms] HttpClientImpl(1) ClientImpl (async) send http://localhost:51393/test123 POST
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.HttpClientImpl$SelectorManager run
INFORMATION: CHANNEL: HttpClient-1-SelectorManager: starting
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.MultiExchange requestFilters
INFORMATION: MISC: Applying request filters
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.MultiExchange requestFilters
INFORMATION: MISC: Applying jdk.internal.net.http.AuthenticationFilter@69da0b12
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.MultiExchange requestFilters
INFORMATION: MISC: Applying jdk.internal.net.http.RedirectFilter@79b08632
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.MultiExchange requestFilters
INFORMATION: MISC: All filters applied
DEBUG: [main] [19ms] Exchange establishing exchange for http://localhost:51393/test123 POST,
     proxy=null
DEBUG: [main] [25ms] Http2ClientImpl not found in connection pool
DEBUG: [main] [25ms] ExchangeImpl get: Trying to get HTTP/2 connection
DEBUG: [main] [25ms] ExchangeImpl handling HTTP/2 connection creation result
DEBUG: [main] [25ms] ExchangeImpl new Http1Exchange, try to upgrade
DEBUG: [main] [36ms] PlainHttpConnection(?) Initial receive buffer size is: 131072
DEBUG: [main] [42ms] Exchange checkFor407: all clear
DEBUG: [main] [42ms] Http1Exchange Sending headers only
DEBUG: [main] [56ms] Http1AsyncReceiver(SocketTube(1)) Subscribed pending jdk.internal.net.http.Http1Response$HeadersReader@2aeefcc queue.isEmpty: true
DEBUG: [main] [60ms] Http1AsyncReceiver(SocketTube(1)) delegate is now jdk.internal.net.http.Http1Response$HeadersReader@2aeefcc, demand=1, canRequestMore=true, queue.isEmpty=true
DEBUG: [main] [60ms] Http1AsyncReceiver(SocketTube(1)) downstream subscription demand is 1
DEBUG: [main] [62ms] Http1AsyncReceiver(SocketTube(1)) checkRequestMore: canRequestMore=true, hasDemand=true
DEBUG: [main] [62ms] Http1AsyncReceiver(SocketTube(1)) downstream subscription demand is 1
DEBUG: [main] [62ms] Http1AsyncReceiver(SocketTube(1)) checkRequestMore: canRequestMore=true, hasDemand=true
DEBUG: [main] [62ms] Http1Exchange response created in advance
DEBUG: [main] [62ms] Http1Exchange initiating connect async
DEBUG: [main] [64ms] PlainHttpConnection(SocketTube(1)) registering connect event
DEBUG: [HttpClient-1-SelectorManager] [67ms] SelectorAttachment Registering jdk.internal.net.http.PlainHttpConnection$ConnectEvent@a8580de for 8 (true)
DEBUG: [HttpClient-1-SelectorManager] [69ms] PlainHttpConnection(SocketTube(1)) ConnectEvent: finishing connect
DEBUG: [HttpClient-1-SelectorManager] [70ms] PlainHttpConnection(SocketTube(1)) ConnectEvent: connect finished: true Local addr: /127.0.0.1:51394
DEBUG: [HttpClient-1-Worker-0] [71ms] PlainHttpConnection(SocketTube(1)) finishConnect, setting connected=true
DEBUG: [HttpClient-1-Worker-0] [71ms] Http1Exchange SocketTube(1) connecting flows
DEBUG: [HttpClient-1-Worker-0] [71ms] SocketTube(1) connecting flows
DEBUG: [HttpClient-1-Worker-0] [71ms] SocketTube(1) read publisher got subscriber
DEBUG: [HttpClient-1-Worker-0] [71ms] SocketTube(1) registering subscribe event
DEBUG: [HttpClient-1-Worker-0] [72ms] SocketTube(1) leaving read.subscribe:  Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=0]
DEBUG: [HttpClient-1-SelectorManager] [72ms] SocketTube(1) subscribe event raised
DEBUG: [HttpClient-1-Worker-0] [72ms] Http1Publisher(SocketTube(1)) got subscriber: SocketTube(1)
DEBUG: [HttpClient-1-Worker-0] [72ms] SocketTube(1) subscribed for writing
DEBUG: [HttpClient-1-Worker-0] [72ms] SocketTube(1) write: registering startSubscription event
DEBUG: [HttpClient-1-Worker-0] [72ms] Http1Exchange requestAction.headers
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription handleSubscribeEvent
INFORMATION: CHANNEL: Start reading from java.nio.channels.SocketChannel[connected local=/127.0.0.1:51394 remote=localhost/127.0.0.1:51393]
DEBUG: [HttpClient-1-SelectorManager] [72ms] SocketTube(1) handling pending subscription for jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber@2efc7bd2
DEBUG: [HttpClient-1-SelectorManager] [72ms] SocketTube(1) read demand reset to 0
DEBUG: [HttpClient-1-SelectorManager] [72ms] SocketTube(1) calling onSubscribe
DEBUG: [HttpClient-1-SelectorManager] [72ms] Http1AsyncReceiver(SocketTube(1)) Received onSubscribed from upstream
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.Http1Request headers
INFORMATION: REQUEST: http://localhost:51393/test123 POST
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber onSubscribe
INFORMATION: CHANNEL: HTTP/1 read subscriber got subscription from http://localhost:51393/test123 POST
DEBUG: [HttpClient-1-SelectorManager] [73ms] SocketTube(1) onSubscribe called
DEBUG: [HttpClient-1-SelectorManager] [73ms] SocketTube(1) pending subscriber subscribed
DEBUG: [HttpClient-1-SelectorManager] [74ms] SocketTube(1) write: starting subscription
DEBUG: [HttpClient-1-Worker-1] [74ms] Http1AsyncReceiver(SocketTube(1)) downstream subscription demand is 1
DEBUG: [HttpClient-1-Worker-1] [74ms] Http1AsyncReceiver(SocketTube(1)) checkRequestMore: canRequestMore=true, hasDemand=true
DEBUG: [HttpClient-1-Worker-1] [74ms] Http1AsyncReceiver(SocketTube(1)) Http1TubeSubscriber: requesting one more from upstream
DEBUG: [HttpClient-1-Worker-1] [74ms] SocketTube(1) got some demand for reading
DEBUG: [HttpClient-1-Worker-1] [74ms] SocketTube(1) resuming read event
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.SocketTube$InternalWriteSubscriber startSubscription
INFORMATION: CHANNEL: Start requesting bytes for writing to channel: java.nio.channels.SocketChannel[connected local=/127.0.0.1:51394 remote=localhost/127.0.0.1:51393]
DEBUG: [HttpClient-1-SelectorManager] [75ms] SocketTube(1) write: offloading requestMore
DEBUG: [HttpClient-1-Worker-1] [75ms] SocketTube(1) leaving request(1):  Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=0]
DEBUG: [HttpClient-1-SelectorManager] [75ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@6a7cfa55 for 1 (true)
DEBUG: [HttpClient-1-Worker-2] [75ms] SocketTube(1) write: requesting more...
DEBUG: [HttpClient-1-Worker-2] [75ms] Http1Publisher(SocketTube(1)) subscription request(1), demand=1
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.Http1Request logHeaders
INFORMATION: HEADERS: REQUEST HEADERS:
POST /test123 HTTP/1.1
Connection: Upgrade, HTTP2-Settings
Host: localhost:51393
HTTP2-Settings: AAEAAEAAAAIAAAABAAMAAABkAAQBAAAAAAUAAEAA
Transfer-encoding: chunked
Upgrade: h2c
User-Agent: Java-http-client/11.0.11

DEBUG: [HttpClient-1-Worker-2] [75ms] Http1Publisher(SocketTube(1)) WriteTask
DEBUG: [HttpClient-1-Worker-0] [75ms] Http1Exchange setting outgoing with headers
DEBUG: [HttpClient-1-Worker-2] [75ms] Http1Publisher(SocketTube(1)) hasOutgoing = false
DEBUG: [HttpClient-1-Worker-2] [75ms] SocketTube(1) leaving requestMore:  Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1]
DEBUG: [HttpClient-1-Worker-0] [76ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=224 cap=224]], throwable=null]
DEBUG: [HttpClient-1-Worker-0] [76ms] Http1Publisher(SocketTube(1)) WriteTask
DEBUG: [HttpClient-1-Worker-0] [76ms] Http1Publisher(SocketTube(1)) hasOutgoing = true
DEBUG: [HttpClient-1-Worker-0] [76ms] Http1Exchange initiating completion of headersSentCF
DEBUG: [HttpClient-1-Worker-0] [76ms] Http1Publisher(SocketTube(1)) onNext with 224 bytes
DEBUG: [HttpClient-1-Worker-0] [76ms] SocketTube(1) trying to write: 224
DEBUG: [HttpClient-1-Worker-0] [77ms] SocketTube(1) wrote: 224
DEBUG: [HttpClient-1-Worker-0] [78ms] SocketTube(1) write: requesting more...
DEBUG: [HttpClient-1-Worker-0] [78ms] Http1Publisher(SocketTube(1)) subscription request(1), demand=1
DEBUG: [HttpClient-1-Worker-0] [78ms] SocketTube(1) leaving requestMore:  Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1]
DEBUG: [HttpClient-1-Worker-0] [78ms] SocketTube(1) leaving w.onNext Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1]
DEBUG: [HttpClient-1-Worker-0] [78ms] Http1Publisher(SocketTube(1)) WriteTask
DEBUG: [HttpClient-1-Worker-0] [78ms] Http1Publisher(SocketTube(1)) hasOutgoing = false
DEBUG: [HttpClient-1-Worker-0] [78ms] Exchange checkFor407: all clear
DEBUG: [HttpClient-1-Worker-0] [78ms] Exchange sendRequestBody
DEBUG: [HttpClient-1-Worker-0] [78ms] Http1Exchange sendBodyAsync
DEBUG: [HttpClient-1-Worker-0] [79ms] Http1Exchange bodySubscriber is class jdk.internal.net.http.Http1Request$StreamSubscriber
DEBUG: [HttpClient-1-Worker-0] [79ms] Http1Exchange requesting more request body from the subscriber
DEBUG: [HttpClient-1-Worker-0] [79ms] jdk.internal.net.http.Http1Request@25bd9fe9 Http1BodySubscriber requesting 1, from jdk.internal.net.http.PullPublisher$Subscription@2be41f2b
DEBUG: [HttpClient-1-Worker-0] [79ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=3 cap=3], java.nio.HeapByteBuffer[pos=0 lim=3 cap=16384], java.nio.HeapByteBuffer[pos=0 lim=2 cap=2]], throwable=null]
DEBUG: [HttpClient-1-Worker-0] [79ms] Http1Publisher(SocketTube(1)) WriteTask
DEBUG: [HttpClient-1-Worker-0] [79ms] Http1Publisher(SocketTube(1)) hasOutgoing = true
DEBUG: [HttpClient-1-Worker-0] [79ms] Http1Exchange requesting more request body from the subscriber
DEBUG: [HttpClient-1-Worker-0] [79ms] jdk.internal.net.http.Http1Request@25bd9fe9 Http1BodySubscriber requesting 1, from jdk.internal.net.http.PullPublisher$Subscription@2be41f2b
DEBUG: [HttpClient-1-Worker-0] [79ms] Http1Publisher(SocketTube(1)) onNext with 8 bytes
DEBUG: [HttpClient-1-Worker-0] [79ms] SocketTube(1) trying to write: 8
DEBUG: [HttpClient-1-Worker-0] [80ms] SocketTube(1) wrote: 8
DEBUG: [HttpClient-1-Worker-0] [80ms] SocketTube(1) write: requesting more...
DEBUG: [HttpClient-1-Worker-0] [80ms] Http1Publisher(SocketTube(1)) subscription request(1), demand=1
DEBUG: [HttpClient-1-Worker-0] [80ms] SocketTube(1) leaving requestMore:  Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1]
DEBUG: [HttpClient-1-Worker-0] [80ms] SocketTube(1) leaving w.onNext Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1]
DEBUG: [HttpClient-1-Worker-0] [80ms] Http1Publisher(SocketTube(1)) WriteTask
DEBUG: [HttpClient-1-Worker-0] [80ms] Http1Publisher(SocketTube(1)) hasOutgoing = false
DEBUG: [HttpClient-1-Worker-0] [80ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=3 cap=3], java.nio.HeapByteBuffer[pos=0 lim=2 cap=2]], throwable=null]
DEBUG: [HttpClient-1-Worker-0] [80ms] Http1Publisher(SocketTube(1)) WriteTask
DEBUG: [HttpClient-1-Worker-0] [80ms] Http1Publisher(SocketTube(1)) hasOutgoing = true
DEBUG: [HttpClient-1-Worker-0] [80ms] Http1Exchange requesting more request body from the subscriber
DEBUG: [HttpClient-1-Worker-0] [80ms] jdk.internal.net.http.Http1Request@25bd9fe9 Http1BodySubscriber requesting 1, from jdk.internal.net.http.PullPublisher$Subscription@2be41f2b
DEBUG: [HttpClient-1-Worker-0] [80ms] Http1Publisher(SocketTube(1)) onNext with 5 bytes
DEBUG: [HttpClient-1-Worker-0] [80ms] SocketTube(1) trying to write: 5
DEBUG: [HttpClient-1-Worker-0] [80ms] SocketTube(1) wrote: 5
DEBUG: [HttpClient-1-Worker-0] [80ms] SocketTube(1) write: requesting more...
DEBUG: [HttpClient-1-Worker-0] [80ms] Http1Publisher(SocketTube(1)) subscription request(1), demand=1
DEBUG: [HttpClient-1-Worker-0] [80ms] SocketTube(1) leaving requestMore:  Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1]
DEBUG: [HttpClient-1-Worker-0] [80ms] SocketTube(1) leaving w.onNext Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1]
DEBUG: [HttpClient-1-Worker-0] [80ms] Http1Publisher(SocketTube(1)) WriteTask
DEBUG: [HttpClient-1-Worker-0] [80ms] Http1Publisher(SocketTube(1)) hasOutgoing = false
DEBUG: [HttpClient-1-Worker-0] [80ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]], throwable=null]
DEBUG: [HttpClient-1-Worker-0] [80ms] Http1Publisher(SocketTube(1)) WriteTask
DEBUG: [HttpClient-1-Worker-0] [80ms] Http1Publisher(SocketTube(1)) hasOutgoing = true
DEBUG: [HttpClient-1-Worker-0] [80ms] Http1Exchange initiating completion of bodySentCF
DEBUG: [HttpClient-1-Worker-0] [80ms] Http1Publisher(SocketTube(1)) completed, stopping jdk.internal.net.http.common.SequentialScheduler@39d2043e
DEBUG: [HttpClient-1-Worker-0] [81ms] Http1Exchange sendBodyAsync completed successfully
DEBUG: [HttpClient-1-Worker-0] [81ms] Http1Exchange reading headers
DEBUG: [HttpClient-1-Worker-0] [84ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Reading Headers: (remaining: 0) READING_HEADERS
DEBUG: [HttpClient-1-Worker-0] [84ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) First time around
DEBUG: [HttpClient-1-Worker-0] [84ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) headersReader is not yet completed
DEBUG: [HttpClient-1-SelectorManager] [123ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@6a7cfa55 for 0 (false)
DEBUG: [HttpClient-1-SelectorManager] [124ms] SocketTube(1) read bytes: 71
DEBUG: [HttpClient-1-SelectorManager] [124ms] Http1AsyncReceiver(SocketTube(1)) Putting 71 bytes into the queue
DEBUG: [HttpClient-1-SelectorManager] [124ms] SocketTube(1) resuming read event
DEBUG: [HttpClient-1-SelectorManager] [124ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@6a7cfa55 for 1 (false)
DEBUG: [HttpClient-1-SelectorManager] [124ms] SocketTube(1) leaving read() loop after onNext:  Reading: [ops=1, demand=0, stopped=false], Writing: [ops=0, demand=1]
DEBUG: [HttpClient-1-Worker-0] [125ms] Http1AsyncReceiver(SocketTube(1)) Got 71 bytes for delegate jdk.internal.net.http.Http1Response$HeadersReader@2aeefcc
DEBUG: [HttpClient-1-Worker-0] [125ms] Http1AsyncReceiver(SocketTube(1)) downstream subscription demand is 1
DEBUG: [HttpClient-1-Worker-0] [125ms] Http1AsyncReceiver(SocketTube(1)) Forwarding 71 bytes to delegate jdk.internal.net.http.Http1Response$HeadersReader@2aeefcc
DEBUG: [HttpClient-1-SelectorManager] [126ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@6a7cfa55 for 0 (false)
DEBUG: [HttpClient-1-SelectorManager] [126ms] SocketTube(1) no more demand for reading
DEBUG: [HttpClient-1-SelectorManager] [126ms] SocketTube(1) leaving read() loop with no demand Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=1]
DEBUG: [HttpClient-1-Worker-0] [127ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Sending 71/71 bytes to header parser
DEBUG: [HttpClient-1-Worker-0] [127ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Parsing headers completed. bytes=71
DEBUG: [HttpClient-1-Worker-0] [127ms] Http1AsyncReceiver(SocketTube(1)) Unsubscribed jdk.internal.net.http.Http1Response$HeadersReader@2aeefcc
DEBUG: [HttpClient-1-Worker-0] [127ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Reading Headers: creating Response object; state is now READING_BODY
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.Http1Response lambda$readHeadersAsync$0
INFORMATION: HEADERS: RESPONSE HEADERS:
    connection: Upgrade
    upgrade: h2c

DEBUG: [HttpClient-1-Worker-0] [128ms] Http1Exchange getResponseAsync completed successfully
DEBUG: [HttpClient-1-Worker-0] [128ms] Exchange Upgrading async PlainHttpConnection: HttpConnection: java.nio.channels.SocketChannel[connected local=/127.0.0.1:51394 remote=localhost/127.0.0.1:51393]
DEBUG: [HttpClient-1-Worker-0] [131ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Operation started: incrementing ref count for jdk.internal.net.http.HttpClientImpl@59496961(1)
DEBUG: [HttpClient-1-Worker-0] [132ms] Http1AsyncReceiver(SocketTube(1)) Subscribed pending jdk.internal.net.http.Http1Response$BodyReader@20bdbe5/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@48f30b87 queue.isEmpty: false
DEBUG: [HttpClient-1-Worker-0] [138ms] Http1AsyncReceiver(SocketTube(1)) Delegate done: 0
DEBUG: [HttpClient-1-Worker-0] [139ms] PlainHttpConnection(SocketTube(1))/ResponseContent/FixedLengthBodyParser length=0, onSubscribe: jdk.internal.net.http.Http1Response$Http1BodySubscriber
DEBUG: [HttpClient-1-Worker-0] [139ms] Http1AsyncReceiver(SocketTube(1)) cleared
DEBUG: [HttpClient-1-Worker-0] [139ms] Exchange Ignored body
DEBUG: [HttpClient-1-Worker-0] [153ms] Http2Connection(SocketTube(1)) For the record:jdk.internal.net.http.Http2Connection@43c9e6bf
DEBUG: [HttpClient-1-Worker-0] [153ms] Http2Connection(SocketTube(1)) Decoder created: jdk.internal.net.http.hpack.Decoder@6ea63687
DEBUG: [HttpClient-1-Worker-0] [153ms] Http2Connection(SocketTube(1)) Encoder created: jdk.internal.net.http.hpack.Encoder@75f099c8
DEBUG: [HttpClient-1-Worker-0] [157ms] Http2Connection(SocketTube(1)):WindowUpdateSender(stream: 0) maxFrameSize=16384, initWindowSize=33554432, limit=16777216
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.Http2Connection <init>
INFORMATION: MISC: Connection send window size 65.535 
DEBUG: [HttpClient-1-Worker-0] [159ms] Http2Connection(SocketTube(1)):WindowUpdateSender(stream: ?) maxFrameSize=16384, initWindowSize=16777216, limit=8388608
DEBUG: [HttpClient-1-Worker-0] [160ms] Http2Connection(SocketTube(1))/Stream(1) Registered stream 1
DEBUG: [HttpClient-1-Worker-0] [160ms] Http2Connection(SocketTube(1))/Stream(1) requestSent: streamid=1 but response not received
DEBUG: [HttpClient-1-Worker-0] [160ms] SocketTube(1) connecting flows
DEBUG: [HttpClient-1-Worker-0] [160ms] SocketTube(1) read publisher got subscriber
DEBUG: [HttpClient-1-Worker-0] [160ms] SocketTube(1) registering subscribe event
DEBUG: [HttpClient-1-Worker-0] [160ms] SocketTube(1) leaving read.subscribe:  Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=1]
DEBUG: [HttpClient-1-SelectorManager] [160ms] SocketTube(1) subscribe event raised
DEBUG: [HttpClient-1-Worker-0] [160ms] SocketTube(1) subscribed for writing
DEBUG: [HttpClient-1-Worker-0] [160ms] SocketTube(1) write: resetting demand to 0
DEBUG: [HttpClient-1-Worker-0] [160ms] SocketTube(1) write: registering startSubscription event
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription handleSubscribeEvent
INFORMATION: CHANNEL: Start reading from java.nio.channels.SocketChannel[connected local=/127.0.0.1:51394 remote=localhost/127.0.0.1:51393]
DEBUG: [HttpClient-1-SelectorManager] [160ms] SocketTube(1) handling pending subscription for jdk.internal.net.http.Http2Connection$Http2TubeSubscriber@264c87a5
DEBUG: [HttpClient-1-SelectorManager] [160ms] Http1AsyncReceiver(SocketTube(1)) Http1TubeSubscriber: dropSubscription
DEBUG: [HttpClient-1-SelectorManager] [160ms] SocketTube(1) read demand reset to 0
DEBUG: [HttpClient-1-SelectorManager] [160ms] SocketTube(1) calling onSubscribe
DEBUG: [HttpClient-1-SelectorManager] [160ms] Http2Connection(SocketTube(1)) onSubscribe: requesting Long.MAX_VALUE for reading
DEBUG: [HttpClient-1-SelectorManager] [160ms] SocketTube(1) got some demand for reading
DEBUG: [HttpClient-1-SelectorManager] [160ms] SocketTube(1) resuming read event
DEBUG: [HttpClient-1-SelectorManager] [160ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@6a7cfa55 for 1 (true)
DEBUG: [HttpClient-1-SelectorManager] [160ms] SocketTube(1) leaving request(9223372036854775807):  Reading: [ops=1, demand=9223372036854775807, stopped=false], Writing: [ops=0, demand=0]
DEBUG: [HttpClient-1-SelectorManager] [160ms] SocketTube(1) onSubscribe called
DEBUG: [HttpClient-1-SelectorManager] [160ms] SocketTube(1) pending subscriber subscribed
DEBUG: [HttpClient-1-SelectorManager] [161ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@6a7cfa55 for 0 (false)
DEBUG: [HttpClient-1-SelectorManager] [161ms] SocketTube(1) read bytes: 97
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.Http2Connection sendConnectionPreface
INFORMATION: MISC: /127.0.0.1:51394: start sending connection preface to localhost/127.0.0.1:51393
DEBUG: [HttpClient-1-SelectorManager] [162ms] Http2Connection(SocketTube(1)) onNext: got 97 bytes in 1 buffers
DEBUG: [HttpClient-1-SelectorManager] [162ms] SocketTube(1) resuming read event
DEBUG: [HttpClient-1-SelectorManager] [162ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@6a7cfa55 for 1 (false)
DEBUG: [HttpClient-1-SelectorManager] [162ms] SocketTube(1) leaving read() loop after onNext:  Reading: [ops=1, demand=9223372036854775806, stopped=false], Writing: [ops=0, demand=0]
DEBUG: [HttpClient-1-SelectorManager] [162ms] SocketTube(1) write: starting subscription
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.SocketTube$InternalWriteSubscriber startSubscription
INFORMATION: CHANNEL: Start requesting bytes for writing to channel: java.nio.channels.SocketChannel[connected local=/127.0.0.1:51394 remote=localhost/127.0.0.1:51393]
DEBUG: [HttpClient-1-SelectorManager] [163ms] SocketTube(1) write: offloading requestMore
DEBUG: [HttpClient-1-SelectorManager] [163ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@6a7cfa55 for 0 (false)
DEBUG: [HttpClient-1-SelectorManager] [163ms] SocketTube(1) got read EOF
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription read
INFORMATION: CHANNEL: EOF read from channel: java.nio.channels.SocketChannel[connected local=/127.0.0.1:51394 remote=localhost/127.0.0.1:51393]
DEBUG: [HttpClient-1-SelectorManager] [163ms] SocketTube(1) pausing read event
DEBUG: [HttpClient-1-Worker-2] [163ms] Http2Connection(SocketTube(1)) sending 97 to Http2Connection.asyncReceive
DEBUG: [HttpClient-1-Worker-2] [163ms] Http1AsyncReceiver(SocketTube(1)) stopping
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.Http1AsyncReceiver stop
INFORMATION: CHANNEL: HTTP/1 read subscriber stopped for <uri unavailable>
DEBUG: [HttpClient-1-Worker-2] [164ms] Http1Exchange asyncReceiver finished (failed=null)
DEBUG: [HttpClient-1-Worker-2] [164ms] Http1AsyncReceiver(SocketTube(1)) Flushing 0 bytes from queue into initial buffer (remaining=0, free=0)
DEBUG: [HttpClient-1-Worker-1] [164ms] SocketTube(1) write: requesting more...
DEBUG: [HttpClient-1-Worker-1] [164ms] PlainHttpConnection(SocketTube(1)) HttpPublisher: got request of 1 from SocketTube(1)
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.Http2Connection sendConnectionPreface
INFORMATION: FRAME: OUT: SETTINGS: length=30, streamid=0, flags=0  Settings: HEADER_TABLE_SIZE=16384 ENABLE_PUSH=1 MAX_CONCURRENT_STREAMS=100 INITIAL_WINDOW_SIZE=16777216 MAX_FRAME_SIZE=16384 
DEBUG: [HttpClient-1-Worker-1] [165ms] SocketTube(1) leaving requestMore:  Reading: [ops=0, demand=9223372036854775805, stopped=false], Writing: [ops=0, demand=1]
DEBUG: [HttpClient-1-SelectorManager] [164ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@6a7cfa55 for 0 (false)
DEBUG: [HttpClient-1-SelectorManager] [165ms] SocketTube(1) completing subscriber
DEBUG: [HttpClient-1-Worker-0] [165ms] PlainHttpConnection(SocketTube(1)) added 63 bytes in the priority write queue
DEBUG: [HttpClient-1-Worker-0] [165ms] PlainHttpConnection(SocketTube(1)) signalling the publisher of the write queue
DEBUG: [HttpClient-1-SelectorManager] [165ms] Http2Connection(SocketTube(1)) EOF reached while reading
DEBUG: [HttpClient-1-SelectorManager] [165ms] SocketTube(1) leaving read() loop after EOF:  Reading: [ops=0, demand=9223372036854775805, stopped=true], Writing: [ops=0, demand=1]
DEBUG: [HttpClient-1-SelectorManager] [165ms] SocketTube(1) Read scheduler stopped
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.SocketTube$InternalReadPublisher$InternalReadSubscription read
INFORMATION: CHANNEL: Stopped reading from channel java.nio.channels.SocketChannel[connected local=/127.0.0.1:51394 remote=localhost/127.0.0.1:51393]
DEBUG: [HttpClient-1-Worker-2] [168ms] Http1AsyncReceiver(SocketTube(1)) Initial buffer now has 0 pos=0 limit=0
DEBUG: [HttpClient-1-Worker-2] [168ms] Http2Connection(SocketTube(1)) H2 Receiving(1): 97
DEBUG: [HttpClient-1-Worker-2] [168ms] Http2Connection(SocketTube(1)) Preface not sent: buffering 97
DEBUG: [HttpClient-1-Worker-2] [169ms] Http2Connection(SocketTube(1)) there are now %d bytes buffered waiting for preface to be sent97
DEBUG: [HttpClient-1-Worker-2] [169ms] Http2Connection(SocketTube(1)) H2 processed(1)
DEBUG: [HttpClient-1-Worker-2] [169ms] Http2Connection(SocketTube(1)) Stopping scheduler java.io.EOFException: EOF reached while reading
DEBUG: [HttpClient-1-Worker-0] [169ms] PlainHttpConnection(SocketTube(1)) HttpPublisher: sending 63 bytes (1 buffers) to SocketTube(1)
DEBUG: [HttpClient-1-Worker-0] [169ms] SocketTube(1) trying to write: 63
java.io.EOFException: EOF reached while reading
    at java.net.http/jdk.internal.net.http.Http2Connection$Http2TubeSubscriber.onComplete(Http2Connection.java:1340)
    at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadSubscription.signalCompletion(SocketTube.java:632)
    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:175)
    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.SocketTube$InternalReadPublisher$InternalReadSubscription.signalReadable(SocketTube.java:763)
    at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent.signalEvent(SocketTube.java:941)
    at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowEvent.handle(SocketTube.java:245)
    at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.handleEvent(HttpClientImpl.java:957)
    at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.lambda$run$3(HttpClientImpl.java:912)
    at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
    at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:912)
DEBUG: [HttpClient-1-Worker-0] [169ms] SocketTube(1) wrote: 63
DEBUG: [HttpClient-1-Worker-0] [169ms] SocketTube(1) write: requesting more...
DEBUG: [HttpClient-1-Worker-0] [169ms] PlainHttpConnection(SocketTube(1)) HttpPublisher: got request of 1 from SocketTube(1)
DEBUG: [HttpClient-1-Worker-0] [170ms] SocketTube(1) leaving requestMore:  Reading: [ops=0, demand=9223372036854775805, stopped=true], Writing: [ops=0, demand=1]
DEBUG: [HttpClient-1-Worker-0] [170ms] SocketTube(1) leaving w.onNext Reading: [ops=0, demand=9223372036854775805, stopped=true], Writing: [ops=0, demand=1]
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.Http2Connection sendConnectionPreface
INFORMATION: MISC: PREFACE_BYTES sent
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.Http2Connection sendConnectionPreface
INFORMATION: MISC: Settings Frame sent
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.Http2Connection sendConnectionPreface
INFORMATION: CHANNEL: Sending initial connection window update frame: 33.488.897 (33.554.432 - 65.535)
DEBUG: [HttpClient-1-Worker-0] [171ms] Http2Connection(SocketTube(1)):WindowUpdateSender(stream: 0) sending window update: 33488897
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.Http2Connection encodeFrame
INFORMATION: FRAME: OUT: WINDOW_UPDATE: length=4, streamid=0, flags=0  WindowUpdate: 33488897
DEBUG: [HttpClient-1-Worker-0] [171ms] PlainHttpConnection(SocketTube(1)) added 13 bytes in the priority write queue
DEBUG: [HttpClient-1-Worker-0] [171ms] PlainHttpConnection(SocketTube(1)) signalling the publisher of the write queue
DEBUG: [HttpClient-1-Worker-0] [171ms] PlainHttpConnection(SocketTube(1)) HttpPublisher: sending 13 bytes (1 buffers) to SocketTube(1)
DEBUG: [HttpClient-1-Worker-0] [171ms] SocketTube(1) trying to write: 13
DEBUG: [HttpClient-1-Worker-2] [172ms] Http2Connection(SocketTube(1)) Shutting down h2c (closed=false): java.io.EOFException: EOF reached while reading
DEBUG: [HttpClient-1-Worker-0] [172ms] SocketTube(1) write error: java.io.IOException: Broken pipe
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.SocketTube$InternalWriteSubscriber signalError
INFORMATION: CHANNEL: Failed to write to channel (java.nio.channels.SocketChannel[connected local=/127.0.0.1:51394 remote=localhost/127.0.0.1:51393]: java.io.IOException: Broken pipe)
DEBUG: [HttpClient-1-Worker-0] [172ms] SocketTube(1) error signalled java.io.IOException: Broken pipe
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.SocketTube$InternalReadPublisher signalError
INFORMATION: CHANNEL: Error signalled on channel java.nio.channels.SocketChannel[connected local=/127.0.0.1:51394 remote=localhost/127.0.0.1:51393]: java.io.IOException: Broken pipe
DEBUG: [HttpClient-1-Worker-0] [173ms] SocketTube(1) write: cancel
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.SocketTube$InternalWriteSubscriber$WriteSubscription cancel
INFORMATION: CHANNEL: Cancelling write subscription
DEBUG: [HttpClient-1-Worker-0] [173ms] SocketTube(1) write: resetting demand to 0
DEBUG: [HttpClient-1-Worker-0] [173ms] PlainHttpConnection(SocketTube(1)) HttpPublisher: cancelled by SocketTube(1)
DEBUG: [HttpClient-1-Worker-0] [173ms] SocketTube(1) leaving w.onNext Reading: [ops=0, demand=9223372036854775805, stopped=true], Writing: [ops=0, demand=0]
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.Http2Connection shutdown
INFORMATION: ERROR: java.io.EOFException: EOF reached while reading
    at java.net.http/jdk.internal.net.http.Http2Connection$Http2TubeSubscriber.onComplete(Http2Connection.java:1340)
    at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadSubscription.signalCompletion(SocketTube.java:632)
    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:175)
    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.SocketTube$InternalReadPublisher$InternalReadSubscription.signalReadable(SocketTube.java:763)
    at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent.signalEvent(SocketTube.java:941)
    at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowEvent.handle(SocketTube.java:245)
    at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.handleEvent(HttpClientImpl.java:957)
    at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.lambda$run$3(HttpClientImpl.java:912)
    at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
    at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:912)

DEBUG: [HttpClient-1-Worker-2] [173ms] Http2ClientImpl removing from the connection pool: Http2Connection(SocketTube(1))
DEBUG: [HttpClient-1-Worker-2] [174ms] Http2Connection(SocketTube(1))/Stream(1) cancelling stream 1: java.io.EOFException: EOF reached while reading
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.Http2Connection sendConnectionPreface
INFORMATION: MISC: finished sending connection preface
DEBUG: [HttpClient-1-Worker-0] [174ms] Http2Connection(SocketTube(1)) Triggering processing of buffered data after sending connection preface
DEBUG: [HttpClient-1-Worker-0] [174ms] Http2Connection(SocketTube(1)) onNext: got 0 bytes in 1 buffers
DEBUG: [HttpClient-1-Worker-0] [174ms] Http2ClientImpl offering to the connection pool: Http2Connection(SocketTube(1))
DEBUG: [HttpClient-1-Worker-0] [174ms] Http2ClientImpl skipping offered closed or closing connection: Http2Connection(SocketTube(1))
DEBUG: [HttpClient-1-Worker-0] [174ms] Http1AsyncReceiver(SocketTube(1)) cleared
DEBUG: [HttpClient-1-Worker-0] [174ms] Exchange Getting response async streamid: 1
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.Stream cancelImpl
INFORMATION: MISC: cancelling stream 1: java.io.EOFException: EOF reached while reading

DEBUG: [HttpClient-1-Worker-2] [175ms] Http2Connection(SocketTube(1)) Closed stream 1
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.Stream getResponseAsync
INFORMATION: MISC: Response future (stream=1) is: jdk.internal.net.http.common.MinimalFuture@4b644c94[Completed exceptionally: java.io.EOFException: EOF reached while reading] (id=55)
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.PlainHttpConnection close
INFORMATION: MISC: Closing: PlainHttpConnection: HttpConnection: java.nio.channels.SocketChannel[connected local=/127.0.0.1:51394 remote=localhost/127.0.0.1:51393]
DEBUG: [HttpClient-1-Worker-2] [176ms] PlainHttpConnection(SocketTube(1)) Closing channel: channel registered with selector, key.interestOps=0, sa.interestOps=0
Nov. 03, 2023 7:33:44 NACHM. jdk.internal.net.http.SocketTube signalClosed
INFORMATION: CHANNEL: Connection close signalled: connection closed locally (java.nio.channels.SocketChannel[closed])
DEBUG: [HttpClient-1-Worker-0] [180ms] HttpClientImpl(1) ClientImpl (async) elapsed 163 millis for POST to http://localhost:51393/test123
DEBUG: [HttpClient-1-Worker-0] [181ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Finished reading body: READING_BODY
DEBUG: [HttpClient-1-Worker-0] [181ms] Http1Response(id=1, PlainHttpConnection(SocketTube(1))) Operation finished: decrementing ref count for jdk.internal.net.http.HttpClientImpl@59496961(1)
DEBUG: [HttpClient-1-Worker-0] [181ms] Http1AsyncReceiver(SocketTube(1)) delegate is now jdk.internal.net.http.Http1Response$BodyReader@20bdbe5/parser=jdk.internal.net.http.ResponseContent$FixedLengthBodyParser@48f30b87, demand=9223372036854775807, canRequestMore=false, queue.isEmpty=true
DEBUG: [HttpClient-1-Worker-0] [181ms] Http1AsyncReceiver(SocketTube(1)) downstream subscription demand is 9223372036854775807
DEBUG: [HttpClient-1-Worker-0] [181ms] Http1AsyncReceiver(SocketTube(1)) checkRequestMore: canRequestMore=false, hasDemand=true
DEBUG: [HttpClient-1-Worker-0] [181ms] Http1AsyncReceiver(SocketTube(1)) Http1TubeSubscriber: no need to request more

java.io.IOException: EOF reached while reading

    at java.net.http/jdk.internal.net.http.HttpClientImpl.send(HttpClientImpl.java:565)
    at java.net.http/jdk.internal.net.http.HttpClientFacade.send(HttpClientFacade.java:119)
    at test.Http2Test.testNative(Http2Test.java:44)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.junit.platform.commons.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:727)
    at org.junit.jupiter.engine.execution.MethodInvocation.proceed(MethodInvocation.java:60)
    at org.junit.jupiter.engine.execution.InvocationInterceptorChain$ValidatingInvocation.proceed(InvocationInterceptorChain.java:131)
    at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:156)
    at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:147)
    at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:86)
    at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(InterceptingExecutableInvoker.java:103)
    at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.lambda$invoke$0(InterceptingExecutableInvoker.java:93)
    at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
    at org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64)
    at org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45)
    at org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37)
    at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:92)
    at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:86)
    at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$7(TestMethodTestDescriptor.java:217)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:213)
    at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:138)
    at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:68)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:151)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
    at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
    at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
    at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:155)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
    at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
    at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
    at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:155)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
    at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
    at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:35)
    at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
    at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:54)
    at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:147)
    at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:127)
    at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:90)
    at org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:55)
    at org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:102)
    at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:54)
    at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:114)
    at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:86)
    at org.junit.platform.launcher.core.DefaultLauncherSession$DelegatingLauncher.execute(DefaultLauncherSession.java:86)
    at org.junit.platform.launcher.core.SessionPerRequestLauncher.execute(SessionPerRequestLauncher.java:53)
    at com.intellij.junit5.JUnit5IdeaTestRunner.startRunnerWithArgs(JUnit5IdeaTestRunner.java:71)
    at com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:33)
    at com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:235)
    at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:54)
Caused by: java.io.EOFException: EOF reached while reading
    at java.net.http/jdk.internal.net.http.Http2Connection$Http2TubeSubscriber.onComplete(Http2Connection.java:1340)
    at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadSubscription.signalCompletion(SocketTube.java:632)
    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:175)
    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.SocketTube$InternalReadPublisher$InternalReadSubscription.signalReadable(SocketTube.java:763)
    at java.net.http/jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent.signalEvent(SocketTube.java:941)
    at java.net.http/jdk.internal.net.http.SocketTube$SocketFlowEvent.handle(SocketTube.java:245)
    at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.handleEvent(HttpClientImpl.java:957)
    at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.lambda$run$3(HttpClientImpl.java:912)
    at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
    at java.net.http/jdk.internal.net.http.HttpClientImpl$SelectorManager.run(HttpClientImpl.java:912)

[main] INFO org.eclipse.jetty.server.Server - Stopped Server@5d1e09bc{STOPPING}[11.0.15,sto=1000]
[main] INFO org.eclipse.jetty.server.Server - Shutdown Server@5d1e09bc{STOPPING}[11.0.15,sto=1000]
[main] INFO org.eclipse.jetty.server.AbstractConnector - Stopped NetworkTrafficServerConnector@16423501{HTTP/1.1, (http/1.1, h2c)}{0.0.0.0:0}
[main] INFO org.eclipse.jetty.server.handler.ContextHandler - Stopped o.e.j.s.ServletContextHandler@250b236d{/,null,STOPPED}
[main] INFO org.eclipse.jetty.server.handler.ContextHandler - Stopped o.e.j.s.ServletContextHandler@398474a2{/__admin,null,STOPPED}

--> looks like it does support "h2c" same as in the upgrade-request, but does not work 🤷 --> or is this more likely a problem in jetty ?

References

Lolf1010 commented 1 year ago

Found the reason: It only works (HTTP/2 + InputStream) only works with HTTPS. Not sure why it works with other bodies like String 🤷

xmicore commented 10 months ago

The use of HTTPS in tests can mean significantly more effort. The bug should be reopened.

twarner-sofi commented 9 months ago

Running into this issue. Is there a workaround other than setting http version in client to 1.1? Anything I can do with wiremock options?