jtjeferreira commented on PR #830:
URL: https://github.com/apache/pekko-connectors/pull/830#issuecomment-2377141976
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](https://datatracker.ietf.org/doc/html/rfc9113#Reliability) 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 ?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscr...@pekko.apache.org
For queries about this service, please contact Infrastructure at:
us...@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: notifications-unsubscr...@pekko.apache.org
For additional commands, e-mail: notifications-h...@pekko.apache.org
