diff --git a/.gitignore b/.gitignore index 12eae962b..f7c4ca041 100644 --- a/.gitignore +++ b/.gitignore @@ -14,6 +14,7 @@ pip-log.txt /build /cover /dist +.venv /example_project/local_settings.py /docs/html /docs/doctrees diff --git a/docs/reference/configuration.md b/docs/reference/configuration.md index cdc0c744e..366f5daac 100644 --- a/docs/reference/configuration.md +++ b/docs/reference/configuration.md @@ -610,6 +610,24 @@ if a span propagates distributed tracing IDs, it will not be ignored, even if it :::: +### `span_min_duration` [config-span-min-duration] + +[![dynamic config](images/dynamic-config.svg "") ](#dynamic-configuration) + +| Environment | Django/Flask | Default | +| --- | --- | --- | +| `ELASTIC_APM_SPAN_MIN_DURATION` | `SPAN_MIN_DURATION` | `"0ms"` | + +Spans shorter than this threshold can be ignored. This applies to successful spans in general. + +For leaf/exit spans, [`exit_span_min_duration`](#config-exit-span-min-duration) takes precedence when it is configured. + +This feature is disabled by default. + +::::{note} +If a span propagates distributed tracing IDs, it will not be ignored, even if it is shorter than the configured threshold. This is to ensure that no broken traces are recorded. +:::: + ### `api_request_size` [config-api-request-size] @@ -1086,4 +1104,3 @@ The *size* format is used for options like maximum buffer sizes. The unit is pro We use the power-of-two sizing convention, e.g. `1 kilobyte == 1024 bytes` :::: - diff --git a/docs/reference/performance-tuning.md b/docs/reference/performance-tuning.md index 6ff228baf..834a717a6 100644 --- a/docs/reference/performance-tuning.md +++ b/docs/reference/performance-tuning.md @@ -60,6 +60,8 @@ The average amount of spans per transaction can influence how much time the agen To avoid these edge cases overloading both the agent and the APM Server, the agent stops recording spans when a specified limit is reached. You can configure this limit by changing the [`transaction_max_spans`](/reference/configuration.md#config-transaction-max-spans) setting. +You can also ignore very short spans by configuring [`span_min_duration`](/reference/configuration.md#config-span-min-duration). If you only want to target leaf/exit spans, use [`exit_span_min_duration`](/reference/configuration.md#config-exit-span-min-duration). + ## Span Stack Trace Collection [tuning-span-stack-trace-collection] @@ -89,4 +91,3 @@ Reading source files inside a running application can cause a lot of disk I/O, a You can configure the Elastic APM agent to capture headers of both requests and responses ([`capture_headers`](/reference/configuration.md#config-capture-headers)), as well as request bodies ([`capture_body`](/reference/configuration.md#config-capture-body)). By default, capturing request bodies is disabled. Enabling it for transactions may introduce noticeable overhead, as well as increased storage use, depending on the nature of your POST requests. In most scenarios, we advise against enabling request body capturing for transactions, and only enable it if necessary for errors. Capturing request/response headers has less overhead on the agent, but can have an impact on storage use. If storage use is a problem for you, it might be worth disabling. - diff --git a/elasticapm/conf/__init__.py b/elasticapm/conf/__init__.py index f00a2cda9..9000c541b 100644 --- a/elasticapm/conf/__init__.py +++ b/elasticapm/conf/__init__.py @@ -678,6 +678,10 @@ class Config(_ConfigBase): "SPAN_COMPRESSION_SAME_KIND_MAX_DURATION", default=timedelta(seconds=0), ) + span_min_duration = _DurationConfigValue( + "SPAN_MIN_DURATION", + default=timedelta(seconds=0), + ) exit_span_min_duration = _DurationConfigValue( "EXIT_SPAN_MIN_DURATION", default=timedelta(seconds=0), diff --git a/elasticapm/traces.py b/elasticapm/traces.py index 929458d7a..9ca83e788 100644 --- a/elasticapm/traces.py +++ b/elasticapm/traces.py @@ -229,6 +229,7 @@ def __init__( self.config_span_compression_enabled = tracer.config.span_compression_enabled self.config_span_compression_exact_match_max_duration = tracer.config.span_compression_exact_match_max_duration self.config_span_compression_same_kind_max_duration = tracer.config.span_compression_same_kind_max_duration + self.config_span_min_duration = tracer.config.span_min_duration self.config_exit_span_min_duration = tracer.config.exit_span_min_duration self.config_transaction_max_spans = tracer.config.transaction_max_spans @@ -675,6 +676,16 @@ def is_compression_eligible(self) -> bool: def discardable(self) -> bool: return self.leaf and not self.dist_tracing_propagated and self.outcome == constants.OUTCOME.SUCCESS + @property + def duration_discardable(self) -> bool: + return not self.dist_tracing_propagated and self.outcome == constants.OUTCOME.SUCCESS + + @property + def min_duration(self) -> timedelta: + if self.leaf and self.transaction.config_exit_span_min_duration: + return self.transaction.config_exit_span_min_duration + return self.transaction.config_span_min_duration + def end(self, skip_frames: int = 0, duration: Optional[float] = None) -> None: """ End this span and queue it for sending. @@ -710,7 +721,7 @@ def end(self, skip_frames: int = 0, duration: Optional[float] = None) -> None: p.child_ended(self) def report(self) -> None: - if self.discardable and self.duration < self.transaction.config_exit_span_min_duration: + if self.duration_discardable and self.duration < self.min_duration: self.transaction.track_dropped_span(self) self.transaction.dropped_spans += 1 elif self._cancelled: diff --git a/tests/client/dropped_spans_tests.py b/tests/client/dropped_spans_tests.py index d7625ee28..2dfd6d5fb 100644 --- a/tests/client/dropped_spans_tests.py +++ b/tests/client/dropped_spans_tests.py @@ -154,6 +154,68 @@ def test_transaction_fast_exit_span(elasticapm_client): assert metrics[1]["samples"]["span.self_time.sum.us"]["value"] == 100 +@pytest.mark.parametrize("elasticapm_client", [{"span_min_duration": "1ms"}], indirect=True) +def test_transaction_fast_span(elasticapm_client): + elasticapm_client.begin_transaction("test_type") + with elasticapm.capture_span(span_type="x", name="x", leaf=False, duration=0.002): # not dropped, too long + pass + with elasticapm.capture_span(span_type="y", name="y", leaf=False, duration=0.0001): # dropped + pass + elasticapm_client.end_transaction("foo", duration=2.2) + transaction = elasticapm_client.events[constants.TRANSACTION][0] + spans = elasticapm_client.events[constants.SPAN] + assert len(spans) == 1 + assert spans[0]["name"] == "x" + assert transaction["span_count"]["started"] == 2 + assert transaction["span_count"]["dropped"] == 1 + + +@pytest.mark.parametrize( + "elasticapm_client", [{"span_min_duration": "10ms", "exit_span_min_duration": "1ms"}], indirect=True +) +def test_transaction_fast_span_exit_threshold_overrides(elasticapm_client): + elasticapm_client.begin_transaction("test_type") + with elasticapm.capture_span(span_type="x", name="leaf", leaf=True, duration=0.002): + pass + with elasticapm.capture_span(span_type="y", name="non-leaf", leaf=False, duration=0.002): + pass + elasticapm_client.end_transaction("foo", duration=2.2) + transaction = elasticapm_client.events[constants.TRANSACTION][0] + spans = elasticapm_client.events[constants.SPAN] + assert len(spans) == 1 + assert spans[0]["name"] == "leaf" + assert transaction["span_count"]["started"] == 2 + assert transaction["span_count"]["dropped"] == 1 + + +@pytest.mark.parametrize("elasticapm_client", [{"span_min_duration": "1ms"}], indirect=True) +def test_transaction_fast_span_not_dropped_on_failure(elasticapm_client): + elasticapm_client.begin_transaction("test_type") + with pytest.raises(ValueError): + with elasticapm.capture_span(span_type="x", name="x", leaf=False, duration=0.0001): + raise ValueError() + elasticapm_client.end_transaction("foo", duration=2.2) + transaction = elasticapm_client.events[constants.TRANSACTION][0] + spans = elasticapm_client.events[constants.SPAN] + assert len(spans) == 1 + assert spans[0]["outcome"] == constants.OUTCOME.FAILURE + assert transaction["span_count"]["started"] == 1 + assert transaction["span_count"]["dropped"] == 0 + + +@pytest.mark.parametrize("elasticapm_client", [{"span_min_duration": "1ms"}], indirect=True) +def test_transaction_fast_span_not_dropped_when_distributed_tracing_propagated(elasticapm_client): + elasticapm_client.begin_transaction("test_type") + with elasticapm.capture_span(span_type="x", name="x", leaf=False, duration=0.0001) as span: + span.dist_tracing_propagated = True + elasticapm_client.end_transaction("foo", duration=2.2) + transaction = elasticapm_client.events[constants.TRANSACTION][0] + spans = elasticapm_client.events[constants.SPAN] + assert len(spans) == 1 + assert transaction["span_count"]["started"] == 1 + assert transaction["span_count"]["dropped"] == 0 + + def test_transaction_cancelled_span(elasticapm_client): elasticapm_client.begin_transaction("test_type") with elasticapm.capture_span("test") as span: diff --git a/tests/config/config_snapshotting_tests.py b/tests/config/config_snapshotting_tests.py index 67b2a88f5..4f40a0472 100644 --- a/tests/config/config_snapshotting_tests.py +++ b/tests/config/config_snapshotting_tests.py @@ -123,6 +123,17 @@ def test_config_snapshotting_span_compression_drop_exit_span(elasticapm_client): assert len(spans) == 0 +def test_config_snapshotting_span_compression_drop_span(elasticapm_client): + elasticapm_client.config.update(version="1", span_min_duration="10ms") + elasticapm_client.begin_transaction("foo") + elasticapm_client.config.update(version="2", span_min_duration="0ms") + with elasticapm.capture_span("x", leaf=False, span_type="a", span_subtype="b", span_action="c", duration=0.005): + pass + elasticapm_client.end_transaction() + spans = elasticapm_client.events[SPAN] + assert len(spans) == 0 + + def test_config_snapshotting_span_compression_max_spans(elasticapm_client): elasticapm_client.config.update(version="1", transaction_max_spans="1") elasticapm_client.begin_transaction("foo") diff --git a/tests/contrib/django/fixtures.py b/tests/contrib/django/fixtures.py index 7d4a64cd1..a0a5cfa34 100644 --- a/tests/contrib/django/fixtures.py +++ b/tests/contrib/django/fixtures.py @@ -59,6 +59,7 @@ def django_elasticapm_client(request): client_config.setdefault("span_stack_trace_min_duration", 0) client_config.setdefault("span_compression_exact_match_max_duration", "0ms") client_config.setdefault("span_compression_same_kind_max_duration", "0ms") + client_config.setdefault("span_min_duration", "0ms") app = apps.get_app_config("elasticapm") old_client = app.client client = TempStoreClient(**client_config) @@ -88,6 +89,7 @@ def django_sending_elasticapm_client(request, validating_httpserver): client_config.setdefault("span_stack_trace_min_duration", 0) client_config.setdefault("span_compression_exact_match_max_duration", "0ms") client_config.setdefault("span_compression_same_kind_max_duration", "0ms") + client_config.setdefault("span_min_duration", "0ms") client_config.setdefault("exit_span_min_duration", "0ms") app = apps.get_app_config("elasticapm") old_client = app.client diff --git a/tests/fixtures.py b/tests/fixtures.py index 25d21ee5d..57365a6af 100644 --- a/tests/fixtures.py +++ b/tests/fixtures.py @@ -227,6 +227,7 @@ def elasticapm_client(request): client_config.setdefault("cloud_provider", False) client_config.setdefault("span_compression_exact_match_max_duration", "0ms") client_config.setdefault("span_compression_same_kind_max_duration", "0ms") + client_config.setdefault("span_min_duration", "0ms") client_config.setdefault("exit_span_min_duration", "0ms") client = client_class(**client_config) yield client @@ -264,6 +265,7 @@ def elasticapm_client_log_file(request): client_config.setdefault("span_stack_trace_min_duration", 0) client_config.setdefault("span_compression_exact_match_max_duration", "0ms") client_config.setdefault("span_compression_same_kind_max_duration", "0ms") + client_config.setdefault("span_min_duration", "0ms") client_config.setdefault("metrics_interval", "0ms") client_config.setdefault("cloud_provider", False) client_config.setdefault("log_level", "warning") @@ -349,6 +351,7 @@ def sending_elasticapm_client(request, validating_httpserver): client_config.setdefault("span_stack_trace_min_duration", 0) client_config.setdefault("span_compression_exact_match_max_duration", "0ms") client_config.setdefault("span_compression_same_kind_max_duration", "0ms") + client_config.setdefault("span_min_duration", "0ms") client_config.setdefault("include_paths", ("*/tests/*",)) client_config.setdefault("metrics_interval", "0ms") client_config.setdefault("cloud_provider", False)