x/net/http2: reduce Framer ReadFrame allocations

[apolcyn]

Please answer these questions before submitting your issue. Thanks!

This is a performance-related issue/proposal for the net/http2 library in https://github.com/golang/net/tree/master/http2.

What version of Go are you using (go version)?

1.8beta2

What operating system and processor architecture are you using (go env)?

amd64

I'm running "grpc-go" (https://github.com/grpc/grpc-go) micro-benchmarks (grpc-go uses only the "framer" from the net/http2 library). Specifically I'm looking at a benchmarks that tests "grpc streaming" throughput, with a couple of clients against one 32 core server.

Details on this benchmark setup: the server has a total of 64 tcp/http2 connections, with 100 long-lived http2 streams over each http2 connection. A streaming "round-trip" is a grpc request-response of about 10 bytes, each fitting into one data frame. The server is ran with a 5 second warmup and a 30 second benchmark, during which it does somewhere around 900K round trips per second.

After multiple changes that reduce memory allocations elsewhere, the memory "alloc_space" profile of the server after running this benchmark looks like:

2139.58MB of 2178.13MB total (98.23%)
Dropped 69 nodes (cum <= 10.89MB)
      flat  flat%   sum%        cum   cum%
 1436.57MB 65.95% 65.95%  1436.57MB 65.95%  golang.org/x/net/http2.parseDataFrame
  473.51MB 21.74% 87.69%   473.51MB 21.74%  google.golang.org/grpc.protoCodec.Marshal
  225.50MB 10.35% 98.05%   225.50MB 10.35%  google.golang.org/grpc/transport.(*http2Server).handleData
    2.50MB  0.11% 98.16%   494.02MB 22.68%  google.golang.org/grpc/benchmark.(*testServer).StreamingCall
       1MB 0.046% 98.21%   495.02MB 22.73%  google.golang.org/grpc.(*Server).processStreamingRPC
    0.50MB 0.023% 98.23%   477.01MB 21.90%  google.golang.org/grpc.(*serverStream).SendMsg
         0     0% 98.23%  1442.07MB 66.21%  golang.org/x/net/http2.(*Framer).ReadFrame
         0     0% 98.23%  1678.60MB 77.07%  google.golang.org/grpc.(*Server).handleRawConn
         0     0% 98.23%   495.02MB 22.73%  google.golang.org/grpc.(*Server).handleStream
         0     0% 98.23%  1677.60MB 77.02%  google.golang.org/grpc.(*Server).serveHTTP2Transport
         0     0% 98.23%  1676.57MB 76.97%  google.golang.org/grpc.(*Server).serveStreams
         0     0% 98.23%   495.02MB 22.73%  google.golang.org/grpc.(*Server).serveStreams.func1.1
         0     0% 98.23%   473.51MB 21.74%  google.golang.org/grpc.(*protoCodec).Marshal
         0     0% 98.23%    14.52MB  0.67%  google.golang.org/grpc.(*serverStream).RecvMsg
         0     0% 98.23%   473.51MB 21.74%  google.golang.org/grpc.encode
         0     0% 98.23%    14.52MB  0.67%  google.golang.org/grpc.recv
         0     0% 98.23%    14.52MB  0.67%  google.golang.org/grpc/benchmark/grpc_testing.(*benchmarkServiceStreamingCallServer).RecvMsg
         0     0% 98.23%   477.01MB 21.90%  google.golang.org/grpc/benchmark/grpc_testing.(*benchmarkServiceStreamingCallServer).Send
         0     0% 98.23%   494.02MB 22.68%  google.golang.org/grpc/benchmark/grpc_testing._BenchmarkService_StreamingCall_Handler
         0     0% 98.23%  1442.07MB 66.21%  google.golang.org/grpc/transport.(*framer).readFrame
         0     0% 98.23%  1676.57MB 76.97%  google.golang.org/grpc/transport.(*http2Server).HandleStreams
         0     0% 98.23%  2173.63MB 99.79%  runtime.goexit

Note golang.org/x/net/http2.parseDataFrame appears to be allocating a new DataFrame struct per-data frame, which ends up being the largest source of allocations. (alloc appears to be from https://github.com/golang/net/blob/master/http2/frame.go#L577)

Also, from the total "alloc_objects" profile, golang.org/x/net/http2.parseDataFrame appears to account for about 30M of the total ~80M object allocations.

Experimenting with a code change that repeatedly returns the same DataFrame struct instead of creating new ones:

• memory allocations from golang.org/x/net/http2.parseDataFrame dissappear,
• total memory allocated by the benchmark goes down ~1.5GB to about 740MB
• QPS in the grpc-microbenchmark increases about 5%

The current http2 framer returns a slice on "data frame reads" that's only valid until the next call to ReadFrame. I'm wondering if similar semantics for the entire DataFrame struct sound reasonable, or possibly an option to turn this on.

I can give more details on the benchmark setup if needed.

thanks

[apolcyn]

cc @iamqizhao

[bradfitz]

The Framer could conditionally (opt-in) keep a reference to each of concrete types of frames and reuse them if the caller wants.

[RLH]

The application is running on a 32 core machine. How much RAM does the machine have? I ask because 2 GBytes of allocation over 30 seconds does not seem like a lot for a 32 core machine. Could you run it with GODEBUG=gctrace=1 and post the output?

…

On Tue, Jan 3, 2017 at 1:37 PM, apolcyn ***@***.***> wrote: cc @iamqizhao <https://github.com/iamqizhao> — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#18502 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AA7Wn-zGdgTVJ9VSWdsUX1X4rN1gotqJks5rOpV_gaJpZM4LZ4p7> .

[apolcyn]

The application is running on a 32 core machine. How much RAM does the
machine have? I ask because 2 GBytes of allocation over 30 seconds does not
seem like a lot for a 32 core machine.

There's about 30GB on this machine.
Other changes to the server outside of this one bring it down from a higher amount (~15GB to ~2GB here), but have still been seeing steady benchmark improvements with general reducing of allocations.

Could you run it with GODEBUG=gctrace=1 and post the output?

Yeah capturing the gc trace from the server's whole life shows: https://gist.github.com/apolcyn/2f19a4230ed65c2b1738c98ee978a8c2

note in this log, the "reset" on lines 30 and 31 just separates the warmup and benchmark periods.

[apolcyn]

The Framer could conditionally (opt-in) keep a reference to each of concrete types of frames and reuse them if the caller wants.

This would work well for me! I can create a PR

[RLH]

The GC is keeping the heap at a modest 45 Mbytes. The trace says 0% overhead for the GC but that is rounded so it really means < 1%. Latency in the warmup is a bit high but still < 9ms and latency during the actual run is between 400 usecs and 1300 usecs. The GC seems to be working as designed. Thanks for the trace.

…

On Tue, Jan 3, 2017 at 5:00 PM, apolcyn ***@***.***> wrote: The Framer could conditionally (opt-in) keep a reference to each of concrete types of frames and reuse them if the caller wants. This would work well for me! I can create a PR — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#18502 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AA7Wn6DazkjNpqQQiEQJnHW_MmJGVdyiks5rOsUagaJpZM4LZ4p7> .

[apolcyn]

fyi just submitted PR with "Change-Id: Iad93420ef6c3918f54249d867098f1dadfa324d8"

(https://go-review.googlesource.com/#/c/34812/)

[gopherbot]

CL https://golang.org/cl/34812 mentions this issue.