From f67aacdcebfcdbb3b12ebe38d57c99dfc12bf60d Mon Sep 17 00:00:00 2001
From: gilesb <giles.bradshaw@sigyl.com>
Date: Mon, 12 Jan 2026 21:07:09 +0000
Subject: [PATCH] Add detailed logging to cache_manager put and get_by_cid

Debug why recipes are not found in cache after upload.
Logs now show each step of put() and get_by_cid().

Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
---
 cache_manager.py | 17 ++++++++++++++---
 1 file changed, 14 insertions(+), 3 deletions(-)

diff --git a/cache_manager.py b/cache_manager.py
index a0a7bde..b29900e 100644
--- a/cache_manager.py
+++ b/cache_manager.py
@@ -404,6 +404,7 @@ class L1CacheManager:
             local_hash = file_hash(source_path)
 
         # Store in local cache
+        logger.info(f"put: Storing in cache with node_id={node_id[:16]}...")
         self.cache.put(
             node_id=node_id,
             source_path=source_path,
@@ -413,9 +414,15 @@ class L1CacheManager:
         )
 
         entry = self.cache.get_entry(node_id)
+        logger.info(f"put: After cache.put, get_entry(node_id={node_id[:16]}...) returned entry={entry is not None}, path={entry.output_path if entry else None}")
+
+        # Verify we can retrieve it
+        verify_path = self.cache.get(node_id)
+        logger.info(f"put: Verify cache.get(node_id={node_id[:16]}...) = {verify_path}")
 
         # Update content index (CID -> node_id mapping)
         self._set_content_index(cid, node_id)
+        logger.info(f"put: Set content index {cid[:16]}... -> {node_id[:16]}...")
 
         # Also index by local hash if cid is an IPFS CID
         # This ensures both IPFS CID and local hash can be used to find the file
@@ -438,27 +445,31 @@ class L1CacheManager:
 
     def get_by_cid(self, cid: str) -> Optional[Path]:
         """Get cached file path by cid or IPFS CID. Falls back to IPFS if not in local cache."""
+        logger.info(f"get_by_cid: Looking for cid={cid[:16]}...")
 
         # Check index first (Redis then local)
         node_id = self._get_content_index(cid)
+        logger.info(f"get_by_cid: Index lookup returned node_id={node_id[:16] if node_id else None}...")
         if node_id:
             path = self.cache.get(node_id)
+            logger.info(f"get_by_cid: cache.get(node_id={node_id[:16]}...) returned path={path}")
             if path and path.exists():
-                logger.debug(f"  Found via index: {path}")
+                logger.info(f"get_by_cid: Found via index: {path}")
                 return path
 
         # For uploads, node_id == cid, so try direct lookup
         # This works even if cache index hasn't been reloaded
         path = self.cache.get(cid)
-        logger.debug(f"  cache.get({cid[:16]}...) returned: {path}")
+        logger.info(f"get_by_cid: Direct cache.get({cid[:16]}...) returned: {path}")
         if path and path.exists():
             self._set_content_index(cid, cid)
             return path
 
         # Scan cache entries (fallback for new structure)
         entry = self.cache.find_by_cid(cid)
+        logger.info(f"get_by_cid: find_by_cid({cid[:16]}...) returned entry={entry}")
         if entry and entry.output_path.exists():
-            logger.debug(f"  Found via scan: {entry.output_path}")
+            logger.info(f"get_by_cid: Found via scan: {entry.output_path}")
             self._set_content_index(cid, entry.node_id)
             return entry.output_path