grpc / grpc-dotnet

gRPC for .NET
Apache License 2.0
4.2k stars 771 forks source link

Bad gRPC response. Response protocol downgraded to HTTP/1.1 with Http2UnencryptedSupport=true #1439

Closed dave-yotta closed 3 years ago

dave-yotta commented 3 years ago

What version of gRPC and what language are you using?

c# .net core 3.1

Client (MagicOnion.Client 4.1.2)

Server (MagicOnion.Server 4.1.2)

What operating system (Linux, Windows,...) and version?

mcr.microsoft.com/dotnet/aspnet:3.1-buster-slim

What runtime / compiler are you using (e.g. .NET Core SDK version dotnet --info)

mcr.microsoft.com/dotnet/sdk:3.1

What did you do?

App running in development env after nightly getting some of these errors - not observed during (fairly extensive) testing. Have added in both client and server:

AppContext.SetSwitch("System.Net.Http.SocketsHttpHandler.Http2UnencryptedSupport", true);
AppContext.SetSwitch("System.Net.Http.SocketsHttpHandler.Http2Support", true);

And additionally on the server told kestrel:

.UseKestrel(x => x.Listen(IPAddress.Loopback, 0, o => o.Protocols = HttpProtocols.Http2))

What did you expect to see?

No Errors :)

What did you see instead?

Grpc.Core.RpcException: Status(StatusCode="Internal", Detail="Bad gRPC response. Response protocol downgraded to HTTP/1.1.")
  Module "System.Runtime.ExceptionServices.ExceptionDispatchInfo", in Throw
  Module "System.Runtime.CompilerServices.TaskAwaiter", in HandleNonSuccessAndDebuggerNotification
  Module "System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1+ConfiguredTaskAwaiter", in GetResult
  Module "MagicOnion.Client.ResponseContext`1", in Deserialize
  Module "System.Runtime.ExceptionServices.ExceptionDispatchInfo", in Throw
  Module "System.Runtime.CompilerServices.TaskAwaiter", in HandleNonSuccessAndDebuggerNotification
  Module "System.Runtime.CompilerServices.TaskAwaiter`1", in GetResult
  Module "MagicOnion.Client.ResponseContext`1", in WaitResponseAsync

(raised on client)

Anything else we should know about your project / environment?

I have a feeling this might be happening when the server is terminated with sigkill by oomkiller or just a straight OOMException that doesn't allow completion of the request - having a dig through observability stuff now to see. Not sure if there's much that can be done in that case but I thought I might as well ask!

Update: That doesn't appear to be the case, at least not OOM. We're running on AWS EB, which is different to our test environemts (EKS) - and have seen it doing some weird things with ulimits and such. Is there anything on the OS/Docker Host level that could prevent Http2 from working? The RPC is IPC between processes running on the same container.

Update 2: Doesn't seem to be environment specific either. It's working with one client (a console app) but raising this error with a different client (a kestrel webapi app).

Update 3: Not sure if related, but debugging on windows I actually am getting:

Status(StatusCode="Internal", Detail="Error starting gRPC call. HttpRequestException: An error occurred while sending the request. WinHttpException: Error 12152 calling WINHTTP_CALLBACK_STATUS_REQUEST_ERROR, 'The server returned an invalid or unrecognized response'.", DebugException="System.Net.Http.HttpRequestException: An error occurred while sending the request.
 ---> System.Net.Http.WinHttpException (80072F78, 12152): Error 12152 calling WINHTTP_CALLBACK_STATUS_REQUEST_ERROR, 'The server returned an invalid or unrecognized response'.
   at System.Threading.Tasks.RendezvousAwaitable`1.GetResult()
   at System.Net.Http.WinHttpHandler.StartRequestAsync(WinHttpRequestState state)
   --- End of inner exception stack trace ---
   at System.Net.Http.DiagnosticsHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
   at Grpc.Net.Client.Internal.GrpcCall`2.RunCall(HttpRequestMessage request, Nullable`1 timeout)")

I'm getting this on the client, this is probabbly the cause of both issues, the server doesn't like the request preface and is closing the connection? Still digging....

Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2.Http2ConnectionErrorException
  HResult=0x80131500
  Message=HTTP/2 connection error (PROTOCOL_ERROR): Invalid HTTP/2 connection preface.
  Source=Microsoft.AspNetCore.Server.Kestrel.Core
  StackTrace:
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http2.Http2Connection.ParsePreface(ReadOnlySequence`1& buffer, SequencePosition& consumed, SequencePosition& examined)

Possibly important: the server is a process started with Process.Start from the client

Update 4: It seems that the HttpClient used here is not compatible with http2 when the Grpc client makes calls from within the ASP,NET Core 3.1 WebApi project - server is saying "Invalid Http/2 connection preface". When doing the same thing from a .NET Core 3.1 Console project - communication takes place without issue.

There are different environment vars being inherited each time - the ASP project starts the server via Proces.Start with the extra vars: "ASPNETCORE_ENVIRONMENT, ASPNETCORE_HTTPS_PORT, ASPNETCORE_URLS, COMPLUS_NoGuiFromShim". However unsettling those in the process start info makes no difference.

I've sett the HttpMessageHandler to set request.Version = "2.0" on all requesets when creating the GrpcChannelOptions Setting HttpHandler. This isn't forcing the communication to 2.0 either.

Update 5: Looks like someone had set AppContext.SetSwitch("System.Net.Http.UseSocketsHttpHandler", false); in the client application which is getting this error

I'll try to remove it, but this was turned on to be compatible with some 3rd party API which had some compatibility issues. Does the fallback http handler not support http 2.0 or something?

captainsafia commented 3 years ago

Does the fallback http handler not support http 2.0 or something?

Yes, it doesn't support unencrypted HTTP/2.

I'll try to remove it, but this was turned on to be compatible with some 3rd party API which had some compatibility issues.

The AppContext.SetSwitch will disable the SocketsHttpHandler globally. Do you know why the 3rd party library requires this global modification? It might help to see if an update of the library would resolve the issue or understand what the underlying compat issue is.

dave-yotta commented 3 years ago

Ok thanks, the 3rd party is the mongodb atlas webapi, there's a .NET runtime ticket to fix up the digest authentication here: https://github.com/dotnet/runtime/issues/50283. I've instead grabbed some manual digest auth code from SO (it's not pretty) for until we get to .NET5/6.

It's not a GRPC bug, and not sure there's a lot you can do here other than improving the message if that's even possible.

JamesNK commented 3 years ago

I don't know of any way to improve the error message thrown by gRPC. It is reporting what HttpClient says.