search

akka / akka-http

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

Failed: Http2ClientSpec.The Http/2 client implementation should support for configurable ping #3706

Open johanandren opened 3 years ago

johanandren commented 3 years ago

https://jenkins.akka.io:8498/job/akka-http-nightly/AKKA_VERSION=release-2.5,Node=akka-http-nightly-node,SCALA_VERSION=2.12.12,jdk=AdoptOpenJDK%208/lastCompletedBuild/testReport/akka.http.impl.engine.http2/Http2ClientSpec/The_Http_2_client_implementation_should_support_for_configurable_ping_should_send_pings_when_there_is_an_active_but_slow_stream_from_client/

assertion failed: received unexpected message RealMessage(OnNext(ByteString(0, 0, 8, 6, 0, 0, 0, 0, 0, 97, 98, 99, 100, 101, 102, 103, 104)),Actor[akka://Http2ClientSpec/deadLetters]) after 0 millis
    at akka.testkit.TestKitBase.expectNoMsg_internal(TestKit.scala:721)
    at akka.testkit.TestKitBase.expectNoMessage(TestKit.scala:688)
    at akka.testkit.TestKitBase.expectNoMessage$(TestKit.scala:687)
    at akka.testkit.TestKit.expectNoMessage(TestKit.scala:923)
    at akka.stream.testkit.TestSubscriber$ManualProbe.expectNoMessage(StreamTestKit.scala:623)
    at akka.http.impl.engine.ws.ByteStringSinkProbe$$anon$1.expectNoBytes(ByteStringSinkProbe.scala:61)
    at akka.http.impl.engine.http2.Http2FrameProbe$$anon$1.expectNoBytes(Http2FrameProbe.scala:118)
    at akka.http.impl.engine.http2.Http2FrameProbeDelegator.expectNoBytes(Http2FrameProbe.scala:82)
    at akka.http.impl.engine.http2.Http2FrameProbeDelegator.expectNoBytes$(Http2FrameProbe.scala:82)
    at akka.http.impl.engine.http2.Http2ClientSpec$NetworkSide.expectNoBytes(Http2ClientSpec.scala:836)
    at akka.http.impl.engine.http2.Http2ClientSpec$$anon$36.<init>(Http2ClientSpec.scala:716)
    at akka.http.impl.engine.http2.Http2ClientSpec.$anonfun$new$55(Http2ClientSpec.scala:706)
    at akka.http.impl.engine.http2.Http2ClientSpec$InWithStoppedStages.$anonfun$inAssertAllStagesStopped$2(Http2ClientSpec.scala:761)
    at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)
    at akka.stream.testkit.scaladsl.StreamTestKit$.assertAllStagesStopped(StreamTestKit.scala:32)
    at akka.http.impl.engine.http2.Http2ClientSpec$InWithStoppedStages.$anonfun$inAssertAllStagesStopped$1(Http2ClientSpec.scala:760)
jrudolph commented 3 years ago

Here it seems to send two pings in quick succession, the first one 1100ms after the last packet and the second one right after. So maybe the first one was late, but should that mean we send the next one immediately?

| [DEBUG] [12/16/2020 04:36:15.249] [Http2ClientSpec-akka.actor.default-dispatcher-3] [akka.stream.Log(akka://Http2ClientSpec/system/StreamSupervisor-0)] [DOWN] Element:    1 HEAD  :method -> GET, :scheme -> , :authority -> , :path -> /, content-type -> application/octet-stream, user-agent -> akka-http/10.2.2+11-801dc222
| [DEBUG] [12/16/2020 04:36:15.249] [Http2ClientSpec-akka.actor.default-dispatcher-3] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from Idle to WaitingForData
| [DEBUG] [12/16/2020 04:36:15.250] [Http2ClientSpec-akka.actor.default-dispatcher-3] [akka.stream.Log(akka://Http2ClientSpec/system/StreamSupervisor-0)] [network-plain-text DOWN] Element:  ByteString(54 bytes)
|    00 00 2D 01 04 00 00 00 01 82 46 00 81 84 5F 90  | ..-.......F..._.
|    1D 75 D0 62 0D 26 3D 4C 1C 89 2A 56 42 6C 28 E9  | .u.b.&=L..*VBl(.
|    7A 94 1F 5E A3 5A 74 A6 B6 02 05 C4 B8 BF D8 42  | z..^.Zt........B
|    B3 C0 0C 84 10 85                                | ......
| [DEBUG] [12/16/2020 04:36:16.352] [Http2ClientSpec-akka.actor.default-dispatcher-4] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from WaitingForData to Idle
| [DEBUG] [12/16/2020 04:36:16.352] [Http2ClientSpec-akka.actor.default-dispatcher-4] [akka.stream.Log(akka://Http2ClientSpec/system/StreamSupervisor-0)] [DOWN] Element:    0 PING  61 62 63 64 65 66 67 68
| [DEBUG] [12/16/2020 04:36:16.353] [Http2ClientSpec-akka.actor.default-dispatcher-4] [akka.stream.Log(akka://Http2ClientSpec/system/StreamSupervisor-0)] [network-plain-text DOWN] Element:  ByteString(17 bytes)
|    00 00 08 06 00 00 00 00 00 61 62 63 64 65 66 67  | .........abcdefg
|    68                                               | h
| [DEBUG] [12/16/2020 04:36:16.355] [Http2ClientSpec-akka.actor.default-dispatcher-4] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from Idle to WaitingForData
| [DEBUG] [12/16/2020 04:36:16.356] [Http2ClientSpec-akka.actor.default-dispatcher-4] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from WaitingForData to Idle
| [DEBUG] [12/16/2020 04:36:16.356] [Http2ClientSpec-akka.actor.default-dispatcher-4] [akka.stream.Log(akka://Http2ClientSpec/system/StreamSupervisor-0)] [DOWN] Element:    0 PING  61 62 63 64 65 66 67 68
| [DEBUG] [12/16/2020 04:36:16.356] [Http2ClientSpec-akka.actor.default-dispatcher-4] [Http2ClientDemux(akka://Http2ClientSpec)] Changing state from Idle to WaitingForData
| [DEBUG] [12/16/2020 04:36:16.356] [Http2ClientSpec-akka.actor.default-dispatcher-4] [akka.stream.Log(akka://Http2ClientSpec/system/StreamSupervisor-0)] [network-plain-text DOWN] Element:  ByteString(17 bytes)
|    00 00 08 06 00 00 00 00 00 61 62 63 64 65 66 67  | .........abcdefg
|    68                                               | h
| [DEBUG] [12/16/2020 04:36:16.360] [pool-1-thread-1-ScalaTest-running-Http2ClientSpec] [WithLogCapturing(akka://Http2ClientSpec)] Logging finished for test [The Http/2 client implementation should support for configurable ping should send pings when there is an active but slow stream from client]