From f5115acac829fc70cde0971d97d1c34b5142463f Mon Sep 17 00:00:00 2001 From: lei Date: Wed, 30 Aug 2017 19:37:30 -0700 Subject: [PATCH 1/6] Add retry for wait_for_ready --- SoftLayer/managers/vs.py | 84 +++++++++++++++++++++++++++------------- 1 file changed, 57 insertions(+), 27 deletions(-) diff --git a/SoftLayer/managers/vs.py b/SoftLayer/managers/vs.py index 772b0c6c1..b0320d340 100644 --- a/SoftLayer/managers/vs.py +++ b/SoftLayer/managers/vs.py @@ -10,10 +10,14 @@ import socket import time import warnings +import logging +import random from SoftLayer import exceptions from SoftLayer.managers import ordering from SoftLayer import utils + +LOGGER = logging.getLogger(__name__) # pylint: disable=no-self-use @@ -46,6 +50,7 @@ def __init__(self, client, ordering_manager=None): self.client = client self.account = client['Account'] self.guest = client['Virtual_Guest'] + self.retry_attempts = 0 self.resolvers = [self._get_ids_from_ip, self._get_ids_from_hostname] if ordering_manager is None: self.ordering_manager = ordering.OrderingManager(client) @@ -431,40 +436,56 @@ def wait_for_ready(self, instance_id, limit, delay=1, pending=False): ready = mgr.wait_for_ready(12345, 10) """ until = time.time() + limit + attempt = 1 for new_instance in itertools.repeat(instance_id): 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 + + except Exception as e : + + if attempt < self.retry_attempts : + LOGGER.info('Exception: %s', str(e)) + LOGGER.info('Auto re-try: %s out of %s', str(attempt), str(self.retry_attempts)) + time_to_sleep = self.delay_backoff(attempt) + attempt = attempt + 1 + time.sleep(time_to_sleep) + pass + + else : + raise + now = time.time() if now >= until: return False - + time.sleep(min(delay, until - now)) def verify_create_instance(self, **kwargs): @@ -963,3 +984,12 @@ def _get_price_id_for_upgrade(self, package_items, option, value, return price['id'] else: return price['id'] + + def delay_backoff(self, attempts): + ''' + Calculate time to sleep based on attempts had been made + ''' + time_to_sleep = random.random() * ( 2 ** attempts) + return time_to_sleep + + From ce1d4db3ad0708bbd65802f40fd9d7d37ae961a2 Mon Sep 17 00:00:00 2001 From: Christopher Gallo Date: Thu, 31 Aug 2017 16:22:02 -0500 Subject: [PATCH 2/6] cleaned up scale-back code and added unit tests --- SoftLayer/managers/vs.py | 34 +++++++++------------------------- tests/managers/vs_tests.py | 30 ++++++++++++++++++++++++------ 2 files changed, 33 insertions(+), 31 deletions(-) diff --git a/SoftLayer/managers/vs.py b/SoftLayer/managers/vs.py index b0320d340..33b537901 100644 --- a/SoftLayer/managers/vs.py +++ b/SoftLayer/managers/vs.py @@ -50,7 +50,6 @@ def __init__(self, client, ordering_manager=None): self.client = client self.account = client['Account'] self.guest = client['Virtual_Guest'] - self.retry_attempts = 0 self.resolvers = [self._get_ids_from_ip, self._get_ids_from_hostname] if ordering_manager is None: self.ordering_manager = ordering.OrderingManager(client) @@ -397,7 +396,7 @@ 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). @@ -413,7 +412,7 @@ def wait_for_transaction(self, instance_id, limit, delay=1): 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. @@ -436,20 +435,15 @@ def wait_for_ready(self, instance_id, limit, delay=1, pending=False): ready = mgr.wait_for_ready(12345, 10) """ until = time.time() + limit - attempt = 1 for new_instance in itertools.repeat(instance_id): mask = """id, lastOperatingSystemReload.id, activeTransaction.id,provisionDate""" - try : + try: instance = self.get_instance(new_instance, mask=mask) - last_reload = utils.lookup(instance, - 'lastOperatingSystemReload', - 'id') - active_transaction = utils.lookup(instance, - 'activeTransaction', - 'id') + last_reload = utils.lookup(instance, 'lastOperatingSystemReload', 'id') + active_transaction = utils.lookup(instance, 'activeTransaction', 'id') reloading = all(( active_transaction, @@ -468,24 +462,14 @@ def wait_for_ready(self, instance_id, limit, delay=1, pending=False): not reloading, not outstanding]): return True - - except Exception as e : - - if attempt < self.retry_attempts : - LOGGER.info('Exception: %s', str(e)) - LOGGER.info('Auto re-try: %s out of %s', str(attempt), str(self.retry_attempts)) - time_to_sleep = self.delay_backoff(attempt) - attempt = attempt + 1 - time.sleep(time_to_sleep) - pass - - else : - raise + except Exception as e: + delay = delay * 2 + LOGGER.info('Exception: %s', str(e)) + LOGGER.info('Auto retry in %s seconds', str(delay)) now = time.time() if now >= until: return False - time.sleep(min(delay, until - now)) def verify_create_instance(self, **kwargs): diff --git a/tests/managers/vs_tests.py b/tests/managers/vs_tests.py index 8773f6ae8..fb47295df 100644 --- a/tests/managers/vs_tests.py +++ b/tests/managers/vs_tests.py @@ -3,13 +3,14 @@ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ :license: MIT, see LICENSE for more details. + """ import mock import SoftLayer from SoftLayer import fixtures from SoftLayer import testing - +from SoftLayer import exceptions class VSTests(testing.TestCase): @@ -748,7 +749,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 +821,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 +831,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 +845,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 +863,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 +882,20 @@ 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('time.time') + @mock.patch('time.sleep') + def test_exception_from_api(self, _sleep, _time, 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] + 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) + ]) \ No newline at end of file From fa44de75ec0221656ef9c9e7b248082199143464 Mon Sep 17 00:00:00 2001 From: Christopher Gallo Date: Thu, 31 Aug 2017 16:58:52 -0500 Subject: [PATCH 3/6] fixing up unit tests and code quality --- SoftLayer/managers/vs.py | 25 +++++++------------------ tests/managers/vs_tests.py | 9 +++++---- 2 files changed, 12 insertions(+), 22 deletions(-) diff --git a/SoftLayer/managers/vs.py b/SoftLayer/managers/vs.py index 33b537901..9c0127f0b 100644 --- a/SoftLayer/managers/vs.py +++ b/SoftLayer/managers/vs.py @@ -7,11 +7,10 @@ """ import datetime import itertools +import logging import socket import time import warnings -import logging -import random from SoftLayer import exceptions from SoftLayer.managers import ordering @@ -441,32 +440,31 @@ def wait_for_ready(self, instance_id, limit, delay=10, pending=False): activeTransaction.id,provisionDate""" 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 - except Exception as e: + except exceptions.SoftLayerAPIError as exception: delay = delay * 2 - LOGGER.info('Exception: %s', str(e)) + LOGGER.info('Exception: %s', str(exception)) LOGGER.info('Auto retry in %s seconds', str(delay)) - + now = time.time() if now >= until: return False @@ -968,12 +966,3 @@ def _get_price_id_for_upgrade(self, package_items, option, value, return price['id'] else: return price['id'] - - def delay_backoff(self, attempts): - ''' - Calculate time to sleep based on attempts had been made - ''' - time_to_sleep = random.random() * ( 2 ** attempts) - return time_to_sleep - - diff --git a/tests/managers/vs_tests.py b/tests/managers/vs_tests.py index fb47295df..4992c5a09 100644 --- a/tests/managers/vs_tests.py +++ b/tests/managers/vs_tests.py @@ -8,9 +8,10 @@ import mock import SoftLayer +from SoftLayer import exceptions from SoftLayer import fixtures from SoftLayer import testing -from SoftLayer import exceptions + class VSTests(testing.TestCase): @@ -883,7 +884,6 @@ def test_iter_20_incomplete(self, _sleep, _time): _sleep.assert_has_calls([mock.call(10)]) - @mock.patch('SoftLayer.managers.vs.VSManager.get_instance') @mock.patch('time.time') @mock.patch('time.sleep') @@ -891,11 +891,12 @@ def test_exception_from_api(self, _sleep, _time, 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] + _time.side_effect = [0, 0, 2, 6, 14, 20, 100] 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) - ]) \ No newline at end of file + ]) + self.assertFalse(value) From a58c26b989deea34be6972f5592cf371537c1f47 Mon Sep 17 00:00:00 2001 From: Christopher Gallo Date: Thu, 31 Aug 2017 17:01:57 -0500 Subject: [PATCH 4/6] fixed documentation --- SoftLayer/managers/vs.py | 9 +++------ 1 file changed, 3 insertions(+), 6 deletions(-) diff --git a/SoftLayer/managers/vs.py b/SoftLayer/managers/vs.py index 9c0127f0b..492306c3f 100644 --- a/SoftLayer/managers/vs.py +++ b/SoftLayer/managers/vs.py @@ -398,14 +398,12 @@ def _generate_create_dict( 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). + 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, @@ -423,8 +421,7 @@ def wait_for_ready(self, instance_id, limit, delay=10, 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. From 1b70b2b0a08b132613a26ce8146159a21288666f Mon Sep 17 00:00:00 2001 From: Christopher Gallo Date: Thu, 31 Aug 2017 17:13:36 -0500 Subject: [PATCH 5/6] removed trailing whitespace --- SoftLayer/managers/vs.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/SoftLayer/managers/vs.py b/SoftLayer/managers/vs.py index 492306c3f..e7e654e45 100644 --- a/SoftLayer/managers/vs.py +++ b/SoftLayer/managers/vs.py @@ -398,7 +398,7 @@ def _generate_create_dict( 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). + 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 From 0bac762cadb96b8795f10d128d838f4927f2978c Mon Sep 17 00:00:00 2001 From: Christopher Gallo Date: Fri, 1 Sep 2017 15:22:20 -0500 Subject: [PATCH 6/6] moved some logging messages around, added random delay --- SoftLayer/managers/vs.py | 9 +++++---- tests/managers/vs_tests.py | 4 +++- 2 files changed, 8 insertions(+), 5 deletions(-) diff --git a/SoftLayer/managers/vs.py b/SoftLayer/managers/vs.py index e7e654e45..8399eb6a5 100644 --- a/SoftLayer/managers/vs.py +++ b/SoftLayer/managers/vs.py @@ -8,6 +8,7 @@ import datetime import itertools import logging +import random import socket import time import warnings @@ -406,8 +407,7 @@ def wait_for_transaction(self, instance_id, limit, delay=10): :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=10, pending=False): """Determine if a VS is ready and available. @@ -457,14 +457,15 @@ def wait_for_ready(self, instance_id, limit, delay=10, pending=False): not reloading, not outstanding]): return True + LOGGER.info("%s not ready.", str(instance_id)) except exceptions.SoftLayerAPIError as exception: - delay = delay * 2 + delay = (delay * 2) + random.randint(0, 9) LOGGER.info('Exception: %s', str(exception)) - LOGGER.info('Auto retry in %s seconds', str(delay)) 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): diff --git a/tests/managers/vs_tests.py b/tests/managers/vs_tests.py index 4992c5a09..5c8f1f473 100644 --- a/tests/managers/vs_tests.py +++ b/tests/managers/vs_tests.py @@ -885,13 +885,15 @@ def test_iter_20_incomplete(self, _sleep, _time): _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, vs): + 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),