Skip to content

Commit 6fae86b

Browse files
authored
chore(telemetry): integration error telemetry logs are sent through a function call (#13510)
## Motivation Integration related error telemetry logs were added in #11732. However, it is using a LogHandler. Therefore, to be able to report integration error logs to telemetry you needed to enable debug logs (as in the integration the errors are logged using debug level). However, telemetry activation should not be tied to the log level. The log handler will stay for the error part as it allows to reduce circular import (see the quoted PR above). ## What does this PR do ? - Add a call tied to the writer to report integration error logs to telemetry - Bump the level of the telemetry logs to error (so it appears in telemetry). - Modification to the redaction process: add `<REDACTED>` for every lines we are redacting (before we were only adding one `<REDACTED>` for the redaction of two lines) ## What this PR doesn't do - The PR does not effectively report any errors to telemetry. A discussion should take place in IDM to chose which errors are worth reporting to telemetry. ## Checklist - [X] PR author has checked that all the criteria below are met - The PR description includes an overview of the change - The PR description articulates the motivation for the change - The change includes tests OR the PR description describes a testing strategy - The PR description notes risks associated with the change, if any - Newly-added code is easy to change - The change follows the [library release note guidelines](https://ddtrace.readthedocs.io/en/stable/releasenotes.html) - The change includes or references documentation updates if necessary - Backport labels are set (if [applicable](https://ddtrace.readthedocs.io/en/latest/contributing.html#backporting)) ## Reviewer Checklist - [x] Reviewer has checked that all the criteria below are met - Title is accurate - All changes are related to the pull request's stated goal - Avoids breaking [API](https://ddtrace.readthedocs.io/en/stable/versioning.html#interfaces) changes - Testing strategy adequately addresses listed risks - Newly-added code is easy to change - Release note makes sense to a user of the library - If necessary, author has acknowledged and discussed the performance implications of this PR as reported in the benchmarks PR comment - Backport labels are set in a manner that is consistent with the [release branch maintenance policy](https://ddtrace.readthedocs.io/en/latest/contributing.html#backporting)
1 parent 17ce936 commit 6fae86b

File tree

4 files changed

+107
-210
lines changed

4 files changed

+107
-210
lines changed
Lines changed: 1 addition & 55 deletions
Original file line numberDiff line numberDiff line change
@@ -1,12 +1,8 @@
11
import logging
22
import os
3-
import traceback
4-
from typing import Union
53

6-
from ddtrace.internal.telemetry.constants import TELEMETRY_LOG_LEVEL
74

8-
9-
class DDTelemetryLogHandler(logging.Handler):
5+
class DDTelemetryErrorHandler(logging.Handler):
106
CWD = os.getcwd()
117

128
def __init__(self, telemetry_writer):
@@ -16,58 +12,8 @@ def __init__(self, telemetry_writer):
1612
def emit(self, record: logging.LogRecord) -> None:
1713
"""This function will:
1814
- Log all records with a level of ERROR or higher with telemetry
19-
- Log all caught exception originated from ddtrace.contrib modules
2015
"""
2116
if record.levelno >= logging.ERROR:
2217
# Capture start up errors
2318
full_file_name = os.path.join(record.pathname, record.filename)
2419
self.telemetry_writer.add_error(1, record.msg % record.args, full_file_name, record.lineno)
25-
26-
# Capture errors logged in the ddtrace integrations
27-
if record.name.startswith("ddtrace.contrib"):
28-
telemetry_level = (
29-
TELEMETRY_LOG_LEVEL.ERROR
30-
if record.levelno >= logging.ERROR
31-
else TELEMETRY_LOG_LEVEL.WARNING
32-
if record.levelno == logging.WARNING
33-
else TELEMETRY_LOG_LEVEL.DEBUG
34-
)
35-
# Only collect telemetry for logs with a traceback
36-
stack_trace = self._format_stack_trace(record.exc_info)
37-
if stack_trace is not None:
38-
# Report only exceptions with a stack trace
39-
self.telemetry_writer.add_log(
40-
telemetry_level,
41-
record.msg,
42-
stack_trace=stack_trace,
43-
)
44-
45-
def _format_stack_trace(self, exc_info) -> Union[str, None]:
46-
if exc_info is None:
47-
return None
48-
49-
exc_type, exc_value, exc_traceback = exc_info
50-
if exc_traceback:
51-
tb = traceback.extract_tb(exc_traceback)
52-
formatted_tb = ["Traceback (most recent call last):"]
53-
for filename, lineno, funcname, srcline in tb:
54-
if self._should_redact(filename):
55-
formatted_tb.append(" <REDACTED>")
56-
else:
57-
relative_filename = self._format_file_path(filename)
58-
formatted_line = f' File "{relative_filename}", line {lineno}, in {funcname}\n {srcline}'
59-
formatted_tb.append(formatted_line)
60-
if exc_type:
61-
formatted_tb.append(f"{exc_type.__module__}.{exc_type.__name__}: {exc_value}")
62-
return "\n".join(formatted_tb)
63-
64-
return None
65-
66-
def _should_redact(self, filename: str) -> bool:
67-
return "ddtrace" not in filename
68-
69-
def _format_file_path(self, filename):
70-
try:
71-
return os.path.relpath(filename, start=self.CWD)
72-
except ValueError:
73-
return filename

ddtrace/internal/telemetry/writer.py

Lines changed: 42 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@
44
import os
55
import sys
66
import time
7+
import traceback
78
from typing import TYPE_CHECKING # noqa:F401
89
from typing import Any # noqa:F401
910
from typing import Dict # noqa:F401
@@ -38,7 +39,7 @@
3839
from .data import get_host_info
3940
from .data import get_python_config_vars
4041
from .data import update_imported_dependencies
41-
from .logging import DDTelemetryLogHandler
42+
from .logging import DDTelemetryErrorHandler
4243
from .metrics_namespaces import MetricNamespace
4344
from .metrics_namespaces import MetricTagType
4445
from .metrics_namespaces import MetricType
@@ -145,6 +146,7 @@ class TelemetryWriter(PeriodicService):
145146
# payloads is only used in tests and is not required to process Telemetry events.
146147
_sequence = itertools.count(1)
147148
_ORIGINAL_EXCEPTHOOK = staticmethod(sys.excepthook)
149+
CWD = os.getcwd()
148150

149151
def __init__(self, is_periodic=True, agentless=None):
150152
# type: (bool, Optional[bool]) -> None
@@ -204,8 +206,8 @@ def __init__(self, is_periodic=True, agentless=None):
204206
# Force app started for unit tests
205207
if config.FORCE_START:
206208
self._app_started()
207-
if config.LOG_COLLECTION_ENABLED:
208-
get_logger("ddtrace").addHandler(DDTelemetryLogHandler(self))
209+
# Send logged error to telemetry
210+
get_logger("ddtrace").addHandler(DDTelemetryErrorHandler(self))
209211

210212
def enable(self):
211213
# type: () -> bool
@@ -503,6 +505,43 @@ def add_log(self, level, message, stack_trace="", tags=None):
503505
# Logs are hashed using the message, level, tags, and stack_trace. This should prevent duplicatation.
504506
self._logs.add(data)
505507

508+
def add_integration_error_log(self, msg: str, exc: BaseException) -> None:
509+
if config.LOG_COLLECTION_ENABLED:
510+
stack_trace = self._format_stack_trace(exc)
511+
self.add_log(
512+
TELEMETRY_LOG_LEVEL.ERROR,
513+
msg,
514+
stack_trace=stack_trace if stack_trace is not None else "",
515+
)
516+
517+
def _format_stack_trace(self, exc: BaseException) -> Optional[str]:
518+
exc_type, exc_value, exc_traceback = type(exc), exc, exc.__traceback__
519+
if exc_traceback:
520+
tb = traceback.extract_tb(exc_traceback)
521+
formatted_tb = ["Traceback (most recent call last):"]
522+
for filename, lineno, funcname, srcline in tb:
523+
if self._should_redact(filename):
524+
formatted_tb.append(" <REDACTED>")
525+
formatted_tb.append(" <REDACTED>")
526+
else:
527+
relative_filename = self._format_file_path(filename)
528+
formatted_line = f' File "{relative_filename}", line {lineno}, in {funcname}\n {srcline}'
529+
formatted_tb.append(formatted_line)
530+
if exc_type:
531+
formatted_tb.append(f"{exc_type.__module__}.{exc_type.__name__}: {exc_value}")
532+
return "\n".join(formatted_tb)
533+
534+
return None
535+
536+
def _should_redact(self, filename: str) -> bool:
537+
return "ddtrace" not in filename
538+
539+
def _format_file_path(self, filename: str) -> str:
540+
try:
541+
return os.path.relpath(filename, start=self.CWD)
542+
except ValueError:
543+
return filename
544+
506545
def add_gauge_metric(self, namespace: TELEMETRY_NAMESPACE, name: str, value: float, tags: MetricTagType = None):
507546
"""
508547
Queues gauge metric

tests/telemetry/test_telemetry_log_handler.py

Lines changed: 0 additions & 152 deletions
This file was deleted.

tests/telemetry/test_writer.py

Lines changed: 64 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -12,11 +12,14 @@
1212
from ddtrace import config
1313
import ddtrace.internal.telemetry
1414
from ddtrace.internal.telemetry.constants import TELEMETRY_APM_PRODUCT
15+
from ddtrace.internal.telemetry.constants import TELEMETRY_LOG_LEVEL
1516
from ddtrace.internal.telemetry.data import get_application
1617
from ddtrace.internal.telemetry.data import get_host_info
18+
from ddtrace.internal.telemetry.writer import TelemetryWriter
1719
from ddtrace.internal.telemetry.writer import get_runtime_id
1820
from ddtrace.internal.utils.version import _pep440_to_semver
1921
from ddtrace.settings._config import DD_TRACE_OBFUSCATION_QUERY_STRING_REGEXP_DEFAULT
22+
from ddtrace.settings._telemetry import config as telemetry_config
2023
from tests.conftest import DEFAULT_DDTRACE_SUBPROCESS_TEST_SERVICE_NAME
2124
from tests.utils import call_program
2225
from tests.utils import override_global_config
@@ -953,3 +956,64 @@ def test_otel_config_telemetry(test_agent_session, run_python_code_in_subprocess
953956
env_invalid_metrics = test_agent_session.get_metrics("otel.env.invalid")
954957
tags = [m["tags"] for m in env_invalid_metrics]
955958
assert tags == [["config_opentelemetry:otel_logs_exporter"]]
959+
960+
961+
def test_add_integration_error_log(mock_time, telemetry_writer, test_agent_session):
962+
"""Test add_integration_error_log functionality with real stack trace"""
963+
try:
964+
raise ValueError("Test exception")
965+
except ValueError as e:
966+
telemetry_writer.add_integration_error_log("Test error message", e)
967+
telemetry_writer.periodic(force_flush=True)
968+
969+
log_events = test_agent_session.get_events("logs")
970+
assert len(log_events) == 1
971+
972+
logs = log_events[0]["payload"]["logs"]
973+
assert len(logs) == 1
974+
975+
log_entry = logs[0]
976+
assert log_entry["level"] == TELEMETRY_LOG_LEVEL.ERROR.value
977+
assert log_entry["message"] == "Test error message"
978+
979+
stack_trace = log_entry["stack_trace"]
980+
expected_lines = [
981+
"Traceback (most recent call last):",
982+
" <REDACTED>",
983+
" <REDACTED>",
984+
"builtins.ValueError: Test exception",
985+
]
986+
for expected_line in expected_lines:
987+
assert expected_line in stack_trace
988+
989+
990+
def test_add_integration_error_log_with_log_collection_disabled(mock_time, telemetry_writer, test_agent_session):
991+
"""Test that add_integration_error_log respects LOG_COLLECTION_ENABLED setting"""
992+
original_value = telemetry_config.LOG_COLLECTION_ENABLED
993+
try:
994+
telemetry_config.LOG_COLLECTION_ENABLED = False
995+
996+
try:
997+
raise ValueError("Test exception")
998+
except ValueError as e:
999+
telemetry_writer.add_integration_error_log("Test error message", e)
1000+
telemetry_writer.periodic(force_flush=True)
1001+
1002+
log_events = test_agent_session.get_events("logs", subprocess=True)
1003+
assert len(log_events) == 0
1004+
finally:
1005+
telemetry_config.LOG_COLLECTION_ENABLED = original_value
1006+
1007+
1008+
@pytest.mark.parametrize(
1009+
"filename, is_redacted",
1010+
[
1011+
("/path/to/file.py", True),
1012+
("/path/to/ddtrace/contrib/flask/file.py", False),
1013+
("/path/to/dd-trace-something/file.py", True),
1014+
],
1015+
)
1016+
def test_redact_filename(filename, is_redacted):
1017+
"""Test file redaction logic"""
1018+
writer = TelemetryWriter(is_periodic=False)
1019+
assert writer._should_redact(filename) == is_redacted

0 commit comments

Comments
 (0)