Skip to content

Commit c815cbf

Browse files
KowalskiThomasKowalskiThomas
authored
fix(profiling): always use leaf Task name [backport 4.1] (#15859)
## Description Backport of #15813.
1 parent 2229361 commit c815cbf

7 files changed

Lines changed: 146 additions & 293 deletions

File tree

‎ddtrace/internal/datadog/profiling/stack/src/stack_renderer.cpp‎

Lines changed: 10 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -75,6 +75,7 @@ StackRenderer::render_task_begin(std::string task_name, bool on_cpu)
7575
if (failed) {
7676
return;
7777
}
78+
7879
if (sample == nullptr) {
7980
// The very first task on a thread will already have a sample, since there's no way to deduce whether
8081
// a thread has tasks without checking, and checking before populating the sample would make the state
@@ -89,10 +90,13 @@ StackRenderer::render_task_begin(std::string task_name, bool on_cpu)
8990
// Add the thread context into the sample
9091
sample->push_threadinfo(
9192
static_cast<int64_t>(thread_state.id), static_cast<int64_t>(thread_state.native_id), thread_state.name);
92-
sample->push_task_name(task_name);
9393
sample->push_walltime(thread_state.wall_time_ns, 1);
94-
if (on_cpu)
95-
sample->push_cputime(thread_state.cpu_time_ns, 1); // initialized to 0, so possibly a no-op
94+
95+
if (on_cpu) {
96+
// initialized to 0, so possibly a no-op
97+
sample->push_cputime(thread_state.cpu_time_ns, 1);
98+
}
99+
96100
sample->push_monotonic_ns(thread_state.now_time_ns);
97101

98102
// We also want to make sure the tid -> span_id mapping is present in the sample for the task
@@ -103,9 +107,10 @@ StackRenderer::render_task_begin(std::string task_name, bool on_cpu)
103107
sample->push_local_root_span_id(active_span->local_root_span_id);
104108
sample->push_trace_type(std::string_view(active_span->span_type));
105109
}
106-
107-
pushed_task_name = true;
108110
}
111+
112+
sample->push_task_name(task_name);
113+
pushed_task_name = true;
109114
}
110115

111116
void

‎releasenotes/notes/profiling-always-use-leaf-task-name-46bf36ed9f1d723b.yaml‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,4 @@
1+
fixes:
2+
- |
3+
profiling: the Profiler now always uses the name of leaf tasks for the "Task name" label. Previously, one of the
4+
Stacks would be labelled with the parent task's name, which would lead to inconsistent behaviour across runs.

‎tests/profiling/collector/test_asyncio_as_completed.py‎

Lines changed: 9 additions & 53 deletions
Original file line numberDiff line numberDiff line change
@@ -15,12 +15,9 @@ def test_asyncio_as_completed() -> None:
1515
from sys import version_info as PYVERSION
1616

1717
from ddtrace.internal.datadog.profiling import stack
18-
from ddtrace.internal.logger import get_logger
1918
from ddtrace.profiling import profiler
2019
from tests.profiling.collector import pprof_utils
2120

22-
LOG = get_logger(__name__)
23-
2421
assert stack.is_available, stack.failure_msg
2522

2623
async def other(t: float) -> None:
@@ -67,17 +64,6 @@ async def main() -> None:
6764

6865
profile = pprof_utils.parse_newest_profile(output_filename)
6966

70-
task_names_in_profile = sorted(
71-
set(
72-
[
73-
(profile.string_table[label.str])
74-
for sample in profile.sample
75-
for label in sample.label
76-
if profile.string_table[label.key] == "task name"
77-
]
78-
)
79-
)
80-
8167
samples = pprof_utils.get_samples_with_label_key(profile, "task name")
8268
assert len(samples) > 0
8369

@@ -110,43 +96,13 @@ async def main() -> None:
11096

11197
# Now, check that we have seen those locations for each Task we've created.
11298
# (They should be named Task-2 .. Task-11, which is the automatic name assigned to Tasks by asyncio.create_task)
113-
# Note: we expect one Task to not be seen (and thus accept to recover from one failure). The reason
114-
# is that there is a bug in ddtrace that makes one Task (randomly picked) appear "as part of" the Parent Task,
115-
# and this Task thus gets the Parent Task's name and not its own.
116-
seen_all_except_one = True
117-
seen_task_names: set[str] = set()
11899
for i in range(2, 12):
119-
try:
120-
pprof_utils.assert_profile_has_sample(
121-
profile,
122-
samples,
123-
expected_sample=pprof_utils.StackEvent(
124-
task_name=f"Task-{i}",
125-
thread_name="MainThread",
126-
locations=locations,
127-
),
128-
)
129-
130-
seen_task_names.add(f"Task-{i}")
131-
except AssertionError:
132-
if not seen_all_except_one:
133-
LOG.error(
134-
f"More than one Task has not been seen; i = {i} " # noqa: G004
135-
f"seen_task_names = {seen_task_names} "
136-
f"task_names_in_profile = {task_names_in_profile}"
137-
)
138-
raise
139-
140-
# This is the bug situation.
141-
# Check that we have seen the expected locations for the Parent Task (Task-1)
142-
# If that isn't the case, then something else is broken.
143-
pprof_utils.assert_profile_has_sample(
144-
profile,
145-
samples,
146-
expected_sample=pprof_utils.StackEvent(
147-
task_name="Task-1",
148-
thread_name="MainThread",
149-
locations=locations,
150-
),
151-
)
152-
seen_all_except_one = False
100+
pprof_utils.assert_profile_has_sample(
101+
profile,
102+
samples,
103+
expected_sample=pprof_utils.StackEvent(
104+
task_name=f"Task-{i}",
105+
thread_name="MainThread",
106+
locations=locations,
107+
),
108+
)

‎tests/profiling/collector/test_asyncio_gather.py‎

Lines changed: 53 additions & 95 deletions
Original file line numberDiff line numberDiff line change
@@ -69,112 +69,70 @@ async def outer() -> None:
6969
# tracking via ddtrace.profiling._asyncio
7070
assert len(samples) > 0
7171

72+
# TODO: Currently, we never report Parent Tasks awaiting a Child Task as part of their own.
73+
# This means we never see the 'await asyncio.gather(...)' tagged with Task name "outer"
74+
# because it is always reported as part of the Stack of a Child Task.
75+
# We will fix this in the future.
76+
# pprof_utils.assert_profile_has_sample(
77+
# profile,
78+
# samples,
79+
# expected_sample=pprof_utils.StackEvent(
80+
# thread_name="MainThread",
81+
# task_name="outer",
82+
# span_id=span_id,
83+
# local_root_span_id=local_root_span_id,
84+
# locations=[
85+
# pprof_utils.StackLocation(
86+
# function_name="outer", filename="test_asyncio_gather.py", line_no=outer.__code__.co_firstlineno+3
87+
# ),
88+
# ],
89+
# ),
90+
# )
91+
7292
pprof_utils.assert_profile_has_sample(
7393
profile,
7494
samples,
7595
expected_sample=pprof_utils.StackEvent(
7696
thread_name="MainThread",
77-
task_name="outer",
97+
task_name="inner 1",
7898
span_id=span_id,
7999
local_root_span_id=local_root_span_id,
80100
locations=[
81101
pprof_utils.StackLocation(
82-
function_name="outer", filename="test_asyncio_gather.py", line_no=outer.__code__.co_firstlineno + 3
102+
function_name="inner1",
103+
filename="test_asyncio_gather.py",
104+
line_no=inner1.__code__.co_firstlineno + 3,
105+
),
106+
pprof_utils.StackLocation(
107+
function_name="outer",
108+
filename="test_asyncio_gather.py",
109+
line_no=outer.__code__.co_firstlineno + 3,
83110
),
84-
# TODO: We should add the locations of the gathered Tasks here as they should be in the same Stack
85111
],
86112
),
113+
print_samples_on_failure=True,
87114
)
88115

89-
try:
90-
pprof_utils.assert_profile_has_sample(
91-
profile,
92-
samples,
93-
expected_sample=pprof_utils.StackEvent(
94-
thread_name="MainThread",
95-
task_name="outer", # TODO: This is a bug and we need to fix it, it should be "inner 1"
96-
span_id=span_id,
97-
local_root_span_id=local_root_span_id,
98-
locations=[
99-
pprof_utils.StackLocation(
100-
function_name="inner2",
101-
filename="test_asyncio_gather.py",
102-
line_no=inner2.__code__.co_firstlineno + 3,
103-
),
104-
pprof_utils.StackLocation(
105-
function_name="outer",
106-
filename="test_asyncio_gather.py",
107-
line_no=outer.__code__.co_firstlineno + 3,
108-
),
109-
],
110-
),
111-
)
112-
113-
pprof_utils.assert_profile_has_sample(
114-
profile,
115-
samples,
116-
expected_sample=pprof_utils.StackEvent(
117-
thread_name="MainThread",
118-
task_name="inner 1",
119-
span_id=span_id,
120-
local_root_span_id=local_root_span_id,
121-
locations=[
122-
pprof_utils.StackLocation(
123-
function_name="inner1",
124-
filename="test_asyncio_gather.py",
125-
line_no=inner1.__code__.co_firstlineno + 3,
126-
),
127-
pprof_utils.StackLocation(
128-
function_name="outer",
129-
filename="test_asyncio_gather.py",
130-
line_no=outer.__code__.co_firstlineno + 3,
131-
),
132-
],
133-
),
134-
)
135-
except AssertionError:
136-
pprof_utils.assert_profile_has_sample(
137-
profile,
138-
samples,
139-
expected_sample=pprof_utils.StackEvent(
140-
thread_name="MainThread",
141-
task_name="inner 2", # TODO: This is a bug and we need to fix it, it should be "inner 1"
142-
span_id=span_id,
143-
local_root_span_id=local_root_span_id,
144-
locations=[
145-
pprof_utils.StackLocation(
146-
function_name="inner2",
147-
filename="test_asyncio_gather.py",
148-
line_no=inner2.__code__.co_firstlineno + 3,
149-
),
150-
pprof_utils.StackLocation(
151-
function_name="outer",
152-
filename="test_asyncio_gather.py",
153-
line_no=outer.__code__.co_firstlineno + 3,
154-
),
155-
],
156-
),
157-
)
158-
159-
pprof_utils.assert_profile_has_sample(
160-
profile,
161-
samples,
162-
expected_sample=pprof_utils.StackEvent(
163-
thread_name="MainThread",
164-
task_name="outer",
165-
span_id=span_id,
166-
local_root_span_id=local_root_span_id,
167-
locations=[
168-
pprof_utils.StackLocation(
169-
function_name="inner1",
170-
filename="test_asyncio_gather.py",
171-
line_no=inner1.__code__.co_firstlineno + 3,
172-
),
173-
pprof_utils.StackLocation(
174-
function_name="outer",
175-
filename="test_asyncio_gather.py",
176-
line_no=outer.__code__.co_firstlineno + 3,
177-
),
178-
],
179-
),
180-
)
116+
pprof_utils.assert_profile_has_sample(
117+
profile,
118+
samples,
119+
expected_sample=pprof_utils.StackEvent(
120+
thread_name="MainThread",
121+
task_name="inner 2",
122+
span_id=span_id,
123+
local_root_span_id=local_root_span_id,
124+
locations=[
125+
pprof_utils.StackLocation(
126+
function_name="inner2",
127+
filename="test_asyncio_gather.py",
128+
line_no=inner2.__code__.co_firstlineno + 3,
129+
),
130+
pprof_utils.StackLocation(
131+
function_name="outer",
132+
filename="test_asyncio_gather.py",
133+
line_no=outer.__code__.co_firstlineno + 3,
134+
),
135+
],
136+
),
137+
print_samples_on_failure=True,
138+
)

‎tests/profiling/collector/test_asyncio_gather_tasks.py‎

Lines changed: 19 additions & 40 deletions
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,7 @@
88
err=None,
99
)
1010
# For macOS: err=None ignores expected stderr from tracer failing to connect to agent (not relevant to this test)
11-
def test_asyncio_gather_wall_time() -> None:
11+
def test_asyncio_gather_tasks() -> None:
1212
import asyncio
1313
import os
1414

@@ -62,42 +62,21 @@ def fn_location(f: str) -> pprof_utils.StackLocation:
6262
line_no=-1,
6363
)
6464

65-
# One of the two Tasks gets included under the Main Task randomly, we have to try both.
66-
try:
67-
for f, t in (("f4_0", "Task-1"), ("f4_1", "F4_1")):
68-
pprof_utils.assert_profile_has_sample(
69-
profile,
70-
samples,
71-
expected_sample=pprof_utils.StackEvent(
72-
thread_name="MainThread",
73-
task_name=t,
74-
locations=[
75-
fn_location("sleep"),
76-
fn_location("f5"),
77-
fn_location(f),
78-
fn_location("f3"),
79-
fn_location("f2"),
80-
fn_location("f1"),
81-
fn_location("main"),
82-
],
83-
),
84-
)
85-
except AssertionError:
86-
for f, t in (("f4_0", "F4_0"), ("f4_1", "Task-1")):
87-
pprof_utils.assert_profile_has_sample(
88-
profile,
89-
samples,
90-
expected_sample=pprof_utils.StackEvent(
91-
thread_name="MainThread",
92-
task_name=t,
93-
locations=[
94-
fn_location("sleep"),
95-
fn_location("f5"),
96-
fn_location(f),
97-
fn_location("f3"),
98-
fn_location("f2"),
99-
fn_location("f1"),
100-
fn_location("main"),
101-
],
102-
),
103-
)
65+
for f, t in (("f4_0", "F4_0"), ("f4_1", "F4_1")):
66+
pprof_utils.assert_profile_has_sample(
67+
profile,
68+
samples,
69+
expected_sample=pprof_utils.StackEvent(
70+
thread_name="MainThread",
71+
task_name=t,
72+
locations=[
73+
fn_location("sleep"),
74+
fn_location("f5"),
75+
fn_location(f),
76+
fn_location("f3"),
77+
fn_location("f2"),
78+
fn_location("f1"),
79+
fn_location("main"),
80+
],
81+
),
82+
)

‎tests/profiling/collector/test_asyncio_recursive_on_cpu_tasks.py‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -114,17 +114,17 @@ def loc(f_name: str) -> StackLocation:
114114
print_samples_on_failure=True,
115115
)
116116

117-
# Same test, but with a specific task_name ("Task-1")``
118-
# Ideally, we should be able to report the Task-2 specific part in its own
119-
# Stack, but at the moment we are not. This will be fixed in the future.
117+
# Same test, but with a specific task_name - "Task-2".
118+
# Task-1 is the "root"/parent Task, Task-2 is the one created by inner1.
119+
# Since we label Samples with the Leaf Task's name, we want to see "Task-2".
120120
pprof_utils.assert_profile_has_sample(
121121
profile,
122122
list(profile.sample),
123123
pprof_utils.StackEvent(
124124
thread_name="MainThread",
125125
span_id=span_id,
126126
local_root_span_id=local_root_span_id,
127-
task_name="Task-1",
127+
task_name="Task-2",
128128
locations=list(
129129
reversed(
130130
[

0 commit comments

Comments
 (0)