Grpc-dotnet: Client-streaming RPC backpressure is broken on Kestrel

Created on 20 Jul 2019  路  14Comments  路  Source: grpc/grpc-dotnet

Related to #104. Demo code: https://github.com/Avilad/grpc-dotnet-flow-control-test.

When a client streams many small messages to a grpc-dotnet server, and the server consumes these messages slower than they are produced, WriteAsync() calls on the client are blocked as expected, but for each call the server makes to MoveNext(), WriteAsync() accepts more than one call before being blocked. This (presumably) causes a buildup of messages in Kestrel's buffers, eventually leading to a "Request body too large" exception.

When the Grpc.Core server is used instead, the backpressure works as expected, and allows on average one WriteAsync() call for each MoveNext() call.

All 14 comments

@Avilad do you have a call stack?

OK I took a quick look at a couple of things and there's a bunch of things to unpack:

When a client streams many small messages to a grpc-dotnet server, and the server consumes these messages slower than they are produced, WriteAsync() calls on the client are blocked as expected, but for each call the server makes to MoveNext(), WriteAsync() accepts more than one call before being blocked.

The number of calls doesn't need to be 1:1 and it cannot exceed the agreed upon window size, that's a protocol violation. Accepting multiple write per unblocked read isn't a problem unless the HTTP/2 protocol is being violated (and I'm not convinced it is).

This (presumably) causes a buildup of messages in Kestrel's buffers, eventually leading to a "Request body too large" exception.

No buffers are being built up. This message is happening because there's a default max body size that should be disabled for streaming requests (its just counting bytes) @JamesNK will fix that.

cc @halter73

At any rate, the behavior is pretty different between the gRPC core server and kestrel. And even though the number of calls doesn't need to be 1:1, in my demo code, it's almost exactly 10:1. The server reads one message from the stream every ~10ms, and the log from the client shows that it sends around 10 messages every 10ms (roughly 1/10 messages send in ~0.01s, and the remaining 9/10 send in ~0.0001s). Since the messages are of constant size, I can't see how this wouldn't result in messages building up in a buffer somewhere.

I tested streaming 1 GB to the server in 64 KB chunks. Removing the default max body size fixes that error, and 1 GB is successfully read. However the server is using a lot of memory. I haven't investigated exactly where it is building up.

At any rate, the behavior is pretty different between the gRPC core server and kestrel.

Keeping the same server behavior isn't a requirement.

Since the messages are of constant size, I can't see how this wouldn't result in messages building up in a buffer somewhere.

I never said data wasn't buffered, I said it wasn't the reason for the exception. Buffers are not being built up until that exception occurs.

At any rate, the behavior is pretty different between the gRPC core server and kestrel. And even though the number of calls doesn't need to be 1:1, in my demo code, it's almost exactly 10:1

What's the default window size in grpc.core?

However the server is using a lot of memory. I haven't investigated exactly where it is building up.

I think it was in my unit test. When I change the unit test to not buffer memory then server memory stays level.

@davidfowl, based on what I've read it seems like the default window size in grpc core is 64KB, and ASP.NET Core uses a 96KB window by default. However, this doesn鈥檛 explain why in my example the client is allowed to send almost 30MB of data roughly 10x faster than the client is reading it, while the grpc core server throttles the client as expected. As far as I can tell, Kestrel doesn鈥檛 perform automatic window size adjustment, so that can鈥檛 be why I鈥檓 seeing this behavior either. I鈥檒l try out @JamesNK鈥檚 changes and investigate what happens if I update my test to send more data.

Logs from a test that is using client streaming attached. It shows:

  1. A slow build up of messages on the server. When a message is processed by the server then the client might send two back
  2. The client eventually runs out of messages to send. The server then takes a while to read the built up messages.

I'm going to log this in aspnet/aspnetcore.

grpc-client-streaming.log

I've updated my demo code to quickly make the server allocate over 9GB, by setting Limits.MaxRequestBodySize = null in my own startup code. I ran the server in a memory profiler ~and the problem is definitely in Kestrel (the data is building up in the Http2Stream inside the RequestBodyPipe). So, since your PR fixes the request body size error, I think this issue is good to close. Thanks for your prompt response!~ Edit: I actually think the problem may be caused by grpc-dotnet using the PipeReader API wrong, so I'm reopening this for now

Per my comment on the Kestrel issue, I think unconditionally passing buffer.End as examined here and here is what's causing this issue.

I was just speaking to @JamesNK about this and I think you're right (great investigation BTW!). GRPC should only pass buffer.End if it can't parse a full message, otherwise it should be the same as consumed.

@Avilad seriously, great job at debugging/diagnosing this issue!

FIXED

Was this page helpful?
0 / 5 - 0 ratings

Related issues

nphmuller picture nphmuller  路  5Comments

JunTaoLuo picture JunTaoLuo  路  5Comments

RiccoYuan picture RiccoYuan  路  4Comments

JamesNK picture JamesNK  路  3Comments

heartacker picture heartacker  路  3Comments