Using cmux with MatchWithWriters consumes too much CPU

[sadlil]

We are using cmux with gRPC and grpc-gateway like this example. . But we found out that using
grpcl := m.MatchWithWriters(cmux.HTTP2MatchHeaderFieldSendSettings("content-type", "application/grpc")) consumes too much cpu.

$ ~> ps axo pid,etime,%cpu,%mem,cmd | grep 'server-combine' | grep -v grep 7054 00:07 123 0.1 server-combine

Using m.Match(cmux.HTTP2HeaderField("content-type", "application/grpc")) is ok. but if try to use the L28 this takes too much CPU.

Is there any fix for this?

[sadlil]

ping @soheilhy

[soheilhy]

Please attach a pprof callgraph and I'll take a look. MatchWithWriters has higher CPU usage as it's doing a lot more work. It's not recommended to use it unless you really have broken clients that need this matcher.

[tamalsaha]

cmux-callgraph.pdf

@soheilhy , I work with @sadlil . Here is a callgraph of this issue. It will be great if you can take a look.

[enm10k]

I have the same problem on latest master branch: bb79a83465015a27a175925ebd155e660f55e9f1 .
After I stopped using MatchWithWriters, high CPU utilization was solved.
Is anyone working on this?

[soheilhy]

I'm not aware of any new issues. Do you have a profile or a call graph?

[enm10k]

Do you have a profile or a call graph?

Not now. I will try to create a PoC.
Please wait a few days.

[talgendler]

@soheilhy Perhaps when you send empty settings the clients can't handle that correctly, one can see that when debugging the server with GODEBUG=http2debug=2
Those 4 lines of code are in infinite loop

2018/01/29 17:19:31 http2: Framer 0xc4201fc2a0: wrote SETTINGS len=0
2018/01/29 17:19:31 http2: Framer 0xc420264000: read SETTINGS len=0
2018/01/29 17:19:31 http2: Framer 0xc420264000: wrote SETTINGS flags=ACK len=0
2018/01/29 17:19:31 http2: Framer 0xc4201fc2a0: read SETTINGS flags=ACK len=0
2018/01/29 17:19:31 http2: Framer 0xc4201fc2a0: wrote SETTINGS len=0
2018/01/29 17:19:31 http2: Framer 0xc420264000: read SETTINGS len=0
2018/01/29 17:19:31 http2: Framer 0xc420264000: wrote SETTINGS flags=ACK len=0
2018/01/29 17:19:31 http2: Framer 0xc4201fc2a0: read SETTINGS flags=ACK len=0
2018/01/29 17:19:31 http2: Framer 0xc4201fc2a0: wrote SETTINGS len=0
2018/01/29 17:19:31 http2: Framer 0xc420264000: read SETTINGS len=0
2018/01/29 17:19:31 http2: Framer 0xc420264000: wrote SETTINGS flags=ACK len=0
2018/01/29 17:19:31 http2: Framer 0xc4201fc2a0: read SETTINGS flags=ACK len=0
2018/01/29 17:19:31 http2: Framer 0xc4201fc2a0: wrote SETTINGS len=0
2018/01/29 17:19:31 http2: Framer 0xc420264000: read SETTINGS len=0
2018/01/29 17:19:31 http2: Framer 0xc420264000: wrote SETTINGS flags=ACK len=0
2018/01/29 17:19:31 http2: Framer 0xc4201fc2a0: read SETTINGS flags=ACK len=0
2018/01/29 17:19:31 http2: Framer 0xc4201fc2a0: wrote SETTINGS len=0

Both client and server are in go, the grpc-gateway is actually creating a local connection to the server so when it translates REST API calls the code call gRPC endpoint locally.

[soheilhy]

I think you've found the bug. Thank you.

Can you give the following patch a try? I think it should fix the issue.
e496b35

[talgendler]

@soheilhy That solves it.
Thanks

[soheilhy]

Great thank you for the confirmation.

[soheilhy]

I'm going to mark this bug as fixed. Please open if it flares up again.