Runtime: HTTP2: The HTTP/2 server sent invalid data on the connection.

[JamesNK]

After updating to 3.0.100-preview8-013532 I got this never seen before error from the gRPC interop tests:

Use TLS: True
Use Test CA: True
Client type: httpclient
Server host: localhost
Server port: 32769
running large_unary
[40m[37mdbug[39m[22m[49m: Grpc.Net.Client.Internal.GrpcCall[1]
      => GrpcMethodType:Unary GrpcUri:/grpc.testing.TestService/UnaryCall
      Starting gRPC call. Method type: 'Unary', URI: '/grpc.testing.TestService/UnaryCall'.
[41m[30mfail[39m[22m[49m: Grpc.Net.Client.Internal.GrpcCall[6]
      => GrpcMethodType:Unary GrpcUri:/grpc.testing.TestService/UnaryCall
      Error starting gRPC call.
System.Net.Http.HttpRequestException: An error occurred while sending the request.
 ---> System.Net.Http.Http2ConnectionException: The HTTP/2 server sent invalid data on the connection. HTTP/2 error code 'PROTOCOL_ERROR' (0x1).
   at System.Net.Http.Http2Connection.ProcessIncomingFramesAsync()
   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.SendHeadersAsync(HttpRequestMessage request, CancellationToken cancellationToken, Boolean mustFlush)
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
   at System.Net.Http.DiagnosticsHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.FinishSendAsyncUnbuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts)
   at Grpc.Net.Client.Internal.GrpcCall`2.SendAsync(HttpClient client, HttpRequestMessage request) in /var/local/git/grpc-dotnet/src/Grpc.Net.Client/Internal/GrpcCall.cs:line 549
Unhandled exception. System.AggregateException: One or more errors occurred. (An error occurred while sending the request.)
 ---> System.Net.Http.HttpRequestException: An error occurred while sending the request.
 ---> System.Net.Http.Http2ConnectionException: The HTTP/2 server sent invalid data on the connection. HTTP/2 error code 'PROTOCOL_ERROR' (0x1).
   at System.Net.Http.Http2Connection.ProcessIncomingFramesAsync()
   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.SendHeadersAsync(HttpRequestMessage request, CancellationToken cancellationToken, Boolean mustFlush)
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
   at System.Net.Http.DiagnosticsHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.FinishSendAsyncUnbuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts)
   at Grpc.Net.Client.Internal.GrpcCall`2.SendAsync(HttpClient client, HttpRequestMessage request) in /var/local/git/grpc-dotnet/src/Grpc.Net.Client/Internal/GrpcCall.cs:line 549
   at Grpc.Net.Client.HttpClientCallInvoker.BlockingUnaryCall[TRequest,TResponse](Method`2 method, String host, CallOptions options, TRequest request) in /var/local/git/grpc-dotnet/src/Grpc.Net.Client/HttpClientCallInvoker.cs:line 145
   at Grpc.Testing.TestService.TestServiceClient.UnaryCall(SimpleRequest request, CallOptions options) in /var/local/git/grpc-dotnet/testassets/InteropTestsClient/obj/Debug/netcoreapp3.0/TestGrpc.cs:line 184
   at Grpc.Testing.TestService.TestServiceClient.UnaryCall(SimpleRequest request, Metadata headers, Nullable`1 deadline, CancellationToken cancellationToken) in /var/local/git/grpc-dotnet/testassets/InteropTestsClient/obj/Debug/netcoreapp3.0/TestGrpc.cs:line 174
   at InteropTestsClient.InteropClient.RunLargeUnary(TestServiceClient client) in /var/local/git/grpc-dotnet/testassets/InteropTestsClient/InteropClient.cs:line 309
   at InteropTestsClient.InteropClient.RunTestCaseAsync(IChannel channel, ClientOptions options) in /var/local/git/grpc-dotnet/testassets/InteropTestsClient/InteropClient.cs:line 232
   at InteropTestsClient.InteropClient.Run() in /var/local/git/grpc-dotnet/testassets/InteropTestsClient/InteropClient.cs:line 129
   --- End of inner exception stack trace ---
   at System.Threading.Tasks.Task.Wait(Int32 millisecondsTimeout, CancellationToken cancellationToken)
   at System.Threading.Tasks.Task.Wait()
   at InteropTestsClient.InteropClient.<>c.<Run>b__5_1(ClientOptions options) in /var/local/git/grpc-dotnet/testassets/InteropTestsClient/InteropClient.cs:line 122
   at CommandLine.ParserResultExtensions.WithParsed[T](ParserResult`1 result, Action`1 action)
   at InteropTestsClient.InteropClient.Run(String[] args) in /var/local/git/grpc-dotnet/testassets/InteropTestsClient/InteropClient.cs:line 111
   at InteropTestsClient.Program.Main(String[] args) in /var/local/git/grpc-dotnet/testassets/InteropTestsClient/Program.cs:line 25

https://source.cloud.google.com/results/invocations/8300cd83-23bd-448f-bf2e-38a27ce64aac/targets/github%2Fgrpc%2Finterop_test/tests

The test is sending a large request (5 + 271828 bytes) and receiving a large response (5 + 314159 bytes). However from the logs it looks like the error is thrown from HttpClient.SendAsync before any request data is sent.

Creating issue here because I know HttpClient HTTP/2 just underwent a large refactor. Kestrel also had some response logic changes in since the last SDK update - https://github.com/aspnet/AspNetCore/pull/12328 - so its not certain that this is a HttpClient issue.

@geoffkizer @Tratcher

[karelz]

@wfurt can you please take a look?

[geoffkizer]

@JamesNK Code to repro?

[JamesNK]

I haven't been able to reproduce it.

[wfurt]

Is there chance this was fixed by the weekend changes?

[JamesNK]

I reran the same test on the same SDK half a dozen times and couldn't reproduce it.

Is there configuration I can add to get HttpClient to write its internal logs to the console? If I enable logging then you'll have more to go on if it happens again on the CI server.

[geoffkizer]

There's no simple configuration switch to write log events to console. But you can add an EventListener to your app that will do it. Warning: there's a lot of log output.

You can see the code in our HttpStress app that does this. Look for the HttpEventListener class.

https://github.com/dotnet/corefx/blob/3ebfae3ed729af13e59c0525e7b794327bfd227f/src/System.Net.Http/tests/StressTests/HttpStress/StressServer.cs

[karelz]

@JamesNK does it repro on older builds? That will tell us if it is likely fixed now.

[karelz]

Ping @JamesNK? I'd like to confirm this is not 3.0 problem anymore. Please work with @wfurt on clarification.

[JamesNK]

I haven't seen this again. I don't have any repro steps, and no idea where the issue occurred.

I think either this can be closed - and reopened if it happens again - or moved to 5.0.

[karelz]

If we can't repro, there is IMO no point to keep it open for 5.0 as it is not actionable.
We can reopen if we see it again somewhere. Thanks @JamesNK !

[tmitchel2]

I just got his error when using the same preview version. I am testing out HTTP2 without https and im using AppContext.SetSwitch("System.Net.Http.SocketsHttpHandler.Http2UnencryptedSupport", true) switch.

[hyspdrt]

RE: HTTP2 without https and AppContext.SetSwitch

I found that, by applying the AppContext.SetSwitch before you make your remote call, yet after you've created the client, it then works.

It doesn't appear to persist when set, in say program Main.

[Tratcher]

Comments on closed issues are not tracked, please open a new issue with the details for your scenario.