Repository: netty/netty
Issue: ChannelOption.AUTO_CLOSE javadoc default value incorrect
Labels: cleanup

- Netty 4.0.33 (client)
- Jetty 9.3 (server)
- OSX 10.11.1
- Hotspot 1.8.0_66

Hi,

I ran into an issue while trying to upgrade AsyncHttpClient test suite to Jetty 9.3, see https://github.com/AsyncHttpClient/async-http-client/issues/1035.

The test is about sending a small `ChunkedStream` to a Jetty server expecting Basic auth, without providing the Authorization header. In this case, Jetty will respond with 401 and then close the socket as soon as it receives the headers and realize Authorization is missing.

It seems that Netty (or JDK NIO?) randomly fails to read the HTTP response and directly jumps to closing the socket.
It checked with Wireshark and Jetty indeed sends the expected 401 response first before FIN.

Please have a look at this reproducer (**client is pure Netty, not AHC**): https://github.com/slandelle/netty-missing-events-issue

Note that running from `mvn test` from the terminal seems to increase the failure likelihood.

Regards


Issue comments:
Will check soon

> Am 18.11.2015 um 14:01 schrieb Stephane Landelle notifications@github.com:
> 
> Netty 4.0.33 (client)
> Jetty 9.3 (server)
> OSX 10.11.1
> Hotspot 1.8.0_66
> AUTO_READ is set to false, read is manually triggered from channelActive and readComplete 
> Hi,
> 
> I ran into an issue while trying to upgrade AsyncHttpClient test suite to Jetty 9.3, see AsyncHttpClient/async-http-client#1035.
> 
> The test is about sending a small ChunkedStream to a Jetty server expecting Basic auth, without providing the Authorization header. In this case, Jetty will respond with 401 and then close the socket as soon as it receives the headers and realize Authorization is missing.
> 
> It seems that Netty (or JDK NIO?) randomly fails to read the HTTP response and directly jumps to closing the socket.
> It checked with Wireshark and Jetty indeed sends the expected 401 response.
> 
> Please have a look at this reproducer (client is pure Netty, not AHC): https://github.com/slandelle/netty-missing-events-issue
> 
> Note that running from mvn test from the terminal seems to increase the failure probability.
> 
> Regards
> 
> —
> Reply to this email directly or view it on GitHub.

@normanmaurer Thanks!

Note: I removed the auto_read disabling comment and updated the code as I can reproduce without.

@slandelle - I took a look at the Netty unit test you linked above. Let me describe the behavior I am seeing and you can confirm if this is what you are seeing:

`testUnauthenticatedGetThenChunkedPostWtf` test behavior:
1. Client sends GET request
2. Server responds with 401 (with some body)
3. Client reads 401.
 3.1 MyHandler.read() called with `DefaultHttpResponse`
 3.2 Myhandler.read() called with `DefaultLastHttpContent` (319 bytes)
4. Client sends POST request (chunked encoding) `4\r\ntest\r\r\n`)
5. Client detects that channel is inactive, `MyHandler.channelInactive` prints out `Channel became inactive before reading anything!!!`.

At some point after 4 the server closes the connection. The code that initiates step 4 above is in a listener when the connection is established, and a flush operation (`channel.writeAndFlush(LastHttpContent.EMPTY_LAST_CONTENT)`) fails with a `java.io.IOException: Broken pipe` in [AbstractChannel](https://github.com/netty/netty/blob/4.0/transport/src/main/java/io/netty/channel/AbstractChannel.java#L776).

I'll need to think about what can be done at this point. Can we close just the outbound portion of the channel? Should we be completing the close promise before we attempt a read? @normanmaurer - Does this make sense?

@Scottmitch just so I understand it correctly... Jetty closes the channel before we are done writing ?

@Scottmitch @normanmaurer Thanks for taking a look.

I've just pushed a new commit on the issue demo, to make sure I don't try to recreate a Jetty server.

Beware that every request creates a new client instance with its own event loop and bootstrap.

I should have been more explicit:
- `testUnauthenticatedGet` and `testUnauthenticatedChunkedPost` are only there to show that, taken separately, those are more likely to succeed.
- `testUnauthenticatedGetThenChunkedPostWtf` basically runs the previous two, but for some reason, is more likely to fail.

So, regarding your sequence, please note that [1, 3] happen in a first (event loop, bootstrap) while [4, 5] happen in a second one.

To be more specific:
1. First client instance opens new Channel
2. First client sends GET request
3. Server responds with 401 (with some body) and closes the socket
4. First client reads 401.
4.1 First client: MyHandler.read() called with DefaultHttpResponse
4.2 First client: Myhandler.read() called with DefaultLastHttpContent (319 bytes)
5. First client gets closed
6. Second client instance opens new Channel
7. Second client sends POST request (chunked encoding) 4\r\ntest\r\r\n)
8. Server responds with 401 (with some body) and closes the socket
9. Client detects that channel is inactive, MyHandler.channelInactive prints out Channel became inactive before reading anything!!!
10. Test fails with:

```
testUnauthenticatedGetThenChunkedPostWtf(io.gatling.issues.MissingEventsTest)  Time elapsed: 0.015 sec  <<< FAILURE!
java.lang.AssertionError: Should have been able to send request and read response
    at org.junit.Assert.fail(Assert.java:88)
    at org.junit.Assert.assertTrue(Assert.java:41)
    at io.gatling.issues.MissingEventsTest.doTest(MissingEventsTest.java:37)
    at io.gatling.issues.MissingEventsTest.testUnauthenticatedGetThenChunkedPostWtf(MissingEventsTest.java:54)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
    at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
    at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
    at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:252)
    at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:141)
    at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:112)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:189)
    at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:165)
    at org.apache.maven.surefire.booter.ProviderFactory.invokeProvider(ProviderFactory.java:85)
    at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:115)
    at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:75)
```

> Note: Failure is very random. Test can pass 10 times, then fail 3 times in a row.

@slandelle - Yip. The details you added are the same I'm seeing on my end.

Can you add `.option(ChannelOption.AUTO_CLOSE, false);`  to your bootstrap and let me know if this gives the expected behavior? 

@slandelle - Also I know this is just an example but I also changed your `channelRead` to make sure there was no premature close.

``` java
@Override
public void channelRead(ChannelHandlerContext ctx, Object msg) throws Exception {
   read = true;
   if (msg instanceof LastHttpContent) {
     ctx.close();
   }
}
```

@Scottmitch Bull's eye, explicitly setting `AUTO_CLOSE` to false did the trick! I run 30 times without being able to reproduce.

Then, I don't get it. `AUTO_CLOSE`'s javadoc says `false` is the default value.

@slandelle - Thanks for pointing out the javadoc error. The "real" default is [true](https://github.com/netty/netty/blob/4.0/transport/src/main/java/io/netty/channel/DefaultChannelConfig.java#L62) :wink:. Let me update the docs so they are not misleading. We can debate what the default should be as part of another issue if necessary.

See https://github.com/netty/netty/pull/4510

@slandelle - I'll close this for now. Please re-open (or open another issue) if the issue pops back up.

@Scottmitch Isn't there anything to do to respect temporality?
I mean that the response was received BEFORE the socket got closed and the next chunk write failed.

Then, what's the behaviour when AUTO_READ is disabled? I mean that it doesn't seem that `exceptionCaught` is notified.

And, I'd really like to hear your opinion on what the default should be. What's the impact if I make AUTO_READ the default in AsyncHttpClient?

> I mean that the response was received BEFORE the socket got closed and the next chunk write failed.....I mean that it doesn't seem that exceptionCaught is notified.

For "outbound" operations generally the promise associated with that operation is failed and `fireExceptionCaught` is not called.  This behavior was recently "clarified" in PR https://github.com/netty/netty/pull/4498.

> Then, what's the behaviour when AUTO_READ is disabled?

I wouldn't expect the behavior to change, other than you must explicitly call `read()`.  When you call `read()` you should get the data, and if the socket is "not suitable for reading" anymore when you call `read()` you should get a `channelInactive()` (and maybe an `exceptionCaught`).

> And, I'd really like to hear your opinion on what the default should be.

I think the default from Netty's perspective (in 4.0 and 4.1) for `AUTO_CLOSE` has to remain `true` to avoid changing the existing behavior (established [a while ago](https://github.com/netty/netty/blame/4.0/transport/src/main/java/io/netty/channel/DefaultChannelConfig.java#L62)).

> What's the impact if I make AUTO_READ the default in AsyncHttpClient?

(caveat - I'm not familiar with the details of AHC.)  Generally turning AUTO_READ off just allows the user of Netty to determine when `read()` is called.  Can explain what your are trying to do by turning auto_read off and what your trigger points will be for reading?

Sorry, late here: I meant AUTO_CLOSE, not AUTO_READ...

@slandelle - Thanks for clarifying. Changing `AUTO_CLOSE` to false will just mean that failures to write will not automatically close the transport (for situations like these). This can be useful for "half closed" situations like the one uncovered in your unit test.  I would imagine AHC would want `AUTO_CLOSE` set to `false` to handle this type of scenario and avoid potentially losing data.

@Scottmitch But does this mean that I then am in charge of closing the channel?

@slandelle - As a result of write failures yes. However you will still get notified if problems are detected on the read side.

@Scottmitch Thanks a lot for your explanations


Pull request review comments:

Patch that resolved the issue:
diff --git a/transport/src/main/java/io/netty/channel/ChannelOption.java b/transport/src/main/java/io/netty/channel/ChannelOption.java
index 08af650cfaa..1695631f50c 100644
--- a/transport/src/main/java/io/netty/channel/ChannelOption.java
+++ b/transport/src/main/java/io/netty/channel/ChannelOption.java
@@ -33,7 +33,6 @@
 public class ChannelOption<T> extends AbstractConstant<ChannelOption<T>> {
 
     private static final ConstantPool<ChannelOption<Object>> pool = new ConstantPool<ChannelOption<Object>>() {
-        @SuppressWarnings("deprecation")
         @Override
         protected ChannelOption<Object> newConstant(int id, String name) {
             return new ChannelOption<Object>(id, name);
@@ -91,8 +90,8 @@ public static <T> ChannelOption<T> newInstance(String name) {
     /**
      * @deprecated From version 5.0, {@link Channel} will not be closed on write failure.
      *
-     * {@code true} if and only if the {@link Channel} is closed automatically and immediately on write failure.
-     * The default is {@code false}.
+     * If {@code true} then the {@link Channel} is closed automatically and immediately on write failure.
+     * The default value is {@code true}.
      */
     @Deprecated
     public static final ChannelOption<Boolean> AUTO_CLOSE = valueOf("AUTO_CLOSE");


Test patch: