From a0098661c8e72a6599b5f73b058546a7789c279c Mon Sep 17 00:00:00 2001 From: Nick Coghlan Date: Mon, 4 Sep 2017 16:20:08 -0700 Subject: [PATCH 1/7] bpo-31344: Per-frame control of trace events f_trace_lines: enable/disable line trace events f_trace_opcodes: enable/disable opcode trace events These are intended primarily for testing of the interpreter itself, as they make it much easier to emulate signals arriving at unfortunate times. --- Doc/library/sys.rst | 19 ++++++- Doc/reference/datamodel.rst | 12 ++++- Include/frameobject.h | 2 + Include/pystate.h | 7 ++- Lib/test/test_sys_settrace.py | 50 +++++++++++++++++-- .../2017-09-06-20-25-47.bpo-31344.XpFs-q.rst | 5 ++ Objects/frameobject.c | 4 ++ Python/ceval.c | 18 +++++-- Python/sysmodule.c | 9 ++-- 9 files changed, 110 insertions(+), 16 deletions(-) create mode 100644 Misc/NEWS.d/next/Core and Builtins/2017-09-06-20-25-47.bpo-31344.XpFs-q.rst diff --git a/Doc/library/sys.rst b/Doc/library/sys.rst index 8b94929c500c3a..d4b23069cf713b 100644 --- a/Doc/library/sys.rst +++ b/Doc/library/sys.rst @@ -1068,7 +1068,7 @@ always available. Trace functions should have three arguments: *frame*, *event*, and *arg*. *frame* is the current stack frame. *event* is a string: ``'call'``, ``'line'``, ``'return'``, ``'exception'``, ``'c_call'``, ``'c_return'``, or - ``'c_exception'``. *arg* depends on the event type. + ``'c_exception'``, ``'opcode'``. *arg* depends on the event type. The trace function is invoked (with *event* set to ``'call'``) whenever a new local scope is entered; it should return a reference to a local trace @@ -1091,6 +1091,8 @@ always available. ``None``; the return value specifies the new local trace function. See :file:`Objects/lnotab_notes.txt` for a detailed explanation of how this works. + Per-line events may be disabled for a frame by setting + :attr:`f_trace_lines` to :const:`False` on that frame. ``'return'`` A function (or other code block) is about to return. The local trace @@ -1113,6 +1115,14 @@ always available. ``'c_exception'`` A C function has raised an exception. *arg* is the C function object. + ``'opcode'`` + The interpreter is about to execute a new opcode (see :mod:`dis` for + opcode details). The local trace function is called; *arg* is + ``None``; the return value specifies the new local trace function. + Per-opcode events are not emitted by default: they must be explicitly + requested by setting :attr:`f_trace_opcodes` to :const:`True` on the + frame. + Note that as an exception is propagated down the chain of callers, an ``'exception'`` event is generated at each level. @@ -1125,6 +1135,13 @@ always available. implementation platform, rather than part of the language definition, and thus may not be available in all Python implementations. + .. versionchanged:: 3.7 + + CPython frames gained the ability to switch off per-line trace events + (by setting :attr:`f_trace_lines` to :const:`False`) and to request + per-opcode trace events (by setting :attr:`f_trace_opcodes` to + :const:`True`) + .. function:: set_asyncgen_hooks(firstiter, finalizer) Accepts two optional keyword arguments which are callables that accept an diff --git a/Doc/reference/datamodel.rst b/Doc/reference/datamodel.rst index 24a2618b01e61b..2516c86544e7c3 100644 --- a/Doc/reference/datamodel.rst +++ b/Doc/reference/datamodel.rst @@ -970,10 +970,20 @@ Internal types .. index:: single: f_trace (frame attribute) + single: f_trace_lines (frame attribute) + single: f_trace_opcodes (frame attribute) single: f_lineno (frame attribute) Special writable attributes: :attr:`f_trace`, if not ``None``, is a function - called at the start of each source code line (this is used by the debugger); + called for various events during code execution (this is used by the debugger). + Normally an event is triggered for each new source line - this can be + disabled by setting :attr:`f_trace_lines` to :const:`False`. + + Implementations *may* allow per-opcode events to be requested by setting + :attr:`f_trace_opcodes` to :const:`True`. This is intended specifically + for interpreter signal safety testing, and may have surprising results + if exceptions are raised by the trace function. + :attr:`f_lineno` is the current line number of the frame --- writing to this from within a trace function jumps to the given line (only for the bottom-most frame). A debugger can implement a Jump command (aka Set Next Statement) diff --git a/Include/frameobject.h b/Include/frameobject.h index 616c611c7e8e67..dbe0a840df964a 100644 --- a/Include/frameobject.h +++ b/Include/frameobject.h @@ -27,6 +27,8 @@ typedef struct _frame { to the current stack top. */ PyObject **f_stacktop; PyObject *f_trace; /* Trace function */ + char f_trace_lines; /* Emit per-line trace events? */ + char f_trace_opcodes; /* Emit per-opcode trace events? */ /* In a generator, we need to be able to swap between the exception state inside the generator and the exception state of the calling diff --git a/Include/pystate.h b/Include/pystate.h index 6229236972a418..f957d536dcdceb 100644 --- a/Include/pystate.h +++ b/Include/pystate.h @@ -92,7 +92,11 @@ typedef struct _is { /* Py_tracefunc return -1 when raising an exception, or 0 for success. */ typedef int (*Py_tracefunc)(PyObject *, struct _frame *, int, PyObject *); -/* The following values are used for 'what' for tracefunc functions: */ +/* The following values are used for 'what' for tracefunc functions + * + * To add a new kind of trace event, also update "trace_init" in + * Python/sysmodule.c to define the Python level event name + */ #define PyTrace_CALL 0 #define PyTrace_EXCEPTION 1 #define PyTrace_LINE 2 @@ -100,6 +104,7 @@ typedef int (*Py_tracefunc)(PyObject *, struct _frame *, int, PyObject *); #define PyTrace_C_CALL 4 #define PyTrace_C_EXCEPTION 5 #define PyTrace_C_RETURN 6 +#define PyTrace_OPCODE 7 #endif #ifdef Py_LIMITED_API diff --git a/Lib/test/test_sys_settrace.py b/Lib/test/test_sys_settrace.py index 25c5835fd6faac..aca283809e980e 100644 --- a/Lib/test/test_sys_settrace.py +++ b/Lib/test/test_sys_settrace.py @@ -234,12 +234,21 @@ def generator_example(): class Tracer: - def __init__(self): + def __init__(self, trace_line_events=None, trace_opcode_events=None): + self.trace_line_events = trace_line_events + self.trace_opcode_events = trace_opcode_events self.events = [] + def _reconfigure_frame(self, frame): + if self.trace_line_events is not None: + frame.f_trace_lines = self.trace_line_events + if self.trace_opcode_events is not None: + frame.f_trace_opcodes = self.trace_opcode_events def trace(self, frame, event, arg): + self._reconfigure_frame(frame) self.events.append((frame.f_lineno, event)) return self.trace def traceWithGenexp(self, frame, event, arg): + self._reconfigure_frame(frame) (o for o in [1]) self.events.append((frame.f_lineno, event)) return self.trace @@ -257,6 +266,10 @@ def tearDown(self): if self.using_gc: gc.enable() + @staticmethod + def make_tracer(): + return Tracer() + def compare_events(self, line_offset, events, expected_events): events = [(l - line_offset, e) for (l, e) in events] if events != expected_events: @@ -266,7 +279,7 @@ def compare_events(self, line_offset, events, expected_events): [str(x) for x in events]))) def run_and_compare(self, func, events): - tracer = Tracer() + tracer = self.make_tracer() sys.settrace(tracer.trace) func() sys.settrace(None) @@ -277,7 +290,7 @@ def run_test(self, func): self.run_and_compare(func, func.events) def run_test2(self, func): - tracer = Tracer() + tracer = self.make_tracer() func(tracer.trace) sys.settrace(None) self.compare_events(func.__code__.co_firstlineno, @@ -329,7 +342,7 @@ def test_13_genexp(self): # and if the traced function contains another generator # that is not completely exhausted, the trace stopped. # Worse: the 'finally' clause was not invoked. - tracer = Tracer() + tracer = self.make_tracer() sys.settrace(tracer.traceWithGenexp) generator_example() sys.settrace(None) @@ -398,6 +411,33 @@ def func(): (1, 'line')]) +class SkipLineEventsTraceTestCase(TraceTestCase): + """Repeat the trace tests, but with per-line events skipped""" + + def compare_events(self, line_offset, events, expected_events): + skip_line_events = [e for e in expected_events if e[1] != 'line'] + super().compare_events(line_offset, events, skip_line_events) + + @staticmethod + def make_tracer(): + return Tracer(trace_line_events=False) + + +@support.cpython_only +class TraceOpcodesTestCase(TraceTestCase): + """Repeat the trace tests, but with per-opcodes events enabled""" + + def compare_events(self, line_offset, events, expected_events): + skip_opcode_events = [e for e in events if e[1] != 'opcode'] + if len(events) > 1: + self.assertLess(len(skip_opcode_events), len(events)) + super().compare_events(line_offset, skip_opcode_events, expected_events) + + @staticmethod + def make_tracer(): + return Tracer(trace_opcode_events=True) + + class RaisingTraceFuncTestCase(unittest.TestCase): def setUp(self): self.addCleanup(sys.settrace, sys.gettrace()) @@ -846,6 +886,8 @@ class fake_function: def test_main(): support.run_unittest( TraceTestCase, + SkipLineEventsTraceTestCase, + TraceOpcodesTestCase, RaisingTraceFuncTestCase, JumpTestCase ) diff --git a/Misc/NEWS.d/next/Core and Builtins/2017-09-06-20-25-47.bpo-31344.XpFs-q.rst b/Misc/NEWS.d/next/Core and Builtins/2017-09-06-20-25-47.bpo-31344.XpFs-q.rst new file mode 100644 index 00000000000000..3fa8433ccb611b --- /dev/null +++ b/Misc/NEWS.d/next/Core and Builtins/2017-09-06-20-25-47.bpo-31344.XpFs-q.rst @@ -0,0 +1,5 @@ +For finer control of tracing behaviour when testing the interpreter, two new +frame attributes have been added to control the emission of particular trace +events: ``f_trace_lines`` (``True`` by default) to turn off per-line trace +events; and ``f_trace_opcodes`` (``False by default) to turn on per-opcode +trace events. diff --git a/Objects/frameobject.c b/Objects/frameobject.c index 84483195ab2ad4..b3f0b65e51c7ac 100644 --- a/Objects/frameobject.c +++ b/Objects/frameobject.c @@ -15,6 +15,8 @@ static PyMemberDef frame_memberlist[] = { {"f_builtins", T_OBJECT, OFF(f_builtins), READONLY}, {"f_globals", T_OBJECT, OFF(f_globals), READONLY}, {"f_lasti", T_INT, OFF(f_lasti), READONLY}, + {"f_trace_lines", T_BOOL, OFF(f_trace_lines), 0}, + {"f_trace_opcodes", T_BOOL, OFF(f_trace_opcodes), 0}, {NULL} /* Sentinel */ }; @@ -728,6 +730,8 @@ _PyFrame_New_NoTrack(PyThreadState *tstate, PyCodeObject *code, f->f_iblock = 0; f->f_executing = 0; f->f_gen = NULL; + f->f_trace_opcodes = 0; + f->f_trace_lines = 1; return f; } diff --git a/Python/ceval.c b/Python/ceval.c index 8fc65cdcc040b2..5f303dce347c47 100644 --- a/Python/ceval.c +++ b/Python/ceval.c @@ -4458,12 +4458,20 @@ maybe_call_line_trace(Py_tracefunc func, PyObject *obj, *instr_lb = bounds.ap_lower; *instr_ub = bounds.ap_upper; } - /* If the last instruction falls at the start of a line or if - it represents a jump backwards, update the frame's line - number and call the trace function. */ - if (frame->f_lasti == *instr_lb || frame->f_lasti < *instr_prev) { + /* Always emit an opcode event if we're tracing all opcodes. + */ + if (frame->f_trace_opcodes) { + result = call_trace(func, obj, tstate, frame, PyTrace_OPCODE, Py_None); + } + /* If the last instruction falls at the start of a line or if it + represents a jump backwards, update the frame's line number and + then call the trace function if we're tracing source lines. + */ + if ((frame->f_lasti == *instr_lb || frame->f_lasti < *instr_prev)) { frame->f_lineno = line; - result = call_trace(func, obj, tstate, frame, PyTrace_LINE, Py_None); + if (frame->f_trace_lines) { + result = call_trace(func, obj, tstate, frame, PyTrace_LINE, Py_None); + } } *instr_prev = frame->f_lasti; return result; diff --git a/Python/sysmodule.c b/Python/sysmodule.c index fba7220e44ccd0..021b95d2c3d444 100644 --- a/Python/sysmodule.c +++ b/Python/sysmodule.c @@ -349,18 +349,19 @@ same value."); * Cached interned string objects used for calling the profile and * trace functions. Initialized by trace_init(). */ -static PyObject *whatstrings[7] = {NULL, NULL, NULL, NULL, NULL, NULL, NULL}; +static PyObject *whatstrings[8] = {NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL}; static int trace_init(void) { - static const char * const whatnames[7] = { + static const char * const whatnames[8] = { "call", "exception", "line", "return", - "c_call", "c_exception", "c_return" + "c_call", "c_exception", "c_return", + "opcode" }; PyObject *name; int i; - for (i = 0; i < 7; ++i) { + for (i = 0; i < 8; ++i) { if (whatstrings[i] == NULL) { name = PyUnicode_InternFromString(whatnames[i]); if (name == NULL) From 75659ffd033b3d1b20db17e273b712b7db974c84 Mon Sep 17 00:00:00 2001 From: Nick Coghlan Date: Thu, 7 Sep 2017 10:01:45 -0700 Subject: [PATCH 2/7] Add What's New entry for tracing changes --- Doc/whatsnew/3.7.rst | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/Doc/whatsnew/3.7.rst b/Doc/whatsnew/3.7.rst index 14c2182e26c3ea..5ee41dcc20b170 100644 --- a/Doc/whatsnew/3.7.rst +++ b/Doc/whatsnew/3.7.rst @@ -348,6 +348,18 @@ Build and C API Changes (Contributed by Antoine Pitrou in :issue:`31370`.). +Other CPython Implementation Changes +==================================== + +* Trace hooks may now opt out of receiving ``line`` events from the interpreter + by setting the new ``f_trace_lines`` attribute to :const:`False` on the frame + being traced. (Contributed by Nick Coghlan in :issue:`31344`.) + +* Trace hooks may now opt in to receiving ``opcode`` events from the interpreter + by setting the new ``f_trace_opcodes`` attribute to :const:`True` on the frame + being traced. (Contributed by Nick Coghlan in :issue:`31344`.) + + Deprecated ========== From 141c8290a0f96149469d85c4436508817911d0ae Mon Sep 17 00:00:00 2001 From: Nick Coghlan Date: Thu, 7 Sep 2017 10:08:14 -0700 Subject: [PATCH 3/7] Fix NEWS formatting --- .../Core and Builtins/2017-09-06-20-25-47.bpo-31344.XpFs-q.rst | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Misc/NEWS.d/next/Core and Builtins/2017-09-06-20-25-47.bpo-31344.XpFs-q.rst b/Misc/NEWS.d/next/Core and Builtins/2017-09-06-20-25-47.bpo-31344.XpFs-q.rst index 3fa8433ccb611b..2b3a386d2b0081 100644 --- a/Misc/NEWS.d/next/Core and Builtins/2017-09-06-20-25-47.bpo-31344.XpFs-q.rst +++ b/Misc/NEWS.d/next/Core and Builtins/2017-09-06-20-25-47.bpo-31344.XpFs-q.rst @@ -1,5 +1,5 @@ For finer control of tracing behaviour when testing the interpreter, two new frame attributes have been added to control the emission of particular trace events: ``f_trace_lines`` (``True`` by default) to turn off per-line trace -events; and ``f_trace_opcodes`` (``False by default) to turn on per-opcode +events; and ``f_trace_opcodes`` (``False`` by default) to turn on per-opcode trace events. From 8c9fcba990328335edebbd812334721416e92c15 Mon Sep 17 00:00:00 2001 From: Nick Coghlan Date: Thu, 7 Sep 2017 10:08:32 -0700 Subject: [PATCH 4/7] Don't repeat docs in versionchanged note --- Doc/library/sys.rst | 6 ++---- 1 file changed, 2 insertions(+), 4 deletions(-) diff --git a/Doc/library/sys.rst b/Doc/library/sys.rst index d4b23069cf713b..85f31368c30621 100644 --- a/Doc/library/sys.rst +++ b/Doc/library/sys.rst @@ -1137,10 +1137,8 @@ always available. .. versionchanged:: 3.7 - CPython frames gained the ability to switch off per-line trace events - (by setting :attr:`f_trace_lines` to :const:`False`) and to request - per-opcode trace events (by setting :attr:`f_trace_opcodes` to - :const:`True`) + ``'opcode'`` event type added; :attr:`f_trace_lines` and + :attr:`f_trace_opcodes` attributes added to frames .. function:: set_asyncgen_hooks(firstiter, finalizer) From 5b453965651828e0a9ba5139b860c4b3567574df Mon Sep 17 00:00:00 2001 From: Nick Coghlan Date: Thu, 7 Sep 2017 14:08:34 -0700 Subject: [PATCH 5/7] Fix frame size test case --- Lib/test/test_sys.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Lib/test/test_sys.py b/Lib/test/test_sys.py index 04550e58b234cc..fd45abee67e5a5 100644 --- a/Lib/test/test_sys.py +++ b/Lib/test/test_sys.py @@ -971,7 +971,7 @@ class C(object): pass nfrees = len(x.f_code.co_freevars) extras = x.f_code.co_stacksize + x.f_code.co_nlocals +\ ncells + nfrees - 1 - check(x, vsize('12P3ic' + CO_MAXBLOCKS*'3i' + 'P' + extras*'P')) + check(x, vsize('8P2c4P3ic' + CO_MAXBLOCKS*'3i' + 'P' + extras*'P')) # function def func(): pass check(func, size('12P')) From aa83722441f3c16f96469e09ee7e7a950da9620f Mon Sep 17 00:00:00 2001 From: Nick Coghlan Date: Thu, 7 Sep 2017 14:09:37 -0700 Subject: [PATCH 6/7] Fix comment formatting --- Python/ceval.c | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/Python/ceval.c b/Python/ceval.c index 5f303dce347c47..a072a5fe81e47e 100644 --- a/Python/ceval.c +++ b/Python/ceval.c @@ -4458,8 +4458,7 @@ maybe_call_line_trace(Py_tracefunc func, PyObject *obj, *instr_lb = bounds.ap_lower; *instr_ub = bounds.ap_upper; } - /* Always emit an opcode event if we're tracing all opcodes. - */ + /* Always emit an opcode event if we're tracing all opcodes. */ if (frame->f_trace_opcodes) { result = call_trace(func, obj, tstate, frame, PyTrace_OPCODE, Py_None); } From 5fa7de4cab3eb0f8f50b8e90b6ec8f7e670a3387 Mon Sep 17 00:00:00 2001 From: Nick Coghlan Date: Thu, 7 Sep 2017 16:37:28 -0700 Subject: [PATCH 7/7] Address review comments --- Doc/reference/datamodel.rst | 6 +++--- Lib/test/test_sys_settrace.py | 8 +++++++- 2 files changed, 10 insertions(+), 4 deletions(-) diff --git a/Doc/reference/datamodel.rst b/Doc/reference/datamodel.rst index 2516c86544e7c3..5f932ae0de7578 100644 --- a/Doc/reference/datamodel.rst +++ b/Doc/reference/datamodel.rst @@ -980,9 +980,9 @@ Internal types disabled by setting :attr:`f_trace_lines` to :const:`False`. Implementations *may* allow per-opcode events to be requested by setting - :attr:`f_trace_opcodes` to :const:`True`. This is intended specifically - for interpreter signal safety testing, and may have surprising results - if exceptions are raised by the trace function. + :attr:`f_trace_opcodes` to :const:`True`. Note that this may lead to + undefined interpreter behaviour if exceptions raised by the trace + function escape to the function being traced. :attr:`f_lineno` is the current line number of the frame --- writing to this from within a trace function jumps to the given line (only for the bottom-most diff --git a/Lib/test/test_sys_settrace.py b/Lib/test/test_sys_settrace.py index aca283809e980e..ed9e6d4f492fec 100644 --- a/Lib/test/test_sys_settrace.py +++ b/Lib/test/test_sys_settrace.py @@ -238,21 +238,25 @@ def __init__(self, trace_line_events=None, trace_opcode_events=None): self.trace_line_events = trace_line_events self.trace_opcode_events = trace_opcode_events self.events = [] + def _reconfigure_frame(self, frame): if self.trace_line_events is not None: frame.f_trace_lines = self.trace_line_events if self.trace_opcode_events is not None: frame.f_trace_opcodes = self.trace_opcode_events + def trace(self, frame, event, arg): self._reconfigure_frame(frame) self.events.append((frame.f_lineno, event)) return self.trace + def traceWithGenexp(self, frame, event, arg): self._reconfigure_frame(frame) (o for o in [1]) self.events.append((frame.f_lineno, event)) return self.trace + class TraceTestCase(unittest.TestCase): # Disable gc collection when tracing, otherwise the @@ -268,6 +272,7 @@ def tearDown(self): @staticmethod def make_tracer(): + """Helper to allow test subclasses to configure tracers differently""" return Tracer() def compare_events(self, line_offset, events, expected_events): @@ -430,7 +435,8 @@ class TraceOpcodesTestCase(TraceTestCase): def compare_events(self, line_offset, events, expected_events): skip_opcode_events = [e for e in events if e[1] != 'opcode'] if len(events) > 1: - self.assertLess(len(skip_opcode_events), len(events)) + self.assertLess(len(skip_opcode_events), len(events), + msg="No 'opcode' events received by the tracer") super().compare_events(line_offset, skip_opcode_events, expected_events) @staticmethod