From 0bf2edd53b6378e5825f9ff02851c521f3a0fb54 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micka=C3=ABl=20Bergem?= Date: Tue, 10 Sep 2019 08:46:06 -0700 Subject: [PATCH 1/6] Record HTTP interactions --- howfast_apm/core.py | 18 +++++- howfast_apm/flask.py | 2 + howfast_apm/hook_requests.py | 104 +++++++++++++++++++++++++++++++++++ tests/test_hook_http.py | 82 +++++++++++++++++++++++++++ 4 files changed, 205 insertions(+), 1 deletion(-) create mode 100644 howfast_apm/hook_requests.py create mode 100644 tests/test_hook_http.py diff --git a/howfast_apm/core.py b/howfast_apm/core.py index c36c427..8321d76 100644 --- a/howfast_apm/core.py +++ b/howfast_apm/core.py @@ -1,10 +1,11 @@ import os import logging -from typing import Optional +from typing import Optional, List from datetime import datetime from queue import Full, Empty from .queue import queue, Runner +from .hook_requests import install_hooks, Interaction logger = logging.getLogger('howfast_apm') @@ -14,10 +15,16 @@ class CoreAPM(object): Base class that provides the shared code for: * starting the background thread * pushing points to the queue + * storing external interactions """ app_id: Optional[str] + interactions: List[Interaction] = [] + + def __init__(self): + self.interactions = [] + def setup( self, # The HowFast app ID to use @@ -31,6 +38,7 @@ def setup( if self.app_id: logger.info(f"HowFast APM configured with DSN {self.app_id}") self.start_background_thread() + self.setup_hooks() else: logger.warning(f"HowFast APM initialized with no DSN, reporting will be disabled.") @@ -40,6 +48,14 @@ def start_background_thread(self): self.runner.start() # TODO: stop the thread at some point? + def setup_hooks(self) -> None: + """ Install hooks to register what is slow """ + install_hooks(self.record_interaction) + + def record_interaction(self, interaction: Interaction) -> None: + """ Save the interaction """ + self.interactions.append(interaction) + @staticmethod def save_point( time_request_started: datetime, diff --git a/howfast_apm/flask.py b/howfast_apm/flask.py index ae8cf6c..14de528 100644 --- a/howfast_apm/flask.py +++ b/howfast_apm/flask.py @@ -47,6 +47,8 @@ def __init__( request_started.connect(self._request_started) + super(CoreAPM, self).__init__() + def __call__(self, environ, start_response): if not self.app_id: # HF APM not configured, return early to save some time diff --git a/howfast_apm/hook_requests.py b/howfast_apm/hook_requests.py new file mode 100644 index 0000000..8e940d4 --- /dev/null +++ b/howfast_apm/hook_requests.py @@ -0,0 +1,104 @@ +import sys +import logging + +from typing import Callable, Union, Any +from timeit import default_timer as timer + +logger = logging.getLogger('howfast_apm') + + +class Interaction(object): + """ An external interaction with other services """ + # Can be "request" + type: str + # Name holds the URL if type is "request" + name: str + elapsed: float + extra: dict + + def __init__(self, type, name, elapsed, extra=None): + self.type = type + self.name = name + self.elapsed = elapsed + self.extra = extra or {} + + +def install_hooks(record_interaction: Callable[[Interaction], Any]) -> None: + """ Install the HTTP hooks """ + patch_requests_module = True + try: + import requests + except ModuleNotFoundError: + # Maybe requests is not installed / available in the instrumented code + patch_requests_module = False + + urllib = sys.modules['urllib'] + if patch_requests_module: + requests = sys.modules['requests'] + + def get_patched(func, meta_extractor: Callable): + + def patched_request(*args, **kwargs): + start = timer() + resp = func(*args, **kwargs) + elapsed = timer() - start + + try: + method, name = meta_extractor(*args, **kwargs) + + record_interaction( + Interaction( + type="request", + name=name, + elapsed=elapsed, + extra={'method': method.lower()}, + )) + except: + logger.error("Unable to record interaction", exc_info=True) # noqa + + return patched_request + + # TODO: build method extractor for urlopen + urllib.request.urlopen = get_patched( + urllib.request.urlopen, + lambda *args, **kwargs: [None, None], + ) + sys.modules['urllib'] = urllib + + if patch_requests_module: + requests.request = get_patched( + requests.request, + lambda *args, **kwargs: [ + args[0] if len(args) > 0 else kwargs.get('method'), + args[1] if len(args) > 1 else kwargs.get('url'), + ], + ) + + def request_alias_extractor(method): + return lambda *args, **kwargs: [ + method, + args[0] if len(args) > 0 else kwargs.get('url'), + ] + + requests.get = get_patched( + requests.get, + meta_extractor=request_alias_extractor('get'), + ) + requests.post = get_patched( + requests.post, + meta_extractor=request_alias_extractor('post'), + ) + requests.head = get_patched( + requests.head, + meta_extractor=request_alias_extractor('head'), + ) + requests.put = get_patched( + requests.put, + meta_extractor=request_alias_extractor('put'), + ) + requests.delete = get_patched( + requests.delete, + meta_extractor=request_alias_extractor('delete'), + ) + + sys.modules['requests'] = requests diff --git a/tests/test_hook_http.py b/tests/test_hook_http.py new file mode 100644 index 0000000..e1fa8d1 --- /dev/null +++ b/tests/test_hook_http.py @@ -0,0 +1,82 @@ +from unittest.mock import MagicMock, patch +from howfast_apm.core import CoreAPM + + +@patch('requests.get') +@patch('requests.post') +def test_hook_requests_get(post_mocked, get_mocked): + """ setup_hooks() should intercept network requests using requests.get """ + import requests + apm = CoreAPM() + apm.setup_hooks() + + assert len(apm.interactions) == 0 + requests.get('some-url') + assert len(apm.interactions) == 1 + assert get_mocked.called is True + + interaction = apm.interactions[0] + assert interaction.type == 'request' + assert interaction.name == 'some-url' + assert interaction.extra.get('method') == 'get' + assert isinstance(interaction.elapsed, float) + assert interaction.elapsed > 0 + assert interaction.elapsed < 1, "interaction should not have lasted more than a second" + + # Other ways of calling requests + requests.post('https://example.org/') + assert len(apm.interactions) == 2 + interaction = apm.interactions[1] + assert interaction.type == 'request' + assert interaction.name == 'https://example.org/' + assert interaction.extra.get('method') == 'post' + + # With a named parameter + requests.get(url='https://example2.org/') + assert len(apm.interactions) == 3 + interaction = apm.interactions[2] + assert interaction.type == 'request' + assert interaction.name == 'https://example2.org/' + assert interaction.extra.get('method') == 'get' + + +def test_hook_no_request(): + """ setup_hooks() should not crash if requests is not installed """ + # This is not exactly reproducing what happens when a module is missing, but it still raises a + # ModuleNotFoundError. + # TODO: use a context manager + import sys + requests_backup = sys.modules['requests'] + try: + sys.modules['requests'] = None + apm = CoreAPM() + apm.setup_hooks() + except Exception as err: + raise err + finally: + # Make sure we put the original module back in place + sys.modules['requests'] = requests_backup + + +@patch('requests.request') +def test_requests_request(request_mocked): + """ setup_hooks() should intercept network requests using requests.request """ + import requests + apm = CoreAPM() + apm.setup_hooks() + + url = 'https://example.org/' + + assert len(apm.interactions) == 0 + requests.request('GET', url) + assert len(apm.interactions) == 1 + assert request_mocked.called is True + + interaction = apm.interactions[0] + assert interaction.type == 'request' + assert interaction.name == url + assert interaction.extra.get('method') == 'get' + + +# TODO: test requests made with urllib +# TODO: test requests made by third-party dependencies - does the hook work? From 50a82a9ce99ea60a91e9659564dbac3d257db95b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micka=C3=ABl=20Bergem?= Date: Tue, 10 Sep 2019 09:12:45 -0700 Subject: [PATCH 2/6] Use a feature flag to control if the APM records interactions --- howfast_apm/config.py | 8 +++++++- howfast_apm/core.py | 9 +++++++-- howfast_apm/flask.py | 6 ++++-- tests/test_middleware_flask.py | 11 +++++++++++ 4 files changed, 29 insertions(+), 5 deletions(-) diff --git a/howfast_apm/config.py b/howfast_apm/config.py index 75ae27d..d90be2d 100644 --- a/howfast_apm/config.py +++ b/howfast_apm/config.py @@ -1,7 +1,13 @@ import os -# Constants +# Where to send the performance data HOWFAST_APM_COLLECTOR_URL = os.environ.get( 'HOWFAST_APM_COLLECTOR_URL', "https://api.howfast.tech/v1.1/apm-collector/store", ) + +# Record interactions of the API with external sources (HTTP requests, etc) +HOWFAST_APM_RECORD_INTERACTIONS = os.environ.get( + 'HOWFAST_APM_RECORD_INTERACTIONS', + False, +) diff --git a/howfast_apm/core.py b/howfast_apm/core.py index 8321d76..caa6b8b 100644 --- a/howfast_apm/core.py +++ b/howfast_apm/core.py @@ -4,6 +4,7 @@ from datetime import datetime from queue import Full, Empty +from .config import HOWFAST_APM_RECORD_INTERACTIONS from .queue import queue, Runner from .hook_requests import install_hooks, Interaction @@ -20,9 +21,12 @@ class CoreAPM(object): app_id: Optional[str] + record_interactions: bool interactions: List[Interaction] = [] - def __init__(self): + def __init__(self, record_interactions=HOWFAST_APM_RECORD_INTERACTIONS): + self.record_interactions = bool(record_interactions) + logger.info("Interactions will %s", 'be enabled' if self.record_interactions else 'NOT be enabled') self.interactions = [] def setup( @@ -38,7 +42,8 @@ def setup( if self.app_id: logger.info(f"HowFast APM configured with DSN {self.app_id}") self.start_background_thread() - self.setup_hooks() + if self.record_interactions: + self.setup_hooks() else: logger.warning(f"HowFast APM initialized with no DSN, reporting will be disabled.") diff --git a/howfast_apm/flask.py b/howfast_apm/flask.py index 14de528..53ca3d2 100644 --- a/howfast_apm/flask.py +++ b/howfast_apm/flask.py @@ -31,7 +31,11 @@ def __init__( app_id: str = None, # Endpoints not to monitor endpoints_blacklist: List[str] = None, + # Other configuration parameters passed to the CoreAPM constructor + **kwargs, ): + super().__init__(**kwargs) + self.app = app self.wsgi_app = app.wsgi_app # Overwrite the WSGI application @@ -47,8 +51,6 @@ def __init__( request_started.connect(self._request_started) - super(CoreAPM, self).__init__() - def __call__(self, environ, start_response): if not self.app_id: # HF APM not configured, return early to save some time diff --git a/tests/test_middleware_flask.py b/tests/test_middleware_flask.py index 07c61b2..4f5f7ff 100644 --- a/tests/test_middleware_flask.py +++ b/tests/test_middleware_flask.py @@ -96,3 +96,14 @@ def test_blacklist_option(HowFastFlaskMiddleware): response = tester.get('/name/test-34abc') assert response.status_code == 200 assert HowFastFlaskMiddleware.save_point.called is False + + +def test_interactions_option(HowFastFlaskMiddleware): + """ The record_interactions parameter should be accepted """ + app = create_app() + HowFastFlaskMiddleware( + app, + app_id='some-dsn', + record_interactions=True, + ) + # TODO: write assertions From a784b5ae1df8ebfaab75c95da5711ab466e621d0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micka=C3=ABl=20Bergem?= Date: Thu, 12 Sep 2019 21:44:09 -0700 Subject: [PATCH 3/6] Send interactions as part of the data point --- howfast_apm/core.py | 29 ++++++++++++++-- howfast_apm/hook_requests.py | 49 +++++++++++++++++---------- howfast_apm/queue.py | 18 +++++----- tests/conftest.py | 51 ++++++++++++++++------------ tests/test_core.py | 19 +++++------ tests/test_hook_http.py | 2 +- tests/test_middleware_flask.py | 62 +++++++++++++++++++++++----------- tests/test_runner.py | 11 +++--- 8 files changed, 157 insertions(+), 84 deletions(-) diff --git a/howfast_apm/core.py b/howfast_apm/core.py index caa6b8b..7487b53 100644 --- a/howfast_apm/core.py +++ b/howfast_apm/core.py @@ -26,7 +26,7 @@ class CoreAPM(object): def __init__(self, record_interactions=HOWFAST_APM_RECORD_INTERACTIONS): self.record_interactions = bool(record_interactions) - logger.info("Interactions will %s", 'be enabled' if self.record_interactions else 'NOT be enabled') + logger.debug("Interactions will %s", 'be enabled' if self.record_interactions else 'NOT be enabled') self.interactions = [] def setup( @@ -61,22 +61,47 @@ def record_interaction(self, interaction: Interaction) -> None: """ Save the interaction """ self.interactions.append(interaction) + def reset_interactions(self): + self.interactions = [] + + def save_point(self, **kwargs) -> None: + """ + Save a request/response performance information. + + This method is called by subclasses with their framework-specific information. We then add + the core-level collected performance data (interactions) and call self._save_point(). + """ + self._save_point( + interactions=self.interactions, + **kwargs, + ) + # Reset the list of interactions, since it's specific to a request/point + self.interactions = [] + @staticmethod - def save_point( + def _save_point( time_request_started: datetime, time_elapsed: float, # seconds method: str, uri: str, endpoint: str = None, # function name handling the request + interactions: List[Interaction] = None, ) -> None: """ Save a request/response performance information """ + + interaction_list = [] + while interactions: # catches "empty list" and None value + interaction_list.append(interactions.pop().serialize()) + item = ( time_request_started, time_elapsed, method, uri, endpoint, + interaction_list, ) + # Capped queue pushed = False while pushed is False: diff --git a/howfast_apm/hook_requests.py b/howfast_apm/hook_requests.py index 8e940d4..18227f5 100644 --- a/howfast_apm/hook_requests.py +++ b/howfast_apm/hook_requests.py @@ -1,7 +1,7 @@ import sys import logging -from typing import Callable, Union, Any +from typing import Callable, Any from timeit import default_timer as timer logger = logging.getLogger('howfast_apm') @@ -22,19 +22,29 @@ def __init__(self, type, name, elapsed, extra=None): self.elapsed = elapsed self.extra = extra or {} + def serialize(self): + """ JSON-serialize the Interaction """ + return { + "type": self.type, + "name": self.name, + "elapsed": self.elapsed, + "extra": self.extra, + } + def install_hooks(record_interaction: Callable[[Interaction], Any]) -> None: """ Install the HTTP hooks """ patch_requests_module = True try: - import requests + # Try to import the module to see if it's available + import requests # noqa except ModuleNotFoundError: # Maybe requests is not installed / available in the instrumented code patch_requests_module = False urllib = sys.modules['urllib'] if patch_requests_module: - requests = sys.modules['requests'] + tmp_requests = sys.modules['requests'] def get_patched(func, meta_extractor: Callable): @@ -53,8 +63,11 @@ def patched_request(*args, **kwargs): elapsed=elapsed, extra={'method': method.lower()}, )) - except: - logger.error("Unable to record interaction", exc_info=True) # noqa + # Catch any exception because we don't want it to bubble up to the real app + except Exception: + logger.error("Unable to record interaction", exc_info=True) # pragma: nocover + + return resp return patched_request @@ -66,8 +79,8 @@ def patched_request(*args, **kwargs): sys.modules['urllib'] = urllib if patch_requests_module: - requests.request = get_patched( - requests.request, + tmp_requests.request = get_patched( + tmp_requests.request, lambda *args, **kwargs: [ args[0] if len(args) > 0 else kwargs.get('method'), args[1] if len(args) > 1 else kwargs.get('url'), @@ -80,25 +93,25 @@ def request_alias_extractor(method): args[0] if len(args) > 0 else kwargs.get('url'), ] - requests.get = get_patched( - requests.get, + tmp_requests.get = get_patched( + tmp_requests.get, meta_extractor=request_alias_extractor('get'), ) - requests.post = get_patched( - requests.post, + tmp_requests.post = get_patched( + tmp_requests.post, meta_extractor=request_alias_extractor('post'), ) - requests.head = get_patched( - requests.head, + tmp_requests.head = get_patched( + tmp_requests.head, meta_extractor=request_alias_extractor('head'), ) - requests.put = get_patched( - requests.put, + tmp_requests.put = get_patched( + tmp_requests.put, meta_extractor=request_alias_extractor('put'), ) - requests.delete = get_patched( - requests.delete, + tmp_requests.delete = get_patched( + tmp_requests.delete, meta_extractor=request_alias_extractor('delete'), ) - sys.modules['requests'] = requests + sys.modules['requests'] = tmp_requests diff --git a/howfast_apm/queue.py b/howfast_apm/queue.py index 2aebff9..3500935 100644 --- a/howfast_apm/queue.py +++ b/howfast_apm/queue.py @@ -76,16 +76,16 @@ def run_once(self): return @staticmethod - def serialize_point(point: tuple) -> tuple: + def serialize_point(point: dict) -> tuple: """ Prepare the point to be sent to the API """ - ( - time_request_started, - time_elapsed, - method, - uri, - endpoint, - ) = point - return (method, uri, time_request_started.isoformat(), time_elapsed, endpoint) + return ( + point['method'], + point['uri'], + point['time_request_started'].isoformat(), + point['time_elapsed'], + point['endpoint'], + point['interactions'], + ) def send_batch(self): """ Process one performance point """ diff --git a/tests/conftest.py b/tests/conftest.py index 9258dcc..ffbf23a 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -1,17 +1,24 @@ import pytest from datetime import datetime, timezone from queue import Queue +# TODO: pytest refuses to start when this line is present :/ +from howfast_apm.hook_requests import Interaction @pytest.fixture def example_queue_item(): - return ( - datetime.now(timezone.utc), - 0.04, - 'PUT', - '/look/here', - 'controllers.endpoint_name', - ) + interactions = [ + Interaction('request', 'https://www.example.org/req1', 0.01), + Interaction('request', 'https://www.example.org/req2', 0.02), + ] + return { + 'time_request_started': datetime.now(timezone.utc), + 'time_elapsed': 0.04, + 'method': 'PUT', + 'uri': '/look/here', + 'endpoint': 'controllers.endpoint_name', + 'interactions': interactions, + } @pytest.fixture @@ -21,21 +28,23 @@ def example_queue_items_gen(): def generator(): id = 1 while True: - yield ( - datetime.now(timezone.utc), - 0.04, - 'PUT', - f'/call/{id}', - 'controllers.endpoint_name', - ) + yield { + 'time_request_started': datetime.now(timezone.utc), + 'time_elapsed': 0.04, + 'method': 'PUT', + 'uri': f'/call/{id}', + 'endpoint': 'controllers.endpoint_name', + 'interactions': [Interaction('request', f'https://www.example.org/req{id}', 0.02)], + } # Alternate between an endpoint or no endpoint - yield ( - datetime.now(timezone.utc), - 0.04, - 'GET', - f'/call/{id}', - None, - ) + yield { + 'time_request_started': datetime.now(timezone.utc), + 'time_elapsed': 0.04, + 'method': 'GET', + 'uri': f'/call/{id}', + 'endpoint': None, + 'interactions': [], + } yield generator() diff --git a/tests/test_core.py b/tests/test_core.py index 2bf8644..8dba728 100644 --- a/tests/test_core.py +++ b/tests/test_core.py @@ -1,4 +1,3 @@ -from unittest.mock import patch from queue import Queue from howfast_apm import core @@ -9,18 +8,18 @@ def test_capped_queue(example_queue_items_gen): core.queue = Queue(maxsize=10) # Save one point assert core.queue.qsize() == 0 - core.CoreAPM.save_point(*next(example_queue_items_gen)) + core.CoreAPM._save_point(**next(example_queue_items_gen)) assert core.queue.qsize() == 1 # Save a second point - core.CoreAPM.save_point(*next(example_queue_items_gen)) + core.CoreAPM._save_point(**next(example_queue_items_gen)) assert core.queue.qsize() == 2 # Fill the queue for i in range(8): - item = list(next(example_queue_items_gen)) - item[3] = f'/call/{i}' # update the URL to keep track of points - core.CoreAPM.save_point(*item) + item = next(example_queue_items_gen) + item['uri'] = f'/call/{i}' # update the URL to keep track of points + core.CoreAPM._save_point(**item) assert core.queue.qsize() == 10 assert core.queue.full() @@ -34,12 +33,12 @@ def test_capped_queue_full(example_queue_item): core.queue = Queue(maxsize=10) # Fill the queue for i in range(10): - item = list(example_queue_item) - item[3] = f'/call/{i}' # update the URL to keep track of points - core.CoreAPM.save_point(*item) + item = example_queue_item + item['uri'] = f'/call/{i}' # update the URL to keep track of points + core.CoreAPM._save_point(**item) assert core.queue.full() # Add one more item to the full queue - core.CoreAPM.save_point(*example_queue_item) + core.CoreAPM._save_point(**example_queue_item) assert core.queue.full(), 'queue should still be full' assert core.queue.qsize() == 10 diff --git a/tests/test_hook_http.py b/tests/test_hook_http.py index e1fa8d1..0e45a17 100644 --- a/tests/test_hook_http.py +++ b/tests/test_hook_http.py @@ -1,4 +1,4 @@ -from unittest.mock import MagicMock, patch +from unittest.mock import patch from howfast_apm.core import CoreAPM diff --git a/tests/test_middleware_flask.py b/tests/test_middleware_flask.py index 4f5f7ff..9a11b50 100644 --- a/tests/test_middleware_flask.py +++ b/tests/test_middleware_flask.py @@ -1,7 +1,8 @@ import pytest +import requests from flask import Flask -from unittest.mock import MagicMock +from unittest.mock import MagicMock, patch from datetime import datetime, timezone @@ -16,6 +17,11 @@ def index(): def names(name): return f'ok, {name}' + @app.route('/external-call') + def external_call(): + requests.put('https://do-not-exists/') + return 'ok' + return app @@ -23,7 +29,7 @@ def names(name): def HowFastFlaskMiddleware(): """ Patch the save_point() method """ from howfast_apm import HowFastFlaskMiddleware - HowFastFlaskMiddleware.save_point = MagicMock() + HowFastFlaskMiddleware._save_point = MagicMock() # Prevent the background thread to actually start HowFastFlaskMiddleware.start_background_thread = MagicMock() return HowFastFlaskMiddleware @@ -33,25 +39,25 @@ def test_ok_without_dsn(HowFastFlaskMiddleware): """ The middleware should install on a Flask application even with no DSN """ app = create_app() # No DSN passed - HowFastFlaskMiddleware(app) + middleware = HowFastFlaskMiddleware(app) tester = app.test_client() response = tester.get('/') assert response.status_code == 200 - assert HowFastFlaskMiddleware.save_point.called is False + assert middleware._save_point.called is False def test_ok_with_dsn(HowFastFlaskMiddleware): """ The middleware should install on a Flask application """ app = create_app() - HowFastFlaskMiddleware(app, app_id='some-dsn') + middleware = HowFastFlaskMiddleware(app, app_id='some-dsn') tester = app.test_client() response = tester.get('/') assert response.status_code == 200 - assert HowFastFlaskMiddleware.save_point.called is True - assert HowFastFlaskMiddleware.save_point.call_count == 1 - point = HowFastFlaskMiddleware.save_point.call_args[1] + assert middleware._save_point.called is True + assert middleware._save_point.call_count == 1 + point = middleware._save_point.call_args[1] assert point.get('time_elapsed') > 0 assert point.get('time_request_started') < datetime.now(timezone.utc) assert point.get('method') == "GET" @@ -59,8 +65,8 @@ def test_ok_with_dsn(HowFastFlaskMiddleware): response = tester.post('/does-not-exist') assert response.status_code == 404 - assert HowFastFlaskMiddleware.save_point.call_count == 2 - point = HowFastFlaskMiddleware.save_point.call_args[1] + assert middleware._save_point.call_count == 2 + point = middleware._save_point.call_args[1] assert point.get('method') == "POST" assert point.get('uri') == "/does-not-exist" @@ -68,20 +74,20 @@ def test_ok_with_dsn(HowFastFlaskMiddleware): def test_with_path_parameter(HowFastFlaskMiddleware): """ Endpoints with a path parameter should be deduplicated """ app = create_app() - HowFastFlaskMiddleware(app, app_id='some-dsn') + middleware = HowFastFlaskMiddleware(app, app_id='some-dsn') tester = app.test_client() response = tester.get('/name/donald') assert response.status_code == 200 - assert HowFastFlaskMiddleware.save_point.call_count == 1 - point = HowFastFlaskMiddleware.save_point.call_args[1] + assert middleware._save_point.call_count == 1 + point = middleware._save_point.call_args[1] assert point.get('endpoint') == "names" def test_blacklist_option(HowFastFlaskMiddleware): """ URLs in the blacklist should not be tracked """ app = create_app() - HowFastFlaskMiddleware( + middleware = HowFastFlaskMiddleware( app, app_id='some-dsn', endpoints_blacklist=['/name/toto', '/name/test-*'], @@ -90,20 +96,38 @@ def test_blacklist_option(HowFastFlaskMiddleware): tester = app.test_client() response = tester.get('/name/toto') assert response.status_code == 200 - assert HowFastFlaskMiddleware.save_point.called is False + assert middleware._save_point.called is False # Matching with patterns response = tester.get('/name/test-34abc') assert response.status_code == 200 - assert HowFastFlaskMiddleware.save_point.called is False + assert middleware._save_point.called is False -def test_interactions_option(HowFastFlaskMiddleware): +@patch('requests.put') +def test_interactions_option(put_mocked, HowFastFlaskMiddleware): """ The record_interactions parameter should be accepted """ + from howfast_apm import HowFastFlaskMiddleware app = create_app() - HowFastFlaskMiddleware( + middleware = HowFastFlaskMiddleware( app, app_id='some-dsn', record_interactions=True, ) - # TODO: write assertions + + tester = app.test_client() + response = tester.get('/external-call') + assert response.status_code == 200 + assert put_mocked.called is True + assert middleware._save_point.called is True + + # This assumes that _save_point is static and is not responsible for emptying the list of + # interactions... + assert len(middleware.interactions + ) == 0, "after the point is saved, the interaction list should be empty for the next point" + + point = middleware._save_point.call_args[1] + assert len(point.get('interactions')) == 1 + [interaction] = point['interactions'] + assert interaction.type == 'request' + assert interaction.name == 'https://do-not-exists/' diff --git a/tests/test_runner.py b/tests/test_runner.py index bd90628..d0bf1d0 100644 --- a/tests/test_runner.py +++ b/tests/test_runner.py @@ -1,4 +1,4 @@ -from unittest.mock import patch, MagicMock +from unittest.mock import patch from howfast_apm.queue import Runner @@ -80,12 +80,15 @@ def test_send_batch(mocked_post, queue_full): # queue_full has 10 elements assert len(points) == 10 assert isinstance(points[0], tuple) - assert len(points[0]) == 5 - assert len(points[1]) == 5 + assert len(points[0]) == 6 + assert len(points[1]) == 6 # Make sure we have the correct point - (method, uri, time_request_started, elapsed, endpoint) = points[0] + (method, uri, time_request_started, elapsed, endpoint, interactions) = points[0] assert method == 'PUT' assert uri == '/call/1' + assert len(interactions) == 1 + assert interactions[0].type == 'request' + assert interactions[0].name == 'https://www.example.org/req1' @patch('requests.post') From 7c26bcecc99285b1d24b55613bd19a6ca66ac672 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micka=C3=ABl=20Bergem?= Date: Fri, 13 Sep 2019 18:39:07 -0700 Subject: [PATCH 4/6] Queue items as Dict --- howfast_apm/core.py | 37 +++++++++++++++++----------------- howfast_apm/queue.py | 4 ++-- tests/test_middleware_flask.py | 4 ++-- 3 files changed, 22 insertions(+), 23 deletions(-) diff --git a/howfast_apm/core.py b/howfast_apm/core.py index 7487b53..291738d 100644 --- a/howfast_apm/core.py +++ b/howfast_apm/core.py @@ -64,7 +64,14 @@ def record_interaction(self, interaction: Interaction) -> None: def reset_interactions(self): self.interactions = [] - def save_point(self, **kwargs) -> None: + def save_point( + self, + time_request_started: datetime, + time_elapsed: float, # seconds + method: str, + uri: str, + endpoint: str = None, # function name handling the request + ) -> None: """ Save a request/response performance information. @@ -72,35 +79,27 @@ def save_point(self, **kwargs) -> None: the core-level collected performance data (interactions) and call self._save_point(). """ self._save_point( + time_request_started=time_request_started, + time_elapsed=time_elapsed, + method=method, + uri=uri, + endpoint=endpoint, interactions=self.interactions, - **kwargs, ) # Reset the list of interactions, since it's specific to a request/point self.interactions = [] @staticmethod - def _save_point( - time_request_started: datetime, - time_elapsed: float, # seconds - method: str, - uri: str, - endpoint: str = None, # function name handling the request - interactions: List[Interaction] = None, - ) -> None: + def _save_point(**kwargs) -> None: """ Save a request/response performance information """ interaction_list = [] - while interactions: # catches "empty list" and None value + interactions = kwargs.get('interactions', []) + while interactions: interaction_list.append(interactions.pop().serialize()) - item = ( - time_request_started, - time_elapsed, - method, - uri, - endpoint, - interaction_list, - ) + # Forward the arguments to the queue + item = kwargs # Capped queue pushed = False diff --git a/howfast_apm/queue.py b/howfast_apm/queue.py index 3500935..929d341 100644 --- a/howfast_apm/queue.py +++ b/howfast_apm/queue.py @@ -1,7 +1,7 @@ import requests from logging import getLogger from threading import Thread -from typing import List +from typing import List, Dict, Any from queue import Queue, Empty from .config import HOWFAST_APM_COLLECTOR_URL @@ -26,7 +26,7 @@ class Runner(Thread): batch_size = 100 # Local list of the points to be sent to the API - current_batch: List[tuple] + current_batch: List[Dict[str, Any]] def __init__(self, queue: Queue, app_id: str): self.queue = queue diff --git a/tests/test_middleware_flask.py b/tests/test_middleware_flask.py index 9a11b50..0a46fe3 100644 --- a/tests/test_middleware_flask.py +++ b/tests/test_middleware_flask.py @@ -123,8 +123,8 @@ def test_interactions_option(put_mocked, HowFastFlaskMiddleware): # This assumes that _save_point is static and is not responsible for emptying the list of # interactions... - assert len(middleware.interactions - ) == 0, "after the point is saved, the interaction list should be empty for the next point" + assert len(middleware.interactions) == 0, \ + "after the point is saved, the interaction list should be empty for the next point" point = middleware._save_point.call_args[1] assert len(point.get('interactions')) == 1 From f4bca6062a1bd2cceea21f485182666e67c4343d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micka=C3=ABl=20Bergem?= Date: Fri, 13 Sep 2019 18:55:47 -0700 Subject: [PATCH 5/6] Install pytest-watch explicitely --- poetry.lock | 59 +++++++++++++++++++++++++++++++++++++++++++++-- pyproject.toml | 1 + tests/conftest.py | 2 +- 3 files changed, 59 insertions(+), 3 deletions(-) diff --git a/poetry.lock b/poetry.lock index 5ec2b18..168bba2 100644 --- a/poetry.lock +++ b/poetry.lock @@ -7,6 +7,14 @@ optional = false python-versions = "*" version = "0.1.0" +[[package]] +category = "dev" +description = "An unobtrusive argparse wrapper with natural syntax" +name = "argh" +optional = false +python-versions = "*" +version = "0.26.2" + [[package]] category = "dev" description = "Atomic file writes." @@ -67,7 +75,6 @@ version = "7.0" [[package]] category = "dev" description = "Cross-platform colored terminal text." -marker = "python_version >= \"3.4\" and sys_platform == \"win32\" or sys_platform == \"win32\"" name = "colorama" optional = false python-versions = ">=2.7, !=3.0.*, !=3.1.*, !=3.2.*, !=3.3.*" @@ -310,6 +317,14 @@ optional = false python-versions = "*" version = "0.5.1" +[[package]] +category = "dev" +description = "File system general utilities" +name = "pathtools" +optional = false +python-versions = "*" +version = "0.1.2" + [[package]] category = "dev" description = "Pexpect allows easy control of interactive console applications." @@ -427,6 +442,28 @@ wcwidth = "*" python = "<3.8" version = ">=0.12" +[[package]] +category = "dev" +description = "Local continuous test runner with pytest and watchdog." +name = "pytest-watch" +optional = false +python-versions = "*" +version = "4.2.0" + +[package.dependencies] +colorama = ">=0.3.3" +docopt = ">=0.4.0" +pytest = ">=2.6.4" +watchdog = ">=0.6.0" + +[[package]] +category = "dev" +description = "YAML parser and emitter for Python" +name = "pyyaml" +optional = false +python-versions = ">=2.7, !=3.0.*, !=3.1.*, !=3.2.*, !=3.3.*" +version = "5.1.2" + [[package]] category = "main" description = "Python HTTP for Humans." @@ -498,6 +535,19 @@ optional = false python-versions = ">=2.7, !=3.0.*, !=3.1.*, !=3.2.*, !=3.3.*, <4" version = "1.25.3" +[[package]] +category = "dev" +description = "Filesystem events monitoring" +name = "watchdog" +optional = false +python-versions = "*" +version = "0.9.0" + +[package.dependencies] +PyYAML = ">=3.10" +argh = ">=0.24.1" +pathtools = ">=0.1.1" + [[package]] category = "dev" description = "Measures number of Terminal column cells of wide-character codes" @@ -537,11 +587,12 @@ more-itertools = "*" flask = ["flask", "blinker"] [metadata] -content-hash = "f127847afe59242d005ff1fb8e5680b207c1c6618aff75d81b13a7dff85dc9c7" +content-hash = "8496bd5bb9cab3d3564ebd155ec95414d4936deafe984cbcef545287429deaa9" python-versions = ">=3.6,<3.9" [metadata.hashes] appnope = ["5b26757dc6f79a3b7dc9fab95359328d5747fcb2409d331ea66d0272b90ab2a0", "8b995ffe925347a2138d7ac0fe77155e4311a0ea6d6da4f5128fe4b3cbe5ed71"] +argh = ["a9b3aaa1904eeb78e32394cd46c6f37ac0fb4af6dc488daa58971bdc7d7fcaf3", "e9535b8c84dc9571a48999094fda7f33e63c3f1b74f3e5f3ac0105a58405bb65"] atomicwrites = ["03472c30eb2c5d1ba9227e4c2ca66ab8287fbfbbda3888aa93dc2e28fc6811b4", "75a9445bac02d8d058d5e1fe689654ba5a6556a1dfd8ce6ec55a0ed79866cfa6"] attrs = ["69c0dbf2ed392de1cb5ec704444b08a5ef81680a61cb899dc08127123af36a79", "f0b870f674851ecbfbbbd364d6b5cbdff9dcedbc7f3f5e18a6891057f21fe399"] backcall = ["38ecd85be2c1e78f77fd91700c76e14667dc21e2713b63876c0eb901196e01e4", "bbbf4b1e5cd2bdb08f915895b51081c041bac22394fdfcfdfbe9f14b77c08bf2"] @@ -572,6 +623,7 @@ mypy = ["0107bff4f46a289f0e4081d59b77cef1c48ea43da5a0dbf0005d54748b26df2a", "079 mypy-extensions = ["37e0e956f41369209a3d5f34580150bcacfabaa57b33a15c0b25f4b5725e0812", "b16cabe759f55e3409a7d231ebd2841378fb0c27a5d1994719e340e4f429ac3e"] packaging = ["a7ac867b97fdc07ee80a8058fe4435ccd274ecc3b0ed61d852d7d53055528cf9", "c491ca87294da7cc01902edbe30a5bc6c4c28172b5138ab4e4aa1b9d7bfaeafe"] parso = ["63854233e1fadb5da97f2744b6b24346d2750b85965e7e399bec1620232797dc", "666b0ee4a7a1220f65d367617f2cd3ffddff3e205f3f16a0284df30e774c2a9c"] +pathtools = ["7c35c5421a39bb82e58018febd90e3b6e5db34c5443aaaf742b3f33d4655f1c0"] pexpect = ["2094eefdfcf37a1fdbfb9aa090862c1a4878e5c7e0e7e7088bdb511c558e5cd1", "9e2c1fd0e6ee3a49b28f95d4b33bc389c89b20af6a1255906e90ff1262ce62eb"] pickleshare = ["87683d47965c1da65cdacaf31c8441d12b8044cdec9aca500cd78fc2c683afca", "9649af414d74d4df115d5d718f82acb59c9d418196b7b4290ed47a12ce62df56"] pluggy = ["0825a152ac059776623854c1543d65a4ad408eb3d33ee114dff91e57ec6ae6fc", "b9817417e95936bf75d85d3f8767f7df6cdde751fc40aed3bb3074cbcb77757c"] @@ -583,6 +635,8 @@ pyflakes = ["17dbeb2e3f4d772725c777fabc446d5634d1038f234e77343108ce445ea69ce0", pygments = ["71e430bc85c88a430f000ac1d9b331d2407f681d6f6aec95e8bcfbc3df5b0127", "881c4c157e45f30af185c1ffe8d549d48ac9127433f2c380c24b84572ad66297"] pyparsing = ["6f98a7b9397e206d78cc01df10131398f1c8b8510a2f4d97d9abd82e1aacdd80", "d9338df12903bbf5d65a0e4e87c2161968b10d2e489652bb47001d82a9b028b4"] pytest = ["95d13143cc14174ca1a01ec68e84d76ba5d9d493ac02716fd9706c949a505210", "b78fe2881323bd44fd9bd76e5317173d4316577e7b1cddebae9136a4495ec865"] +pytest-watch = ["06136f03d5b361718b8d0d234042f7b2f203910d8568f63df2f866b547b3d4b9"] +pyyaml = ["0113bc0ec2ad727182326b61326afa3d1d8280ae1122493553fd6f4397f33df9", "01adf0b6c6f61bd11af6e10ca52b7d4057dd0be0343eb9283c878cf3af56aee4", "5124373960b0b3f4aa7df1707e63e9f109b5263eca5976c66e08b1c552d4eaf8", "5ca4f10adbddae56d824b2c09668e91219bb178a1eee1faa56af6f99f11bf696", "7907be34ffa3c5a32b60b95f4d95ea25361c951383a894fec31be7252b2b6f34", "7ec9b2a4ed5cad025c2278a1e6a19c011c80a3caaac804fd2d329e9cc2c287c9", "87ae4c829bb25b9fe99cf71fbb2140c448f534e24c998cc60f39ae4f94396a73", "9de9919becc9cc2ff03637872a440195ac4241c80536632fffeb6a1e25a74299", "a5a85b10e450c66b49f98846937e8cfca1db3127a9d5d1e31ca45c3d0bef4c5b", "b0997827b4f6a7c286c01c5f60384d218dca4ed7d9efa945c3e1aa623d5709ae", "b631ef96d3222e62861443cc89d6563ba3eeb816eeb96b2629345ab795e53681", "bf47c0607522fdbca6c9e817a6e81b08491de50f3766a7a0e6a5be7905961b41", "f81025eddd0327c7d4cfe9b62cf33190e1e736cc6e97502b3ec425f574b3e7a8"] requests = ["11e007a8a2aa0323f5a921e9e6a2d7e4e67d9877e85773fba9ba6419025cbeb4", "9cf5292fcd0f598c671cfc1e0d7d1a7f13bb8085e9a590f48c010551dc6c4b31"] six = ["3350809f0555b11f552448330d0b52d5f24c91a322ea4a15ef22629740f3761c", "d16a0141ec1a18405cd4ce8b4613101da75da0e9a7aec5bdd4fa804d0e0eba73"] traitlets = ["9c4bd2d267b7153df9152698efb1050a5d84982d3384a37b2c1f7723ba3e7835", "c6cb5e6f57c5a9bdaa40fa71ce7b4af30298fbab9ece9815b5d995ab6217c7d9"] @@ -590,6 +644,7 @@ typed-ast = ["18511a0b3e7922276346bcb47e2ef9f38fb90fd31cb9223eed42c85d1312344e", typing = ["91dfe6f3f706ee8cc32d38edbbf304e9b7583fb37108fef38229617f8b3eba23", "c8cabb5ab8945cd2f54917be357d134db9cc1eb039e59d1606dc1e60cb1d9d36", "f38d83c5a7a7086543a0f649564d661859c5146a85775ab90c0d2f93ffaa9714"] typing-extensions = ["2ed632b30bb54fc3941c382decfd0ee4148f5c591651c9272473fea2c6397d95", "b1edbbf0652660e32ae780ac9433f4231e7339c7f9a8057d0f042fcbcea49b87", "d8179012ec2c620d3791ca6fe2bf7979d979acdbef1fca0bc56b37411db682ed"] urllib3 = ["b246607a25ac80bedac05c6f282e3cdaf3afb65420fd024ac94435cabe6e18d1", "dbe59173209418ae49d485b87d1681aefa36252ee85884c31346debd19463232"] +watchdog = ["965f658d0732de3188211932aeb0bb457587f04f63ab4c1e33eab878e9de961d"] wcwidth = ["3df37372226d6e63e1b1e1eda15c594bca98a22d33a23832a90998faa96bc65e", "f4ebe71925af7b40a864553f761ed559b43544f8f71746c2d756c7fe788ade7c"] werkzeug = ["87ae4e5b5366da2347eb3116c0e6c681a0e939a33b2805e2c0cbd282664932c4", "a13b74dd3c45f758d4ebdb224be8f1ab8ef58b3c0ffc1783a8c7d9f4f50227e6"] yapf = ["02ace10a00fa2e36c7ebd1df2ead91dbfbd7989686dc4ccbdc549e95d19f5780", "6f94b6a176a7c114cfa6bad86d40f259bbe0f10cf2fa7f2f4b3596fc5802a41b"] diff --git a/pyproject.toml b/pyproject.toml index 7da87d2..6d3dc94 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -39,6 +39,7 @@ yapf = "^0.28.0" mypy = "^0.720.0" coveralls = "^1.8" ipdb = "^0.12.2" +pytest-watch = "^4.2" [tool.poetry.extras] flask = ["flask", "blinker"] diff --git a/tests/conftest.py b/tests/conftest.py index ffbf23a..7ae1ac9 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -1,7 +1,7 @@ import pytest from datetime import datetime, timezone from queue import Queue -# TODO: pytest refuses to start when this line is present :/ + from howfast_apm.hook_requests import Interaction From 0f08f83c9dd5d2a8d6ad02b705a1735e504a6367 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micka=C3=ABl=20Bergem?= Date: Fri, 13 Sep 2019 19:05:03 -0700 Subject: [PATCH 6/6] Clean code --- howfast_apm/hook_requests.py | 8 ++++---- tests/test_middleware_flask.py | 4 ++-- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/howfast_apm/hook_requests.py b/howfast_apm/hook_requests.py index 18227f5..66f30f3 100644 --- a/howfast_apm/hook_requests.py +++ b/howfast_apm/hook_requests.py @@ -42,7 +42,7 @@ def install_hooks(record_interaction: Callable[[Interaction], Any]) -> None: # Maybe requests is not installed / available in the instrumented code patch_requests_module = False - urllib = sys.modules['urllib'] + tmp_urllib = sys.modules['urllib'] if patch_requests_module: tmp_requests = sys.modules['requests'] @@ -72,11 +72,11 @@ def patched_request(*args, **kwargs): return patched_request # TODO: build method extractor for urlopen - urllib.request.urlopen = get_patched( - urllib.request.urlopen, + tmp_urllib.request.urlopen = get_patched( + tmp_urllib.request.urlopen, lambda *args, **kwargs: [None, None], ) - sys.modules['urllib'] = urllib + sys.modules['urllib'] = tmp_urllib if patch_requests_module: tmp_requests.request = get_patched( diff --git a/tests/test_middleware_flask.py b/tests/test_middleware_flask.py index 0a46fe3..284a828 100644 --- a/tests/test_middleware_flask.py +++ b/tests/test_middleware_flask.py @@ -19,7 +19,7 @@ def names(name): @app.route('/external-call') def external_call(): - requests.put('https://do-not-exists/') + requests.put('https://does-not-exist/') return 'ok' return app @@ -130,4 +130,4 @@ def test_interactions_option(put_mocked, HowFastFlaskMiddleware): assert len(point.get('interactions')) == 1 [interaction] = point['interactions'] assert interaction.type == 'request' - assert interaction.name == 'https://do-not-exists/' + assert interaction.name == 'https://does-not-exist/'