vs manager wait_for_ready exception handling

SoftLayer/managers/vs.py

@@ -7,13 +7,17 @@
 """
 import datetime
 import itertools
+import logging
+import random
 import socket
 import time
 import warnings
 
 from SoftLayer import exceptions
 from SoftLayer.managers import ordering
 from SoftLayer import utils
+
+LOGGER = logging.getLogger(__name__)
 # pylint: disable=no-self-use
 
 
@@ -392,23 +396,20 @@ def _generate_create_dict(
 
         return data
 
-    def wait_for_transaction(self, instance_id, limit, delay=1):
+    def wait_for_transaction(self, instance_id, limit, delay=10):
         """Waits on a VS transaction for the specified amount of time.
 
         This is really just a wrapper for wait_for_ready(pending=True).
         Provided for backwards compatibility.
 
-
         :param int instance_id: The instance ID with the pending transaction
         :param int limit: The maximum amount of time to wait.
-        :param int delay: The number of seconds to sleep before checks.
-                          Defaults to 1.
+        :param int delay: The number of seconds to sleep before checks. Defaults to 10.
         """
 
-        return self.wait_for_ready(instance_id, limit, delay=delay,
-                                   pending=True)
+        return self.wait_for_ready(instance_id, limit, delay=delay, pending=True)
 
-    def wait_for_ready(self, instance_id, limit, delay=1, pending=False):
+    def wait_for_ready(self, instance_id, limit, delay=10, pending=False):
         """Determine if a VS is ready and available.
 
         In some cases though, that can mean that no transactions are running.
@@ -420,8 +421,7 @@ def wait_for_ready(self, instance_id, limit, delay=1, pending=False):
 
         :param int instance_id: The instance ID with the pending transaction
         :param int limit: The maximum amount of time to wait.
-        :param int delay: The number of seconds to sleep before checks.
-                          Defaults to 1.
+        :param int delay: The number of seconds to sleep before checks. Defaults to 10.
         :param bool pending: Wait for pending transactions not related to
                              provisioning or reloads such as monitoring.
 
@@ -435,36 +435,37 @@ def wait_for_ready(self, instance_id, limit, delay=1, pending=False):
             mask = """id,
                       lastOperatingSystemReload.id,
                       activeTransaction.id,provisionDate"""
-            instance = self.get_instance(new_instance, mask=mask)
-            last_reload = utils.lookup(instance,
-                                       'lastOperatingSystemReload',
-                                       'id')
-            active_transaction = utils.lookup(instance,
-                                              'activeTransaction',
-                                              'id')
-
-            reloading = all((
-                active_transaction,
-                last_reload,
-                last_reload == active_transaction,
-            ))
-
-            # only check for outstanding transactions if requested
-            outstanding = False
-            if pending:
-                outstanding = active_transaction
-
-            # return True if the instance has finished provisioning
-            # and isn't currently reloading the OS.
-            if all([instance.get('provisionDate'),
-                    not reloading,
-                    not outstanding]):
-                return True
+            try:
+                instance = self.get_instance(new_instance, mask=mask)
+                last_reload = utils.lookup(instance, 'lastOperatingSystemReload', 'id')
+                active_transaction = utils.lookup(instance, 'activeTransaction', 'id')
+
+                reloading = all((
+                    active_transaction,
+                    last_reload,
+                    last_reload == active_transaction,
+                ))
+
+                # only check for outstanding transactions if requested
+                outstanding = False
+                if pending:
+                    outstanding = active_transaction
+
+                # return True if the instance has finished provisioning
+                # and isn't currently reloading the OS.
+                if all([instance.get('provisionDate'),
+                        not reloading,
+                        not outstanding]):
+                    return True
+                LOGGER.info("%s not ready.", str(instance_id))
+            except exceptions.SoftLayerAPIError as exception:
+                delay = (delay * 2) + random.randint(0, 9)
+                LOGGER.info('Exception: %s', str(exception))
 
             now = time.time()
             if now >= until:
                 return False
-
+            LOGGER.info('Auto retry in %s seconds', str(min(delay, until - now)))
             time.sleep(min(delay, until - now))
 
     def verify_create_instance(self, **kwargs):

tests/managers/vs_tests.py

@@ -3,10 +3,12 @@
     ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
 
     :license: MIT, see LICENSE for more details.
+
 """
 import mock
 
 import SoftLayer
+from SoftLayer import exceptions
 from SoftLayer import fixtures
 from SoftLayer import testing
 
@@ -748,7 +750,7 @@ def set_up(self):
     def test_wait_interface(self, ready):
         # verify interface to wait_for_ready is intact
         self.vs.wait_for_transaction(1, 1)
-        ready.assert_called_once_with(1, 1, delay=1, pending=True)
+        ready.assert_called_once_with(1, 1, delay=10, pending=True)
 
     def test_active_not_provisioned(self):
         # active transaction and no provision date should be false
@@ -820,7 +822,7 @@ def test_ready_iter_once_incomplete(self, _sleep):
         self.guestObject.side_effect = [
             {'activeTransaction': {'id': 1}},
         ]
-        value = self.vs.wait_for_ready(1, 0)
+        value = self.vs.wait_for_ready(1, 0, delay=1)
         self.assertFalse(value)
         self.assertFalse(_sleep.called)
 
@@ -830,7 +832,7 @@ def test_iter_once_complete(self, _sleep):
         self.guestObject.side_effect = [
             {'provisionDate': 'aaa'},
         ]
-        value = self.vs.wait_for_ready(1, 1)
+        value = self.vs.wait_for_ready(1, 1, delay=1)
         self.assertTrue(value)
         self.assertFalse(_sleep.called)
 
@@ -844,7 +846,7 @@ def test_iter_four_complete(self, _sleep):
             {'provisionDate': 'aaa'},
         ]
 
-        value = self.vs.wait_for_ready(1, 4)
+        value = self.vs.wait_for_ready(1, 4, delay=1)
         self.assertTrue(value)
         _sleep.assert_has_calls([mock.call(1), mock.call(1), mock.call(1)])
         self.guestObject.assert_has_calls([
@@ -862,7 +864,7 @@ def test_iter_two_incomplete(self, _sleep, _time):
             {'provisionDate': 'aaa'}
         ]
         _time.side_effect = [0, 1, 2]
-        value = self.vs.wait_for_ready(1, 2)
+        value = self.vs.wait_for_ready(1, 2, delay=1)
         self.assertFalse(value)
         _sleep.assert_called_once_with(1)
         self.guestObject.assert_has_calls([
@@ -881,3 +883,22 @@ def test_iter_20_incomplete(self, _sleep, _time):
         self.guestObject.assert_has_calls([mock.call(id=1, mask=mock.ANY)])
 
         _sleep.assert_has_calls([mock.call(10)])
+
+    @mock.patch('SoftLayer.managers.vs.VSManager.get_instance')
+    @mock.patch('random.randint')
+    @mock.patch('time.time')
+    @mock.patch('time.sleep')
+    def test_exception_from_api(self, _sleep, _time, _random, vs):
+        """Tests escalating scale back when an excaption is thrown"""
+        self.guestObject.return_value = {'activeTransaction': {'id': 1}}
+        vs.side_effect = exceptions.TransportError(104, "Its broken")
+        _time.side_effect = [0, 0, 2, 6, 14, 20, 100]
+        _random.side_effect = [0, 0, 0, 0, 0]
+        value = self.vs.wait_for_ready(1, 20, delay=1)
+        _sleep.assert_has_calls([
+            mock.call(2),
+            mock.call(4),
+            mock.call(8),
+            mock.call(6)
+        ])
+        self.assertFalse(value)