logger: use lazy formatting

dvc/analytics.py

@@ -50,7 +50,7 @@ def is_enabled():
             Config(validate=False).get("core", {}).get("analytics", "true")
         )
 
-    logger.debug("Analytics is {}abled.".format("en" if enabled else "dis"))
+    logger.debug("Analytics is %sabled.", "en" if enabled else "dis")
 
     return enabled
 
@@ -187,4 +187,4 @@ def _find_or_create_user_id():
             return user_id
 
     except LockError:
-        logger.debug(f"Failed to acquire '{lockfile}'")
+        logger.debug("Failed to acquire '%s'", lockfile)

dvc/commands/freeze.py

@@ -16,7 +16,7 @@ def _run(self, func, name):
             try:
                 func(target)
             except DvcException:
-                logger.exception(f"failed to {name} '{target}'")
+                logger.exception("failed to %s '%s'", name, target)
                 ret = 1
         return ret
 

dvc/commands/get_url.py

@@ -18,7 +18,7 @@ def run(self):
             Repo.get_url(self.args.url, out=self.args.out, jobs=self.args.jobs)
             return 0
         except DvcException:
-            logger.exception(f"failed to get '{self.args.url}'")
+            logger.exception("failed to get '%s'", self.args.url)
             return 1
 
 

dvc/commands/ls/__init__.py

@@ -42,7 +42,7 @@ def run(self):
                 ui.write("\n".join(entries))
             return 0
         except DvcException:
-            logger.exception(f"failed to list '{self.args.url}'")
+            logger.exception("failed to list '%s'", self.args.url)
             return 1
 
 

dvc/config.py

@@ -187,7 +187,7 @@ def _save_config(self, level, conf_dict):
         filename = self.files[level]
         fs = self._get_fs(level)
 
-        logger.debug(f"Writing '{filename}'.")
+        logger.debug("Writing '%s'.", filename)
 
         fs.makedirs(os.path.dirname(filename))
 

dvc/daemon.py

@@ -81,7 +81,7 @@ def _spawn_posix(cmd, env):
 
 
 def _spawn(cmd, env):
-    logger.debug(f"Trying to spawn '{cmd}'")
+    logger.debug("Trying to spawn '%s'", cmd)
 
     if os.name == "nt":
         _spawn_windows(cmd, env)
@@ -90,7 +90,7 @@ def _spawn(cmd, env):
     else:
         raise NotImplementedError
 
-    logger.debug(f"Spawned '{cmd}'")
+    logger.debug("Spawned '%s'", cmd)
 
 
 def daemon(args):

dvc/data_cloud.py

@@ -64,7 +64,7 @@ def _init_odb(self, name):
         return get_odb(cls(**config), fs_path, **config)
 
     def _log_missing(self, status: "CompareStatusResult"):
-        if status.missing:
+        if status.missing and logger.isEnabledFor(logging.WARNING):
             missing_desc = "\n".join(
                 f"name: {hash_info.obj_name}, {hash_info}"
                 for hash_info in status.missing

dvc/dvcfile.py

@@ -197,7 +197,7 @@ def dump(self, stage, **kwargs):
         assert not isinstance(stage, PipelineStage)
         if self.verify:
             check_dvcfile_path(self.repo, self.path)
-        logger.debug(f"Saving information to '{relpath(self.path)}'.")
+        logger.debug("Saving information to '%s'.", relpath(self.path))
         dump_yaml(self.path, serialize.to_single_stage_file(stage))
         self.repo.scm_context.track_file(self.relpath)
 

dvc/output.py

@@ -541,7 +541,7 @@ def save(self):
             raise self.IsNotFileOrDirError(self)
 
         if self.is_empty:
-            logger.warning(f"'{self}' is empty.")
+            logger.warning("'%s' is empty.", self)
 
         self.ignore()
 
@@ -912,7 +912,7 @@ def _collect_used_dir_cache(
         except RemoteMissingDepsError:  # pylint: disable=try-except-raise
             raise
         except DvcException:
-            logger.debug(f"failed to pull cache for '{self}'")
+            logger.debug("failed to pull cache for '%s'", self)
 
         try:
             ocheck(self.odb, self.odb.get(self.hash_info.value))

dvc/prompt.py

@@ -52,5 +52,5 @@ def password(statement):
     Returns:
         str: password entered by the user.
     """
-    logger.info(f"{statement}: ")
+    logger.info("%s: ", statement)
     return getpass("")

dvc/repo/experiments/executor/base.py

@@ -348,10 +348,11 @@ def _validate_remotes(cls, dvc: "Repo", git_remote: Optional[str]):
 
         if git_remote == dvc.root_dir:
             logger.warning(
-                f"'{git_remote}' points to the current Git repo, experiment "
+                "'%s' points to the current Git repo, experiment "
                 "Git refs will not be pushed. But DVC cache and run cache "
                 "will automatically be pushed to the default DVC remote "
-                "(if any) on each experiment commit."
+                "(if any) on each experiment commit.",
+                git_remote,
             )
         try:
             dvc.scm.validate_git_remote(git_remote)
@@ -603,7 +604,9 @@ def _auto_push(
         except BaseException as exc:  # pylint: disable=broad-except
             logger.warning(
                 "Something went wrong while auto pushing experiment "
-                f"to the remote '{git_remote}': {exc}"
+                "to the remote '%s': %s",
+                git_remote,
+                exc,
             )
 
     @classmethod

dvc/repo/experiments/pull.py

@@ -82,7 +82,7 @@ def _pull(
     force: bool,
 ) -> Mapping[SyncStatus, List["ExpRefInfo"]]:
     refspec_list = [f"{exp_ref}:{exp_ref}" for exp_ref in refs]
-    logger.debug(f"git pull experiment '{git_remote}' -> '{refspec_list}'")
+    logger.debug("git pull experiment '%s' -> '%s'", git_remote, refspec_list)
 
     with TqdmGit(desc="Fetching git refs") as pbar:
         results: Mapping[str, SyncStatus] = repo.scm.fetch_refspecs(
@@ -113,7 +113,7 @@ def _pull_cache(
     if isinstance(refs, ExpRefInfo):
         refs = [refs]
     revs = list(exp_commits(repo.scm, refs))
-    logger.debug(f"dvc fetch experiment '{refs}'")
+    logger.debug("dvc fetch experiment '%s'", refs)
     repo.fetch(
         jobs=jobs, remote=dvc_remote, run_cache=run_cache, revs=revs, odb=odb
     )

dvc/repo/experiments/push.py

@@ -85,7 +85,7 @@ def _push(
     from ...scm import GitAuthError
 
     refspec_list = [f"{exp_ref}:{exp_ref}" for exp_ref in refs]
-    logger.debug(f"git push experiment '{refs}' -> '{git_remote}'")
+    logger.debug("git push experiment '%s' -> '%s'", refspec_list, git_remote)
 
     with TqdmGit(desc="Pushing git refs") as pbar:
         try:
@@ -118,5 +118,5 @@ def _push_cache(
     if isinstance(refs, ExpRefInfo):
         refs = [refs]
     revs = list(exp_commits(repo.scm, refs))
-    logger.debug(f"dvc push experiment '{refs}'")
+    logger.debug("dvc push experiment '%s'", refs)
     repo.push(jobs=jobs, remote=dvc_remote, run_cache=run_cache, revs=revs)

dvc/repo/gc.py

@@ -76,7 +76,7 @@ def gc(
 
         removed = ogc(odb, used_obj_ids, jobs=jobs)
         if not removed:
-            logger.info(f"No unused '{scheme}' cache to remove.")
+            logger.info("No unused '%s' cache to remove.", scheme)
 
     if not cloud:
         return

dvc/repo/reproduce.py

@@ -33,8 +33,9 @@ def _run_callback(repro_callback):
 
     if stage.frozen and not stage.is_import:
         logger.warning(
-            "{} is frozen. Its dependencies are"
-            " not going to be reproduced.".format(stage)
+            "%s is frozen. Its dependencies are"
+            " not going to be reproduced.",
+            stage,
         )
 
     stage = stage.reproduce(**kwargs)

dvc/repo/scm_context.py

@@ -124,7 +124,11 @@ def __call__(
 
         if autostage:
             self.track_changed_files()
-        elif not quiet and not isinstance(self.scm, NoSCM):
+        elif (
+            not quiet
+            and not isinstance(self.scm, NoSCM)
+            and logger.isEnabledFor(logging.INFO)
+        ):
             add_cmd = self._make_git_add_cmd(self.files_to_track)
             logger.info(
                 f"\nTo track the changes with git, run:\n" f"\n{add_cmd}"

dvc/repo/status.py

@@ -16,8 +16,9 @@ def _joint_status(pairs):
     for stage, filter_info in pairs:
         if stage.frozen and not stage.is_repo_import:
             logger.warning(
-                "{} is frozen. Its dependencies are"
-                " not going to be shown in the status output.".format(stage)
+                "%s is frozen. Its dependencies are"
+                " not going to be shown in the status output.",
+                stage,
             )
         status_info.update(
             stage.status(check_updates=True, filter_info=filter_info)

dvc/stage/__init__.py

@@ -323,10 +323,10 @@ def _changed_deps(self):
             status = dep.status()
             if status:
                 logger.debug(
-                    "Dependency '{dep}' of {stage} changed because it is "
-                    "'{status}'.".format(
-                        dep=dep, stage=self, status=status[str(dep)]
-                    )
+                    "Dependency '%s' of %s changed because it is '%s'.",
+                    dep,
+                    self,
+                    status[str(dep)],
                 )
                 return True
         return False
@@ -337,10 +337,10 @@ def changed_outs(self):
             status = out.status()
             if status:
                 logger.debug(
-                    "Output '{out}' of {stage} changed because it is "
-                    "'{status}'".format(
-                        out=out, stage=self, status=status[str(out)]
-                    )
+                    "Output '%s' of %s changed because it is '%s'.",
+                    out,
+                    self,
+                    status[str(out)],
                 )
                 return True
 
@@ -373,7 +373,7 @@ def remove_outs(self, ignore_remove=False, force=False):
                 out.unprotect()
                 continue
 
-            logger.debug(f"Removing output '{out}' of {self}.")
+            logger.debug("Removing output '%s' of %s.", out, self)
             out.remove(ignore_remove=ignore_remove)
 
     def unprotect_outs(self):
@@ -429,7 +429,7 @@ def reproduce(self, interactive=False, **kwargs):
 
         self.run(**kwargs)
 
-        logger.debug(f"{self} was reproduced")
+        logger.debug("%s was reproduced", self)
 
         return self
 
@@ -452,7 +452,7 @@ def compute_md5(self):
             m = None
         else:
             m = compute_md5(self)
-        logger.debug(f"Computed {self} md5: '{m}'")
+        logger.debug("Computed %s md5: '%s'", self, m)
         return m
 
     def save(self, allow_missing=False):

dvc/stage/imports.py

@@ -32,11 +32,7 @@ def update_import(stage, rev=None, to_remote=False, remote=None, jobs=None):
 
 def sync_import(stage, dry=False, force=False, jobs=None):
     """Synchronize import's outs to the workspace."""
-    logger.info(
-        "Importing '{dep}' -> '{out}'".format(
-            dep=stage.deps[0], out=stage.outs[0]
-        )
-    )
+    logger.info("Importing '%s' -> '%s'", stage.deps[0], stage.outs[0])
     if dry:
         return
 

dvc/ui/pager.py

@@ -62,9 +62,8 @@ def find_pager():
         if os.system(f"({DEFAULT_PAGER}) 2>{os.devnull}") != 0:
             logger.warning(
                 "Unable to find `less` in the PATH. Check out "
-                "{} for more info.".format(
-                    format_link("https://man.dvc.org/pipeline/show")
-                )
+                "%s for more info.",
+                format_link("https://man.dvc.org/pipeline/show"),
             )
         else:
             pager = DEFAULT_PAGER
@@ -86,7 +85,7 @@ def find_pager():
 
 def pager(text: str) -> None:
     _pager = find_pager()
-    logger.trace(f"Using pager: '{_pager}'")  # type: ignore[attr-defined]
+    logger.trace("Using pager: '%s'", _pager)  # type: ignore[attr-defined]
     make_pager(_pager)(text)
 
 

dvc/updater.py

@@ -37,7 +37,7 @@ def _is_outdated_file(self):
         ctime = os.path.getmtime(self.updater_file)
         outdated = time.time() - ctime >= self.TIMEOUT
         if outdated:
-            logger.debug(f"'{self.updater_file}' is outdated")
+            logger.debug("'%s' is outdated", self.updater_file)
         return outdated
 
     def _with_lock(self, func, action):
@@ -47,8 +47,11 @@ def _with_lock(self, func, action):
             with self.lock:
                 func()
         except LockError:
-            msg = "Failed to acquire '{}' before {} updates"
-            logger.debug(msg.format(self.lock.lockfile, action))
+            logger.debug(
+                "Failed to acquire '%s' before %s updates",
+                self.lock.lockfile,
+                action,
+            )
 
     def check(self):
         from dvc.utils import env2bool
@@ -75,8 +78,9 @@ def _check(self):
                 info = json.load(fobj)
                 latest = info["version"]
             except Exception as exc:  # pylint: disable=broad-except
-                msg = "'{}' is not a valid json: {}"
-                logger.debug(msg.format(self.updater_file, exc))
+                logger.debug(
+                    "'%s' is not a valid json: %s", self.updater_file, exc
+                )
                 self.fetch()
                 return
 
@@ -101,8 +105,7 @@ def _get_latest_version(self):
             resp = requests.get(self.URL, timeout=self.TIMEOUT_GET)
             info = resp.json()
         except requests.exceptions.RequestException as exc:
-            msg = "Failed to retrieve latest version: {}"
-            logger.debug(msg.format(exc))
+            logger.debug("Failed to retrieve latest version: %s", exc)
             return
 
         with open(self.updater_file, "w+", encoding="utf-8") as fobj:
@@ -171,7 +174,7 @@ def is_enabled(self):
             Config(validate=False).get("core", {}).get("check_update", "true")
         )
         logger.debug(
-            "Check for update is {}abled.".format("en" if enabled else "dis")
+            "Check for update is %sabled.", "en" if enabled else "dis"
         )
         return enabled