perf: Caching of variable imports

Author: d-biehl

package.json

@@ -493,7 +493,18 @@
               "type": "string"
             },
             "markdownDescription": [
-              "Specifies the library names that should not be cached. This is useful if you have a dynamic or hybrid library that has different keywords depending on the arguments. You can specify a glob pattern that matches the library name or the source file. \n\nExamples:\n- `**/mylibfolder/mylib.py`\n- `MyLib`\n- `mylibfolder.mylib.subpackage` \n\nFor robot framework internal libraries, you have to specify the full module name like `robot.libraries.Remote`.\n\nIf you change this setting, you may need to run the command `Robot Code: Clear Cache and Restart Language Servers`."
+              "Specifies the library names that should not be cached. This is useful if you have a dynamic or hybrid library that has different keywords depending on the arguments. You can specify a glob pattern that matches the library name or the source file. \n\nExamples:\n- `**/mylibfolder/mylib.py`\n- `MyLib`\n- `mylib.subpackage.subpackage` \n\nFor robot framework internal libraries, you have to specify the full module name like `robot.libraries.Remote`.\n\nIf you change this setting, you may need to run the command `Robot Code: Clear Cache and Restart Language Servers`."
+            ],
+            "scope": "resource"
+          },
+          "robotcode.analysis.cache.ignoredVariables": {
+            "type": "array",
+            "default": [],
+            "items": {
+              "type": "string"
+            },
+            "markdownDescription": [
+              "Specifies the variable files that should not be cached. This is useful if you have a dynamic or hybrid variable files that has different variables depending on the arguments. You can specify a glob pattern that matches the variable module name or the source file. \n\nExamples:\n- `**/variables/myvars.py`\n- `MyVariables`\n- `myvars.subpackage.subpackage` \n\nIf you change this setting, you may need to run the command `Robot Code: Clear Cache and Restart Language Servers`."
             ],
             "scope": "resource"
           },

robotcode/debugger/launcher/server.py

@@ -317,7 +317,7 @@ async def _terminate(self, arguments: Optional[TerminateArguments] = None, *args
 
     async def handle_unknown_command(self, message: Request) -> Any:
         if self.connected:
-            self._logger.info("Forward request to client...")
+            self._logger.debug("Forward request to client...")
 
             return await self.client.protocol.send_request_async(message)
 

robotcode/debugger/protocol.py

@@ -248,7 +248,7 @@ def done(t: asyncio.Task[Any]) -> None:
             try:
                 self.send_response(message.seq, message.command, t.result())
             except asyncio.CancelledError:
-                self._logger.info(f"request message {repr(message)} canceled")
+                self._logger.debug(f"request message {repr(message)} canceled")
             except (SystemExit, KeyboardInterrupt):
                 raise
             except DebugAdapterRPCErrorException as ex:

robotcode/language_server/common/parts/commands.py

@@ -67,7 +67,7 @@ def extend_capabilities(self, capabilities: ServerCapabilities) -> None:
     async def _workspace_execute_command(
         self, command: str, arguments: Optional[List[LSPAny]], *args: Any, **kwargs: Any
     ) -> Optional[LSPAny]:
-        self._logger.info(f"execute command {command}")
+        self._logger.debug(f"execute command {command}")
 
         entry = self.commands.get(command, None)
         if entry is None or entry.callback is None:

robotcode/language_server/robotframework/configuration.py

@@ -83,6 +83,7 @@ class WorkspaceConfig(ConfigBase):
 class Cache(ConfigBase):
     save_location: CacheSaveLocation = CacheSaveLocation.WORKSPACE_STORAGE
     ignored_libraries: List[str] = field(default_factory=list)
+    ignored_variables: List[str] = field(default_factory=list)
 
 
 @config_section("robotcode.analysis")

robotcode/language_server/robotframework/diagnostics/entities.py

@@ -177,6 +177,7 @@ class VariableDefinition(SourceEntity):
     resolvable: bool = field(default=False, compare=False)
 
     value: Any = field(default=None, compare=False)
+    value_is_native: bool = field(default=False, compare=False)
 
     __matcher: Optional[VariableMatcher] = None
 
@@ -250,9 +251,21 @@ def __hash__(self) -> int:
         return hash((type(self), self.name, self.type, self.range, self.source))
 
 
+@dataclass(frozen=True, eq=False, repr=False)
+class NativeValue:
+    value: Any
+
+    def __repr__(self) -> str:
+        return repr(self.value)
+
+    def __str__(self) -> str:
+        return str(self.value)
+
+
 @dataclass
 class ImportedVariableDefinition(VariableDefinition):
     type: VariableDefinitionType = VariableDefinitionType.IMPORTED_VARIABLE
+    value: Optional[NativeValue] = field(default=None, compare=False)
 
     @single_call
     def __hash__(self) -> int:

robotcode/language_server/robotframework/diagnostics/imports_manager.py

@@ -519,9 +519,17 @@ def __init__(self, parent_protocol: RobotLanguageServerProtocol, folder: Uri, co
             / get_robot_version_str()
             / "libdoc"
         )
+        self.variables_doc_cache_path = (
+            self.cache_path
+            / f"{sys.version_info.major}.{sys.version_info.minor}.{sys.version_info.micro}"
+            / get_robot_version_str()
+            / "variables"
+        )
+
         self.config = config
 
         self.ignored_libraries_patters = [Pattern(s) for s in config.analysis.cache.ignored_libraries]
+        self.ignored_variables_patters = [Pattern(s) for s in config.analysis.cache.ignored_variables]
         self._libaries_lock = Lock()
         self._libaries: OrderedDict[_LibrariesEntryKey, _LibrariesEntry] = OrderedDict()
         self._resources_lock = Lock()
@@ -796,9 +804,68 @@ async def get_library_meta(
                     or (p.matches(result.origin) if result.origin is not None else False)
                     for p in self.ignored_libraries_patters
                 ):
-                    self._logger.critical(
-                        lambda: f"Ignore library {result.name or ''} {result.origin or ''} for caching."  # type: ignore
+                    self._logger.debug(f"Ignore library {result.name or ''} {result.origin or ''} for caching.")
+                    return None, import_name
+
+                if result.origin is not None:
+                    result.mtimes = {result.origin: Path(result.origin).resolve().stat().st_mtime_ns}
+
+                if result.submodule_search_locations:
+                    if result.mtimes is None:
+                        result.mtimes = {}
+                    result.mtimes.update(
+                        {
+                            str(f): f.resolve().stat().st_mtime_ns
+                            for f in itertools.chain(
+                                *(iter_files(loc, "**/*.py") for loc in result.submodule_search_locations)
+                            )
+                        }
                     )
+
+            return result, import_name
+        except (SystemExit, KeyboardInterrupt):
+            raise
+        except BaseException:
+            pass
+
+        return None, import_name
+
+    async def get_variables_meta(
+        self,
+        name: str,
+        base_dir: str = ".",
+        variables: Optional[Dict[str, Optional[Any]]] = None,
+    ) -> Tuple[Optional[LibraryMetaData], str]:
+        try:
+            import_name = await self.find_variables(
+                name,
+                base_dir=base_dir,
+                variables=variables,
+            )
+
+            result: Optional[LibraryMetaData] = None
+            module_spec: Optional[ModuleSpec] = None
+            if is_variables_by_path(import_name):
+                if (p := Path(import_name)).exists():
+                    result = LibraryMetaData(__version__, p.stem, import_name, None, True)
+            else:
+                module_spec = get_module_spec(import_name)
+                if module_spec is not None and module_spec.origin is not None:
+                    result = LibraryMetaData(
+                        __version__,
+                        module_spec.name,
+                        module_spec.origin,
+                        module_spec.submodule_search_locations,
+                        False,
+                    )
+
+            if result is not None:
+                if any(
+                    (p.matches(result.name) if result.name is not None else False)
+                    or (p.matches(result.origin) if result.origin is not None else False)
+                    for p in self.ignored_variables_patters
+                ):
+                    self._logger.debug(f"Ignore Variables {result.name or ''} {result.origin or ''} for caching.")
                     return None, import_name
 
                 if result.origin is not None:
@@ -968,11 +1035,17 @@ async def _get_libdoc(name: str, args: Tuple[Any, ...], working_dir: str, base_d
                 try:
                     if meta is not None:
                         meta_file = Path(self.lib_doc_cache_path, meta.filepath_base.with_suffix(".meta.json"))
-                        meta_file.parent.mkdir(parents=True, exist_ok=True)
-                        meta_file.write_text(as_json(meta), "utf-8")
-
                         spec_file = Path(self.lib_doc_cache_path, meta.filepath_base.with_suffix(".spec.json"))
-                        spec_file.write_text(as_json(result), "utf-8")
+                        spec_file.parent.mkdir(parents=True, exist_ok=True)
+
+                        try:
+                            spec_file.write_text(as_json(result), "utf-8")
+                        except (SystemExit, KeyboardInterrupt):
+                            raise
+                        except BaseException as e:
+                            raise RuntimeError(f"Cannot write spec file for library '{name}' to '{spec_file}'") from e
+
+                        meta_file.write_text(as_json(meta), "utf-8")
                     else:
                         self._logger.debug(lambda: f"Skip caching library {name}{repr(args)}")
                 except (SystemExit, KeyboardInterrupt):
@@ -1145,7 +1218,38 @@ async def get_libdoc_for_variables_import(
         )
 
         async def _get_libdoc() -> VariablesDoc:
+            meta, source = await self.get_variables_meta(
+                name,
+                base_dir,
+                variables,
+            )
+
             self._logger.debug(lambda: f"Load variables {source}{repr(args)}")
+            if meta is not None:
+                meta_file = Path(self.variables_doc_cache_path, meta.filepath_base.with_suffix(".meta.json"))
+                if meta_file.exists():
+                    try:
+                        try:
+                            saved_meta = from_json(meta_file.read_text("utf-8"), LibraryMetaData)
+                            spec_path = None
+                            if saved_meta == meta:
+                                spec_path = Path(
+                                    self.variables_doc_cache_path, meta.filepath_base.with_suffix(".spec.json")
+                                )
+                                return from_json(
+                                    spec_path.read_text("utf-8"),
+                                    VariablesDoc,
+                                )
+                        except (SystemExit, KeyboardInterrupt):
+                            raise
+                        except BaseException as e:
+                            raise RuntimeError(
+                                f"Failed to load library meta data for library {name} from {spec_path}"
+                            ) from e
+                    except (SystemExit, KeyboardInterrupt):
+                        raise
+                    except BaseException as e:
+                        self._logger.exception(e)
 
             with ProcessPoolExecutor(max_workers=1) as executor:
                 result = await asyncio.wait_for(
@@ -1166,6 +1270,26 @@ async def _get_libdoc() -> VariablesDoc:
                     self._logger.warning(
                         lambda: f"stdout captured at loading variables {name}{repr(args)}:\n{result.stdout}"
                     )
+
+                try:
+                    if meta is not None:
+                        meta_file = Path(self.variables_doc_cache_path, meta.filepath_base.with_suffix(".meta.json"))
+                        spec_file = Path(self.variables_doc_cache_path, meta.filepath_base.with_suffix(".spec.json"))
+                        spec_file.parent.mkdir(parents=True, exist_ok=True)
+
+                        try:
+                            spec_file.write_text(as_json(result), "utf-8")
+                        except (SystemExit, KeyboardInterrupt):
+                            raise
+                        except BaseException as e:
+                            raise RuntimeError(f"Cannot write spec file for variables '{name}' to '{spec_file}'") from e
+                        meta_file.write_text(as_json(meta), "utf-8")
+                    else:
+                        self._logger.debug(lambda: f"Skip caching variables {name}{repr(args)}")
+                except (SystemExit, KeyboardInterrupt):
+                    raise
+                except BaseException as e:
+                    self._logger.exception(e)
                 return result
 
         entry_key = _VariablesEntryKey(source, args)

robotcode/language_server/robotframework/diagnostics/library_doc.py

@@ -38,8 +38,8 @@
 from .entities import (
     ArgumentDefinition,
     ImportedVariableDefinition,
+    NativeValue,
     SourceEntity,
-    VariableDefinition,
     single_call,
 )
 
@@ -811,7 +811,7 @@ class VariablesDoc(LibraryDoc):
     type: str = "VARIABLES"
     scope: str = "GLOBAL"
 
-    variables: List[VariableDefinition] = field(default_factory=list)
+    variables: List[ImportedVariableDefinition] = field(default_factory=list)
 
 
 def is_library_by_path(path: str) -> bool:
@@ -1488,20 +1488,6 @@ def find_variables(
         )
 
 
-# @dataclass
-class NativeValue:
-    __slots__ = ["value"]
-
-    def __init__(self, value: Any) -> None:
-        self.value = value
-
-    def __repr__(self) -> str:
-        return repr(self.value)
-
-    def __str__(self) -> str:
-        return str(self.value)
-
-
 def get_variables_doc(
     name: str,
     args: Optional[Tuple[Any, ...]] = None,
@@ -1554,7 +1540,7 @@ def import_variables(self, path: str, args: Optional[Tuple[Any, ...]] = None) ->
 
                 importer = MyPythonImporter(libcode)
 
-            vars: List[VariableDefinition] = [
+            vars: List[ImportedVariableDefinition] = [
                 ImportedVariableDefinition(
                     1,
                     0,
@@ -1564,9 +1550,10 @@ def import_variables(self, path: str, args: Optional[Tuple[Any, ...]] = None) ->
                     name,
                     None,
                     value=NativeValue(value)
-                    if isinstance(value, (int, float, bool, str, set, tuple, dict, list))
+                    if value is None or isinstance(value, (int, float, bool, str, dict, list))
                     else None,
-                    has_value=isinstance(value, (int, float, bool, str, set, tuple, dict, list)),
+                    has_value=value is None or isinstance(value, (int, float, bool, str, dict, list)),
+                    value_is_native=value is None or isinstance(value, (int, float, bool, str, dict, list)),
                 )
                 for name, value in importer.import_variables(import_name, args)
             ]

robotcode/language_server/robotframework/diagnostics/namespace.py

@@ -28,7 +28,6 @@
     cast,
 )
 
-from ....utils.async_itertools import as_async_iterable
 from ....utils.async_tools import Lock, async_event
 from ....utils.logging import LoggingDescriptor
 from ....utils.uri import Uri
@@ -62,6 +61,7 @@
     CommandLineVariableDefinition,
     EnvironmentVariableDefinition,
     Import,
+    ImportedVariableDefinition,
     InvalidVariableError,
     LibraryImport,
     LocalVariableDefinition,
@@ -537,7 +537,7 @@ class ResourceEntry(LibraryEntry):
 
 @dataclass
 class VariablesEntry(LibraryEntry):
-    variables: List[VariableDefinition] = field(default_factory=lambda: [])
+    variables: List[ImportedVariableDefinition] = field(default_factory=lambda: [])
 
 
 class DocumentType(enum.Enum):
@@ -611,6 +611,8 @@ def __init__(
 
         self._in_initialize = False
 
+        self._ignored_lines: Optional[List[int]] = None
+
     @async_event
     async def has_invalidated(sender) -> None:  # NOSONAR
         ...
@@ -689,6 +691,7 @@ async def _invalidate(self) -> None:
 
         self._finder = None
         self._in_initialize = False
+        self._ignored_lines = None
 
         await self._reset_global_variables()
 
@@ -1192,7 +1195,7 @@ async def _import(
         self._logger.debug(lambda: f"start imports for {self.document if top_level else source}")
         try:
 
-            async for imp in as_async_iterable(imports):
+            for imp in imports:
                 if variables is None:
                     variables = await self.get_resolvable_variables()
 
@@ -1552,7 +1555,7 @@ async def append_diagnostics(
         related_information: Optional[List[DiagnosticRelatedInformation]] = None,
         data: Optional[Any] = None,
     ) -> None:
-        if await self.should_ignore(self.document, range):
+        if await self._should_ignore(range):
             return
 
         self._diagnostics.append(
@@ -1667,6 +1670,12 @@ async def __get_ignored_lines(document: TextDocument) -> List[int]:
     async def should_ignore(cls, document: Optional[TextDocument], range: Range) -> bool:
         return cls.__should_ignore(await cls.get_ignored_lines(document) if document is not None else [], range)
 
+    async def _should_ignore(self, range: Range) -> bool:
+        if self._ignored_lines is None:
+            self._ignored_lines = await self.get_ignored_lines(self.document) if self.document is not None else []
+
+        return self.__should_ignore(self._ignored_lines, range)
+
     @staticmethod
     def __should_ignore(lines: List[int], range: Range) -> bool:
         import builtins