You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@hc.apache.org by ol...@apache.org on 2017/10/16 21:03:45 UTC

[4/8] httpcomponents-client git commit: Revised HTTP cache debug logging

Revised HTTP cache debug logging


Project: http://git-wip-us.apache.org/repos/asf/httpcomponents-client/repo
Commit: http://git-wip-us.apache.org/repos/asf/httpcomponents-client/commit/74ed4dfe
Tree: http://git-wip-us.apache.org/repos/asf/httpcomponents-client/tree/74ed4dfe
Diff: http://git-wip-us.apache.org/repos/asf/httpcomponents-client/diff/74ed4dfe

Branch: refs/heads/master
Commit: 74ed4dfebfe5df8de7ee3a16a75cb21062efe8a2
Parents: 30320fe
Author: Oleg Kalnichevski <ol...@apache.org>
Authored: Sun Oct 15 13:44:51 2017 +0200
Committer: Oleg Kalnichevski <ol...@apache.org>
Committed: Mon Oct 16 23:00:19 2017 +0200

----------------------------------------------------------------------
 .../http/impl/cache/AsyncCachingExec.java       |  8 +-
 .../http/impl/cache/CacheInvalidator.java       | 18 ++--
 .../http/impl/cache/CacheableRequestPolicy.java | 23 +++--
 .../cache/CachedResponseSuitabilityChecker.java | 18 ++--
 .../hc/client5/http/impl/cache/CachingExec.java |  7 +-
 .../http/impl/cache/CachingExecBase.java        |  8 +-
 .../http/impl/cache/ResponseCachingPolicy.java  | 95 +++++++++++---------
 7 files changed, 99 insertions(+), 78 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/httpcomponents-client/blob/74ed4dfe/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/AsyncCachingExec.java
----------------------------------------------------------------------
diff --git a/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/AsyncCachingExec.java b/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/AsyncCachingExec.java
index 104ca75..36aedaa 100644
--- a/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/AsyncCachingExec.java
+++ b/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/AsyncCachingExec.java
@@ -238,7 +238,7 @@ public class AsyncCachingExec extends CachingExecBase implements AsyncExecChainH
             final AsyncExecChain.Scope scope,
             final AsyncExecChain chain,
             final InternalCallback asyncExecCallback) throws HttpException, IOException {
-        log.trace("Calling the backend");
+        log.debug("Calling the backend");
         final Date requestDate = getCurrentDate();
         chain.proceed(request, entityProducer, scope, new AsyncExecCallback() {
 
@@ -253,7 +253,6 @@ public class AsyncCachingExec extends CachingExecBase implements AsyncExecChainH
                 final Date responseDate = getCurrentDate();
                 backendResponse.addHeader("Via", generateViaHeader(backendResponse));
 
-                log.trace("Handling Backend response");
                 responseCompliance.ensureProtocolCompliance(scope.originalRequest, request, backendResponse);
 
                 final boolean cacheable = asyncExecCallback.cacheResponse(backendResponse)
@@ -265,6 +264,7 @@ public class AsyncCachingExec extends CachingExecBase implements AsyncExecChainH
                         bufferRef.set(new ByteArrayBuffer(1024));
                     }
                 } else {
+                    log.debug("Backend response is not cacheable");
                     try {
                         responseCache.flushCacheEntriesFor(target, request);
                     } catch (final IOException ioe) {
@@ -272,10 +272,12 @@ public class AsyncCachingExec extends CachingExecBase implements AsyncExecChainH
                     }
                 }
                 if (bufferRef.get() != null) {
+                    log.debug("Caching backend response");
                     if (entityDetails == null) {
                         scope.execRuntime.releaseConnection();
                         final HttpCacheEntry entry = responseCache.createCacheEntry(
                                 target, request, backendResponse, null, requestDate, responseDate);
+                        log.debug("Backend response successfully cached");
                         responseRef.set(responseGenerator.generateResponse(request, entry));
                         return null;
                     } else {
@@ -303,6 +305,7 @@ public class AsyncCachingExec extends CachingExecBase implements AsyncExecChainH
                                         }
                                     }
                                     if (buffer.length() > cacheConfig.getMaxObjectSize()) {
+                                        log.debug("Backend response content length exceeds maximum");
                                         // Over the max limit. Stop buffering and forward the response
                                         // along with all the data buffered so far to the caller.
                                         bufferRef.set(null);
@@ -339,6 +342,7 @@ public class AsyncCachingExec extends CachingExecBase implements AsyncExecChainH
                                 if (buffer != null) {
                                     final HttpCacheEntry entry = responseCache.createCacheEntry(
                                             target, request, backendResponse, buffer, requestDate, responseDate);
+                                    log.debug("Backend response successfully cached");
                                     responseRef.set(responseGenerator.generateResponse(request, entry));
                                 }
                             }

http://git-wip-us.apache.org/repos/asf/httpcomponents-client/blob/74ed4dfe/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CacheInvalidator.java
----------------------------------------------------------------------
diff --git a/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CacheInvalidator.java b/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CacheInvalidator.java
index 9ba1fc4..09638c9 100644
--- a/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CacheInvalidator.java
+++ b/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CacheInvalidator.java
@@ -64,13 +64,13 @@ class CacheInvalidator implements HttpCacheInvalidator {
      * Create a new {@link CacheInvalidator} for a given {@link HttpCache} and
      * {@link CacheKeyGenerator}.
      *
-     * @param uriExtractor Provides identifiers for the keys to store cache entries
+     * @param cacheKeyGenerator Provides identifiers for the keys to store cache entries
      * @param storage the cache to store items away in
      */
     public CacheInvalidator(
-            final CacheKeyGenerator uriExtractor,
+            final CacheKeyGenerator cacheKeyGenerator,
             final HttpCacheStorage storage) {
-        this.cacheKeyGenerator = uriExtractor;
+        this.cacheKeyGenerator = cacheKeyGenerator;
         this.storage = storage;
     }
 
@@ -83,18 +83,20 @@ class CacheInvalidator implements HttpCacheInvalidator {
      */
     @Override
     public void flushInvalidatedCacheEntries(final HttpHost host, final HttpRequest req)  {
-        final String theUri = cacheKeyGenerator.generateKey(host, req);
-        final HttpCacheEntry parent = getEntry(theUri);
+        final String key = cacheKeyGenerator.generateKey(host, req);
+        final HttpCacheEntry parent = getEntry(key);
 
         if (requestShouldNotBeCached(req) || shouldInvalidateHeadCacheEntry(req, parent)) {
-            log.debug("Invalidating parent cache entry: " + parent);
+            if (log.isDebugEnabled()) {
+                log.debug("Invalidating parent cache entry: " + parent);
+            }
             if (parent != null) {
                 for (final String variantURI : parent.getVariantMap().values()) {
                     flushEntry(variantURI);
                 }
-                flushEntry(theUri);
+                flushEntry(key);
             }
-            final URL reqURL = getAbsoluteURL(theUri);
+            final URL reqURL = getAbsoluteURL(key);
             if (reqURL == null) {
                 log.error("Couldn't transform request into valid URL");
                 return;

http://git-wip-us.apache.org/repos/asf/httpcomponents-client/blob/74ed4dfe/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CacheableRequestPolicy.java
----------------------------------------------------------------------
diff --git a/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CacheableRequestPolicy.java b/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CacheableRequestPolicy.java
index b22c54e..e1d0a69 100644
--- a/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CacheableRequestPolicy.java
+++ b/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CacheableRequestPolicy.java
@@ -61,37 +61,34 @@ class CacheableRequestPolicy {
 
         final ProtocolVersion pv = request.getVersion() != null ? request.getVersion() : HttpVersion.DEFAULT;
         if (HttpVersion.HTTP_1_1.compareToVersion(pv) != 0) {
-            log.trace("non-HTTP/1.1 request was not serveable from cache");
+            log.debug("non-HTTP/1.1 request is not serveable from cache");
             return false;
         }
 
-        if (!(method.equals(HeaderConstants.GET_METHOD) || method
-                .equals(HeaderConstants.HEAD_METHOD))) {
-            log.trace("non-GET or non-HEAD request was not serveable from cache");
+        if (!method.equals(HeaderConstants.GET_METHOD) && !method.equals(HeaderConstants.HEAD_METHOD)) {
+            log.debug(method + " request is not serveable from cache");
             return false;
         }
 
-        if (request.getHeaders(HeaderConstants.PRAGMA).length > 0) {
-            log.trace("request with Pragma header was not serveable from cache");
+        if (request.containsHeaders(HeaderConstants.PRAGMA) > 0) {
+            log.debug("request with Pragma header is not serveable from cache");
             return false;
         }
 
         final Iterator<HeaderElement> it = MessageSupport.iterate(request, HeaderConstants.CACHE_CONTROL);
         while (it.hasNext()) {
             final HeaderElement cacheControlElement = it.next();
-            if (HeaderConstants.CACHE_CONTROL_NO_STORE.equalsIgnoreCase(cacheControlElement
-                    .getName())) {
-                log.trace("Request with no-store was not serveable from cache");
+            if (HeaderConstants.CACHE_CONTROL_NO_STORE.equalsIgnoreCase(cacheControlElement.getName())) {
+                log.debug("Request with no-store is not serveable from cache");
                 return false;
             }
-            if (HeaderConstants.CACHE_CONTROL_NO_CACHE.equalsIgnoreCase(cacheControlElement
-                    .getName())) {
-                log.trace("Request with no-cache was not serveable from cache");
+            if (HeaderConstants.CACHE_CONTROL_NO_CACHE.equalsIgnoreCase(cacheControlElement.getName())) {
+                log.debug("Request with no-cache is not serveable from cache");
                 return false;
             }
         }
 
-        log.trace("Request was serveable from cache");
+        log.debug("Request is serveable from cache");
         return true;
     }
 

http://git-wip-us.apache.org/repos/asf/httpcomponents-client/blob/74ed4dfe/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CachedResponseSuitabilityChecker.java
----------------------------------------------------------------------
diff --git a/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CachedResponseSuitabilityChecker.java b/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CachedResponseSuitabilityChecker.java
index f5dff51..4754f04 100644
--- a/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CachedResponseSuitabilityChecker.java
+++ b/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CachedResponseSuitabilityChecker.java
@@ -146,7 +146,7 @@ class CachedResponseSuitabilityChecker {
      */
     public boolean canCachedResponseBeUsed(final HttpHost host, final HttpRequest request, final HttpCacheEntry entry, final Date now) {
         if (!isFreshEnough(entry, request, now)) {
-            log.trace("Cache entry was not fresh enough");
+            log.debug("Cache entry is not fresh enough");
             return false;
         }
 
@@ -156,15 +156,17 @@ class CachedResponseSuitabilityChecker {
         }
 
         if (hasUnsupportedConditionalHeaders(request)) {
-            log.debug("Request contained conditional headers we don't handle");
+            log.debug("Request contains unsupported conditional headers");
             return false;
         }
 
         if (!isConditional(request) && entry.getStatus() == HttpStatus.SC_NOT_MODIFIED) {
+            log.debug("Unconditional request and non-modified cached response");
             return false;
         }
 
         if (isConditional(request) && !allConditionalsMatch(request, entry, now)) {
+            log.debug("Conditional request and with mismatched conditions");
             return false;
         }
 
@@ -177,12 +179,12 @@ class CachedResponseSuitabilityChecker {
         while (it.hasNext()) {
             final HeaderElement elt = it.next();
             if (HeaderConstants.CACHE_CONTROL_NO_CACHE.equals(elt.getName())) {
-                log.trace("Response contained NO CACHE directive, cache was not suitable");
+                log.debug("Response contained NO CACHE directive, cache was not suitable");
                 return false;
             }
 
             if (HeaderConstants.CACHE_CONTROL_NO_STORE.equals(elt.getName())) {
-                log.trace("Response contained NO STORE directive, cache was not suitable");
+                log.debug("Response contained NO STORE directive, cache was not suitable");
                 return false;
             }
 
@@ -190,7 +192,7 @@ class CachedResponseSuitabilityChecker {
                 try {
                     final int maxage = Integer.parseInt(elt.getValue());
                     if (validityStrategy.getCurrentAgeSecs(entry, now) > maxage) {
-                        log.trace("Response from cache was NOT suitable due to max age");
+                        log.debug("Response from cache was NOT suitable due to max age");
                         return false;
                     }
                 } catch (final NumberFormatException ex) {
@@ -204,7 +206,7 @@ class CachedResponseSuitabilityChecker {
                 try {
                     final int maxstale = Integer.parseInt(elt.getValue());
                     if (validityStrategy.getFreshnessLifetimeSecs(entry) > maxstale) {
-                        log.trace("Response from cache was not suitable due to Max stale freshness");
+                        log.debug("Response from cache was not suitable due to Max stale freshness");
                         return false;
                     }
                 } catch (final NumberFormatException ex) {
@@ -223,7 +225,7 @@ class CachedResponseSuitabilityChecker {
                     final long age = validityStrategy.getCurrentAgeSecs(entry, now);
                     final long freshness = validityStrategy.getFreshnessLifetimeSecs(entry);
                     if (freshness - age < minfresh) {
-                        log.trace("Response from cache was not suitable due to min fresh " +
+                        log.debug("Response from cache was not suitable due to min fresh " +
                                 "freshness requirement");
                         return false;
                     }
@@ -235,7 +237,7 @@ class CachedResponseSuitabilityChecker {
             }
         }
 
-        log.trace("Response from cache was suitable");
+        log.debug("Response from cache was suitable");
         return true;
     }
 

http://git-wip-us.apache.org/repos/asf/httpcomponents-client/blob/74ed4dfe/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CachingExec.java
----------------------------------------------------------------------
diff --git a/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CachingExec.java b/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CachingExec.java
index e4b59e4..d5e06c5 100644
--- a/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CachingExec.java
+++ b/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CachingExec.java
@@ -213,7 +213,7 @@ public class CachingExec extends CachingExecBase implements ExecChainHandler {
 
         final Date requestDate = getCurrentDate();
 
-        log.trace("Calling the backend");
+        log.debug("Calling the backend");
         final ClassicHttpResponse backendResponse = chain.proceed(request, scope);
         try {
             backendResponse.addHeader("Via", generateViaHeader(backendResponse));
@@ -337,7 +337,6 @@ public class CachingExec extends CachingExecBase implements ExecChainHandler {
             final Date responseDate,
             final ClassicHttpResponse backendResponse) throws IOException {
 
-        log.trace("Handling Backend response");
         responseCompliance.ensureProtocolCompliance(scope.originalRequest, request, backendResponse);
 
         final boolean cacheable = responseCachingPolicy.isResponseCacheable(request, backendResponse);
@@ -347,6 +346,7 @@ public class CachingExec extends CachingExecBase implements ExecChainHandler {
             return cacheAndReturnResponse(target, request, backendResponse, requestDate, responseDate);
         }
         if (!cacheable) {
+            log.debug("Backend response is not cacheable");
             try {
                 responseCache.flushCacheEntriesFor(target, request);
             } catch (final IOException ioe) {
@@ -362,6 +362,7 @@ public class CachingExec extends CachingExecBase implements ExecChainHandler {
             final ClassicHttpResponse backendResponse,
             final Date requestSent,
             final Date responseReceived) throws IOException {
+        log.debug("Caching backend response");
         final ByteArrayBuffer buf;
         final HttpEntity entity = backendResponse.getEntity();
         if (entity != null) {
@@ -374,6 +375,7 @@ public class CachingExec extends CachingExecBase implements ExecChainHandler {
                 buf.append(tmp, 0, l);
                 total += l;
                 if (total > cacheConfig.getMaxObjectSize()) {
+                    log.debug("Backend response content length exceeds maximum");
                     backendResponse.setEntity(new CombinedEntity(entity, buf));
                     return backendResponse;
                 }
@@ -383,6 +385,7 @@ public class CachingExec extends CachingExecBase implements ExecChainHandler {
         }
         backendResponse.close();
         final HttpCacheEntry entry = responseCache.createCacheEntry(target, request, backendResponse, buf, requestSent, responseReceived);
+        log.debug("Backend response successfully cached");
         return convert(responseGenerator.generateResponse(request, entry));
     }
 

http://git-wip-us.apache.org/repos/asf/httpcomponents-client/blob/74ed4dfe/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CachingExecBase.java
----------------------------------------------------------------------
diff --git a/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CachingExecBase.java b/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CachingExecBase.java
index 1ab84d6..d823513 100644
--- a/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CachingExecBase.java
+++ b/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/CachingExecBase.java
@@ -177,21 +177,21 @@ public class CachingExecBase {
     void recordCacheMiss(final HttpHost target, final HttpRequest request) {
         cacheMisses.getAndIncrement();
         if (log.isTraceEnabled()) {
-            log.trace("Cache miss [host: " + target + "; uri: " + request.getRequestUri() + "]");
+            log.debug("Cache miss [host: " + target + "; uri: " + request.getRequestUri() + "]");
         }
     }
 
     void recordCacheHit(final HttpHost target, final HttpRequest request) {
         cacheHits.getAndIncrement();
         if (log.isTraceEnabled()) {
-            log.trace("Cache hit [host: " + target + "; uri: " + request.getRequestUri() + "]");
+            log.debug("Cache hit [host: " + target + "; uri: " + request.getRequestUri() + "]");
         }
     }
 
     void recordCacheFailure(final HttpHost target, final HttpRequest request) {
         cacheMisses.getAndIncrement();
         if (log.isTraceEnabled()) {
-            log.trace("Cache failure [host: " + target + "; uri: " + request.getRequestUri() + "]");
+            log.debug("Cache failure [host: " + target + "; uri: " + request.getRequestUri() + "]");
         }
     }
 
@@ -266,7 +266,7 @@ public class CachingExecBase {
         while (it.hasNext()) {
             final HeaderElement elt = it.next();
             if ("only-if-cached".equals(elt.getName())) {
-                log.trace("Request marked only-if-cached");
+                log.debug("Request marked only-if-cached");
                 return false;
             }
         }

http://git-wip-us.apache.org/repos/asf/httpcomponents-client/blob/74ed4dfe/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/ResponseCachingPolicy.java
----------------------------------------------------------------------
diff --git a/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/ResponseCachingPolicy.java b/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/ResponseCachingPolicy.java
index 3c4fff9..37d8a97 100644
--- a/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/ResponseCachingPolicy.java
+++ b/httpclient5-cache/src/main/java/org/apache/hc/client5/http/impl/cache/ResponseCachingPolicy.java
@@ -60,17 +60,20 @@ class ResponseCachingPolicy {
     private static final String[] AUTH_CACHEABLE_PARAMS = {
             "s-maxage", HeaderConstants.CACHE_CONTROL_MUST_REVALIDATE, HeaderConstants.PUBLIC
     };
+
+    private final static Set<Integer> CACHEABLE_STATUS_CODES =
+            new HashSet<>(Arrays.asList(HttpStatus.SC_OK,
+                    HttpStatus.SC_NON_AUTHORITATIVE_INFORMATION,
+                    HttpStatus.SC_MULTIPLE_CHOICES,
+                    HttpStatus.SC_MOVED_PERMANENTLY,
+                    HttpStatus.SC_GONE));
+
+    private final Logger log = LogManager.getLogger(getClass());
+
     private final long maxObjectSizeBytes;
     private final boolean sharedCache;
     private final boolean neverCache1_0ResponsesWithQueryString;
-    private final Logger log = LogManager.getLogger(getClass());
-    private static final Set<Integer> cacheableStatuses =
-        new HashSet<>(Arrays.asList(HttpStatus.SC_OK,
-                HttpStatus.SC_NON_AUTHORITATIVE_INFORMATION,
-                HttpStatus.SC_MULTIPLE_CHOICES,
-                HttpStatus.SC_MOVED_PERMANENTLY,
-                HttpStatus.SC_GONE));
-    private final Set<Integer> uncacheableStatuses;
+    private final Set<Integer> uncacheableStatusCodes;
 
     /**
      * Define a cache policy that limits the size of things that should be stored
@@ -91,11 +94,9 @@ class ResponseCachingPolicy {
         this.sharedCache = sharedCache;
         this.neverCache1_0ResponsesWithQueryString = neverCache1_0ResponsesWithQueryString;
         if (allow303Caching) {
-            uncacheableStatuses = new HashSet<>(
-                    Arrays.asList(HttpStatus.SC_PARTIAL_CONTENT));
+            uncacheableStatusCodes = new HashSet<>(Arrays.asList(HttpStatus.SC_PARTIAL_CONTENT));
         } else {
-            uncacheableStatuses = new HashSet<>(Arrays.asList(
-                    HttpStatus.SC_PARTIAL_CONTENT, HttpStatus.SC_SEE_OTHER));
+            uncacheableStatusCodes = new HashSet<>(Arrays.asList(HttpStatus.SC_PARTIAL_CONTENT, HttpStatus.SC_SEE_OTHER));
         }
     }
 
@@ -109,21 +110,28 @@ class ResponseCachingPolicy {
     public boolean isResponseCacheable(final String httpMethod, final HttpResponse response) {
         boolean cacheable = false;
 
-        if (!(HeaderConstants.GET_METHOD.equals(httpMethod) ||
-                HeaderConstants.HEAD_METHOD.equals(httpMethod))) {
-            log.debug("Response was not cacheable.");
+        if (!HeaderConstants.GET_METHOD.equals(httpMethod) && !HeaderConstants.HEAD_METHOD.equals(httpMethod)) {
+            if (log.isDebugEnabled()) {
+                log.debug(httpMethod + " method response is not cacheable");
+            }
             return false;
         }
 
         final int status = response.getCode();
-        if (cacheableStatuses.contains(status)) {
+        if (CACHEABLE_STATUS_CODES.contains(status)) {
             // these response codes MAY be cached
             cacheable = true;
-        } else if (uncacheableStatuses.contains(status)) {
+        } else if (uncacheableStatusCodes.contains(status)) {
+            if (log.isDebugEnabled()) {
+                log.debug(status + " response is not cacheable");
+            }
             return false;
         } else if (unknownStatusCode(status)) {
             // a response with an unknown status code MUST NOT be
             // cached
+            if (log.isDebugEnabled()) {
+                log.debug(status + " response is unknown");
+            }
             return false;
         }
 
@@ -131,30 +139,32 @@ class ResponseCachingPolicy {
         if (contentLength != null) {
             final long contentLengthValue = Long.parseLong(contentLength.getValue());
             if (contentLengthValue > this.maxObjectSizeBytes) {
+                if (log.isDebugEnabled()) {
+                    log.debug("Response content length exceeds " + this.maxObjectSizeBytes);
+                }
                 return false;
             }
         }
 
-        final Header[] ageHeaders = response.getHeaders(HeaderConstants.AGE);
-
-        if (ageHeaders.length > 1) {
+        if (response.containsHeaders(HeaderConstants.AGE) > 1) {
+            log.debug("Multiple Age headers");
             return false;
         }
 
-        final Header[] expiresHeaders = response.getHeaders(HeaderConstants.EXPIRES);
-
-        if (expiresHeaders.length > 1) {
+        if (response.containsHeaders(HeaderConstants.EXPIRES) > 1) {
+            log.debug("Multiple Expires headers");
             return false;
         }
 
-        final Header[] dateHeaders = response.getHeaders(HttpHeaders.DATE);
-
-        if (dateHeaders.length != 1) {
+        if (response.containsHeaders(HttpHeaders.DATE) > 1) {
+            log.debug("Multiple Date headers");
             return false;
         }
 
-        final Date date = DateUtils.parseDate(dateHeaders[0].getValue());
+        final Header h = response.getFirstHeader(HttpHeaders.DATE);
+        final Date date = h != null ? DateUtils.parseDate(h.getValue()) : null;
         if (date == null) {
+            log.debug("Invalid / missing Date header");
             return false;
         }
 
@@ -162,15 +172,19 @@ class ResponseCachingPolicy {
         while (it.hasNext()) {
             final HeaderElement elem = it.next();
             if ("*".equals(elem.getName())) {
+                if (log.isDebugEnabled()) {
+                    log.debug("Vary * found");
+                }
                 return false;
             }
         }
 
         if (isExplicitlyNonCacheable(response)) {
+            log.debug("Response is explicitly non-cacheable");
             return false;
         }
 
-        return (cacheable || isExplicitlyCacheable(response));
+        return cacheable || isExplicitlyCacheable(response);
     }
 
     private boolean unknownStatusCode(final int status) {
@@ -239,34 +253,39 @@ class ResponseCachingPolicy {
      * @return {@code true} if response is cacheable
      */
     public boolean isResponseCacheable(final HttpRequest request, final HttpResponse response) {
-        if (requestProtocolGreaterThanAccepted(request)) {
-            log.debug("Response was not cacheable.");
+        final ProtocolVersion version = request.getVersion() != null ? request.getVersion() : HttpVersion.DEFAULT;
+        if (version.compareToVersion(HttpVersion.HTTP_1_1) > 0) {
+            if (log.isDebugEnabled()) {
+                log.debug("Protocol version " + version + " is non-cacheable");
+            }
             return false;
         }
 
         final String[] uncacheableRequestDirectives = { HeaderConstants.CACHE_CONTROL_NO_STORE };
         if (hasCacheControlParameterFrom(request,uncacheableRequestDirectives)) {
+            log.debug("Response is explcitily non-cacheable per cache control directive");
             return false;
         }
 
         if (request.getRequestUri().contains("?")) {
             if (neverCache1_0ResponsesWithQueryString && from1_0Origin(response)) {
-                log.debug("Response was not cacheable as it had a query string.");
+                log.debug("Response is not cacheable as it had a query string");
                 return false;
             } else if (!isExplicitlyCacheable(response)) {
-                log.debug("Response was not cacheable as it is missing explicit caching headers.");
+                log.debug("Response is not cacheable as it is missing explicit caching headers");
                 return false;
             }
         }
 
         if (expiresHeaderLessOrEqualToDateHeaderAndNoCacheControl(response)) {
+            log.debug("Expires header less or equal to Date header and no cache control directives");
             return false;
         }
 
         if (sharedCache) {
-            final Header[] authNHeaders = request.getHeaders(HeaderConstants.AUTHORIZATION);
-            if (authNHeaders != null && authNHeaders.length > 0
+            if (request.containsHeaders(HeaderConstants.AUTHORIZATION) > 0
                     && !hasCacheControlParameterFrom(response, AUTH_CACHEABLE_PARAMS)) {
+                log.debug("Request contains private credentials");
                 return false;
             }
         }
@@ -275,8 +294,7 @@ class ResponseCachingPolicy {
         return isResponseCacheable(method, response);
     }
 
-    private boolean expiresHeaderLessOrEqualToDateHeaderAndNoCacheControl(
-            final HttpResponse response) {
+    private boolean expiresHeaderLessOrEqualToDateHeaderAndNoCacheControl(final HttpResponse response) {
         if (response.getFirstHeader(HeaderConstants.CACHE_CONTROL) != null) {
             return false;
         }
@@ -308,9 +326,4 @@ class ResponseCachingPolicy {
         return HttpVersion.HTTP_1_0.equals(version);
     }
 
-    private boolean requestProtocolGreaterThanAccepted(final HttpRequest req) {
-        final ProtocolVersion version = req.getVersion() != null ? req.getVersion() : HttpVersion.DEFAULT;
-        return version.compareToVersion(HttpVersion.HTTP_1_1) > 0;
-    }
-
 }