The latency of http2 server is much higher than the network latency

[dominiquelefevre]

Hi,

After hitting hyperium/tonic#103 I decided to look for the source of latency in tonic.

Please have a look at two trivial servers and clients. In both cases the client and the server talk over the loopback device, so there is very little latency in the link.

tokio-test.tar.gz
hyper-test.tar.gz

tokio-test

The server is the echo server from the tokio examples collection. The client proceeds this way:

1. send a few bytes to the server,
2. wait for a complete echo to come back,
3. repeat.

This test uses http/2 so that a single connection is reused for all requests.

On my test machine, this client runs 16K iterations in 0.75sec.

hyper-test

The server responds to any request with "Hello, world!\n". Essentially, it is hyper/examples/multi_server.rs with "multi" part removed. The client proceeds this way:

1. send "GET http://127.0.0.1:9091/",
2. wait for a complete reply,
3. repeat.

On my test machine, this client runs 16K iterations in 35.10sec.

There is an interesting aspect to the second test: neither the server, nor the client use 100% CPU. In fact, the server uses approx. 15% CPU. Essentially, it sleeps instead of serving requests.

---

Where does so much latency and idle time come from in hyper?

I've used the following package versions:

• tokio 0.2.0-alpha.6,
• hyper 0.13.0-alpha.4,
• rustc 1.39.0-beta.7 (23f8f652b 2019-10-26),
• Linux 5.3.6-300.fc31.x86_64

[piakushin]

Hi
This happens because of the TCP Nagle's algorithm. You need to set the NO_DELAY option for client and for server

[dominiquelefevre]

NO_DELAY is enabled by tokio automatically.

This is strace of the client:

151018 connect(18, {sa_family=AF_INET, sin_port=htons(9091), sin_addr=inet_addr("127.0.0.1")}, 16 <unfinished ...>
...
151018 getsockopt(18, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
151018 setsockopt(18, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0
151018 setsockopt(18, SOL_TCP, TCP_KEEPIDLE, [90], 4) = 0
151018 setsockopt(18, SOL_TCP, TCP_NODELAY, [0], 4) = 0

And this is strace of the server:

151036 accept4(18, {sa_family=AF_INET, sin_port=htons(47432), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 19
...
151036 setsockopt(19, SOL_TCP, TCP_NODELAY, [0], 4) = 0

[dominiquelefevre]

setsockopt(18, SOL_TCP, TCP_NODELAY, [0], 4)

I am a moron :)

Pavel, thank you!