Skip to content

Faster tracing test #6

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
markshannon wants to merge 4 commits into from
Closed

Faster tracing test #6

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
88fc80c
Remove redundant tracing_possible field from interpreter state.
markshannon Apr 7, 2021
6458071
Move 'use_tracing' from tstate onto C stack, for fastest possible che…
markshannon Apr 7, 2021
2cf3c98
Add more comments strssing the importance satck discipline when deali…
markshannon Apr 8, 2021
5ba8650
Add NEWS
markshannon Apr 8, 2021
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Prev Previous commit
Next Next commit
Move 'use_tracing' from tstate onto C stack, for fastest possible che… 
…cking in dispatch logic.
  • Loading branch information
@markshannon
markshannon committed Apr 8, 2021
commit 64580715ce10c72cec02b7f03e74c8f1b78b56a8
11 changes: 10 additions & 1 deletion Include/cpython/pystate.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,14 @@ typedef int (*Py_tracefunc)(PyObject *, PyFrameObject *, int, PyObject *);
#define PyTrace_OPCODE 7


typedef struct _cframe {
/* This struct will be threaded through the C stack
* allowing faster access to state that must can be modified
* outside of the interpreter must be accessed within it */
int use_tracing;
struct _cframe *previous;
} CFrame;

typedef struct _err_stackitem {
/* This struct represents an entry on the exception stack, which is a
* per-coroutine state. (Coroutine in the computer science sense,
Expand Down Expand Up @@ -61,7 +69,7 @@ struct _ts {
This is to prevent the actual trace/profile code from being recorded in
the trace/profile. */
int tracing;
int use_tracing;
CFrame *cframe;

Py_tracefunc c_profilefunc;
Py_tracefunc c_tracefunc;
Expand Down Expand Up @@ -128,6 +136,7 @@ struct _ts {

/* Unique thread state id. */
uint64_t id;
CFrame root_cframe;
Comment thread
markshannon marked this conversation as resolved.
Resolved

/* XXX signal handlers should also be here */

Expand Down
44 changes: 27 additions & 17 deletions Python/ceval.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -38,6 +38,7 @@ typedef struct {
PyCodeObject *code; // The code object for the bounds. May be NULL.
int instr_prev; // Only valid if code != NULL.
PyCodeAddressRange bounds; // Only valid if code != NULL.
CFrame cframe;
} PyTraceInfo;


Expand Down Expand Up @@ -1306,7 +1307,7 @@ eval_frame_handle_pending(PyThreadState *tstate)

#define DISPATCH() \
{ \
if (tstate->use_tracing OR_DTRACE_LINE OR_LLTRACE) { \
if (trace_info.cframe.use_tracing OR_DTRACE_LINE OR_LLTRACE) { \
goto tracing_dispatch; \
} \
f->f_lasti = INSTR_OFFSET(); \
Expand Down Expand Up @@ -1614,11 +1615,16 @@ _PyEval_EvalFrameDefault(PyThreadState *tstate, PyFrameObject *f, int throwflag)
/* Mark trace_info as uninitialized */
trace_info.code = NULL;

CFrame *prev_cframe = tstate->cframe;
trace_info.cframe.use_tracing = prev_cframe->use_tracing;
trace_info.cframe.previous = prev_cframe;
tstate->cframe = &trace_info.cframe;

@gvanrossum gvanrossum Apr 7, 2021

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hm, this is disturbing -- tstate (which is pretty much a global structure) now has a pointer to a local variable. That means you have to restore this on every exit from the function. Now, we know there's only one exit, and it's handled there, but it still makes me feel weird. And all this to make it possible to set a single int (perhaps even a single bit) from "outside" this function.

@markshannon markshannon Apr 8, 2021

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I know, and it would seem like overkill, if it weren't for how critical reads of that single int are.
That one int gets read 100 million times per second, and the code to read it occurs over 100 times in the interpreter.


/* push frame */
tstate->frame = f;
co = f->f_code;

if (tstate->use_tracing) {
if (trace_info.cframe.use_tracing) {
if (tstate->c_tracefunc != NULL) {
/* tstate->c_tracefunc, if defined, is a
function that will be called on *every* entry
Expand Down Expand Up @@ -1780,7 +1786,7 @@ _PyEval_EvalFrameDefault(PyThreadState *tstate, PyFrameObject *f, int throwflag)

/* line-by-line tracing support */

if (tstate->use_tracing &&
if (trace_info.cframe.use_tracing &&
tstate->c_tracefunc != NULL && !tstate->tracing) {
int err;
/* see maybe_call_line_trace()
Expand Down Expand Up @@ -4541,7 +4547,7 @@ _PyEval_EvalFrameDefault(PyThreadState *tstate, PyFrameObject *f, int throwflag)
PUSH(val);
PUSH(exc);
JUMPTO(handler);
if (tstate->use_tracing) {
if (trace_info.cframe.use_tracing) {
trace_info.instr_prev = INT_MAX;
}
/* Resume normal execution */
Expand All @@ -4565,7 +4571,7 @@ _PyEval_EvalFrameDefault(PyThreadState *tstate, PyFrameObject *f, int throwflag)
f->f_stackdepth = 0;
f->f_state = FRAME_RAISED;
exiting:
if (tstate->use_tracing) {
if (trace_info.cframe.use_tracing) {
if (tstate->c_tracefunc) {
if (call_trace_protected(tstate->c_tracefunc, tstate->c_traceobj,
tstate, f, &trace_info, PyTrace_RETURN, retval)) {
Expand All @@ -4582,6 +4588,10 @@ _PyEval_EvalFrameDefault(PyThreadState *tstate, PyFrameObject *f, int throwflag)

/* pop frame */
exit_eval_frame:

tstate->cframe = trace_info.cframe.previous;
tstate->cframe->use_tracing = trace_info.cframe.use_tracing;

if (PyDTrace_FUNCTION_RETURN_ENABLED())
dtrace_function_return(f);
_Py_LeaveRecursiveCall(tstate);
Expand Down Expand Up @@ -5505,7 +5515,7 @@ call_trace(Py_tracefunc func, PyObject *obj,
if (tstate->tracing)
return 0;
tstate->tracing++;
tstate->use_tracing = 0;
tstate->cframe->use_tracing = 0;
if (frame->f_lasti < 0) {
frame->f_lineno = frame->f_code->co_firstlineno;
}
Expand All @@ -5515,7 +5525,7 @@ call_trace(Py_tracefunc func, PyObject *obj,
}
result = func(obj, frame, what, arg);
frame->f_lineno = 0;
tstate->use_tracing = ((tstate->c_tracefunc != NULL)
tstate->cframe->use_tracing = ((tstate->c_tracefunc != NULL)
|| (tstate->c_profilefunc != NULL));
tstate->tracing--;
return result;
Expand All @@ -5526,15 +5536,15 @@ _PyEval_CallTracing(PyObject *func, PyObject *args)
{
PyThreadState *tstate = _PyThreadState_GET();
int save_tracing = tstate->tracing;
int save_use_tracing = tstate->use_tracing;
int save_use_tracing = tstate->cframe->use_tracing;
PyObject *result;

tstate->tracing = 0;
tstate->use_tracing = ((tstate->c_tracefunc != NULL)
tstate->cframe->use_tracing = ((tstate->c_tracefunc != NULL)
|| (tstate->c_profilefunc != NULL));
result = PyObject_Call(func, args, NULL);
tstate->tracing = save_tracing;
tstate->use_tracing = save_use_tracing;
tstate->cframe->use_tracing = save_use_tracing;
return result;
}

Expand Down Expand Up @@ -5588,15 +5598,15 @@ _PyEval_SetProfile(PyThreadState *tstate, Py_tracefunc func, PyObject *arg)
tstate->c_profilefunc = NULL;
tstate->c_profileobj = NULL;
/* Must make sure that tracing is not ignored if 'profileobj' is freed */
tstate->use_tracing = tstate->c_tracefunc != NULL;
tstate->cframe->use_tracing = tstate->c_tracefunc != NULL;
Py_XDECREF(profileobj);

Py_XINCREF(arg);
tstate->c_profileobj = arg;
tstate->c_profilefunc = func;

/* Flag that tracing or profiling is turned on */
tstate->use_tracing = (func != NULL) || (tstate->c_tracefunc != NULL);
tstate->cframe->use_tracing = (func != NULL) || (tstate->c_tracefunc != NULL);
return 0;
}

Expand Down Expand Up @@ -5629,15 +5639,15 @@ _PyEval_SetTrace(PyThreadState *tstate, Py_tracefunc func, PyObject *arg)
tstate->c_tracefunc = NULL;
tstate->c_traceobj = NULL;
/* Must make sure that profiling is not ignored if 'traceobj' is freed */
tstate->use_tracing = (tstate->c_profilefunc != NULL);
tstate->cframe->use_tracing = (tstate->c_profilefunc != NULL);
Py_XDECREF(traceobj);

Py_XINCREF(arg);
tstate->c_traceobj = arg;
tstate->c_tracefunc = func;

/* Flag that tracing or profiling is turned on */
tstate->use_tracing = ((func != NULL)
tstate->cframe->use_tracing = ((func != NULL)
|| (tstate->c_profilefunc != NULL));

return 0;
Expand Down Expand Up @@ -5832,7 +5842,7 @@ PyEval_GetFuncDesc(PyObject *func)
}

#define C_TRACE(x, call) \
if (tstate->use_tracing && tstate->c_profilefunc) { \
if (trace_info->cframe.use_tracing && tstate->c_profilefunc) { \
if (call_trace(tstate->c_profilefunc, tstate->c_profileobj, \
tstate, tstate->frame, trace_info, \
PyTrace_C_CALL, func)) { \
Expand Down Expand Up @@ -5913,7 +5923,7 @@ call_function(PyThreadState *tstate,
Py_ssize_t nargs = oparg - nkwargs;
PyObject **stack = (*pp_stack) - nargs - nkwargs;

if (tstate->use_tracing) {
if (trace_info->cframe.use_tracing) {
x = trace_call_function(tstate, trace_info, func, stack, nargs, kwnames);
}
else {
Expand Down Expand Up @@ -5946,7 +5956,7 @@ do_call_core(PyThreadState *tstate,
}
else if (Py_IS_TYPE(func, &PyMethodDescr_Type)) {
Py_ssize_t nargs = PyTuple_GET_SIZE(callargs);
if (nargs > 0 && tstate->use_tracing) {
if (nargs > 0 && trace_info->cframe.use_tracing) {
/* We need to create a temporary bound method as argument
for profiling.

Expand Down
3 changes: 2 additions & 1 deletion Python/pystate.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -624,7 +624,8 @@ new_threadstate(PyInterpreterState *interp, int init)
tstate->recursion_headroom = 0;
tstate->stackcheck_counter = 0;
tstate->tracing = 0;
tstate->use_tracing = 0;
tstate->root_cframe.use_tracing = 0;
tstate->cframe = &tstate->root_cframe;
tstate->gilstate_counter = 0;
tstate->async_exc = NULL;
tstate->thread_id = PyThread_get_thread_ident();
Expand Down
8 changes: 4 additions & 4 deletions Python/sysmodule.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -252,7 +252,7 @@ sys_audit_tstate(PyThreadState *ts, const char *event,

/* Disallow tracing in hooks unless explicitly enabled */
ts->tracing++;
ts->use_tracing = 0;
ts->cframe->use_tracing = 0;
while ((hook = PyIter_Next(hooks)) != NULL) {
_Py_IDENTIFIER(__cantrace__);
PyObject *o;
Expand All @@ -265,22 +265,22 @@ sys_audit_tstate(PyThreadState *ts, const char *event,
break;
}
if (canTrace) {
ts->use_tracing = (ts->c_tracefunc || ts->c_profilefunc);
ts->cframe->use_tracing = (ts->c_tracefunc || ts->c_profilefunc);
ts->tracing--;
}
PyObject* args[2] = {eventName, eventArgs};
o = _PyObject_FastCallTstate(ts, hook, args, 2);
if (canTrace) {
ts->tracing++;
ts->use_tracing = 0;
ts->cframe->use_tracing = 0;
}
if (!o) {
break;
}
Py_DECREF(o);
Py_CLEAR(hook);
}
ts->use_tracing = (ts->c_tracefunc || ts->c_profilefunc);
ts->cframe->use_tracing = (ts->c_tracefunc || ts->c_profilefunc);
ts->tracing--;
if (_PyErr_Occurred(ts)) {
goto exit;
Expand Down