Grpc.Core.Internal.AsyncCall<>.UnaryCall hangs (malformed call status?)

[zhenomansh]

Ver 1.45 (1.46 code is the same)
The symptom is hanging in Grpc.Core.Internal.AsyncCall<>.UnaryCall on return unaryResponseTcs.Task.GetAwaiter().GetResult(); line.

The stack trace example is:

[Waiting on Async Operation, double-click or press enter to view Async Call Stacks]
Grpc.Core.dll!Grpc.Core.Internal.AsyncCall<GenericRequest, GenericResponse>.UnaryCall(GenericRequest msg) Line 116 C#
Grpc.Core.dll!Grpc.Core.Calls.BlockingUnaryCall<GenericRequest, GenericResponse>(Grpc.Core.CallInvocationDetails<GenericRequest, GenericResponse> call, GenericRequest req) Line 25 C#
Grpc.Core.dll!Grpc.Core.DefaultCallInvoker.BlockingUnaryCall<GenericRequest, GenericResponse>(Grpc.Core.Method<GenericRequest, GenericResponse> method, string host, Grpc.Core.CallOptions options, GenericRequest request) Line 16 C#
Grpc.Core.Api.dll!Grpc.Core.Interceptors.InterceptingCallInvoker.BlockingUnaryCall.AnonymousMethod__3_0<GenericRequest, MGenericResponse>(GenericRequest req, Grpc.Core.Interceptors.ClientInterceptorContext<GenericRequest, GenericResponse> ctx) Line 51 C#
Grpc.Core.Api.dll!Grpc.Core.ClientBase.ClientBaseConfiguration.ClientBaseConfigurationInterceptor.BlockingUnaryCall<GenericRequest, GenericResponse>(GenericRequest request, Grpc.Core.Interceptors.ClientInterceptorContext<GenericRequest, GenericResponse> context, Grpc.Core.Interceptors.Interceptor.BlockingUnaryCallContinuation<GenericRequest, GenericResponse> continuation) Line 174 C#
Grpc.Core.Api.dll!Grpc.Core.Interceptors.InterceptingCallInvoker.BlockingUnaryCall<GenericRequest, GenericResponse>(Grpc.Core.Method<GenericRequest, GenericResponse> method, string host, Grpc.Core.CallOptions options, GenericRequest request) Line 48 C#

It is happening periodically, the problem how I think is in the next code in of the UnaryCall method:

try
{
  using (profiler.NewScope("AsyncCall.UnaryCall.HandleBatch"))
  {
    HandleUnaryResponse(success, ctx.GetReceivedStatusOnClient(), ctx.GetReceivedMessageReader(), ctx.GetReceivedInitialMetadata());
  }
}
catch (Exception e)
{
  Logger.Error(e, "Exception occurred while invoking completion delegate.");

  **!!! here should be "throw;" !!!**
}

Without that line, in case of HandleUnaryResponse error, unaryResponseTcs will never get neither error, nor value and will wait infinitely.

Also, a test could be added to ensure, the unaryResponseTcs state is not WaitingForActivationcan prior to call GetResult().

[zhenomansh]

@jtattermusch, @hassox, @beccasaurus, @timburks, could you please fix the issue asap? :)
It is critical in terms of nature of the bug - it hangs threads.
I already tested the fix on production, and it behaves as expected.

[zhenomansh]

The causing the exception message:

System.ArgumentException: The output char buffer is too small to contain the decoded characters, encoding 'Unicode (UTF-8)' fallback 'System.Text.DecoderReplacementFallback'.
Parameter name: chars
   at System.Text.Encoding.ThrowCharsOverflow()
   at System.Text.Encoding.ThrowCharsOverflow(DecoderNLS decoder, Boolean nothingDecoded)
   at System.Text.UTF8Encoding.GetChars(Byte* bytes, Int32 byteCount, Char* chars, Int32 charCount, DecoderNLS baseDecoder)
   at System.Text.UTF8Encoding.GetChars(Byte* bytes, Int32 byteCount, Char* chars, Int32 charCount)
   at Grpc.Core.Api.Utils.EncodingExtensions.GetString(Encoding encoding, Byte* source, Int32 byteCount)
   at Grpc.Core.Api.Utils.EncodingExtensions.GetString(Encoding encoding, IntPtr ptr, Int32 len)
   at Grpc.Core.Internal.BatchContextSafeHandle.**GetReceivedStatusOnClient**()
   at Grpc.Core.Internal.AsyncCall'2.UnaryCall(TRequest msg)
   at Grpc.Core.Calls.BlockingUnaryCall[TRequest,TResponse](CallInvocationDetails'2 call, TRequest req)
   at Grpc.Core.DefaultCallInvoker.BlockingUnaryCall[TRequest,TResponse](Method'2 method, String host, CallOptions options, TRequest request)
   at Grpc.Core.Interceptors.InterceptingCallInvoker.<BlockingUnaryCall>b__3_0[TRequest,TResponse](TRequest req, ClientInterceptorContext'2 ctx)
   at Grpc.Core.ClientBase.ClientBaseConfiguration.ClientBaseConfigurationInterceptor.BlockingUnaryCall[TRequest,TResponse](TRequest request, ClientInterceptorContext'2 context, BlockingUnaryCallContinuation'2 continuation)
   at Grpc.Core.Interceptors.InterceptingCallInvoker.BlockingUnaryCall[TRequest,TResponse](Method'2 method, String host, CallOptions options, TRequest request)

[jtattermusch]

FTR Looks like this is the code location the user is referring to:

grpc/src/csharp/Grpc.Core/Internal/AsyncCall.cs

Line 124 in 53d69cc

Logger.Error(e, "Exception occurred while invoking completion delegate.");

[jtattermusch]

The causing the exception message:

System.ArgumentException: The output char buffer is too small to contain the decoded characters, encoding 'Unicode (UTF-8)' fallback 'System.Text.DecoderReplacementFallback'.
Parameter name: chars
   at System.Text.Encoding.ThrowCharsOverflow()
   at System.Text.Encoding.ThrowCharsOverflow(DecoderNLS decoder, Boolean nothingDecoded)
   at System.Text.UTF8Encoding.GetChars(Byte* bytes, Int32 byteCount, Char* chars, Int32 charCount, DecoderNLS baseDecoder)
   at System.Text.UTF8Encoding.GetChars(Byte* bytes, Int32 byteCount, Char* chars, Int32 charCount)
   at Grpc.Core.Api.Utils.EncodingExtensions.GetString(Encoding encoding, Byte* source, Int32 byteCount)
   at Grpc.Core.Api.Utils.EncodingExtensions.GetString(Encoding encoding, IntPtr ptr, Int32 len)
   at Grpc.Core.Internal.BatchContextSafeHandle.**GetReceivedStatusOnClient**()
   at Grpc.Core.Internal.AsyncCall'2.UnaryCall(TRequest msg)
   at Grpc.Core.Calls.BlockingUnaryCall[TRequest,TResponse](CallInvocationDetails'2 call, TRequest req)
   at Grpc.Core.DefaultCallInvoker.BlockingUnaryCall[TRequest,TResponse](Method'2 method, String host, CallOptions options, TRequest request)
   at Grpc.Core.Interceptors.InterceptingCallInvoker.<BlockingUnaryCall>b__3_0[TRequest,TResponse](TRequest req, ClientInterceptorContext'2 ctx)
   at Grpc.Core.ClientBase.ClientBaseConfiguration.ClientBaseConfigurationInterceptor.BlockingUnaryCall[TRequest,TResponse](TRequest request, ClientInterceptorContext'2 context, BlockingUnaryCallContinuation'2 continuation)
   at Grpc.Core.Interceptors.InterceptingCallInvoker.BlockingUnaryCall[TRequest,TResponse](Method'2 method, String host, CallOptions options, TRequest request)

Ok, that's quite odd. Can you share the code that reproduces the above problem?

It looks like decoding the call's status (likely the "details" field) is failing - what is the contents of the call's status?

grpc/src/csharp/Grpc.Core/Internal/BatchContextSafeHandle.cs

Line 90 in 53d69cc

public ClientSideStatus GetReceivedStatusOnClient()

AFAIK this is a situation that should never happen (receiving malformed details message)

[zhenomansh]

@jtattermusch, I see the issue on production with bad Wi-Fi network access few times per a day, i.e. I cannot reproduce it via a test program.
However, as I wrote, because of this catch (Exception e) without throw (or unaryResponseTcs.SetException) inside, the code hangs forever.
We patch the code locally by adding throw, it stopped hanging and we were able to see this stacktrace, which I added previously.
So the exception is happening in the GetReceivedStatusOnClient method, not sure why, but I think a broken connection is the reason.

Also, imho, as an additional protection from possible similar issues, this unaryResponseTcs TaskCompletionSource status could be checked prior to GetResult(), for a case of future possible changes, preventing setting a result/exception to the unaryResponseTcs.

Anyway, adding throw and releasing a new fix version - all we desire now :)

[tonydnewell]

I've created a Pull Request to handle the exception in AsyncCall.UnaryCall().
PR #30429

Rather than just throwing the exception I have created an RcpException and set the exception in unaryResponseTcs.

I was unable to reproduce the original corrupt status code. Looking at the marshalling code it is unclear
how the UTF-8 decoding would fail.

There is no obvious way to create a unit test with a mock failure and the failure happens at quite a low level. I was able to test locally by temporarily modifying AsyncCall.UnaryCall() and explicitly throwing an exception and checking the behaviour of both the fixed and non-fixed code.

[jtattermusch]

I commented on the proposed fix and I think we need to understand more why exactly does the status from ctx.GetReceivedStatusOnClient() seem to be malformed.

@zhenomansh can you dump the contents of the "detailsLength" bytes starting at "detailsPtr" in the invocation of

grpc/src/csharp/Grpc.Core/Internal/BatchContextSafeHandle.cs

Line 90 in c34b22e

public ClientSideStatus GetReceivedStatusOnClient()

when the exception System.ArgumentException: The output char buffer is too small to contain the decoded characters, encoding 'Unicode (UTF-8)' fallback 'System.Text.DecoderReplacementFallback'. happens?
Also, what is the "status"?
We need to understand why the status delivered by the internal logic seems corrupt (it should not be) in order to come up with the right fix.

[tonydnewell]

There are two issues to address:

• why does the decoding of the status fail?
• how to handle a low level error and report the error rather than causing the call to hang

I've tried to address the second issue, albeit without the clean up. I could add some resource clean up in a finally block.

For the first issue (why does the decoding fail?) - code inspection looks like it shouldn't happen - in EncodingExtensions.GetString the size of the required buffer is obtained with Encoding.GetCharCount() before calling Encoding.GetChars() so there shouldn't be an exception with The output char buffer is too small to contain the decoded characters.

public static unsafe string GetString(this Encoding encoding, byte* source, int byteCount)
{
	if (byteCount == 0) return ""; // most callers will have already checked, but: make sure

	// allocate a right-sized string and decode into it
	int charCount = encoding.GetCharCount(source, byteCount);
	string s = new string('\0', charCount);
	fixed (char* cPtr = s)
	{
		encoding.GetChars(source, byteCount, cPtr, charCount);
	}
	return s;
}

The fallback System.Text.DecoderReplacementFallback() is being called meaning the bytes aren't valid UTF-8 - so unless the replacement string has been defined elsewhere in the application that should just mean that a single char '?' is being substituted.

Since we are dealing with unmanaged code in an error situation it is always possible that something elsewhere in the application is overwriting memory while we are trying to decode it.