diff --git a/Lib/test/dtracedata/call_stack.py b/Lib/test/dtracedata/call_stack.py index ee9f3ae8d6c..11c0369d4ba 100644 --- a/Lib/test/dtracedata/call_stack.py +++ b/Lib/test/dtracedata/call_stack.py @@ -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 diff --git a/Lib/test/dtracedata/call_stack.stp.expected b/Lib/test/dtracedata/call_stack.stp.expected index 32cf396f820..6f8c19847ec 100644 --- a/Lib/test/dtracedata/call_stack.stp.expected +++ b/Lib/test/dtracedata/call_stack.stp.expected @@ -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 diff --git a/Lib/test/dtracedata/line.d b/Lib/test/dtracedata/line.d deleted file mode 100644 index 03f22db6fcc..00000000000 --- a/Lib/test/dtracedata/line.d +++ /dev/null @@ -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); -} diff --git a/Lib/test/dtracedata/line.d.expected b/Lib/test/dtracedata/line.d.expected deleted file mode 100644 index 9b16ce76ee6..00000000000 --- a/Lib/test/dtracedata/line.d.expected +++ /dev/null @@ -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 diff --git a/Lib/test/dtracedata/line.py b/Lib/test/dtracedata/line.py deleted file mode 100644 index 0930ff391f7..00000000000 --- a/Lib/test/dtracedata/line.py +++ /dev/null @@ -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() diff --git a/Lib/test/test_dtrace.py b/Lib/test/test_dtrace.py index e1adf8e9748..861468a7108 100644 --- a/Lib/test/test_dtrace.py +++ b/Lib/test/test_dtrace.py @@ -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 entry/return and may have slight timing + # differences compared to SystemTap due to probe firing order + EXPECTED = { + "call_stack": """function__entry:call_stack.py::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::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", ] diff --git a/Misc/NEWS.d/next/Core_and_Builtins/2025-12-08-00-25-35.gh-issue-98894.hKWyfqNx.rst b/Misc/NEWS.d/next/Core_and_Builtins/2025-12-08-00-25-35.gh-issue-98894.hKWyfqNx.rst new file mode 100644 index 00000000000..09ccf198a90 --- /dev/null +++ b/Misc/NEWS.d/next/Core_and_Builtins/2025-12-08-00-25-35.gh-issue-98894.hKWyfqNx.rst @@ -0,0 +1,2 @@ +Restore ``function__entry`` and ``function__return`` DTrace/SystemTap probes +that were broken since Python 3.11. diff --git a/Python/bytecodes.c b/Python/bytecodes.c index 4ba255d28bd..296bcf1b527 100644 --- a/Python/bytecodes.c +++ b/Python/bytecodes.c @@ -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()); diff --git a/Python/ceval.c b/Python/ceval.c index a1d54bd058b..38eb91ea5cb 100644 --- a/Python/ceval.c +++ b/Python/ceval.c @@ -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) { diff --git a/Python/ceval_macros.h b/Python/ceval_macros.h index edf8fc9a57d..41646970fc6 100644 --- a/Python/ceval_macros.h +++ b/Python/ceval_macros.h @@ -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. */ diff --git a/Python/executor_cases.c.h b/Python/executor_cases.c.h index 7273a87681b..908dd1afd1e 100644 --- a/Python/executor_cases.c.h +++ b/Python/executor_cases.c.h @@ -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); diff --git a/Python/generated_cases.c.h b/Python/generated_cases.c.h index 68d73cccec4..c6cf3dfa17f 100644 --- a/Python/generated_cases.c.h +++ b/Python/generated_cases.c.h @@ -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());