akka / akka-grpc

Akka gRPC
https://doc.akka.io/docs/akka-grpc/
Other
432 stars 123 forks source link

akka-grpc server scala with akka-grpc scala client tester should pass the custom_metadata integration test #219

Open raboof opened 6 years ago

raboof commented 6 years ago

https://travis-ci.org/akka/akka-grpc/jobs/386240856 Looks like the x-grpc-test-echo-trailing-bin trailing header was missing

johanandren commented 6 years ago

Was this fixed by #215 or did it happen just after that got merged?

raboof commented 6 years ago

It looks like just after, though I haven't seen it since

raboof commented 6 years ago

So far I've only seen it with the akka-grpc scala server and the akka-grpc scala or java client:

https://travis-ci.org/akka/akka-grpc/jobs/386589637
  akka-grpc server scala with akka-grpc scala client tester
https://travis-ci.org/akka/akka-grpc/jobs/386576573
  akka-grpc server scala with akka-grpc scala client tester
https://travis-ci.org/akka/akka-grpc/jobs/386589617
  akka-grpc server scala with akka-grpc scala client tester
https://travis-ci.org/akka/akka-grpc/jobs/386586816
  akka-grpc server scala with akka-grpc java client tester

That suggests we're doing something wrong in our server implementation, but let's keep an eye on this

johanandren commented 6 years ago

👁

raboof commented 6 years ago

Seems to fail fairly consistently (but not all the time) on travis, very rarely (but a couple of times) locally.

Added some debug logging (branch debugCustomMetadataServing), this confirms the headers are added on the server side but are not presented to use from Netty on the client side.

Configured the test to run without TLS (branch debugCustomMetadataServingWithoutTls, with a snapshot akka-http version). Haven't seen it fail yet, but wireshark does show there appears to be padding missing from the final HEADERS frame. Might be something to look into monday.

raboof commented 6 years ago

Looking at https://http2.github.io/http2-spec/#rfc.section.6.2 is seems not having padding is perfectly fine.

johanandren commented 6 years ago

https://travis-ci.org/akka/akka-grpc/jobs/394514604

patriknw commented 6 years ago

Seems to be failing rather frequently on travis.

Running test custom_metadata
[INFO] [06/21/2018 06:41:25.598] [pool-1-thread-1-ScalaTest-running-GrpcInteropSpec] [akka.actor.ActorSystemImpl(default)] Exception thrown, unbinding
org.scalatest.exceptions.TestFailedException
    at org.scalatest.Assertions.newAssertionFailedException(Assertions.scala:528)
    at org.scalatest.Assertions.newAssertionFailedException$(Assertions.scala:527)
    at org.scalatest.WordSpec.newAssertionFailedException(WordSpec.scala:1881)
    at org.scalatest.Assertions.fail(Assertions.scala:1121)
    at org.scalatest.Assertions.fail$(Assertions.scala:1117)
    at org.scalatest.WordSpec.fail(WordSpec.scala:1881)
    at com.lightbend.grpc.interop.GrpcInteropTests.withGrpcServer(GrpcInteropTests.scala:82)
    at com.lightbend.grpc.interop.GrpcInteropTests.$anonfun$grpcTests$4(GrpcInteropTests.scala:50)
    at com.lightbend.grpc.interop.GrpcInteropTests.pendingTestCaseSupport(GrpcInteropTests.scala:98)
    at com.lightbend.grpc.interop.GrpcInteropTests.$anonfun$grpcTests$3(GrpcInteropTests.scala:50)
    at org.scalatest.OutcomeOf.outcomeOf(OutcomeOf.scala:85)
    at org.scalatest.OutcomeOf.outcomeOf$(OutcomeOf.scala:83)
    at org.scalatest.OutcomeOf$.outcomeOf(OutcomeOf.scala:104)
    at org.scalatest.Transformer.apply(Transformer.scala:22)
    at org.scalatest.Transformer.apply(Transformer.scala:20)
    at org.scalatest.WordSpecLike$$anon$1.apply(WordSpecLike.scala:1078)
    at org.scalatest.TestSuite.withFixture(TestSuite.scala:196)
    at org.scalatest.TestSuite.withFixture$(TestSuite.scala:195)
    at org.scalatest.WordSpec.withFixture(WordSpec.scala:1881)
    at org.scalatest.WordSpecLike.invokeWithFixture$1(WordSpecLike.scala:1076)
    at org.scalatest.WordSpecLike.$anonfun$runTest$1(WordSpecLike.scala:1088)
    at org.scalatest.SuperEngine.runTestImpl(Engine.scala:289)
    at org.scalatest.WordSpecLike.runTest(WordSpecLike.scala:1088)
    at org.scalatest.WordSpecLike.runTest$(WordSpecLike.scala:1070)
    at org.scalatest.WordSpec.runTest(WordSpec.scala:1881)
    at org.scalatest.WordSpecLike.$anonfun$runTests$1(WordSpecLike.scala:1147)
    at org.scalatest.SuperEngine.$anonfun$runTestsInBranch$1(Engine.scala:396)
    at scala.collection.immutable.List.foreach(List.scala:389)
    at org.scalatest.SuperEngine.traverseSubNodes$1(Engine.scala:384)
    at org.scalatest.SuperEngine.runTestsInBranch(Engine.scala:373)
    at org.scalatest.SuperEngine.$anonfun$runTestsInBranch$1(Engine.scala:410)
    at scala.collection.immutable.List.foreach(List.scala:389)
    at org.scalatest.SuperEngine.traverseSubNodes$1(Engine.scala:384)
    at org.scalatest.SuperEngine.runTestsInBranch(Engine.scala:379)
    at org.scalatest.SuperEngine.runTestsImpl(Engine.scala:461)
    at org.scalatest.WordSpecLike.runTests(WordSpecLike.scala:1147)
    at org.scalatest.WordSpecLike.runTests$(WordSpecLike.scala:1146)
    at org.scalatest.WordSpec.runTests(WordSpec.scala:1881)
    at org.scalatest.Suite.run(Suite.scala:1147)
    at org.scalatest.Suite.run$(Suite.scala:1129)
    at org.scalatest.WordSpec.org$scalatest$WordSpecLike$$super$run(WordSpec.scala:1881)
    at org.scalatest.WordSpecLike.$anonfun$run$1(WordSpecLike.scala:1192)
    at org.scalatest.SuperEngine.runImpl(Engine.scala:521)
    at org.scalatest.WordSpecLike.run(WordSpecLike.scala:1192)
    at org.scalatest.WordSpecLike.run$(WordSpecLike.scala:1190)
    at org.scalatest.WordSpec.run(WordSpec.scala:1881)
    at org.scalatest.tools.Framework.org$scalatest$tools$Framework$$runSuite(Framework.scala:314)
    at org.scalatest.tools.Framework$ScalaTestTask.execute(Framework.scala:507)
    at sbt.ForkMain$Run$2.call(ForkMain.java:301)
    at sbt.ForkMain$Run$2.call(ForkMain.java:291)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.AssertionError: Trailer should contain binary header [Metadata()] expected:<Optional[ByteString(-85)]> but was:<Optional.empty>
    at org.junit.Assert.fail(Assert.java:88)
    at org.junit.Assert.failNotEquals(Assert.java:834)
    at org.junit.Assert.assertEquals(Assert.java:118)
    at io.grpc.testing.integration.AkkaGrpcJavaClientTester.customMetadata(AkkaGrpcJavaClientTester.java:302)
    at io.grpc.testing.integration2.TestServiceClient.runTest(TestServiceClient.java:181)
    at io.grpc.testing.integration2.TestServiceClient.run(TestServiceClient.java:93)
    at com.lightbend.grpc.interop.AkkaGrpcClientJava.run(AkkaGrpcClientJava.java:40)
    at com.lightbend.grpc.interop.GrpcInteropTests.runGrpcClient(GrpcInteropTests.scala:92)
    at com.lightbend.grpc.interop.GrpcInteropTests.$anonfun$grpcTests$5(GrpcInteropTests.scala:51)
    at com.lightbend.grpc.interop.GrpcInteropTests.withGrpcServer(GrpcInteropTests.scala:63)
    ... 47 more
[info] - should pass the custom_metadata integration test *** FAILED ***
[info]   org.scalatest.exceptions.TestFailedException was thrown. (GrpcInteropTests.scala:82)
raboof commented 6 years ago

Yes, very frequently. When I looked into it it only happened quite rarely locally, and I haven't been able to pin down why yet..

raboof commented 6 years ago

Finally saw it once with TLS disabled and wireshark running: looks like the client is tearing down the connection (RST_STREAM, GOAWAY frames, then FIN TCP flag) before the server has sent the trailing HEADERS frame: selection_335