SG-11528 Add optional sleep between retries

.travis.yml

@@ -2,6 +2,10 @@ language: python
 python:
   - "2.6"
   - "2.7"
+
+# use trusty dist, since xenial (default) does not support python 2.6
+dist: trusty
+
 # command to install dependencies
 install:
   - pip install -r tests/ci_requirements.txt

HISTORY.rst

@@ -4,6 +4,10 @@ Shotgun Python API Changelog
 
 Here you can see the full list of changes between each Python API release.
 
+v3.0.41 (2019 June 28)
+=====================
+- Adds an optional sleep between retries specified via the `SHOTGUN_API_RETRY_INTERVAL` environment variable, or by setting `sg.config.rpc_attempt_interval`.
+
 v3.0.40 (2019 March 13)
 =====================
 - Updates encoding method to use shutil when uploading, to avoid memory and overflow errors when reading large files. (contributed by @eestrada)

docs/reference.rst

@@ -868,4 +868,23 @@ are specifically displaying EventLogEntries in the web application, or API queri
 log that are run. We are always looking for ways to improve this in the future. If you have any
 immediate concerns, please `reach out to our support team <https://support.shotgunsoftware.com>`_
 
+*********************
+Environment Variables
+*********************
+
+SHOTGUN_API_CACERTS
+===================
+
+Used to specify a path to an external SSL certificates file.  This environment variable can be used in place of the ``ca_certs`` keyword argument to the :class:`~shotgun.Shotgun` constructor.  In the case that both this environment variable is set and the keyword argument is provided, the value from the keyword argument will be used.
+
+
+SHOTGUN_API_RETRY_INTERVAL
+==========================
+
+Stores the number of milliseconds to wait between request retries.  By default, a value of 3000 milliseconds is used. You can override the default either by setting this environment variable, or by setting the ``rpc_attempt_interval`` property on the config like so: ::
+
+    sg = Shotgun(site_name, script_name, script_key)
+    sg.config.rpc_attempt_interval = 1000 # adjusting default interval
+
+In the case that both this environment variable and the config's ``rpc_attempt_interval`` property are set, the value in ``rpc_attempt_interal`` will be used.
 

setup.py

@@ -17,7 +17,7 @@
 
 setup(
     name='shotgun_api3',
-    version='3.0.40',
+    version='3.0.41',
     description='Shotgun Python API ',
     long_description=readme,
     author='Shotgun Software',

shotgun_api3/shotgun.py

@@ -92,7 +92,7 @@
 
 # ----------------------------------------------------------------------------
 # Version
-__version__ = "3.0.40"
+__version__ = "3.0.41"
 
 # ----------------------------------------------------------------------------
 # Errors
@@ -345,6 +345,17 @@ def __init__(self, sg):
         """
         self._sg = sg
         self.max_rpc_attempts = 3
+        # rpc_attempt_interval stores the number of milliseconds to wait between
+        # request retries.  By default, this will be 3000 milliseconds. You can
+        # override this by setting this property on the config like so:
+        #
+        #      sg = Shotgun(site_name, script_name, script_key)
+        #      sg.config.rpc_attempt_interval = 1000 # adjusting default interval
+        #
+        # Or by setting the ``SHOTGUN_API_RETRY_INTERVAL`` environment variable.
+        # In the case that the environment variable is already set, setting the
+        # property on the config will override it.
+        self.rpc_attempt_interval = 3000
         # From http://docs.python.org/2.6/library/httplib.html:
         # If the optional timeout parameter is given, blocking operations
         # (like connection attempts) will timeout after that many seconds
@@ -553,6 +564,17 @@ def __init__(self,
         self.config.convert_datetimes_to_utc = convert_datetimes_to_utc
         self.config.no_ssl_validation = NO_SSL_VALIDATION
         self.config.raw_http_proxy = http_proxy
+
+        try:
+            self.config.rpc_attempt_interval = int(os.environ.get("SHOTGUN_API_RETRY_INTERVAL", 3000))
+        except ValueError:
+            retry_interval = os.environ.get("SHOTGUN_API_RETRY_INTERVAL", 3000)
+            raise ValueError("Invalid value '%s' found in environment variable "
+                             "SHOTGUN_API_RETRY_INTERVAL, must be int." % retry_interval)
+        if self.config.rpc_attempt_interval < 0:
+            raise ValueError("Value of SHOTGUN_API_RETRY_INTERVAL must be positive, "
+                             "got '%s'." % self.config.rpc_attempt_interval)
+
         self._connection = None
         if ca_certs is not None:
             self.__ca_certs = ca_certs
@@ -3308,6 +3330,7 @@ def _make_call(self, verb, path, body, headers):
         body = body or None
 
         max_rpc_attempts = self.config.max_rpc_attempts
+        rpc_attempt_interval = self.config.rpc_attempt_interval / 1000.0
 
         while (attempt < max_rpc_attempts):
             attempt += 1
@@ -3346,10 +3369,15 @@ def _make_call(self, verb, path, body, headers):
                 if attempt == max_rpc_attempts:
                     raise
             except Exception:
-                #TODO: LOG ?
                 self._close_connection()
                 if attempt == max_rpc_attempts:
+                    LOG.debug("Request failed.  Giving up after %d attempts." % attempt)
                     raise
+                LOG.debug(
+                    "Request failed, attempt %d of %d.  Retrying in %.2f seconds..." %
+                    (attempt, max_rpc_attempts, rpc_attempt_interval)
+                )
+                time.sleep(rpc_attempt_interval)
 
     def _http_request(self, verb, path, body, headers):
         """

tests/test_api.py

@@ -801,6 +801,7 @@ def test_preferences_read(self):
 
         expected = {
             'date_component_order': 'month_day',
+            'duration_units': 'days',
             'format_currency_fields_decimal_options': '$1,000.99',
             'format_currency_fields_display_dollar_sign': False,
             'format_currency_fields_negative_options': '- $1,000',
@@ -810,8 +811,10 @@ def test_preferences_read(self):
             'format_footage_fields': '10-05',
             'format_number_fields': '1,000',
             'format_time_hour_fields': '12 hour',
+            'hours_per_day': 8.0,
+            'last_day_work_week': None,
             'support_local_storage': False,
-            'view_master_settings': '{"status_groups":[{"name":"Upcoming","code":"upc_stgr","status_list":["wtg","rdy"]},{"name":"Active","code":"act_stgr","status_list":["ip","kickbk","rev","act","rsk","blk","late","opn","pndng","tkt","push","rrq","vwd","out"]},{"name":"Done","code":"done_stgr","status_list":["fin","cmpt","apr","cbb","clsd","cfrm","dlvr","recd","res"]}],"entity_fields":{"Task":["content","sg_description","sg_status_list","due_date","task_assignees","task_reviewers"],"Shot":["code","description","sg_status_list","created_at","sg_cut_in","sg_cut_out","sg_cut_duration","sg_cut_order"],"Asset":["code","description","sg_status_list","created_at"],"Scene":["code","sg_status_list","created_at"],"Element":["code","sg_status_list","created_at"],"Release":["code","sg_status_list","created_at"],"ShootDay":["code","sg_status_list","created_at"],"MocapTake":["code","sg_status_list","created_at"],"MocapSetup":["code","sg_status_list","created_at"],"Camera":["code","sg_status_list","created_at"],"MocapTakeRange":["code","sg_status_list","created_at"],"Sequence":["code","sg_status_list","created_at"],"Level":["code","sg_status_list","created_at"],"Episode":["code","sg_status_list","created_at"]},"entity_fields_fixed":{"Asset":["code","description","sg_status_list"],"Shot":["code","description","sg_status_list"],"Task":["content","sg_status_list","due_date","task_assignees","task_reviewers"],"Scene":["code","description","sg_status_list"],"Element":["code","description","sg_status_list"],"Release":["code","description","sg_status_list"],"ShootDay":["code","description","sg_status_list"],"MocapTake":["code","description","sg_status_list"],"MocapSetup":["code","description","sg_status_list"],"Camera":["code","description","sg_status_list"],"MocapTakeRange":["code","description","sg_status_list"],"Sequence":["code","description","sg_status_list"],"Level":["code","description","sg_status_list"],"Episode":["code","description","sg_status_list"]}}' # noqa
+            'view_master_settings': '{"status_groups":[{"name":"Upcoming","code":"upc_stgr","status_list":["wtg","rdy"]},{"name":"Active","code":"act_stgr","status_list":["ip","kickbk","rev","act","rsk","blk","late","opn","pndng","tkt","push","rrq","vwd","out"]},{"name":"Done","code":"done_stgr","status_list":["fin","cmpt","apr","cbb","clsd","cfrm","dlvr","recd","res"]}],"entity_fields":{"Task":["content","sg_description","sg_status_list","due_date","task_assignees","task_reviewers","time_logs_sum"],"Shot":["code","description","sg_status_list","created_at","sg_cut_in","sg_cut_out","sg_cut_duration","sg_cut_order"],"Asset":["code","description","sg_status_list","created_at"],"Scene":["code","sg_status_list","created_at"],"Element":["code","sg_status_list","created_at"],"Release":["code","sg_status_list","created_at"],"ShootDay":["code","sg_status_list","created_at"],"MocapTake":["code","sg_status_list","created_at"],"MocapSetup":["code","sg_status_list","created_at"],"Camera":["code","sg_status_list","created_at"],"MocapTakeRange":["code","sg_status_list","created_at"],"Sequence":["code","sg_status_list","created_at"],"Level":["code","sg_status_list","created_at"],"Episode":["code","sg_status_list","created_at"],"Version":["code","description","sg_status_list"]},"entity_fields_fixed":{"Asset":["code","description","sg_status_list"],"Shot":["code","description","sg_status_list"],"Task":["content","sg_status_list","due_date","task_assignees","task_reviewers","time_logs_sum"],"Scene":["code","description","sg_status_list"],"Element":["code","description","sg_status_list"],"Release":["code","description","sg_status_list"],"ShootDay":["code","description","sg_status_list"],"MocapTake":["code","description","sg_status_list"],"MocapSetup":["code","description","sg_status_list"],"Camera":["code","description","sg_status_list"],"MocapTakeRange":["code","description","sg_status_list"],"Sequence":["code","description","sg_status_list"],"Level":["code","description","sg_status_list"],"Episode":["code","description","sg_status_list"],"Version":["code","description","sg_status_list"]},"board_sorting":{"Upcoming":{"Task":[{"direction":"desc","field_name":"due_date"},{"direction":"asc","field_name":"content"}]},"Done":{"Task":[{"direction":"desc","field_name":"due_date"},{"direction":"asc","field_name":"content"}]},"Active":{"Task":[{"direction":"desc","field_name":"due_date"},{"direction":"asc","field_name":"content"}]}},"status_default":{"Version":{"pending_review_status":["rev"],"viewed_review_status":["vwd"]},"Task":{"final_review_status":["fin"]}},"entity_forms":{"TimeLog":["date","description","duration"]},"entity_forms_fixed":{"TimeLog":["date","description","duration"]},"enable_timelog_at_version_creation":false}' # noqa
         }
         self.assertEqual(expected, resp)
 

tests/test_client.py

@@ -5,6 +5,7 @@
 import base64
 import datetime
 import urllib
+import os
 import re
 try:
     import simplejson as json
@@ -225,15 +226,61 @@ def test_connect_close(self):
         self.sg.close()
         self.assertEqual(None, self.sg._connection)
 
-
     def test_network_retry(self):
-        """Network failure is retried"""
+        """Network failure is retried, with a sleep call between retries."""
         self.sg._http_request.side_effect = httplib2.HttpLib2Error
 
-        self.assertRaises(httplib2.HttpLib2Error, self.sg.info)
-        self.assertTrue(
-            self.sg.config.max_rpc_attempts ==self.sg._http_request.call_count,
-            "Call is repeated")
+        with mock.patch("time.sleep") as mock_sleep:
+            self.assertRaises(httplib2.HttpLib2Error, self.sg.info)
+            self.assertTrue(
+                self.sg.config.max_rpc_attempts == self.sg._http_request.call_count,
+                "Call is repeated")
+            # Ensure that sleep was called with the retry interval between each attempt
+            attempt_interval = self.sg.config.rpc_attempt_interval / 1000.0
+            calls = [mock.callargs(((attempt_interval,), {}))]
+            calls *= (self.sg.config.max_rpc_attempts - 1)
+            self.assertTrue(
+                mock_sleep.call_args_list == calls,
+                "Call is repeated at correct interval."
+            )
+
+    def test_set_retry_interval(self):
+        """Setting the retry interval through parameter and environment variable works."""
+        original_env_val = os.environ.pop("SHOTGUN_API_RETRY_INTERVAL", None)
+
+        try:
+            def run_interval_test(expected_interval, interval_property=None):
+                self.sg = api.Shotgun(self.config.server_url,
+                                      self.config.script_name,
+                                      self.config.api_key,
+                                      http_proxy=self.config.http_proxy,
+                                      connect=self.connect)
+                self._setup_mock()
+                if interval_property:
+                    # if a value was provided for interval_property, set the
+                    # config's property to that value.
+                    self.sg.config.rpc_attempt_interval = interval_property
+                self.sg._http_request.side_effect = httplib2.HttpLib2Error
+                self.assertEqual(self.sg.config.rpc_attempt_interval, expected_interval)
+                self.test_network_retry()
+
+            # Try passing parameter and ensure the correct interval is used.
+            run_interval_test(expected_interval=2500, interval_property=2500)
+
+            # Try setting ENV VAR and ensure the correct interval is used.
+            os.environ["SHOTGUN_API_RETRY_INTERVAL"] = "2000"
+            run_interval_test(expected_interval=2000)
+
+            # Try both parameter and environment variable, to ensure parameter wins.
+            run_interval_test(expected_interval=4000, interval_property=4000)
+
+        finally:
+            # Restore environment variable.
+            if original_env_val is not None:
+                os.environ["SHOTGUN_API_RETRY_INTERVAL"] = original_env_val
+            elif "SHOTGUN_API_RETRY_INTERVAL" in os.environ:
+                os.environ.pop("SHOTGUN_API_RETRY_INTERVAL")
+
 
     def test_http_error(self):
         """HTTP error raised and not retried."""