Repository: netty/netty
Issue: HTTP/2 server example not using flow controller
Labels: defect

@nmittler - I'd like to get your input on the following.  I have a non-netty server communicating with a netty client.  All is well on this front ;).  However I am trying to interact with my server from curl.  I am having issues getting curl to read all data for multiple frames from my server and so naturally I tried netty's example server and I am seeing the same issue.  I am also seeing the same behavior in firefox nightly (client appears to be waiting for something to happen and never fully reads the data).  I figured I would discuss with you before getting support from the client perspective (seeing as these are 2 mainstream clients).

 Greater than 16384 seems to be the magic number (see code below) which gets these clients into this state.  I think this number is special because it is the maximum TLS plaintext size per unit (see here https://github.com/openssl/openssl/blob/f47e203975133ddbae3cde20c8c3c0516f62066c/ssl/ssl3.h#L303).  Is there anything we should be doing special from a server point of view here?

I modified the `HelloWorldHttp2Handler.java` to observe this issue:

``` java
private void sendResponse(ChannelHandlerContext ctx, int streamId, ByteBuf payload) {
            // Send a frame for the response status
            Http2Headers headers = new DefaultHttp2Headers().status(new AsciiString("200"));
            payload.release();
            final int len = 16384 + 1;
            payload = buffer(len);
            for (int i = 0; i < len; ++i) {
                payload.writeByte((byte) 'a');
            }
            frameWriter.writeHeaders(ctx, streamId, headers, 0, false, ctx.newPromise());
            frameWriter.writeData(ctx, streamId, payload, 0, true, ctx.newPromise());
            ctx.flush();
        }
```


Issue comments:
Now I'm thinking this is an issue because our netty client example reliably times out in this case.  The server (netty server example) prints that it sent everything, but the client hangs after processing the headers.

**Server**

``` bash
Selected Protocol is HTTP_2
Oct 10, 2014 3:57:45 PM io.netty.handler.codec.http2.Http2FrameLogger log
INFO: 
----------------OUTBOUND--------------------
SETTINGS: ack=false, settings={HEADER_TABLE_SIZE=4096, MAX_CONCURRENT_STREAMS=2147483647, INITIAL_WINDOW_SIZE=65535, MAX_FRAME_SIZE=16384, MAX_HEADER_LIST_SIZE=2147483647}
------------------------------------
Oct 10, 2014 3:57:45 PM io.netty.handler.codec.http2.Http2FrameLogger log
INFO: 
----------------INBOUND--------------------
SETTINGS: ack=false, settings={HEADER_TABLE_SIZE=4096, ENABLE_PUSH=1, MAX_CONCURRENT_STREAMS=2147483647, INITIAL_WINDOW_SIZE=65535, MAX_FRAME_SIZE=16384, MAX_HEADER_LIST_SIZE=2147483647}
------------------------------------
Oct 10, 2014 3:57:45 PM io.netty.handler.codec.http2.Http2FrameLogger log
INFO: 
----------------OUTBOUND--------------------
SETTINGS ack=true
------------------------------------
Oct 10, 2014 3:57:45 PM io.netty.handler.codec.http2.Http2FrameLogger log
INFO: 
----------------INBOUND--------------------
SETTINGS ack=true
------------------------------------
Oct 10, 2014 3:57:46 PM io.netty.handler.codec.http2.Http2FrameLogger log
INFO: 
----------------INBOUND--------------------
HEADERS: streamId:3, headers=DefaultHttp2Headers[:authority: 127.0.0.1:13443, :method: GET, :path: /whatever, :scheme: https, Accept-Encoding: deflate, Accept-Encoding: gzip], streamDependency=0, weight=16, exclusive=false, padding=0, endStream=true
------------------------------------
Oct 10, 2014 3:57:46 PM io.netty.handler.codec.http2.Http2FrameLogger log
INFO: 
----------------OUTBOUND--------------------
HEADERS: streamId:3, headers=DefaultHttp2Headers[:status: 200], padding=0, endStream=false
------------------------------------
Oct 10, 2014 3:57:46 PM io.netty.handler.codec.http2.Http2FrameLogger log
INFO: 
----------------OUTBOUND--------------------
DATA: streamId=3, padding=0, endStream=true, length=16385, bytes=6161616....
------------------------------------
```

**Client**

``` bash
./run-example.sh -Dssl -Dport=13443 http2-client
[INFO] Running: http2-client (io.netty.example.http2.client.Http2Client -D_ -Dssl -Dport=13443)
[GC (Allocation Failure)  8704K->2567K(31744K), 0.0048808 secs]
[GC (Allocation Failure)  11271K->4654K(31744K), 0.0043717 secs]
[GC (Allocation Failure)  13358K->6590K(31744K), 0.0086735 secs]
Connected to [127.0.0.1:13443]
Oct 10, 2014 3:57:45 PM io.netty.handler.codec.http2.Http2FrameLogger log
INFO: 
----------------OUTBOUND--------------------
SETTINGS: ack=false, settings={HEADER_TABLE_SIZE=4096, ENABLE_PUSH=1, MAX_CONCURRENT_STREAMS=2147483647, INITIAL_WINDOW_SIZE=65535, MAX_FRAME_SIZE=16384, MAX_HEADER_LIST_SIZE=2147483647}
------------------------------------
Oct 10, 2014 3:57:45 PM io.netty.handler.codec.http2.Http2FrameLogger log
INFO: 
----------------INBOUND--------------------
SETTINGS: ack=false, settings={HEADER_TABLE_SIZE=4096, MAX_CONCURRENT_STREAMS=2147483647, INITIAL_WINDOW_SIZE=65535, MAX_FRAME_SIZE=16384, MAX_HEADER_LIST_SIZE=2147483647}
------------------------------------
Oct 10, 2014 3:57:45 PM io.netty.handler.codec.http2.Http2FrameLogger log
INFO: 
----------------OUTBOUND--------------------
SETTINGS ack=true
------------------------------------
Sending request(s)...
[Full GC (Ergonomics)  48062K->40805K(66560K), 0.0868109 secs]
Oct 10, 2014 3:57:46 PM io.netty.handler.codec.http2.Http2FrameLogger log
INFO: 
----------------INBOUND--------------------
SETTINGS ack=true
------------------------------------
Oct 10, 2014 3:57:46 PM io.netty.handler.codec.http2.Http2FrameLogger log
INFO: 
----------------OUTBOUND--------------------
HEADERS: streamId:3, headers=DefaultHttp2Headers[:authority: 127.0.0.1:13443, :method: GET, :path: /whatever, :scheme: https, Accept-Encoding: deflate, Accept-Encoding: gzip], streamDependency=0, weight=16, exclusive=false, padding=0, endStream=true
------------------------------------
Oct 10, 2014 3:57:46 PM io.netty.handler.codec.http2.Http2FrameLogger log
INFO: 
----------------INBOUND--------------------
HEADERS: streamId:3, headers=DefaultHttp2Headers[:status: 200], padding=0, endStream=false
------------------------------------
Exception in thread "main" java.lang.IllegalStateException: Timed out waiting for response on stream id 3
    at io.netty.example.http2.client.HttpResponseHandler.awaitResponses(HttpResponseHandler.java:67)
    at io.netty.example.http2.client.Http2Client.main(Http2Client.java:118)
[ERROR] Failed to execute goal kr.motd.maven:exec-maven-plugin:1.0.0.Final:exec (default-cli) on project netty-example: Command execution failed. Process exited with an error: 1 (Exit value: 1) -> [Help 1]
[ERROR] 
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR] 
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoExecutionException
```

@nmittler - It looks like it may be a flush issue?  I can confirm from the netty example client that it is not recieving the last partial frame partition (which happens to be non-full) when the timeout happens.

I'm using wireshark and there is alot going on with my current setup but I'm not seeing an object of the appropriate size go accross in the failure case.

@nmittler - Turns out the server example is no longer using the flow controllers properly for sending data.  The `SimpleHttp2FrameListener` is taking a raw `Http2FrameWriter` and should be using a `Http2ConnectionEncoder`.  I'll start by fixing that and see where that leaves us.

Cherry picked

@Scottmitch you've closed this issue so I'm assuming that adding flow control to the example was the fix here?

@nmittler - Yes the Netty issue I was observing where the clients were waiting for stuff to happen was resolved by ensuring flow-control was used. PR #3000 addressed this issue.

It was a different issue for my personal server but this helped me also track down my own issues ;)

@nmittler - As a result of this we can say that curl and netty are talking ;) see https://github.com/netty/netty/issues/2828

@Scottmitch I saw that ... good stuff! :)


Pull request review comments:

Patch that resolved the issue:
diff --git a/codec-http2/src/main/java/io/netty/handler/codec/http2/Http2ConnectionHandler.java b/codec-http2/src/main/java/io/netty/handler/codec/http2/Http2ConnectionHandler.java
index 7d53e3cd093..19575ec2726 100644
--- a/codec-http2/src/main/java/io/netty/handler/codec/http2/Http2ConnectionHandler.java
+++ b/codec-http2/src/main/java/io/netty/handler/codec/http2/Http2ConnectionHandler.java
@@ -64,15 +64,10 @@ public Http2ConnectionHandler(Http2Connection connection, Http2FrameReader frame
     public Http2ConnectionHandler(Http2Connection connection, Http2FrameReader frameReader,
             Http2FrameWriter frameWriter, Http2InboundFlowController inboundFlow,
             Http2OutboundFlowController outboundFlow, Http2FrameListener listener) {
-        this.encoder =
-                DefaultHttp2ConnectionEncoder.newBuilder().connection(connection)
-                        .frameWriter(frameWriter).outboundFlow(outboundFlow).lifecycleManager(this)
-                        .build();
-        this.decoder =
-                DefaultHttp2ConnectionDecoder.newBuilder().connection(connection)
-                        .frameReader(frameReader).inboundFlow(inboundFlow).encoder(encoder)
-                        .listener(listener).lifecycleManager(this).build();
-        clientPrefaceString = clientPrefaceString(connection);
+        this(DefaultHttp2ConnectionDecoder.newBuilder().connection(connection)
+                .frameReader(frameReader).inboundFlow(inboundFlow).listener(listener),
+             DefaultHttp2ConnectionEncoder.newBuilder().connection(connection)
+                .frameWriter(frameWriter).outboundFlow(outboundFlow));
     }
 
     /**
diff --git a/example/src/main/java/io/netty/example/http2/server/HelloWorldHttp2Handler.java b/example/src/main/java/io/netty/example/http2/server/HelloWorldHttp2Handler.java
index abacae15b59..8aed6610b76 100644
--- a/example/src/main/java/io/netty/example/http2/server/HelloWorldHttp2Handler.java
+++ b/example/src/main/java/io/netty/example/http2/server/HelloWorldHttp2Handler.java
@@ -28,6 +28,7 @@
 import io.netty.handler.codec.http2.DefaultHttp2FrameWriter;
 import io.netty.handler.codec.http2.DefaultHttp2Headers;
 import io.netty.handler.codec.http2.Http2Connection;
+import io.netty.handler.codec.http2.Http2ConnectionEncoder;
 import io.netty.handler.codec.http2.Http2ConnectionHandler;
 import io.netty.handler.codec.http2.Http2Exception;
 import io.netty.handler.codec.http2.Http2FrameAdapter;
@@ -52,12 +53,13 @@ public class HelloWorldHttp2Handler extends Http2ConnectionHandler {
     public HelloWorldHttp2Handler() {
         this(new DefaultHttp2Connection(true), new Http2InboundFrameLogger(
                 new DefaultHttp2FrameReader(), logger), new Http2OutboundFrameLogger(
-                new DefaultHttp2FrameWriter(), logger));
+                new DefaultHttp2FrameWriter(), logger), new SimpleHttp2FrameListener());
     }
 
     private HelloWorldHttp2Handler(Http2Connection connection, Http2FrameReader frameReader,
-            Http2FrameWriter frameWriter) {
-        super(connection, frameReader, frameWriter, new SimpleHttp2FrameListener(frameWriter));
+            Http2FrameWriter frameWriter, SimpleHttp2FrameListener listener) {
+        super(connection, frameReader, frameWriter, listener);
+        listener.encoder(encoder());
     }
 
     /**
@@ -83,10 +85,10 @@ public void exceptionCaught(ChannelHandlerContext ctx, Throwable cause) {
     }
 
     private static class SimpleHttp2FrameListener extends Http2FrameAdapter {
-        private Http2FrameWriter frameWriter;
+        private Http2ConnectionEncoder encoder;
 
-        public SimpleHttp2FrameListener(Http2FrameWriter frameWriter) {
-            this.frameWriter = frameWriter;
+        public void encoder(Http2ConnectionEncoder encoder) {
+            this.encoder = encoder;
         }
 
         /**
@@ -118,8 +120,8 @@ public void onHeadersRead(ChannelHandlerContext ctx, int streamId,
         private void sendResponse(ChannelHandlerContext ctx, int streamId, ByteBuf payload) {
             // Send a frame for the response status
             Http2Headers headers = new DefaultHttp2Headers().status(new AsciiString("200"));
-            frameWriter.writeHeaders(ctx, streamId, headers, 0, false, ctx.newPromise());
-            frameWriter.writeData(ctx, streamId, payload, 0, true, ctx.newPromise());
+            encoder.writeHeaders(ctx, streamId, headers, 0, false, ctx.newPromise());
+            encoder.writeData(ctx, streamId, payload, 0, true, ctx.newPromise());
             ctx.flush();
         }
     };


Test patch: