Graceful shutdown with bidirectional stream

[anjmao]

I have bidirectional streaming endpoint with ping pong (server is sending message to client and client sends it back).

If I use server.GracefulStop server is never get killed since there is active stream. I see that go client receives GOAWAY.

2019/07/01 11:27:27 http2: Framer 0xc0001ee000: wrote SETTINGS len=0
2019/07/01 11:27:27 http2: Framer 0xc0001ee000: read SETTINGS flags=ACK len=0
2019/07/01 11:27:28 http2: Framer 0xc0001ee000: wrote HEADERS flags=END_HEADERS stream=1 len=69
2019/07/01 11:27:28 http2: Framer 0xc0001ee000: wrote DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16client ping 1561969648"
2019/07/01 11:27:28 http2: Framer 0xc0001ee000: read WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:28 http2: Framer 0xc0001ee000: read PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:28 http2: Framer 0xc0001ee000: wrote PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:28 http2: Framer 0xc0001ee000: read HEADERS flags=END_HEADERS stream=1 len=14
2019/07/01 11:27:28 http2: decoded hpack field header field ":status" = "200"
2019/07/01 11:27:28 http2: decoded hpack field header field "content-type" = "application/grpc"
2019/07/01 11:27:28 http2: Framer 0xc0001ee000: read DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16server ping 1561969648"
2019/07/01 11:27:28 http2: Framer 0xc0001ee000: wrote WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:28 http2: Framer 0xc0001ee000: wrote PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:28 message:"server ping 1561969648" 
2019/07/01 11:27:28 http2: Framer 0xc0001ee000: wrote DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16client ping 1561969648"
2019/07/01 11:27:28 http2: Framer 0xc0001ee000: read PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:28 http2: Framer 0xc0001ee000: read WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:28 http2: Framer 0xc0001ee000: read PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:28 http2: Framer 0xc0001ee000: wrote PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:31 http2: Framer 0xc0001ee000: read DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16server ping 1561969651"
2019/07/01 11:27:31 http2: Framer 0xc0001ee000: wrote WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:31 http2: Framer 0xc0001ee000: wrote PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:31 message:"server ping 1561969651" 
2019/07/01 11:27:31 http2: Framer 0xc0001ee000: wrote DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16client ping 1561969651"
2019/07/01 11:27:31 http2: Framer 0xc0001ee000: read PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:31 http2: Framer 0xc0001ee000: read WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:31 http2: Framer 0xc0001ee000: read PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:31 http2: Framer 0xc0001ee000: wrote PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:34 http2: Framer 0xc0001ee000: read DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16server ping 1561969654"
2019/07/01 11:27:34 http2: Framer 0xc0001ee000: wrote WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:34 message:"server ping 1561969654" 
2019/07/01 11:27:34 http2: Framer 0xc0001ee000: wrote PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:34 http2: Framer 0xc0001ee000: wrote DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16client ping 1561969654"
2019/07/01 11:27:34 http2: Framer 0xc0001ee000: read PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:34 http2: Framer 0xc0001ee000: read WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:34 http2: Framer 0xc0001ee000: read PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:34 http2: Framer 0xc0001ee000: wrote PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:37 http2: Framer 0xc0001ee000: read DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16server ping 1561969657"
2019/07/01 11:27:37 http2: Framer 0xc0001ee000: wrote WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:37 http2: Framer 0xc0001ee000: wrote PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:37 message:"server ping 1561969657" 
2019/07/01 11:27:37 http2: Framer 0xc0001ee000: wrote DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16client ping 1561969657"
2019/07/01 11:27:37 http2: Framer 0xc0001ee000: read PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:37 http2: Framer 0xc0001ee000: read WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:37 http2: Framer 0xc0001ee000: read PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:37 http2: Framer 0xc0001ee000: wrote PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:37 http2: Framer 0xc0001ee000: read GOAWAY len=8 LastStreamID=2147483647 ErrCode=NO_ERROR Debug=""
2019/07/01 11:27:37 http2: Framer 0xc0001ee000: read PING len=8 ping="\x01\x06\x01\b\x00\x03\x03\t"
2019/07/01 11:27:37 http2: Framer 0xc0001ee000: wrote PING flags=ACK len=8 ping="\x01\x06\x01\b\x00\x03\x03\t"
2019/07/01 11:27:37 http2: Framer 0xc0001ee000: read GOAWAY len=8 LastStreamID=1 ErrCode=NO_ERROR Debug=""
2019/07/01 11:27:40 http2: Framer 0xc0001ee000: read DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16server ping 1561969660"
2019/07/01 11:27:40 http2: Framer 0xc0001ee000: wrote WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:40 http2: Framer 0xc0001ee000: wrote PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:40 message:"server ping 1561969660" 
2019/07/01 11:27:40 http2: Framer 0xc0001ee000: wrote DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16client ping 1561969660"
2019/07/01 11:27:40 http2: Framer 0xc0001ee000: read PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:40 http2: Framer 0xc0001ee000: read WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:40 http2: Framer 0xc0001ee000: read PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:40 http2: Framer 0xc0001ee000: wrote PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:43 http2: Framer 0xc0001ee000: read DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16server ping 1561969663"
2019/07/01 11:27:43 http2: Framer 0xc0001ee000: wrote WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:43 http2: Framer 0xc0001ee000: wrote PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:43 message:"server ping 1561969663" 
2019/07/01 11:27:43 http2: Framer 0xc0001ee000: wrote DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16client ping 1561969663"
2019/07/01 11:27:43 http2: Framer 0xc0001ee000: read PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:43 http2: Framer 0xc0001ee000: read WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:43 http2: Framer 0xc0001ee000: read PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:43 http2: Framer 0xc0001ee000: wrote PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:46 http2: Framer 0xc0001ee000: read DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16server ping 1561969666"
2019/07/01 11:27:46 http2: Framer 0xc0001ee000: wrote WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:46 message:"server ping 1561969666" 
2019/07/01 11:27:46 http2: Framer 0xc0001ee000: wrote PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:46 http2: Framer 0xc0001ee000: wrote DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16client ping 1561969666"
2019/07/01 11:27:46 http2: Framer 0xc0001ee000: read PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:46 http2: Framer 0xc0001ee000: read WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:46 http2: Framer 0xc0001ee000: read PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:46 http2: Framer 0xc0001ee000: wrote PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:49 http2: Framer 0xc0001ee000: read DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16server ping 1561969669"
2019/07/01 11:27:49 http2: Framer 0xc0001ee000: wrote WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:49 http2: Framer 0xc0001ee000: wrote PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:49 message:"server ping 1561969669" 
2019/07/01 11:27:49 http2: Framer 0xc0001ee000: wrote DATA stream=1 len=29 data="\x00\x00\x00\x00\x18\n\x16client ping 1561969669"
2019/07/01 11:27:49 http2: Framer 0xc0001ee000: read PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:49 http2: Framer 0xc0001ee000: read WINDOW_UPDATE len=4 (conn) incr=29
2019/07/01 11:27:49 http2: Framer 0xc0001ee000: read PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2019/07/01 11:27:49 http2: Framer 0xc0001ee000: wrote PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"

From what I see in the source code this works as expected and server is not killed if there is at least one active stream. My questions are:

1. Is it possible to graceful shutdown only unary rpc calls and force to drop all streams on the server side?
2. Is it possible to handle GOAWAY from client side and close stream? I don't see any public API for handling GOAWAY from the client side.

Thanks.

[dfawley]

Is it possible to graceful shutdown only unary rpc calls and force to drop all streams on the server side?

Not like this. The common way to shut down a server would be to do a graceful stop, sleep for some grace period, and then do a hard shutdown. After the graceful stop, no new RPCs will be accepted, so after the grace period, only longer-lived streaming RPCs should remain, which the hard shutdown will terminate.

Is it possible to handle GOAWAY from client side and close stream? I don't see any public API for handling GOAWAY from the client side.

No, there is currently no way for the client to know that the connection a stream is using received a GOAWAY. In general, the procedure I described above is used to handle these types of situations.

Please let me know if you have any further questions.

[anjmao]

@dfawley Drawback is that some RPC calls may still be killed if they takes longer than grace period but it's still good idea to try. Thanks.

Feel free to close this issue if you don't have any plans for graceful stop improvements.

[hanjm]

@anjmao see also #2849

[dfawley]

Number 2 is an interesting suggestion. Given that clients should always be resilient to network outages/server failures, this would be more of an optimization to help clients play along nicely with the server's graceful shutdown. As such, it would likely be a pretty low priority for us. Closing, but if you feel there is sufficient benefit to this feature, feel free to open a new feature request issue -- or it may be more appropriate to request it as a cross-langauge feature in the main grpc/grpc repo.