From 4dd900c65ae7a770cf40dbb70f2955416beaa958 Mon Sep 17 00:00:00 2001 From: Tian Gao Date: Fri, 15 Sep 2023 15:47:35 -0700 Subject: [PATCH 1/6] Use local monitoring for opcode trace --- Include/internal/pycore_ceval.h | 2 ++ Include/internal/pycore_instruments.h | 2 ++ Objects/frameobject.c | 9 ++++++ Python/instrumentation.c | 17 ++++++++++ Python/legacy_tracing.c | 45 +++++++++++++++++++++++++-- 5 files changed, 73 insertions(+), 2 deletions(-) diff --git a/Include/internal/pycore_ceval.h b/Include/internal/pycore_ceval.h index e9535023cec46b..8368f9eb90135c 100644 --- a/Include/internal/pycore_ceval.h +++ b/Include/internal/pycore_ceval.h @@ -20,6 +20,8 @@ PyAPI_FUNC(int) _PyEval_SetProfile(PyThreadState *tstate, Py_tracefunc func, PyO extern int _PyEval_SetTrace(PyThreadState *tstate, Py_tracefunc func, PyObject *arg); +extern int _PyEval_SetOpcodeTrace(PyFrameObject *f, bool enable); + // Helper to look up a builtin object // Export for 'array' shared extension PyAPI_FUNC(PyObject*) _PyEval_GetBuiltin(PyObject *); diff --git a/Include/internal/pycore_instruments.h b/Include/internal/pycore_instruments.h index 97dcfb9f8672f7..eae8371ef7f9b8 100644 --- a/Include/internal/pycore_instruments.h +++ b/Include/internal/pycore_instruments.h @@ -63,6 +63,8 @@ typedef uint32_t _PyMonitoringEventSet; PyObject *_PyMonitoring_RegisterCallback(int tool_id, int event_id, PyObject *obj); int _PyMonitoring_SetEvents(int tool_id, _PyMonitoringEventSet events); +int _PyMonitoring_SetLocalEvents(PyCodeObject *code, int tool_id, _PyMonitoringEventSet events); +int _PyMonitoring_GetLocalEvents(PyCodeObject *code, int tool_id, _PyMonitoringEventSet *events); extern int _Py_call_instrumentation(PyThreadState *tstate, int event, diff --git a/Objects/frameobject.c b/Objects/frameobject.c index d75444393f3697..a13cc01f3405f0 100644 --- a/Objects/frameobject.c +++ b/Objects/frameobject.c @@ -128,9 +128,13 @@ frame_settrace_opcodes(PyFrameObject *f, PyObject* value, void *Py_UNUSED(ignore if (value == Py_True) { f->f_trace_opcodes = 1; _PyInterpreterState_GET()->f_opcode_trace_set = true; + if (f->f_trace) { + return _PyEval_SetOpcodeTrace(f, true); + } } else { f->f_trace_opcodes = 0; + return _PyEval_SetOpcodeTrace(f, false); } return 0; } @@ -840,6 +844,11 @@ frame_settrace(PyFrameObject *f, PyObject* v, void *closure) } if (v != f->f_trace) { Py_XSETREF(f->f_trace, Py_XNewRef(v)); + if (v == NULL) { + return _PyEval_SetOpcodeTrace(f, false); + } else if (f->f_trace_opcodes) { + return _PyEval_SetOpcodeTrace(f, true); + } } return 0; } diff --git a/Python/instrumentation.c b/Python/instrumentation.c index 0768c82ba29882..97648b080830f9 100644 --- a/Python/instrumentation.c +++ b/Python/instrumentation.c @@ -1808,6 +1808,23 @@ _PyMonitoring_SetLocalEvents(PyCodeObject *code, int tool_id, _PyMonitoringEvent return 0; } +int +_PyMonitoring_GetLocalEvents(PyCodeObject *code, int tool_id, _PyMonitoringEventSet *events) +{ + assert(0 <= tool_id && tool_id < PY_MONITORING_TOOL_IDS); + PyInterpreterState *interp = _PyInterpreterState_GET(); + if (check_tool(interp, tool_id)) { + return -1; + } + if (code->_co_monitoring == NULL) { + *events = 0; + return 0; + } + _Py_LocalMonitors *local = &code->_co_monitoring->local_monitors; + *events = get_local_events(local, tool_id); + return 0; +} + /*[clinic input] module monitoring [clinic start generated code]*/ diff --git a/Python/legacy_tracing.c b/Python/legacy_tracing.c index 9258091afc7c49..3659d324a88bd9 100644 --- a/Python/legacy_tracing.c +++ b/Python/legacy_tracing.c @@ -107,6 +107,33 @@ sys_profile_call_or_return( Py_RETURN_NONE; } +int +_PyEval_SetOpcodeTrace( + PyFrameObject *frame, + bool enable +) { + assert(frame != NULL); + assert(PyCode_Check(frame->f_frame->f_executable)); + + PyCodeObject *code = (PyCodeObject *)frame->f_frame->f_executable; + _PyMonitoringEventSet events = 0; + if (_PyMonitoring_GetLocalEvents(code, PY_MONITORING_SYS_TRACE_ID, &events) == 0) { + if (enable) { + if (events & (1 << PY_MONITORING_EVENT_INSTRUCTION)) { + return 0; + } + events |= (1 << PY_MONITORING_EVENT_INSTRUCTION); + } else { + if (!(events & (1 << PY_MONITORING_EVENT_INSTRUCTION))) { + return 0; + } + events &= (~(1 << PY_MONITORING_EVENT_INSTRUCTION)); + } + return _PyMonitoring_SetLocalEvents(code, PY_MONITORING_SYS_TRACE_ID, events); + } + return -1; +} + static PyObject * call_trace_func(_PyLegacyEventHandler *self, PyObject *arg) { @@ -120,6 +147,12 @@ call_trace_func(_PyLegacyEventHandler *self, PyObject *arg) "Missing frame when calling trace function."); return NULL; } + if (frame->f_trace_opcodes) { + if (_PyEval_SetOpcodeTrace(frame, true) != 0) { + return NULL; + } + } + Py_INCREF(frame); int err = tstate->c_tracefunc(tstate->c_traceobj, frame, self->event, arg); Py_DECREF(frame); @@ -211,6 +244,9 @@ sys_trace_instruction_func( return NULL; } if (!frame->f_trace_opcodes) { + if (_PyEval_SetOpcodeTrace(frame, false) != 0) { + return NULL; + } Py_RETURN_NONE; } Py_INCREF(frame); @@ -505,8 +541,13 @@ _PyEval_SetTrace(PyThreadState *tstate, Py_tracefunc func, PyObject *arg) (1 << PY_MONITORING_EVENT_PY_UNWIND) | (1 << PY_MONITORING_EVENT_PY_THROW) | (1 << PY_MONITORING_EVENT_STOP_ITERATION) | (1 << PY_MONITORING_EVENT_EXCEPTION_HANDLED); - if (tstate->interp->f_opcode_trace_set) { - events |= (1 << PY_MONITORING_EVENT_INSTRUCTION); + } + + PyFrameObject* frame = PyEval_GetFrame(); + if (frame->f_trace_opcodes) { + int ret = _PyEval_SetOpcodeTrace(frame, true); + if (ret != 0) { + return ret; } } return _PyMonitoring_SetEvents(PY_MONITORING_SYS_TRACE_ID, events); From dfc5aa6dba9a86ed8a545e642caef497f5ce69ce Mon Sep 17 00:00:00 2001 From: Tian Gao Date: Fri, 15 Sep 2023 16:06:22 -0700 Subject: [PATCH 2/6] Remove f_opcode_trace_set and fix a bug --- Include/internal/pycore_interp.h | 1 - Objects/frameobject.c | 1 - Python/legacy_tracing.c | 4 ++-- Python/pystate.c | 2 -- 4 files changed, 2 insertions(+), 6 deletions(-) diff --git a/Include/internal/pycore_interp.h b/Include/internal/pycore_interp.h index ba5764e943e676..2d05536e5abc54 100644 --- a/Include/internal/pycore_interp.h +++ b/Include/internal/pycore_interp.h @@ -189,7 +189,6 @@ struct _is { uint32_t next_func_version; _Py_GlobalMonitors monitors; - bool f_opcode_trace_set; bool sys_profile_initialized; bool sys_trace_initialized; Py_ssize_t sys_profiling_threads; /* Count of threads with c_profilefunc set */ diff --git a/Objects/frameobject.c b/Objects/frameobject.c index a13cc01f3405f0..f2f8851ed412ad 100644 --- a/Objects/frameobject.c +++ b/Objects/frameobject.c @@ -127,7 +127,6 @@ frame_settrace_opcodes(PyFrameObject *f, PyObject* value, void *Py_UNUSED(ignore } if (value == Py_True) { f->f_trace_opcodes = 1; - _PyInterpreterState_GET()->f_opcode_trace_set = true; if (f->f_trace) { return _PyEval_SetOpcodeTrace(f, true); } diff --git a/Python/legacy_tracing.c b/Python/legacy_tracing.c index 3659d324a88bd9..085781b60285dc 100644 --- a/Python/legacy_tracing.c +++ b/Python/legacy_tracing.c @@ -243,14 +243,14 @@ sys_trace_instruction_func( "Missing frame when calling trace function."); return NULL; } - if (!frame->f_trace_opcodes) { + PyThreadState *tstate = _PyThreadState_GET(); + if (!tstate->c_tracefunc || !frame->f_trace_opcodes) { if (_PyEval_SetOpcodeTrace(frame, false) != 0) { return NULL; } Py_RETURN_NONE; } Py_INCREF(frame); - PyThreadState *tstate = _PyThreadState_GET(); int err = tstate->c_tracefunc(tstate->c_traceobj, frame, self->event, Py_None); frame->f_lineno = 0; Py_DECREF(frame); diff --git a/Python/pystate.c b/Python/pystate.c index b5c4fd7fb50616..788496b8193554 100644 --- a/Python/pystate.c +++ b/Python/pystate.c @@ -702,7 +702,6 @@ init_interpreter(PyInterpreterState *interp, /* Fix the self-referential, statically initialized fields. */ interp->dtoa = (struct _dtoa_state)_dtoa_state_INIT(interp); } - interp->f_opcode_trace_set = false; interp->_initialized = 1; return _PyStatus_OK(); } @@ -947,7 +946,6 @@ interpreter_clear(PyInterpreterState *interp, PyThreadState *tstate) interp->code_watchers[i] = NULL; } interp->active_code_watchers = 0; - interp->f_opcode_trace_set = false; // XXX Once we have one allocator per interpreter (i.e. // per-interpreter GC) we must ensure that all of the interpreter's // objects have been cleaned up at the point. From ebf9d029370abdcad936ab1833e79dd8969b5441 Mon Sep 17 00:00:00 2001 From: Tian Gao Date: Fri, 15 Sep 2023 16:32:10 -0700 Subject: [PATCH 3/6] Remove redundant disable --- Objects/frameobject.c | 4 +--- Python/legacy_tracing.c | 13 +++++++------ 2 files changed, 8 insertions(+), 9 deletions(-) diff --git a/Objects/frameobject.c b/Objects/frameobject.c index f2f8851ed412ad..c1f0ede1b23786 100644 --- a/Objects/frameobject.c +++ b/Objects/frameobject.c @@ -843,9 +843,7 @@ frame_settrace(PyFrameObject *f, PyObject* v, void *closure) } if (v != f->f_trace) { Py_XSETREF(f->f_trace, Py_XNewRef(v)); - if (v == NULL) { - return _PyEval_SetOpcodeTrace(f, false); - } else if (f->f_trace_opcodes) { + if (v != NULL && f->f_trace_opcodes) { return _PyEval_SetOpcodeTrace(f, true); } } diff --git a/Python/legacy_tracing.c b/Python/legacy_tracing.c index 085781b60285dc..133795bbd3a202 100644 --- a/Python/legacy_tracing.c +++ b/Python/legacy_tracing.c @@ -541,14 +541,15 @@ _PyEval_SetTrace(PyThreadState *tstate, Py_tracefunc func, PyObject *arg) (1 << PY_MONITORING_EVENT_PY_UNWIND) | (1 << PY_MONITORING_EVENT_PY_THROW) | (1 << PY_MONITORING_EVENT_STOP_ITERATION) | (1 << PY_MONITORING_EVENT_EXCEPTION_HANDLED); - } - PyFrameObject* frame = PyEval_GetFrame(); - if (frame->f_trace_opcodes) { - int ret = _PyEval_SetOpcodeTrace(frame, true); - if (ret != 0) { - return ret; + PyFrameObject* frame = PyEval_GetFrame(); + if (frame->f_trace_opcodes) { + int ret = _PyEval_SetOpcodeTrace(frame, true); + if (ret != 0) { + return ret; + } } } + return _PyMonitoring_SetEvents(PY_MONITORING_SYS_TRACE_ID, events); } From c2075a4da6e0117094b1350d7ecb0cdcafb5c789 Mon Sep 17 00:00:00 2001 From: "blurb-it[bot]" <43283697+blurb-it[bot]@users.noreply.github.com> Date: Fri, 15 Sep 2023 23:39:45 +0000 Subject: [PATCH 4/6] =?UTF-8?q?=F0=9F=93=9C=F0=9F=A4=96=20Added=20by=20blu?= =?UTF-8?q?rb=5Fit.?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../2023-09-15-23-39-43.gh-issue-103615.WZavly.rst | 1 + 1 file changed, 1 insertion(+) create mode 100644 Misc/NEWS.d/next/Core and Builtins/2023-09-15-23-39-43.gh-issue-103615.WZavly.rst diff --git a/Misc/NEWS.d/next/Core and Builtins/2023-09-15-23-39-43.gh-issue-103615.WZavly.rst b/Misc/NEWS.d/next/Core and Builtins/2023-09-15-23-39-43.gh-issue-103615.WZavly.rst new file mode 100644 index 00000000000000..2a0e10b84ccf32 --- /dev/null +++ b/Misc/NEWS.d/next/Core and Builtins/2023-09-15-23-39-43.gh-issue-103615.WZavly.rst @@ -0,0 +1 @@ +Use local events for opcode tracing From e4f7e9706281136ea6eae0affca2a175cbeae975 Mon Sep 17 00:00:00 2001 From: Tian Gao Date: Fri, 29 Sep 2023 16:33:38 -0700 Subject: [PATCH 5/6] Add test for setting f_trace_opcodes after settrace --- Lib/test/test_sys_settrace.py | 37 +++++++++++++++++++++++++++++++++++ 1 file changed, 37 insertions(+) diff --git a/Lib/test/test_sys_settrace.py b/Lib/test/test_sys_settrace.py index f02169602e4925..ce042979abb262 100644 --- a/Lib/test/test_sys_settrace.py +++ b/Lib/test/test_sys_settrace.py @@ -9,6 +9,10 @@ import asyncio from test.support import import_helper import contextlib +import os +import tempfile +import textwrap +import subprocess support.requires_working_socket(module=True) @@ -1801,6 +1805,39 @@ def compare_events(self, line_offset, events, expected_events): def make_tracer(): return Tracer(trace_opcode_events=True) + def test_trace_opcodes_after_settrace(self): + """Make sure setting f_trace_opcodes after starting trace works even + if it's the first time f_trace_opcodes is being set. GH-103615""" + + code = textwrap.dedent(""" + import sys + + def opcode_trace_func(frame, event, arg): + if event == "opcode": + print("opcode trace triggered") + return opcode_trace_func + + sys.settrace(opcode_trace_func) + sys._getframe().f_trace = opcode_trace_func + sys._getframe().f_trace_opcodes = True + a = 1 + """) + + # We can't use context manager because Windows can't execute a file while + # it's being written + tmp = tempfile.NamedTemporaryFile(delete=False, suffix='.py') + tmp.write(code.encode('utf-8')) + tmp.close() + try: + p = subprocess.Popen([sys.executable, tmp.name], stdout=subprocess.PIPE, stderr=subprocess.PIPE) + p.wait() + out = p.stdout.read() + finally: + os.remove(tmp.name) + p.stdout.close() + p.stderr.close() + self.assertIn(b"opcode trace triggered", out) + class RaisingTraceFuncTestCase(unittest.TestCase): def setUp(self): From 3a8811a35fcae6e63ad437679254151247617f52 Mon Sep 17 00:00:00 2001 From: Tian Gao Date: Tue, 24 Oct 2023 11:59:39 -0700 Subject: [PATCH 6/6] Change error style --- Python/legacy_tracing.c | 28 +++++++++++++++------------- 1 file changed, 15 insertions(+), 13 deletions(-) diff --git a/Python/legacy_tracing.c b/Python/legacy_tracing.c index a221726a9d5e8e..b496d3c179d83b 100644 --- a/Python/legacy_tracing.c +++ b/Python/legacy_tracing.c @@ -117,21 +117,23 @@ _PyEval_SetOpcodeTrace( PyCodeObject *code = (PyCodeObject *)frame->f_frame->f_executable; _PyMonitoringEventSet events = 0; - if (_PyMonitoring_GetLocalEvents(code, PY_MONITORING_SYS_TRACE_ID, &events) == 0) { - if (enable) { - if (events & (1 << PY_MONITORING_EVENT_INSTRUCTION)) { - return 0; - } - events |= (1 << PY_MONITORING_EVENT_INSTRUCTION); - } else { - if (!(events & (1 << PY_MONITORING_EVENT_INSTRUCTION))) { - return 0; - } - events &= (~(1 << PY_MONITORING_EVENT_INSTRUCTION)); + + if (_PyMonitoring_GetLocalEvents(code, PY_MONITORING_SYS_TRACE_ID, &events) < 0) { + return -1; + } + + if (enable) { + if (events & (1 << PY_MONITORING_EVENT_INSTRUCTION)) { + return 0; + } + events |= (1 << PY_MONITORING_EVENT_INSTRUCTION); + } else { + if (!(events & (1 << PY_MONITORING_EVENT_INSTRUCTION))) { + return 0; } - return _PyMonitoring_SetLocalEvents(code, PY_MONITORING_SYS_TRACE_ID, events); + events &= (~(1 << PY_MONITORING_EVENT_INSTRUCTION)); } - return -1; + return _PyMonitoring_SetLocalEvents(code, PY_MONITORING_SYS_TRACE_ID, events); } static PyObject *