logger: use standard lazy formatting (#3487)

Unfortunately overriding `format` is not enough in order to use our own
custom formatting in logger. `Record` uses percent formatting that is
hardcoded inside, so we would also have to override it, which is just
way too much effort that will inevitably break as we discover other
methods that are not ready for non-% formatting. So we are just giving
up and sticking to default %-formatting for lazy log messages.

Fixes #3397
This commit is contained in:
Ruslan Kuprieiev
2020-03-17 00:38:00 +02:00
committed by GitHub
parent 87338c994f
commit 2ffebb0b5e
5 changed files with 34 additions and 33 deletions
+5 -5
View File
@@ -24,7 +24,7 @@ logger = logging.getLogger(__name__)
@contextmanager
def external_repo(url, rev=None, for_write=False):
logger.debug("Creating external repo {}@{}", url, rev)
logger.debug("Creating external repo %s@%s", url, rev)
path = _cached_clone(url, rev, for_write=for_write)
try:
repo = ExternalRepo(path, url)
@@ -208,7 +208,7 @@ def _cached_clone(url, rev, for_write=False):
# Copy to a new dir to keep the clone clean
repo_path = tempfile.mkdtemp("dvc-erepo")
logger.debug("erepo: making a copy of {} clone", url)
logger.debug("erepo: making a copy of %s clone", url)
copy_tree(clone_path, repo_path)
# Check out the specified revision
@@ -234,10 +234,10 @@ def _clone_default_branch(url, rev):
git = Git(clone_path)
# Do not pull for known shas, branches and tags might move
if not Git.is_sha(rev) or not git.has_rev(rev):
logger.debug("erepo: git pull {}", url)
logger.debug("erepo: git pull %s", url)
git.pull()
else:
logger.debug("erepo: git clone {} to a temporary dir", url)
logger.debug("erepo: git clone %s to a temporary dir", url)
clone_path = tempfile.mkdtemp("dvc-clone")
git = Git.clone(url, clone_path)
CLONES[url] = clone_path
@@ -249,7 +249,7 @@ def _clone_default_branch(url, rev):
def _git_checkout(repo_path, rev):
logger.debug("erepo: git checkout {}@{}", repo_path, rev)
logger.debug("erepo: git checkout %s@%s", repo_path, rev)
git = Git(repo_path)
try:
git.checkout(rev)
+2 -1
View File
@@ -55,7 +55,8 @@ class ColorFormatter(logging.Formatter):
}
def format(self, record):
msg = record.msg.format(*record.args) if record.args else record.msg
record.message = record.getMessage()
msg = self.formatMessage(record)
if record.levelname == "INFO":
return msg
+21 -21
View File
@@ -266,7 +266,7 @@ class RemoteBASE(object):
if not isinstance(d, list):
logger.error(
"dir cache file format error '{}' [skipping the file]",
"dir cache file format error '%s' [skipping the file]",
path_info,
)
return []
@@ -334,35 +334,35 @@ class RemoteBASE(object):
"""
logger.debug(
"checking if '{}'('{}') has changed.", path_info, checksum_info
"checking if '%s'('%s') has changed.", path_info, checksum_info
)
if not self.exists(path_info):
logger.debug("'{}' doesn't exist.", path_info)
logger.debug("'%s' doesn't exist.", path_info)
return True
checksum = checksum_info.get(self.PARAM_CHECKSUM)
if checksum is None:
logger.debug("hash value for '{}' is missing.", path_info)
logger.debug("hash value for '%s' is missing.", path_info)
return True
if self.changed_cache(checksum):
logger.debug(
"cache for '{}'('{}') has changed.", path_info, checksum
"cache for '%s'('%s') has changed.", path_info, checksum
)
return True
actual = self.get_checksum(path_info)
if checksum != actual:
logger.debug(
"hash value '{}' for '{}' has changed (actual '{}').",
"hash value '%s' for '%s' has changed (actual '%s').",
checksum,
actual,
path_info,
)
return True
logger.debug("'{}' hasn't changed.", path_info)
logger.debug("'%s' hasn't changed.", path_info)
return False
def link(self, from_info, to_info):
@@ -397,7 +397,7 @@ class RemoteBASE(object):
except DvcException as exc:
logger.debug(
"Cache type '{}' is not supported: {}", link_types[0], exc
"Cache type '%s' is not supported: %s", link_types[0], exc
)
del link_types[0]
@@ -413,7 +413,7 @@ class RemoteBASE(object):
self.protect(to_info)
logger.debug(
"Created {}'{}': {} -> {}",
"Created %s'%s': %s -> %s",
"protected " if self.protected else "",
self.cache_types[0],
from_info,
@@ -522,7 +522,7 @@ class RemoteBASE(object):
def _save(self, path_info, checksum):
to_info = self.checksum_to_path_info(checksum)
logger.debug("Saving '{}' to '{}'.", path_info, to_info)
logger.debug("Saving '%s' to '%s'.", path_info, to_info)
if self.isdir(path_info):
self._save_dir(path_info, checksum)
return
@@ -535,7 +535,7 @@ class RemoteBASE(object):
raise exception
logger.exception(
"failed to {} '{}' to '{}'", operation, from_info, to_info
"failed to %s '%s' to '%s'", operation, from_info, to_info
)
return 1
@@ -549,7 +549,7 @@ class RemoteBASE(object):
if from_info.scheme != "local":
raise NotImplementedError
logger.debug("Uploading '{}' to '{}'", from_info, to_info)
logger.debug("Uploading '%s' to '%s'", from_info, to_info)
name = name or from_info.name
@@ -628,7 +628,7 @@ class RemoteBASE(object):
):
makedirs(to_info.parent, exist_ok=True, mode=dir_mode)
logger.debug("Downloading '{}' to '{}'", from_info, to_info)
logger.debug("Downloading '%s' to '%s'", from_info, to_info)
name = name or to_info.name
tmp_file = tmp_fname(to_info)
@@ -734,7 +734,7 @@ class RemoteBASE(object):
actual = self.get_checksum(cache_info)
logger.debug(
"cache '{}' expected '{}' actual '{}'",
"cache '%s' expected '%s' actual '%s'",
cache_info,
checksum,
actual,
@@ -747,7 +747,7 @@ class RemoteBASE(object):
return False
if self.exists(cache_info):
logger.warning("corrupted cache file '{}'.", cache_info)
logger.warning("corrupted cache file '%s'.", cache_info)
self.remove(cache_info)
return True
@@ -858,7 +858,7 @@ class RemoteBASE(object):
added, modified = True, False
cache_info = self.checksum_to_path_info(checksum)
if self.exists(path_info):
logger.debug("data '{}' will be replaced.", path_info)
logger.debug("data '%s' will be replaced.", path_info)
self.safe_remove(path_info, force=force)
added, modified = False, True
@@ -893,7 +893,7 @@ class RemoteBASE(object):
dir_info = self.get_dir_cache(checksum)
logger.debug("Linking directory '{}'.", path_info)
logger.debug("Linking directory '%s'.", path_info)
for entry in dir_info:
relative_path = entry[self.PARAM_RELPATH]
@@ -953,21 +953,21 @@ class RemoteBASE(object):
skip = False
if not checksum:
logger.warning(
"No file hash info found for '{}'. " "It won't be created.",
"No file hash info found for '%s'. " "It won't be created.",
path_info,
)
self.safe_remove(path_info, force=force)
failed = path_info
elif not relink and not self.changed(path_info, checksum_info):
logger.debug("Data '{}' didn't change.", path_info)
logger.debug("Data '%s' didn't change.", path_info)
skip = True
elif self.changed_cache(
checksum, path_info=path_info, filter_info=filter_info
):
logger.warning(
"Cache '{}' not found. File '{}' won't be created.",
"Cache '%s' not found. File '%s' won't be created.",
checksum,
path_info,
)
@@ -986,7 +986,7 @@ class RemoteBASE(object):
raise CheckoutError([failed])
return
logger.debug("Checking out '{}' with cache '{}'.", path_info, checksum)
logger.debug("Checking out '%s' with cache '%s'.", path_info, checksum)
return self._checkout(
path_info, checksum, force, progress_callback, relink, filter_info,
+4 -4
View File
@@ -137,7 +137,7 @@ class State(object): # pylint: disable=too-many-instance-attributes
def _fetchall(self):
ret = self.cursor.fetchall()
logger.debug("fetched: {}", ret)
logger.debug("fetched: %s", ret)
return ret
def _to_sqlite(self, num):
@@ -178,8 +178,8 @@ class State(object): # pylint: disable=too-many-instance-attributes
)
elif version < self.VERSION:
logger.warning(
"State file version '{}' is too old. "
"Reformatting to the current version '{}'.",
"State file version '%d' is too old. "
"Reformatting to the current version '%d'.",
version,
self.VERSION,
)
@@ -460,7 +460,7 @@ class State(object): # pylint: disable=too-many-instance-attributes
actual_mtime, _ = get_mtime_and_size(path, self.repo.tree)
if (inode, mtime) == (actual_inode, actual_mtime):
logger.debug("Removing '{}' as unused link.", path)
logger.debug("Removing '%s' as unused link.", path)
unused.append(relpath)
return unused
+2 -2
View File
@@ -29,7 +29,7 @@ def fs_copy(src, dst):
def get_inode(path):
inode = System.inode(path)
logger.debug("Path {} inode {}", path, inode)
logger.debug("Path '%s' inode '%d'", path, inode)
return inode
@@ -130,7 +130,7 @@ def _chmod(func, p, excinfo):
def remove(path):
logger.debug("Removing '{}'", path)
logger.debug("Removing '%s'", path)
path = fspath_py35(path)
try: