Repository: dbt-labs/dbt-core
Pull request: Retry GitHub download failures
resolves https://github.com/dbt-labs/dbt/issues/3546

### Description

We are seeing `dbt deps` fail intermittently when trying to reach out to GitHub. We do retry logic for when we reach out to the registry hub so we want to try the same retry logic for GitHub to see if it improves the success rate of `dbt deps`.


### Checklist
 - [ ] I have signed the [CLA](https://docs.getdbt.com/docs/contributor-license-agreements)
 - [ ] I have run this code in development and it appears to resolve the stated issue
 - [ ] This PR includes tests, or tests are not required/relevant for this PR
 - [ ] I have updated the `CHANGELOG.md` and added information about my change to the "dbt next" section.


Problem statement:
Detect GitHub network errors and provide a clean error that defines that a bad response came from GitHub
### Describe the feature
When running `dbt deps`, we found multiple users coming across different error states:
* tarfile.ReadError: file could not be opened successfully
* 2021-06-28 17:02:01.465062 (MainThread): STDOUT: "b''"
2021-06-28 17:02:01.465389 (MainThread): STDERR: "b"fatal: destination path '2570ae56bf9cb34e49fe01aa3bc99195' already exists and is not an empty directory.\n""
* HTTPSConnectionPool(host='codeload.github.com', port=443): Read timed out. (read timeout=10.0)

```
/usr/local/lib/python3.8/dist-packages/dbt/clients/system.py", line 471, in untar_package
  with tarfile.open(tar_path, 'r') as tarball:
File "usr/lib/python3.8/tarfile.py", line 1608, in open
  raise ReadError("file could not be opened successfully")
```

For all of these, the root cause was an intermittent outage of GitHub which meant that the repo was never pulled, timed out, or gave some kind of bad response.

I would like dbt to provide a cleaner error that properly identifies when a request to GitHub does not come back with the expected response, rather than failing in a followup I/O step with an unrelated error.

### Describe alternatives you've considered
We can write more logic around a dbt deps call to catch and confirm any kind of error state that may have come from this, but since the GitHub network request happens inside the core logic, it would be much harder to detect that the network response came back in a state that was not expected.

### Who will this benefit?
While I do think this could benefit anybody who is using GitHub with their dbt setup, this would greatly benefit the Support staff at dbt Labs, as well as the engineers at the company who triaged and attempted to identify a root cause, which could have been more easily identified at the site of the network request itself.

Hints from issue discussion:
Thanks for opening @heysweet!

This was cropping up in the `install` method of `dbt deps`. We failed to download the tar package, so when it came time to unpack ("untar") it, there was no tar there:

https://github.com/dbt-labs/dbt/blob/f460d275baa4df8cf8713f27e198a3577d6ea71c/core/dbt/deps/registry.py#L63-L67

Presumably, the error was a timeout in `system.download`:

https://github.com/dbt-labs/dbt/blob/f460d275baa4df8cf8713f27e198a3577d6ea71c/core/dbt/clients/system.py#L444-L452

I imagine we could do either of:
- Raise a descriptive exception the first time `download` times out
- Try `download` five times, then raise the exception

The latter would be consistent with [how we handle Hub site unavailability](https://github.com/dbt-labs/dbt/blob/f460d275baa4df8cf8713f27e198a3577d6ea71c/core/dbt/clients/registry.py#L25-L27), in an earlier `deps` step.
Thanks for this

We have just had this become a big issue for us. We have our dbt running in docker containers and it needs to run `dbt deps` every time an airflow dag is run. 

Our dags are now constantly failing due to this issue (presumably some kind of latency has been introduced into our network, not sure).

cc @BenBalde 


[ Subscribed ] A lot of etl jobs failing today because of this 👎

Commit message: Fixed linting and added comment

Patch to review:
diff --git a/core/dbt/clients/registry.py b/core/dbt/clients/registry.py
index 30b2c9020e6..78e569a8a3a 100644
--- a/core/dbt/clients/registry.py
+++ b/core/dbt/clients/registry.py
@@ -1,10 +1,7 @@
-from functools import wraps
 import requests
-from dbt.exceptions import RegistryException
-from dbt.utils import memoized
+from dbt.utils import memoized, _connection_exception_retry as connection_exception_retry
 from dbt.logger import GLOBAL_LOGGER as logger
 import os
-import time
 
 if os.getenv('DBT_PACKAGE_HUB_URL'):
     DEFAULT_REGISTRY_BASE_URL = os.getenv('DBT_PACKAGE_HUB_URL')
@@ -19,26 +16,10 @@ def _get_url(url, registry_base_url=None):
     return '{}{}'.format(registry_base_url, url)
 
 
-def _wrap_exceptions(fn):
-    @wraps(fn)
-    def wrapper(*args, **kwargs):
-        max_attempts = 5
-        attempt = 0
-        while True:
-            attempt += 1
-            try:
-                return fn(*args, **kwargs)
-            except (requests.exceptions.ConnectionError, requests.exceptions.Timeout) as exc:
-                if attempt < max_attempts:
-                    time.sleep(1)
-                    continue
-                raise RegistryException(
-                    'Unable to connect to registry hub'
-                ) from exc
-    return wrapper
-
-
-@_wrap_exceptions
+def _get_with_retries(path, registry_base_url=None):
+    return connection_exception_retry(lambda: _get(path, registry_base_url), 5)
+
+
 def _get(path, registry_base_url=None):
     url = _get_url(path, registry_base_url)
     logger.debug('Making package registry request: GET {}'.format(url))
@@ -50,22 +31,22 @@ def _get(path, registry_base_url=None):
 
 
 def index(registry_base_url=None):
-    return _get('api/v1/index.json', registry_base_url)
+    return _get_with_retries('api/v1/index.json', registry_base_url)
 
 
 index_cached = memoized(index)
 
 
 def packages(registry_base_url=None):
-    return _get('api/v1/packages.json', registry_base_url)
+    return _get_with_retries('api/v1/packages.json', registry_base_url)
 
 
 def package(name, registry_base_url=None):
-    return _get('api/v1/{}.json'.format(name), registry_base_url)
+    return _get_with_retries('api/v1/{}.json'.format(name), registry_base_url)
 
 
 def package_version(name, version, registry_base_url=None):
-    return _get('api/v1/{}/{}.json'.format(name, version), registry_base_url)
+    return _get_with_retries('api/v1/{}/{}.json'.format(name, version), registry_base_url)
 
 
 def get_available_versions(name):
diff --git a/core/dbt/clients/system.py b/core/dbt/clients/system.py
index 7d4de07108c..d3abc38876a 100644
--- a/core/dbt/clients/system.py
+++ b/core/dbt/clients/system.py
@@ -15,9 +15,8 @@
 )
 
 import dbt.exceptions
-import dbt.utils
-
 from dbt.logger import GLOBAL_LOGGER as logger
+from dbt.utils import _connection_exception_retry as connection_exception_retry
 
 if sys.platform == 'win32':
     from ctypes import WinDLL, c_bool
@@ -441,6 +440,12 @@ def run_cmd(
     return out, err
 
 
+def download_with_retries(
+    url: str, path: str, timeout: Optional[Union[float, tuple]] = None
+) -> None:
+    connection_exception_retry(lambda: download(url, path, timeout), 5)
+
+
 def download(
     url: str, path: str, timeout: Optional[Union[float, tuple]] = None
 ) -> None:
diff --git a/core/dbt/deps/registry.py b/core/dbt/deps/registry.py
index 59593dcce60..43033138fd7 100644
--- a/core/dbt/deps/registry.py
+++ b/core/dbt/deps/registry.py
@@ -61,7 +61,7 @@ def install(self, project, renderer):
         system.make_directory(os.path.dirname(tar_path))
 
         download_url = metadata.downloads.tarball
-        system.download(download_url, tar_path)
+        system.download_with_retries(download_url, tar_path)
         deps_path = project.modules_path
         package_name = self.get_project_name(project, renderer)
         system.untar_package(tar_path, deps_path, package_name)
diff --git a/core/dbt/exceptions.py b/core/dbt/exceptions.py
index 38f39580d47..674207c4153 100644
--- a/core/dbt/exceptions.py
+++ b/core/dbt/exceptions.py
@@ -714,7 +714,7 @@ def system_error(operation_name):
         .format(operation_name))
 
 
-class RegistryException(Exception):
+class ConnectionException(Exception):
     pass
 
 
diff --git a/core/dbt/utils.py b/core/dbt/utils.py
index 0fec7cf4850..0e97ee2483f 100644
--- a/core/dbt/utils.py
+++ b/core/dbt/utils.py
@@ -8,7 +8,12 @@
 import itertools
 import json
 import os
+import requests
+import time
+
 from contextlib import contextmanager
+from dbt.exceptions import ConnectionException
+from dbt.logger import GLOBAL_LOGGER as logger
 from enum import Enum
 from typing_extensions import Protocol
 from typing import (
@@ -599,3 +604,19 @@ def __getitem__(self, name: str) -> Any:
 
     def __contains__(self, name) -> bool:
         return any((name in entry for entry in self._itersource()))
+
+
+def _connection_exception_retry(fn, max_attempts: int, attempt: int = 0):
+    """Attempts to run a function that makes an external call, if the call fails
+    on a connection error or timeout, it will be tried up to 5 more times.
+    """
+    try:
+        return fn()
+    except (requests.exceptions.ConnectionError, requests.exceptions.Timeout) as exc:
+        if attempt <= max_attempts - 1:
+            logger.debug('Retrying external call. Attempt: ' +
+                         f'{attempt} Max attempts: {max_attempts}')
+            time.sleep(1)
+            _connection_exception_retry(fn, max_attempts, attempt + 1)
+        else:
+            raise ConnectionException('External connection exception occurred: ' + str(exc))
diff --git a/test/unit/test_core_dbt_utils.py b/test/unit/test_core_dbt_utils.py
new file mode 100644
index 00000000000..d3841071d8f
--- /dev/null
+++ b/test/unit/test_core_dbt_utils.py
@@ -0,0 +1,41 @@
+import requests
+import unittest
+
+from dbt.exceptions import ConnectionException
+from dbt.utils import _connection_exception_retry as connection_exception_retry
+
+
+class testCoreDbtUtils(unittest.TestCase):
+    def test_connection_exception_retry_none(self):
+        Counter._reset()
+        connection_exception_retry(lambda: Counter._add(), 5)
+        self.assertEqual(1, counter)
+
+    def test_connection_exception_retry_max(self):
+        Counter._reset()
+        self.assertRaises(ConnectionException, connection_exception_retry(lambda: Counter._add_with_exception(), 5))
+        self.assertEqual(6, counter) # 6 = original attempt plus 5 retries
+
+    def test_connection_exception_retry_success(self):
+        Counter._reset()
+        connection_exception_retry(lambda: Counter._add_with_limited_exception(), 5)
+        self.assertEqual(2, counter) # 2 = original attempt plus 1 retry
+
+
+counter:int = 0 
+class Counter():
+    def _add():
+        global counter
+        counter+=1
+    def _add_with_exception():
+        global counter
+        counter+=1
+        raise requests.exceptions.ConnectionError
+    def _add_with_limited_exception():
+        global counter
+        counter+=1
+        if counter < 2:
+            raise requests.exceptions.ConnectionError
+    def _reset():
+        global counter
+        counter = 0
diff --git a/test/unit/test_registry_get_request_exception.py b/test/unit/test_registry_get_request_exception.py
index 254169d9894..44033fe0546 100644
--- a/test/unit/test_registry_get_request_exception.py
+++ b/test/unit/test_registry_get_request_exception.py
@@ -1,9 +1,9 @@
 import unittest
 
-from dbt.exceptions import RegistryException
-from dbt.clients.registry import _get
+from dbt.exceptions import ConnectionException
+from dbt.clients.registry import _get_with_retries
 
 class testRegistryGetRequestException(unittest.TestCase):
     def test_registry_request_error_catching(self):
-        # using non routable IP to test connection error logic in the _get function
-        self.assertRaises(RegistryException, _get, '', 'http://0.0.0.0')
+        # using non routable IP to test connection error logic in the _get_with_retries function
+        self.assertRaises(ConnectionException, _get_with_retries, '', 'http://0.0.0.0')


Code review comments:
diff_hunk: @@ -0,0 +1,41 @@
+import requests
+import unittest
+
+from dbt.exceptions import ConnectionException
+from dbt.utils import _connection_exception_retry as connection_exception_retry
+
+
+class testCoreDbtUtils(unittest.TestCase):
+    def test_connection_exception_retry_none(self):
+        Counter._reset()
+        connection_exception_retry(lambda: Counter._add(), 5)
+        self.assertEqual(1, counter)
+
+    def test_connection_exception_retry_max(self):
+        Counter._reset()
+        self.assertRaises(ConnectionException, connection_exception_retry(lambda: Counter._add_with_exception(), 5))
path: test/unit/test_core_dbt_utils.py
text: @author:
This `assertRaises` doesn't work for me where it doesn't catch the exception (its the and the `ConnectionException` that is listed) and the test fails because an exception is hit. Can anyone see why that would be the case instead of it just succeeding that it was raised?

diff_hunk: @@ -19,26 +16,10 @@ def _get_url(url, registry_base_url=None):
     return '{}{}'.format(registry_base_url, url)
 
 
-def _wrap_exceptions(fn):
-    @wraps(fn)
-    def wrapper(*args, **kwargs):
-        max_attempts = 5
-        attempt = 0
-        while True:
-            attempt += 1
-            try:
-                return fn(*args, **kwargs)
-            except (requests.exceptions.ConnectionError, requests.exceptions.Timeout) as exc:
-                if attempt < max_attempts:
-                    time.sleep(1)
-                    continue
-                raise RegistryException(
-                    'Unable to connect to registry hub'
-                ) from exc
-    return wrapper
-
-
-@_wrap_exceptions
+def _get_with_retries(path, registry_base_url=None):
+    return connection_exception_retry(lambda: _get(path, registry_base_url), 5)
path: core/dbt/clients/registry.py
text: @user1:
Not a required change, but I _think_ this might be a good place to use `functools.partial`!(https://docs.python.org/3/library/functools.html#functools.partial)

```suggestion
    get_fn = partial(_get, path, registry_base_url)
    return connection_exception_retry(get_fn, 5)
```

diff_hunk: @@ -0,0 +1,41 @@
+import requests
+import unittest
+
+from dbt.exceptions import ConnectionException
+from dbt.utils import _connection_exception_retry as connection_exception_retry
+
+
+class testCoreDbtUtils(unittest.TestCase):
+    def test_connection_exception_retry_none(self):
+        Counter._reset()
+        connection_exception_retry(lambda: Counter._add(), 5)
+        self.assertEqual(1, counter)
+
+    def test_connection_exception_retry_max(self):
+        Counter._reset()
+        self.assertRaises(ConnectionException, connection_exception_retry(lambda: Counter._add_with_exception(), 5))
+        self.assertEqual(6, counter) # 6 = original attempt plus 5 retries
path: test/unit/test_core_dbt_utils.py
text: @user1:
Ah ya, `assertRaises` is annoying. I think this is failing here because `connection_exception_retry` is raising an exception before the `self.assertRaises` function call, so it is unable to "capture" the exception. I think you have 2 options to fix this issue, I personally like the first one and thing it is a little easier to follow.

```suggestion
    def test_connection_exception_retry_max(self):
        Counter._reset()
        with self.assertRaises(ConnectionException):
            connection_exception_retry(lambda: Counter._add_with_exception(), 5)
        self.assertEqual(6, counter) # 6 = original attempt plus 5 retries
```
or
```suggestion
    def test_connection_exception_retry_max(self):
        Counter._reset()
        self.assertRaises(ConnectionException, lambda: connection_exception_retry(lambda: Counter._add_with_exception(), 5))
        self.assertEqual(6, counter) # 6 = original attempt plus 5 retries
```

diff_hunk: @@ -0,0 +1,41 @@
+import requests
+import unittest
+
+from dbt.exceptions import ConnectionException
+from dbt.utils import _connection_exception_retry as connection_exception_retry
+
+
+class testCoreDbtUtils(unittest.TestCase):
path: test/unit/test_core_dbt_utils.py
text: @user1:
nit 😄 
```suggestion
class TestCoreDbtUtils(unittest.TestCase):
```