From 19007ff0814b9eccefef607f2a177edb08ea61c7 Mon Sep 17 00:00:00 2001 From: "Mr. Outis" Date: Fri, 7 Dec 2018 22:39:24 -0600 Subject: [PATCH 1/5] scripts: Add file completion to `dvc add` command (#1423) --- scripts/completion/dvc.zsh | 1 + 1 file changed, 1 insertion(+) diff --git a/scripts/completion/dvc.zsh b/scripts/completion/dvc.zsh index dcf837886..f516aeb45 100644 --- a/scripts/completion/dvc.zsh +++ b/scripts/completion/dvc.zsh @@ -61,6 +61,7 @@ _dvc_destroy=( _dvc_add=( {-R,--recursive}"[Recursively add each file under the directory.]" + "1:File:_files" ) _dvc_import=( From b8e5c51424f9ad7534ccd7b6eeed84307d644397 Mon Sep 17 00:00:00 2001 From: Ruslan Kuprieiev Date: Mon, 10 Dec 2018 05:58:35 +0200 Subject: [PATCH 2/5] cli: fix run description --- dvc/cli.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/dvc/cli.py b/dvc/cli.py index 627694e43..9ac5f5db5 100644 --- a/dvc/cli.py +++ b/dvc/cli.py @@ -293,7 +293,7 @@ def parse_args(argv=None): run_parser.add_argument( 'command', nargs=argparse.REMAINDER, - help='Command or command file to execute.') + help='Command to execute.') run_parser.set_defaults(func=CmdRun) # Parent parser used in pull/push/status From cf8ab291294e2e41a7cf92ae5a2e170a3b1d7aa4 Mon Sep 17 00:00:00 2001 From: Ruslan Kuprieiev Date: Tue, 11 Dec 2018 05:24:59 +0200 Subject: [PATCH 3/5] local: don't use relpath in debug msgs Signed-off-by: Ruslan Kuprieiev --- dvc/remote/local.py | 11 ++--------- 1 file changed, 2 insertions(+), 9 deletions(-) diff --git a/dvc/remote/local.py b/dvc/remote/local.py index 7d5845530..f30f1bff7 100644 --- a/dvc/remote/local.py +++ b/dvc/remote/local.py @@ -133,11 +133,7 @@ class RemoteLOCAL(RemoteBase): if os.path.getsize(cache) == 0: open(path, 'w+').close() - msg = "Created empty file: {} -> {}".format( - os.path.relpath(cache), - os.path.relpath(path), - ) - + msg = "Created empty file: {} -> {}".format(cache, path) Logger.debug(msg) return @@ -151,10 +147,7 @@ class RemoteLOCAL(RemoteBase): msg = "Created {}'{}': {} -> {}".format( 'protected ' if self.protected else '', - self.cache_types[0], - os.path.relpath(cache), - os.path.relpath(path) - ) + self.cache_types[0], cache, path) Logger.debug(msg) return From e02a33f934a3d78cad3ec75b80d9e74966908a15 Mon Sep 17 00:00:00 2001 From: Ruslan Kuprieiev Date: Tue, 11 Dec 2018 11:49:17 +0200 Subject: [PATCH 4/5] logger: shortcut logger in quiet and normal modes In scenarios with millions of files, late shorcutting of debug msgs results in massive overhead. In order to avoid that, just shortcut logger messages ASAP if verbose mode is not enabled. Signed-off-by: Ruslan Kuprieiev --- dvc/analytics.py | 12 +-- dvc/cli.py | 4 +- dvc/command/add.py | 4 +- dvc/command/base.py | 8 +- dvc/command/config.py | 8 +- dvc/command/imp.py | 4 +- dvc/command/init.py | 4 +- dvc/command/install.py | 4 +- dvc/command/remote.py | 6 +- dvc/command/remove.py | 4 +- dvc/config.py | 6 +- dvc/daemon.py | 10 +-- dvc/data_cloud.py | 6 +- dvc/dependency/local.py | 4 +- dvc/logger.py | 194 +++++++++++++++++++--------------------- dvc/main.py | 10 +-- dvc/progress.py | 4 +- dvc/project.py | 11 +-- dvc/remote/azure.py | 12 +-- dvc/remote/base.py | 4 +- dvc/remote/gs.py | 22 ++--- dvc/remote/hdfs.py | 14 +-- dvc/remote/http.py | 6 +- dvc/remote/local.py | 42 ++++----- dvc/remote/s3.py | 22 ++--- dvc/remote/ssh.py | 26 +++--- dvc/scm.py | 6 +- dvc/stage.py | 10 +-- dvc/state.py | 14 +-- dvc/updater.py | 12 +-- dvc/utils.py | 6 +- tests/test_logger.py | 91 ++++++++++--------- 32 files changed, 292 insertions(+), 298 deletions(-) diff --git a/dvc/analytics.py b/dvc/analytics.py index 67c6d39fa..f0604aa88 100644 --- a/dvc/analytics.py +++ b/dvc/analytics.py @@ -3,7 +3,7 @@ import json import errno from dvc import VERSION -from dvc.logger import Logger +from dvc.logger import logger class Analytics(object): @@ -75,7 +75,7 @@ class Analytics(object): info = json.load(fobj) return info[self.PARAM_USER_ID] except json.JSONDecodeError as exc: - Logger.debug("Failed to load user_id: {}".format(exc)) + logger.debug("Failed to load user_id: {}".format(exc)) return None def _get_user_id(self): @@ -89,7 +89,7 @@ class Analytics(object): return user_id except LockError: msg = "Failed to acquire '{}'" - Logger.debug(msg.format(self.user_id_file_lock.lock_file)) + logger.debug(msg.format(self.user_id_file_lock.lock_file)) def _collect_windows(self): import sys @@ -194,7 +194,7 @@ class Analytics(object): core = config._config.get(Config.SECTION_CORE, {}) enabled = core.get(Config.SECTION_CORE_ANALYTICS, True) - Logger.debug("Analytics is {}abled." + logger.debug("Analytics is {}abled." .format('en' if enabled else 'dis')) return enabled @@ -217,9 +217,9 @@ class Analytics(object): self.collect() - Logger.debug("Sending analytics: {}".format(self.info)) + logger.debug("Sending analytics: {}".format(self.info)) try: requests.post(self.URL, json=self.info, timeout=self.TIMEOUT_POST) except requests.exceptions.RequestException as exc: - Logger.debug("Failed to send analytics: {}".format(str(exc))) + logger.debug("Failed to send analytics: {}".format(str(exc))) diff --git a/dvc/cli.py b/dvc/cli.py index 9ac5f5db5..10dcc09d7 100644 --- a/dvc/cli.py +++ b/dvc/cli.py @@ -28,7 +28,7 @@ from dvc.command.lock import CmdLock, CmdUnlock from dvc.command.pipeline import CmdPipelineShow, CmdPipelineList from dvc.command.daemon import CmdDaemonUpdater, CmdDaemonAnalytics from dvc.exceptions import DvcParserError -from dvc.logger import Logger +from dvc.logger import logger from dvc import VERSION @@ -44,7 +44,7 @@ def _fix_subparsers(subparsers): class DvcParser(argparse.ArgumentParser): def error(self, message): - sys.stderr.write('{}: {}\n'.format(Logger.error_prefix(), message)) + sys.stderr.write('{}: {}\n'.format(logger.error_prefix(), message)) self.print_help() raise DvcParserError() diff --git a/dvc/command/add.py b/dvc/command/add.py index ae11035bb..1b81361e6 100644 --- a/dvc/command/add.py +++ b/dvc/command/add.py @@ -1,6 +1,6 @@ from dvc.exceptions import DvcException from dvc.command.base import CmdBase -from dvc.logger import Logger +from dvc.logger import logger class CmdAdd(CmdBase): @@ -9,6 +9,6 @@ class CmdAdd(CmdBase): try: self.project.add(target, recursive=self.args.recursive) except DvcException as ex: - Logger.error('Failed to add \'{}\''.format(target), ex) + logger.error('Failed to add \'{}\''.format(target), ex) return 1 return 0 diff --git a/dvc/command/base.py b/dvc/command/base.py index 2d9be98c1..1eadfd541 100644 --- a/dvc/command/base.py +++ b/dvc/command/base.py @@ -1,4 +1,4 @@ -from dvc.logger import Logger +from dvc.logger import logger class CmdBase(object): @@ -13,10 +13,10 @@ class CmdBase(object): @staticmethod def _set_loglevel(args): if args.quiet: - Logger.be_quiet() + logger.be_quiet() elif args.verbose: - Logger.be_verbose() + logger.be_verbose() def run_cmd(self): from dvc.lock import LockError @@ -25,7 +25,7 @@ class CmdBase(object): with self.project.lock: return self.run() except LockError as ex: - Logger.error('Failed to lock before running a command', ex) + logger.error('Failed to lock before running a command', ex) return 1 # Abstract methods that have to be implemented by any inheritance class diff --git a/dvc/command/config.py b/dvc/command/config.py index 75fb009fd..ea33654ae 100644 --- a/dvc/command/config.py +++ b/dvc/command/config.py @@ -1,7 +1,7 @@ import os from dvc.command.base import CmdBase -from dvc.logger import Logger +from dvc.logger import logger from dvc.config import Config from dvc.exceptions import DvcException @@ -44,7 +44,7 @@ class CmdConfig(CmdBase): self.config.unset(configobj, section, opt) self.config.save(configobj) except DvcException as exc: - Logger.error("Failed to unset '{}'".format(self.args.name), exc) + logger.error("Failed to unset '{}'".format(self.args.name), exc) return 1 return 0 @@ -52,7 +52,7 @@ class CmdConfig(CmdBase): try: self.config.show(self.configobj, section, opt) except DvcException as exc: - Logger.error("Failed to show '{}'".format(self.args.name), exc) + logger.error("Failed to show '{}'".format(self.args.name), exc) return 1 return 0 @@ -61,7 +61,7 @@ class CmdConfig(CmdBase): self.config.set(self.configobj, section, opt, value) self.config.save(self.configobj) except DvcException as exc: - Logger.error("Failed to set '{}.{}' to '{}'".format(section, + logger.error("Failed to set '{}.{}' to '{}'".format(section, opt, value), exc) diff --git a/dvc/command/imp.py b/dvc/command/imp.py index d7d9835b7..a8316f3de 100644 --- a/dvc/command/imp.py +++ b/dvc/command/imp.py @@ -7,7 +7,7 @@ except ImportError: from dvc.exceptions import DvcException from dvc.command.base import CmdBase -from dvc.logger import Logger +from dvc.logger import logger class CmdImport(CmdBase): @@ -21,6 +21,6 @@ class CmdImport(CmdBase): self.project.imp(self.args.url, out) except DvcException as ex: - Logger.error('Failed to import {}'.format(self.args.url), ex) + logger.error('Failed to import {}'.format(self.args.url), ex) return 1 return 0 diff --git a/dvc/command/init.py b/dvc/command/init.py index 988551b32..a8bcc3376 100644 --- a/dvc/command/init.py +++ b/dvc/command/init.py @@ -1,4 +1,4 @@ -from dvc.logger import Logger +from dvc.logger import logger class CmdInit(object): @@ -14,6 +14,6 @@ class CmdInit(object): force=self.args.force) self.config = self.project.config except InitError as e: - Logger.error('Failed to initiate dvc', e) + logger.error('Failed to initiate dvc', e) return 1 return 0 diff --git a/dvc/command/install.py b/dvc/command/install.py index 55d6341de..0ac3c2bd8 100644 --- a/dvc/command/install.py +++ b/dvc/command/install.py @@ -1,4 +1,4 @@ -from dvc.logger import Logger +from dvc.logger import logger from dvc.command.base import CmdBase @@ -7,6 +7,6 @@ class CmdInstall(CmdBase): try: self.project.install() except Exception as e: - Logger.error('Failed to install dvc hooks', e) + logger.error('Failed to install dvc hooks', e) return 1 return 0 diff --git a/dvc/command/remote.py b/dvc/command/remote.py index 384197285..011823265 100644 --- a/dvc/command/remote.py +++ b/dvc/command/remote.py @@ -2,7 +2,7 @@ import re from dvc.config import Config from dvc.command.config import CmdConfig -from dvc.logger import Logger +from dvc.logger import logger class CmdRemoteAdd(CmdConfig): @@ -14,7 +14,7 @@ class CmdRemoteAdd(CmdConfig): if self.args.default: msg = 'Setting \'{}\' as a default remote.'.format(self.args.name) - Logger.info(msg) + logger.info(msg) ret = self._set(Config.SECTION_CORE, Config.SECTION_CORE_REMOTE, self.args.name) @@ -70,5 +70,5 @@ class CmdRemoteList(CmdConfig): name = r.group('name') url = self.configobj[section].get(Config.SECTION_REMOTE_URL, '') - Logger.info('{}\t{}'.format(name, url)) + logger.info('{}\t{}'.format(name, url)) return 0 diff --git a/dvc/command/remove.py b/dvc/command/remove.py index 41de21e2f..df3d35dad 100644 --- a/dvc/command/remove.py +++ b/dvc/command/remove.py @@ -1,6 +1,6 @@ from dvc.exceptions import DvcException from dvc.command.base import CmdBase -from dvc.logger import Logger +from dvc.logger import logger class CmdRemove(CmdBase): @@ -32,6 +32,6 @@ class CmdRemove(CmdBase): outs_only = self._is_outs_only(target) self.project.remove(target, outs_only=outs_only) except DvcException as ex: - Logger.error('Failed to remove {}'.format(target), ex) + logger.error('Failed to remove {}'.format(target), ex) return 1 return 0 diff --git a/dvc/config.py b/dvc/config.py index c310be2ec..ade17be31 100644 --- a/dvc/config.py +++ b/dvc/config.py @@ -6,7 +6,7 @@ import errno import configobj from schema import Schema, Optional, And, Use, Regex -from dvc.logger import Logger +from dvc.logger import logger from dvc.exceptions import DvcException @@ -295,7 +295,7 @@ class Config(object): continue try: - Logger.debug("Writing '{}'.".format(conf.filename)) + logger.debug("Writing '{}'.".format(conf.filename)) dname = os.path.dirname(os.path.abspath(conf.filename)) try: os.makedirs(dname) @@ -337,7 +337,7 @@ class Config(object): raise ConfigError("Option '{}.{}' doesn't exist".format(section, opt)) - Logger.info(config[section][opt]) + logger.info(config[section][opt]) @staticmethod def _merge(first, second): diff --git a/dvc/daemon.py b/dvc/daemon.py index a4d715707..3ae15147d 100644 --- a/dvc/daemon.py +++ b/dvc/daemon.py @@ -1,7 +1,7 @@ import os import sys from subprocess import Popen -from dvc.logger import Logger +from dvc.logger import logger class Daemon(object): # pragma: no cover @@ -20,7 +20,7 @@ class Daemon(object): # pragma: no cover if pid > 0: return except OSError as exc: - Logger.error("Failed at first fork", exc) + logger.error("Failed at first fork", exc) sys.exit(1) os.setsid() @@ -31,7 +31,7 @@ class Daemon(object): # pragma: no cover if pid > 0: sys.exit(0) except OSError as exc: - Logger.error("Failed at second fork", exc) + logger.error("Failed at second fork", exc) sys.exit(1) sys.stdin.close() @@ -50,7 +50,7 @@ class Daemon(object): # pragma: no cover cmd += ['-m', 'dvc'] cmd += ['daemon', '-q'] + args - Logger.debug("Trying to spawn '{}'".format(cmd)) + logger.debug("Trying to spawn '{}'".format(cmd)) if os.name == 'nt': self._spawn_windows(cmd) @@ -59,4 +59,4 @@ class Daemon(object): # pragma: no cover else: raise NotImplementedError - Logger.debug("Spawned '{}'".format(cmd)) + logger.debug("Spawned '{}'".format(cmd)) diff --git a/dvc/data_cloud.py b/dvc/data_cloud.py index 91ba35bb3..fd55f665b 100644 --- a/dvc/data_cloud.py +++ b/dvc/data_cloud.py @@ -1,4 +1,4 @@ -from dvc.logger import Logger +from dvc.logger import logger from dvc.config import Config, ConfigError from dvc.remote.s3 import RemoteS3 @@ -36,7 +36,7 @@ class DataCloud(object): if self._core.get(Config.SECTION_CORE_CLOUD, None): # backward compatibility msg = 'Using obsoleted config format. Consider updating.' - Logger.warn(msg) + logger.warn(msg) return self._init_compat() return None @@ -87,7 +87,7 @@ class DataCloud(object): def _init_cloud(self, cloud_config, cloud_type): global_storage_path = self._core.get(Config.SECTION_CORE_STORAGEPATH) if global_storage_path: - Logger.warn('Using obsoleted config format. Consider updating.') + logger.warn('Using obsoleted config format. Consider updating.') cloud = cloud_type(self.project, cloud_config) return cloud diff --git a/dvc/dependency/local.py b/dvc/dependency/local.py index 696672a88..e858cf54a 100644 --- a/dvc/dependency/local.py +++ b/dvc/dependency/local.py @@ -8,7 +8,6 @@ except ImportError: from dvc.dependency.base import DependencyBase from dvc.dependency.base import DependencyDoesNotExistError from dvc.dependency.base import DependencyIsNotFileOrDirError -from dvc.logger import Logger from dvc.remote.local import RemoteLOCAL @@ -73,7 +72,8 @@ class DependencyLOCAL(DependencyBase): if (os.path.isfile(self.path) and os.path.getsize(self.path) == 0) or \ (os.path.isdir(self.path) and len(os.listdir(self.path)) == 0): - Logger.warn("File/directory '{}' is empty.".format(self.rel_path)) + msg = "File/directory '{}' is empty.".format(self.rel_path) + self.project.logger.warn(msg) self.info = self.remote.save_info(self.path_info) diff --git a/dvc/logger.py b/dvc/logger.py index 971b31f7b..b750743df 100644 --- a/dvc/logger.py +++ b/dvc/logger.py @@ -27,6 +27,7 @@ def visual_center(line, width): class Logger(object): FMT = '%(message)s' DEFAULT_LEVEL = logging.INFO + DEFAULT_LEVEL_NAME = 'info' LEVEL_MAP = { 'debug': logging.DEBUG, @@ -48,66 +49,55 @@ class Logger(object): 'error': 'red', } - def __init__(self, loglevel=None): - if loglevel: - Logger.set_level(loglevel) + def __init__(self, loglevel=None, force=False): + self.logger = logging.getLogger('dvc') + if force or not self._already_initialized(): + class LogLevelFilter(logging.Filter): + def filter(self, record): + return record.levelno <= logging.WARNING - @staticmethod - def init(): + sh_out = logging.StreamHandler(sys.stdout) + sh_out.setFormatter(logging.Formatter(self.FMT)) + sh_out.setLevel(logging.DEBUG) + sh_out.addFilter(LogLevelFilter()) - class LogLevelFilter(logging.Filter): - def filter(self, record): - return record.levelno <= logging.WARNING + sh_err = logging.StreamHandler(sys.stderr) + sh_err.setFormatter(logging.Formatter(self.FMT)) + sh_err.setLevel(logging.ERROR) - if Logger._already_initialized(): - return + self.logger.addHandler(sh_out) + self.logger.addHandler(sh_err) - sh_out = logging.StreamHandler(sys.stdout) - sh_out.setFormatter(logging.Formatter(Logger.FMT)) - sh_out.setLevel(logging.DEBUG) - sh_out.addFilter(LogLevelFilter()) + self.set_level(loglevel) - sh_err = logging.StreamHandler(sys.stderr) - sh_err.setFormatter(logging.Formatter(Logger.FMT)) - sh_err.setLevel(logging.ERROR) - - Logger.logger().addHandler(sh_out) - Logger.logger().addHandler(sh_err) - Logger.set_level() - - @staticmethod - def logger(): - return logging.getLogger('dvc') - - @staticmethod - def set_level(level=None): + def set_level(self, level=None): if not level: - lvl = Logger.DEFAULT_LEVEL + lvl = self.DEFAULT_LEVEL else: - lvl = Logger.LEVEL_MAP.get(level.lower(), Logger.DEFAULT_LEVEL) - Logger.logger().setLevel(lvl) + level = level.lower() + lvl = self.LEVEL_MAP.get(level, self.DEFAULT_LEVEL) + self.logger.setLevel(lvl) + self.lvl = lvl - @staticmethod - def be_quiet(): - Logger.logger().setLevel(logging.CRITICAL) + def be_quiet(self): + self.lvl = logging.CRITICAL + self.logger.setLevel(logging.CRITICAL) - @staticmethod - def be_verbose(): - Logger.logger().setLevel(logging.DEBUG) + def be_verbose(self): + self.lvl = logging.DEBUG + self.logger.setLevel(logging.DEBUG) - @staticmethod - def colorize(msg, color): + def colorize(self, msg, color): header = '' footer = '' if sys.stdout.isatty(): # pragma: no cover - header = Logger.COLOR_MAP.get(color.lower(), '') + header = self.COLOR_MAP.get(color.lower(), '') footer = colorama.Style.RESET_ALL return u'{}{}{}'.format(header, msg, footer) - @staticmethod - def parse_exc(exc, tb=None): + def parse_exc(self, exc, tb=None): str_tb = tb if tb else None str_exc = str(exc) if exc else "" l_str_exc = [] @@ -117,91 +107,89 @@ class Logger(object): if exc and hasattr(exc, 'cause') and exc.cause: cause_tb = exc.cause_tb if hasattr(exc, 'cause_tb') else None - l_cause_str_exc, cause_str_tb = Logger.parse_exc(exc.cause, - cause_tb) + l_cause_str_exc, cause_str_tb = self.parse_exc(exc.cause, cause_tb) str_tb = cause_str_tb l_str_exc += l_cause_str_exc return (l_str_exc, str_tb) - @staticmethod - def _prefix(msg, typ): - color = Logger.LEVEL_COLOR_MAP.get(typ.lower(), '') - return Logger.colorize('{}'.format(msg), color) + def _prefix(self, msg, typ): + color = self.LEVEL_COLOR_MAP.get(typ.lower(), '') + return self.colorize('{}'.format(msg), color) - @staticmethod - def error_prefix(): - return Logger._prefix('Error', 'error') + def error_prefix(self): + return self._prefix('Error', 'error') - @staticmethod - def warning_prefix(): - return Logger._prefix('Warning', 'warn') + def warning_prefix(self): + return self._prefix('Warning', 'warn') - @staticmethod - def debug_prefix(): - return Logger._prefix('Debug', 'debug') + def debug_prefix(self): + return self._prefix('Debug', 'debug') - @staticmethod - def _with_progress(func, msg): + def _with_progress(self, func, msg): from dvc.progress import progress with progress: func(msg) - @staticmethod - def _with_exc(func, prefix, msg, suffix="", exc=None): - l_str_exc, str_tb = Logger.parse_exc(exc) + def _with_exc(self, func, prefix, msg, suffix="", exc=None): + l_str_exc, str_tb = self.parse_exc(exc) - if exc is not None and Logger.is_verbose(): + if exc is not None and self.is_verbose(): str_tb = str_tb if str_tb else traceback.format_exc() - Logger._with_progress(Logger.logger().error, str_tb) + self._with_progress(self.logger.error, str_tb) l_msg = [prefix] if msg is not None and len(msg) != 0: l_msg.append(msg) l_msg += l_str_exc - Logger._with_progress(func, ': '.join(l_msg) + suffix) + self._with_progress(func, ': '.join(l_msg) + suffix) + + def error(self, msg, exc=None): + if self.is_quiet(): + return - @staticmethod - def error(msg, exc=None): chat = "\n\nHaving any troubles? Hit us up at dvc.org/support, " \ "we are always happy to help!" - Logger._with_exc(Logger.logger().error, - Logger.error_prefix(), - msg, - suffix=chat, - exc=exc) + self._with_exc(self.logger.error, + self.error_prefix(), + msg, + suffix=chat, + exc=exc) - @classmethod - def warn(cls, msg, exc=None): - cls._with_exc(cls.logger().warning, - cls.warning_prefix(), - msg, - exc=exc) + def warn(self, msg, exc=None): + if self.is_quiet(): + return - @classmethod - def debug(cls, msg, exc=None): - cls._with_exc(cls.logger().debug, - cls.debug_prefix(), - msg, - exc=exc) + self._with_exc(self.logger.warning, + self.warning_prefix(), + msg, + exc=exc) - @staticmethod - def info(msg): - Logger._with_progress(Logger.logger().info, msg) + def debug(self, msg, exc=None): + if not self.is_verbose(): + return - @staticmethod - def is_quiet(): - return Logger.logger().level == logging.CRITICAL + self._with_exc(self.logger.debug, + self.debug_prefix(), + msg, + exc=exc) - @staticmethod - def is_verbose(): - return Logger.logger().getEffectiveLevel() == logging.DEBUG + def info(self, msg): + if self.is_quiet(): + return - @classmethod - def box(cls, msg, border_color=''): - if cls.is_quiet(): + self._with_progress(self.logger.info, msg) + + def is_quiet(self): + return self.lvl == logging.CRITICAL + + def is_verbose(self): + return self.lvl == logging.DEBUG + + def box(self, msg, border_color=''): + if self.is_quiet(): return lines = msg.split('\n') @@ -226,27 +214,29 @@ class Logger(object): padding_lines = [ "{border}{space}{border}\n".format( - border=cls.colorize(chars['vertical'], border_color), + border=self.colorize(chars['vertical'], border_color), space=chars['empty'] * box_size_horizontal, ) * padding_vertical ] content_lines = [ "{border}{space}{content}{space}{border}\n".format( - border=cls.colorize(chars['vertical'], border_color), + border=self.colorize(chars['vertical'], border_color), space=chars['empty'] * padding_horizontal, content=visual_center(line, max_width), ) for line in lines ] box = "{margin}{padding}{content}{padding}{margin}".format( - margin=cls.colorize(margin, border_color), + margin=self.colorize(margin, border_color), padding=''.join(padding_lines), content=''.join(content_lines), ) print(box) - @staticmethod - def _already_initialized(): - return bool(Logger.logger().handlers) + def _already_initialized(self): + return bool(self.logger.handlers) + + +logger = Logger() diff --git a/dvc/main.py b/dvc/main.py index ab1aa96ee..61ee3562e 100644 --- a/dvc/main.py +++ b/dvc/main.py @@ -1,4 +1,4 @@ -from dvc.logger import Logger +from dvc.logger import logger from dvc.cli import parse_args from dvc.command.base import CmdBase from dvc.analytics import Analytics @@ -6,8 +6,6 @@ from dvc.exceptions import NotDvcProjectError, DvcParserError def main(argv=None): - Logger.init() - args = None cmd = None try: @@ -21,15 +19,15 @@ def main(argv=None): ret = cmd.run_cmd() except KeyboardInterrupt as ex: - Logger.error("Interrupted by the user", ex) + logger.error("Interrupted by the user", ex) ret = 252 except NotDvcProjectError as ex: - Logger.error("", ex) + logger.error("", ex) ret = 253 except DvcParserError: ret = 254 except Exception as ex: - Logger.error('Unexpected error', ex) + logger.error('Unexpected error', ex) ret = 255 Analytics().send_cmd(cmd, args, ret) diff --git a/dvc/progress.py b/dvc/progress.py index 7ec2e2c82..ad8c9867c 100644 --- a/dvc/progress.py +++ b/dvc/progress.py @@ -86,9 +86,9 @@ class Progress(object): return num + bar + percent + target_name def _print(self, *args, **kwargs): - from dvc.logger import Logger + from dvc.logger import logger - if Logger.is_quiet(): + if logger.is_quiet(): return print(*args, **kwargs) diff --git a/dvc/project.py b/dvc/project.py index be08b2ae8..526d8de75 100644 --- a/dvc/project.py +++ b/dvc/project.py @@ -21,7 +21,7 @@ class Project(object): DVC_DIR = '.dvc' def __init__(self, root_dir=None): - from dvc.logger import Logger + from dvc.logger import logger from dvc.config import Config from dvc.state import State from dvc.lock import Lock @@ -45,7 +45,8 @@ class Project(object): self.state = State(self, self.config._config) core = self.config._config[Config.SECTION_CORE] - self.logger = Logger(core.get(Config.SECTION_CORE_LOGLEVEL, None)) + self.logger = logger + self.logger.set_level(core.get(Config.SECTION_CORE_LOGLEVEL, None)) self.cache = Cache(self) self.cloud = DataCloud(self, config=self.config._config) @@ -106,7 +107,7 @@ class Project(object): import shutil from dvc.scm import SCM, Base from dvc.config import Config - from dvc.logger import Logger + from dvc.logger import logger root_dir = os.path.abspath(root_dir) dvc_dir = os.path.join(root_dir, Project.DVC_DIR) @@ -130,9 +131,9 @@ class Project(object): if scm.ignore_file(): scm.add([os.path.join(dvc_dir, scm.ignore_file())]) - Logger.info('\nYou can now commit the changes to git.') + logger.info('\nYou can now commit the changes to git.') - Logger.info( + logger.info( "\n" "{yellow}What's next?{nc}\n" "{yellow}------------{nc}\n" diff --git a/dvc/remote/azure.py b/dvc/remote/azure.py index 2bc3112b6..f971b4141 100644 --- a/dvc/remote/azure.py +++ b/dvc/remote/azure.py @@ -8,7 +8,7 @@ try: except ImportError: BlockBlobService = None -from dvc.logger import Logger +from dvc.logger import logger from dvc.progress import progress from dvc.config import Config from dvc.remote.base import RemoteBase @@ -129,7 +129,7 @@ class RemoteAzure(RemoteBase): if path_info['scheme'] != self.scheme: raise NotImplementedError - Logger.debug('Removing azure://{}/{}'.format(path_info['bucket'], + logger.debug('Removing azure://{}/{}'.format(path_info['bucket'], path_info['key'])) self.blob_service.delete_blob(path_info['bucket'], path_info['key']) @@ -177,7 +177,7 @@ class RemoteAzure(RemoteBase): bucket = to_info['bucket'] key = to_info['key'] - Logger.debug("Uploading '{}' to '{}/{}'".format( + logger.debug("Uploading '{}' to '{}/{}'".format( from_info['path'], bucket, key)) if not name: @@ -190,7 +190,7 @@ class RemoteAzure(RemoteBase): bucket, key, from_info['path'], progress_callback=cb) except Exception as ex: msg = "Failed to upload '{}'".format(from_info['path']) - Logger.warn(msg, ex) + logger.warn(msg, ex) else: progress.finish_target(name) @@ -211,7 +211,7 @@ class RemoteAzure(RemoteBase): bucket = from_info['bucket'] key = from_info['key'] - Logger.debug("Downloading '{}/{}' to '{}'".format( + logger.debug("Downloading '{}/{}' to '{}'".format( bucket, key, to_info['path'])) tmp_file = self.tmp_file(to_info['path']) @@ -227,7 +227,7 @@ class RemoteAzure(RemoteBase): bucket, key, tmp_file, progress_callback=cb) except Exception as exc: msg = "Failed to download '{}/{}'".format(bucket, key) - Logger.warn(msg, exc) + logger.warn(msg, exc) else: os.rename(tmp_file, to_info['path']) diff --git a/dvc/remote/base.py b/dvc/remote/base.py index 8868e4156..a61fb87b2 100644 --- a/dvc/remote/base.py +++ b/dvc/remote/base.py @@ -4,7 +4,7 @@ import errno from multiprocessing import cpu_count from dvc.config import Config -from dvc.logger import Logger +from dvc.logger import logger from dvc.exceptions import DvcException @@ -69,7 +69,7 @@ class RemoteBase(object): "are still seeing this message, please report it to us " \ "using https://github.com/iterative/dvc/issues. Thank you!" msg = msg.format(url, missing, " ".join(missing), cls.scheme) - Logger.warn(msg) + logger.warn(msg) return url_ok and deps_ok diff --git a/dvc/remote/gs.py b/dvc/remote/gs.py index 049f75335..23830071f 100644 --- a/dvc/remote/gs.py +++ b/dvc/remote/gs.py @@ -11,7 +11,7 @@ try: except ImportError: from urllib.parse import urlparse -from dvc.logger import Logger +from dvc.logger import logger from dvc.remote.base import RemoteBase from dvc.remote.local import RemoteLOCAL from dvc.config import Config @@ -84,7 +84,7 @@ class RemoteGS(RemoteBase): if {self.PARAM_MD5: md5} != self.save_info(cache): if self.exists([cache])[0]: msg = 'Corrupted cache file {}' - Logger.warn(msg.format(self.to_string(cache))) + logger.warn(msg.format(self.to_string(cache))) self.remove(cache) return True @@ -138,22 +138,22 @@ class RemoteGS(RemoteBase): if not self.changed(path_info, checksum_info): msg = "Data '{}' didn't change." - Logger.info(msg.format(self.to_string(path_info))) + logger.info(msg.format(self.to_string(path_info))) return if self.changed_cache(md5): msg = "Cache '{}' not found. File '{}' won't be created." - Logger.warn(msg.format(md5, self.to_string(path_info))) + logger.warn(msg.format(md5, self.to_string(path_info))) return if self.exists([path_info])[0]: msg = "Data '{}' exists. Removing before checkout." - Logger.warn(msg.format(self.to_string(path_info))) + logger.warn(msg.format(self.to_string(path_info))) self.remove(path_info) return msg = "Checking out '{}' with cache '{}'." - Logger.info(msg.format(self.to_string(path_info), md5)) + logger.info(msg.format(self.to_string(path_info), md5)) key = posixpath.join(self.prefix, md5[0:2], md5[2:]) from_info = {'scheme': 'gs', 'bucket': self.bucket, 'key': key} @@ -164,7 +164,7 @@ class RemoteGS(RemoteBase): if path_info['scheme'] != 'gs': raise NotImplementedError - Logger.debug("Removing gs://{}/{}".format(path_info['bucket'], + logger.debug("Removing gs://{}/{}".format(path_info['bucket'], path_info['key'])) blob = self.gs.bucket(path_info['bucket']).get_blob(path_info['key']) @@ -213,7 +213,7 @@ class RemoteGS(RemoteBase): if from_info['scheme'] != 'local': raise NotImplementedError - Logger.debug("Uploading '{}' to '{}/{}'".format(from_info['path'], + logger.debug("Uploading '{}' to '{}/{}'".format(from_info['path'], to_info['bucket'], to_info['key'])) @@ -228,7 +228,7 @@ class RemoteGS(RemoteBase): blob.upload_from_filename(from_info['path']) except Exception as exc: msg = "Failed to upload '{}' to '{}/{}'" - Logger.warn(msg.format(from_info['path'], + logger.warn(msg.format(from_info['path'], to_info['bucket'], to_info['key']), exc) continue @@ -258,7 +258,7 @@ class RemoteGS(RemoteBase): msg = "Downloading '{}/{}' to '{}'".format(from_info['bucket'], from_info['key'], to_info['path']) - Logger.debug(msg) + logger.debug(msg) tmp_file = self.tmp_file(to_info['path']) if not name: @@ -277,7 +277,7 @@ class RemoteGS(RemoteBase): blob.download_to_filename(tmp_file) except Exception as exc: msg = "Failed to download '{}/{}' to '{}'" - Logger.warn(msg.format(from_info['bucket'], + logger.warn(msg.format(from_info['bucket'], from_info['key'], to_info['path']), exc) continue diff --git a/dvc/remote/hdfs.py b/dvc/remote/hdfs.py index 1f5a337ed..dfc1f331c 100644 --- a/dvc/remote/hdfs.py +++ b/dvc/remote/hdfs.py @@ -7,7 +7,7 @@ from subprocess import Popen, PIPE from dvc.config import Config from dvc.remote.base import RemoteBase, RemoteBaseCmdError from dvc.remote.local import RemoteLOCAL -from dvc.logger import Logger +from dvc.logger import logger from dvc.utils import fix_env @@ -95,7 +95,7 @@ class RemoteHDFS(RemoteBase): if {self.PARAM_CHECKSUM: checksum} != self.save_info(cache): if self.exists([cache])[0]: msg = 'Corrupted cache file {}' - Logger.warn(msg.format(self.to_string(cache))) + logger.warn(msg.format(self.to_string(cache))) self.remove(cache) return True @@ -140,22 +140,22 @@ class RemoteHDFS(RemoteBase): if not self.changed(path_info, checksum_info): msg = "Data '{}' didn't change." - Logger.info(msg.format(self.to_string(path_info))) + logger.info(msg.format(self.to_string(path_info))) return if self.changed_cache(checksum): msg = "Cache '{}' not found. File '{}' won't be created." - Logger.warn(msg.format(checksum, self.to_string(path_info))) + logger.warn(msg.format(checksum, self.to_string(path_info))) return if self.exists([path_info])[0]: msg = "Data '{}' exists. Removing before checkout." - Logger.warn(msg.format(self.to_string(path_info))) + logger.warn(msg.format(self.to_string(path_info))) self.remove(path_info) return msg = "Checking out '{}' with cache '{}'." - Logger.info(msg.format(self.to_string(path_info), checksum)) + logger.info(msg.format(self.to_string(path_info), checksum)) src = path_info.copy() src['url'] = posixpath.join(self.url, checksum[0:2], checksum[2:]) @@ -168,7 +168,7 @@ class RemoteHDFS(RemoteBase): assert path_info.get('url') - Logger.debug('Removing {}'.format(path_info['url'])) + logger.debug('Removing {}'.format(path_info['url'])) self.rm(path_info) diff --git a/dvc/remote/http.py b/dvc/remote/http.py index 10390715b..171a0737f 100644 --- a/dvc/remote/http.py +++ b/dvc/remote/http.py @@ -3,7 +3,7 @@ import threading import requests import posixpath -from dvc.logger import Logger +from dvc.logger import logger from dvc.progress import progress from dvc.exceptions import DvcException from dvc.config import Config @@ -54,7 +54,7 @@ class RemoteHTTP(RemoteBase): msg = "Downloading '{}' to '{}'".format(from_info['url'], to_info['path']) - Logger.debug(msg) + logger.debug(msg) tmp_file = self.tmp_file(to_info['path']) if not name: @@ -73,7 +73,7 @@ class RemoteHTTP(RemoteBase): self._download_to(from_info['url'], tmp_file, callback=cb) except Exception as exc: msg = "Failed to download '{}'".format(from_info['url']) - Logger.warn(msg, exc) + logger.warn(msg, exc) continue os.rename(tmp_file, to_info['path']) diff --git a/dvc/remote/local.py b/dvc/remote/local.py index f30f1bff7..3274ce9c1 100644 --- a/dvc/remote/local.py +++ b/dvc/remote/local.py @@ -9,7 +9,7 @@ from operator import itemgetter from dvc.system import System from dvc.remote.base import RemoteBase, STATUS_MAP -from dvc.logger import Logger +from dvc.logger import logger from dvc.utils import remove, move, copyfile, dict_md5, to_chunks from dvc.utils import LARGE_DIR_SIZE from dvc.config import Config @@ -95,7 +95,7 @@ class RemoteLOCAL(RemoteBase): if self.state.changed(cache, md5=md5): if os.path.exists(cache): msg = 'Corrupted cache file {}.' - Logger.warn(msg.format(os.path.relpath(cache))) + logger.warn(msg.format(os.path.relpath(cache))) remove(cache) return True return False @@ -134,7 +134,7 @@ class RemoteLOCAL(RemoteBase): open(path, 'w+').close() msg = "Created empty file: {} -> {}".format(cache, path) - Logger.debug(msg) + logger.debug(msg) return i = len(self.cache_types) @@ -149,11 +149,11 @@ class RemoteLOCAL(RemoteBase): 'protected ' if self.protected else '', self.cache_types[0], cache, path) - Logger.debug(msg) + logger.debug(msg) return except DvcException as exc: msg = 'Cache type \'{}\' is not supported: {}' - Logger.debug(msg.format(self.cache_types[0], str(exc))) + logger.debug(msg.format(self.cache_types[0], str(exc))) del self.cache_types[0] i -= 1 @@ -186,7 +186,7 @@ class RemoteLOCAL(RemoteBase): if len(files) > LARGE_DIR_SIZE: msg = "Computing md5 for a large directory {}. " \ "This is only done once." - Logger.info(msg.format(os.path.relpath(root))) + logger.info(msg.format(os.path.relpath(root))) bar = True title = os.path.relpath(root) processed = 0 @@ -227,12 +227,12 @@ class RemoteLOCAL(RemoteBase): d = json.load(fd) except Exception as exc: msg = u'Failed to load dir cache \'{}\'' - Logger.error(msg.format(os.path.relpath(path)), exc) + logger.error(msg.format(os.path.relpath(path)), exc) return [] if not isinstance(d, list): msg = u'Dir cache file format error \'{}\': skipping the file' - Logger.error(msg.format(os.path.relpath(path))) + logger.error(msg.format(os.path.relpath(path))) return [] for info in d: @@ -268,22 +268,22 @@ class RemoteLOCAL(RemoteBase): if not cache: msg = 'No cache info for \'{}\'. Skipping checkout.' - Logger.warn(msg.format(os.path.relpath(path))) + logger.warn(msg.format(os.path.relpath(path))) return if not self.changed(path_info, checksum_info): msg = "Data '{}' didn't change." - Logger.info(msg.format(os.path.relpath(path))) + logger.info(msg.format(os.path.relpath(path))) return if self.changed_cache(md5): msg = u'Cache \'{}\' not found. File \'{}\' won\'t be created.' - Logger.warn(msg.format(md5, os.path.relpath(path))) + logger.warn(msg.format(md5, os.path.relpath(path))) remove(path) return msg = u'Checking out \'{}\' with cache \'{}\'.' - Logger.info(msg.format(os.path.relpath(path), md5)) + logger.info(msg.format(os.path.relpath(path), md5)) if not self.is_dir_cache(cache): if os.path.exists(path): @@ -306,7 +306,7 @@ class RemoteLOCAL(RemoteBase): dir_size = len(dir_info) bar = dir_size > LARGE_DIR_SIZE - Logger.info("Linking directory '{}'.".format(dir_relpath)) + logger.info("Linking directory '{}'.".format(dir_relpath)) for processed, entry in enumerate(dir_info): relpath = entry[self.PARAM_RELPATH] @@ -412,7 +412,7 @@ class RemoteLOCAL(RemoteBase): dir_size = len(dir_info) bar = dir_size > LARGE_DIR_SIZE - Logger.info("Linking directory '{}'.".format(dir_relpath)) + logger.info("Linking directory '{}'.".format(dir_relpath)) for processed, entry in enumerate(dir_info): relpath = entry[self.PARAM_RELPATH] @@ -444,7 +444,7 @@ class RemoteLOCAL(RemoteBase): path = path_info['path'] msg = "Saving '{}' to cache '{}'." - Logger.info(msg.format(os.path.relpath(path), + logger.info(msg.format(os.path.relpath(path), os.path.relpath(self.cache_dir))) if os.path.isdir(path): @@ -512,7 +512,7 @@ class RemoteLOCAL(RemoteBase): if from_info['scheme'] != 'local': raise NotImplementedError - Logger.debug("Uploading '{}' to '{}'".format(from_info['path'], + logger.debug("Uploading '{}' to '{}'".format(from_info['path'], to_info['path'])) if not name: @@ -524,7 +524,7 @@ class RemoteLOCAL(RemoteBase): copyfile(from_info['path'], to_info['path'], name=name) except Exception as exc: msg = "Failed to upload '{}' tp '{}'" - Logger.warn(msg.format(from_info['path'], + logger.warn(msg.format(from_info['path'], to_info['path']), exc) def download(self, @@ -541,7 +541,7 @@ class RemoteLOCAL(RemoteBase): if to_info['scheme'] != 'local': raise NotImplementedError - Logger.debug("Downloading '{}' to '{}'".format(from_info['path'], + logger.debug("Downloading '{}' to '{}'".format(from_info['path'], to_info['path'])) if not name: @@ -556,7 +556,7 @@ class RemoteLOCAL(RemoteBase): name=name) except Exception as exc: msg = "Failed to download '{}' to '{}'" - Logger.warn(msg.format(from_info['path'], + logger.warn(msg.format(from_info['path'], to_info['path']), exc) continue @@ -600,7 +600,7 @@ class RemoteLOCAL(RemoteBase): return removed def status(self, checksum_infos, remote, jobs=None, show_checksums=False): - Logger.info("Preparing to pull data from {}".format(remote.url)) + logger.info("Preparing to pull data from {}".format(remote.url)) title = "Collecting information" progress.set_n_total(1) @@ -697,7 +697,7 @@ class RemoteLOCAL(RemoteBase): f.result() def push(self, checksum_infos, remote, jobs=None, show_checksums=False): - Logger.info("Preparing to push data to {}".format(remote.url)) + logger.info("Preparing to push data to {}".format(remote.url)) title = "Collecting information" progress.set_n_total(1) diff --git a/dvc/remote/s3.py b/dvc/remote/s3.py index 38735bcc1..944a0cadc 100644 --- a/dvc/remote/s3.py +++ b/dvc/remote/s3.py @@ -12,7 +12,7 @@ try: except ImportError: from urllib.parse import urlparse -from dvc.logger import Logger +from dvc.logger import logger from dvc.progress import progress from dvc.config import Config from dvc.remote.base import RemoteBase @@ -144,7 +144,7 @@ class RemoteS3(RemoteBase): if {self.PARAM_ETAG: etag} != self.save_info(cache): if self.exists([cache])[0]: msg = 'Corrupted cache file {}' - Logger.warn(msg.format(self.to_string(cache))) + logger.warn(msg.format(self.to_string(cache))) self.remove(cache) return True @@ -160,22 +160,22 @@ class RemoteS3(RemoteBase): if not self.changed(path_info, checksum_info): msg = "Data '{}' didn't change." - Logger.info(msg.format(self.to_string(path_info))) + logger.info(msg.format(self.to_string(path_info))) return if self.changed_cache(etag): msg = "Cache '{}' not found. File '{}' won't be created." - Logger.warn(msg.format(etag, self.to_string(path_info))) + logger.warn(msg.format(etag, self.to_string(path_info))) return if self.exists([path_info])[0]: msg = "Data '{}' exists. Removing before checkout." - Logger.warn(msg.format(self.to_string(path_info))) + logger.warn(msg.format(self.to_string(path_info))) self.remove(path_info) return msg = "Checking out '{}' with cache '{}'." - Logger.info(msg.format(self.to_string(path_info), etag)) + logger.info(msg.format(self.to_string(path_info), etag)) key = posixpath.join(self.prefix, etag[0:2], etag[2:]) from_info = {'scheme': 's3', 'bucket': self.bucket, 'key': key} @@ -186,7 +186,7 @@ class RemoteS3(RemoteBase): if path_info['scheme'] != 's3': raise NotImplementedError - Logger.debug('Removing s3://{}/{}'.format(path_info['bucket'], + logger.debug('Removing s3://{}/{}'.format(path_info['bucket'], path_info['key'])) self.s3.delete_object(Bucket=path_info['bucket'], @@ -256,7 +256,7 @@ class RemoteS3(RemoteBase): if from_info['scheme'] != 'local': raise NotImplementedError - Logger.debug("Uploading '{}' to '{}/{}'".format(from_info['path'], + logger.debug("Uploading '{}' to '{}/{}'".format(from_info['path'], to_info['bucket'], to_info['key'])) @@ -273,7 +273,7 @@ class RemoteS3(RemoteBase): Callback=cb) except Exception as exc: msg = "Failed to upload '{}'".format(from_info['path']) - Logger.warn(msg, exc) + logger.warn(msg, exc) continue progress.finish_target(name) @@ -301,7 +301,7 @@ class RemoteS3(RemoteBase): msg = "Downloading '{}/{}' to '{}'".format(from_info['bucket'], from_info['key'], to_info['path']) - Logger.debug(msg) + logger.debug(msg) tmp_file = self.tmp_file(to_info['path']) if not name: @@ -325,7 +325,7 @@ class RemoteS3(RemoteBase): except Exception as exc: msg = "Failed to download '{}/{}'".format(from_info['bucket'], from_info['key']) - Logger.warn(msg, exc) + logger.warn(msg, exc) continue os.rename(tmp_file, to_info['path']) diff --git a/dvc/remote/ssh.py b/dvc/remote/ssh.py index 5da03e866..7f5b6aa9b 100644 --- a/dvc/remote/ssh.py +++ b/dvc/remote/ssh.py @@ -7,7 +7,7 @@ try: except ImportError: paramiko = None -from dvc.logger import Logger +from dvc.logger import logger from dvc.progress import progress from dvc.remote.base import RemoteBase, RemoteBaseCmdError from dvc.remote.local import RemoteLOCAL @@ -26,7 +26,7 @@ def sizeof_fmt(num, suffix='B'): def percent_cb(name, complete, total): """ Callback for updating target progress """ - Logger.debug('{}: {} transferred out of {}'.format(name, + logger.debug('{}: {} transferred out of {}'.format(name, sizeof_fmt(complete), sizeof_fmt(total))) progress.update_target(name, complete, total) @@ -83,7 +83,7 @@ class RemoteSSH(RemoteBase): def ssh(self, host=None, user=None, port=None): msg = "Establishing ssh connection with '{}' " \ "through port '{}' as user '{}'" - Logger.debug(msg.format(host, port, user)) + logger.debug(msg.format(host, port, user)) ssh = paramiko.SSHClient() @@ -245,7 +245,7 @@ class RemoteSSH(RemoteBase): if {self.PARAM_MD5: md5} != self.save_info(cache): if self.exists([cache])[0]: msg = 'Corrupted cache file {}' - Logger.warn(msg.format(self.to_string(cache))) + logger.warn(msg.format(self.to_string(cache))) self.remove(cache) return True @@ -286,22 +286,22 @@ class RemoteSSH(RemoteBase): if not self.changed(path_info, checksum_info): msg = "Data '{}' didn't change." - Logger.info(msg.format(self.to_string(path_info))) + logger.info(msg.format(self.to_string(path_info))) return if self.changed_cache(md5): msg = "Cache '{}' not found. File '{}' won't be created." - Logger.warn(msg.format(md5, self.to_string(path_info))) + logger.warn(msg.format(md5, self.to_string(path_info))) return if self.exists([path_info])[0]: msg = "Data '{}' exists. Removing before checkout." - Logger.warn(msg.format(self.to_string(path_info))) + logger.warn(msg.format(self.to_string(path_info))) self.remove(path_info) return msg = "Checking out '{}' with cache '{}'." - Logger.info(msg.format(self.to_string(path_info), md5)) + logger.info(msg.format(self.to_string(path_info), md5)) src = path_info.copy() src['path'] = posixpath.join(self.prefix, md5[0:2], md5[2:]) @@ -312,7 +312,7 @@ class RemoteSSH(RemoteBase): if path_info['scheme'] != 'ssh': raise NotImplementedError - Logger.debug('Removing ssh://{}@{}/{}'.format(path_info['user'], + logger.debug('Removing ssh://{}@{}/{}'.format(path_info['user'], path_info['host'], path_info['path'])) @@ -350,7 +350,7 @@ class RemoteSSH(RemoteBase): msg = "Downloading '{}/{}' to '{}'".format(from_info['host'], from_info['path'], to_info['path']) - Logger.debug(msg) + logger.debug(msg) if not name: name = os.path.basename(to_info['path']) @@ -363,7 +363,7 @@ class RemoteSSH(RemoteBase): callback=create_cb(name)) except Exception as exc: msg = "Failed to download '{}/{}' to '{}'" - Logger.warn(msg.format(from_info['host'], + logger.warn(msg.format(from_info['host'], from_info['path'], to_info['path']), exc) continue @@ -388,7 +388,7 @@ class RemoteSSH(RemoteBase): if from_info['scheme'] != 'local': raise NotImplementedError - Logger.debug("Uploading '{}' to '{}/{}'".format(from_info['path'], + logger.debug("Uploading '{}' to '{}/{}'".format(from_info['path'], to_info['host'], to_info['path'])) @@ -404,7 +404,7 @@ class RemoteSSH(RemoteBase): callback=create_cb(name)) except Exception as exc: msg = "Failed to upload '{}' to '{}/{}'" - Logger.warn(msg.format(from_info['path'], + logger.warn(msg.format(from_info['path'], to_info['host'], to_info['path'], exc)) continue diff --git a/dvc/scm.py b/dvc/scm.py index e32ed2913..24a08951a 100644 --- a/dvc/scm.py +++ b/dvc/scm.py @@ -1,7 +1,7 @@ import os from dvc.exceptions import DvcException -from dvc.logger import Logger +from dvc.logger import logger from dvc.utils import fix_env @@ -173,7 +173,7 @@ class Git(Base): msg = "Adding '{}' to '{}'.".format(os.path.relpath(path), os.path.relpath(gitignore)) - Logger.info(msg) + logger.info(msg) content = entry if len(ignore_list) > 0: @@ -212,7 +212,7 @@ class Git(Base): msg += 'manually using \'git add\'. ' msg += 'See \'https://github.com/iterative/dvc/issues/610\' ' msg += 'for more details.' - Logger.error(msg.format(str(paths)), exc) + logger.error(msg.format(str(paths)), exc) def commit(self, msg): self.repo.index.commit(msg) diff --git a/dvc/stage.py b/dvc/stage.py index 952197872..345c3120c 100644 --- a/dvc/stage.py +++ b/dvc/stage.py @@ -7,7 +7,7 @@ from schema import Schema, SchemaError, Optional, Or, And import dvc.dependency as dependency import dvc.output as output from dvc.exceptions import DvcException -from dvc.logger import Logger +from dvc.logger import logger from dvc.utils import dict_md5, fix_env @@ -205,7 +205,7 @@ class Stage(object): msg = "Stage '{}' didn't change.".format(self.relpath) color = 'green' - log(Logger.colorize(msg, color)) + log(logger.colorize(msg, color)) return ret @@ -386,7 +386,7 @@ class Stage(object): if os.path.exists(path): if not ignore_build_cache and stage.is_cached(): - Logger.info('Stage is cached, skipping.') + logger.info('Stage is cached, skipping.') return None msg = "'{}' already exists. Do you wish to run the command and " \ @@ -408,7 +408,7 @@ class Stage(object): def _check_dvc_file(fname): sname = fname + Stage.STAGE_FILE_SUFFIX if Stage.is_stage_file(sname): - Logger.info("Do you mean '{}'?".format(sname)) + logger.info("Do you mean '{}'?".format(sname)) @staticmethod def load(project, fname): @@ -451,7 +451,7 @@ class Stage(object): self._check_dvc_filename(fname) msg = "Saving information to '{}'.".format(os.path.relpath(fname)) - Logger.info(msg) + logger.info(msg) with open(fname, 'w') as fd: yaml.safe_dump(self.dumpd(), fd, default_flow_style=False) diff --git a/dvc/state.py b/dvc/state.py index ce1dd4a90..0fb48c1cb 100644 --- a/dvc/state.py +++ b/dvc/state.py @@ -7,7 +7,7 @@ from dvc.config import Config from dvc.system import System from dvc.utils import file_md5, remove from dvc.exceptions import DvcException -from dvc.logger import Logger +from dvc.logger import logger class StateDuplicateError(DvcException): @@ -88,7 +88,7 @@ class State(object): actual = self.update(path) msg = "File '{}', md5 '{}', actual '{}'" - Logger.debug(msg.format(path, md5, actual)) + logger.debug(msg.format(path, md5, actual)) if not md5 or not actual: return True @@ -96,12 +96,12 @@ class State(object): return actual.split('.')[0] != md5.split('.')[0] def _execute(self, cmd): - Logger.debug(cmd) + logger.debug(cmd) return self.c.execute(cmd) def _fetchall(self): ret = self.c.fetchall() - Logger.debug("fetched: {}".format(ret)) + logger.debug("fetched: {}".format(ret)) return ret def _to_sqlite(self, n): @@ -263,7 +263,7 @@ class State(object): @staticmethod def inode(path): - Logger.debug('Path {} inode {}'.format(path, System.inode(path))) + logger.debug('Path {} inode {}'.format(path, System.inode(path))) return System.inode(path) def _do_update(self, path): @@ -299,7 +299,7 @@ class State(object): i = self._from_sqlite(i) assert i == inode msg = "Inode '{}', mtime '{}', actual mtime '{}'." - Logger.debug(msg.format(i, m, mtime)) + logger.debug(msg.format(i, m, mtime)) if mtime != m: md5, info = self._collect(path) cmd = 'UPDATE {} SET ' \ @@ -362,7 +362,7 @@ class State(object): mtime = self.mtime(path) if i == inode and m == mtime: - Logger.debug('Removing \'{}\' as unused link.'.format(path)) + logger.debug('Removing \'{}\' as unused link.'.format(path)) remove(path) unused.append(p) diff --git a/dvc/updater.py b/dvc/updater.py index 2e8cff96f..f2f9ebb3c 100644 --- a/dvc/updater.py +++ b/dvc/updater.py @@ -6,7 +6,7 @@ import colorama from dvc import VERSION_BASE from dvc.lock import Lock, LockError -from dvc.logger import Logger +from dvc.logger import logger from dvc.utils import is_binary @@ -27,7 +27,7 @@ class Updater(object): # pragma: no cover ctime = os.path.getmtime(self.updater_file) outdated = (time.time() - ctime >= self.TIMEOUT) if outdated: - Logger.debug("'{}' is outdated(".format(self.updater_file)) + logger.debug("'{}' is outdated(".format(self.updater_file)) return outdated def _with_lock(self, func, action): @@ -36,7 +36,7 @@ class Updater(object): # pragma: no cover func() except LockError: msg = "Failed to acquire '{}' before {} updates" - Logger.debug(msg.format(self.lock.lock_file, action)) + logger.debug(msg.format(self.lock.lock_file, action)) def check(self): if os.getenv('CI') or os.getenv('DVC_TEST'): @@ -57,7 +57,7 @@ class Updater(object): # pragma: no cover self.latest = info['version'] except Exception as exc: msg = "'{}' is not a valid json: {}" - Logger.debug(msg.format(self.updater_file, exc)) + logger.debug(msg.format(self.updater_file, exc)) self.fetch() return @@ -81,7 +81,7 @@ class Updater(object): # pragma: no cover info = r.json() except requests.exceptions.RequestException as exc: msg = "Failed to retrieve latest version: {}" - Logger.debug(msg.format(exc)) + logger.debug(msg.format(exc)) return with open(self.updater_file, 'w+') as fobj: @@ -113,7 +113,7 @@ class Updater(object): # pragma: no cover latest=self.latest) if sys.stdout.isatty(): - Logger.box(message, border_color='yellow') + logger.box(message, border_color='yellow') def _get_update_instructions(self): instructions = { diff --git a/dvc/utils.py b/dvc/utils.py index 89f912df6..b43160d4d 100644 --- a/dvc/utils.py +++ b/dvc/utils.py @@ -11,7 +11,7 @@ import hashlib from dvc.progress import progress from dvc.istextfile import istextfile -from dvc.logger import Logger +from dvc.logger import logger LOCAL_CHUNK_SIZE = 1024*1024 @@ -33,7 +33,7 @@ def file_md5(fname): if size >= LARGE_FILE_SIZE: bar = True msg = "Computing md5 for a large file {}. This is only done once." - Logger.info(msg.format(os.path.relpath(fname))) + logger.info(msg.format(os.path.relpath(fname))) name = os.path.relpath(fname) total = 0 @@ -143,7 +143,7 @@ def remove(path): if not os.path.exists(path): return - Logger.debug(u'Removing \'{}\''.format(os.path.relpath(path))) + logger.debug(u'Removing \'{}\''.format(os.path.relpath(path))) def _chmod(func, p, excinfo): perm = os.stat(p).st_mode diff --git a/tests/test_logger.py b/tests/test_logger.py index c4865f6bd..bfa988b11 100644 --- a/tests/test_logger.py +++ b/tests/test_logger.py @@ -8,7 +8,7 @@ except ImportError: import logging from dvc.command.base import CmdBase -from dvc.logger import Logger +from dvc.logger import Logger, logger from tests.basic_env import TestDvc @@ -20,70 +20,75 @@ class StringContaining(str): class TestLogger(TestDvc): def test_config(self): - Logger('debug') - self.assertEqual(Logger.logger().getEffectiveLevel(), logging.DEBUG) + logger.set_level() + logger.set_level('debug') + self.assertEqual(logger.logger.getEffectiveLevel(), logging.DEBUG) - Logger('error') - self.assertEqual(Logger.logger().getEffectiveLevel(), logging.ERROR) + logger.set_level('error') + self.assertEqual(logger.logger.getEffectiveLevel(), logging.ERROR) def test_set_level(self): - Logger.set_level('debug') - self.assertEqual(Logger.logger().getEffectiveLevel(), logging.DEBUG) + logger.set_level() + logger.set_level('debug') + self.assertEqual(logger.logger.getEffectiveLevel(), logging.DEBUG) def test_be_quiet(self): - Logger.be_quiet() - self.assertEqual(Logger.logger().getEffectiveLevel(), logging.CRITICAL) + logger.set_level() + logger.be_quiet() + self.assertEqual(logger.logger.getEffectiveLevel(), logging.CRITICAL) def test_be_verbose(self): - Logger.be_verbose() - self.assertEqual(Logger.logger().getEffectiveLevel(), logging.DEBUG) + logger.set_level() + logger.be_verbose() + self.assertEqual(logger.logger.getEffectiveLevel(), logging.DEBUG) def test_colorize(self): - for name, color in Logger.COLOR_MAP.items(): - msg = Logger.colorize(name, name) + for name, color in logger.COLOR_MAP.items(): + msg = logger.colorize(name, name) # This is not a tty, so it should not colorize anything self.assertEqual(msg, name) def test_handlers(self): - Logger.init() - Logger.init() - self.assertEqual(len(Logger.logger().handlers), 2) + Logger() + Logger() + self.assertEqual(len(logger.logger.handlers), 2) - @patch('dvc.logger.Logger._already_initialized', return_value=False) @patch('sys.stderr', new_callable=StringIO) @patch('sys.stdout', new_callable=StringIO) - def test_stderr(self, mock_stdout, mock_stderr, mock_logger): + def test_stderr(self, mock_stdout, mock_stderr): + logger = Logger(force=True) error_message = 'error msg' - Logger.init() - Logger.error(error_message) + logger.error(error_message) self.assertEqual('', mock_stdout.getvalue()) self.assertEqual('Error: {}\n\nHaving any troubles? ' 'Hit us up at dvc.org/support, we ' 'are always happy to help!\n'.format(error_message), mock_stderr.getvalue()) - @patch('dvc.logger.Logger._already_initialized', return_value=False) @patch('sys.stderr', new_callable=StringIO) @patch('sys.stdout', new_callable=StringIO) - def test_stdout(self, mock_stdout, mock_stderr, mock_logger): + def test_stdout(self, mock_stdout, mock_stderr): + logger = Logger(force=True) non_error_message = 'non-error message' - Logger.init() - Logger.info(non_error_message) + logger.info(non_error_message) self.assertEqual('', mock_stderr.getvalue()) self.assertEqual('{}\n'.format(non_error_message), mock_stdout.getvalue()) class TestLoggerException(TestDvc): - @patch('dvc.logger.Logger._already_initialized', return_value=False) + def setUp(self): + super(TestLoggerException, self).setUp() + @patch('sys.stderr', new_callable=StringIO) @patch('sys.stdout', new_callable=StringIO) - def test_empty_err_msg(self, mock_stdout, mock_stderr, mock_logger): + def test_empty_err_msg(self, mock_stdout, mock_stderr): from dvc.exceptions import DvcException - Logger.init() + logger = Logger(force=True) + exc_msg = 'msg' - Logger.error("", exc=DvcException(exc_msg)) + logger.error("", exc=DvcException(exc_msg)) self.assertEqual('', mock_stdout.getvalue()) self.assertEqual('Error: {}\n\nHaving any troubles? ' @@ -91,15 +96,15 @@ class TestLoggerException(TestDvc): 'are always happy to help!\n'.format(exc_msg), mock_stderr.getvalue()) - @patch('dvc.logger.Logger._already_initialized', return_value=False) @patch('sys.stderr', new_callable=StringIO) @patch('sys.stdout', new_callable=StringIO) - def test_empty_exc_msg(self, mock_stdout, mock_stderr, mock_logger): + def test_empty_exc_msg(self, mock_stdout, mock_stderr): from dvc.exceptions import DvcException - Logger.init() + logger = Logger(force=True) + err_msg = 'msg' - Logger.error(err_msg, exc=DvcException("")) + logger.error(err_msg, exc=DvcException("")) self.assertEqual('', mock_stdout.getvalue()) self.assertEqual('Error: {}\n\nHaving any troubles? ' @@ -107,16 +112,16 @@ class TestLoggerException(TestDvc): 'are always happy to help!\n'.format(err_msg), mock_stderr.getvalue()) - @patch('dvc.logger.Logger._already_initialized', return_value=False) @patch('sys.stderr', new_callable=StringIO) @patch('sys.stdout', new_callable=StringIO) - def test_msg_and_exc(self, mock_stdout, mock_stderr, mock_logger): + def test_msg_and_exc(self, mock_stdout, mock_stderr): from dvc.exceptions import DvcException - Logger.init() + logger = Logger(force=True) + err_msg = 'error' exc_msg = 'exception' - Logger.error(err_msg, exc=DvcException(exc_msg)) + logger.error(err_msg, exc=DvcException(exc_msg)) self.assertEqual('', mock_stdout.getvalue()) self.assertEqual('Error: {}: {}\n\nHaving any troubles? ' @@ -135,35 +140,35 @@ class TestLoggerQuiet(TestDvc): CmdBase._set_loglevel(A()) - @patch('dvc.logger.Logger._already_initialized', return_value=False) @patch('sys.stderr', new_callable=StringIO) @patch('sys.stdout', new_callable=StringIO) - def test_progress(self, mock_stdout, mock_stderr, mock_logger): + def test_progress(self, mock_stdout, mock_stderr): from dvc.progress import progress progress.update_target('target', 50, 100) self.assertEqual('', mock_stdout.getvalue()) self.assertEqual('', mock_stderr.getvalue()) - @patch('dvc.logger.Logger._already_initialized', return_value=False) @patch('sys.stderr', new_callable=StringIO) @patch('sys.stdout', new_callable=StringIO) - def test_box(self, mock_stdout, mock_stderr, mock_logger): - Logger.box('message') + def test_box(self, mock_stdout, mock_stderr): + logger.box('message') self.assertEqual('', mock_stdout.getvalue()) self.assertEqual('', mock_stderr.getvalue()) class TestLoggerCLI(TestDvc): def test(self): + from dvc.logger import logger + class A(object): quiet = True verbose = False args = A() CmdBase._set_loglevel(args) - self.assertEqual(Logger.logger().getEffectiveLevel(), logging.CRITICAL) + self.assertEqual(logger.logger.getEffectiveLevel(), logging.CRITICAL) args.quiet = False args.verbose = True CmdBase._set_loglevel(args) - self.assertEqual(Logger.logger().getEffectiveLevel(), logging.DEBUG) + self.assertEqual(logger.logger.getEffectiveLevel(), logging.DEBUG) From 22724f0500b6e74ef9899b0b9aae7946e9db9b99 Mon Sep 17 00:00:00 2001 From: Ruslan Kuprieiev Date: Tue, 11 Dec 2018 14:11:21 +0200 Subject: [PATCH 5/5] ssh: mention private key passphrase in the prompt Fixes #1425 --- dvc/prompt.py | 2 +- dvc/remote/ssh.py | 3 ++- 2 files changed, 3 insertions(+), 2 deletions(-) diff --git a/dvc/prompt.py b/dvc/prompt.py index 1144d4316..827aeff2d 100644 --- a/dvc/prompt.py +++ b/dvc/prompt.py @@ -32,7 +32,7 @@ class Prompt(object): if not sys.stdout.isatty(): return None - msg = 'Enter password for {}:\n'.format(msg) + msg = '{}:\n'.format(msg) if not progress.is_finished: msg = u'\n' + msg diff --git a/dvc/remote/ssh.py b/dvc/remote/ssh.py index 7f5b6aa9b..46652388e 100644 --- a/dvc/remote/ssh.py +++ b/dvc/remote/ssh.py @@ -91,7 +91,8 @@ class RemoteSSH(RemoteBase): ssh.set_missing_host_key_policy(paramiko.AutoAddPolicy()) if self.ask_password and self.password is None: - msg = "host '{}' port '{}' user '{}'".format(host, port, user) + msg = ("Enter a private key passphrase or a password for " + "host '{}' port '{}' user '{}'").format(host, port, user) self.password = self.project.prompt.prompt_password(msg) ssh.connect(host,