3
#include "frameobject.h"
5
#include "rotatingtree.h"
7
#if !defined(HAVE_LONG_LONG)
8
#error "This module requires long longs!"
11
/*** Selection of a high-precision timer ***/
21
QueryPerformanceCounter(&li);
29
if (QueryPerformanceFrequency(&li))
30
return 1.0 / li.QuadPart;
32
return 0.000001; /* unlikely */
35
#else /* !MS_WINDOWS */
37
#ifndef HAVE_GETTIMEOFDAY
38
#error "This module requires gettimeofday() on non-Windows platforms!"
41
#if (defined(PYOS_OS2) && defined(PYCC_GCC))
44
#include <sys/resource.h>
45
#include <sys/times.h>
53
#ifdef GETTIMEOFDAY_NO_TZ
56
gettimeofday(&tv, (struct timezone *)NULL);
59
ret = ret * 1000000 + tv.tv_usec;
69
#endif /* MS_WINDOWS */
71
/************************************************************/
72
/* Written by Brett Rosen and Ted Czotter */
74
struct _ProfilerEntry;
76
/* represents a function called from another function */
77
typedef struct _ProfilerSubEntry {
78
rotating_node_t header;
82
long recursivecallcount;
86
/* represents a function or user defined block */
87
typedef struct _ProfilerEntry {
88
rotating_node_t header;
89
PyObject *userObj; /* PyCodeObject, or a descriptive str for builtins */
90
PY_LONG_LONG tt; /* total time in this entry */
91
PY_LONG_LONG it; /* inline time in this entry (not in subcalls) */
92
long callcount; /* how many times this was called */
93
long recursivecallcount; /* how many times called recursively */
95
rotating_node_t *calls;
98
typedef struct _ProfilerContext {
101
struct _ProfilerContext *previous;
102
ProfilerEntry *ctxEntry;
107
rotating_node_t *profilerEntries;
108
ProfilerContext *currentProfilerContext;
109
ProfilerContext *freelistProfilerContext;
111
PyObject *externalTimer;
112
double externalTimerUnit;
115
#define POF_ENABLED 0x001
116
#define POF_SUBCALLS 0x002
117
#define POF_BUILTINS 0x004
118
#define POF_NOMEMORY 0x100
120
static PyTypeObject PyProfiler_Type;
122
#define PyProfiler_Check(op) PyObject_TypeCheck(op, &PyProfiler_Type)
123
#define PyProfiler_CheckExact(op) (Py_TYPE(op) == &PyProfiler_Type)
125
/*** External Timers ***/
127
#define DOUBLE_TIMER_PRECISION 4294967296.0
128
static PyObject *empty_tuple;
130
static PY_LONG_LONG CallExternalTimer(ProfilerObject *pObj)
133
PyObject *o = PyObject_Call(pObj->externalTimer, empty_tuple, NULL);
135
PyErr_WriteUnraisable(pObj->externalTimer);
138
if (pObj->externalTimerUnit > 0.0) {
139
/* interpret the result as an integer that will be scaled
140
in profiler_getstats() */
141
result = PyLong_AsLongLong(o);
144
/* interpret the result as a double measured in seconds.
145
As the profiler works with PY_LONG_LONG internally
146
we convert it to a large integer */
147
double val = PyFloat_AsDouble(o);
148
/* error handling delayed to the code below */
149
result = (PY_LONG_LONG) (val * DOUBLE_TIMER_PRECISION);
152
if (PyErr_Occurred()) {
153
PyErr_WriteUnraisable(pObj->externalTimer);
159
#define CALL_TIMER(pObj) ((pObj)->externalTimer ? \
160
CallExternalTimer(pObj) : \
163
/*** ProfilerObject ***/
166
normalizeUserObj(PyObject *obj)
168
PyCFunctionObject *fn;
169
if (!PyCFunction_Check(obj)) {
173
/* Replace built-in function objects with a descriptive string
174
because of built-in methods -- keeping a reference to
175
__self__ is probably not a good idea. */
176
fn = (PyCFunctionObject *)obj;
178
if (fn->m_self == NULL) {
179
/* built-in function: look up the module name */
180
PyObject *mod = fn->m_module;
182
if (mod && PyUnicode_Check(mod)) {
183
modname = _PyUnicode_AsString(mod);
185
else if (mod && PyModule_Check(mod)) {
186
modname = PyModule_GetName(mod);
187
if (modname == NULL) {
189
modname = "builtins";
193
modname = "builtins";
195
if (strcmp(modname, "builtins") != 0)
196
return PyUnicode_FromFormat("<%s.%s>",
200
return PyUnicode_FromFormat("<%s>",
204
/* built-in method: try to return
205
repr(getattr(type(__self__), __name__))
207
PyObject *self = fn->m_self;
208
PyObject *name = PyUnicode_FromString(fn->m_ml->ml_name);
210
PyObject *mo = _PyType_Lookup(Py_TYPE(self), name);
214
PyObject *res = PyObject_Repr(mo);
221
return PyUnicode_FromFormat("<built-in method %s>",
226
static ProfilerEntry*
227
newProfilerEntry(ProfilerObject *pObj, void *key, PyObject *userObj)
230
self = (ProfilerEntry*) malloc(sizeof(ProfilerEntry));
232
pObj->flags |= POF_NOMEMORY;
235
userObj = normalizeUserObj(userObj);
236
if (userObj == NULL) {
239
pObj->flags |= POF_NOMEMORY;
242
self->header.key = key;
243
self->userObj = userObj;
247
self->recursivecallcount = 0;
248
self->recursionLevel = 0;
249
self->calls = EMPTY_ROTATING_TREE;
250
RotatingTree_Add(&pObj->profilerEntries, &self->header);
254
static ProfilerEntry*
255
getEntry(ProfilerObject *pObj, void *key)
257
return (ProfilerEntry*) RotatingTree_Get(&pObj->profilerEntries, key);
260
static ProfilerSubEntry *
261
getSubEntry(ProfilerObject *pObj, ProfilerEntry *caller, ProfilerEntry* entry)
263
return (ProfilerSubEntry*) RotatingTree_Get(&caller->calls,
267
static ProfilerSubEntry *
268
newSubEntry(ProfilerObject *pObj, ProfilerEntry *caller, ProfilerEntry* entry)
270
ProfilerSubEntry *self;
271
self = (ProfilerSubEntry*) malloc(sizeof(ProfilerSubEntry));
273
pObj->flags |= POF_NOMEMORY;
276
self->header.key = (void *)entry;
280
self->recursivecallcount = 0;
281
self->recursionLevel = 0;
282
RotatingTree_Add(&caller->calls, &self->header);
286
static int freeSubEntry(rotating_node_t *header, void *arg)
288
ProfilerSubEntry *subentry = (ProfilerSubEntry*) header;
293
static int freeEntry(rotating_node_t *header, void *arg)
295
ProfilerEntry *entry = (ProfilerEntry*) header;
296
RotatingTree_Enum(entry->calls, freeSubEntry, NULL);
297
Py_DECREF(entry->userObj);
302
static void clearEntries(ProfilerObject *pObj)
304
RotatingTree_Enum(pObj->profilerEntries, freeEntry, NULL);
305
pObj->profilerEntries = EMPTY_ROTATING_TREE;
306
/* release the memory hold by the free list of ProfilerContexts */
307
while (pObj->freelistProfilerContext) {
308
ProfilerContext *c = pObj->freelistProfilerContext;
309
pObj->freelistProfilerContext = c->previous;
315
initContext(ProfilerObject *pObj, ProfilerContext *self, ProfilerEntry *entry)
317
self->ctxEntry = entry;
319
self->previous = pObj->currentProfilerContext;
320
pObj->currentProfilerContext = self;
321
++entry->recursionLevel;
322
if ((pObj->flags & POF_SUBCALLS) && self->previous) {
323
/* find or create an entry for me in my caller's entry */
324
ProfilerEntry *caller = self->previous->ctxEntry;
325
ProfilerSubEntry *subentry = getSubEntry(pObj, caller, entry);
326
if (subentry == NULL)
327
subentry = newSubEntry(pObj, caller, entry);
329
++subentry->recursionLevel;
331
self->t0 = CALL_TIMER(pObj);
335
Stop(ProfilerObject *pObj, ProfilerContext *self, ProfilerEntry *entry)
337
PY_LONG_LONG tt = CALL_TIMER(pObj) - self->t0;
338
PY_LONG_LONG it = tt - self->subt;
340
self->previous->subt += tt;
341
pObj->currentProfilerContext = self->previous;
342
if (--entry->recursionLevel == 0)
345
++entry->recursivecallcount;
348
if ((pObj->flags & POF_SUBCALLS) && self->previous) {
349
/* find or create an entry for me in my caller's entry */
350
ProfilerEntry *caller = self->previous->ctxEntry;
351
ProfilerSubEntry *subentry = getSubEntry(pObj, caller, entry);
353
if (--subentry->recursionLevel == 0)
356
++subentry->recursivecallcount;
358
++subentry->callcount;
364
ptrace_enter_call(PyObject *self, void *key, PyObject *userObj)
366
/* entering a call to the function identified by 'key'
367
(which can be a PyCodeObject or a PyMethodDef pointer) */
368
ProfilerObject *pObj = (ProfilerObject*)self;
369
ProfilerEntry *profEntry;
370
ProfilerContext *pContext;
372
/* In the case of entering a generator expression frame via a
373
* throw (gen_send_ex(.., 1)), we may already have an
374
* Exception set here. We must not mess around with this
375
* exception, and some of the code under here assumes that
376
* PyErr_* is its own to mess around with, so we have to
377
* save and restore any current exception. */
378
PyObject *last_type, *last_value, *last_tb;
379
PyErr_Fetch(&last_type, &last_value, &last_tb);
381
profEntry = getEntry(pObj, key);
382
if (profEntry == NULL) {
383
profEntry = newProfilerEntry(pObj, key, userObj);
384
if (profEntry == NULL)
387
/* grab a ProfilerContext out of the free list */
388
pContext = pObj->freelistProfilerContext;
390
pObj->freelistProfilerContext = pContext->previous;
393
/* free list exhausted, allocate a new one */
394
pContext = (ProfilerContext*)
395
malloc(sizeof(ProfilerContext));
396
if (pContext == NULL) {
397
pObj->flags |= POF_NOMEMORY;
401
initContext(pObj, pContext, profEntry);
404
PyErr_Restore(last_type, last_value, last_tb);
408
ptrace_leave_call(PyObject *self, void *key)
410
/* leaving a call to the function identified by 'key' */
411
ProfilerObject *pObj = (ProfilerObject*)self;
412
ProfilerEntry *profEntry;
413
ProfilerContext *pContext;
415
pContext = pObj->currentProfilerContext;
416
if (pContext == NULL)
418
profEntry = getEntry(pObj, key);
420
Stop(pObj, pContext, profEntry);
423
pObj->currentProfilerContext = pContext->previous;
425
/* put pContext into the free list */
426
pContext->previous = pObj->freelistProfilerContext;
427
pObj->freelistProfilerContext = pContext;
431
profiler_callback(PyObject *self, PyFrameObject *frame, int what,
436
/* the 'frame' of a called function is about to start its execution */
438
ptrace_enter_call(self, (void *)frame->f_code,
439
(PyObject *)frame->f_code);
442
/* the 'frame' of a called function is about to finish
443
(either normally or with an exception) */
445
ptrace_leave_call(self, (void *)frame->f_code);
448
/* case PyTrace_EXCEPTION:
449
If the exception results in the function exiting, a
450
PyTrace_RETURN event will be generated, so we don't need to
453
#ifdef PyTrace_C_CALL /* not defined in Python <= 2.3 */
454
/* the Python function 'frame' is issuing a call to the built-in
457
if ((((ProfilerObject *)self)->flags & POF_BUILTINS)
458
&& PyCFunction_Check(arg)) {
459
ptrace_enter_call(self,
460
((PyCFunctionObject *)arg)->m_ml,
465
/* the call to the built-in function 'arg' is returning into its
467
case PyTrace_C_RETURN: /* ...normally */
468
case PyTrace_C_EXCEPTION: /* ...with an exception set */
469
if ((((ProfilerObject *)self)->flags & POF_BUILTINS)
470
&& PyCFunction_Check(arg)) {
471
ptrace_leave_call(self,
472
((PyCFunctionObject *)arg)->m_ml);
484
pending_exception(ProfilerObject *pObj)
486
if (pObj->flags & POF_NOMEMORY) {
487
pObj->flags -= POF_NOMEMORY;
488
PyErr_SetString(PyExc_MemoryError,
489
"memory was exhausted while profiling");
495
/************************************************************/
497
static PyStructSequence_Field profiler_entry_fields[] = {
498
{"code", "code object or built-in function name"},
499
{"callcount", "how many times this was called"},
500
{"reccallcount", "how many times called recursively"},
501
{"totaltime", "total time in this entry"},
502
{"inlinetime", "inline time in this entry (not in subcalls)"},
503
{"calls", "details of the calls"},
507
static PyStructSequence_Field profiler_subentry_fields[] = {
508
{"code", "called code object or built-in function name"},
509
{"callcount", "how many times this is called"},
510
{"reccallcount", "how many times this is called recursively"},
511
{"totaltime", "total time spent in this call"},
512
{"inlinetime", "inline time (not in further subcalls)"},
516
static PyStructSequence_Desc profiler_entry_desc = {
517
"_lsprof.profiler_entry", /* name */
519
profiler_entry_fields,
523
static PyStructSequence_Desc profiler_subentry_desc = {
524
"_lsprof.profiler_subentry", /* name */
526
profiler_subentry_fields,
530
static int initialized;
531
static PyTypeObject StatsEntryType;
532
static PyTypeObject StatsSubEntryType;
541
static int statsForSubEntry(rotating_node_t *node, void *arg)
543
ProfilerSubEntry *sentry = (ProfilerSubEntry*) node;
544
statscollector_t *collect = (statscollector_t*) arg;
545
ProfilerEntry *entry = (ProfilerEntry*) sentry->header.key;
548
sinfo = PyObject_CallFunction((PyObject*) &StatsSubEntryType,
552
sentry->recursivecallcount,
553
collect->factor * sentry->tt,
554
collect->factor * sentry->it);
557
err = PyList_Append(collect->sublist, sinfo);
562
static int statsForEntry(rotating_node_t *node, void *arg)
564
ProfilerEntry *entry = (ProfilerEntry*) node;
565
statscollector_t *collect = (statscollector_t*) arg;
568
if (entry->callcount == 0)
571
if (entry->calls != EMPTY_ROTATING_TREE) {
572
collect->sublist = PyList_New(0);
573
if (collect->sublist == NULL)
575
if (RotatingTree_Enum(entry->calls,
576
statsForSubEntry, collect) != 0) {
577
Py_DECREF(collect->sublist);
583
collect->sublist = Py_None;
586
info = PyObject_CallFunction((PyObject*) &StatsEntryType,
590
entry->recursivecallcount,
591
collect->factor * entry->tt,
592
collect->factor * entry->it,
594
Py_DECREF(collect->sublist);
597
err = PyList_Append(collect->list, info);
602
PyDoc_STRVAR(getstats_doc, "\
603
getstats() -> list of profiler_entry objects\n\
605
Return all information collected by the profiler.\n\
606
Each profiler_entry is a tuple-like object with the\n\
607
following attributes:\n\
610
callcount how many times this was called\n\
611
reccallcount how many times called recursively\n\
612
totaltime total time in this entry\n\
613
inlinetime inline time in this entry (not in subcalls)\n\
614
calls details of the calls\n\
616
The calls attribute is either None or a list of\n\
617
profiler_subentry objects:\n\
619
code called code object\n\
620
callcount how many times this is called\n\
621
reccallcount how many times this is called recursively\n\
622
totaltime total time spent in this call\n\
623
inlinetime inline time (not in further subcalls)\n\
627
profiler_getstats(ProfilerObject *pObj, PyObject* noarg)
629
statscollector_t collect;
630
if (pending_exception(pObj))
632
if (!pObj->externalTimer)
633
collect.factor = hpTimerUnit();
634
else if (pObj->externalTimerUnit > 0.0)
635
collect.factor = pObj->externalTimerUnit;
637
collect.factor = 1.0 / DOUBLE_TIMER_PRECISION;
638
collect.list = PyList_New(0);
639
if (collect.list == NULL)
641
if (RotatingTree_Enum(pObj->profilerEntries, statsForEntry, &collect)
643
Py_DECREF(collect.list);
650
setSubcalls(ProfilerObject *pObj, int nvalue)
653
pObj->flags &= ~POF_SUBCALLS;
655
pObj->flags |= POF_SUBCALLS;
660
setBuiltins(ProfilerObject *pObj, int nvalue)
663
pObj->flags &= ~POF_BUILTINS;
664
else if (nvalue > 0) {
665
#ifndef PyTrace_C_CALL
666
PyErr_SetString(PyExc_ValueError,
667
"builtins=True requires Python >= 2.4");
670
pObj->flags |= POF_BUILTINS;
676
PyDoc_STRVAR(enable_doc, "\
677
enable(subcalls=True, builtins=True)\n\
679
Start collecting profiling information.\n\
680
If 'subcalls' is True, also records for each function\n\
681
statistics separated according to its current caller.\n\
682
If 'builtins' is True, records the time spent in\n\
683
built-in functions separately from their caller.\n\
687
profiler_enable(ProfilerObject *self, PyObject *args, PyObject *kwds)
691
static char *kwlist[] = {"subcalls", "builtins", 0};
692
if (!PyArg_ParseTupleAndKeywords(args, kwds, "|ii:enable",
693
kwlist, &subcalls, &builtins))
695
if (setSubcalls(self, subcalls) < 0 || setBuiltins(self, builtins) < 0)
697
PyEval_SetProfile(profiler_callback, (PyObject*)self);
698
self->flags |= POF_ENABLED;
704
flush_unmatched(ProfilerObject *pObj)
706
while (pObj->currentProfilerContext) {
707
ProfilerContext *pContext = pObj->currentProfilerContext;
708
ProfilerEntry *profEntry= pContext->ctxEntry;
710
Stop(pObj, pContext, profEntry);
712
pObj->currentProfilerContext = pContext->previous;
719
PyDoc_STRVAR(disable_doc, "\
722
Stop collecting profiling information.\n\
726
profiler_disable(ProfilerObject *self, PyObject* noarg)
728
self->flags &= ~POF_ENABLED;
729
PyEval_SetProfile(NULL, NULL);
730
flush_unmatched(self);
731
if (pending_exception(self))
737
PyDoc_STRVAR(clear_doc, "\
740
Clear all profiling information collected so far.\n\
744
profiler_clear(ProfilerObject *pObj, PyObject* noarg)
752
profiler_dealloc(ProfilerObject *op)
754
if (op->flags & POF_ENABLED)
755
PyEval_SetProfile(NULL, NULL);
758
Py_XDECREF(op->externalTimer);
759
Py_TYPE(op)->tp_free(op);
763
profiler_init(ProfilerObject *pObj, PyObject *args, PyObject *kw)
766
PyObject *timer = NULL;
767
double timeunit = 0.0;
769
#ifdef PyTrace_C_CALL
774
static char *kwlist[] = {"timer", "timeunit",
775
"subcalls", "builtins", 0};
777
if (!PyArg_ParseTupleAndKeywords(args, kw, "|Odii:Profiler", kwlist,
779
&subcalls, &builtins))
782
if (setSubcalls(pObj, subcalls) < 0 || setBuiltins(pObj, builtins) < 0)
784
o = pObj->externalTimer;
785
pObj->externalTimer = timer;
788
pObj->externalTimerUnit = timeunit;
792
static PyMethodDef profiler_methods[] = {
793
{"getstats", (PyCFunction)profiler_getstats,
794
METH_NOARGS, getstats_doc},
795
{"enable", (PyCFunction)profiler_enable,
796
METH_VARARGS | METH_KEYWORDS, enable_doc},
797
{"disable", (PyCFunction)profiler_disable,
798
METH_NOARGS, disable_doc},
799
{"clear", (PyCFunction)profiler_clear,
800
METH_NOARGS, clear_doc},
804
PyDoc_STRVAR(profiler_doc, "\
805
Profiler(custom_timer=None, time_unit=None, subcalls=True, builtins=True)\n\
807
Builds a profiler object using the specified timer function.\n\
808
The default timer is a fast built-in one based on real time.\n\
809
For custom timer functions returning integers, time_unit can\n\
810
be a float specifying a scale (i.e. how long each integer unit\n\
814
static PyTypeObject PyProfiler_Type = {
815
PyVarObject_HEAD_INIT(NULL, 0)
816
"_lsprof.Profiler", /* tp_name */
817
sizeof(ProfilerObject), /* tp_basicsize */
819
(destructor)profiler_dealloc, /* tp_dealloc */
825
0, /* tp_as_number */
826
0, /* tp_as_sequence */
827
0, /* tp_as_mapping */
833
0, /* tp_as_buffer */
834
Py_TPFLAGS_DEFAULT | Py_TPFLAGS_BASETYPE, /* tp_flags */
835
profiler_doc, /* tp_doc */
838
0, /* tp_richcompare */
839
0, /* tp_weaklistoffset */
842
profiler_methods, /* tp_methods */
847
0, /* tp_descr_get */
848
0, /* tp_descr_set */
849
0, /* tp_dictoffset */
850
(initproc)profiler_init, /* tp_init */
851
PyType_GenericAlloc, /* tp_alloc */
852
PyType_GenericNew, /* tp_new */
853
PyObject_Del, /* tp_free */
856
static PyMethodDef moduleMethods[] = {
861
static struct PyModuleDef _lsprofmodule = {
862
PyModuleDef_HEAD_INIT,
876
PyObject *module, *d;
877
module = PyModule_Create(&_lsprofmodule);
880
d = PyModule_GetDict(module);
881
if (PyType_Ready(&PyProfiler_Type) < 0)
883
PyDict_SetItemString(d, "Profiler", (PyObject *)&PyProfiler_Type);
886
PyStructSequence_InitType(&StatsEntryType,
887
&profiler_entry_desc);
888
PyStructSequence_InitType(&StatsSubEntryType,
889
&profiler_subentry_desc);
891
Py_INCREF((PyObject*) &StatsEntryType);
892
Py_INCREF((PyObject*) &StatsSubEntryType);
893
PyModule_AddObject(module, "profiler_entry",
894
(PyObject*) &StatsEntryType);
895
PyModule_AddObject(module, "profiler_subentry",
896
(PyObject*) &StatsSubEntryType);
897
empty_tuple = PyTuple_New(0);