diff --git a/CHANGELOG.asciidoc b/CHANGELOG.asciidoc index b28cd0d85..f61926e9d 100644 --- a/CHANGELOG.asciidoc +++ b/CHANGELOG.asciidoc @@ -14,6 +14,7 @@ https://github.com/elastic/apm-agent-python/compare/v2.0.1\...master[Check the H * made skipping of initial `elasticapm` frames for span stack traces more generic ({pull}167[#167]) * added `context.process.ppid` field (supported in apm-server 6.3+) ({pull}168[#168]) + * added option to disable stack frame collection for very short spans ({pull}142[#142]) [[release-2.0.1]] [float] diff --git a/docs/configuration.asciidoc b/docs/configuration.asciidoc index ad7650323..2d296286c 100644 --- a/docs/configuration.asciidoc +++ b/docs/configuration.asciidoc @@ -368,6 +368,24 @@ Limits the amount of spans that are recorded per transaction. This is helpful in cases where a transaction creates a very high amount of spans (e.g. thousands of SQL queries). Setting an upper limit will prevent overloading the agent and the APM server with too much work for such edge cases. +[float] +[[config-span-frames-min-duration-ms]] +==== `span_frames_min_duration_ms` + +|============ +| Environment | Django/Flask | Default +| `ELASTIC_APM_SPAN_FRAMES_MIN_DURATION_MS` | `SPAN_FRAMES_MIN_DURATION_MS` | `-1` +|============ + +In its default settings, the APM agent will collect a stack trace with every recorded span. +While this is very helpful to find the exact place in your code that causes the span, +collecting this stack trace does have some overhead. + +With the default setting, `-1`, stack traces will be collected for all spans. +Setting it to a positive value, e.g. `5`, will limit stack trace collection to spans +with durations equal or longer than the given value in milliseconds, e.g. 5 milliseconds. + +To disable stack trace collection for spans completely, set the value to 0. [float] [[config-max-queue-size]] diff --git a/docs/tuning.asciidoc b/docs/tuning.asciidoc index 7cb9c4bac..21ace2f60 100644 --- a/docs/tuning.asciidoc +++ b/docs/tuning.asciidoc @@ -73,3 +73,11 @@ In some cases however, the number of spans can explode: To avoid that such edge cases overload both the agent and the APM Server, the agent stops recording spans when a limit is reached. You can configure this limit by changing the <> setting. + +Another option to reduce overhead of collecting contextual data for spans is to disable collection for very short spans. +While this contextual data (specifically, the stack trace) can be very useful to pinpoint where exectly the span is caused in your code, +it is less interesting for very short spans. +You can define a minimal threshold for span duration in milliseconds, +using the <> setting. +If a span takes less than this duration, no stack frames will be collected for this span. +Other contextual information, like the SQL query, will still be available. diff --git a/elasticapm/base.py b/elasticapm/base.py index a0fcba463..a96350258 100644 --- a/elasticapm/base.py +++ b/elasticapm/base.py @@ -154,6 +154,7 @@ def frames_collector_func(): collect_frequency=self.config.flush_interval, sample_rate=self.config.transaction_sample_rate, max_spans=self.config.transaction_max_spans, + span_frames_min_duration=self.config.span_frames_min_duration_ms, max_queue_size=self.config.max_queue_size, ignore_patterns=self.config.transactions_ignore_patterns, ) diff --git a/elasticapm/conf/__init__.py b/elasticapm/conf/__init__.py index d6f206b2e..bcda125ae 100644 --- a/elasticapm/conf/__init__.py +++ b/elasticapm/conf/__init__.py @@ -158,6 +158,7 @@ class Config(_ConfigBase): flush_interval = _ConfigValue('FLUSH_INTERVAL', type=int, default=10) transaction_sample_rate = _ConfigValue('TRANSACTION_SAMPLE_RATE', type=float, default=1.0) transaction_max_spans = _ConfigValue('TRANSACTION_MAX_SPANS', type=int, default=500) + span_frames_min_duration_ms = _ConfigValue('SPAN_FRAMES_MIN_DURATION', default=5, type=int) max_queue_size = _ConfigValue('MAX_QUEUE_SIZE', type=int, default=500) collect_local_variables = _ConfigValue('COLLECT_LOCAL_VARIABLES', default='errors') source_lines_error_app_frames = _ConfigValue('SOURCE_LINES_ERROR_APP_FRAMES', type=int, default=5) diff --git a/elasticapm/traces.py b/elasticapm/traces.py index 7bf5e2627..094a7df93 100644 --- a/elasticapm/traces.py +++ b/elasticapm/traces.py @@ -42,7 +42,8 @@ def get_transaction(clear=False): class Transaction(object): - def __init__(self, frames_collector_func, transaction_type="custom", is_sampled=True, max_spans=None): + def __init__(self, frames_collector_func, transaction_type="custom", is_sampled=True, max_spans=None, + span_frames_min_duration=None): self.id = str(uuid.uuid4()) self.timestamp = datetime.datetime.utcnow() self.start_time = _time_func() @@ -55,6 +56,7 @@ def __init__(self, frames_collector_func, transaction_type="custom", is_sampled= self.spans = [] self.span_stack = [] self.max_spans = max_spans + self.span_frames_min_duration = span_frames_min_duration self.dropped_spans = 0 self.ignore_subtree = False self.context = {} @@ -103,7 +105,8 @@ def end_span(self, skip_frames): if self.span_stack: span.parent = self.span_stack[-1].idx - span.frames = self._frames_collector_func()[skip_frames:] + if not self.span_frames_min_duration or span.duration >= self.span_frames_min_duration: + span.frames = self._frames_collector_func()[skip_frames:] self.spans.append(span) return span @@ -129,8 +132,9 @@ def to_dict(self): class Span(object): - def __init__(self, idx, name, span_type, start_time, context=None, - leaf=False): + __slots__ = ('idx', 'name', 'type', 'context', 'leaf', 'start_time', 'duration', 'parent', 'frames') + + def __init__(self, idx, name, span_type, start_time, context=None, leaf=False): """ Create a new Span @@ -148,14 +152,9 @@ def __init__(self, idx, name, span_type, start_time, context=None, self.leaf = leaf self.start_time = start_time self.duration = None - self.transaction = None self.parent = None self.frames = None - @property - def fingerprint(self): - return self.transaction, self.parent, self.name, self.type - def to_dict(self): return { 'id': self.idx, @@ -171,7 +170,7 @@ def to_dict(self): class TransactionsStore(object): def __init__(self, frames_collector_func, collect_frequency, sample_rate=1.0, max_spans=0, max_queue_size=None, - ignore_patterns=None): + span_frames_min_duration=None, ignore_patterns=None): self.cond = threading.Condition() self.collect_frequency = collect_frequency self.max_queue_size = max_queue_size @@ -181,6 +180,11 @@ def __init__(self, frames_collector_func, collect_frequency, sample_rate=1.0, ma self._last_collect = _time_func() self._ignore_patterns = [re.compile(p) for p in ignore_patterns or []] self._sample_rate = sample_rate + if span_frames_min_duration in (-1, None): + # both None and -1 mean "no minimum" + self.span_frames_min_duration = None + else: + self.span_frames_min_duration = span_frames_min_duration / 1000.0 def add_transaction(self, transaction): with self.cond: @@ -212,7 +216,7 @@ def begin_transaction(self, transaction_type): """ is_sampled = self._sample_rate == 1.0 or self._sample_rate > random.random() transaction = Transaction(self._frames_collector_func, transaction_type, max_spans=self.max_spans, - is_sampled=is_sampled) + span_frames_min_duration=self.span_frames_min_duration, is_sampled=is_sampled) thread_local.transaction = transaction return transaction diff --git a/tests/client/client_tests.py b/tests/client/client_tests.py index 0493782f1..c30a26679 100644 --- a/tests/client/client_tests.py +++ b/tests/client/client_tests.py @@ -663,6 +663,50 @@ def test_transaction_max_spans(should_collect, elasticapm_client): assert transaction['span_count'] == {'dropped': {'total': 10}} +@pytest.mark.parametrize('elasticapm_client', [{'span_frames_min_duration_ms': 20}], indirect=True) +@mock.patch('elasticapm.base.TransactionsStore.should_collect') +def test_transaction_span_frames_min_duration(should_collect, elasticapm_client): + should_collect.return_value = False + elasticapm_client.begin_transaction('test_type') + with elasticapm.capture_span('noframes'): + time.sleep(0.001) + with elasticapm.capture_span('frames'): + time.sleep(0.040) + elasticapm_client.end_transaction('test') + + transaction = elasticapm_client.instrumentation_store.get_all()[0] + spans = transaction['spans'] + + assert len(spans) == 2 + assert spans[0]['name'] == 'noframes' + assert spans[0]['stacktrace'] is None + + assert spans[1]['name'] == 'frames' + assert spans[1]['stacktrace'] is not None + + +@pytest.mark.parametrize('elasticapm_client', [{'span_frames_min_durarion_ms': -1}], indirect=True) +@mock.patch('elasticapm.base.TransactionsStore.should_collect') +def test_transaction_span_frames_min_duration_no_limit(should_collect, elasticapm_client): + should_collect.return_value = False + elasticapm_client.begin_transaction('test_type') + with elasticapm.capture_span('frames'): + pass + with elasticapm.capture_span('frames'): + time.sleep(0.040) + elasticapm_client.end_transaction('test') + + transaction = elasticapm_client.instrumentation_store.get_all()[0] + spans = transaction['spans'] + + assert len(spans) == 2 + assert spans[0]['name'] == 'frames' + assert spans[0]['stacktrace'] is not None + + assert spans[1]['name'] == 'frames' + assert spans[1]['stacktrace'] is not None + + @pytest.mark.parametrize('elasticapm_client', [{'transaction_max_spans': 3}], indirect=True) @mock.patch('elasticapm.base.TransactionsStore.should_collect') def test_transaction_max_span_nested(should_collect, elasticapm_client): diff --git a/tests/contrib/django/fixtures.py b/tests/contrib/django/fixtures.py index 660ce43ce..4c9fb6010 100644 --- a/tests/contrib/django/fixtures.py +++ b/tests/contrib/django/fixtures.py @@ -18,6 +18,9 @@ def send(self, url, **kwargs): @pytest.fixture() def django_elasticapm_client(request): client_config = getattr(request, 'param', {}) + client_config.setdefault('service_name', 'app') + client_config.setdefault('secret_token', 'secret') + client_config.setdefault('span_frames_min_duration_ms', -1) app = apps.get_app_config('elasticapm.contrib.django') old_client = app.client client = TempStoreClient(**client_config) @@ -41,6 +44,7 @@ def django_sending_elasticapm_client(request, validating_httpserver): client_config.setdefault('service_name', 'app') client_config.setdefault('secret_token', 'secret') client_config.setdefault('transport_class', 'elasticapm.transport.http.Transport') + client_config.setdefault('span_frames_min_duration_ms', -1) app = apps.get_app_config('elasticapm.contrib.django') old_client = app.client client = DjangoClient(**client_config) diff --git a/tests/fixtures.py b/tests/fixtures.py index 148016730..72772fa66 100644 --- a/tests/fixtures.py +++ b/tests/fixtures.py @@ -72,6 +72,7 @@ def elasticapm_client(request): client_config.setdefault('service_name', 'myapp') client_config.setdefault('secret_token', 'test_key') client_config.setdefault('include_paths', ('*/tests/*',)) + client_config.setdefault('span_frames_min_duration_ms', -1) client = TempStoreClient(**client_config) yield client client.close() @@ -93,6 +94,7 @@ def sending_elasticapm_client(request, validating_httpserver): client_config.setdefault('service_name', 'myapp') client_config.setdefault('secret_token', 'test_key') client_config.setdefault('transport_class', 'elasticapm.transport.http.Transport') + client_config.setdefault('span_frames_min_duration_ms', -1) client_config.setdefault('include_paths', ('*/tests/*',)) client = Client(**client_config) client.httpserver = validating_httpserver