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

@@ -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]

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,

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):
         """

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

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:

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)

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')

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/*',)