Skip to content

Commit 99e322d

Browse files
committed
refactor(diagnostics): add debug logging for namespace cache misses
Log specific reasons when namespace cache entries are invalidated, including source mtime changes, config fingerprint mismatches, and dependency changes (libraries, resources, variables). Uses debug level with context_name="cache" for targeted activation.
1 parent c34455f commit 99e322d

File tree

2 files changed

+66
-5
lines changed

2 files changed

+66
-5
lines changed

packages/robot/src/robotcode/robot/diagnostics/document_cache_helper.py

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -496,9 +496,17 @@ def _try_load_cached_namespace(
496496
return None
497497

498498
if entry is None or entry.meta is None:
499+
self._logger.debug(
500+
lambda: f"Cache miss for {source}: no cached entry found",
501+
context_name="cache",
502+
)
499503
return None
500504

501505
if not imports_manager.validate_namespace_meta(entry.meta):
506+
self._logger.debug(
507+
lambda: f"Cache miss for {source}: cached entry is stale, re-analyzing",
508+
context_name="cache",
509+
)
502510
return None
503511

504512
# Meta is valid — load the full NamespaceData (lazy deserialization)

packages/robot/src/robotcode/robot/diagnostics/imports_manager.py

Lines changed: 58 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -835,20 +835,37 @@ def validate_namespace_meta(self, meta: NamespaceMetaData) -> bool:
835835
Level 1 (fast): source_mtime_ns, config_fingerprint
836836
Level 2 (dependency check): each dependency fingerprint
837837
"""
838+
source = meta.source
839+
838840
# Level 1: fast checks
839841
try:
840-
current_mtime = os.stat(meta.source, follow_symlinks=False).st_mtime_ns
842+
current_mtime = os.stat(source, follow_symlinks=False).st_mtime_ns
841843
except OSError:
844+
self._logger.debug(
845+
lambda: f"Cache miss for {source}: source file no longer exists",
846+
context_name="cache",
847+
)
842848
return False
843849

844850
if meta.source_mtime_ns != current_mtime:
851+
self._logger.debug(
852+
lambda: (
853+
f"Cache miss for {source}: source mtime changed"
854+
f" (cached={meta.source_mtime_ns}, current={current_mtime})"
855+
),
856+
context_name="cache",
857+
)
845858
return False
846859

847860
if meta.config_fingerprint != self.config_fingerprint:
861+
self._logger.debug(
862+
lambda: f"Cache miss for {source}: config fingerprint changed",
863+
context_name="cache",
864+
)
848865
return False
849866

850867
# Level 2: dependency checks — direct comparison, no hashing
851-
base_dir = os.path.dirname(meta.source)
868+
base_dir = os.path.dirname(source)
852869
for key, saved_value in meta.dependency_fingerprints.items():
853870
if key.startswith("lib:"):
854871
lib_name = key[4:]
@@ -857,10 +874,22 @@ def validate_namespace_meta(self, meta: NamespaceMetaData) -> bool:
857874
if lib_meta is None:
858875
lib_meta, _, _ = self.get_library_meta(lib_name, base_dir=base_dir)
859876
if lib_meta is None or lib_meta != saved_value:
877+
self._logger.debug(
878+
lambda: (
879+
f"Cache miss for {source}: library {lib_name!r} changed"
880+
f" (found={'yes' if lib_meta is not None else 'no'})"
881+
),
882+
context_name="cache",
883+
)
860884
return False
861885
except (SystemExit, KeyboardInterrupt):
862886
raise
863-
except BaseException:
887+
except BaseException as e:
888+
ex = e
889+
self._logger.debug(
890+
lambda: f"Cache miss for {source}: error checking library {lib_name!r}: {ex}",
891+
context_name="cache",
892+
)
864893
return False
865894
elif key.startswith("res:"):
866895
res_source = key[4:]
@@ -869,10 +898,22 @@ def validate_namespace_meta(self, meta: NamespaceMetaData) -> bool:
869898
if res_meta is None:
870899
res_meta = self.get_resource_meta(res_source)
871900
if res_meta is None or res_meta != saved_value:
901+
self._logger.debug(
902+
lambda: (
903+
f"Cache miss for {source}: resource {res_source!r} changed"
904+
f" (found={'yes' if res_meta is not None else 'no'})"
905+
),
906+
context_name="cache",
907+
)
872908
return False
873909
except (SystemExit, KeyboardInterrupt):
874910
raise
875-
except BaseException:
911+
except BaseException as e:
912+
ex = e
913+
self._logger.debug(
914+
lambda: f"Cache miss for {source}: error checking resource {res_source!r}: {ex}",
915+
context_name="cache",
916+
)
876917
return False
877918
elif key.startswith("var:"):
878919
var_name = key[4:]
@@ -881,10 +922,22 @@ def validate_namespace_meta(self, meta: NamespaceMetaData) -> bool:
881922
if var_meta is None:
882923
var_meta, _ = self.get_variables_meta(var_name, base_dir=base_dir)
883924
if var_meta is None or var_meta != saved_value:
925+
self._logger.debug(
926+
lambda: (
927+
f"Cache miss for {source}: variables {var_name!r} changed"
928+
f" (found={'yes' if var_meta is not None else 'no'})"
929+
),
930+
context_name="cache",
931+
)
884932
return False
885933
except (SystemExit, KeyboardInterrupt):
886934
raise
887-
except BaseException:
935+
except BaseException as e:
936+
ex = e
937+
self._logger.debug(
938+
lambda: f"Cache miss for {source}: error checking variables {var_name!r}: {ex}",
939+
context_name="cache",
940+
)
888941
return False
889942

890943
return True

0 commit comments

Comments
 (0)