From 85cd34415218bb963016d197faad1c70eb97e517 Mon Sep 17 00:00:00 2001 From: "Mr. Outis" Date: Mon, 1 Apr 2019 21:40:14 -0600 Subject: [PATCH] logger: Use a more _pythonic_ logging - Uses a formatter for coloring output - Move the `progress_aware` decorator logic to the logger itself - Refactor modules so each one uses their own instance of a logger Close #1753 --- dvc/__init__.py | 4 + dvc/analytics.py | 5 +- dvc/cli.py | 4 +- dvc/command/add.py | 7 +- dvc/command/base.py | 16 +- dvc/command/commit.py | 7 +- dvc/command/config.py | 11 +- dvc/command/daemon.py | 1 - dvc/command/data_sync.py | 11 +- dvc/command/destroy.py | 7 +- dvc/command/gc.py | 5 +- dvc/command/imp.py | 7 +- dvc/command/init.py | 7 +- dvc/command/install.py | 7 +- dvc/command/lock.py | 7 +- dvc/command/metrics.py | 13 +- dvc/command/move.py | 7 +- dvc/command/pipeline.py | 10 +- dvc/command/pkg.py | 7 +- dvc/command/remote.py | 6 +- dvc/command/remove.py | 7 +- dvc/command/repro.py | 7 +- dvc/command/root.py | 5 +- dvc/command/run.py | 7 +- dvc/command/status.py | 8 +- dvc/command/tag.py | 11 +- dvc/command/unprotect.py | 7 +- dvc/config.py | 6 +- dvc/daemon.py | 8 +- dvc/data_cloud.py | 7 +- dvc/logger.py | 436 ++++++++++++----------------------- dvc/main.py | 23 +- dvc/output/local.py | 5 +- dvc/progress.py | 16 +- dvc/remote/azure.py | 5 +- dvc/remote/base.py | 5 +- dvc/remote/gs.py | 9 +- dvc/remote/hdfs.py | 5 +- dvc/remote/http.py | 5 +- dvc/remote/local.py | 5 +- dvc/remote/s3.py | 5 +- dvc/remote/ssh/__init__.py | 7 +- dvc/remote/ssh/connection.py | 5 +- dvc/repo/__init__.py | 11 +- dvc/repo/checkout.py | 6 +- dvc/repo/gc.py | 4 +- dvc/repo/init.py | 22 +- dvc/repo/metrics/show.py | 10 +- dvc/repo/pkg.py | 7 +- dvc/repo/reproduce.py | 5 +- dvc/repo/status.py | 5 +- dvc/repo/tag/add.py | 5 +- dvc/repo/tag/remove.py | 5 +- dvc/scm/git/__init__.py | 7 +- dvc/scm/git/temp_git_repo.py | 5 +- dvc/stage.py | 13 +- dvc/state.py | 5 +- dvc/updater.py | 9 +- dvc/utils/__init__.py | 89 ++++++- dvc/utils/fs.py | 5 +- 60 files changed, 533 insertions(+), 433 deletions(-) diff --git a/dvc/__init__.py b/dvc/__init__.py index 8c1eba236..2a60bc900 100644 --- a/dvc/__init__.py +++ b/dvc/__init__.py @@ -8,6 +8,10 @@ from __future__ import unicode_literals from dvc.version import __version__ # noqa: F401 import warnings +import dvc.logger + + +dvc.logger.setup() # Ignore numpy's runtime warnings: https://github.com/numpy/numpy/pull/432. # We don't directly import numpy, but our dependency networkx does, causing diff --git a/dvc/analytics.py b/dvc/analytics.py index 0b7a4e94f..2a7ad7c8f 100644 --- a/dvc/analytics.py +++ b/dvc/analytics.py @@ -7,11 +7,14 @@ from dvc.utils.compat import str import os import json import errno +import logging -import dvc.logger as logger from dvc import __version__ +logger = logging.getLogger(__name__) + + class Analytics(object): """Class for collecting and sending usage analytics. diff --git a/dvc/cli.py b/dvc/cli.py index d59ec653d..55949d715 100644 --- a/dvc/cli.py +++ b/dvc/cli.py @@ -5,8 +5,8 @@ from __future__ import unicode_literals import sys import argparse +import logging -import dvc.logger as logger from dvc.command.base import fix_subparsers import dvc.command.init as init import dvc.command.pkg as pkg @@ -36,6 +36,8 @@ import dvc.command.diff as diff from dvc.exceptions import DvcParserError +logger = logging.getLogger(__name__) + COMMANDS = [ init, pkg, diff --git a/dvc/command/add.py b/dvc/command/add.py index 487dd654d..f6f9ab279 100644 --- a/dvc/command/add.py +++ b/dvc/command/add.py @@ -1,12 +1,15 @@ from __future__ import unicode_literals import argparse +import logging -import dvc.logger as logger from dvc.exceptions import DvcException from dvc.command.base import CmdBase, append_doc_link +logger = logging.getLogger(__name__) + + class CmdAdd(CmdBase): def run(self): try: @@ -22,7 +25,7 @@ class CmdAdd(CmdBase): ) except DvcException: - logger.error("failed to add file") + logger.exception("failed to add file") return 1 return 0 diff --git a/dvc/command/base.py b/dvc/command/base.py index 9c9e9eb3c..c39abb7fa 100644 --- a/dvc/command/base.py +++ b/dvc/command/base.py @@ -1,8 +1,10 @@ from __future__ import unicode_literals import colorama +import logging -import dvc.logger as logger + +logger = logging.getLogger(__name__) def fix_subparsers(subparsers): @@ -40,7 +42,6 @@ class CmdBase(object): self.repo = Repo() self.config = self.repo.config self.args = args - self.set_loglevel(args) @property def default_targets(self): @@ -51,15 +52,6 @@ class CmdBase(object): logger.warning(msg) return [Stage.STAGE_FILE] - @staticmethod - def set_loglevel(args): - """Sets log level from CLI arguments.""" - if args.quiet: - logger.be_quiet() - - elif args.verbose: - logger.be_verbose() - def run_cmd(self): from dvc.lock import LockError @@ -67,7 +59,7 @@ class CmdBase(object): with self.repo.lock: return self.run() except LockError: - logger.error("failed to lock before running a command") + logger.exception("failed to lock before running a command") return 1 # Abstract methods that have to be implemented by any inheritance class diff --git a/dvc/command/commit.py b/dvc/command/commit.py index 611f72bf7..fd8f017e9 100644 --- a/dvc/command/commit.py +++ b/dvc/command/commit.py @@ -1,12 +1,15 @@ from __future__ import unicode_literals import argparse +import logging -import dvc.logger as logger from dvc.exceptions import DvcException from dvc.command.base import CmdBase, append_doc_link +logger = logging.getLogger(__name__) + + class CmdCommit(CmdBase): def run(self): if not self.args.targets: @@ -21,7 +24,7 @@ class CmdCommit(CmdBase): force=self.args.force, ) except DvcException: - logger.error( + logger.exception( "failed to commit{}".format( (" " + target) if target else "" ) diff --git a/dvc/command/config.py b/dvc/command/config.py index c4c049982..7cd594803 100644 --- a/dvc/command/config.py +++ b/dvc/command/config.py @@ -2,13 +2,16 @@ from __future__ import unicode_literals import os import argparse +import logging -import dvc.logger as logger from dvc.command.base import CmdBase, append_doc_link from dvc.config import Config from dvc.exceptions import DvcException +logger = logging.getLogger(__name__) + + class CmdConfig(CmdBase): def __init__(self, args): from dvc.repo import Repo, NotDvcRepoError @@ -47,7 +50,7 @@ class CmdConfig(CmdBase): self.config.unset(configobj, section, opt) self.config.save(configobj) except DvcException: - logger.error("failed to unset '{}'".format(self.args.name)) + logger.exception("failed to unset '{}'".format(self.args.name)) return 1 return 0 @@ -55,7 +58,7 @@ class CmdConfig(CmdBase): try: self.config.show(self.configobj, section, opt) except DvcException: - logger.error("failed to show '{}'".format(self.args.name)) + logger.exception("failed to show '{}'".format(self.args.name)) return 1 return 0 @@ -64,7 +67,7 @@ class CmdConfig(CmdBase): self.config.set(self.configobj, section, opt, value) self.config.save(self.configobj) except DvcException: - logger.error( + logger.exception( "failed to set '{}.{}' to '{}'".format(section, opt, value) ) return 1 diff --git a/dvc/command/daemon.py b/dvc/command/daemon.py index db0bf757f..07b931c72 100644 --- a/dvc/command/daemon.py +++ b/dvc/command/daemon.py @@ -7,7 +7,6 @@ class CmdDaemonBase(CmdBase): def __init__(self, args): self.args = args self.config = None - self.set_loglevel(args) def run_cmd(self): return self.run() diff --git a/dvc/command/data_sync.py b/dvc/command/data_sync.py index 6937484ff..f31c2aa87 100644 --- a/dvc/command/data_sync.py +++ b/dvc/command/data_sync.py @@ -1,11 +1,14 @@ from __future__ import unicode_literals import argparse +import logging -import dvc.logger as logger from dvc.command.base import CmdBase, append_doc_link +logger = logging.getLogger(__name__) + + class CmdDataBase(CmdBase): UP_TO_DATE_MSG = "Everything is up to date." @@ -43,7 +46,7 @@ class CmdDataPull(CmdDataBase): recursive=self.args.recursive, ) except Exception: - logger.error("failed to pull data from the cloud") + logger.exception("failed to pull data from the cloud") return 1 self.check_up_to_date(processed_files_count) return 0 @@ -63,7 +66,7 @@ class CmdDataPush(CmdDataBase): recursive=self.args.recursive, ) except Exception: - logger.error("failed to push data to the cloud") + logger.exception("failed to push data to the cloud") return 1 self.check_up_to_date(processed_files_count) return 0 @@ -83,7 +86,7 @@ class CmdDataFetch(CmdDataBase): recursive=self.args.recursive, ) except Exception: - logger.error("failed to fetch data from the cloud") + logger.exception("failed to fetch data from the cloud") return 1 self.check_up_to_date(processed_files_count) return 0 diff --git a/dvc/command/destroy.py b/dvc/command/destroy.py index 837dba18e..0ffacc127 100644 --- a/dvc/command/destroy.py +++ b/dvc/command/destroy.py @@ -1,13 +1,16 @@ from __future__ import unicode_literals import argparse +import logging import dvc.prompt as prompt -import dvc.logger as logger from dvc.command.base import CmdBase, append_doc_link from dvc.exceptions import DvcException +logger = logging.getLogger(__name__) + + class CmdDestroy(CmdBase): def run_cmd(self): try: @@ -26,7 +29,7 @@ class CmdDestroy(CmdBase): self.repo.destroy() except Exception: - logger.error("failed to destroy DVC") + logger.exception("failed to destroy DVC") return 1 return 0 diff --git a/dvc/command/gc.py b/dvc/command/gc.py index 582e06290..dc3b191fe 100644 --- a/dvc/command/gc.py +++ b/dvc/command/gc.py @@ -3,11 +3,14 @@ from __future__ import unicode_literals import argparse import os import dvc.prompt as prompt -import dvc.logger as logger +import logging from dvc.command.base import CmdBase, append_doc_link +logger = logging.getLogger(__name__) + + class CmdGC(CmdBase): def run(self): msg = "this will remove all cache except the cache that is used in " diff --git a/dvc/command/imp.py b/dvc/command/imp.py index 6e925ab80..726bb193c 100644 --- a/dvc/command/imp.py +++ b/dvc/command/imp.py @@ -2,13 +2,16 @@ from __future__ import unicode_literals import argparse import os +import logging -import dvc.logger as logger from dvc.utils.compat import urlparse from dvc.exceptions import DvcException from dvc.command.base import CmdBase, append_doc_link +logger = logging.getLogger(__name__) + + class CmdImport(CmdBase): def run(self): try: @@ -18,7 +21,7 @@ class CmdImport(CmdBase): self.repo.imp(self.args.url, out, self.args.resume) except DvcException: - logger.error( + logger.exception( "failed to import {}. You could also try downloading " "it manually and adding it with `dvc add` command.".format( self.args.url diff --git a/dvc/command/init.py b/dvc/command/init.py index 3cf1a10ac..c435a9757 100644 --- a/dvc/command/init.py +++ b/dvc/command/init.py @@ -1,11 +1,14 @@ from __future__ import unicode_literals import argparse +import logging -import dvc.logger as logger from dvc.command.base import append_doc_link +logger = logging.getLogger(__name__) + + class CmdInit(object): def __init__(self, args): self.args = args @@ -20,7 +23,7 @@ class CmdInit(object): ) self.config = self.repo.config except InitError: - logger.error("failed to initiate dvc") + logger.exception("failed to initiate dvc") return 1 return 0 diff --git a/dvc/command/install.py b/dvc/command/install.py index 775bfc414..4967eee6e 100644 --- a/dvc/command/install.py +++ b/dvc/command/install.py @@ -1,17 +1,20 @@ from __future__ import unicode_literals import argparse +import logging -import dvc.logger as logger from dvc.command.base import CmdBase, append_doc_link +logger = logging.getLogger(__name__) + + class CmdInstall(CmdBase): def run_cmd(self): try: self.repo.install() except Exception: - logger.error("failed to install dvc hooks") + logger.exception("failed to install dvc hooks") return 1 return 0 diff --git a/dvc/command/lock.py b/dvc/command/lock.py index 204bf0108..e435e8dcc 100644 --- a/dvc/command/lock.py +++ b/dvc/command/lock.py @@ -1,19 +1,22 @@ from __future__ import unicode_literals import argparse +import logging -import dvc.logger as logger from dvc.exceptions import DvcException from dvc.command.base import CmdBase, append_doc_link +logger = logging.getLogger(__name__) + + class CmdLockBase(CmdBase): def _run(self, unlock): for target in self.args.targets: try: self.repo.lock_stage(target, unlock=unlock) except DvcException: - logger.error( + logger.exception( "failed to {}lock '{}'".format( "un" if unlock else "", target ) diff --git a/dvc/command/metrics.py b/dvc/command/metrics.py index a4ef129c8..39c53f5b8 100644 --- a/dvc/command/metrics.py +++ b/dvc/command/metrics.py @@ -1,12 +1,15 @@ from __future__ import unicode_literals import argparse +import logging -import dvc.logger as logger from dvc.exceptions import DvcException from dvc.command.base import CmdBase, fix_subparsers, append_doc_link +logger = logging.getLogger(__name__) + + def show_metrics(metrics, all_branches=False, all_tags=False): """ Args: @@ -46,7 +49,7 @@ class CmdMetricsShow(CmdBase): show_metrics(metrics, self.args.all_branches, self.args.all_tags) except DvcException: - logger.error("failed to show metrics") + logger.exception("failed to show metrics") return 1 return 0 @@ -59,7 +62,7 @@ class CmdMetricsModify(CmdBase): self.args.path, typ=self.args.type, xpath=self.args.xpath ) except DvcException: - logger.error("failed to modify metric file settings") + logger.exception("failed to modify metric file settings") return 1 return 0 @@ -73,7 +76,7 @@ class CmdMetricsAdd(CmdBase): ) except DvcException: msg = "failed to add metric file '{}'".format(self.args.path) - logger.error(msg) + logger.exception(msg) return 1 return 0 @@ -85,7 +88,7 @@ class CmdMetricsRemove(CmdBase): self.repo.metrics.remove(self.args.path) except DvcException: msg = "failed to remove metric file '{}'".format(self.args.path) - logger.error(msg) + logger.exception(msg) return 1 return 0 diff --git a/dvc/command/move.py b/dvc/command/move.py index 283344e6a..4fce351f0 100644 --- a/dvc/command/move.py +++ b/dvc/command/move.py @@ -1,12 +1,15 @@ from __future__ import unicode_literals import argparse +import logging -import dvc.logger as logger from dvc.exceptions import DvcException from dvc.command.base import CmdBase, append_doc_link +logger = logging.getLogger(__name__) + + class CmdMove(CmdBase): def run(self): try: @@ -15,7 +18,7 @@ class CmdMove(CmdBase): msg = "failed to move '{}' -> '{}'".format( self.args.src, self.args.dst ) - logger.error(msg) + logger.exception(msg) return 1 return 0 diff --git a/dvc/command/pipeline.py b/dvc/command/pipeline.py index d1f10341a..c30160fb9 100644 --- a/dvc/command/pipeline.py +++ b/dvc/command/pipeline.py @@ -1,16 +1,18 @@ from __future__ import unicode_literals -import argparse - from dvc.utils.compat import str +import argparse import os +import logging -import dvc.logger as logger from dvc.exceptions import DvcException from dvc.command.base import CmdBase, fix_subparsers, append_doc_link +logger = logging.getLogger(__name__) + + class CmdPipelineShow(CmdBase): def _show(self, target, commands, outs): import networkx @@ -145,7 +147,7 @@ class CmdPipelineShow(CmdBase): self._show(target, self.args.commands, self.args.outs) except DvcException: msg = "failed to show pipeline for '{}'".format(target) - logger.error(msg) + logger.exception(msg) return 1 return 0 diff --git a/dvc/command/pkg.py b/dvc/command/pkg.py index ae313c456..c1d4ace99 100644 --- a/dvc/command/pkg.py +++ b/dvc/command/pkg.py @@ -1,13 +1,16 @@ from __future__ import unicode_literals import argparse +import logging -import dvc.logger as logger from dvc.exceptions import DvcException from dvc.command.base import CmdBase, fix_subparsers, append_doc_link from dvc.repo.pkg import PackageParams +logger = logging.getLogger(__name__) + + class CmdPkg(CmdBase): def run(self, unlock=False): try: @@ -19,7 +22,7 @@ class CmdPkg(CmdBase): ) return self.repo.install_pkg(pkg_params) except DvcException: - logger.error( + logger.exception( "failed to install package '{}'".format(self.args.address) ) return 1 diff --git a/dvc/command/remote.py b/dvc/command/remote.py index 9bb487639..1dee14949 100644 --- a/dvc/command/remote.py +++ b/dvc/command/remote.py @@ -3,13 +3,15 @@ from __future__ import unicode_literals import argparse import os import re +import logging -import dvc.logger as logger -from dvc.command.base import append_doc_link, fix_subparsers from dvc.command.config import CmdConfig from dvc.config import Config +logger = logging.getLogger(__name__) + + class CmdRemoteAdd(CmdConfig): @staticmethod def resolve_path(path, config_file): diff --git a/dvc/command/remove.py b/dvc/command/remove.py index 2d366f8d8..aa455702b 100644 --- a/dvc/command/remove.py +++ b/dvc/command/remove.py @@ -1,13 +1,16 @@ from __future__ import unicode_literals import argparse +import logging import dvc.prompt as prompt -import dvc.logger as logger from dvc.exceptions import DvcException from dvc.command.base import CmdBase, append_doc_link +logger = logging.getLogger(__name__) + + class CmdRemove(CmdBase): def _is_outs_only(self, target): if not self.args.purge: @@ -34,7 +37,7 @@ class CmdRemove(CmdBase): outs_only = self._is_outs_only(target) self.repo.remove(target, outs_only=outs_only) except DvcException: - logger.error("failed to remove {}".format(target)) + logger.exception("failed to remove {}".format(target)) return 1 return 0 diff --git a/dvc/command/repro.py b/dvc/command/repro.py index ba5a17ae0..3db04b79d 100644 --- a/dvc/command/repro.py +++ b/dvc/command/repro.py @@ -2,14 +2,17 @@ from __future__ import unicode_literals import argparse import os +import logging -import dvc.logger as logger from dvc.command.base import CmdBase, append_doc_link from dvc.command.metrics import show_metrics from dvc.command.status import CmdDataStatus from dvc.exceptions import DvcException +logger = logging.getLogger(__name__) + + class CmdRepro(CmdBase): def run(self): recursive = not self.args.single_item @@ -45,7 +48,7 @@ class CmdRepro(CmdBase): metrics = self.repo.metrics.show() show_metrics(metrics) except DvcException: - logger.error() + logger.exception() ret = 1 break diff --git a/dvc/command/root.py b/dvc/command/root.py index da154ad97..f51e19da6 100644 --- a/dvc/command/root.py +++ b/dvc/command/root.py @@ -2,11 +2,14 @@ from __future__ import unicode_literals import argparse import os +import logging -import dvc.logger as logger from dvc.command.base import CmdBase, append_doc_link +logger = logging.getLogger(__name__) + + class CmdRoot(CmdBase): def run_cmd(self): return self.run() diff --git a/dvc/command/run.py b/dvc/command/run.py index 619dea51f..f29e15207 100644 --- a/dvc/command/run.py +++ b/dvc/command/run.py @@ -1,12 +1,15 @@ from __future__ import unicode_literals import argparse +import logging -import dvc.logger as logger from dvc.command.base import CmdBase, append_doc_link from dvc.exceptions import DvcException +logger = logging.getLogger(__name__) + + class CmdRun(CmdBase): def run(self): overwrite = self.args.yes or self.args.overwrite_dvcfile @@ -50,7 +53,7 @@ class CmdRun(CmdBase): outs_persist_no_cache=self.args.outs_persist_no_cache, ) except DvcException: - logger.error("failed to run command") + logger.exception("failed to run command") return 1 return 0 diff --git a/dvc/command/status.py b/dvc/command/status.py index 1e38ed0d8..8a9c94540 100644 --- a/dvc/command/status.py +++ b/dvc/command/status.py @@ -1,10 +1,14 @@ from __future__ import unicode_literals -import dvc.logger as logger +import logging + from dvc.command.data_sync import CmdDataBase from dvc.utils.compat import str +logger = logging.getLogger(__name__) + + class CmdDataStatus(CmdDataBase): STATUS_LEN = 20 STATUS_INDENT = "\t" @@ -58,6 +62,6 @@ class CmdDataStatus(CmdDataBase): logger.info(self.UP_TO_DATE_MSG) except Exception: - logger.error("failed to obtain data status") + logger.exception("failed to obtain data status") return 1 return 0 diff --git a/dvc/command/tag.py b/dvc/command/tag.py index ed2367d67..789dacabd 100644 --- a/dvc/command/tag.py +++ b/dvc/command/tag.py @@ -1,10 +1,13 @@ import yaml +import logging -import dvc.logger as logger from dvc.exceptions import DvcException from dvc.command.base import CmdBase, fix_subparsers, append_doc_link +logger = logging.getLogger(__name__) + + class CmdTagAdd(CmdBase): def run(self): for target in self.args.targets: @@ -16,7 +19,7 @@ class CmdTagAdd(CmdBase): recursive=self.args.recursive, ) except DvcException: - logger.error("failed to add tag") + logger.exception("failed to add tag") return 1 return 0 @@ -32,7 +35,7 @@ class CmdTagRemove(CmdBase): recursive=self.args.recursive, ) except DvcException: - logger.error("failed to remove tag") + logger.exception("failed to remove tag") return 1 return 0 @@ -49,7 +52,7 @@ class CmdTagList(CmdBase): if tags: logger.info(yaml.dump(tags, default_flow_style=False)) except DvcException: - logger.error("failed list tags") + logger.exception("failed list tags") return 1 return 0 diff --git a/dvc/command/unprotect.py b/dvc/command/unprotect.py index 98716952f..e62848992 100644 --- a/dvc/command/unprotect.py +++ b/dvc/command/unprotect.py @@ -1,12 +1,15 @@ from __future__ import unicode_literals import argparse +import logging -import dvc.logger as logger from dvc.exceptions import DvcException from dvc.command.base import CmdBase, append_doc_link +logger = logging.getLogger(__name__) + + class CmdUnprotect(CmdBase): def run(self): for target in self.args.targets: @@ -14,7 +17,7 @@ class CmdUnprotect(CmdBase): self.repo.unprotect(target) except DvcException: msg = "failed to unprotect '{}'".format(target) - logger.error(msg) + logger.exception(msg) return 1 return 0 diff --git a/dvc/config.py b/dvc/config.py index 8716aacae..25472546c 100644 --- a/dvc/config.py +++ b/dvc/config.py @@ -7,11 +7,13 @@ from dvc.utils.compat import str, open import os import errno import configobj -from schema import Schema, Optional, And, Use, Regex +import logging -import dvc.logger as logger +from schema import Schema, Optional, And, Use, Regex from dvc.exceptions import DvcException +logger = logging.getLogger(__name__) + class ConfigError(DvcException): """DVC config exception. diff --git a/dvc/daemon.py b/dvc/daemon.py index 39731c844..fc0d1e458 100644 --- a/dvc/daemon.py +++ b/dvc/daemon.py @@ -5,13 +5,15 @@ from __future__ import unicode_literals import os import sys import inspect +import logging from subprocess import Popen -import dvc.logger as logger from dvc.utils import is_binary, fix_env from dvc.utils.compat import cast_bytes_py2 +logger = logging.getLogger(__name__) + CREATE_NEW_PROCESS_GROUP = 0x00000200 DETACHED_PROCESS = 0x00000008 @@ -43,7 +45,7 @@ def _spawn_posix(cmd, env): if pid > 0: return except OSError: - logger.error("failed at first fork") + logger.exception("failed at first fork") os._exit(1) # pylint: disable=protected-access os.setsid() @@ -54,7 +56,7 @@ def _spawn_posix(cmd, env): if pid > 0: os._exit(0) # pylint: disable=protected-access except OSError: - logger.error("failed at second fork") + logger.exception("failed at second fork") os._exit(1) # pylint: disable=protected-access sys.stdin.close() diff --git a/dvc/data_cloud.py b/dvc/data_cloud.py index e78a0d916..e5f7f0189 100644 --- a/dvc/data_cloud.py +++ b/dvc/data_cloud.py @@ -2,9 +2,9 @@ from __future__ import unicode_literals -import dvc.logger as logger -from dvc.config import Config, ConfigError +import logging +from dvc.config import Config, ConfigError from dvc.remote import Remote from dvc.remote.s3 import RemoteS3 from dvc.remote.gs import RemoteGS @@ -15,6 +15,9 @@ from dvc.remote.local import RemoteLOCAL from dvc.remote.http import RemoteHTTP +logger = logging.getLogger(__name__) + + class DataCloud(object): """Class that manages dvc remotes. diff --git a/dvc/logger.py b/dvc/logger.py index d756c0d6f..d6ec9fdd0 100644 --- a/dvc/logger.py +++ b/dvc/logger.py @@ -1,315 +1,173 @@ -"""Manages logger for dvc repo.""" +"""Manages logging configuration for dvc repo.""" from __future__ import unicode_literals -from dvc.exceptions import DvcException from dvc.utils.compat import str -from dvc.progress import progress_aware -import re -import sys import logging -import traceback - -from contextlib import contextmanager - +import logging.handlers +import logging.config import colorama -@progress_aware -def info(message): - """Prints an info message.""" - logger.info(message) +class ExcludeErrorsFilter(logging.Filter): + def filter(self, record): + return record.levelno < logging.ERROR -# Do not annotate debug with progress_aware. Why? Debug messages are called -# in analytics.py. Trigger introduced by @progress_aware may run even -# if log_level != DEBUG (look at Progress.print) Which might result in -# messy terminal after any command (because analytics run in separate thread) -def debug(message): - """Prints a debug message.""" - prefix = colorize("Debug", color="blue") +class ColorFormatter(logging.Formatter): + """Enable color support when logging to a terminal that supports it. - out = "{prefix}: {message}".format(prefix=prefix, message=message) + Color support on Windows versions that do not support ANSI color codes is + enabled by use of the colorama__ library. + See the colorama documentation for details. - logger.debug(out) + __ https://pypi.python.org/pypi/colorama - -@progress_aware -def warning(message, parse_exception=False): - """Prints a warning message.""" - prefix = colorize("Warning", color="yellow") - - exception, stack_trace = None, "" - if parse_exception: - exception, stack_trace = _parse_exc() - - out = "{prefix}: {description}".format( - prefix=prefix, description=_description(message, exception) - ) - - if stack_trace: - out += "\n{stack_trace}".format(stack_trace=stack_trace) - - logger.warning(out) - - -@progress_aware -def error(message=None): - """Prints an error message.""" - prefix = colorize("Error", color="red") - - exception, stack_trace = _parse_exc() - - out = ( - "{prefix}: {description}" - "\n" - "{stack_trace}" - "\n" - "{footer}".format( - prefix=prefix, - description=_description(message, exception), - stack_trace=stack_trace, - footer=_footer(), - ) - ) - - logger.error(out) - - -def box(message, border_color=None): - """Prints a message in a box. - - Args: - message (unicode): message to print. - border_color (unicode): name of a color to outline the box with. + For records containing `exc_info`, it will use a custom `_walk_exc` to + retrieve the whole tracebak. """ - lines = message.split("\n") - max_width = max(_visual_width(line) for line in lines) - padding_horizontal = 5 - padding_vertical = 1 - - box_size_horizontal = max_width + (padding_horizontal * 2) - - chars = {"corner": "+", "horizontal": "-", "vertical": "|", "empty": " "} - - margin = "{corner}{line}{corner}\n".format( - corner=chars["corner"], line=chars["horizontal"] * box_size_horizontal - ) - - padding_lines = [ - "{border}{space}{border}\n".format( - border=colorize(chars["vertical"], color=border_color), - space=chars["empty"] * box_size_horizontal, - ) - * padding_vertical - ] - - content_lines = [ - "{border}{space}{content}{space}{border}\n".format( - border=colorize(chars["vertical"], color=border_color), - space=chars["empty"] * padding_horizontal, - content=_visual_center(line, max_width), - ) - for line in lines - ] - - box_str = "{margin}{padding}{content}{padding}{margin}".format( - margin=colorize(margin, color=border_color), - padding="".join(padding_lines), - content="".join(content_lines), - ) - - logger.info(box_str) - - -def level(): - """Returns current log level.""" - return logger.getEffectiveLevel() - - -def set_level(level_name): - """Sets log level. - - Args: - level_name (str): log level name. E.g. info, debug, warning, error, - critical. - """ - if not level_name: - return - - levels = { - "info": logging.INFO, - "debug": logging.DEBUG, - "warning": logging.WARNING, - "error": logging.ERROR, - "critical": logging.CRITICAL, + color_code = { + "DEBUG": colorama.Fore.BLUE, + "INFO": "", + "WARNING": colorama.Fore.YELLOW, + "ERROR": colorama.Fore.RED, + "CRITICAL": colorama.Fore.RED, } - logger.setLevel(levels.get(level_name)) - - -def be_quiet(): - """Disables all messages except critical ones.""" - logger.setLevel(logging.CRITICAL) - - -def be_verbose(): - """Enables all messages.""" - logger.setLevel(logging.DEBUG) - - -@contextmanager -def verbose(): - """Enables verbose mode for the context.""" - previous_level = level() - be_verbose() - yield - logger.setLevel(previous_level) - - -@contextmanager -def quiet(): - """Enables quiet mode for the context.""" - previous_level = level() - be_quiet() - yield - logger.setLevel(previous_level) - - -def is_quiet(): - """Returns whether or not all messages except critical ones are - disabled. - """ - return level() == logging.CRITICAL - - -def is_verbose(): - """Returns whether or not all messages are enabled.""" - return level() == logging.DEBUG - - -def colorize(message, color=None): - """Returns a message in a specified color.""" - if not color: - return message - - colors = { - "green": colorama.Fore.GREEN, - "yellow": colorama.Fore.YELLOW, - "blue": colorama.Fore.BLUE, - "red": colorama.Fore.RED, - } - - return "{color}{message}{nc}".format( - color=colors.get(color, ""), message=message, nc=colorama.Fore.RESET + footer = ( + "{yellow}Having any troubles?{nc}." + " Hit us up at {blue}https://dvc.org/support{nc}," + " we are always happy to help!" + ).format( + blue=colorama.Fore.BLUE, + nc=colorama.Fore.RESET, + yellow=colorama.Fore.YELLOW, ) + def format(self, record): + # Might result in messy terminal if we allow this in DEBUG records, + # because analytics is logging on a separate thread, that might not + # be using the same instance of `progress`. + if record.levelname != "DEBUG": + self._progress_aware() -def set_default_level(): - """Sets default log level.""" - logger.setLevel(logging.INFO) + if record.levelname == "INFO": + return record.msg + + if record.levelname == "ERROR" or record.levelname == "CRITICAL": + exception, stack_trace = self._parse_exc() + + return ( + "{color}{levelname}{nc}: {description}" + "{stack_trace}\n" + "\n" + "{footer}" + ).format( + color=self.color_code.get(record.levelname, ""), + nc=colorama.Fore.RESET, + levelname=record.levelname, + description=self._description(record.msg, exception), + msg=record.msg, + stack_trace=stack_trace, + footer=self.footer, + ) + + return "{color}{levelname}{nc}: {msg}".format( + color=self.color_code.get(record.levelname, ""), + nc=colorama.Fore.RESET, + levelname=record.levelname, + msg=record.msg, + ) + + def _description(self, message, exception): + if exception and message: + description = "{message} - {exception}" + elif exception: + description = "{exception}" + elif message: + description = "{message}" + + return description.format(message=message, exception=exception) + + def _walk_exc(self, exc): + import traceback + + exc_list = [str(exc)] + tb_list = [traceback.format_exc()] + + # NOTE: parsing chained exceptions. See dvc/exceptions.py for more info + while hasattr(exc, "cause") and exc.cause is not None: + exc_list.append(str(exc.cause)) + if hasattr(exc, "cause_tb") and exc.cause_tb is not None: + tb_list.insert(0, str(exc.cause_tb)) + exc = exc.cause + + return exc_list, tb_list + + def _parse_exc(self): + import sys + + exc = sys.exc_info()[1] + if not exc: + return (None, "") + + exc_list, tb_list = self._walk_exc(exc) + + exception = ": ".join(exc_list) + + if logging.getLogger("dvc").getEffectiveLevel() == logging.DEBUG: + stack_trace = ( + "\n" "{red}{line}{nc}\n" "{stack_trace}" "{red}{line}{nc}" + ).format( + red=colorama.Fore.RED, + nc=colorama.Fore.RESET, + line="-" * 60, + stack_trace="\n".join(tb_list), + ) + else: + stack_trace = "" + + return (exception, stack_trace) + + def _progress_aware(self): + """Add a new line if progress bar hasn't finished""" + from dvc.progress import progress + + if not progress.is_finished: + progress._print() + progress.clearln() -def _add_handlers(): - # NOTE: We need to initialize colorama before setting the stream handlers - # so it can wrap stdout/stderr and convert color codes to Windows. +def setup(level=logging.INFO): colorama.init() - formatter = "%(message)s" - - class _LogLevelFilter(logging.Filter): - # pylint: disable=too-few-public-methods - def filter(self, record): - return record.levelno <= logging.WARNING - - sh_out = logging.StreamHandler(sys.stdout) - sh_out.setFormatter(logging.Formatter(formatter)) - sh_out.setLevel(logging.DEBUG) - sh_out.addFilter(_LogLevelFilter()) - - sh_err = logging.StreamHandler(sys.stderr) - sh_err.setFormatter(logging.Formatter(formatter)) - sh_err.setLevel(logging.ERROR) - - logger.addHandler(sh_out) - logger.addHandler(sh_err) - - -def _walk_exc(exc): - exc_list = [str(exc)] - tb_list = [traceback.format_exc()] - - # NOTE: parsing chained exceptions. See dvc/exceptions.py for more info. - while hasattr(exc, "cause") and exc.cause is not None: - exc_list.append(str(exc.cause)) - if hasattr(exc, "cause_tb") and exc.cause_tb is not None: - tb_list.insert(0, str(exc.cause_tb)) - exc = exc.cause - - return exc_list, tb_list - - -def _parse_exc(): - exc = sys.exc_info()[1] - if not exc: - return (None, "") - - exc_list, tb_list = _walk_exc(exc) - - exception = ": ".join(exc_list) - - if is_verbose(): - stack_trace = "{line}\n{stack_trace}{line}\n".format( - line=colorize("-" * 60, color="red"), - stack_trace="\n".join(tb_list), - ) - else: - stack_trace = "" - - return (exception, stack_trace) - - -def _description(message, exception): - if exception and message: - description = "{message} - {exception}" - elif exception: - description = "{exception}" - elif message: - description = "{message}" - else: - raise DvcException( - "Unexpected error - either exception or message must be provided" - ) - - return description.format(message=message, exception=exception) - - -def _footer(): - return "{phrase} Hit us up at {url}, we are always happy to help!".format( - phrase=colorize("Having any troubles?", "yellow"), - url=colorize("https://dvc.org/support", "blue"), + logging.config.dictConfig( + { + "version": 1, + "filters": {"exclude_errors": {"()": ExcludeErrorsFilter}}, + "formatters": {"color": {"()": ColorFormatter}}, + "handlers": { + "console": { + "class": "logging.StreamHandler", + "level": "DEBUG", + "formatter": "color", + "stream": "ext://sys.stdout", + "filters": ["exclude_errors"], + }, + "console_errors": { + "class": "logging.StreamHandler", + "level": "ERROR", + "formatter": "color", + "stream": "ext://sys.stderr", + }, + }, + "loggers": { + "dvc": { + "level": level, + "handlers": ["console", "console_errors"], + } + }, + } ) - - -def _visual_width(line): - """Get the the number of columns required to display a string""" - - return len(re.sub(colorama.ansitowin32.AnsiToWin32.ANSI_CSI_RE, "", line)) - - -def _visual_center(line, width): - """Center align string according to it's visual width""" - - spaces = max(width - _visual_width(line), 0) - left_padding = int(spaces / 2) - right_padding = spaces - left_padding - - return (left_padding * " ") + line + (right_padding * " ") - - -logger = logging.getLogger("dvc") # pylint: disable=invalid-name - -set_default_level() -_add_handlers() diff --git a/dvc/main.py b/dvc/main.py index 18a952463..68329f120 100644 --- a/dvc/main.py +++ b/dvc/main.py @@ -2,13 +2,16 @@ from __future__ import unicode_literals -import dvc.logger as logger +import logging + from dvc.cli import parse_args -from dvc.command.base import CmdBase from dvc.analytics import Analytics from dvc.exceptions import NotDvcRepoError, DvcParserError +logger = logging.getLogger("dvc") + + def main(argv=None): """Run dvc CLI command. @@ -20,26 +23,28 @@ def main(argv=None): """ args = None cmd = None + try: args = parse_args(argv) - # Init loglevel early in case we'll run - # into errors before setting it properly - CmdBase.set_loglevel(args) + if args.quiet: + logger.setLevel(logging.CRITICAL) + + elif args.verbose: + logger.setLevel(logging.DEBUG) cmd = args.func(args) - ret = cmd.run_cmd() except KeyboardInterrupt: - logger.error("interrupted by the user") + logger.exception("interrupted by the user") ret = 252 except NotDvcRepoError: - logger.error() + logger.exception("") ret = 253 except DvcParserError: ret = 254 except Exception: # pylint: disable=broad-except - logger.error("unexpected error") + logger.exception("unexpected error") ret = 255 Analytics().send_cmd(cmd, args, ret) diff --git a/dvc/output/local.py b/dvc/output/local.py index f7cbaca68..b984083b0 100644 --- a/dvc/output/local.py +++ b/dvc/output/local.py @@ -1,8 +1,8 @@ from __future__ import unicode_literals import os +import logging -import dvc.logger as logger from dvc.utils.compat import urlparse from dvc.istextfile import istextfile from dvc.exceptions import DvcException @@ -10,6 +10,9 @@ from dvc.remote.local import RemoteLOCAL from dvc.output.base import OutputBase, OutputAlreadyTrackedError +logger = logging.getLogger(__name__) + + class OutputLOCAL(OutputBase): REMOTE = RemoteLOCAL diff --git a/dvc/progress.py b/dvc/progress.py index 8444b808b..3e247623e 100644 --- a/dvc/progress.py +++ b/dvc/progress.py @@ -33,11 +33,11 @@ class Progress(object): return self._n_total == self._n_finished def clearln(self): - self.print(CLEARLINE_PATTERN, end="") + self._print(CLEARLINE_PATTERN, end="") def _writeln(self, line): self.clearln() - self.print(line, end="") + self._print(line, end="") sys.stdout.flush() def reset(self): @@ -74,7 +74,7 @@ class Progress(object): if sys.stdout.isatty(): self.clearln() - self.print(pbar) + self._print(pbar) self._n_finished += 1 self._line = None @@ -106,10 +106,12 @@ class Progress(object): return num + pbar + percent + target_name @staticmethod - def print(*args, **kwargs): - import dvc.logger as logger + def _print(*args, **kwargs): + import logging - if logger.is_quiet(): + logger = logging.getLogger(__name__) + + if logger.getEffectiveLevel() == "CRITICAL": return print(*args, **kwargs) @@ -132,7 +134,7 @@ def progress_aware(f): @wraps(f) def wrapper(*args, **kwargs): if not progress.is_finished: - progress.print() + progress._print() progress.clearln() return f(*args, **kwargs) diff --git a/dvc/remote/azure.py b/dvc/remote/azure.py index 99fbcef7b..da13d942b 100644 --- a/dvc/remote/azure.py +++ b/dvc/remote/azure.py @@ -3,6 +3,7 @@ from __future__ import unicode_literals import os import re +import logging try: from azure.storage.blob import BlockBlobService @@ -10,7 +11,6 @@ try: except ImportError: BlockBlobService = None -import dvc.logger as logger from dvc.utils import tmp_fname, move from dvc.utils.compat import urlparse, makedirs from dvc.progress import progress @@ -18,6 +18,9 @@ from dvc.config import Config from dvc.remote.base import RemoteBase +logger = logging.getLogger(__name__) + + class Callback(object): def __init__(self, name): self.name = name diff --git a/dvc/remote/base.py b/dvc/remote/base.py index cdba4c620..abdcf633c 100644 --- a/dvc/remote/base.py +++ b/dvc/remote/base.py @@ -4,14 +4,17 @@ from dvc.utils.compat import str import re import posixpath +import logging from multiprocessing import cpu_count import dvc.prompt as prompt -import dvc.logger as logger from dvc.config import Config from dvc.exceptions import DvcException, ConfirmRemoveError +logger = logging.getLogger(__name__) + + STATUS_OK = 1 STATUS_MISSING = 2 STATUS_NEW = 3 diff --git a/dvc/remote/gs.py b/dvc/remote/gs.py index dd57ad9d2..9e494ce97 100644 --- a/dvc/remote/gs.py +++ b/dvc/remote/gs.py @@ -1,13 +1,13 @@ from __future__ import unicode_literals import os +import logging try: from google.cloud import storage except ImportError: storage = None -import dvc.logger as logger from dvc.utils import tmp_fname, move from dvc.utils.compat import urlparse, makedirs from dvc.remote.base import RemoteBase @@ -16,6 +16,9 @@ from dvc.progress import progress from dvc.exceptions import DvcException +logger = logging.getLogger(__name__) + + class RemoteGS(RemoteBase): scheme = "gs" REGEX = r"^gs://(?P.*)$" @@ -146,7 +149,7 @@ class RemoteGS(RemoteBase): blob.upload_from_filename(from_info["path"]) except Exception: msg = "failed to upload '{}' to '{}/{}'" - logger.error( + logger.exception( msg.format( from_info["path"], to_info["bucket"], to_info["path"] ) @@ -200,7 +203,7 @@ class RemoteGS(RemoteBase): blob.download_to_filename(tmp_file) except Exception: msg = "failed to download '{}/{}' to '{}'" - logger.error( + logger.exception( msg.format( from_info["bucket"], from_info["path"], to_info["path"] ) diff --git a/dvc/remote/hdfs.py b/dvc/remote/hdfs.py index 31620e82e..4a0a66ff6 100644 --- a/dvc/remote/hdfs.py +++ b/dvc/remote/hdfs.py @@ -4,14 +4,17 @@ import os import re import getpass import posixpath +import logging from subprocess import Popen, PIPE -import dvc.logger as logger from dvc.config import Config from dvc.remote.base import RemoteBase, RemoteCmdError from dvc.utils import fix_env, tmp_fname +logger = logging.getLogger(__name__) + + class RemoteHDFS(RemoteBase): scheme = "hdfs" REGEX = r"^hdfs://((?P.*)@)?.*$" diff --git a/dvc/remote/http.py b/dvc/remote/http.py index ed587f35b..2132e1e55 100644 --- a/dvc/remote/http.py +++ b/dvc/remote/http.py @@ -4,8 +4,8 @@ from dvc.utils.compat import open, makedirs import os import threading import requests +import logging -import dvc.logger as logger from dvc.progress import progress from dvc.exceptions import DvcException from dvc.config import Config @@ -13,6 +13,9 @@ from dvc.remote.base import RemoteBase from dvc.utils import move +logger = logging.getLogger(__name__) + + class ProgressBarCallback(object): def __init__(self, name, total): self.name = name diff --git a/dvc/remote/local.py b/dvc/remote/local.py index 702f34ad2..833f59bb4 100644 --- a/dvc/remote/local.py +++ b/dvc/remote/local.py @@ -9,9 +9,9 @@ import json import ntpath import shutil import posixpath +import logging from operator import itemgetter -import dvc.logger as logger from dvc.system import System from dvc.remote.base import ( RemoteBase, @@ -38,6 +38,9 @@ from concurrent.futures import ThreadPoolExecutor from dvc.utils.fs import get_mtime_and_size, get_inode +logger = logging.getLogger(__name__) + + class RemoteLOCAL(RemoteBase): scheme = "local" REGEX = r"^(?P.*)$" diff --git a/dvc/remote/s3.py b/dvc/remote/s3.py index 8e7f20b7f..baef66c3e 100644 --- a/dvc/remote/s3.py +++ b/dvc/remote/s3.py @@ -2,13 +2,13 @@ from __future__ import unicode_literals import os import threading +import logging try: import boto3 except ImportError: boto3 = None -import dvc.logger as logger from dvc.utils import tmp_fname, move from dvc.utils.compat import urlparse, makedirs from dvc.progress import progress @@ -17,6 +17,9 @@ from dvc.remote.base import RemoteBase from dvc.exceptions import DvcException +logger = logging.getLogger(__name__) + + class Callback(object): def __init__(self, name, total): self.name = name diff --git a/dvc/remote/ssh/__init__.py b/dvc/remote/ssh/__init__.py index 862247a56..7bcac9557 100644 --- a/dvc/remote/ssh/__init__.py +++ b/dvc/remote/ssh/__init__.py @@ -1,6 +1,7 @@ from __future__ import unicode_literals import getpass +import logging try: import paramiko @@ -8,13 +9,15 @@ except ImportError: paramiko = None import dvc.prompt as prompt -import dvc.logger as logger from dvc.remote.ssh.connection import SSHConnection from dvc.config import Config from dvc.utils.compat import urlparse from dvc.remote.base import RemoteBase +logger = logging.getLogger(__name__) + + class RemoteSSH(RemoteBase): scheme = "ssh" @@ -184,7 +187,7 @@ class RemoteSSH(RemoteBase): from_info["path"], to_info["path"], progress_title=name ) except Exception: - logger.error( + logger.exception( "failed to upload '{host}/{path}' to '{dest}'".format( host=from_info["host"], path=from_info["path"], diff --git a/dvc/remote/ssh/connection.py b/dvc/remote/ssh/connection.py index f8576a7f1..3b2b64594 100644 --- a/dvc/remote/ssh/connection.py +++ b/dvc/remote/ssh/connection.py @@ -1,13 +1,13 @@ import errno import os import posixpath +import logging try: import paramiko except ImportError: paramiko = None -import dvc.logger as logger from dvc.utils import tmp_fname from dvc.utils.compat import makedirs from dvc.progress import progress @@ -15,6 +15,9 @@ from dvc.exceptions import DvcException from dvc.remote.base import RemoteCmdError +logger = logging.getLogger(__name__) + + def sizeof_fmt(num, suffix="B"): """ Convert number of bytes to human-readable string """ for unit in ["", "K", "M", "G", "T", "P", "E", "Z"]: diff --git a/dvc/repo/__init__.py b/dvc/repo/__init__.py index a082e7c0b..8a5bc7bc7 100644 --- a/dvc/repo/__init__.py +++ b/dvc/repo/__init__.py @@ -1,9 +1,9 @@ from __future__ import unicode_literals import os +import logging import dvc.prompt as prompt -import dvc.logger as logger from dvc.exceptions import ( DvcException, @@ -13,6 +13,9 @@ from dvc.exceptions import ( ) +logger = logging.getLogger(__name__) + + class Repo(object): DVC_DIR = ".dvc" @@ -65,7 +68,11 @@ class Repo(object): core = self.config.config[Config.SECTION_CORE] - logger.set_level(core.get(Config.SECTION_CORE_LOGLEVEL)) + logger.setLevel( + logging.getLevelName( + core.get(Config.SECTION_CORE_LOGLEVEL, "info").upper() + ) + ) self.cache = Cache(self) self.cloud = DataCloud(self, config=self.config.config) diff --git a/dvc/repo/checkout.py b/dvc/repo/checkout.py index d5365a893..8083feabc 100644 --- a/dvc/repo/checkout.py +++ b/dvc/repo/checkout.py @@ -1,10 +1,14 @@ from __future__ import unicode_literals -import dvc.logger as logger +import logging + from dvc.exceptions import CheckoutErrorSuggestGit from dvc.progress import ProgressCallback +logger = logging.getLogger(__name__) + + def _cleanup_unused_links(self, all_stages): used = [] for stage in all_stages: diff --git a/dvc/repo/gc.py b/dvc/repo/gc.py index b99c39ac8..58ed42e59 100644 --- a/dvc/repo/gc.py +++ b/dvc/repo/gc.py @@ -1,8 +1,10 @@ from __future__ import unicode_literals import collections +import logging -import dvc.logger as logger + +logger = logging.getLogger(__name__) def _merge_cache_lists(clists): diff --git a/dvc/repo/init.py b/dvc/repo/init.py index dc23f223a..ab4fb723a 100644 --- a/dvc/repo/init.py +++ b/dvc/repo/init.py @@ -1,22 +1,28 @@ import os import shutil import colorama +import logging -import dvc.logger as logger from dvc.repo import Repo from dvc.scm import SCM, NoSCM from dvc.config import Config from dvc.exceptions import InitError +from dvc.utils import boxify + + +logger = logging.getLogger(__name__) def _welcome_message(): - logger.box( - "DVC has enabled anonymous aggregate usage analytics.\n" - "Read the analytics documentation (and how to opt-out) here:\n" - "{blue}https://dvc.org/doc/user-guide/analytics{nc}".format( - blue=colorama.Fore.BLUE, nc=colorama.Fore.RESET - ), - border_color="red", + logger.info( + boxify( + "DVC has enabled anonymous aggregate usage analytics.\n" + "Read the analytics documentation (and how to opt-out) here:\n" + "{blue}https://dvc.org/doc/user-guide/analytics{nc}".format( + blue=colorama.Fore.BLUE, nc=colorama.Fore.RESET + ), + border_color="red", + ) ) msg = ( diff --git a/dvc/repo/metrics/show.py b/dvc/repo/metrics/show.py index 4bbd5a16e..e331f096b 100644 --- a/dvc/repo/metrics/show.py +++ b/dvc/repo/metrics/show.py @@ -3,13 +3,16 @@ from __future__ import unicode_literals import os import csv import json +import logging from jsonpath_rw import parse -import dvc.logger as logger from dvc.exceptions import OutputNotFoundError, BadMetricError, NoMetricsError from dvc.utils.compat import builtin_str, open, StringIO, csv_reader +logger = logging.getLogger(__name__) + + def _read_metric_json(fd, json_path): parser = parse(json_path) return [x.value for x in parser.find(json.load(fd))] @@ -136,11 +139,10 @@ def _read_metric(fd, typ=None, xpath=None, rel_path=None, branch=None): # Json path library has to be replaced or wrapped in # order to fix this too broad except clause. except Exception: - logger.warning( + logger.exception( "unable to read metric in '{}' in branch '{}'".format( rel_path, branch - ), - parse_exception=True, + ) ) return None diff --git a/dvc/repo/pkg.py b/dvc/repo/pkg.py index b58d08108..30f57a99d 100644 --- a/dvc/repo/pkg.py +++ b/dvc/repo/pkg.py @@ -2,13 +2,16 @@ from __future__ import unicode_literals import os import shutil +import logging -import dvc.logger as logger from dvc.exceptions import DvcException from dvc.stage import Stage from dvc.scm.git.temp_git_repo import TempGitRepo +logger = logging.getLogger(__name__) + + class PackageParams(object): def __init__(self, address, target_dir, select=[], file=None): self.address = address @@ -196,7 +199,7 @@ def install_pkg(self, pkg_params): mgr = PackageManager.get_package(addr) mgr.install_or_update(self, pkg_params) except Exception as ex: - logger.error("Unable to install package: ".format(ex)) + logger.exception("Unable to install package: ".format(ex)) return 1 return 0 diff --git a/dvc/repo/reproduce.py b/dvc/repo/reproduce.py index 83b1f85e4..54c4d3361 100644 --- a/dvc/repo/reproduce.py +++ b/dvc/repo/reproduce.py @@ -1,12 +1,15 @@ from __future__ import unicode_literals import os +import logging -import dvc.logger as logger from dvc.exceptions import ReproductionError from dvc.repo.scm_context import scm_context +logger = logging.getLogger(__name__) + + def _reproduce_stage(stages, node, force, dry, interactive, no_commit): stage = stages[node] diff --git a/dvc/repo/status.py b/dvc/repo/status.py index da931ed17..24bc17fc6 100644 --- a/dvc/repo/status.py +++ b/dvc/repo/status.py @@ -1,6 +1,9 @@ from __future__ import unicode_literals -import dvc.logger as logger +import logging + + +logger = logging.getLogger(__name__) def _local_status(self, target=None, with_deps=False): diff --git a/dvc/repo/tag/add.py b/dvc/repo/tag/add.py index 5a06f2129..4dd866da3 100644 --- a/dvc/repo/tag/add.py +++ b/dvc/repo/tag/add.py @@ -1,4 +1,7 @@ -import dvc.logger as logger +import logging + + +logger = logging.getLogger(__name__) def add(self, tag, target=None, with_deps=False, recursive=False): diff --git a/dvc/repo/tag/remove.py b/dvc/repo/tag/remove.py index f5f29f8bc..6ce540164 100644 --- a/dvc/repo/tag/remove.py +++ b/dvc/repo/tag/remove.py @@ -1,4 +1,7 @@ -import dvc.logger as logger +import logging + + +logger = logging.getLogger(__name__) def remove(self, tag, target=None, with_deps=False, recursive=False): diff --git a/dvc/scm/git/__init__.py b/dvc/scm/git/__init__.py index 9eb49f096..c6db51da5 100644 --- a/dvc/scm/git/__init__.py +++ b/dvc/scm/git/__init__.py @@ -3,6 +3,7 @@ from __future__ import unicode_literals import os +import logging from dvc.utils.compat import str, open from dvc.utils import fix_env @@ -13,7 +14,9 @@ from dvc.scm.base import ( FileNotInTargetSubdirError, ) from dvc.scm.git.tree import GitTree -import dvc.logger as logger + + +logger = logging.getLogger(__name__) DIFF_A_TREE = "a_tree" @@ -161,7 +164,7 @@ class Git(Base): " for more details.".format(str(paths)) ) - logger.error(msg) + logger.exception(msg) def commit(self, msg): self.git.index.commit(msg) diff --git a/dvc/scm/git/temp_git_repo.py b/dvc/scm/git/temp_git_repo.py index 7faf30868..9793a08cf 100644 --- a/dvc/scm/git/temp_git_repo.py +++ b/dvc/scm/git/temp_git_repo.py @@ -1,11 +1,14 @@ import os import shutil import tempfile +import logging -from dvc import logger from dvc.exceptions import DvcException +logger = logging.getLogger(__name__) + + class TempRepoException(DvcException): """Raise when temporary package repository has not properly created""" diff --git a/dvc/stage.py b/dvc/stage.py index 8aafc029e..eecfaa2b2 100644 --- a/dvc/stage.py +++ b/dvc/stage.py @@ -6,18 +6,21 @@ import re import os import yaml import subprocess +import logging from dvc.utils.fs import contains_symlink_up_to from schema import Schema, SchemaError, Optional, Or, And import dvc.prompt as prompt -import dvc.logger as logger import dvc.dependency as dependency import dvc.output as output from dvc.exceptions import DvcException from dvc.utils import dict_md5, fix_env, load_stage_file_fobj +logger = logging.getLogger(__name__) + + class StageCmdFailedError(DvcException): def __init__(self, stage): msg = "stage '{}' cmd {} failed".format(stage.relpath, stage.cmd) @@ -254,13 +257,9 @@ class Stage(object): ) if ret: - msg = "Stage '{}' changed.".format(self.relpath) - color = "yellow" + logger.warning("Stage '{}' changed.".format(self.relpath)) else: - msg = "Stage '{}' didn't change.".format(self.relpath) - color = "green" - - logger.info(logger.colorize(msg, color)) + logger.info("Stage '{}' didn't change.".format(self.relpath)) return ret diff --git a/dvc/state.py b/dvc/state.py index d7aee402d..70c7317fb 100644 --- a/dvc/state.py +++ b/dvc/state.py @@ -4,14 +4,17 @@ from __future__ import unicode_literals import os import sqlite3 +import logging -import dvc.logger as logger from dvc.config import Config from dvc.utils import file_md5, remove, current_timestamp from dvc.exceptions import DvcException from dvc.utils.fs import get_mtime_and_size, get_inode +logger = logging.getLogger(__name__) + + class StateVersionTooNewError(DvcException): """Thrown when dvc version is older than the state database version.""" diff --git a/dvc/updater.py b/dvc/updater.py index b7bd00760..008e37ea7 100644 --- a/dvc/updater.py +++ b/dvc/updater.py @@ -3,14 +3,17 @@ from __future__ import unicode_literals import sys import os import time +import logging import requests import colorama from pkg_resources import parse_version from dvc import __version__ -import dvc.logger as logger from dvc.lock import Lock, LockError -from dvc.utils import is_binary +from dvc.utils import is_binary, boxify + + +logger = logging.getLogger(__name__) class Updater(object): # pragma: no cover @@ -110,7 +113,7 @@ class Updater(object): # pragma: no cover latest=self.latest, ) - logger.box(message, border_color="yellow") + logger.info(boxify(message, border_color="yellow")) def _get_update_instructions(self): instructions = { diff --git a/dvc/utils/__init__.py b/dvc/utils/__init__.py index 624edc7ab..553f503eb 100644 --- a/dvc/utils/__init__.py +++ b/dvc/utils/__init__.py @@ -14,9 +14,15 @@ import shutil import hashlib import nanotime import time +import colorama +import re +import logging from yaml.scanner import ScannerError + +logger = logging.getLogger(__name__) + LOCAL_CHUNK_SIZE = 1024 * 1024 LARGE_FILE_SIZE = 1024 * 1024 * 1024 LARGE_DIR_SIZE = 100 @@ -28,7 +34,6 @@ def dos2unix(data): def file_md5(fname): """ get the (md5 hexdigest, md5 digest) of a file """ - import dvc.logger as logger from dvc.progress import progress from dvc.istextfile import istextfile @@ -152,8 +157,6 @@ def move(src, dst): def remove(path): - import dvc.logger as logger - if not os.path.exists(path): return @@ -249,3 +252,83 @@ def walk_files(directory): for root, _, files in os.walk(str(directory)): for f in files: yield os.path.join(root, f) + + +def colorize(message, color=None): + """Returns a message in a specified color.""" + if not color: + return message + + colors = { + "green": colorama.Fore.GREEN, + "yellow": colorama.Fore.YELLOW, + "blue": colorama.Fore.BLUE, + "red": colorama.Fore.RED, + } + + return "{color}{message}{nc}".format( + color=colors.get(color, ""), message=message, nc=colorama.Fore.RESET + ) + + +def boxify(message, border_color=None): + """Put a message inside a box. + + Args: + message (unicode): message to decorate. + border_color (unicode): name of the color to outline the box with. + """ + lines = message.split("\n") + max_width = max(_visual_width(line) for line in lines) + + padding_horizontal = 5 + padding_vertical = 1 + + box_size_horizontal = max_width + (padding_horizontal * 2) + + chars = {"corner": "+", "horizontal": "-", "vertical": "|", "empty": " "} + + margin = "{corner}{line}{corner}\n".format( + corner=chars["corner"], line=chars["horizontal"] * box_size_horizontal + ) + + padding_lines = [ + "{border}{space}{border}\n".format( + border=colorize(chars["vertical"], color=border_color), + space=chars["empty"] * box_size_horizontal, + ) + * padding_vertical + ] + + content_lines = [ + "{border}{space}{content}{space}{border}\n".format( + border=colorize(chars["vertical"], color=border_color), + space=chars["empty"] * padding_horizontal, + content=_visual_center(line, max_width), + ) + for line in lines + ] + + box_str = "{margin}{padding}{content}{padding}{margin}".format( + margin=colorize(margin, color=border_color), + padding="".join(padding_lines), + content="".join(content_lines), + ) + + return box_str + + +def _visual_width(line): + """Get the the number of columns required to display a string""" + + return len(re.sub(colorama.ansitowin32.AnsiToWin32.ANSI_CSI_RE, "", line)) + + +def _visual_center(line, width): + """Center align string according to it's visual width""" + + spaces = max(width - _visual_width(line), 0) + left_padding = int(spaces / 2) + right_padding = spaces - left_padding + + return (left_padding * " ") + line + (right_padding * " ") diff --git a/dvc/utils/fs.py b/dvc/utils/fs.py index 07efa2d1f..822ef6401 100644 --- a/dvc/utils/fs.py +++ b/dvc/utils/fs.py @@ -2,13 +2,16 @@ from __future__ import unicode_literals import nanotime import os +import logging -import dvc.logger as logger from dvc.exceptions import DvcException from dvc.system import System from dvc.utils.compat import str +logger = logging.getLogger(__name__) + + def get_inode(path): inode = System.inode(path) logger.debug("Path {} inode {}".format(path, inode))