From a31762048003301aaa9b02168d84d9d8bf4676ec Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Fri, 18 May 2018 10:14:59 +0200 Subject: [PATCH 01/15] Add background Soap server to test suite. --- setup.py | 2 +- tests/__init__.py | 23 +++++++++++++++++++++-- tests/apps/soapserver4132.py | 34 ++++++++++++++++++++++++++++++++++ 3 files changed, 56 insertions(+), 3 deletions(-) create mode 100644 tests/apps/soapserver4132.py diff --git a/setup.py b/setup.py index 6a93400b..cb7eda9f 100644 --- a/setup.py +++ b/setup.py @@ -11,7 +11,7 @@ packages=find_packages(exclude=['tests', 'examples']), long_description="The instana package provides Python metrics and traces for Instana.", zip_safe=False, - setup_requires=['nose>=1.0', 'flask>=0.12.2'], + setup_requires=['nose>=1.0', 'flask>=0.12.2', 'spyne>=2.9', 'lxml>=3.4'], install_requires=['autowrapt>=1.0', 'fysom>=2.1.2', 'opentracing>=1.2.1,<1.3', diff --git a/tests/__init__.py b/tests/__init__.py index ebd8b01a..5482ccbb 100644 --- a/tests/__init__.py +++ b/tests/__init__.py @@ -3,14 +3,33 @@ import time import threading from .apps.flaskalino import app as flaskalino +from .apps.soapserver4132 import soapserver + os.environ["INSTANA_TEST"] = "true" + +# Background Flask application +# # Spawn our background Flask app that the tests will throw # requests at. Don't continue until the test app is fully # up and running. timer = threading.Thread(target=flaskalino.run) timer.daemon = True -timer.name = "Test Flask app" -print("Starting background test app") +timer.name = "Background Flask app" +print("Starting background Flask app") timer.start() + + +# Background Soap Server +# +# Spawn our background Flask app that the tests will throw +# requests at. Don't continue until the test app is fully +# up and running. +timer = threading.Thread(target=soapserver.serve_forever) +timer.daemon = True +timer.name = "Background Soap server" +print("Starting background Soap server") +timer.start() + + time.sleep(1) diff --git a/tests/apps/soapserver4132.py b/tests/apps/soapserver4132.py new file mode 100644 index 00000000..524bf79e --- /dev/null +++ b/tests/apps/soapserver4132.py @@ -0,0 +1,34 @@ +# vim: set fileencoding=UTF-8 : +from spyne import Application, rpc, ServiceBase, Iterable, Integer, Unicode +from spyne.protocol.soap import Soap11 +from spyne.server.wsgi import WsgiApplication +from wsgiref.simple_server import make_server +from instana.wsgi import iWSGIMiddleware + +# Simple in test suite SOAP server to test suds client instrumentation against. +# Configured to listen on localhost port 4132 +# WSDL: http://localhost:4232/?wsdl + +class StanSoapService(ServiceBase): + @rpc(Unicode, Integer, _returns=Iterable(Unicode)) + def ask_question(ctx, question, answer): + """Ask Stan a question! + Ask Stan questions as a Service + + @param name the name to say hello to + @param times the number of times to say hello + @return the completed array + """ + + yield u'¯\_(ツ)_/¯' + + +app = Application([StanSoapService], 'instana.tests.app.ask_question', + in_protocol=Soap11(validator='lxml'), out_protocol=Soap11()) + +# Use Instana middleware so we can test context passing and Soap server traces. +wsgi_app = iWSGIMiddleware(WsgiApplication(app)) +soapserver = make_server('127.0.0.1', 4132, wsgi_app) + +if __name__ == '__main__': + soapserver.serve_forever() From 1fb877179dcda75e496d53447f0935592d4bf8d1 Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Fri, 18 May 2018 10:49:14 +0200 Subject: [PATCH 02/15] Better exception capture & logging in metric thread --- instana/meter.py | 17 +++++++---------- 1 file changed, 7 insertions(+), 10 deletions(-) diff --git a/instana/meter.py b/instana/meter.py index cd262d33..63430a17 100644 --- a/instana/meter.py +++ b/instana/meter.py @@ -153,12 +153,10 @@ def collect_snapshot(self): s = Snapshot(name=appname, version=sys.version) s.version = sys.version s.versions = self.collect_modules() - - return s except Exception as e: - log.debug("collect_snapshot: ", str(e)) - - return None + log.debug(e.message) + else: + return s def jsonable(self, value): try: @@ -174,8 +172,8 @@ def jsonable(self, value): def collect_modules(self): try: - m = sys.modules r = {} + m = sys.modules for k in m: # Don't report submodules (e.g. django.x, django.y, django.z) if ('.' in k): @@ -193,11 +191,10 @@ def collect_modules(self): r[k] = "unknown" log.debug("collect_modules: could not process module ", k, str(e)) - return r except Exception as e: - log.debug("collect_modules: ", str(e)) - - return None + log.debug(e.message) + else: + return r def collect_metrics(self): u = resource.getrusage(resource.RUSAGE_SELF) From a09f0e23b1f68a70a9dc2151363bc99be33ae055 Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Fri, 18 May 2018 16:30:52 +0200 Subject: [PATCH 03/15] Initial suds-jurko instrumentation --- instana/__init__.py | 1 + instana/instrumentation/sudsjurko.py | 44 ++++++++++++++++++++++++++++ 2 files changed, 45 insertions(+) create mode 100644 instana/instrumentation/sudsjurko.py diff --git a/instana/__init__.py b/instana/__init__.py index 7eb20112..ef4c15de 100644 --- a/instana/__init__.py +++ b/instana/__init__.py @@ -9,6 +9,7 @@ # Import & initialize instrumentation # noqa: ignore=W0611 from .instrumentation import urllib3 # noqa + from .instrumentation import sudsjurko # noqa """ The Instana package has two core components: the sensor and the tracer. diff --git a/instana/instrumentation/sudsjurko.py b/instana/instrumentation/sudsjurko.py new file mode 100644 index 00000000..cd286420 --- /dev/null +++ b/instana/instrumentation/sudsjurko.py @@ -0,0 +1,44 @@ +from __future__ import absolute_import +import instana +from instana.log import logger +import opentracing +import opentracing.ext.tags as ext +import wrapt + + +try: + import suds # noqa + + # previously named SoapClient + @wrapt.patch_function_wrapper('suds.client', '_SoapClient.send') + def send_with_instana(wrapped, instance, args, kwargs): + context = instana.internal_tracer.current_context() + + # If we're not tracing, just return + if context is None: + return wrapped(*args, **kwargs) + + try: + span = instana.internal_tracer.start_span("soap", child_of=context) + span.set_tag('soap.action', instance.method.name) + span.set_tag(ext.HTTP_URL, instance.method.location) + + instana.internal_tracer.inject(span.context, opentracing.Format.HTTP_HEADERS, + instance.options.headers) + + rv = wrapped(*args, **kwargs) + + except Exception as e: + span.log_kv({'message': e}) + span.set_tag("error", True) + ec = span.tags.get('ec', 0) + span.set_tag("ec", ec+1) + raise + else: + return rv + finally: + span.finish() + + instana.log.debug("Instrumenting suds-jurko") +except ImportError: + pass From 627766a45ca0b5bf5632a1e660670d711a50b629 Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Fri, 18 May 2018 16:32:10 +0200 Subject: [PATCH 04/15] Basic Soap request tests. --- tests/__init__.py | 4 +-- tests/test_sudsjurko.py | 61 +++++++++++++++++++++++++++++++++++++++++ 2 files changed, 63 insertions(+), 2 deletions(-) create mode 100644 tests/test_sudsjurko.py diff --git a/tests/__init__.py b/tests/__init__.py index 5482ccbb..5b1af350 100644 --- a/tests/__init__.py +++ b/tests/__init__.py @@ -16,7 +16,7 @@ timer = threading.Thread(target=flaskalino.run) timer.daemon = True timer.name = "Background Flask app" -print("Starting background Flask app") +print("Starting background Flask app...") timer.start() @@ -28,7 +28,7 @@ timer = threading.Thread(target=soapserver.serve_forever) timer.daemon = True timer.name = "Background Soap server" -print("Starting background Soap server") +print("Starting background Soap server...") timer.start() diff --git a/tests/test_sudsjurko.py b/tests/test_sudsjurko.py new file mode 100644 index 00000000..6029b496 --- /dev/null +++ b/tests/test_sudsjurko.py @@ -0,0 +1,61 @@ +from __future__ import absolute_import +from nose.tools import assert_equals +from instana import internal_tracer as tracer +from instana.util import to_json +from suds.client import Client + + + + +class TestSudsJurko: + def setUp(self): + """ Clear all spans before a test run """ + self.client = Client('http://localhost:4132/?wsdl', cache=None) + self.recorder = tracer.recorder + self.recorder.clear_spans() + tracer.cur_ctx = None + + def tearDown(self): + """ Do nothing for now """ + # after each test, tracer context should be None (not tracing) + # assert_equals(None, tracer.current_context()) + return None + + def test_vanilla_request(self): + response = self.client.service.ask_question(u'Why u like dat?', 5) + + assert_equals(1, len(response)) + assert_equals(1, len(response[0])) + assert(type(response[0]) is list) + + spans = self.recorder.queued_spans() + assert_equals(1, len(spans)) + + def test_basic_request(self): + span = tracer.start_span("test") + response = self.client.service.ask_question(u'Why u like dat?', 5) + span.finish() + + spans = self.recorder.queued_spans() + assert_equals(3, len(spans)) + wsgi_span = spans[0] + soap_span = spans[1] + test_span = spans[2] + + assert_equals(1, len(response)) + assert_equals(1, len(response[0])) + assert(type(response[0]) is list) + + assert_equals("test", test_span.data.sdk.name) + assert_equals(test_span.t, soap_span.t) + assert_equals(soap_span.p, test_span.s) + assert_equals(wsgi_span.t, soap_span.t) + assert_equals(wsgi_span.p, soap_span.s) + + assert_equals(None, soap_span.error) + assert_equals(None, soap_span.ec) + + assert_equals('ask_question', soap_span.data.soap.action) + assert_equals('http://localhost:4132/', soap_span.data.http.url) + + assert_equals(None, tracer.current_context()) From 377e272cd2df99822e9fa2f00044a58d3401244d Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Fri, 18 May 2018 16:32:50 +0200 Subject: [PATCH 05/15] Add SoapData section; Add soap as registered span --- instana/json_span.py | 7 +++++++ instana/recorder.py | 11 ++++++++--- 2 files changed, 15 insertions(+), 3 deletions(-) diff --git a/instana/json_span.py b/instana/json_span.py index 9415ddaf..281224e0 100644 --- a/instana/json_span.py +++ b/instana/json_span.py @@ -22,6 +22,7 @@ class Data(object): baggage = None custom = None sdk = None + soap = None def __init__(self, **kwds): self.__dict__.update(kwds) @@ -36,6 +37,12 @@ class HttpData(object): def __init__(self, **kwds): self.__dict__.update(kwds) +class SoapData(object): + action = None + + def __init__(self, **kwds): + self.__dict__.update(kwds) + class CustomData(object): tags = None diff --git a/instana/recorder.py b/instana/recorder.py index fd21e7a9..b64d278c 100644 --- a/instana/recorder.py +++ b/instana/recorder.py @@ -6,7 +6,7 @@ import opentracing.ext.tags as ext from basictracer import Sampler, SpanRecorder -from .json_span import CustomData, Data, HttpData, JsonSpan, SDKData +from .json_span import CustomData, Data, HttpData, SoapData, JsonSpan, SDKData from .agent_const import AGENT_TRACES_URL import sys @@ -18,9 +18,10 @@ class InstanaRecorder(SpanRecorder): sensor = None - registered_spans = ("django", "memcache", "rpc-client", "rpc-server", "urllib3", "wsgi") + registered_spans = ("django", "memcache", "rpc-client", "rpc-server", + "soap", "urllib3", "wsgi") entry_kind = ["entry", "server", "consumer"] - exit_kind = ["exit", "client", "producer"] + exit_kind = ["exit", "client", "producer", "soap"] queue = queue.Queue() def __init__(self, sensor): @@ -84,9 +85,11 @@ def build_registered_span(self, span): url=self.get_string_tag(span, ext.HTTP_URL), method=self.get_string_tag(span, ext.HTTP_METHOD), status=self.get_tag(span, ext.HTTP_STATUS_CODE)), + soap=SoapData(action=self.get_tag(span, 'soap.action')), baggage=span.context.baggage, custom=CustomData(tags=span.tags, logs=self.collect_logs(span))) + entityFrom = {'e': self.sensor.agent.from_.pid, 'h': self.sensor.agent.from_.agentUuid} @@ -124,6 +127,8 @@ def build_sdk_span(self, span): d=int(round(span.duration * 1000)), n="sdk", f=entityFrom, + # ec=self.get_tag(span, "ec"), + # error=self.get_tag(span, "error"), data=data) def get_tag(self, span, tag): From 34e13da72eafb7c4ca390d6f7ae4a1c619611c31 Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Fri, 18 May 2018 16:54:01 +0200 Subject: [PATCH 06/15] Cleanup and organize package dependencies --- requirements-test.txt | 2 ++ requirements.txt | 6 ++--- setup.py | 52 +++++++++++++++++++++++++------------------ test_requirements.txt | 8 ------- 4 files changed, 34 insertions(+), 34 deletions(-) create mode 100644 requirements-test.txt delete mode 100644 test_requirements.txt diff --git a/requirements-test.txt b/requirements-test.txt new file mode 100644 index 00000000..a717fa0a --- /dev/null +++ b/requirements-test.txt @@ -0,0 +1,2 @@ +# See setup.py for dependencies +-e .[test] diff --git a/requirements.txt b/requirements.txt index 56514551..a72ab0d3 100644 --- a/requirements.txt +++ b/requirements.txt @@ -1,4 +1,2 @@ -fysom>=2.1.2 -opentracing>=1.2.1 -basictracer>=2.2.0 -autowrapt>=1.0 +# See setup.py for dependencies +-e . diff --git a/setup.py b/setup.py index cb7eda9f..21fba1b5 100644 --- a/setup.py +++ b/setup.py @@ -1,28 +1,36 @@ from setuptools import setup, find_packages setup(name='instana', - version='0.7.12', - download_url='https://github.com/instana/python-sensor', - url='https://www.instana.com/', - license='MIT', - author='Instana Inc.', - author_email='peter.lombardo@instana.com', - description='Metrics sensor and trace collector for Instana', - packages=find_packages(exclude=['tests', 'examples']), - long_description="The instana package provides Python metrics and traces for Instana.", - zip_safe=False, - setup_requires=['nose>=1.0', 'flask>=0.12.2', 'spyne>=2.9', 'lxml>=3.4'], - install_requires=['autowrapt>=1.0', - 'fysom>=2.1.2', - 'opentracing>=1.2.1,<1.3', - 'basictracer>=2.2.0'], - entry_points={'django': ['django.core.handlers.base = instana.django:hook'], - 'django19': ['django.core.handlers.base = instana.django:hook19'], - 'flask': ['flask = instana.flaskana:hook'], - 'runtime': ['string = instana.runtime:hook']}, - test_suite='nose.collector', - keywords=['performance', 'opentracing', 'metrics', 'monitoring'], - classifiers=[ + version='0.7.12', + download_url='https://github.com/instana/python-sensor', + url='https://www.instana.com/', + license='MIT', + author='Instana Inc.', + author_email='peter.lombardo@instana.com', + description='Metrics sensor and trace collector for Instana', + packages=find_packages(exclude=['tests', 'examples']), + long_description="The instana package provides Python metrics and traces for Instana.", + zip_safe=False, + install_requires=['autowrapt>=1.0', + 'fysom>=2.1.2', + 'opentracing>=1.2.1,<1.3', + 'basictracer>=2.2.0'], + entry_points={'django': ['django.core.handlers.base = instana.django:hook'], + 'django19': ['django.core.handlers.base = instana.django:hook19'], + 'flask': ['flask = instana.flaskana:hook'], + 'runtime': ['string = instana.runtime:hook']}, + extras_require={ + 'test': [ + 'nose>=1.0', + 'flask>=0.12.2', + 'spyne>=2.9', + 'lxml>=3.4', + 'suds-jurko>=0.6' + ], + }, + test_suite='nose.collector', + keywords=['performance', 'opentracing', 'metrics', 'monitoring'], + classifiers=[ 'Development Status :: 5 - Production/Stable', 'Framework :: Django', 'Framework :: Flask', diff --git a/test_requirements.txt b/test_requirements.txt deleted file mode 100644 index 695c7f06..00000000 --- a/test_requirements.txt +++ /dev/null @@ -1,8 +0,0 @@ -nose>=1.0 -fysom>=2.1.2 -opentracing>=1.2.1 -basictracer>=2.2.0 -autowrapt>=1.0 -flask>=0.12.2 -urllib3>=1.9 -requests>=2.11.1 From 91c2cbc1d9feba65f085cd7eede98920624b5804 Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Fri, 18 May 2018 16:57:39 +0200 Subject: [PATCH 07/15] New test dependencies for Travis --- .travis.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.travis.yml b/.travis.yml index ae6c37a1..c328f52f 100644 --- a/.travis.yml +++ b/.travis.yml @@ -5,5 +5,5 @@ python: - "3.4" - "3.5" - "3.6" -install: "pip install -r test_requirements.txt" +install: "pip install -r requirements-test.txt" script: nosetests -v From 3afeb21d1e827f8add319e333c669430487a9c76 Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Fri, 18 May 2018 17:15:22 +0200 Subject: [PATCH 08/15] Version sensitive class & method --- instana/instrumentation/sudsjurko.py | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/instana/instrumentation/sudsjurko.py b/instana/instrumentation/sudsjurko.py index cd286420..fcac81c0 100644 --- a/instana/instrumentation/sudsjurko.py +++ b/instana/instrumentation/sudsjurko.py @@ -9,8 +9,15 @@ try: import suds # noqa + # import pdb; pdb.Pdb(skip=['django.*']).set_trace() + + if (suds.version.__version__ <= '0.6'): + class_method = 'SoapClient.send' + else: + class_method = '_SoapClient.send' + # previously named SoapClient - @wrapt.patch_function_wrapper('suds.client', '_SoapClient.send') + @wrapt.patch_function_wrapper('suds.client', class_method) def send_with_instana(wrapped, instance, args, kwargs): context = instana.internal_tracer.current_context() From a868cfc7ad559888016dc74031731f12d0ff051f Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Fri, 18 May 2018 17:39:16 +0200 Subject: [PATCH 09/15] Add requests to test bundle --- setup.py | 1 + 1 file changed, 1 insertion(+) diff --git a/setup.py b/setup.py index 21fba1b5..927239e0 100644 --- a/setup.py +++ b/setup.py @@ -23,6 +23,7 @@ 'test': [ 'nose>=1.0', 'flask>=0.12.2', + 'requests>=2.17.1', 'spyne>=2.9', 'lxml>=3.4', 'suds-jurko>=0.6' From 54f265280a1c9565c20accde36ddb2d65a8dfedf Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Fri, 18 May 2018 17:43:39 +0200 Subject: [PATCH 10/15] Remove unicode characters; silence spyne logging --- tests/apps/soapserver4132.py | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/tests/apps/soapserver4132.py b/tests/apps/soapserver4132.py index 524bf79e..2f147994 100644 --- a/tests/apps/soapserver4132.py +++ b/tests/apps/soapserver4132.py @@ -1,4 +1,5 @@ # vim: set fileencoding=UTF-8 : +import logging from spyne import Application, rpc, ServiceBase, Iterable, Integer, Unicode from spyne.protocol.soap import Soap11 from spyne.server.wsgi import WsgiApplication @@ -20,7 +21,7 @@ def ask_question(ctx, question, answer): @return the completed array """ - yield u'¯\_(ツ)_/¯' + yield u'To an artificial mind, all reality is virtual. How do they know that the real world isn\'t just another simulation? How do you?' app = Application([StanSoapService], 'instana.tests.app.ask_question', @@ -30,5 +31,11 @@ def ask_question(ctx, question, answer): wsgi_app = iWSGIMiddleware(WsgiApplication(app)) soapserver = make_server('127.0.0.1', 4132, wsgi_app) +logging.basicConfig(level=logging.WARN) +logging.getLogger('suds').setLevel(logging.WARN) +logging.getLogger('suds.resolver').setLevel(logging.WARN) +logging.getLogger('spyne.protocol.xml').setLevel(logging.WARN) +logging.getLogger('spyne.model.complex').setLevel(logging.WARN) + if __name__ == '__main__': soapserver.serve_forever() From 73a57497229ff6ba0cf23d4cbab5807caa819c98 Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Mon, 21 May 2018 12:30:40 +0200 Subject: [PATCH 11/15] Exception & fault logging plus tests --- instana/instrumentation/sudsjurko.py | 2 +- tests/apps/soapserver4132.py | 16 ++- tests/test_sudsjurko.py | 155 ++++++++++++++++++++++++++- 3 files changed, 169 insertions(+), 4 deletions(-) diff --git a/instana/instrumentation/sudsjurko.py b/instana/instrumentation/sudsjurko.py index fcac81c0..263c673a 100644 --- a/instana/instrumentation/sudsjurko.py +++ b/instana/instrumentation/sudsjurko.py @@ -36,7 +36,7 @@ def send_with_instana(wrapped, instance, args, kwargs): rv = wrapped(*args, **kwargs) except Exception as e: - span.log_kv({'message': e}) + span.log_kv({'message': e.message}) span.set_tag("error", True) ec = span.tags.get('ec', 0) span.set_tag("ec", ec+1) diff --git a/tests/apps/soapserver4132.py b/tests/apps/soapserver4132.py index 2f147994..5fd5ce9b 100644 --- a/tests/apps/soapserver4132.py +++ b/tests/apps/soapserver4132.py @@ -1,6 +1,6 @@ # vim: set fileencoding=UTF-8 : import logging -from spyne import Application, rpc, ServiceBase, Iterable, Integer, Unicode +from spyne import Application, rpc, ServiceBase, Iterable, Integer, Unicode, Fault from spyne.protocol.soap import Soap11 from spyne.server.wsgi import WsgiApplication from wsgiref.simple_server import make_server @@ -24,6 +24,20 @@ def ask_question(ctx, question, answer): yield u'To an artificial mind, all reality is virtual. How do they know that the real world isn\'t just another simulation? How do you?' + @rpc() + def server_exception(ctx): + raise Exception("Server side exception example.") + + @rpc() + def server_fault(ctx): + raise Fault("Server", "Server side fault example.") + + @rpc() + def client_fault(ctx): + raise Fault("Client", "Client side fault example") + + + app = Application([StanSoapService], 'instana.tests.app.ask_question', in_protocol=Soap11(validator='lxml'), out_protocol=Soap11()) diff --git a/tests/test_sudsjurko.py b/tests/test_sudsjurko.py index 6029b496..f8630b44 100644 --- a/tests/test_sudsjurko.py +++ b/tests/test_sudsjurko.py @@ -5,8 +5,6 @@ from suds.client import Client - - class TestSudsJurko: def setUp(self): """ Clear all spans before a test run """ @@ -59,3 +57,156 @@ def test_basic_request(self): assert_equals('http://localhost:4132/', soap_span.data.http.url) assert_equals(None, tracer.current_context()) + + def test_server_exception(self): + response = None + try: + span = tracer.start_span("test") + response = self.client.service.server_exception() + except: + pass + finally: + span.finish() + + spans = self.recorder.queued_spans() + assert_equals(3, len(spans)) + wsgi_span = spans[0] + soap_span = spans[1] + test_span = spans[2] + + assert_equals(None, response) + assert_equals("test", test_span.data.sdk.name) + assert_equals(test_span.t, soap_span.t) + assert_equals(soap_span.p, test_span.s) + assert_equals(wsgi_span.t, soap_span.t) + assert_equals(wsgi_span.p, soap_span.s) + + assert_equals(True, soap_span.error) + assert_equals(1, soap_span.ec) + assert('logs' in soap_span.data.custom.__dict__) + assert_equals(1, len(soap_span.data.custom.logs.keys())) + + tskey = soap_span.data.custom.logs.keys()[0] + assert('message' in soap_span.data.custom.logs[tskey]) + assert_equals(u"Server raised fault: 'Internal Error'", + soap_span.data.custom.logs[tskey]['message']) + + assert_equals('server_exception', soap_span.data.soap.action) + assert_equals('http://localhost:4132/', soap_span.data.http.url) + + assert_equals(None, tracer.current_context()) + + def test_server_fault(self): + response = None + try: + span = tracer.start_span("test") + response = self.client.service.server_fault() + except: + pass + finally: + span.finish() + + spans = self.recorder.queued_spans() + assert_equals(3, len(spans)) + wsgi_span = spans[0] + soap_span = spans[1] + test_span = spans[2] + + assert_equals(None, response) + assert_equals("test", test_span.data.sdk.name) + assert_equals(test_span.t, soap_span.t) + assert_equals(soap_span.p, test_span.s) + assert_equals(wsgi_span.t, soap_span.t) + assert_equals(wsgi_span.p, soap_span.s) + + assert_equals(True, soap_span.error) + assert_equals(1, soap_span.ec) + assert('logs' in soap_span.data.custom.__dict__) + assert_equals(1, len(soap_span.data.custom.logs.keys())) + + tskey = soap_span.data.custom.logs.keys()[0] + assert('message' in soap_span.data.custom.logs[tskey]) + assert_equals(u"Server raised fault: 'Server side fault example.'", + soap_span.data.custom.logs[tskey]['message']) + + assert_equals('server_fault', soap_span.data.soap.action) + assert_equals('http://localhost:4132/', soap_span.data.http.url) + + assert_equals(None, tracer.current_context()) + + def test_server_fault(self): + response = None + try: + span = tracer.start_span("test") + response = self.client.service.server_fault() + except: + pass + finally: + span.finish() + + spans = self.recorder.queued_spans() + assert_equals(3, len(spans)) + wsgi_span = spans[0] + soap_span = spans[1] + test_span = spans[2] + + assert_equals(None, response) + assert_equals("test", test_span.data.sdk.name) + assert_equals(test_span.t, soap_span.t) + assert_equals(soap_span.p, test_span.s) + assert_equals(wsgi_span.t, soap_span.t) + assert_equals(wsgi_span.p, soap_span.s) + + assert_equals(True, soap_span.error) + assert_equals(1, soap_span.ec) + assert('logs' in soap_span.data.custom.__dict__) + assert_equals(1, len(soap_span.data.custom.logs.keys())) + + tskey = soap_span.data.custom.logs.keys()[0] + assert('message' in soap_span.data.custom.logs[tskey]) + assert_equals(u"Server raised fault: 'Server side fault example.'", + soap_span.data.custom.logs[tskey]['message']) + + assert_equals('server_fault', soap_span.data.soap.action) + assert_equals('http://localhost:4132/', soap_span.data.http.url) + + assert_equals(None, tracer.current_context()) + + + def test_client_fault(self): + response = None + try: + span = tracer.start_span("test") + response = self.client.service.client_fault() + except: + pass + finally: + span.finish() + + spans = self.recorder.queued_spans() + assert_equals(3, len(spans)) + wsgi_span = spans[0] + soap_span = spans[1] + test_span = spans[2] + + assert_equals(None, response) + assert_equals("test", test_span.data.sdk.name) + assert_equals(test_span.t, soap_span.t) + assert_equals(soap_span.p, test_span.s) + assert_equals(wsgi_span.t, soap_span.t) + assert_equals(wsgi_span.p, soap_span.s) + + assert_equals(True, soap_span.error) + assert_equals(1, soap_span.ec) + assert('logs' in soap_span.data.custom.__dict__) + assert_equals(1, len(soap_span.data.custom.logs.keys())) + + tskey = soap_span.data.custom.logs.keys()[0] + assert('message' in soap_span.data.custom.logs[tskey]) + assert_equals(u"Server raised fault: 'Client side fault example'", + soap_span.data.custom.logs[tskey]['message']) + + assert_equals('client_fault', soap_span.data.soap.action) + assert_equals('http://localhost:4132/', soap_span.data.http.url) + + assert_equals(None, tracer.current_context()) From fe746ed39bba3d64da54e71870594c74b32a8b17 Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Mon, 21 May 2018 13:26:28 +0200 Subject: [PATCH 12/15] Move exception logging out to span --- instana/instrumentation/sudsjurko.py | 5 +---- instana/span.py | 12 ++++++++++++ 2 files changed, 13 insertions(+), 4 deletions(-) diff --git a/instana/instrumentation/sudsjurko.py b/instana/instrumentation/sudsjurko.py index 263c673a..29eb13c1 100644 --- a/instana/instrumentation/sudsjurko.py +++ b/instana/instrumentation/sudsjurko.py @@ -36,10 +36,7 @@ def send_with_instana(wrapped, instance, args, kwargs): rv = wrapped(*args, **kwargs) except Exception as e: - span.log_kv({'message': e.message}) - span.set_tag("error", True) - ec = span.tags.get('ec', 0) - span.set_tag("ec", ec+1) + span.log_exception(e) raise else: return rv diff --git a/instana/span.py b/instana/span.py index 947b56d4..057848c6 100644 --- a/instana/span.py +++ b/instana/span.py @@ -14,3 +14,15 @@ def finish(self, finish_time=None): sampled=True) self.tracer.cur_ctx = pctx super(InstanaSpan, self).finish(finish_time) + + def log_exception(self, e): + if hasattr(e, 'message'): + self.log_kv({'message': e.message}) + elif hasattr(e, '__str__'): + self.log_kv({'message': e.__str__()}) + else: + self.log_kv({'message': str(e)}) + + self.set_tag("error", True) + ec = self.tags.get('ec', 0) + self.set_tag("ec", ec+1) From 9873d24ccf7c62f42c359878ead17764e49a7987 Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Mon, 21 May 2018 13:26:42 +0200 Subject: [PATCH 13/15] Python 2 <-> 3 compatibility change --- tests/test_sudsjurko.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/tests/test_sudsjurko.py b/tests/test_sudsjurko.py index f8630b44..4efb1dfe 100644 --- a/tests/test_sudsjurko.py +++ b/tests/test_sudsjurko.py @@ -86,7 +86,7 @@ def test_server_exception(self): assert('logs' in soap_span.data.custom.__dict__) assert_equals(1, len(soap_span.data.custom.logs.keys())) - tskey = soap_span.data.custom.logs.keys()[0] + tskey = list(soap_span.data.custom.logs.keys())[0] assert('message' in soap_span.data.custom.logs[tskey]) assert_equals(u"Server raised fault: 'Internal Error'", soap_span.data.custom.logs[tskey]['message']) @@ -124,7 +124,7 @@ def test_server_fault(self): assert('logs' in soap_span.data.custom.__dict__) assert_equals(1, len(soap_span.data.custom.logs.keys())) - tskey = soap_span.data.custom.logs.keys()[0] + tskey = list(soap_span.data.custom.logs.keys())[0] assert('message' in soap_span.data.custom.logs[tskey]) assert_equals(u"Server raised fault: 'Server side fault example.'", soap_span.data.custom.logs[tskey]['message']) @@ -162,7 +162,7 @@ def test_server_fault(self): assert('logs' in soap_span.data.custom.__dict__) assert_equals(1, len(soap_span.data.custom.logs.keys())) - tskey = soap_span.data.custom.logs.keys()[0] + tskey = list(soap_span.data.custom.logs.keys())[0] assert('message' in soap_span.data.custom.logs[tskey]) assert_equals(u"Server raised fault: 'Server side fault example.'", soap_span.data.custom.logs[tskey]['message']) @@ -201,7 +201,7 @@ def test_client_fault(self): assert('logs' in soap_span.data.custom.__dict__) assert_equals(1, len(soap_span.data.custom.logs.keys())) - tskey = soap_span.data.custom.logs.keys()[0] + tskey = list(soap_span.data.custom.logs.keys())[0] assert('message' in soap_span.data.custom.logs[tskey]) assert_equals(u"Server raised fault: 'Client side fault example'", soap_span.data.custom.logs[tskey]['message']) From c510d4358c309581764d45d61b3796ee11c3800e Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Wed, 23 May 2018 11:23:44 +0200 Subject: [PATCH 14/15] Moar HTTP tags. --- instana/instrumentation/sudsjurko.py | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/instana/instrumentation/sudsjurko.py b/instana/instrumentation/sudsjurko.py index 29eb13c1..253e3abf 100644 --- a/instana/instrumentation/sudsjurko.py +++ b/instana/instrumentation/sudsjurko.py @@ -16,7 +16,6 @@ else: class_method = '_SoapClient.send' - # previously named SoapClient @wrapt.patch_function_wrapper('suds.client', class_method) def send_with_instana(wrapped, instance, args, kwargs): context = instana.internal_tracer.current_context() @@ -29,6 +28,7 @@ def send_with_instana(wrapped, instance, args, kwargs): span = instana.internal_tracer.start_span("soap", child_of=context) span.set_tag('soap.action', instance.method.name) span.set_tag(ext.HTTP_URL, instance.method.location) + span.set_tag(ext.HTTP_METHOD, 'POST') instana.internal_tracer.inject(span.context, opentracing.Format.HTTP_HEADERS, instance.options.headers) @@ -37,8 +37,10 @@ def send_with_instana(wrapped, instance, args, kwargs): except Exception as e: span.log_exception(e) + span.set_tag(ext.HTTP_STATUS_CODE, 500) raise else: + span.set_tag(ext.HTTP_STATUS_CODE, 200) return rv finally: span.finish() From 4d16728a675fe7aa9954ed6ac1279d6a0c2e825c Mon Sep 17 00:00:00 2001 From: Peter Giacomo Lombardo Date: Sun, 27 May 2018 12:30:29 +0200 Subject: [PATCH 15/15] Remove debug remnant and fix logger call --- instana/instrumentation/sudsjurko.py | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/instana/instrumentation/sudsjurko.py b/instana/instrumentation/sudsjurko.py index 253e3abf..633813f8 100644 --- a/instana/instrumentation/sudsjurko.py +++ b/instana/instrumentation/sudsjurko.py @@ -9,8 +9,6 @@ try: import suds # noqa - # import pdb; pdb.Pdb(skip=['django.*']).set_trace() - if (suds.version.__version__ <= '0.6'): class_method = 'SoapClient.send' else: @@ -45,6 +43,6 @@ def send_with_instana(wrapped, instance, args, kwargs): finally: span.finish() - instana.log.debug("Instrumenting suds-jurko") + logger.debug("Instrumenting suds-jurko") except ImportError: pass