diff --git a/SoftLayer/CLI/__init__.py b/SoftLayer/CLI/__init__.py index 31d8f4b88..3d5d6bf79 100644 --- a/SoftLayer/CLI/__init__.py +++ b/SoftLayer/CLI/__init__.py @@ -6,10 +6,5 @@ :license: MIT, see LICENSE for more details. """ # pylint: disable=w0401, invalid-name -import logging from SoftLayer.CLI.helpers import * # NOQA - -logger = logging.getLogger() -logger.addHandler(logging.StreamHandler()) -logger.setLevel(logging.INFO) diff --git a/SoftLayer/CLI/core.py b/SoftLayer/CLI/core.py index 860cdff17..82ad1f7ed 100644 --- a/SoftLayer/CLI/core.py +++ b/SoftLayer/CLI/core.py @@ -88,8 +88,7 @@ def get_command(self, ctx, name): help="Config file location", type=click.Path(resolve_path=True)) @click.option('--verbose', '-v', - help="Sets the debug noise level, specify multiple times " - "for more verbosity.", + help="Sets the debug noise level, specify multiple times for more verbosity.", type=click.IntRange(0, 3, clamp=True), count=True) @click.option('--proxy', @@ -115,10 +114,9 @@ def cli(env, **kwargs): """Main click CLI entry-point.""" - if verbose > 0: - logger = logging.getLogger() - logger.addHandler(logging.StreamHandler()) - logger.setLevel(DEBUG_LOGGING_MAP.get(verbose, logging.DEBUG)) + logger = logging.getLogger() + logger.addHandler(logging.StreamHandler()) + logger.setLevel(DEBUG_LOGGING_MAP.get(verbose, logging.DEBUG)) # Populate environement with client and set it as the context object env.skip_confirmations = really @@ -127,7 +125,7 @@ def cli(env, env.ensure_client(config_file=config, is_demo=demo, proxy=proxy) env.vars['_start'] = time.time() - env.vars['_timings'] = SoftLayer.TimingTransport(env.client.transport) + env.vars['_timings'] = SoftLayer.DebugTransport(env.client.transport) env.client.transport = env.vars['_timings'] @@ -138,22 +136,37 @@ def output_diagnostics(env, verbose=0, **kwargs): if verbose > 0: diagnostic_table = formatting.Table(['name', 'value']) - diagnostic_table.add_row(['execution_time', - '%fs' % (time.time() - START_TIME)]) + diagnostic_table.add_row(['execution_time', '%fs' % (time.time() - START_TIME)]) api_call_value = [] - for call, _, duration in env.vars['_timings'].get_last_calls(): - api_call_value.append( - "%s::%s (%fs)" % (call.service, call.method, duration)) + for call in env.client.transport.get_last_calls(): + api_call_value.append("%s::%s (%fs)" % (call.service, call.method, call.end_time - call.start_time)) diagnostic_table.add_row(['api_calls', api_call_value]) diagnostic_table.add_row(['version', consts.USER_AGENT]) diagnostic_table.add_row(['python_version', sys.version]) - diagnostic_table.add_row(['library_location', - os.path.dirname(SoftLayer.__file__)]) + diagnostic_table.add_row(['library_location', os.path.dirname(SoftLayer.__file__)]) env.err(env.fmt(diagnostic_table)) + if verbose > 1: + for call in env.client.transport.get_last_calls(): + call_table = formatting.Table(['', '{}::{}'.format(call.service, call.method)]) + nice_mask = '' + if call.mask is not None: + nice_mask = call.mask + + call_table.add_row(['id', call.identifier]) + call_table.add_row(['mask', nice_mask]) + call_table.add_row(['filter', call.filter]) + call_table.add_row(['limit', call.limit]) + call_table.add_row(['offset', call.offset]) + env.err(env.fmt(call_table)) + + if verbose > 2: + for call in env.client.transport.get_last_calls(): + env.err(env.client.transport.print_reproduceable(call)) + def main(reraise_exceptions=False, **kwargs): """Main program. Catches several common errors and displays them nicely.""" @@ -163,8 +176,7 @@ def main(reraise_exceptions=False, **kwargs): cli.main(**kwargs) except SoftLayer.SoftLayerAPIError as ex: if 'invalid api token' in ex.faultString.lower(): - print("Authentication Failed: To update your credentials," - " use 'slcli config setup'") + print("Authentication Failed: To update your credentials, use 'slcli config setup'") exit_status = 1 else: print(str(ex)) @@ -184,6 +196,7 @@ def main(reraise_exceptions=False, **kwargs): print(str(traceback.format_exc())) print("Feel free to report this error as it is likely a bug:") print(" https://github.com/softlayer/softlayer-python/issues") + print("The following snippet should be able to reproduce the error") exit_status = 1 sys.exit(exit_status) diff --git a/SoftLayer/managers/hardware.py b/SoftLayer/managers/hardware.py index cbeb60fb8..0b8d7a693 100644 --- a/SoftLayer/managers/hardware.py +++ b/SoftLayer/managers/hardware.py @@ -78,9 +78,12 @@ def cancel_hardware(self, hardware_id, reason='unneeded', comment='', immediate= reasons = self.get_cancellation_reasons() cancel_reason = reasons.get(reason, reasons['unneeded']) ticket_mgr = SoftLayer.TicketManager(self.client) - mask = 'mask[id, hourlyBillingFlag, billingItem[id], openCancellationTicket[id]]' + mask = 'mask[id, hourlyBillingFlag, billingItem[id], openCancellationTicket[id], activeTransaction]' hw_billing = self.get_hardware(hardware_id, mask=mask) + if 'activeTransaction' in hw_billing: + raise SoftLayer.SoftLayerError("Unable to cancel hardware with running transaction") + if 'billingItem' not in hw_billing: raise SoftLayer.SoftLayerError("Ticket #%s already exists for this server" % hw_billing['openCancellationTicket']['id']) diff --git a/SoftLayer/transports.py b/SoftLayer/transports.py index fef83496e..15abe362a 100644 --- a/SoftLayer/transports.py +++ b/SoftLayer/transports.py @@ -8,6 +8,7 @@ import importlib import json import logging +import re import time import requests @@ -20,13 +21,14 @@ LOGGER = logging.getLogger(__name__) # transports.Request does have a lot of instance attributes. :( -# pylint: disable=too-many-instance-attributes +# pylint: disable=too-many-instance-attributes, no-self-use __all__ = [ 'Request', 'XmlRpcTransport', 'RestTransport', 'TimingTransport', + 'DebugTransport', 'FixtureTransport', 'SoftLayerListResult', ] @@ -100,6 +102,24 @@ def __init__(self): #: Integer result offset. self.offset = None + #: Integer call start time + self.start_time = None + + #: Integer call end time + self.end_time = None + + #: String full url + self.url = None + + #: String result of api call + self.result = None + + #: String payload to send in + self.payload = None + + #: Exception any exceptions that got caught + self.exception = None + class SoftLayerListResult(list): """A SoftLayer API list result.""" @@ -117,8 +137,7 @@ class XmlRpcTransport(object): """XML-RPC transport.""" def __init__(self, endpoint_url=None, timeout=None, proxy=None, user_agent=None, verify=True): - self.endpoint_url = (endpoint_url or - consts.API_PUBLIC_ENDPOINT).rstrip('/') + self.endpoint_url = (endpoint_url or consts.API_PUBLIC_ENDPOINT).rstrip('/') self.timeout = timeout or None self.proxy = proxy self.user_agent = user_agent or consts.USER_AGENT @@ -139,7 +158,6 @@ def __call__(self, request): :param request request: Request object """ largs = list(request.args) - headers = request.headers if request.identifier is not None: @@ -147,8 +165,12 @@ def __call__(self, request): headers[header_name] = {'id': request.identifier} if request.mask is not None: - headers.update(_format_object_mask_xmlrpc(request.mask, - request.service)) + if isinstance(request.mask, dict): + mheader = '%sObjectMask' % request.service + else: + mheader = 'SoftLayer_ObjectMask' + request.mask = _format_object_mask(request.mask) + headers.update({mheader: {'mask': request.mask}}) if request.filter is not None: headers['%sObjectFilter' % request.service] = request.filter @@ -163,32 +185,25 @@ def __call__(self, request): request.transport_headers.setdefault('Content-Type', 'application/xml') request.transport_headers.setdefault('User-Agent', self.user_agent) - url = '/'.join([self.endpoint_url, request.service]) - payload = utils.xmlrpc_client.dumps(tuple(largs), - methodname=request.method, - allow_none=True) + request.url = '/'.join([self.endpoint_url, request.service]) + request.payload = utils.xmlrpc_client.dumps(tuple(largs), + methodname=request.method, + allow_none=True) # Prefer the request setting, if it's not None verify = request.verify if verify is None: - verify = self.verify - - LOGGER.debug("=== REQUEST ===") - LOGGER.debug('POST %s', url) - LOGGER.debug(request.transport_headers) - LOGGER.debug(payload) + request.verify = self.verify try: - resp = self.client.request('POST', url, - data=payload, + resp = self.client.request('POST', request.url, + data=request.payload, headers=request.transport_headers, timeout=self.timeout, - verify=verify, + verify=request.verify, cert=request.cert, proxies=_proxies_dict(self.proxy)) - LOGGER.debug("=== RESPONSE ===") - LOGGER.debug(resp.headers) - LOGGER.debug(resp.content) + resp.raise_for_status() result = utils.xmlrpc_client.loads(resp.content)[0][0] if isinstance(result, list): @@ -218,6 +233,44 @@ def __call__(self, request): except requests.RequestException as ex: raise exceptions.TransportError(0, str(ex)) + def print_reproduceable(self, request): + """Prints out the minimal python code to reproduce a specific request + + The will also automatically replace the API key so its not accidently exposed. + + :param request request: Request object + """ + from string import Template + output = Template('''============= testing.py ============= +import requests +from requests.adapters import HTTPAdapter +from urllib3.util.retry import Retry +from xml.etree import ElementTree +client = requests.Session() +client.headers.update({'Content-Type': 'application/json', 'User-Agent': 'softlayer-python/testing',}) +retry = Retry(connect=3, backoff_factor=3) +adapter = HTTPAdapter(max_retries=retry) +client.mount('https://', adapter) +url = '$url' +payload = """$payload""" +transport_headers = $transport_headers +timeout = $timeout +verify = $verify +cert = $cert +proxy = $proxy +response = client.request('POST', url, data=payload, headers=transport_headers, timeout=timeout, + verify=verify, cert=cert, proxies=proxy) +xml = ElementTree.fromstring(response.content) +ElementTree.dump(xml) +==========================''') + + safe_payload = re.sub(r'[a-z0-9]{64}', r'API_KEY_GOES_HERE', request.payload) + safe_payload = re.sub(r'(\s+)', r' ', safe_payload) + substitutions = dict(url=request.url, payload=safe_payload, transport_headers=request.transport_headers, + timeout=self.timeout, verify=request.verify, cert=request.cert, + proxy=_proxies_dict(self.proxy)) + return output.substitute(substitutions) + class RestTransport(object): """REST transport. @@ -253,17 +306,19 @@ def __call__(self, request): """ params = request.headers.copy() if request.mask: - params['objectMask'] = _format_object_mask(request.mask) + request.mask = _format_object_mask(request.mask) + params['objectMask'] = request.mask - if request.limit: - params['limit'] = request.limit - - if request.offset: - params['offset'] = request.offset + if request.limit or request.offset: + limit = request.limit or 0 + offset = request.offset or 0 + params['resultLimit'] = "%d,%d" % (offset, limit) if request.filter: params['objectFilter'] = json.dumps(request.filter) + request.params = params + auth = None if request.transport_user: auth = requests.auth.HTTPBasicAuth( @@ -283,9 +338,8 @@ def __call__(self, request): method = 'POST' body['parameters'] = request.args - raw_body = None if body: - raw_body = json.dumps(body) + request.payload = json.dumps(body) url_parts = [self.endpoint_url, request.service] if request.identifier is not None: @@ -294,32 +348,29 @@ def __call__(self, request): if request.method is not None: url_parts.append(request.method) - url = '%s.%s' % ('/'.join(url_parts), 'json') + request.url = '%s.%s' % ('/'.join(url_parts), 'json') # Prefer the request setting, if it's not None - verify = request.verify - if verify is None: - verify = self.verify - LOGGER.debug("=== REQUEST ===") - LOGGER.debug(url) - LOGGER.debug(request.transport_headers) - LOGGER.debug(raw_body) + if request.verify is None: + request.verify = self.verify + try: - resp = self.client.request(method, url, + resp = self.client.request(method, request.url, auth=auth, headers=request.transport_headers, - params=params, - data=raw_body, + params=request.params, + data=request.payload, timeout=self.timeout, - verify=verify, + verify=request.verify, cert=request.cert, proxies=_proxies_dict(self.proxy)) - LOGGER.debug("=== RESPONSE ===") - LOGGER.debug(resp.headers) - LOGGER.debug(resp.text) + + request.url = resp.url + resp.raise_for_status() result = json.loads(resp.text) + request.result = result if isinstance(result, list): return SoftLayerListResult( @@ -328,11 +379,82 @@ def __call__(self, request): return result except requests.HTTPError as ex: message = json.loads(ex.response.text)['error'] - raise exceptions.SoftLayerAPIError(ex.response.status_code, - message) + request.url = ex.response.url + raise exceptions.SoftLayerAPIError(ex.response.status_code, message) except requests.RequestException as ex: raise exceptions.TransportError(0, str(ex)) + def print_reproduceable(self, request): + """Prints out the minimal python code to reproduce a specific request + + The will also automatically replace the API key so its not accidently exposed. + + :param request request: Request object + """ + command = "curl -u $SL_USER:$SL_APIKEY -X {method} -H {headers} {data} '{uri}'" + + method = REST_SPECIAL_METHODS.get(request.method) + + if method is None: + method = 'GET' + if request.args: + method = 'POST' + + data = '' + if request.payload is not None: + data = "-d '{}'".format(request.payload) + + headers = ['"{0}: {1}"'.format(k, v) for k, v in request.transport_headers.items()] + headers = " -H ".join(headers) + return command.format(method=method, headers=headers, data=data, uri=request.url) + + +class DebugTransport(object): + """Transport that records API call timings.""" + + def __init__(self, transport): + self.transport = transport + + #: List All API calls made during a session + self.requests = [] + + def __call__(self, call): + call.start_time = time.time() + + self.pre_transport_log(call) + try: + call.result = self.transport(call) + except (exceptions.SoftLayerAPIError, exceptions.TransportError) as ex: + call.exception = ex + + self.post_transport_log(call) + + call.end_time = time.time() + self.requests.append(call) + + if call.exception is not None: + raise call.exception + + return call.result + + def pre_transport_log(self, call): + """Prints a warning before calling the API """ + output = "Calling: {}::{}(id={})".format(call.service, call.method, call.identifier) + LOGGER.warning(output) + + def post_transport_log(self, call): + """Prints the result "Returned Data: \n%s" % (call.result)of an API call""" + output = "Returned Data: \n{}".format(call.result) + LOGGER.debug(output) + + def get_last_calls(self): + """Returns all API calls for a session""" + return self.requests + + def print_reproduceable(self, call): + """Prints a reproduceable debugging output""" + return self.transport.print_reproduceable(call) + class TimingTransport(object): """Transport that records API call timings.""" @@ -361,6 +483,10 @@ def get_last_calls(self): self.last_calls = [] return last_calls + def print_reproduceable(self, call): + """Not Implemented""" + return call.service + class FixtureTransport(object): """Implements a transport which returns fixtures.""" @@ -376,6 +502,10 @@ def __call__(self, call): except AttributeError: raise NotImplementedError('%s::%s fixture is not implemented' % (call.service, call.method)) + def print_reproduceable(self, call): + """Not Implemented""" + return call.service + def _proxies_dict(proxy): """Makes a proxy dict appropriate to pass to requests.""" @@ -384,22 +514,6 @@ def _proxies_dict(proxy): return {'http': proxy, 'https': proxy} -def _format_object_mask_xmlrpc(objectmask, service): - """Format new and old style object masks into proper headers. - - :param objectmask: a string- or dict-based object mask - :param service: a SoftLayer API service name - - """ - if isinstance(objectmask, dict): - mheader = '%sObjectMask' % service - else: - mheader = 'SoftLayer_ObjectMask' - objectmask = _format_object_mask(objectmask) - - return {mheader: {'mask': objectmask}} - - def _format_object_mask(objectmask): """Format the new style object mask. @@ -410,6 +524,7 @@ def _format_object_mask(objectmask): """ objectmask = objectmask.strip() + if (not objectmask.startswith('mask') and not objectmask.startswith('[')): objectmask = "mask[%s]" % objectmask diff --git a/tests/managers/vs_tests.py b/tests/managers/vs_tests.py index b3b57eb30..7f4592ea1 100644 --- a/tests/managers/vs_tests.py +++ b/tests/managers/vs_tests.py @@ -809,19 +809,6 @@ def test_active_provision_pending(self, _now, _sleep): _sleep.assert_has_calls([mock.call(0)]) self.assertFalse(value) - def test_active_reload(self): - # actively running reload - self.guestObject.side_effect = [ - {'activeTransaction': {'id': 1}}, - { - 'activeTransaction': {'id': 1}, - 'provisionDate': 'aaa', - 'lastOperatingSystemReload': {'id': 1}, - }, - ] - value = self.vs.wait_for_ready(1, 0) - self.assertFalse(value) - def test_reload_no_pending(self): # reload complete, maintance transactions self.guestObject.return_value = { diff --git a/tests/transport_tests.py b/tests/transport_tests.py index d4145e823..87a43de62 100644 --- a/tests/transport_tests.py +++ b/tests/transport_tests.py @@ -256,6 +256,14 @@ def test_request_exception(self, request): self.assertRaises(SoftLayer.TransportError, self.transport, req) + def test_print_reproduceable(self): + req = transports.Request() + req.url = "https://test.com" + req.payload = "testing" + req.transport_headers = {"test-headers": 'aaaa'} + output_text = self.transport.print_reproduceable(req) + self.assertIn("https://test.com", output_text) + @mock.patch('SoftLayer.transports.requests.Session.request') @pytest.mark.parametrize( @@ -529,7 +537,7 @@ def test_with_limit_offset(self, request): headers=mock.ANY, auth=None, data=None, - params={'limit': 10, 'offset': 5}, + params={'resultLimit': '5,10'}, verify=True, cert=None, proxies=None, @@ -578,6 +586,14 @@ def test_with_special_auth(self, auth, request): proxies=None, timeout=None) + def test_print_reproduceable(self): + req = transports.Request() + req.url = "https://test.com" + req.payload = "testing" + req.transport_headers = {"test-headers": 'aaaa'} + output_text = self.transport.print_reproduceable(req) + self.assertIn("https://test.com", output_text) + class TestFixtureTransport(testing.TestCase): @@ -602,3 +618,99 @@ def test_no_method(self): req.service = 'SoftLayer_Account' req.method = 'getObjectzzzz' self.assertRaises(NotImplementedError, self.transport, req) + + +class TestTimingTransport(testing.TestCase): + + def set_up(self): + fixture_transport = transports.FixtureTransport() + self.transport = transports.TimingTransport(fixture_transport) + + def test_call(self): + req = transports.Request() + req.service = 'SoftLayer_Account' + req.method = 'getObject' + resp = self.transport(req) + self.assertEqual(resp['accountId'], 1234) + + def test_get_last_calls(self): + req = transports.Request() + req.service = 'SoftLayer_Account' + req.method = 'getObject' + resp = self.transport(req) + self.assertEqual(resp['accountId'], 1234) + calls = self.transport.get_last_calls() + self.assertEqual(calls[0][0].service, 'SoftLayer_Account') + + def test_print_reproduceable(self): + req = transports.Request() + req.service = 'SoftLayer_Account' + req.method = 'getObject' + output_text = self.transport.print_reproduceable(req) + self.assertEqual('SoftLayer_Account', output_text) + + +class TestDebugTransport(testing.TestCase): + + def set_up(self): + fixture_transport = transports.FixtureTransport() + self.transport = transports.DebugTransport(fixture_transport) + req = transports.Request() + req.service = 'SoftLayer_Account' + req.method = 'getObject' + self.req = req + + def test_call(self): + + resp = self.transport(self.req) + self.assertEqual(resp['accountId'], 1234) + + def test_get_last_calls(self): + + resp = self.transport(self.req) + self.assertEqual(resp['accountId'], 1234) + calls = self.transport.get_last_calls() + self.assertEqual(calls[0].service, 'SoftLayer_Account') + + def test_print_reproduceable(self): + req = transports.Request() + req.service = 'SoftLayer_Account' + req.method = 'getObject' + output_text = self.transport.print_reproduceable(self.req) + self.assertEqual('SoftLayer_Account', output_text) + + def test_print_reproduceable_post(self): + req = transports.Request() + req.url = "https://test.com" + req.payload = "testing" + req.transport_headers = {"test-headers": 'aaaa'} + req.args = 'createObject' + + rest_transport = transports.RestTransport() + transport = transports.DebugTransport(rest_transport) + + output_text = transport.print_reproduceable(req) + + self.assertIn("https://test.com", output_text) + self.assertIn("-X POST", output_text) + + @mock.patch('SoftLayer.transports.requests.Session.request') + def test_error(self, request): + # Test JSON Error + e = requests.HTTPError('error') + e.response = mock.MagicMock() + e.response.status_code = 404 + e.response.text = '''{ + "error": "description", + "code": "Error Code" + }''' + request().raise_for_status.side_effect = e + + req = transports.Request() + req.service = 'SoftLayer_Service' + req.method = 'Resource' + rest_transport = transports.RestTransport() + transport = transports.DebugTransport(rest_transport) + self.assertRaises(SoftLayer.SoftLayerAPIError, transport, req) + calls = transport.get_last_calls() + self.assertEqual(404, calls[0].exception.faultCode)