From 3d68d1a92c22a1c054bd4e6edc43008a9c6ed9a2 Mon Sep 17 00:00:00 2001 From: Benjamin Wohlwend Date: Wed, 21 Feb 2018 16:33:28 +0100 Subject: [PATCH] ignore elasticapm frames from frame collection logic for spans (#167) this should clean up the collected stack traces quite a bit Note, for Django this has been done a bit differently, this specialization has been removed. closes #167 --- CHANGELOG.asciidoc | 9 +++++---- elasticapm/base.py | 11 +++++++---- elasticapm/contrib/django/client.py | 11 +---------- elasticapm/utils/stacks.py | 25 ++++++++++++++++++++++--- tests/client/client_tests.py | 6 +++--- tests/contrib/django/django_tests.py | 2 +- tests/instrumentation/base_tests.py | 10 ++++++++++ tests/utils/stacks/tests.py | 27 +++++++++++++++++++++++++++ 8 files changed, 76 insertions(+), 25 deletions(-) diff --git a/CHANGELOG.asciidoc b/CHANGELOG.asciidoc index 6760be953..618223a36 100644 --- a/CHANGELOG.asciidoc +++ b/CHANGELOG.asciidoc @@ -7,11 +7,12 @@ == Changelog -//[[release-next]] -//[float] -//=== Unreleased -//https://github.com/elastic/apm-agent-python/compare/v2.0.1\...master[Check the HEAD diff] +[[release-next]] +[float] +=== Unreleased +https://github.com/elastic/apm-agent-python/compare/v2.0.1\...master[Check the HEAD diff] + * made skipping of initial `elasticapm` frames for span stack traces more generic ({pull}167[#167]) [[release-2.0.1]] [float] diff --git a/elasticapm/base.py b/elasticapm/base.py index 2aec7c865..5a7a20932 100644 --- a/elasticapm/base.py +++ b/elasticapm/base.py @@ -129,9 +129,9 @@ def __init__(self, config=None, **defaults): self.processors = [import_string(p) for p in self.config.processors] if self.config.processors else [] - self.instrumentation_store = TransactionsStore( - lambda: self._get_stack_info_for_trace( - stacks.iter_stack_frames(), + def frames_collector_func(): + return self._get_stack_info_for_trace( + stacks.iter_stack_frames(skip_top_modules=('elasticapm.',)), library_frame_context_lines=self.config.source_lines_span_library_frames, in_app_frame_context_lines=self.config.source_lines_span_app_frames, with_locals=self.config.collect_local_variables in ('all', 'transactions'), @@ -140,7 +140,10 @@ def __init__(self, config=None, **defaults): list_length=self.config.local_var_list_max_length, string_length=self.config.local_var_max_length, ), local_var) - ), + ) + + self.instrumentation_store = TransactionsStore( + frames_collector_func=frames_collector_func, collect_frequency=self.config.flush_interval, sample_rate=self.config.transaction_sample_rate, max_spans=self.config.transaction_max_spans, diff --git a/elasticapm/contrib/django/client.py b/elasticapm/contrib/django/client.py index 82e4d3817..0252ee1f4 100644 --- a/elasticapm/contrib/django/client.py +++ b/elasticapm/contrib/django/client.py @@ -179,7 +179,7 @@ def _get_stack_info_for_trace(self, frames, locals_processor_func=None): """If the stacktrace originates within the elasticapm module, it will skip frames until some other module comes up.""" - frames = list(iterate_with_template_sources( + return list(iterate_with_template_sources( frames, with_locals=with_locals, library_frame_context_lines=library_frame_context_lines, @@ -188,15 +188,6 @@ def _get_stack_info_for_trace(self, frames, exclude_paths_re=self.exclude_paths_re, locals_processor_func=locals_processor_func, )) - i = 0 - while len(frames) > i: - if 'module' in frames[i] and not ( - frames[i]['module'].startswith('elasticapm.') or - frames[i]['module'] == 'contextlib' - ): - return frames[i:] - i += 1 - return frames def send(self, url, **kwargs): """ diff --git a/elasticapm/utils/stacks.py b/elasticapm/utils/stacks.py index c2117ebc7..a40e4ad03 100644 --- a/elasticapm/utils/stacks.py +++ b/elasticapm/utils/stacks.py @@ -147,24 +147,43 @@ def iter_traceback_frames(tb): while tb: # support for __traceback_hide__ which is used by a few libraries # to hide internal frames. - f_locals = getattr(tb.tb_frame, 'f_locals', {}) + frame = tb.tb_frame + f_locals = getattr(frame, 'f_locals', {}) if not _getitem_from_frame(f_locals, '__traceback_hide__'): - yield tb.tb_frame, getattr(tb, 'tb_lineno', None) + yield frame, getattr(tb, 'tb_lineno', None) tb = tb.tb_next -def iter_stack_frames(frames=None, skip=0): +def iter_stack_frames(frames=None, skip=0, skip_top_modules=()): """ Given an optional list of frames (defaults to current stack), iterates over all frames that do not contain the ``__traceback_hide__`` local variable. + + Frames can be skipped by either providing a number, or a tuple + of module names. If the module of a frame matches one of the names + (using `.startswith`, that frame will be skipped. This matching will only + be done until the first frame doesn't match. + + This is useful to filter out frames that are caused by frame collection + itself. + + :param frames: a list of frames, or None + :param skip: number of frames to skip from the beginning + :param skip_top_modules: tuple of strings + """ if not frames: frame = inspect.currentframe().f_back frames = _walk_stack(frame) + stop_ignoring = False for i, frame in enumerate(frames): if i < skip: continue + f_globals = getattr(frame, 'f_globals', {}) + if not stop_ignoring and f_globals.get('__name__', '').startswith(skip_top_modules): + continue + stop_ignoring = True f_locals = getattr(frame, 'f_locals', {}) if not _getitem_from_frame(f_locals, '__traceback_hide__'): yield frame, frame.f_lineno diff --git a/tests/client/client_tests.py b/tests/client/client_tests.py index 11aebc6d4..e3f659e51 100644 --- a/tests/client/client_tests.py +++ b/tests/client/client_tests.py @@ -552,7 +552,7 @@ def test_collect_local_variables_transactions(should_collect, elasticapm_client) pass elasticapm_client.end_transaction('test', 'ok') transaction = elasticapm_client.instrumentation_store.get_all()[0] - frame = transaction['spans'][0]['stacktrace'][5] + frame = transaction['spans'][0]['stacktrace'][0] if mode in ('transactions', 'all'): assert 'vars' in frame, mode assert frame['vars']['a_local_var'] == 1 @@ -578,8 +578,8 @@ def test_collect_source_transactions(should_collect, elasticapm_client): pass elasticapm_client.end_transaction('test', 'ok') transaction = elasticapm_client.instrumentation_store.get_all()[0] - in_app_frame = transaction['spans'][0]['stacktrace'][5] - library_frame = transaction['spans'][0]['stacktrace'][6] + in_app_frame = transaction['spans'][0]['stacktrace'][0] + library_frame = transaction['spans'][0]['stacktrace'][1] assert not in_app_frame['library_frame'] assert library_frame['library_frame'] if library_frame_context: diff --git a/tests/contrib/django/django_tests.py b/tests/contrib/django/django_tests.py index 1c6c15b07..f2cf3a611 100644 --- a/tests/contrib/django/django_tests.py +++ b/tests/contrib/django/django_tests.py @@ -966,7 +966,7 @@ def test_stacktrace_filtered_for_elasticapm(client, django_elasticapm_client): assert spans[1]['name'] == 'list_users.html' # Top frame should be inside django rendering - assert spans[1]['stacktrace'][0]['module'].startswith('django.template') + assert spans[1]['stacktrace'][0]['module'].startswith('django.template'), spans[1]['stacktrace'][0]['function'] @pytest.mark.parametrize('django_elasticapm_client', [{'_wait_to_first_send': 100}], indirect=True) diff --git a/tests/instrumentation/base_tests.py b/tests/instrumentation/base_tests.py index 89f1b02d0..c10e08f0d 100644 --- a/tests/instrumentation/base_tests.py +++ b/tests/instrumentation/base_tests.py @@ -4,6 +4,7 @@ import mock import pytest +import elasticapm from elasticapm.instrumentation.packages.base import (AbstractInstrumentedModule, OriginalNamesBoundFunctionWrapper) from elasticapm.utils import compat @@ -79,3 +80,12 @@ def test_skip_instrument_env_var(): with mock.patch.dict('os.environ', {'SKIP_INSTRUMENT_TEST_DUMMY_INSTRUMENT': 'foo'}): instrumentation.instrument() assert not instrumentation.instrumented + + +def test_skip_ignored_frames(elasticapm_client): + elasticapm_client.begin_transaction('test') + with elasticapm.capture_span('test'): + pass + transaction = elasticapm_client.end_transaction('test', 'test') + for frame in transaction.spans[0].frames: + assert not frame['module'].startswith('elasticapm') diff --git a/tests/utils/stacks/tests.py b/tests/utils/stacks/tests.py index 7f6d43891..69cccdc84 100644 --- a/tests/utils/stacks/tests.py +++ b/tests/utils/stacks/tests.py @@ -78,6 +78,33 @@ def get_me_a_filtered_frame(hide=True): assert frames[0]['function'] == 'get_me_a_filtered_frame' +def test_iter_stack_frames_skip_frames(): + frames = [ + Mock(f_lineno=1, f_globals={}), + Mock(f_lineno=2, f_globals={}), + Mock(f_lineno=3, f_globals={}), + Mock(f_lineno=4, f_globals={}), + ] + + iterated_frames = list(stacks.iter_stack_frames(frames, skip=3)) + assert len(iterated_frames) == 1 + assert iterated_frames[0][1] == 4 + + +def test_iter_stack_frames_skip_frames_by_module(): + frames = [ + Mock(f_lineno=1, f_globals={'__name__': 'foo.bar'}), + Mock(f_lineno=2, f_globals={'__name__': 'foo.bar'}), + Mock(f_lineno=3, f_globals={'__name__': 'baz.bar'}), + Mock(f_lineno=4, f_globals={'__name__': 'foo.bar'}), + ] + + iterated_frames = list(stacks.iter_stack_frames(frames, skip_top_modules=('foo.',))) + assert len(iterated_frames) == 2 + assert iterated_frames[0][1] == 3 + assert iterated_frames[1][1] == 4 + + @pytest.mark.parametrize('elasticapm_client', [{ 'include_paths': ('/a/b/c/*', '/c/d/*'), 'exclude_paths': ('/c/*',)