Fix read timeout scheduling, close AsyncHttpClient#1203

Author: slandelle

client/src/main/java/org/asynchttpclient/netty/channel/DefaultChannelPool.java

@@ -224,7 +224,7 @@ public void run(Timeout timeout) throws Exception {
 
             if (LOGGER.isDebugEnabled()) {
                 long duration = unpreciseMillisTime() - start;
-                LOGGER.debug("Closed {} connections out of {} in {}ms", closedCount, totalCount, duration);
+                LOGGER.debug("Closed {} connections out of {} in {} ms", closedCount, totalCount, duration);
             }
 
             scheduleNewIdleChannelDetector(timeout.task());

client/src/main/java/org/asynchttpclient/netty/timeout/RequestTimeoutTimerTask.java

@@ -43,7 +43,7 @@ public void run(Timeout timeout) throws Exception {
         if (nettyResponseFuture.isDone())
             return;
 
-        String message = "Request timeout to " + timeoutsHolder.remoteAddress() + " after " + requestTimeout + "ms";
+        String message = "Request timeout to " + timeoutsHolder.remoteAddress() + " after " + requestTimeout + " ms";
         long age = unpreciseMillisTime() - nettyResponseFuture.getStart();
         expire(message, age);
     }

client/src/main/java/org/asynchttpclient/netty/timeout/TimeoutsHolder.java

@@ -71,7 +71,7 @@ public void startReadTimeout() {
     }
 
     void startReadTimeout(ReadTimeoutTimerTask task) {
-        if (requestTimeout == null || (!requestTimeout.isExpired() && readTimeoutValue > (requestTimeoutMillisTime - unpreciseMillisTime()))) {
+        if (requestTimeout == null || (!requestTimeout.isExpired() && readTimeoutValue < (requestTimeoutMillisTime - unpreciseMillisTime()))) {
             // only schedule a new readTimeout if the requestTimeout doesn't happen first
             if (task == null) {
                 // first call triggered from outside (else is read timeout is re-scheduling itself)

client/src/test/java/org/asynchttpclient/PerRequestTimeoutTest.java

@@ -43,10 +43,13 @@
 public class PerRequestTimeoutTest extends AbstractBasicTest {
     private static final String MSG = "Enough is enough.";
 
-    private void checkTimeoutMessage(String message) {
-        assertTrue(message.startsWith("Request timeout"), "error message indicates reason of error but got: " + message);
+    private void checkTimeoutMessage(String message, boolean requestTimeout) {
+        if (requestTimeout)
+            assertTrue(message.startsWith("Request timeout"), "error message indicates reason of error but got: " + message);
+        else
+            assertTrue(message.startsWith("Read timeout"), "error message indicates reason of error but got: " + message);
         assertTrue(message.contains("localhost"), "error message contains remote host address but got: " + message);
-        assertTrue(message.contains("after 100ms"), "error message contains timeout configuration value but got: " + message);
+        assertTrue(message.contains("after 100 ms"), "error message contains timeout configuration value but got: " + message);
     }
 
     @Override
@@ -100,7 +103,23 @@ public void testRequestTimeout() throws IOException {
             fail("Interrupted.", e);
         } catch (ExecutionException e) {
             assertTrue(e.getCause() instanceof TimeoutException);
-            checkTimeoutMessage(e.getCause().getMessage());
+            checkTimeoutMessage(e.getCause().getMessage(), true);
+        } catch (TimeoutException e) {
+            fail("Timeout.", e);
+        }
+    }
+
+    @Test(groups = "standalone")
+    public void testReadTimeout() throws IOException {
+        try (AsyncHttpClient client = asyncHttpClient(config().setReadTimeout(100))) {
+            Future<Response> responseFuture = client.prepareGet(getTargetUrl()).execute();
+            Response response = responseFuture.get(2000, TimeUnit.MILLISECONDS);
+            assertNull(response);
+        } catch (InterruptedException e) {
+            fail("Interrupted.", e);
+        } catch (ExecutionException e) {
+            assertTrue(e.getCause() instanceof TimeoutException);
+            checkTimeoutMessage(e.getCause().getMessage(), false);
         } catch (TimeoutException e) {
             fail("Timeout.", e);
         }
@@ -116,7 +135,7 @@ public void testGlobalDefaultPerRequestInfiniteTimeout() throws IOException {
             fail("Interrupted.", e);
         } catch (ExecutionException e) {
             assertTrue(e.getCause() instanceof TimeoutException);
-            checkTimeoutMessage(e.getCause().getMessage());
+            checkTimeoutMessage(e.getCause().getMessage(), true);
         }
     }
 
@@ -130,7 +149,7 @@ public void testGlobalRequestTimeout() throws IOException {
             fail("Interrupted.", e);
         } catch (ExecutionException e) {
             assertTrue(e.getCause() instanceof TimeoutException);
-            checkTimeoutMessage(e.getCause().getMessage());
+            checkTimeoutMessage(e.getCause().getMessage(), true);
         } catch (TimeoutException e) {
             fail("Timeout.", e);
         }