Some additional logging and tests

3 files changed, 31 insertions, 5 deletions

diff --git a/requests_cache/_utils.py b/requests_cache/_utils.py
index 591c4c1..ea6948f 100644
--- a/requests_cache/_utils.py
+++ b/requests_cache/_utils.py
@@ -23,11 +23,15 @@ def decode(value, encoding='utf-8') -> str:
     """Decode a value from bytes, if hasn't already been.
     Note: ``PreparedRequest.body`` is always encoded in utf-8.
     """
+    if not value:
+        return ''
     return value.decode(encoding) if isinstance(value, bytes) else value
 
 
 def encode(value, encoding='utf-8') -> bytes:
     """Encode a value to bytes, if it hasn't already been"""
+    if not value:
+        return b''
     return value if isinstance(value, bytes) else str(value).encode(encoding)
 
 
diff --git a/requests_cache/cache_keys.py b/requests_cache/cache_keys.py
index 1652bd7..c2f295a 100644
--- a/requests_cache/cache_keys.py
+++ b/requests_cache/cache_keys.py
@@ -28,7 +28,13 @@ from url_normalize import url_normalize
 
 from ._utils import decode, encode
 
-__all__ = ['create_key', 'normalize_request']
+__all__ = [
+    'create_key',
+    'normalize_body',
+    'normalize_headers',
+    'normalize_request',
+    'normalize_url',
+]
 if TYPE_CHECKING:
     from .models import AnyPreparedRequest, AnyRequest, CachedResponse
 
@@ -117,7 +123,7 @@ def normalize_request(
 
 
 def normalize_headers(
-    headers: MutableMapping[str, str], ignored_parameters: ParamList
+    headers: MutableMapping[str, str], ignored_parameters: ParamList = None
 ) -> CaseInsensitiveDict:
     """Sort and filter request headers, and normalize minor variations in multi-value headers"""
     if ignored_parameters:
diff --git a/requests_cache/policy/actions.py b/requests_cache/policy/actions.py
index ad201f9..aedd4eb 100644
--- a/requests_cache/policy/actions.py
+++ b/requests_cache/policy/actions.py
@@ -1,11 +1,12 @@
 from datetime import datetime, timedelta
-from logging import getLogger
-from typing import TYPE_CHECKING, Dict, Optional, Union
+from logging import DEBUG, getLogger
+from typing import TYPE_CHECKING, Dict, List, MutableMapping, Optional, Union
 
 from attr import define, field
 from requests import PreparedRequest, Response
 
 from .._utils import coalesce
+from ..cache_keys import normalize_headers
 from ..models import RichMixin
 from . import (
     DO_NOT_CACHE,
@@ -291,7 +292,22 @@ class CacheActions(RichMixin):
         # Generate a secondary cache key based on Vary for both the cached request and new request
         key_kwargs['match_headers'] = [k.strip() for k in vary.split(',')]
         vary_cache_key = create_key(cached_response.request, **key_kwargs)
-        return create_key(self._request, **key_kwargs) == vary_cache_key
+        headers_match = create_key(self._request, **key_kwargs) == vary_cache_key
+        if not headers_match:
+            _log_vary_diff(
+                self._request.headers, cached_response.request.headers, key_kwargs['match_headers']
+            )
+        return headers_match
+
+
+def _log_vary_diff(
+    headers_1: MutableMapping[str, str], headers_2: MutableMapping[str, str], vary: List[str]
+):
+    """Log which specific headers specified by Vary did not match, debug purposes"""
+    headers_1 = normalize_headers(headers_1)
+    headers_2 = normalize_headers(headers_2)
+    nonmatching = [k for k in vary if headers_1.get(k) != headers_2.get(k)]
+    logger.debug(f'Failed Vary check. Non-matching headers: {", ".join(nonmatching)}')
 
 
 def _log_cache_criteria(operation: str, criteria: Dict):