Improve logging and do not replay request when cauthException gets invoked as eventualy closeChannel will recover itself from it

Author: jfarcand

pom.xml

@@ -80,7 +80,6 @@
             <groupId>ch.qos.logback</groupId>
             <artifactId>logback-classic</artifactId>
             <version>0.9.26</version>
-            <scope>test</scope>
         </dependency>       
         <dependency>
             <groupId>log4j</groupId>

src/main/java/com/ning/http/client/providers/netty/NettyAsyncHttpProvider.java

@@ -100,7 +100,6 @@
 import java.net.InetSocketAddress;
 import java.net.MalformedURLException;
 import java.net.URI;
-import java.net.URISyntaxException;
 import java.nio.channels.ClosedChannelException;
 import java.nio.channels.FileChannel;
 import java.nio.channels.WritableByteChannel;
@@ -749,7 +748,7 @@ private <T> ListenableFuture<T> doConnect(final Request request, final AsyncHand
             f.setState(NettyResponseFuture.STATE.POOLED);
             f.attachChannel(channel, false);
 
-            log.debug("\nUsing cached Channel {}\n for request {}\n", channel, request);
+            log.debug("\nUsing cached Channel {}\n for request \n{}\n", channel, nettyRequest);
             channel.getPipeline().getContext(NettyAsyncHttpProvider.class).setAttachment(f);
 
             try {
@@ -824,7 +823,7 @@ private <T> ListenableFuture<T> doConnect(final Request request, final AsyncHand
             channelFuture.addListener(c);
         }
 
-        log.debug("\n\nNon cached Request {}\n with channel {}\n", request, channel);
+        log.debug("\nNon cached request \n{}\n\nusing Channel \n{}\n", c.future().getNettyRequest(), channelFuture.getChannel());
 
         if (!c.future().isCancelled() || !c.future().isDone()) {
             openChannels.add(channelFuture.getChannel());
@@ -1343,7 +1342,7 @@ protected boolean remotelyClosed(Channel channel, NettyResponseFuture<?> future)
         }
 
         if (future == null || future.cannotBeReplay()) {
-            log.debug("Unable to replay request {}\n associated with future {}\n", future == null ? "null" : future.getNettyRequest(), future);
+            log.debug("Unable to recover request {}\n associated with future {}\n", future == null ? "null" : future.getNettyRequest(), future);
             return false;
         }
 
@@ -1400,7 +1399,7 @@ public Object call() throws Exception {
     }
 
     private boolean markChannelNotReadable(final ChannelHandlerContext ctx) {
-        // Catch any unexpected exception when marking the channel.        
+        // Catch any unexpected exception when marking the channel.
         ctx.setAttachment(new DiscardEvent());
         return true;
     }
@@ -1432,6 +1431,13 @@ public void exceptionCaught(ChannelHandlerContext ctx, ExceptionEvent e)
         Throwable cause = e.getCause();
         NettyResponseFuture<?> future = null;
 
+        if (log.isDebugEnabled()) {
+            log.debug("Exception Caught: {} Attachment was {}",
+                    cause != null ? cause.getMessage() : "unavailable cause",
+                    ctx.getAttachment());
+            log.debug(cause.getMessage(), cause);
+        }
+
         try {
 
             if (cause != null && ClosedChannelException.class.isAssignableFrom(cause.getClass())) {
@@ -1454,10 +1460,8 @@ public void exceptionCaught(ChannelHandlerContext ctx, ExceptionEvent e)
                 }
 
                 if (abortOnReadCloseException(cause) || abortOnWriteCloseException(cause)) {
-                    log.debug("Trying to recover from dead Channel: {}\n request {}", channel, future.getNettyRequest());
-                    if (remotelyClosed(channel, future)) {
-                        return;
-                    }
+                    log.debug("Trying to recover from dead Channel: {}", channel);
+                    return;
                 }
             } else if (ctx.getAttachment() instanceof AsyncCallable) {
                 future = ((AsyncCallable) ctx.getAttachment()).future();
@@ -1473,13 +1477,6 @@ public void exceptionCaught(ChannelHandlerContext ctx, ExceptionEvent e)
                 log.error(t.getMessage(), t);
             }
         }
-
-        if (log.isDebugEnabled()) {
-            log.error("Exception Caught: {} Attachment was {}",
-                    cause != null ? cause.getMessage() : "unavailable cause",
-                    ctx.getAttachment());
-            log.error(cause.getMessage(), cause);
-        }
         closeChannel(ctx);
         ctx.sendUpstream(e);
     }

src/main/java/com/ning/http/client/providers/netty/NettyResponseFuture.java

@@ -16,7 +16,6 @@
 package com.ning.http.client.providers.netty;
 
 import com.ning.http.client.AsyncHandler;
-import com.ning.http.client.ListenableFuture;
 import com.ning.http.client.Request;
 import com.ning.http.client.listenable.AbstractListenableFuture;
 import org.jboss.netty.channel.Channel;
@@ -422,23 +421,22 @@ public boolean cannotBeReplay() {
     @Override
     public String toString() {
         return "NettyResponseFuture{" +
-                "latch=" + latch +
-                ", isDone=" + isDone +
-                ", isCancelled=" + isCancelled +
-                ", asyncHandler=" + asyncHandler +
-                ", responseTimeoutInMs=" + responseTimeoutInMs +
-                ", request=" + request +
-                ", nettyRequest=" + nettyRequest +
-                ", content=" + content +
-                ", uri=" + uri +
-                ", keepAlive=" + keepAlive +
-                ", httpResponse=" + httpResponse +
-                ", exEx=" + exEx +
-                ", redirectCount=" + redirectCount +
-                ", reaperFuture=" + reaperFuture +
-                ", inAuth=" + inAuth +
-                ", statusReceived=" + statusReceived +
-                ", touch=" + touch +
+                "currentRetry=" + currentRetry +
+                ",\nisDone=" + isDone +
+                ",\nisCancelled=" + isCancelled +
+                ",\nasyncHandler=" + asyncHandler +
+                ",\nresponseTimeoutInMs=" + responseTimeoutInMs +
+                ",\nnettyRequest=" + nettyRequest +
+                ",\ncontent=" + content +
+                ",\nuri=" + uri +
+                ",\nkeepAlive=" + keepAlive +
+                ",\nhttpResponse=" + httpResponse +
+                ",\nexEx=" + exEx +
+                ",\nredirectCount=" + redirectCount +
+                ",\nreaperFuture=" + reaperFuture +
+                ",\ninAuth=" + inAuth +
+                ",\nstatusReceived=" + statusReceived +
+                ",\ntouch=" + touch +
                 '}';
     }