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 staticforward PyTypeObject PyProfiler_Type
;
122 #define PyProfiler_Check(op) PyObject_TypeCheck(op, &PyProfiler_Type)
123 #define PyProfiler_CheckExact(op) ((op)->ob_type == &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((PyObject
*) pObj
);
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
&& PyString_Check(mod
)) {
183 modname
= PyString_AS_STRING(mod
);
185 else if (mod
&& PyModule_Check(mod
)) {
186 modname
= PyModule_GetName(mod
);
187 if (modname
== NULL
) {
189 modname
= "__builtin__";
193 modname
= "__builtin__";
195 if (strcmp(modname
, "__builtin__") != 0)
196 return PyString_FromFormat("<%s.%s>",
200 return PyString_FromFormat("<%s>",
204 /* built-in method: try to return
205 repr(getattr(type(__self__), __name__))
207 PyObject
*self
= fn
->m_self
;
208 PyObject
*name
= PyString_FromString(fn
->m_ml
->ml_name
);
210 PyObject
*mo
= _PyType_Lookup(self
->ob_type
, name
);
214 PyObject
*res
= PyObject_Repr(mo
);
221 return PyString_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 profEntry
= getEntry(pObj
, key
);
373 if (profEntry
== NULL
) {
374 profEntry
= newProfilerEntry(pObj
, key
, userObj
);
375 if (profEntry
== NULL
)
378 /* grab a ProfilerContext out of the free list */
379 pContext
= pObj
->freelistProfilerContext
;
381 pObj
->freelistProfilerContext
= pContext
->previous
;
384 /* free list exhausted, allocate a new one */
385 pContext
= (ProfilerContext
*)
386 malloc(sizeof(ProfilerContext
));
387 if (pContext
== NULL
) {
388 pObj
->flags
|= POF_NOMEMORY
;
392 initContext(pObj
, pContext
, profEntry
);
396 ptrace_leave_call(PyObject
*self
, void *key
)
398 /* leaving a call to the function identified by 'key' */
399 ProfilerObject
*pObj
= (ProfilerObject
*)self
;
400 ProfilerEntry
*profEntry
;
401 ProfilerContext
*pContext
;
403 pContext
= pObj
->currentProfilerContext
;
404 if (pContext
== NULL
)
406 profEntry
= getEntry(pObj
, key
);
408 Stop(pObj
, pContext
, profEntry
);
411 pObj
->currentProfilerContext
= pContext
->previous
;
413 /* put pContext into the free list */
414 pContext
->previous
= pObj
->freelistProfilerContext
;
415 pObj
->freelistProfilerContext
= pContext
;
419 profiler_callback(PyObject
*self
, PyFrameObject
*frame
, int what
,
424 /* the 'frame' of a called function is about to start its execution */
426 ptrace_enter_call(self
, (void *)frame
->f_code
,
427 (PyObject
*)frame
->f_code
);
430 /* the 'frame' of a called function is about to finish
431 (either normally or with an exception) */
433 ptrace_leave_call(self
, (void *)frame
->f_code
);
436 /* case PyTrace_EXCEPTION:
437 If the exception results in the function exiting, a
438 PyTrace_RETURN event will be generated, so we don't need to
441 #ifdef PyTrace_C_CALL /* not defined in Python <= 2.3 */
442 /* the Python function 'frame' is issuing a call to the built-in
445 if ((((ProfilerObject
*)self
)->flags
& POF_BUILTINS
)
446 && PyCFunction_Check(arg
)) {
447 ptrace_enter_call(self
,
448 ((PyCFunctionObject
*)arg
)->m_ml
,
453 /* the call to the built-in function 'arg' is returning into its
455 case PyTrace_C_RETURN
: /* ...normally */
456 case PyTrace_C_EXCEPTION
: /* ...with an exception set */
457 if ((((ProfilerObject
*)self
)->flags
& POF_BUILTINS
)
458 && PyCFunction_Check(arg
)) {
459 ptrace_leave_call(self
,
460 ((PyCFunctionObject
*)arg
)->m_ml
);
472 pending_exception(ProfilerObject
*pObj
)
474 if (pObj
->flags
& POF_NOMEMORY
) {
475 pObj
->flags
-= POF_NOMEMORY
;
476 PyErr_SetString(PyExc_MemoryError
,
477 "memory was exhausted while profiling");
483 /************************************************************/
485 static PyStructSequence_Field profiler_entry_fields
[] = {
486 {"code", "code object or built-in function name"},
487 {"callcount", "how many times this was called"},
488 {"reccallcount", "how many times called recursively"},
489 {"totaltime", "total time in this entry"},
490 {"inlinetime", "inline time in this entry (not in subcalls)"},
491 {"calls", "details of the calls"},
495 static PyStructSequence_Field profiler_subentry_fields
[] = {
496 {"code", "called code object or built-in function name"},
497 {"callcount", "how many times this is called"},
498 {"reccallcount", "how many times this is called recursively"},
499 {"totaltime", "total time spent in this call"},
500 {"inlinetime", "inline time (not in further subcalls)"},
504 static PyStructSequence_Desc profiler_entry_desc
= {
505 "_lsprof.profiler_entry", /* name */
507 profiler_entry_fields
,
511 static PyStructSequence_Desc profiler_subentry_desc
= {
512 "_lsprof.profiler_subentry", /* name */
514 profiler_subentry_fields
,
518 static int initialized
;
519 static PyTypeObject StatsEntryType
;
520 static PyTypeObject StatsSubEntryType
;
529 static int statsForSubEntry(rotating_node_t
*node
, void *arg
)
531 ProfilerSubEntry
*sentry
= (ProfilerSubEntry
*) node
;
532 statscollector_t
*collect
= (statscollector_t
*) arg
;
533 ProfilerEntry
*entry
= (ProfilerEntry
*) sentry
->header
.key
;
536 sinfo
= PyObject_CallFunction((PyObject
*) &StatsSubEntryType
,
540 sentry
->recursivecallcount
,
541 collect
->factor
* sentry
->tt
,
542 collect
->factor
* sentry
->it
);
545 err
= PyList_Append(collect
->sublist
, sinfo
);
550 static int statsForEntry(rotating_node_t
*node
, void *arg
)
552 ProfilerEntry
*entry
= (ProfilerEntry
*) node
;
553 statscollector_t
*collect
= (statscollector_t
*) arg
;
556 if (entry
->callcount
== 0)
559 if (entry
->calls
!= EMPTY_ROTATING_TREE
) {
560 collect
->sublist
= PyList_New(0);
561 if (collect
->sublist
== NULL
)
563 if (RotatingTree_Enum(entry
->calls
,
564 statsForSubEntry
, collect
) != 0) {
565 Py_DECREF(collect
->sublist
);
571 collect
->sublist
= Py_None
;
574 info
= PyObject_CallFunction((PyObject
*) &StatsEntryType
,
578 entry
->recursivecallcount
,
579 collect
->factor
* entry
->tt
,
580 collect
->factor
* entry
->it
,
582 Py_DECREF(collect
->sublist
);
585 err
= PyList_Append(collect
->list
, info
);
590 PyDoc_STRVAR(getstats_doc
, "\
591 getstats() -> list of profiler_entry objects\n\
593 Return all information collected by the profiler.\n\
594 Each profiler_entry is a tuple-like object with the\n\
595 following attributes:\n\
598 callcount how many times this was called\n\
599 reccallcount how many times called recursively\n\
600 totaltime total time in this entry\n\
601 inlinetime inline time in this entry (not in subcalls)\n\
602 calls details of the calls\n\
604 The calls attribute is either None or a list of\n\
605 profiler_subentry objects:\n\
607 code called code object\n\
608 callcount how many times this is called\n\
609 reccallcount how many times this is called recursively\n\
610 totaltime total time spent in this call\n\
611 inlinetime inline time (not in further subcalls)\n\
615 profiler_getstats(ProfilerObject
*pObj
, PyObject
* noarg
)
617 statscollector_t collect
;
618 if (pending_exception(pObj
))
620 if (!pObj
->externalTimer
)
621 collect
.factor
= hpTimerUnit();
622 else if (pObj
->externalTimerUnit
> 0.0)
623 collect
.factor
= pObj
->externalTimerUnit
;
625 collect
.factor
= 1.0 / DOUBLE_TIMER_PRECISION
;
626 collect
.list
= PyList_New(0);
627 if (collect
.list
== NULL
)
629 if (RotatingTree_Enum(pObj
->profilerEntries
, statsForEntry
, &collect
)
631 Py_DECREF(collect
.list
);
638 setSubcalls(ProfilerObject
*pObj
, int nvalue
)
641 pObj
->flags
&= ~POF_SUBCALLS
;
643 pObj
->flags
|= POF_SUBCALLS
;
648 setBuiltins(ProfilerObject
*pObj
, int nvalue
)
651 pObj
->flags
&= ~POF_BUILTINS
;
652 else if (nvalue
> 0) {
653 #ifndef PyTrace_C_CALL
654 PyErr_SetString(PyExc_ValueError
,
655 "builtins=True requires Python >= 2.4");
658 pObj
->flags
|= POF_BUILTINS
;
664 PyDoc_STRVAR(enable_doc
, "\
665 enable(subcalls=True, builtins=True)\n\
667 Start collecting profiling information.\n\
668 If 'subcalls' is True, also records for each function\n\
669 statistics separated according to its current caller.\n\
670 If 'builtins' is True, records the time spent in\n\
671 built-in functions separately from their caller.\n\
675 profiler_enable(ProfilerObject
*self
, PyObject
*args
, PyObject
*kwds
)
679 static char *kwlist
[] = {"subcalls", "builtins", 0};
680 if (!PyArg_ParseTupleAndKeywords(args
, kwds
, "|ii:enable",
681 kwlist
, &subcalls
, &builtins
))
683 if (setSubcalls(self
, subcalls
) < 0 || setBuiltins(self
, builtins
) < 0)
685 PyEval_SetProfile(profiler_callback
, (PyObject
*)self
);
686 self
->flags
|= POF_ENABLED
;
692 flush_unmatched(ProfilerObject
*pObj
)
694 while (pObj
->currentProfilerContext
) {
695 ProfilerContext
*pContext
= pObj
->currentProfilerContext
;
696 ProfilerEntry
*profEntry
= pContext
->ctxEntry
;
698 Stop(pObj
, pContext
, profEntry
);
700 pObj
->currentProfilerContext
= pContext
->previous
;
707 PyDoc_STRVAR(disable_doc
, "\
710 Stop collecting profiling information.\n\
714 profiler_disable(ProfilerObject
*self
, PyObject
* noarg
)
716 self
->flags
&= ~POF_ENABLED
;
717 PyEval_SetProfile(NULL
, NULL
);
718 flush_unmatched(self
);
719 if (pending_exception(self
))
725 PyDoc_STRVAR(clear_doc
, "\
728 Clear all profiling information collected so far.\n\
732 profiler_clear(ProfilerObject
*pObj
, PyObject
* noarg
)
740 profiler_dealloc(ProfilerObject
*op
)
742 if (op
->flags
& POF_ENABLED
)
743 PyEval_SetProfile(NULL
, NULL
);
746 Py_XDECREF(op
->externalTimer
);
747 op
->ob_type
->tp_free(op
);
751 profiler_init(ProfilerObject
*pObj
, PyObject
*args
, PyObject
*kw
)
754 PyObject
*timer
= NULL
;
755 double timeunit
= 0.0;
757 #ifdef PyTrace_C_CALL
762 static char *kwlist
[] = {"timer", "timeunit",
763 "subcalls", "builtins", 0};
765 if (!PyArg_ParseTupleAndKeywords(args
, kw
, "|Odii:Profiler", kwlist
,
767 &subcalls
, &builtins
))
770 if (setSubcalls(pObj
, subcalls
) < 0 || setBuiltins(pObj
, builtins
) < 0)
772 o
= pObj
->externalTimer
;
773 pObj
->externalTimer
= timer
;
776 pObj
->externalTimerUnit
= timeunit
;
780 static PyMethodDef profiler_methods
[] = {
781 {"getstats", (PyCFunction
)profiler_getstats
,
782 METH_NOARGS
, getstats_doc
},
783 {"enable", (PyCFunction
)profiler_enable
,
784 METH_VARARGS
| METH_KEYWORDS
, enable_doc
},
785 {"disable", (PyCFunction
)profiler_disable
,
786 METH_NOARGS
, disable_doc
},
787 {"clear", (PyCFunction
)profiler_clear
,
788 METH_NOARGS
, clear_doc
},
792 PyDoc_STRVAR(profiler_doc
, "\
793 Profiler(custom_timer=None, time_unit=None, subcalls=True, builtins=True)\n\
795 Builds a profiler object using the specified timer function.\n\
796 The default timer is a fast built-in one based on real time.\n\
797 For custom timer functions returning integers, time_unit can\n\
798 be a float specifying a scale (i.e. how long each integer unit\n\
802 statichere PyTypeObject PyProfiler_Type
= {
803 PyObject_HEAD_INIT(NULL
)
805 "_lsprof.Profiler", /* tp_name */
806 sizeof(ProfilerObject
), /* tp_basicsize */
808 (destructor
)profiler_dealloc
, /* tp_dealloc */
814 0, /* tp_as_number */
815 0, /* tp_as_sequence */
816 0, /* tp_as_mapping */
822 0, /* tp_as_buffer */
823 Py_TPFLAGS_DEFAULT
| Py_TPFLAGS_BASETYPE
, /* tp_flags */
824 profiler_doc
, /* tp_doc */
827 0, /* tp_richcompare */
828 0, /* tp_weaklistoffset */
831 profiler_methods
, /* tp_methods */
836 0, /* tp_descr_get */
837 0, /* tp_descr_set */
838 0, /* tp_dictoffset */
839 (initproc
)profiler_init
, /* tp_init */
840 PyType_GenericAlloc
, /* tp_alloc */
841 PyType_GenericNew
, /* tp_new */
842 PyObject_Del
, /* tp_free */
845 static PyMethodDef moduleMethods
[] = {
852 PyObject
*module
, *d
;
853 module
= Py_InitModule3("_lsprof", moduleMethods
, "Fast profiler");
856 d
= PyModule_GetDict(module
);
857 if (PyType_Ready(&PyProfiler_Type
) < 0)
859 PyDict_SetItemString(d
, "Profiler", (PyObject
*)&PyProfiler_Type
);
862 PyStructSequence_InitType(&StatsEntryType
,
863 &profiler_entry_desc
);
864 PyStructSequence_InitType(&StatsSubEntryType
,
865 &profiler_subentry_desc
);
867 Py_INCREF((PyObject
*) &StatsEntryType
);
868 Py_INCREF((PyObject
*) &StatsSubEntryType
);
869 PyModule_AddObject(module
, "profiler_entry",
870 (PyObject
*) &StatsEntryType
);
871 PyModule_AddObject(module
, "profiler_subentry",
872 (PyObject
*) &StatsSubEntryType
);
873 empty_tuple
= PyTuple_New(0);