Merge pull request #1914 from pared/1890

repo: different cache link types info on long lasting operations

dvc/config.py

@@ -154,6 +154,7 @@ class Config(object):  # pylint: disable=too-many-instance-attributes
     SECTION_CACHE_SSH = "ssh"
     SECTION_CACHE_HDFS = "hdfs"
     SECTION_CACHE_AZURE = "azure"
+    SECTION_CACHE_SLOW_LINK_WARNING = "slow_link_warning"
     SECTION_CACHE_SCHEMA = {
         Optional(SECTION_CACHE_LOCAL): str,
         Optional(SECTION_CACHE_S3): str,
@@ -167,6 +168,9 @@ class Config(object):  # pylint: disable=too-many-instance-attributes
             str, is_bool, Use(to_bool)
         ),
         Optional(PRIVATE_CWD): str,
+        Optional(SECTION_CACHE_SLOW_LINK_WARNING, default=True): And(
+            str, is_bool, Use(to_bool)
+        ),
     }
 
     # backward compatibility

dvc/remote/local/__init__.py

@@ -2,6 +2,7 @@ from __future__ import unicode_literals
 
 from copy import copy
 
+from dvc.remote.local.slow_link_detection import slow_link_guard
 from dvc.utils.compat import str, makedirs
 
 import os
@@ -122,6 +123,7 @@ class RemoteLOCAL(RemoteBase):
         if not self.exists(path_info):
             os.makedirs(path_info["path"])
 
+    @slow_link_guard
     def link(self, cache_info, path_info):
         cache = cache_info["path"]
         path = path_info["path"]

dvc/remote/local/slow_link_detection.py

@@ -0,0 +1,63 @@
+import logging
+import time
+
+import colorama
+from dvc.config import Config
+
+logger = logging.getLogger(__name__)
+
+
+class SlowLinkDetectorDecorator(object):
+    LINKING_TIMEOUT_SECONDS = 10.0
+    was_displayed = False
+
+    @classmethod
+    def should_display(cls):
+        if not cls.was_displayed:
+            cls.was_displayed = True
+            return True
+        return False
+
+    def __init__(self, method):
+        self.method = method
+
+    def __call__(self, *args, **kwargs):
+        start = time.time()
+        result = self.method(*args, **kwargs)
+        execution_time_seconds = time.time() - start
+
+        if (
+            execution_time_seconds >= self.LINKING_TIMEOUT_SECONDS
+            and self.should_display()
+        ):
+            msg = (
+                "You can cut execution time considerably. Check:\n"
+                "{blue}https://dvc.org/doc/commands-reference/config#cache{"
+                "reset}"
+                "\nfor "
+                "more information.\nTo disable this message, run:\n'dvc "
+                "config "
+                "cache.slow_link_warning False'".format(
+                    blue=colorama.Fore.BLUE, reset=colorama.Fore.RESET
+                )
+            )
+            logger.warning(msg)
+
+        return result
+
+
+def slow_link_guard(method):
+    def call(remote_local, *args, **kwargs):
+        cache_config = remote_local.repo.config.config.get(
+            Config.SECTION_CACHE
+        )
+        should_warn = cache_config.get(
+            Config.SECTION_CACHE_SLOW_LINK_WARNING, True
+        ) and not cache_config.get(Config.SECTION_CACHE_TYPE, None)
+
+        if should_warn:
+            decorated = SlowLinkDetectorDecorator(method)
+            return decorated(remote_local, *args, **kwargs)
+        return method(remote_local, *args, **kwargs)
+
+    return call

tests/unit/remote/test_slow_link_detection.py

@@ -0,0 +1,115 @@
+import logging
+
+import colorama
+import pytest
+from dvc.config import Config
+from dvc.remote.local.slow_link_detection import (
+    slow_link_guard,
+    SlowLinkDetectorDecorator,
+)
+from mock import Mock, patch
+
+
+@patch(
+    "dvc.remote.local.slow_link_detection.SlowLinkDetectorDecorator",
+    autospec=True,
+)
+class TestSlowLinkGuard(object):
+    @pytest.fixture(autouse=True)
+    def setUp(self):
+        self.method = Mock()
+        self.remote_local_mock = Mock()
+        self.config_mock = Mock()
+        self.remote_local_mock.repo.config.config.get.return_value = (
+            self.config_mock
+        )
+
+    def _cache_config(self, slow_link_warning, cache_type):
+        def config_side_effect(section_name, _):
+            if section_name == Config.SECTION_CACHE_SLOW_LINK_WARNING:
+                return slow_link_warning
+            elif section_name == Config.SECTION_CACHE_TYPE:
+                return cache_type
+
+        self.config_mock.get.side_effect = config_side_effect
+
+    def test_should_decorate_on_slow_link_warning_and_no_cache_type(
+        self, SlowLinkDetectorDecoratorClassMock
+    ):
+        self._cache_config(slow_link_warning=True, cache_type=None)
+
+        slow_link_guard(self.method)(self.remote_local_mock)
+
+        assert 1 == SlowLinkDetectorDecoratorClassMock.call_count
+        assert 0 == self.method.call_count
+
+    @pytest.mark.parametrize(
+        "slow_link_warning, cache_type",
+        [(True, "any_cache_type"), (False, None)],
+    )
+    def test_should_not_decorate(
+        self, SlowLinkDetectorDecoratorClassMock, slow_link_warning, cache_type
+    ):
+        self._cache_config(
+            slow_link_warning=slow_link_warning, cache_type=cache_type
+        )
+
+        slow_link_guard(self.method)(self.remote_local_mock)
+
+        assert 0 == SlowLinkDetectorDecoratorClassMock.call_count
+        assert 1 == self.method.call_count
+
+
+class TestSlowLinkDetectorDecorator(object):
+    @pytest.fixture(autouse=True)
+    def setUp(self):
+        self.args_mock = Mock()
+        self.method_result_mock = Mock()
+
+        def method_effect(arg):
+            assert self.args_mock == arg
+            return self.method_result_mock
+
+        self.method_mock = Mock(side_effect=method_effect)
+
+    @patch.object(SlowLinkDetectorDecorator, "LINKING_TIMEOUT_SECONDS", 0.0)
+    def test_should_log_only_once(self, caplog):
+
+        with caplog.at_level(logging.WARNING, logger="dvc"):
+            test_instance = SlowLinkDetectorDecorator(self.method_mock)
+            result = test_instance(self.args_mock)
+            assert self.method_result_mock == result
+
+            # slow link guard keeps creating new SlowLinkDetectorDecorators
+            # each time it is called, so we need to make sure that we are
+            # preventing every new instance of this class from displaying the
+            # message
+            test_instance2 = SlowLinkDetectorDecorator(self.method_mock)
+            result = test_instance2(self.args_mock)
+            assert self.method_result_mock == result
+
+        msg = (
+            "You can cut execution time considerably. Check:\n"
+            "{blue}https://dvc.org/doc/commands-reference/config#cache{"
+            "reset}"
+            "\nfor "
+            "more information.\nTo disable this message, run:\n'dvc "
+            "config "
+            "cache.slow_link_warning False'".format(
+                blue=colorama.Fore.BLUE, reset=colorama.Fore.RESET
+            )
+        )
+        assert 1 == len(caplog.messages)
+        assert msg == caplog.messages[0]
+
+    @patch.object(
+        SlowLinkDetectorDecorator, "LINKING_TIMEOUT_SECONDS", 99999.0
+    )
+    def test_should_not_log(self, caplog):
+        test_instance = SlowLinkDetectorDecorator(self.method_mock)
+
+        with caplog.at_level(logging.WARNING, logger="dvc"):
+            result = test_instance(self.args_mock)
+
+        assert self.method_result_mock == result
+        assert 0 == len(caplog.messages)