Stress test error: 'ignoring out of order new grpc_chttp2_stream request on server'

[Okke Hendriks]

Hello,

I am doing a stress test:

• 50 clients each doing 5000 async requests.
  
• There is 1ms between each async call.
  
• The service is a simple return of the requests message.
  
• The request are being processed by an simple asynchronous API gRPC server doing nothing else as processing the test requests. 
  
• All traffic is via localhost.
  
• gRPC C++ 1.0.0
  

I am, sometimes and usually after a while into the run, getting the following message a lot:

** more output here

E1110 18:02:45.561700666   57211 parsing.c:801]              ignoring out of order new grpc_chttp2_stream request on server; last grpc_chttp2_stream id=9999, new grpc_chttp2_stream id=9995

E1110 18:02:45.561863408   57211 parsing.c:801]              ignoring out of order new grpc_chttp2_stream request on server; last grpc_chttp2_stream id=9999, new grpc_chttp2_stream id=9997

E1110 18:02:46.309517548   56746 parsing.c:801]              ignoring out of order new grpc_chttp2_stream request on server; last grpc_chttp2_stream id=3807, new grpc_chttp2_stream id=2385

E1110 18:02:46.309809566   56746 parsing.c:801]              ignoring out of order new grpc_chttp2_stream request on server; last grpc_chttp2_stream id=3807, new grpc_chttp2_stream id=2387

E1110 18:02:46.310132458   56746 parsing.c:801]              ignoring out of order new grpc_chttp2_stream request on server; last grpc_chttp2_stream id=3807, new grpc_chttp2_stream id=2389

E1110 18:02:46.310476893   56746 parsing.c:801]              ignoring out of order new grpc_chttp2_stream request on server; last grpc_chttp2_stream id=3807, new grpc_chttp2_stream id=2391

E1110 18:02:46.310763893   56746 parsing.c:801]              ignoring out of order new grpc_chttp2_stream request on server; last grpc_chttp2_stream id=3807, new grpc_chttp2_stream id=2393

E1110 18:02:46.311340403   56746 parsing.c:801]              ignoring out of order new grpc_chttp2_stream request on server; last grpc_chttp2_stream id=3807, new grpc_chttp2_stream id=2395

E1110 18:02:46.311623344   56746 parsing.c:801]              ignoring out of order new grpc_chttp2_stream request on server; last grpc_chttp2_stream id=3807, new grpc_chttp2_stream id=2397

E1110 18:02:46.312027031   56746 parsing.c:801]              ignoring out of order new grpc_chttp2_stream request on server; last grpc_chttp2_stream id=3807, new grpc_chttp2_stream id=3723

** more output here

What exactly does this imply? 

Is this expected, with this kind of stress? And if so what determines/are the limits?

Or is there something else which I should investigate going on?

[Okke Hendriks]

When I increase the delay between making calls to 2ms instead of 1ms everything is fine.

Using netstat -o | grep <port>  I see that when the delay is only 1ms the receive queue fills up, when it shows a high number ~30000 the messages start appearing.

So this might be unrelated to gRPC itself but the sockets being overloaded?

[Ken Payson]

This looks like the same issue seen here: https://github.com/grpc/grpc/issues/7785

It was caused by concurrency issues in the http2 parser.  I've verified that the issue is fixed in the master branch.

--
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+unsubscribe@googlegroups.com.
To post to this group, send email to grp...@googlegroups.com.
Visit this group at https://groups.google.com/group/grpc-io.
To view this discussion on the web visit https://groups.google.com/d/msgid/grpc-io/0fb6a686-4130-4bbd-8ea2-4388565fccb9%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.