Skip to content

Commit f6c014a

Browse files
authored
chore(telemetry): telemetry log messages must be constant (#14642)
Last PR in a list of 3 PRs to achieved requirements listed [here](https://docs.google.com/document/d/16SFeOp7yxzT6dM1O0TKtWkgDsiq6SeV8P_MAYboCdOI/edit?tab=t.gho5ikpq9hed). See: #14639. See: #14641 # Constant log message enforcement Every log.error() messages are by default reported to telemetry. Message reported to telemetry must be constant. A check was added in CI (you can test it by running `hatch run lint:error-log-check`): you will not be able to merge a PR that sends a non constant message to telemetry. You are two ways to still doing that: - `log.error("my message", extra={"send_to_telemetry"=False})`: this will only log the message and not sending it to telemetry. - add an exception in `check_constant_log_message.py`. The reason should be added in a comment and is only valid if you are 100% that the message is constant or the log.error will not send telemetry. For instance in a file of the debugger, log.error will eventually call log.debug. Note that `log.error("my message with: %s", "something")` is valid but only "my messag with %s", will be sent 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 12f39b7 commit f6c014a

File tree

12 files changed

+153
-15
lines changed

12 files changed

+153
-15
lines changed

ddtrace/appsec/_iast/_taint_tracking/_taint_objects_base.py

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -72,7 +72,7 @@ def get_tainted_ranges(pyobject: Any) -> Tuple:
7272
try:
7373
return get_ranges(pyobject)
7474
except ValueError as e:
75-
iast_propagation_error_log(f"get_tainted_ranges error (pyobject type {type(pyobject)}): {e}")
75+
iast_propagation_error_log(f"get_tainted_ranges error (pyobject type {type(pyobject)})", exc=e)
7676
return tuple()
7777

7878

@@ -83,5 +83,5 @@ def is_pyobject_tainted(pyobject: Any) -> bool:
8383
try:
8484
return is_in_taint_map(pyobject)
8585
except ValueError as e:
86-
iast_propagation_error_log(f"Checking tainted object error: {e}")
86+
iast_propagation_error_log("Checking tainted object error", exc=e)
8787
return False

ddtrace/contrib/internal/botocore/services/bedrock_agents.py

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -38,8 +38,8 @@ def __iter__(self):
3838
response = _process_streamed_response_chunks(chunks)
3939
try:
4040
self._dd_integration.translate_bedrock_traces(traces, self._dd_span)
41-
except Exception as e:
42-
log.error("Error translating Bedrock traces: %s", e, exc_info=True)
41+
except Exception:
42+
log.error("Error translating Bedrock traces", exc_info=True)
4343
self._dd_integration.llmobs_set_tags(self._dd_span, self._args, self._kwargs, response, operation="agent")
4444
self._dd_span.finish()
4545

ddtrace/debugging/_debugger.py

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -366,7 +366,7 @@ def _probe_injection_hook(self, module: ModuleType) -> None:
366366
f"Cannot install probe {probe.probe_id}: "
367367
f"no functions at line {line} within source file {module_origin} found"
368368
)
369-
log.error(message)
369+
log.error(message, extra={"send_to_telemetry": False})
370370
self._probe_registry.set_error(probe, "NoFunctionsAtLine", message)
371371
continue
372372
for function in (cast(FullyNamedContextWrappedFunction, _) for _ in functions):
@@ -487,7 +487,7 @@ def _probe_wrapping_hook(self, module: ModuleType) -> None:
487487
"found (note: if the function exists, it might be decorated with an unsupported decorator)"
488488
)
489489
self._probe_registry.set_error(probe, "NoFunctionInModule", message)
490-
log.error(message)
490+
log.error(message, extra={"send_to_telemetry": False})
491491
continue
492492

493493
if DebuggerWrappingContext.is_wrapped(function):

ddtrace/internal/telemetry/logging.py

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -14,4 +14,5 @@ def emit(self, record: logging.LogRecord) -> None:
1414
- Log all records with a level of ERROR or higher with telemetry
1515
"""
1616
if record.levelno >= logging.ERROR:
17-
self.telemetry_writer.add_error_log(record.msg, record.exc_info)
17+
if getattr(record, "send_to_telemetry", None) in (None, True):
18+
self.telemetry_writer.add_error_log(record.msg, record.exc_info)

ddtrace/internal/telemetry/writer.py

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -743,7 +743,8 @@ def _telemetry_excepthook(self, tp, value, root_traceback):
743743
lineno = traceback.tb_frame.f_code.co_firstlineno
744744
filename = traceback.tb_frame.f_code.co_filename
745745

746-
self.add_error_log("Unhandled exception from ddtrace code", (tp, None, root_traceback))
746+
if "ddtrace/" in filename:
747+
self.add_error_log("Unhandled exception from ddtrace code", (tp, None, root_traceback))
747748

748749
dir_parts = filename.split(os.path.sep)
749750
# Check if exception was raised in the `ddtrace.contrib` package

ddtrace/internal/writer/writer.py

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -330,7 +330,7 @@ def _send_payload(self, payload: bytes, count: int, client: WriterClientBase) ->
330330
else:
331331
log_args += (payload,)
332332

333-
log.error(msg, *log_args)
333+
log.error(msg, *log_args, extra={"send_to_telemetry": False})
334334
self._metrics_dist("http.dropped.bytes", len(payload))
335335
self._metrics_dist("http.dropped.traces", count)
336336
return response
@@ -1052,7 +1052,7 @@ def _flush_single_payload(
10521052
msg += ", payload %s"
10531053
log_args += (binascii.hexlify(encoded).decode(),) # type: ignore
10541054

1055-
log.error(msg, *log_args)
1055+
log.error(msg, *log_args, extra={"send_to_telemetry": False})
10561056

10571057
def periodic(self):
10581058
self.flush_queue(raise_exc=False)

ddtrace/vendor/ply/yacc.py

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -3177,7 +3177,7 @@ def validate_pfunctions(self):
31773177
for g in parsed_g:
31783178
grammar.append((name, g))
31793179
except SyntaxError as e:
3180-
self.log.error(str(e))
3180+
self.log.error(str(e), extra={"send_to_telemetry": False})
31813181
self.error = True
31823182

31833183
# Looks like a valid grammar rule
@@ -3351,7 +3351,7 @@ def yacc(method='LALR', debug=yaccdebug, module=None, tabmodule=tab_module, star
33513351
else:
33523352
grammar.set_start(start)
33533353
except GrammarError as e:
3354-
errorlog.error(str(e))
3354+
errorlog.error(str(e), extra={"send_to_telemetry": False})
33553355
errors = True
33563356

33573357
if errors:

hatch.toml

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,7 @@ checks = [
5656
"security",
5757
"test",
5858
"suitespec-check",
59+
"error-log-check",
5960
"sg",
6061
"sg-test",
6162
]
@@ -77,6 +78,9 @@ riot = [
7778
suitespec-check = [
7879
"python scripts/check_suitespec_coverage.py"
7980
]
81+
error-log-check = [
82+
"python scripts/check_constant_log_message.py"
83+
]
8084
sg = [
8185
"ast-grep scan {args:.}",
8286
]
Lines changed: 123 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,123 @@
1+
"""
2+
Check that log.error() and add_error_log calls use constant string literals as first argument.
3+
This script scans all Python files in ddtrace/ and reports violations.
4+
Exceptions can be specified in the EXCEPTIONS set using:
5+
- "filepath:line" to exclude a specific line in a file
6+
"""
7+
8+
import ast
9+
import pathlib
10+
import sys
11+
from typing import List
12+
from typing import Tuple
13+
14+
15+
# Line-specific exceptions to exclude from checking
16+
# Format: "filepath:line" to exclude a specific line in a file
17+
EXCEPTIONS = {
18+
# only constant message can be log.error()
19+
"ddtrace/internal/telemetry/logging.py:18",
20+
# log.exception calls use constant messages
21+
"ddtrace/contrib/internal/aws_lambda/patch.py:36",
22+
# log.error in _probe/registry.py ends up with a log.debug()
23+
"ddtrace/debugging/_probe/registry.py:137",
24+
"ddtrace/debugging/_probe/registry.py:146",
25+
# we added a constant check for the wrapping method of add_error_log
26+
"ddtrace/appsec/_iast/_metrics.py:53",
27+
# we added a constant check for the wrapping method of iast_error
28+
"ddtrace/appsec/_iast/_logs.py:41",
29+
"ddtrace/appsec/_iast/_logs.py:45",
30+
# the non constant part is an object type
31+
"ddtrace/appsec/_iast/_taint_tracking/_taint_objects_base.py:75",
32+
}
33+
34+
35+
class LogMessageChecker(ast.NodeVisitor):
36+
def __init__(self, filepath: str):
37+
self.filepath = filepath
38+
self.errors: List[Tuple[int, int]] = []
39+
40+
def _has_send_to_telemetry_false(self, node: ast.Call) -> bool:
41+
"""Check if the call has extra={'send_to_telemetry': False}."""
42+
for keyword in node.keywords:
43+
if keyword.arg == "extra" and isinstance(keyword.value, ast.Dict):
44+
for key, value in zip(keyword.value.keys, keyword.value.values):
45+
if (
46+
isinstance(key, ast.Constant)
47+
and key.value == "send_to_telemetry"
48+
and isinstance(value, ast.Constant)
49+
and value.value is False
50+
):
51+
return True
52+
return False
53+
54+
def visit_Call(self, node: ast.Call) -> None:
55+
"""Check if this is a log.error(), add_error_log, or iast_error call with non-constant first arg."""
56+
fn = node.func
57+
58+
# Check for add_error_log calls
59+
is_add_integration_error = isinstance(fn, ast.Attribute) and fn.attr == "add_error_log"
60+
# Check for log.error() calls (simple check for .error() on any variable)
61+
is_log_error = isinstance(fn, ast.Attribute) and (fn.attr == "error" or fn.attr == "exception")
62+
# Check for iast_error calls
63+
is_iast_log = isinstance(fn, ast.Name) and (
64+
fn.id == "iast_error"
65+
or fn.id == "iast_instrumentation_ast_patching_errorr_log"
66+
or fn.id == "iast_propagation_error_log"
67+
)
68+
is_target = is_add_integration_error or is_log_error or is_iast_log
69+
70+
if is_target and node.args:
71+
msg = node.args[0]
72+
is_constant_string = isinstance(msg, ast.Constant) and isinstance(msg.value, str)
73+
74+
# Skip constant string check if send_to_telemetry is False for log.error/exception calls
75+
if not is_constant_string and is_log_error and self._has_send_to_telemetry_false(node):
76+
pass
77+
elif not is_constant_string and not self._is_line_exception(node.lineno):
78+
self.errors.append((node.lineno, node.col_offset))
79+
80+
self.generic_visit(node)
81+
82+
def _is_line_exception(self, line_no: int) -> bool:
83+
"""Check if this specific line is in the exceptions list."""
84+
return f"{str(self.filepath)}:{line_no}" in EXCEPTIONS
85+
86+
87+
def check_file(filepath: pathlib.Path) -> List[Tuple[int, int]]:
88+
try:
89+
source = filepath.read_text(encoding="utf-8")
90+
tree = ast.parse(source, filename=str(filepath))
91+
checker = LogMessageChecker(str(filepath))
92+
checker.visit(tree)
93+
return checker.errors
94+
except (OSError, UnicodeDecodeError) as e:
95+
print(f"Error reading {filepath}: {e}", file=sys.stderr)
96+
return []
97+
except SyntaxError as e:
98+
print(f"Syntax error in {filepath}:{e.lineno}:{e.offset}: {e.msg}", file=sys.stderr)
99+
return []
100+
101+
102+
def main() -> int:
103+
contrib_path = pathlib.Path("ddtrace")
104+
python_files = list(contrib_path.rglob("*.py"))
105+
106+
total_errors = 0
107+
108+
for filepath in python_files:
109+
errors = check_file(filepath)
110+
for line_no, col_no in errors:
111+
print(f"{filepath}:{line_no}:{col_no}: " "LOG001 first argument to logging call must be a constant string")
112+
total_errors += 1
113+
114+
if total_errors > 0:
115+
print(f"\nFound {total_errors} violation(s)", file=sys.stderr)
116+
return 1
117+
118+
print("All logging calls use constant strings ✓")
119+
return 0
120+
121+
122+
if __name__ == "__main__":
123+
sys.exit(main())

scripts/gen_gitlab_config.py

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -265,6 +265,11 @@ def check(name: str, command: str, paths: t.Set[str]) -> None:
265265
command="hatch run lint:suitespec-check",
266266
paths={"*"},
267267
)
268+
check(
269+
name="Check integration error logs",
270+
command="hatch run lint:error-log-check",
271+
paths={"ddtrace/contrib/**/*.py"},
272+
)
268273
if not checks:
269274
return
270275

0 commit comments

Comments
 (0)