grpc c++ performance - help required

[Sureshbabu Seshadri]

Environment

1. Both client and server are C++
2. Server might be running either locally or in different system
3. In case of remote server, it is in same network.
4. Using SYNC C++ server
5. Unary RPC

Our performance numbers are very low for running 1000 RPC calls (continuous calls through loop for testing) it takes about 10 seconds when server running in different PC.

The client creates channel using hostname:portnumber method and using this approach the local server were also taking similar 10 seconds for 1000 calls. Later we modified channel creation for local server by using localhost:port then it was much improved performance, all the 1000 calls completed within 300 ms.

Based on the above test, we strongly believe DNS resolution seems to cause slow performance as change hostname to localhost results in huge performance gain, however that is not possible for servers running on different PC.

Can someone help with this? Is DNS the real culprit or what else can be changed to get good performance throughput in this case.

Please let me know if there any other input required for this.

[Jeff Steger]

Sounds like network delays. try doing a traceroute to see the paths packets are taking from client to server and their associated delays. 

https://en.m.wikipedia.org/wiki/Traceroute

--
You received this message because you are subscribed to the Google Groups "grpc.io" group.
To unsubscribe from this group and stop receiving emails from it, send an email to grpc-io+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/grpc-io/02e772e3-5f78-4133-b7b2-5fd6cb1d2ab8n%40googlegroups.com.

[Christoph John]

What happens if you use the IP instead of the hostname?

Cheers
Chris

[Mark D. Roth]

You can check to see whether the problem is a channel startup problem or a latency problem by calling channel->WaitForConnected(gpr_inf_future(GPR_CLOCK_MONOTONIC)) before you start sending RPCs on the channel.  That call won't return until the channel has completed the DNS lookup and established a connection to the server, so if you start timing after that, your timing will exclude the channel startup time.

If you see that the channel startup time is high but the RPCs flow quickly once the startup time is passed, then the problem is either the DNS lookup or establishing a connection to the server.  In that case, please try running with the environment variables GRPC_VERBOSITY=DEBUG GRPC_TRACE=client_channel_routing,pick_first and share the log, so that we can help you figure out which one is the problem.

If you see that the channel startup time is not that high but that the RPCs are actually flowing more slowly over the network, then the problem might be network congestion of some sort.

Also, if the problem does turn out to be channel startup time, note that it probably won't matter much in practice, as long as your application creates the channel once and reuses it for all of its RPCs.  We do not recommend a pattern where you create a channel, send a bunch of RPCs, then destroy the channel, and then do that whole thing again later when you need to send more RPCs.

I hope this information is helpful.

[Sureshbabu Seshadri]

No luck with IP also, it is same timings, it was already tried missed to mention

[Sureshbabu Seshadri]

Thanks Mark, my current profile does not include channel creation time. Profiling is only applicable for RPC calls. We have an existing code base for IPC which uses CORBA architecture and we are trying to replace it with GRPC, similar sample in CORBA completes quickly that is 1000 RPCs are completed within 2 seconds in same network. Hence this is kind of roadblock for our migration.

I will execute test with traces enabled and share the logs ASAP

[Sureshbabu Seshadri]

Mark, 

Please find the grpc ttrace logs in the following link https://drive.google.com/file/d/15y7KzyCtIeAoYSUzyPHpY4gcr7uUnIP0/view?usp=sharing

I am not able to upload files directly here. Please note that the profiling is done for same API called in loop for 1000 times and let me know.

[Sureshbabu Seshadri]

Dear GRPC team,

Can any one help on this?

[Mark D. Roth]

I'm so sorry for not responding sooner!  For some reason, gmail tagged your messages as spam, so I didn't see them. :(

On Fri, Aug 27, 2021 at 10:55 PM Sureshbabu Seshadri <sureshb...@gmail.com> wrote:

Dear GRPC team,

Can any one help on this?

On Friday, August 13, 2021 at 12:53:21 PM UTC+5:30 Sureshbabu Seshadri wrote:

Mark, 

Please find the grpc ttrace logs in the following link https://drive.google.com/file/d/15y7KzyCtIeAoYSUzyPHpY4gcr7uUnIP0/view?usp=sharing

I am not able to upload files directly here. Please note that the profiling is done for same API called in loop for 1000 times and let me know.

On Thursday, August 12, 2021 at 11:27:16 AM UTC+5:30 Sureshbabu Seshadri wrote:

Thanks Mark, my current profile does not include channel creation time. Profiling is only applicable for RPC calls.

Note that when you first create a gRPC channel, it does not actually do any name resolution or connect to any servers until you either explicitly tell it to do so (such as by calling channel->WaitForConnected(gpr_inf_future(GPR_CLOCK_MONOTONIC))) or send the first RPC on it.  So if you don't proactively tell the channel to connect but start counting the elapsed time right before you send the first RPC, then you are actually including the channel connection time in your benchmark.

From the trace log above, though, it seems clear that the problem you're seeing here is not actually channel startup time.  The channel starts to connect on this line:

I0812 21:30:17.760000000  5748 resolving_lb_policy.cc:161] resolving_lb=000001EBA08F00D0: starting name resolution

And it finishes connecting here:

I0812 21:30:17.903000000 44244 client_channel.cc:1362] chand=000001EBA08F35B0: update: state=READY picker=000001EBA0900B70

So it took the channel only 0.143 seconds to get connected, which means that's probably not the problem you're seeing here.

Once it did get connected, it looks like it took about 8 seconds to process 1000 RPCs, which does seem quite slow.

Can you share the code you're using for the client and server?

 

We have an existing code base for IPC which uses CORBA architecture and we are trying to replace it with GRPC, similar sample in CORBA completes quickly that is 1000 RPCs are completed within 2 seconds in same network. Hence this is kind of roadblock for our migration.

I will execute test with traces enabled and share the logs ASAP

On Wednesday, August 11, 2021 at 10:38:48 PM UTC+5:30 Mark D. Roth wrote:

You can check to see whether the problem is a channel startup problem or a latency problem by calling channel->WaitForConnected(gpr_inf_future(GPR_CLOCK_MONOTONIC)) before you start sending RPCs on the channel.  That call won't return until the channel has completed the DNS lookup and established a connection to the server, so if you start timing after that, your timing will exclude the channel startup time.

If you see that the channel startup time is high but the RPCs flow quickly once the startup time is passed, then the problem is either the DNS lookup or establishing a connection to the server.  In that case, please try running with the environment variables GRPC_VERBOSITY=DEBUG GRPC_TRACE=client_channel_routing,pick_first and share the log, so that we can help you figure out which one is the problem.

If you see that the channel startup time is not that high but that the RPCs are actually flowing more slowly over the network, then the problem might be network congestion of some sort.

Also, if the problem does turn out to be channel startup time, note that it probably won't matter much in practice, as long as your application creates the channel once and reuses it for all of its RPCs.  We do not recommend a pattern where you create a channel, send a bunch of RPCs, then destroy the channel, and then do that whole thing again later when you need to send more RPCs.

I hope this information is helpful.

On Sunday, August 8, 2021 at 9:34:43 AM UTC-7 sureshb...@gmail.com wrote:

Environment

1. Both client and server are C++
2. Server might be running either locally or in different system
3. In case of remote server, it is in same network.
4. Using SYNC C++ server
5. Unary RPC

Our performance numbers are very low for running 1000 RPC calls (continuous calls through loop for testing) it takes about 10 seconds when server running in different PC.

The client creates channel using hostname:portnumber method and using this approach the local server were also taking similar 10 seconds for 1000 calls. Later we modified channel creation for local server by using localhost:port then it was much improved performance, all the 1000 calls completed within 300 ms.

Based on the above test, we strongly believe DNS resolution seems to cause slow performance as change hostname to localhost results in huge performance gain, however that is not possible for servers running on different PC.

Can someone help with this? Is DNS the real culprit or what else can be changed to get good performance throughput in this case.

Please let me know if there any other input required for this.

--
You received this message because you are subscribed to a topic in the Google Groups "grpc.io" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/grpc-io/pD3HiDvxymY/unsubscribe.
To unsubscribe from this group and all its topics, send an email to grpc-io+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/grpc-io/66ff211a-e86f-47ff-9583-b423877b8f02n%40googlegroups.com.

--

Mark D. Roth <ro...@google.com>
Software Engineer
Google, Inc.

[Sureshbabu Seshadri]

Thanks Mark. The below link has source code of my sample, please let me know if you need any other information to analyze

https://drive.google.com/file/d/12PH65OYwflaPBpa2a-yMcBqSE3xYX9S-/view?usp=sharing

[Mark D. Roth]

I don't see anything obviously wrong with your code.

Since this test is sending RPCs serially instead of in parallel, it's possible that there are too many network round-trips happening here, each one of which would increase latency because the next operation is blocking on the previous one.  Can you try running with the environment variables GRPC_VERBOSITY=DEBUG GRPC_TRACE=tcp?  Or, alternatively, getting a wireshark capture of the network communication?  That might help us see how many round-trips are happening here.

You might also consider whether sending a bunch of RPCs serially is actually a realistic benchmark for your production workload.  You might get better performance by parallelizing the requests from the client.

To view this discussion on the web visit https://groups.google.com/d/msgid/grpc-io/f010b3e1-8554-4c39-a086-a0741e4f7d12n%40googlegroups.com.

[Sureshbabu Seshadri]

thanks Mark, parallelizing is not an option for my project. As I initially mentioned this project is conversion of CORBA IPC into GRPC whereas CORBA able to complete 1000 RPCs in 1 second vs 10 seconds in GRPC.

I will send GRPC logs with TCP enabled soon; If you prefer wireshark, i need to learn the tool usage and send it later.

[Jeff Steger]

you either have network congestion or nagle algo is interfering. try disabling nagle and/or running traceroute.

You received this message because you are subscribed to the Google Groups "grpc.io" group.

To unsubscribe from this group and stop receiving emails from it, send an email to grpc-io+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/grpc-io/50c98f17-fdee-4e33-bbc1-dbd4d77897fdn%40googlegroups.com.

[Jeff Steger]

Also, I would be careful posting a wireshark pcap to a public forum. The pcap contains lots of information a hacker could potentially use to attack your servers. 

[Sureshbabu Seshadri]

Thanks Jeff for suggestions. disabling nagle did not help, BTW i guess this algo is independent of application and hence when our old SW performs well and not GRPC might require some tuning in GRPC side. correct me if i am wrong

[Sureshbabu Seshadri]

Hi Mark,

Please find GRPC logs with tcp enabled in the below share

https://drive.google.com/file/d/1kjLcaVJtZ3XX2xMUWyoTbXJJ3rsE6xaO/view?usp=sharing

[Mark D. Roth]

Thanks, that's helpful.

From the trace, it looks like you're running on Windows.  Most of our performance efforts have been focused on Linux, not Windows, so it may be that this is just an inefficiency in gRPC's Windows TCP code.  Can you run the client on a Linux machine to see if it makes a difference?  I'd be interested in seeing the log with the same env vars on Linux to compare with the log you've just sent.

One potential problem shown by the trace is that we're splitting up the data for each RPC into a large number of writes instead of coalescing it into a single write.  This does suggest that there's an inefficiency in the gRPC code somewhere, although it's not clear whether the problem is in the Windows TCP code or in the HTTP/2 transport code itself.  If it's in the Windows TCP code, then running on Linux should show an improvement; if it's in the HTTP/2 transport code, then running on Linux probably wouldn't make a difference.

If the problem is in the Windows TCP code, then I would guess that it will be fixed by the work we're doing to replace our current I/O subsystem with a new pluggable system called EventEngine, as per https://github.com/grpc/proposal/pull/245.

If the problem is in the HTTP/2 transport, then it will probably need more work to fix.

I will note that this kind of serialized approach to sending RPCs is not the kind of scenario that our performance work has attempted to optimize, because it's actually a very unusual case.  You say that parallelizing the RPCs is not an option for your project, but it might be useful to understand why.  If you can change that, I think you will see significant performance wins.

You received this message because you are subscribed to the Google Groups "grpc.io" group.

To unsubscribe from this group and stop receiving emails from it, send an email to grpc-io+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/grpc-io/db64a7a7-a4d2-4b67-90fa-627bacfd1407n%40googlegroups.com.

[Sureshbabu Seshadri]

Thanks Mark for some more details. 

Our target environment is windows client and Linux Server and hence executed samples in similar fashion. Now as per your request executed same sample in Linux client and the performance is very good. 1000 RPCs are finished within 1 second (about 500 ms). Here is the requested log with TCP enabled

https://drive.google.com/file/d/1BmgDip5zPUHAiI9VUCrpXPhfe7OXWNnc/view?usp=sharing

Regarding Parallizing, our  software is 20 years old and we have just changed IPC layer from CORBA to GRPC and observed this slowness. Parallelizing is also not possible as there are requests to be processed in client end before executing next RPC call. There are some use cases 200-300 different RPCs are executed and in some use cases, few RPCs are repeatedly called and eventually ending in slowness as each RPC call has signifcant degradation compare to our old SW (CORBA).

One additional point might be interesting to you is, even in windows client when i am executing sample application of calling 1000 RPCs, at sometiimes the performance is good say less than 2 seconds, but majority of execution ending up in slowness about 8-9 seconds.

Additional Question about Windows grpc library building procedure, we are using 64bit Release mode for this. Do you see any scope to optimize GRPC library for better performance by adding some build parameters. The one used is the default procedure mentioned in GRPC site.

[Mark D. Roth]

It sounds like this is a Windows-specific problem, which unfortunately means that we probably can't help you much in the short term, since we don't have any spare cycles to focus on Windows-specific performance.

As I mentioned earlier, the Windows-specific TCP code in gRPC will be replaced by the new EventEngine implementation, probably within the next 6 months or so, so if the problem is in our current Windows TCP code, then that might fix it, although you'd have to wait for that change and then test it to see if it helps.

Of course, gRPC is open-source, so you're welcome to take a look at the code and try to fix this yourself.  We'd be happy to accept patches.

One other experiment that you might try is to increase the payload size of each RPC such that the requests are larger than the TCP MSS.  That would force the server to send a TCP ACK immediately, rather than potentially delaying.  But I don't know if this would help, since you already said that you aren't seeing this problem with the legacy CORBA code (although I don't know what the wire protocol looks like for that, so maybe it's larger?).

I'm sorry that we can't be of more immediate help here.  Good luck!

To view this discussion on the web visit https://groups.google.com/d/msgid/grpc-io/16335180-2397-472b-a8e6-f4004c80d291n%40googlegroups.com.

[Sureshbabu Seshadri]

Thanks Mark for your support. We may now forced to wait for the redesign task you have mentioned. BTW is there way to get that offline (though its not officially pushed into GRPC git hub) to check whether it helps our scenario.

[Mark D. Roth]

(Adding AJ, who's driving the EventEngine effort.)

AJ, it looks like Sureshbabu wants to be an early tester of the new EventEngine code on Windows.  Please coordinate with him when we get to a point where the new code is actually ready for testing (specifically the client-side endpoint code).

To view this discussion on the web visit https://groups.google.com/d/msgid/grpc-io/8acf6cef-9adc-4365-9912-c600108bde55n%40googlegroups.com.

[AJ Heller]

Absolutely, I'll reach out when the EventEngine integration is a bit more feasible. As Mark said, getting to a point where gRPC is ready for custom EventEngine integration is maybe 6 months away.

The EventEngine API is public, you can review and comment on it here: https://github.com/grpc/proposal/pull/245. It's an experimental API that is still undergoing changes, since we're building our first implementations and working out performance problems, etc. We're doing all of this development in the open, so there's no internal channel or early release to offer you, but hopefully this is a good start.