WIP: Support HTTP2 protocol + Kinesis integration test puzzle

[jtjeferreira]

depends on #829

This PR adds support for HTTP/2 protocol in AWS SDK HttpClient. Since the pekko-http support for http/2 is different than for http (it only support " Host-Level" and not "Request-Level" API) the implementation is a bit more tricky.

However, I found a problem when writing integration tests: the test KinesisITTest#list streams in parallel runs successfully in about 2 seconds, but if I increase number of clients from 5 to 6 it gets stuck and takes more than 60s to finish...

Can someone confirm they see this same behavior:

• configure AWS credentials
• run aws-spi-pekko-http/it:testOnly org.apache.pekko.stream.connectors.awsspi.kinesis.KinesisITTest -- -z "list streams"
• it should take 2s ✅
• change "list streams" test to use 6 clients instead of 5
• run test again
• test pass, but takes more than 60s ❌

[pjfanning]

Unfortunately, I don't have an AWS account to test those Kinesis tests against.

[jtjeferreira]

By comparing the logs of list streams test with list streams in parallel, I noticed these log lines:

✅

[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-0)] [ UP ] Element:    0 SETT  SETTINGS_MAX_CONCURRENT_STREAMS -> 5, SETTINGS_INITIAL_WINDOW_SIZE -> 1048576, SETTINGS_MAX_HEADER_LIST_SIZE -> 16384
[Http2ClientDemux(pekko://aws-pekko-http)] Got 3 settings!
[Http2ClientDemux(pekko://aws-pekko-http)] Setting initial window to 1048576
[Http2ClientDemux(pekko://aws-pekko-http)] Incoming side of stream [1] changed state: HalfClosedLocalWaitingForPeerStream -> HalfClosedLocalWaitingForPeerStream after handling [distributeWindowDeltaToAllStreams]
[Http2ClientDemux(pekko://aws-pekko-http)] Ignoring setting SETTINGS_MAX_HEADER_LIST_SIZE -> 16384 (in Demux)
[Http2ClientDemux(pekko://aws-pekko-http)] Changing state from WaitingForData to Idle
[Http2ClientDemux(pekko://aws-pekko-http)] Changing state from Idle to WaitingForData
[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-0)] [DOWN] Element:    0 SETA  SETTINGS_MAX_CONCURRENT_STREAMS -> 5, SETTINGS_INITIAL_WINDOW_SIZE -> 1048576, SETTINGS_MAX_HEADER_LIST_SIZE -> 16384
[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-0)] [ UP ] Element:    0 WIND  + 1966082
[Http2ClientDemux(pekko://aws-pekko-http)] Updating outgoing connection window by 1966082 to 2031615
[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-0)] [ UP ] Element:    0 SETA
[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-0)] [ UP ] Element:    1 HEAD  :status -> 200, x-amzn-requestid -> x-amzn-requestid: e8b5205a-b511-6707-b7da-4d6ee15c480c, x-amz-id-2 -> x-amz-id-2: gyTW39DLO+UMAdCvml6DeWqqMpyVNDG2RVep5GMfRo+loNQAQt4SglrWalTWv5PquPMtcb54RyLQePNa1866dJ559aPW6QKw, date -> Date: Thu, 26 Sep 2024 14:08:52 GMT, content-type -> application/x-amz-cbor-1.1, content-length -> 50
[Http2ClientDemux(pekko://aws-pekko-http)] Incoming side of stream [1] changed state: HalfClosedLocalWaitingForPeerStream -> HalfClosedLocal after handling [handleStreamEvent(ParsedHeadersFrame)]
[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-0)] [ UP ] Element:    1 DATA ES bf 6e 48 61 73 4d 6f 72 65 53 74 72 65 61 6d 73 [... 34 more bytes]
[Http2ClientDemux(pekko://aws-pekko-http)] Received DATA 50 for stream [1], remaining window space now 65485, buffered: 50
[Http2ClientDemux(pekko://aws-pekko-http)] Changing state from WaitingForData to Idle
[Http2ClientDemux(pekko://aws-pekko-http)] Incoming side of stream [1] changed state: HalfClosedLocal -> HalfClosedLocal after handling [handleStreamEvent(DataFrame)]
[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-0)] [DOWN] Element:    0 WIND  + 9934465
[Http2ClientDemux(pekko://aws-pekko-http)] Changing state from Idle to WaitingForData
[Http2ClientDemux(pekko://aws-pekko-http)] Dispatched chunk of 50 for stream [1], remaining window space now 65485, buffered: 0
[Http2ClientDemux(pekko://aws-pekko-http)] adjusting con-level window by 0, stream-level window by 446515, remaining window space now 65485, buffered: 0, remaining connection window space now 9999950, total buffered: 0
[Http2ClientDemux(pekko://aws-pekko-http)] Incoming side of stream [1] changed state: HalfClosedLocal -> Closed after handling [incomingStreamPulled]
[Http2ClientDemux(pekko://aws-pekko-http)] Closing connection after all streams are done and all data has been flushed.
[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-0)] [DOWN] Upstream finished.

❌

[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-1)] [ UP ] Element:    0 SETT  SETTINGS_MAX_CONCURRENT_STREAMS -> 5, SETTINGS_INITIAL_WINDOW_SIZE -> 1048576, SETTINGS_MAX_HEADER_LIST_SIZE -> 16384
[Http2ClientDemux(pekko://aws-pekko-http)] Got 3 settings!
[Http2ClientDemux(pekko://aws-pekko-http)] Setting initial window to 1048576
[Http2ClientDemux(pekko://aws-pekko-http)] Incoming side of stream [1] changed state: HalfClosedLocalWaitingForPeerStream -> HalfClosedLocalWaitingForPeerStream after handling [distributeWindowDeltaToAllStreams]
[Http2ClientDemux(pekko://aws-pekko-http)] Incoming side of stream [3] changed state: HalfClosedLocalWaitingForPeerStream -> HalfClosedLocalWaitingForPeerStream after handling [distributeWindowDeltaToAllStreams]
[Http2ClientDemux(pekko://aws-pekko-http)] Incoming side of stream [7] changed state: HalfClosedLocalWaitingForPeerStream -> HalfClosedLocalWaitingForPeerStream after handling [distributeWindowDeltaToAllStreams]
[Http2ClientDemux(pekko://aws-pekko-http)] Incoming side of stream [9] changed state: HalfClosedLocalWaitingForPeerStream -> HalfClosedLocalWaitingForPeerStream after handling [distributeWindowDeltaToAllStreams]
[Http2ClientDemux(pekko://aws-pekko-http)] Incoming side of stream [11] changed state: HalfClosedLocalWaitingForPeerStream -> HalfClosedLocalWaitingForPeerStream after handling [distributeWindowDeltaToAllStreams]
[Http2ClientDemux(pekko://aws-pekko-http)] Incoming side of stream [5] changed state: HalfClosedLocalWaitingForPeerStream -> HalfClosedLocalWaitingForPeerStream after handling [distributeWindowDeltaToAllStreams]
[Http2ClientDemux(pekko://aws-pekko-http)] Ignoring setting SETTINGS_MAX_HEADER_LIST_SIZE -> 16384 (in Demux)
[Http2ClientDemux(pekko://aws-pekko-http)] Changing state from WaitingForData to Idle
[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-1)] [DOWN] Element:    0 SETA  SETTINGS_MAX_CONCURRENT_STREAMS -> 5, SETTINGS_INITIAL_WINDOW_SIZE -> 1048576, SETTINGS_MAX_HEADER_LIST_SIZE -> 16384
[Http2ClientDemux(pekko://aws-pekko-http)] Changing state from Idle to WaitingForData
[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-1)] [ UP ] Element:    0 WIND  + 1966082
[Http2ClientDemux(pekko://aws-pekko-http)] Updating outgoing connection window by 1966082 to 2031605
[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-1)] [ UP ] Element:    0 SETA
[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-1)] [ UP ] Element:   11 RSET  REFUSED_STREAM
[Http2ClientDemux(pekko://aws-pekko-http)] Received unexpected frame of type RstStreamFrame for stream 11 in state HalfClosedLocalWaitingForPeerStream
[Http2ClientDemux(pekko://aws-pekko-http)] Changing state from WaitingForData to Idle
[Http2ClientDemux(pekko://aws-pekko-http)] Incoming side of stream [11] changed state: HalfClosedLocalWaitingForPeerStream -> Closed after handling [handleStreamEvent(RstStreamFrame)]
[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-1)] [DOWN] Element:    0 GOAY  lastStreamId = 11, errorCode = PROTOCOL_ERROR, debug = Received unexpected frame of type RstStreamFrame for stream 11 in state HalfClosedLocalWaitingForPeerStream

(streams 7, 3, 5, 1, 9 successfully receive data and are closed)

(1 minute passes)

[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-1)] [ UP ] Element:    0 GOAY  lastStreamId = 11, errorCode = NO_ERROR, debug =
[Http2ClientDemux(pekko://aws-pekko-http)] Got unhandled event GoAwayFrame(11,NO_ERROR,debug:<hidden>)
[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-1)] [ UP ] Upstream finished.
[org.apache.pekko.stream.Log(pekko://aws-pekko-http/system/Materializers/StreamSupervisor-1)] [DOWN] Upstream finished.

Retryable error detected. Will retry in 71ms. Request attempt number 1
software.amazon.awssdk.services.kinesis.model.KinesisException: Service returned HTTP status code 502 (Service: Kinesis, Status Code: 502, Request ID: null)

1 request is retried and test eventually passes

Important bits:

• On Got 3 settings! we received a SETTINGS_MAX_CONCURRENT_STREAMS with value 5, but 6 requests were already sent.
• On Received unexpected frame of type RstStreamFrame for stream 11 in state HalfClosedLocalWaitingForPeerStream and above Element: 11 RSET REFUSED_STREAM.
  • The Error code is REFUSED_STREAM
  • The RFC states that when the error code is REFUSED_STREAM the request can be safely retried: The REFUSED_STREAM error code can be included in a RST_STREAM frame to indicate that the stream is being closed prior to any processing having occurred. Any request that was sent on the reset stream can be safely retried.

So I think that this is a bug in http2 support of pekko-http... cc @jrudolph @raboof ?

[pjfanning]

Is it possible to also support HTTP 1.1? It might be a nice option to be able to use a HTTP 1.1 client if there are issues with the HTTP/2 one.

[jtjeferreira]

Is it possible to also support HTTP 1.1? It might be a nice option to be able to use a HTTP 1.1 client if there are issues with the HTTP/2 one.

Yes, HTTP 1.1 is supported and the default except for the kinesis client is the only that "forces" the use of HTTP/2. However, before this PR the PekkoClient only supports HTTP/1 and kinesis works fine with it. From what I could research [1], only kinesis servers support http/2