From e2a07e8d19f55a9a52cc177a223064136cd287fb Mon Sep 17 00:00:00 2001 From: Stefan Behnel Date: Fri, 5 Apr 2013 17:11:28 +0200 Subject: [PATCH] implement experimental support for line tracing --- CHANGES.rst | 3 ++ Cython/Compiler/Code.py | 13 ++++-- Cython/Compiler/Nodes.py | 23 +++++++---- Cython/Compiler/Options.py | 1 + Cython/Utility/Profile.c | 84 +++++++++++++++++++++++++++++++------- docs/src/reference/compilation.rst | 7 ++++ runtests.py | 5 +++ tests/run/line_trace.pyx | 65 +++++++++++++++++++++++++++++ 8 files changed, 175 insertions(+), 26 deletions(-) create mode 100644 tests/run/line_trace.pyx diff --git a/CHANGES.rst b/CHANGES.rst index 7c26a93..b465371 100644 --- a/CHANGES.rst +++ b/CHANGES.rst @@ -8,6 +8,9 @@ Cython Changelog Features added -------------- +* EXPERIMENTAL support for simple Cython code level line tracing. Enabled by + the "linetrace" compiler directive. + * Cython implemented functions make their argument and return type annotations available through the ``__annotations__`` attribute (PEP 3107). diff --git a/Cython/Compiler/Code.py b/Cython/Compiler/Code.py index 807e6e0..bb60ab2 100644 --- a/Cython/Compiler/Code.py +++ b/Cython/Compiler/Code.py @@ -467,6 +467,7 @@ class FunctionState(object): # label_counter integer counter for naming labels # in_try_finally boolean inside try of try...finally # exc_vars (string * 3) exception variables for reraise, or None + # can_trace boolean line tracing is supported in the current context # Not used for now, perhaps later def __init__(self, owner, names_taken=set()): @@ -483,6 +484,7 @@ class FunctionState(object): self.in_try_finally = 0 self.exc_vars = None + self.can_trace = False self.temps_allocated = [] # of (name, type, manage_ref, static) self.temps_free = {} # (type, manage_ref) -> list of free vars with same type/managed status @@ -1494,13 +1496,16 @@ class CCodeWriter(object): self.put_safe(code) else: self.put(code) - self.write("\n"); + self.write("\n") self.bol = 1 def emit_marker(self): - self.write("\n"); + self.write("\n") self.indent() self.write("/* %s */\n" % self.marker[1]) + if self.funcstate.can_trace and self.globalstate.directives['linetrace']: + self.indent() + self.write('__Pyx_TraceLine(%d)\n' % self.marker[0]) self.last_marker_line = self.marker[0] self.marker = None @@ -1966,10 +1971,10 @@ class CCodeWriter(object): self.putln('__Pyx_AddTraceback("%s", %s, %s, %s);' % format_tuple) def put_trace_declarations(self): - self.putln('__Pyx_TraceDeclarations'); + self.putln('__Pyx_TraceDeclarations') def put_trace_call(self, name, pos): - self.putln('__Pyx_TraceCall("%s", %s[%s], %s);' % (name, Naming.filetable_cname, self.lookup_filename(pos[0]), pos[1])); + self.putln('__Pyx_TraceCall("%s", %s[%s], %s);' % (name, Naming.filetable_cname, self.lookup_filename(pos[0]), pos[1])) def put_trace_exception(self): self.putln("__Pyx_TraceException();") diff --git a/Cython/Compiler/Nodes.py b/Cython/Compiler/Nodes.py index a4cfa48..50ba555 100644 --- a/Cython/Compiler/Nodes.py +++ b/Cython/Compiler/Nodes.py @@ -1537,10 +1537,11 @@ class FuncDefNode(StatNode, BlockNode): preprocessor_guard = self.get_preprocessor_guard() profile = code.globalstate.directives['profile'] - if profile and lenv.nogil: + linetrace = code.globalstate.directives['linetrace'] + if (linetrace or profile) and lenv.nogil: warning(self.pos, "Cannot profile nogil function.", 1) - profile = False - if profile: + profile = linetrace = False + if profile or linetrace: code.globalstate.use_utility_code( UtilityCode.load_cached("Profile", "Profile.c")) @@ -1601,7 +1602,7 @@ class FuncDefNode(StatNode, BlockNode): tempvardecl_code = code.insertion_point() self.generate_keyword_list(code) - if profile: + if profile or linetrace: code.put_trace_declarations() # ----- Extern library function declarations @@ -1616,7 +1617,7 @@ class FuncDefNode(StatNode, BlockNode): # Profiling or closures are not currently possible for cdef nogil # functions, but check them anyway have_object_args = (self.needs_closure or self.needs_outer_scope or - profile) + profile or linetrace) for arg in lenv.arg_entries: if arg.type.is_pyobject: have_object_args = True @@ -1690,10 +1691,11 @@ class FuncDefNode(StatNode, BlockNode): code.put_incref(outer_scope_cname, cenv.scope_class.type) code.put_giveref(outer_scope_cname) # ----- Trace function call - if profile: + if profile or linetrace: # this looks a bit late, but if we don't get here due to a # fatal error before hand, it's not really worth tracing code.put_trace_call(self.entry.name, self.pos) + code.funcstate.can_trace = True # ----- Fetch arguments self.generate_argument_parsing_code(env, code) # If an argument is assigned to in the body, we must @@ -1891,7 +1893,8 @@ class FuncDefNode(StatNode, BlockNode): code.putln("if (unlikely(%s == -1) && !PyErr_Occurred()) %s = -2;" % ( Naming.retval_cname, Naming.retval_cname)) - if profile: + if profile or linetrace: + code.funcstate.can_trace = False if self.return_type.is_pyobject: code.put_trace_return(Naming.retval_cname) else: @@ -6542,15 +6545,21 @@ class GILStatNode(NogilTryFinallyStatNode): else: variable = None + old_trace_config = code.funcstate.can_trace if self.state == 'gil': code.put_ensure_gil(variable=variable) + # FIXME: not that easy, tracing may not be possible at all here + #code.funcstate.can_trace = True else: code.put_release_gil(variable=variable) + code.funcstate.can_trace = False TryFinallyStatNode.generate_execution_code(self, code) if self.state_temp: self.state_temp.release(code) + + code.funcstate.can_trace = old_trace_config code.end_block() diff --git a/Cython/Compiler/Options.py b/Cython/Compiler/Options.py index 1a82164..04a1579 100644 --- a/Cython/Compiler/Options.py +++ b/Cython/Compiler/Options.py @@ -90,6 +90,7 @@ directive_defaults = { 'final' : False, 'internal' : False, 'profile': False, + 'linetrace': False, 'infer_types': None, 'infer_types.verbose': False, 'autotestdict': True, diff --git a/Cython/Utility/Profile.c b/Cython/Utility/Profile.c index 37bb4e3..704756c 100644 --- a/Cython/Utility/Profile.c +++ b/Cython/Utility/Profile.c @@ -8,11 +8,19 @@ #define CYTHON_PROFILE 1 #endif +#ifndef CYTHON_TRACE + #define CYTHON_TRACE 0 +#endif + +#if CYTHON_TRACE + #undef CYTHON_PROFILE_REUSE_FRAME +#endif + #ifndef CYTHON_PROFILE_REUSE_FRAME #define CYTHON_PROFILE_REUSE_FRAME 0 #endif -#if CYTHON_PROFILE +#if CYTHON_PROFILE || CYTHON_TRACE #include "compile.h" #include "frameobject.h" @@ -23,34 +31,49 @@ #define CYTHON_FRAME_DEL #else #define CYTHON_FRAME_MODIFIER - #define CYTHON_FRAME_DEL Py_DECREF($frame_cname) + #define CYTHON_FRAME_DEL Py_CLEAR($frame_cname) #endif - #define __Pyx_TraceDeclarations \ + #define __Pyx_TraceDeclarations \ static PyCodeObject *$frame_code_cname = NULL; \ CYTHON_FRAME_MODIFIER PyFrameObject *$frame_cname = NULL; \ int __Pyx_use_tracing = 0; #define __Pyx_TraceCall(funcname, srcfile, firstlineno) \ - if (unlikely(PyThreadState_GET()->use_tracing && PyThreadState_GET()->c_profilefunc)) { \ + if (unlikely(PyThreadState_GET()->use_tracing && \ + (PyThreadState_GET()->c_profilefunc || (CYTHON_TRACE && PyThreadState_GET()->c_tracefunc)))) { \ __Pyx_use_tracing = __Pyx_TraceSetupAndCall(&$frame_code_cname, &$frame_cname, funcname, srcfile, firstlineno); \ } #define __Pyx_TraceException() \ - if (unlikely(__Pyx_use_tracing( && PyThreadState_GET()->use_tracing && PyThreadState_GET()->c_profilefunc) { \ + if (unlikely(__Pyx_use_tracing) && PyThreadState_GET()->use_tracing && \ + (PyThreadState_GET()->c_profilefunc || (CYTHON_TRACE && PyThreadState_GET()->c_tracefunc))) { \ + PyThreadState* tstate = PyThreadState_GET(); \ + tstate->use_tracing = 0; \ PyObject *exc_info = __Pyx_GetExceptionTuple(); \ if (exc_info) { \ - PyThreadState_GET()->c_profilefunc( \ - PyThreadState_GET()->c_profileobj, $frame_cname, PyTrace_EXCEPTION, exc_info); \ + if (CYTHON_TRACE && tstate->c_tracefunc) \ + tstate->c_tracefunc( \ + tstate->c_traceobj, $frame_cname, PyTrace_EXCEPTION, exc_info); \ + tstate->c_profilefunc( \ + tstate->c_profileobj, $frame_cname, PyTrace_EXCEPTION, exc_info); \ Py_DECREF(exc_info); \ } \ + tstate->use_tracing = 1; \ } #define __Pyx_TraceReturn(result) \ - if (unlikely(__Pyx_use_tracing) && PyThreadState_GET()->use_tracing && PyThreadState_GET()->c_profilefunc) { \ - PyThreadState_GET()->c_profilefunc( \ - PyThreadState_GET()->c_profileobj, $frame_cname, PyTrace_RETURN, (PyObject*)result); \ + if (unlikely(__Pyx_use_tracing) && PyThreadState_GET()->use_tracing) { \ + PyThreadState* tstate = PyThreadState_GET(); \ + tstate->use_tracing = 0; \ + if (CYTHON_TRACE && tstate->c_tracefunc) \ + tstate->c_tracefunc( \ + tstate->c_traceobj, $frame_cname, PyTrace_RETURN, (PyObject*)result); \ + if (tstate->c_profilefunc) \ + tstate->c_profilefunc( \ + tstate->c_profileobj, $frame_cname, PyTrace_RETURN, (PyObject*)result); \ CYTHON_FRAME_DEL; \ + tstate->use_tracing = 1; \ } static PyCodeObject *__Pyx_createFrameCodeObject(const char *funcname, const char *srcfile, int firstlineno); /*proto*/ @@ -65,6 +88,19 @@ #endif /* CYTHON_PROFILE */ +#if CYTHON_TRACE + #define __Pyx_TraceLine(lineno) \ + if (unlikely(__Pyx_use_tracing) && unlikely(PyThreadState_GET()->use_tracing && PyThreadState_GET()->c_tracefunc)) { \ + PyThreadState* tstate = PyThreadState_GET(); \ + $frame_cname->f_lineno = lineno; \ + tstate->use_tracing = 0; \ + tstate->c_tracefunc(tstate->c_traceobj, $frame_cname, PyTrace_LINE, NULL); \ + tstate->use_tracing = 1; \ + } +#else + #define __Pyx_TraceLine(lineno) +#endif + /////////////// Profile /////////////// //@substitute: naming @@ -75,23 +111,41 @@ static int __Pyx_TraceSetupAndCall(PyCodeObject** code, const char *funcname, const char *srcfile, int firstlineno) { + int retval; + PyThreadState* tstate = PyThreadState_GET(); if (*frame == NULL || !CYTHON_PROFILE_REUSE_FRAME) { if (*code == NULL) { *code = __Pyx_createFrameCodeObject(funcname, srcfile, firstlineno); if (*code == NULL) return 0; } *frame = PyFrame_New( - PyThreadState_GET(), /*PyThreadState *tstate*/ + tstate, /*PyThreadState *tstate*/ *code, /*PyCodeObject *code*/ $moddict_cname, /*PyObject *globals*/ 0 /*PyObject *locals*/ ); if (*frame == NULL) return 0; + if (CYTHON_TRACE && (*frame)->f_trace == NULL) { + // this enables "f_lineno" lookup, at least in CPython ... + Py_INCREF(Py_None); + (*frame)->f_trace = Py_None; + } + } else { + (*frame)->f_tstate = tstate; } - else { - (*frame)->f_tstate = PyThreadState_GET(); - } - return PyThreadState_GET()->c_profilefunc(PyThreadState_GET()->c_profileobj, *frame, PyTrace_CALL, NULL) == 0; + (*frame)->f_lineno = firstlineno; + tstate->use_tracing = 0; + #if CYTHON_TRACE + if (tstate->c_tracefunc) + tstate->c_tracefunc(tstate->c_traceobj, *frame, PyTrace_CALL, NULL); + if (!tstate->c_profilefunc) + retval = 1; + else + #endif + retval = tstate->c_profilefunc(tstate->c_profileobj, *frame, PyTrace_CALL, NULL) == 0; + tstate->use_tracing = (tstate->c_profilefunc || + (CYTHON_TRACE && tstate->c_tracefunc)); + return tstate->use_tracing && retval; } static PyCodeObject *__Pyx_createFrameCodeObject(const char *funcname, const char *srcfile, int firstlineno) { diff --git a/docs/src/reference/compilation.rst b/docs/src/reference/compilation.rst index 71e81bf..4053f9e 100644 --- a/docs/src/reference/compilation.rst +++ b/docs/src/reference/compilation.rst @@ -194,6 +194,13 @@ Cython code. Here is the list of currently supported directives: Add hooks for Python profilers into the compiled C code. Default is False. +``linetrace`` (True / False) + Add line tracing hooks for Python profilers into the compiled C code. + This also enables profiling. Default is False. Note that the + generated module will not actually use line tracing, unless you + additionally pass the C macro definition ``CYTHON_TRACE=1`` to the + C compiler (e.g. using the distutils option ``define_macros``). + ``infer_types`` (True / False) Infer types of untyped variables in function bodies. Default is None, indicating that on safe (semantically-unchanging) inferences diff --git a/runtests.py b/runtests.py index 337fd65..ad321d2 100755 --- a/runtests.py +++ b/runtests.py @@ -104,6 +104,10 @@ def unpatch_inspect_isfunction(): else: inspect.isfunction = orig_isfunction +def update_linetrace_extension(ext): + ext.define_macros.append(('CYTHON_TRACE', 1)) + return ext + def update_numpy_extension(ext): import numpy ext.include_dirs.append(numpy.get_include()) @@ -186,6 +190,7 @@ EXCLUDE_EXT = object() EXT_EXTRAS = { 'tag:numpy' : update_numpy_extension, 'tag:openmp': update_openmp_extension, + 'tag:trace': update_linetrace_extension, } # TODO: use tags diff --git a/tests/run/line_trace.pyx b/tests/run/line_trace.pyx new file mode 100644 index 0000000..1f86624 --- /dev/null +++ b/tests/run/line_trace.pyx @@ -0,0 +1,65 @@ +# cython: linetrace=True +# mode: run +# tag: trace + +from cpython.ref cimport PyObject + +from cpython.pystate cimport ( + Py_tracefunc, PyFrameObject, + PyTrace_CALL, PyTrace_EXCEPTION, PyTrace_LINE, PyTrace_RETURN, + PyTrace_C_CALL, PyTrace_C_EXCEPTION, PyTrace_C_RETURN) + +cdef extern from *: + void PyEval_SetProfile(Py_tracefunc cfunc, object obj) + void PyEval_SetTrace(Py_tracefunc cfunc, object obj) + + +map_trace_types = { + PyTrace_CALL: 'call', + PyTrace_EXCEPTION: 'exc', + PyTrace_LINE: 'line', + PyTrace_RETURN: 'return', + PyTrace_C_CALL: 'ccall', + PyTrace_C_EXCEPTION: 'cexc', + PyTrace_C_RETURN: 'cret', +}.get + + +cdef int _trace_func(PyObject* _traceobj, PyFrameObject* _frame, int what, PyObject* arg) except -1: + frame, traceobj = _frame, _traceobj + traceobj.append((map_trace_types(what), frame.f_lineno - frame.f_code.co_firstlineno)) + return 0 + + +def cy_add(a,b): + x = a + b + return x + + +def cy_add_nogil(a,b): + cdef int z, x=a, y=b + with nogil: # no traces in this block ! + z = 0 + z += x + y + return z + + +def run_trace(func, *args): + """ + >>> def py_add(a,b): + ... x = a+b + ... return x + >>> run_trace(py_add, 1, 2) + [('call', 0), ('line', 1), ('line', 2), ('return', 2)] + >>> run_trace(cy_add, 1, 2) + [('call', 0), ('line', 1), ('line', 2), ('return', 2)] + >>> run_trace(cy_add_nogil, 1, 2) + [('call', 0), ('line', 1), ('line', 2), ('line', 5), ('return', 5)] + """ + trace = [] + PyEval_SetTrace(_trace_func, trace) + try: + func(*args) + finally: + PyEval_SetTrace(NULL, None) + return trace -- 2.7.4