search

akka / akka-http

The Streaming-first HTTP server/module of Akka
https://doc.akka.io/docs/akka-http
Other
1.34k stars 594 forks source link

Failed: Http2ClientSpec should send RST_STREAM if entity stream is canceled #4332

Open johanandren opened 8 months ago

johanandren commented 8 months ago

https://github.com/akka/akka-http/actions/runs/6621440323/job/17985400975#step:7:1735

--> [The Http/2 client implementation should support stream for response data should send RST_STREAM if entity stream is canceled] Start of log messages of test that [Failed(org.scalatest.exceptions.TestFailedException: WINDOW_UPDATE was not equal to RST_STREAM)]
| [DEBUG] [10/24/2023 02:17:35.628] [pool-1-thread-1-ScalaTest-running-Http2ClientSpec] [WithLogCapturing(akka://Http2ClientSpec)] Logging started for test [The Http/2 client implementation should support stream for response data should send RST_STREAM if entity stream is canceled]
| [DEBUG] [10/24/2023 02:17:35.677] [Http2ClientSpec-akka.actor.default-dispatcher-6] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from Idle to WaitingForNetworkToSendControlFrames
| [DEBUG] [10/24/2023 02:17:35.677] [Http2ClientSpec-akka.actor.default-dispatcher-6] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from WaitingForNetworkToSendControlFrames to Idle
| [DEBUG] [10/24/2023 02:17:35.677] [Http2ClientSpec-akka.actor.default-dispatcher-6] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [DOWN] Element:    0 SETT  SETTINGS_MAX_CONCURRENT_STREAMS -> 256, SETTINGS_ENABLE_PUSH -> 0
| [DEBUG] [10/24/2023 02:17:35.678] [Http2ClientSpec-akka.actor.default-dispatcher-6] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [network-plain-text DOWN] Element:  ByteString(24 bytes)
|  50 52 49 20 2A 20 48 54 54 50 2F 32 2E 30 0D 0A  | PRI * HTTP/2.0..
|  0D 0A 53 4D 0D 0A 0D 0A                          | ..SM....
| [DEBUG] [10/24/2023 02:17:35.678] [Http2ClientSpec-akka.actor.default-dispatcher-6] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from Idle to WaitingForData
| [DEBUG] [10/24/2023 02:17:35.679] [Http2ClientSpec-akka.actor.default-dispatcher-6] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [network-plain-text DOWN] Element:  ByteString(21 bytes)
|  00 00 0C 04 00 00 00 00 00 00 03 00 00 01 00 00  | ................
|  02 00 00 00 00                                   | .....
| [DEBUG] [10/24/2023 02:17:35.679] [Http2ClientSpec-akka.actor.default-dispatcher-6] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [network-plain-text UP  ] Element:  ByteString(9 bytes)
|  00 00 00 04 00 00 00 00 00                       | .........
| [DEBUG] [10/24/2023 02:17:35.679] [Http2ClientSpec-akka.actor.default-dispatcher-6] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [ UP ] Element:    0 SETT  
| [DEBUG] [10/24/2023 02:17:35.679] [Http2ClientSpec-akka.actor.default-dispatcher-6] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from WaitingForData to Idle
| [DEBUG] [10/24/2023 02:17:35.680] [Http2ClientSpec-akka.actor.default-dispatcher-6] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [DOWN] Element:    0 SETA  
| [DEBUG] [10/24/2023 02:17:35.680] [Http2ClientSpec-akka.actor.default-dispatcher-6] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from Idle to WaitingForData
| [DEBUG] [10/24/2023 02:17:35.680] [Http2ClientSpec-akka.actor.default-dispatcher-6] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [network-plain-text DOWN] Element:  ByteString(9 bytes)
|  00 00 00 04 01 00 00 00 00                       | .........
| [DEBUG] [10/24/2023 02:17:35.680] [Http2ClientSpec-akka.actor.default-dispatcher-6] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from WaitingForData to Idle
| [DEBUG] [10/24/2023 02:17:35.680] [Http2ClientSpec-akka.actor.default-dispatcher-6] [Http2ClientDemux(akka://Http2ClientSpec)] Incoming side of stream [1] changed state: Idle -> HalfClosedLocalWaitingForPeerStream after handling [handleOutgoingCreatedAndFinished]
| [DEBUG] [10/24/2023 02:17:35.680] [Http2ClientSpec-akka.actor.default-dispatcher-6] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [DOWN] Element:    1 HEAD ES :method -> GET, :scheme -> , :authority -> , :path -> /, content-length -> 0, user-agent -> akka-http/10.6.0
| [DEBUG] [10/24/2023 02:17:35.681] [Http2ClientSpec-akka.actor.default-dispatcher-6] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from Idle to WaitingForData
| [DEBUG] [10/24/2023 02:17:35.681] [Http2ClientSpec-akka.actor.default-dispatcher-6] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [network-plain-text DOWN] Element:  ByteString(31 bytes)
|  00 00 16 01 05 00 00 00 01 82 46 00 81 84 5C 01  | ..........F...\.
|  30 7A 8C 1F 5E A3 5A 74 A6 B6 02 05 DC 5C 1F     | 0z..^.Zt.....\.
| [DEBUG] [10/24/2023 02:17:35.682] [Http2ClientSpec-akka.actor.default-dispatcher-6] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [network-plain-text UP  ] Element:  ByteString(10 bytes)
|  00 00 01 01 04 00 00 00 01 88                    | ..........
| [DEBUG] [10/24/2023 02:17:35.682] [Http2ClientSpec-akka.actor.default-dispatcher-6] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [ UP ] Element:    1 HEAD  :status -> 200
| [DEBUG] [10/24/2023 02:17:35.682] [Http2ClientSpec-akka.actor.default-dispatcher-6] [Http2ClientDemux(akka://Http2ClientSpec)] Incoming side of stream [1] changed state: HalfClosedLocalWaitingForPeerStream -> HalfClosedLocal after handling [handleStreamEvent(ParsedHeadersFrame)]
| [DEBUG] [10/24/2023 02:17:35.693] [Http2ClientSpec-akka.actor.default-dispatcher-13] [Http2ClientDemux(akka://Http2ClientSpec)] Incoming side of stream [1] changed state: HalfClosedLocal -> HalfClosedLocal after handling [incomingStreamPulled]
| [DEBUG] [10/24/2023 02:17:35.694] [Http2ClientSpec-akka.actor.default-dispatcher-10] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [network-plain-text UP  ] Element:  ByteString(15 bytes)
|  00 00 06 00 00 00 00 00 01 61 62 63 64 65 66     | .........abcdef
| [DEBUG] [10/24/2023 02:17:35.694] [Http2ClientSpec-akka.actor.default-dispatcher-10] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [ UP ] Element:    1 DATA  61 62 63 64 65 66
| [DEBUG] [10/24/2023 02:17:35.694] [Http2ClientSpec-akka.actor.default-dispatcher-10] [Http2ClientDemux(akka://Http2ClientSpec)] Received DATA 6 for stream [1], remaining window space now 65529, buffered: 6
| [DEBUG] [10/24/2023 02:17:35.694] [Http2ClientSpec-akka.actor.default-dispatcher-10] [Http2ClientDemux(akka://Http2ClientSpec)] Dispatched chunk of 6 for stream [1], remaining window space now 65529, buffered: 0
| [DEBUG] [10/24/2023 02:17:35.694] [Http2ClientSpec-akka.actor.default-dispatcher-10] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from WaitingForData to Idle
| [DEBUG] [10/24/2023 02:17:35.694] [Http2ClientSpec-akka.actor.default-dispatcher-10] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from Idle to WaitingForNetworkToSendControlFrames
| [DEBUG] [10/24/2023 02:17:35.694] [Http2ClientSpec-akka.actor.default-dispatcher-10] [Http2ClientDemux(akka://Http2ClientSpec)] adjusting con-level window by 9934471, stream-level window by 446471, remaining window space now 512000, buffered: 0, remaining connection window space now 10000000, total buffered: 0
| [DEBUG] [10/24/2023 02:17:35.694] [Http2ClientSpec-akka.actor.default-dispatcher-10] [Http2ClientDemux(akka://Http2ClientSpec)] Incoming side of stream [1] changed state: HalfClosedLocal -> HalfClosedLocal after handling [handleStreamEvent(DataFrame)]
| [DEBUG] [10/24/2023 02:17:35.694] [Http2ClientSpec-akka.actor.default-dispatcher-10] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [DOWN] Element:    0 WIND  + 9934471
| [DEBUG] [10/24/2023 02:17:35.694] [Http2ClientSpec-akka.actor.default-dispatcher-13] [Http2ClientDemux(akka://Http2ClientSpec)] Incoming side of stream [1] changed state: HalfClosedLocal -> HalfClosedLocal after handling [incomingStreamPulled]
| [DEBUG] [10/24/2023 02:17:35.696] [Http2ClientSpec-akka.actor.default-dispatcher-6] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from WaitingForNetworkToSendControlFrames to Idle
| [DEBUG] [10/24/2023 02:17:35.696] [Http2ClientSpec-akka.actor.default-dispatcher-6] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [DOWN] Element:    1 WIND  + 446471
| [DEBUG] [10/24/2023 02:17:35.709] [Http2ClientSpec-akka.actor.default-dispatcher-6] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [network-plain-text DOWN] Element:  ByteString(13 bytes)
|  00 00 04 08 00 00 00 00 00 00 97 96 87           | .............
| [DEBUG] [10/24/2023 02:17:35.719] [Http2ClientSpec-akka.actor.default-dispatcher-6] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from Idle to WaitingForData
| [DEBUG] [10/24/2023 02:17:35.719] [Http2ClientSpec-akka.actor.default-dispatcher-6] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [network-plain-text DOWN] Element:  ByteString(13 bytes)
|  00 00 04 08 00 00 00 00 01 00 06 D0 07           | .............
| [DEBUG] [10/24/2023 02:17:35.719] [Http2ClientSpec-akka.actor.default-dispatcher-6] [Http2ClientDemux(akka://Http2ClientSpec)] Incoming side of stream [1]: cancelling because downstream finished
| [DEBUG] [10/24/2023 02:17:35.719] [Http2ClientSpec-akka.actor.default-dispatcher-6] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from WaitingForData to Idle
| [DEBUG] [10/24/2023 02:17:35.719] [Http2ClientSpec-akka.actor.default-dispatcher-6] [akka.stream.Log(akka://Http2ClientSpec/system/Materializers/StreamSupervisor-0)] [DOWN] Element:    1 RSET  CANCEL
| [DEBUG] [10/24/2023 02:17:35.752] [pool-1-thread-1-ScalaTest-running-Http2ClientSpec] [WithLogCapturing(akka://Http2ClientSpec)] Logging finished for test [The Http/2 client implementation should support stream for response data should send RST_STREAM if entity stream is canceled]
<-- [The Http/2 client implementation should support stream for response data should send RST_STREAM if entity stream is canceled] End of log messages of test that [Failed(org.scalatest.exceptions.TestFailedException: WINDOW_UPDATE was not equal to RST_STREAM)]
[info]   - should send RST_STREAM if entity stream is canceled *** FAILED *** (156 milliseconds)
[info]     WINDOW_UPDATE was not equal to RST_STREAM (Http2FrameProbe.scala:208)
[info]     org.scalatest.exceptions.TestFailedException:
[info]     at org.scalatest.matchers.MatchersHelper$.indicateFailure(MatchersHelper.scala:392)
[info]     at org.scalatest.matchers.should.Matchers.shouldBe(Matchers.scala:6985)
[info]     at org.scalatest.matchers.should.Matchers.shouldBe$(Matchers.scala:1808)
[info]     at akka.http.impl.engine.http2.Http2FrameProbe$.shouldBe(Http2FrameProbe.scala:106)
[info]     at akka.http.impl.engine.http2.Http2FrameProbe$$anon$1.expectFrameFlagsStreamIdAndPayload(Http2FrameProbe.scala:208)
[info]     at akka.http.impl.engine.http2.Http2FrameProbe$$anon$1.expectFrameFlagsAndPayload(Http2FrameProbe.scala:202)
[info]     at akka.http.impl.engine.http2.Http2FrameProbe$$anon$1.expectFramePayload(Http2FrameProbe.scala:197)
[info]     at akka.http.impl.engine.http2.Http2FrameProbe$$anon$1.expectRST_STREAM(Http2FrameProbe.scala:165)
[info]     at akka.http.impl.engine.http2.Http2FrameProbe$$anon$1.expectRST_STREAM(Http2FrameProbe.scala:162)
[info]     at akka.http.impl.engine.http2.Http2FrameProbeDelegator.expectRST_STREAM(Http2FrameProbe.scala:87)
[info]     at akka.http.impl.engine.http2.Http2FrameProbeDelegator.expectRST_STREAM$(Http2FrameProbe.scala:74)
[info]     at akka.http.impl.engine.http2.Http2ClientSpec$NetworkSide.expectRST_STREAM(Http2ClientSpec.scala:1000)
[info]     at akka.http.impl.engine.http2.Http2ClientSpec$$anon$16.<init>(Http2ClientSpec.scala:362)
[info]     at akka.http.impl.engine.http2.Http2ClientSpec.$init$$$anonfun$1$$anonfun$2$$anonfun$6(Http2ClientSpec.scala:363)
johanandren commented 8 months ago

https://github.com/akka/akka-http/actions/runs/6680635128/job/18153939691

johanandren commented 8 months ago

https://github.com/akka/akka-http/actions/runs/6674148999/job/18140612146#step:7:1778