Serving: gRPC streaming responses smaller than 4KB are buffered indefinitely

[tanzeeb]

In what area(s)?

/area networking

What version of Knative?

HEAD

Expected Behavior

Streaming gRPC responses should be returned immediately.

Actual Behavior

Streaming gRPC responses are held until a 4KB buffer is filled.

Steps to Reproduce the Problem

Reported by @fbiville:

@ericbottard and I worked together to investigate the response buffering issue.
As suggested by @dprotaso last Friday, we tried again to deploy our https://github.com/fbiville/hello-grpc Go server in the following setups:

1. plain Kubernetes (no Istio, no Knative)
2. plain Kubernetes + Istio (no Knative)
3. Knative + @tanzeeb's PR knative/serving#2539

You can check the commit history of this project to follow what we exactly did (https://github.com/fbiville/streaming-loudly).

The buffering issue occurred only in situation 3.

After digging in Knative/serving codebase, we found that the queue-proxy transport uses buffered IO and the writer holds a buffer of 4K.

The code paths are approximately like:
cmd/queue/main h2cproxy httputil.ReverseProxy -> ReverseProxy#ServeHTTP transport.RoundTrip -> http2.transport#RoundTrip GetClientConn -> newClientConn -> buf.NewWriter with the default size

[fbiville]

You can reproduce the issue easily with https://github.com/ericbottard/knative-grpc, by following the steps described in the README file.

[mattmoor]

From here:

        // FlushInterval specifies the flush interval
        // to flush to the client while copying the
        // response body.
        // If zero, no periodic flushing is done.
        FlushInterval time.Duration

I wonder if this would at least help mitigate the problem?

[mattmoor]

Though setting the payload to 10 bytes, I see the test hang at this for a while (and now it is on to the scale to zero)

2019-02-16T17:31:30.969Z        info    TestGRPC        e2e/grpc_test.go:167    Sending stream 1 of 3

Though, I only tried it in ./cmd/queue/main.go on the h2cProxy.

[mattmoor]

This issue mentions exactly the issue we are seeing https://github.com/fabiolb/fabio/issues/324

[mattmoor]

cc @bradfitz in case he has any recommendations that aren't forking this library.

[bradfitz]

In Go 1.12, an explicit negative interval disables buffering, but it's also disabled for text/event-stream responses (and perhaps more will be added in the future; there's a TODO in the code):

https://tip.golang.org/pkg/net/http/httputil/#ReverseProxy.FlushInterval

    // A negative value means to flush immediately
    // after each write to the client.
    // The FlushInterval is ignored when ReverseProxy
    // recognizes a response as a streaming response;
    // for such responses, writes are flushed to the client
    // immediately.
    FlushInterval time.Duration

Have you tried Go 1.12? Go 1.12rc1 is out.

[mattmoor]

That's actually perfect, we switched to 1.12 for websocket support yesterday :)

[mattmoor]

Thanks @bradfitz, I'll try that out when I get back

[mattmoor]

Hmm, this doesn't seem to do it.

[mattmoor]

@tcnghia and I got it. queue.timeoutWriter doesn't implement http.Flusher :)