grpc: Server.Serve failed to create ServerTransport: connection error: desc = "transport: short write"

[bioothod]

grpc: Server.Serve failed to create ServerTransport:  connection error: desc = "transport: short write"

I frequently get this error during usual request-response operations. Single RPC, small amount of data.
Client side is a python if that matters. Server is just a grpc.NewServer() without fancy options as well as listener. I've slightly modified transport/http2_server.go to print delta size.
Delta happens to be less than 1M:

grpc: Server.Serve failed to create ServerTransport:  connection error: desc = "transport: short write, delta: 983025"

(also, checking that uint32 > 0 looks like a bug, if it is not a plain check against zero)

diff --git a/transport/http2_server.go b/transport/http2_server.go
index a095dd0..c4275c5 100644
--- a/transport/http2_server.go
+++ b/transport/http2_server.go
@@ -123,9 +123,10 @@ func newHTTP2Server(conn net.Conn, config *ServerConfig) (_ ServerTransport, err
                return nil, connectionErrorf(true, err, "transport: %v", err)
        }
        // Adjust the connection flow control window if needed.
-       if delta := uint32(initialConnWindowSize - defaultWindowSize); delta > 0 {
-               if err := framer.writeWindowUpdate(true, 0, delta); err != nil {
-                       return nil, connectionErrorf(true, err, "transport: %v", err)
+       delta := initialConnWindowSize - defaultWindowSize
+       if delta > 0 {
+               if err := framer.writeWindowUpdate(true, 0, uint32(delta)); err != nil {
+                       return nil, connectionErrorf(true, err, "transport: %v, delta: %d", err, delta)
                }
        }
        var buf bytes.Buffer

Client fails with the following message when this happens:

Traceback (most recent call last):
  File "security.py", line 23, in <module>
    reply = stub.SearchSecurity(req)
  File "/usr/lib64/python2.7/site-packages/grpc/_channel.py", line 481, in __call__
    return _end_unary_response_blocking(state, False, deadline)
  File "/usr/lib64/python2.7/site-packages/grpc/_channel.py", line 432, in _end_unary_response_blocking
    raise _Rendezvous(state, None, None, deadline)
grpc._channel._Rendezvous: <_Rendezvous of RPC that terminated with (StatusCode.UNAVAILABLE, {"created":"@1484928335.749505066","description":"EOF","file":"src/core/lib/iomgr/tcp_posix.c","file_line":235,"grpc_status":14})>

[bioothod]

Client code (that's it):

channel = grpc.insecure_channel('localhost:8080')
stub = service_pb2_grpc.XXXStub(channel)

req = service_pb2.SearchRequest(content=['test'])
reply = stub.SearchSecurity(req)

Server (simplified, dropped error checks and so on) :

lis, err := net.Listen("tcp", "localhost:8080")
srv := grpc.NewServer()
pb.RegisterXXXServer(srv, fh)
reflection.Register(srv)
srv.Serve(lis)

func (fh *XXX) SearchSecurity(ctx context.Context, req *pb.SearchRequest) (*pb.SearchReply, error) {
	reply := &pb.SearchReply {
		Securities: make([]*pb.Security, 0, 0),
	}
	return reply, nil
}

[bioothod]

This is the test I use: https://github.com/bioothod/grpc_test
It is not actually a grpc problem, but wine. I ran this test on linux and windows quite alot, and there were no problems, but it breaks quickly on wine.
This patch golang/go#18537 helps, but problem persists - it just started to appear not after 5-10 requests, but after like 100k-500k, so there is a problem somewhere in the golang network stack when running on wine, which I will try to resolve. I'm not sure whether both these issues I opened (#1054, #1053) should not be closed by you, but since I found these while testing grpc, I filled them here first.

[bioothod]

And the bug seems related to grpc code which doesn't tolerate 'short writes', i.e. when underlying connection writer's Flush() method is invoked and it fails to flush the whole buffer into the network.

So, here is a story.
There is grpc-go server and one or more python clients. Server runs under wine and this was the first suspect, but it turns out to be unlikely.

Server frequently fails to accept new client, i.e. it accepts it and immediately closes connection with abovementioned error

grpc: Server.Serve failed to create ServerTransport:  connection error: desc = "transport: short write"

This is because of this Flush() method returns error: https://github.com/grpc/grpc-go/blob/master/transport/http_util.go#L408
It returns error because underlying bufio.Flush() invokes net.Conn.Write() which returns smaller number of bytes than buffer size: https://golang.org/src/bufio/bufio.go?s=14020:14050#L564

There are at least 2 places where this error appears:
https://github.com/grpc/grpc-go/blob/master/transport/http2_server.go#L127
https://github.com/grpc/grpc-go/blob/master/transport/http2_server.go#L499 (the latter ends up with use of closed network connection message described at #1053)

Bug is 100% reproducible under wine using https://github.com/bioothod/grpc_test

$ make windows
$ ./grpc_server
$ python client.py

requires editing Makefile to specify correct go compiler and goroot

[menghanl]

Do you think if this is a gRPC-go issue? Can we close this issue now?

[bioothod]

Yes, you are right, it could be closed, it went down to wine