This commit is contained in:
Pablo Galindo Salgado 2025-12-08 09:28:36 +04:00 committed by GitHub
commit 4c219f6f43
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
12 changed files with 237 additions and 57 deletions

View file

@ -5,16 +5,16 @@ def function_1():
def function_2():
function_1()
# CALL_FUNCTION_VAR
# CALL with positional args
def function_3(dummy, dummy2):
pass
# CALL_FUNCTION_KW
# CALL_KW (keyword arguments)
def function_4(**dummy):
return 1
return 2 # unreachable
# CALL_FUNCTION_VAR_KW
# CALL_FUNCTION_EX (unpacking)
def function_5(dummy, dummy2, **dummy3):
if False:
return 7

View file

@ -1,8 +1,10 @@
function__entry:call_stack.py:start:23
function__entry:call_stack.py:function_1:1
function__entry:call_stack.py:function_3:9
function__return:call_stack.py:function_3:10
function__return:call_stack.py:function_1:2
function__entry:call_stack.py:function_2:5
function__entry:call_stack.py:function_1:1
function__return:call_stack.py:function_3:10
function__return:call_stack.py:function_1:2
function__return:call_stack.py:function_2:6
function__entry:call_stack.py:function_3:9
@ -11,4 +13,3 @@ function__entry:call_stack.py:function_4:13
function__return:call_stack.py:function_4:14
function__entry:call_stack.py:function_5:18
function__return:call_stack.py:function_5:21
function__return:call_stack.py:start:28

View file

@ -1,7 +0,0 @@
python$target:::line
/(copyinstr(arg1)=="test_line")/
{
printf("%d\t%s:%s:%s:%d\n", timestamp,
probename, basename(copyinstr(arg0)),
copyinstr(arg1), arg2);
}

View file

@ -1,20 +0,0 @@
line:line.py:test_line:2
line:line.py:test_line:3
line:line.py:test_line:4
line:line.py:test_line:5
line:line.py:test_line:6
line:line.py:test_line:7
line:line.py:test_line:8
line:line.py:test_line:9
line:line.py:test_line:10
line:line.py:test_line:11
line:line.py:test_line:4
line:line.py:test_line:5
line:line.py:test_line:6
line:line.py:test_line:7
line:line.py:test_line:8
line:line.py:test_line:10
line:line.py:test_line:11
line:line.py:test_line:4
line:line.py:test_line:12
line:line.py:test_line:13

View file

@ -1,17 +0,0 @@
def test_line():
a = 1
print('# Preamble', a)
for i in range(2):
a = i
b = i+2
c = i+3
if c < 4:
a = c
d = a + b +c
print('#', a, b, c, d)
a = 1
print('# Epilogue', a)
if __name__ == '__main__':
test_line()

View file

@ -33,11 +33,17 @@ def normalize_trace_output(output):
result = [
row.split("\t")
for row in output.splitlines()
if row and not row.startswith('#')
if row and not row.startswith('#') and not row.startswith('@')
]
result.sort(key=lambda row: int(row[0]))
result = [row[1] for row in result]
return "\n".join(result)
# Normalize paths to basenames (bpftrace outputs full paths)
normalized = []
for line in result:
# Replace full paths with just the filename
line = re.sub(r'/[^:]+/([^/:]+\.py)', r'\1', line)
normalized.append(line)
return "\n".join(normalized)
except (IndexError, ValueError):
raise AssertionError(
"tracer produced unparsable output:\n{}".format(output)
@ -103,6 +109,156 @@ class SystemTapBackend(TraceBackend):
COMMAND = ["stap", "-g"]
class BPFTraceBackend(TraceBackend):
EXTENSION = ".bt"
COMMAND = ["bpftrace"]
# Inline bpftrace programs for each test case
PROGRAMS = {
"call_stack": """
usdt:{python}:python:function__entry {{
printf("%lld\\tfunction__entry:%s:%s:%d\\n",
nsecs, str(arg0), str(arg1), arg2);
}}
usdt:{python}:python:function__return {{
printf("%lld\\tfunction__return:%s:%s:%d\\n",
nsecs, str(arg0), str(arg1), arg2);
}}
""",
"gc": """
usdt:{python}:python:function__entry {{
if (str(arg1) == "start") {{ @tracing = 1; }}
}}
usdt:{python}:python:function__return {{
if (str(arg1) == "start") {{ @tracing = 0; }}
}}
usdt:{python}:python:gc__start {{
if (@tracing) {{
printf("%lld\\tgc__start:%d\\n", nsecs, arg0);
}}
}}
usdt:{python}:python:gc__done {{
if (@tracing) {{
printf("%lld\\tgc__done:%lld\\n", nsecs, arg0);
}}
}}
END {{ clear(@tracing); }}
""",
}
# Which test scripts to filter by filename (None = use @tracing flag)
FILTER_BY_FILENAME = {"call_stack": "call_stack.py"}
# Expected outputs for each test case
# Note: bpftrace captures <module> entry/return and may have slight timing
# differences compared to SystemTap due to probe firing order
EXPECTED = {
"call_stack": """function__entry:call_stack.py:<module>:0
function__entry:call_stack.py:start:23
function__entry:call_stack.py:function_1:1
function__entry:call_stack.py:function_3:9
function__return:call_stack.py:function_3:10
function__return:call_stack.py:function_1:2
function__entry:call_stack.py:function_2:5
function__entry:call_stack.py:function_1:1
function__return:call_stack.py:function_3:10
function__return:call_stack.py:function_1:2
function__return:call_stack.py:function_2:6
function__entry:call_stack.py:function_3:9
function__return:call_stack.py:function_3:10
function__entry:call_stack.py:function_4:13
function__return:call_stack.py:function_4:14
function__entry:call_stack.py:function_5:18
function__return:call_stack.py:function_5:21
function__return:call_stack.py:start:28
function__return:call_stack.py:<module>:30""",
"gc": """gc__start:0
gc__done:0
gc__start:1
gc__done:0
gc__start:2
gc__done:0
gc__start:2
gc__done:1""",
}
def run_case(self, name, optimize_python=None):
if name not in self.PROGRAMS:
raise unittest.SkipTest(f"No bpftrace program for {name}")
python_file = abspath(name + ".py")
python_flags = []
if optimize_python:
python_flags.extend(["-O"] * optimize_python)
subcommand = [sys.executable] + python_flags + [python_file]
program = self.PROGRAMS[name].format(python=sys.executable)
try:
proc = subprocess.Popen(
["bpftrace", "-e", program, "-c", " ".join(subcommand)],
stdout=subprocess.PIPE,
stderr=subprocess.PIPE,
universal_newlines=True,
)
stdout, stderr = proc.communicate(timeout=60)
except subprocess.TimeoutExpired:
proc.kill()
raise AssertionError("bpftrace timed out")
except (FileNotFoundError, PermissionError) as e:
raise unittest.SkipTest(f"bpftrace not available: {e}")
if proc.returncode != 0:
raise AssertionError(
f"bpftrace failed with code {proc.returncode}:\n{stderr}"
)
# Filter output by filename if specified (bpftrace captures everything)
if name in self.FILTER_BY_FILENAME:
filter_filename = self.FILTER_BY_FILENAME[name]
filtered_lines = [
line for line in stdout.splitlines()
if filter_filename in line
]
stdout = "\n".join(filtered_lines)
actual_output = normalize_trace_output(stdout)
expected_output = self.EXPECTED[name].strip()
return (expected_output, actual_output)
def assert_usable(self):
# Check if bpftrace is available and can attach to USDT probes
program = f'usdt:{sys.executable}:python:function__entry {{ printf("probe: success\\n"); exit(); }}'
try:
proc = subprocess.Popen(
["bpftrace", "-e", program, "-c", f"{sys.executable} -c pass"],
stdout=subprocess.PIPE,
stderr=subprocess.PIPE,
universal_newlines=True,
)
stdout, stderr = proc.communicate(timeout=10)
except subprocess.TimeoutExpired:
proc.kill()
proc.communicate() # Clean up
raise unittest.SkipTest("bpftrace timed out during usability check")
except OSError as e:
raise unittest.SkipTest(f"bpftrace not available: {e}")
# Check for permission errors (bpftrace usually requires root)
if proc.returncode != 0:
raise unittest.SkipTest(
f"bpftrace(1) failed with code {proc.returncode}: {stderr}"
)
if "probe: success" not in stdout:
raise unittest.SkipTest(
f"bpftrace(1) failed: stdout={stdout!r} stderr={stderr!r}"
)
class TraceTests:
# unittest.TestCase options
maxDiff = None
@ -126,7 +282,8 @@ def test_function_entry_return(self):
def test_verify_call_opcodes(self):
"""Ensure our call stack test hits all function call opcodes"""
opcodes = set(["CALL_FUNCTION", "CALL_FUNCTION_EX", "CALL_FUNCTION_KW"])
# Modern Python uses CALL, CALL_KW, and CALL_FUNCTION_EX
opcodes = set(["CALL", "CALL_FUNCTION_EX", "CALL_KW"])
with open(abspath("call_stack.py")) as f:
code_string = f.read()
@ -151,9 +308,6 @@ def get_function_instructions(funcname):
def test_gc(self):
self.run_case("gc")
def test_line(self):
self.run_case("line")
class DTraceNormalTests(TraceTests, unittest.TestCase):
backend = DTraceBackend()
@ -174,6 +328,17 @@ class SystemTapOptimizedTests(TraceTests, unittest.TestCase):
backend = SystemTapBackend()
optimize_python = 2
class BPFTraceNormalTests(TraceTests, unittest.TestCase):
backend = BPFTraceBackend()
optimize_python = 0
class BPFTraceOptimizedTests(TraceTests, unittest.TestCase):
backend = BPFTraceBackend()
optimize_python = 2
class CheckDtraceProbes(unittest.TestCase):
@classmethod
def setUpClass(cls):
@ -234,6 +399,8 @@ def test_check_probes(self):
"Name: audit",
"Name: gc__start",
"Name: gc__done",
"Name: function__entry",
"Name: function__return",
]
for probe_name in available_probe_names:
@ -246,8 +413,6 @@ def test_missing_probes(self):
# Missing probes will be added in the future.
missing_probe_names = [
"Name: function__entry",
"Name: function__return",
"Name: line",
]

View file

@ -0,0 +1,2 @@
Restore ``function__entry`` and ``function__return`` DTrace/SystemTap probes
that were broken since Python 3.11.

View file

@ -1242,6 +1242,7 @@ dummy_func(
DEAD(retval);
SAVE_STACK();
assert(STACK_LEVEL() == 0);
DTRACE_FUNCTION_RETURN();
_Py_LeaveRecursiveCallPy(tstate);
// GH-99729: We need to unlink the frame *before* clearing it:
_PyInterpreterFrame *dying = frame;
@ -1418,6 +1419,7 @@ dummy_func(
_PyStackRef temp = retval;
DEAD(retval);
SAVE_STACK();
DTRACE_FUNCTION_RETURN();
tstate->exc_info = gen->gi_exc_state.previous_item;
gen->gi_exc_state.previous_item = NULL;
_Py_LeaveRecursiveCallPy(tstate);
@ -5564,6 +5566,7 @@ dummy_func(
if (too_deep) {
goto exit_unwind;
}
DTRACE_FUNCTION_ENTRY();
next_instr = frame->instr_ptr;
#ifdef Py_DEBUG
int lltrace = maybe_lltrace_resume_frame(frame, GLOBALS());

View file

@ -1452,6 +1452,38 @@ stop_tracing_and_jit(PyThreadState *tstate, _PyInterpreterFrame *frame)
#define DONT_SLP_VECTORIZE
#endif
#ifdef WITH_DTRACE
static void
dtrace_function_entry(_PyInterpreterFrame *frame)
{
const char *filename;
const char *funcname;
int lineno;
PyCodeObject *code = _PyFrame_GetCode(frame);
filename = PyUnicode_AsUTF8(code->co_filename);
funcname = PyUnicode_AsUTF8(code->co_name);
lineno = PyUnstable_InterpreterFrame_GetLine(frame);
PyDTrace_FUNCTION_ENTRY(filename, funcname, lineno);
}
static void
dtrace_function_return(_PyInterpreterFrame *frame)
{
const char *filename;
const char *funcname;
int lineno;
PyCodeObject *code = _PyFrame_GetCode(frame);
filename = PyUnicode_AsUTF8(code->co_filename);
funcname = PyUnicode_AsUTF8(code->co_name);
lineno = PyUnstable_InterpreterFrame_GetLine(frame);
PyDTrace_FUNCTION_RETURN(filename, funcname, lineno);
}
#endif
typedef struct {
_PyInterpreterFrame frame;
_PyStackRef stack[1];
@ -1531,6 +1563,7 @@ _PyEval_EvalFrameDefault(PyThreadState *tstate, _PyInterpreterFrame *frame, int
if (_Py_EnterRecursivePy(tstate)) {
goto early_exit;
}
DTRACE_FUNCTION_ENTRY();
#ifdef Py_GIL_DISABLED
/* Load thread-local bytecode */
if (frame->tlbc_index != ((_PyThreadStateImpl *)tstate)->tlbc_index) {

View file

@ -305,11 +305,24 @@ GETITEM(PyObject *v, Py_ssize_t i) {
#define CONSTS() _PyFrame_GetCode(frame)->co_consts
#define NAMES() _PyFrame_GetCode(frame)->co_names
#ifdef WITH_DTRACE
static void dtrace_function_entry(_PyInterpreterFrame *);
static void dtrace_function_return(_PyInterpreterFrame *);
#define DTRACE_FUNCTION_ENTRY() \
if (PyDTrace_FUNCTION_ENTRY_ENABLED()) { \
dtrace_function_entry(frame); \
}
#define DTRACE_FUNCTION_RETURN() \
if (PyDTrace_FUNCTION_RETURN_ENABLED()) { \
dtrace_function_return(frame); \
}
#else
#define DTRACE_FUNCTION_ENTRY() ((void)0)
#define DTRACE_FUNCTION_RETURN() ((void)0)
#endif
/* This takes a uint16_t instead of a _Py_BackoffCounter,
* because it is used directly on the cache entry in generated code,
* which is always an integral type. */

View file

@ -1925,6 +1925,7 @@
ASSERT_WITHIN_STACK_BOUNDS(__FILE__, __LINE__);
_PyFrame_SetStackPointer(frame, stack_pointer);
assert(STACK_LEVEL() == 0);
DTRACE_FUNCTION_RETURN();
_Py_LeaveRecursiveCallPy(tstate);
_PyInterpreterFrame *dying = frame;
frame = tstate->current_frame = dying->previous;
@ -2080,6 +2081,7 @@
stack_pointer += -1;
ASSERT_WITHIN_STACK_BOUNDS(__FILE__, __LINE__);
_PyFrame_SetStackPointer(frame, stack_pointer);
DTRACE_FUNCTION_RETURN();
tstate->exc_info = gen->gi_exc_state.previous_item;
gen->gi_exc_state.previous_item = NULL;
_Py_LeaveRecursiveCallPy(tstate);

View file

@ -7093,6 +7093,7 @@
ASSERT_WITHIN_STACK_BOUNDS(__FILE__, __LINE__);
_PyFrame_SetStackPointer(frame, stack_pointer);
assert(STACK_LEVEL() == 0);
DTRACE_FUNCTION_RETURN();
_Py_LeaveRecursiveCallPy(tstate);
_PyInterpreterFrame *dying = frame;
frame = tstate->current_frame = dying->previous;
@ -7150,6 +7151,7 @@
stack_pointer += -1;
ASSERT_WITHIN_STACK_BOUNDS(__FILE__, __LINE__);
_PyFrame_SetStackPointer(frame, stack_pointer);
DTRACE_FUNCTION_RETURN();
tstate->exc_info = gen->gi_exc_state.previous_item;
gen->gi_exc_state.previous_item = NULL;
_Py_LeaveRecursiveCallPy(tstate);
@ -10056,6 +10058,7 @@
ASSERT_WITHIN_STACK_BOUNDS(__FILE__, __LINE__);
_PyFrame_SetStackPointer(frame, stack_pointer);
assert(STACK_LEVEL() == 0);
DTRACE_FUNCTION_RETURN();
_Py_LeaveRecursiveCallPy(tstate);
_PyInterpreterFrame *dying = frame;
frame = tstate->current_frame = dying->previous;
@ -11795,6 +11798,7 @@
stack_pointer += -1;
ASSERT_WITHIN_STACK_BOUNDS(__FILE__, __LINE__);
_PyFrame_SetStackPointer(frame, stack_pointer);
DTRACE_FUNCTION_RETURN();
tstate->exc_info = gen->gi_exc_state.previous_item;
gen->gi_exc_state.previous_item = NULL;
_Py_LeaveRecursiveCallPy(tstate);
@ -11970,6 +11974,7 @@ JUMP_TO_LABEL(error);
if (too_deep) {
JUMP_TO_LABEL(exit_unwind);
}
DTRACE_FUNCTION_ENTRY();
next_instr = frame->instr_ptr;
#ifdef Py_DEBUG
int lltrace = maybe_lltrace_resume_frame(frame, GLOBALS());