Cleanup debug log messages when loading stages (#5125)

* Cleanup log messages when loading stages

1. Simplified callback stage debug message
2. Reduced no lock entry message to trace
   If lockfile does not have some entry, it will simply complain
   that lockfile is not uptodate once.
   If there is no lockfile or empty lockfile, it will complain that
   lockfile not found.
3. Annoying parametrization related wdir-interpolated debug message
   removed.

* Update dvc/stage/__init__.py

* black

Author: skshetry

dvc/parsing/__init__.py

@@ -246,11 +246,6 @@ def resolve_stage(self, skip_checks=False):
         definition = deepcopy(self.definition)
 
         wdir = self._resolve_wdir(context, name, definition.get(WDIR_KWD))
-        if self.wdir != wdir:
-            logger.debug(
-                "Stage %s has different wdir than dvc.yaml file", name
-            )
-
         vars_ = definition.pop(VARS_KWD, [])
         # FIXME: Should `vars` be templatized?
         check_interpolations(vars_, f"{self.where}.{name}.vars", self.relpath)

dvc/stage/__init__.py

@@ -257,10 +257,7 @@ def changed_deps(self):
 
         if self.is_callback:
             logger.debug(
-                '%s is a "callback" stage '
-                "(has a command and no dependencies) and thus always "
-                "considered as changed.",
-                self,
+                "%s has a command but no dependencies", self.addressing
             )
             return True
 

dvc/stage/loader.py

@@ -3,7 +3,7 @@
 from copy import deepcopy
 from itertools import chain
 
-from funcy import cached_property, get_in, lcat, project
+from funcy import cached_property, get_in, lcat, once, project
 
 from dvc import dependency, output
 from dvc.hash_info import HashInfo
@@ -24,13 +24,19 @@ def __init__(self, dvcfile, data, lockfile_data=None):
         self.data = data or {}
         self.stages_data = self.data.get("stages", {})
         self.repo = self.dvcfile.repo
-        self.lockfile_data = lockfile_data or {}
+        self._lockfile_data = lockfile_data or {}
 
     @cached_property
     def resolver(self):
         wdir = PathInfo(self.dvcfile.path).parent
         return DataResolver(self.repo, wdir, self.data)
 
+    @cached_property
+    def lockfile_data(self):
+        if not self._lockfile_data:
+            logger.debug("Lockfile for '%s' not found", self.dvcfile.relpath)
+        return self._lockfile_data
+
     @staticmethod
     def fill_from_lock(stage, lock_data=None):
         """Fill values for params, checksums for outs and deps from lock."""
@@ -88,6 +94,14 @@ def load_stage(cls, dvcfile, name, stage_data, lock_data=None):
         cls.fill_from_lock(stage, lock_data)
         return stage
 
+    @once
+    def lockfile_needs_update(self):
+        # if lockfile does not have all of the entries that dvc.yaml says it
+        # should have, provide a debug message once
+        # pylint: disable=protected-access
+        lockfile = self.dvcfile._lockfile.relpath
+        logger.debug("Lockfile '%s' needs to be updated.", lockfile)
+
     def __getitem__(self, name):
         if not name:
             raise StageNameUnspecified(self.dvcfile)
@@ -97,8 +111,9 @@ def __getitem__(self, name):
         except EntryNotFound:
             raise StageNotFound(self.dvcfile, name)
 
-        if not self.lockfile_data.get(name):
-            logger.debug(
+        if self.lockfile_data and name not in self.lockfile_data:
+            self.lockfile_needs_update()
+            logger.trace(  # type: ignore[attr-defined]
                 "No lock entry found for '%s:%s'", self.dvcfile.relpath, name,
             )