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 1000.0 / li
.QuadPart
;
32 return 0.001; /* 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 PyTypeObject StatsEntryType
;
519 static PyTypeObject StatsSubEntryType
;
528 static int statsForSubEntry(rotating_node_t
*node
, void *arg
)
530 ProfilerSubEntry
*sentry
= (ProfilerSubEntry
*) node
;
531 statscollector_t
*collect
= (statscollector_t
*) arg
;
532 ProfilerEntry
*entry
= (ProfilerEntry
*) sentry
->header
.key
;
535 sinfo
= PyObject_CallFunction((PyObject
*) &StatsSubEntryType
,
539 sentry
->recursivecallcount
,
540 collect
->factor
* sentry
->tt
,
541 collect
->factor
* sentry
->it
);
544 err
= PyList_Append(collect
->sublist
, sinfo
);
549 static int statsForEntry(rotating_node_t
*node
, void *arg
)
551 ProfilerEntry
*entry
= (ProfilerEntry
*) node
;
552 statscollector_t
*collect
= (statscollector_t
*) arg
;
555 if (entry
->callcount
== 0)
558 if (entry
->calls
!= EMPTY_ROTATING_TREE
) {
559 collect
->sublist
= PyList_New(0);
560 if (collect
->sublist
== NULL
)
562 if (RotatingTree_Enum(entry
->calls
,
563 statsForSubEntry
, collect
) != 0) {
564 Py_DECREF(collect
->sublist
);
570 collect
->sublist
= Py_None
;
573 info
= PyObject_CallFunction((PyObject
*) &StatsEntryType
,
577 entry
->recursivecallcount
,
578 collect
->factor
* entry
->tt
,
579 collect
->factor
* entry
->it
,
581 Py_DECREF(collect
->sublist
);
584 err
= PyList_Append(collect
->list
, info
);
589 PyDoc_STRVAR(getstats_doc
, "\
590 getstats() -> list of profiler_entry objects\n\
592 Return all information collected by the profiler.\n\
593 Each profiler_entry is a tuple-like object with the\n\
594 following attributes:\n\
597 callcount how many times this was called\n\
598 reccallcount how many times called recursively\n\
599 totaltime total time in this entry\n\
600 inlinetime inline time in this entry (not in subcalls)\n\
601 calls details of the calls\n\
603 The calls attribute is either None or a list of\n\
604 profiler_subentry objects:\n\
606 code called code object\n\
607 callcount how many times this is called\n\
608 reccallcount how many times this is called recursively\n\
609 totaltime total time spent in this call\n\
610 inlinetime inline time (not in further subcalls)\n\
614 profiler_getstats(ProfilerObject
*pObj
, PyObject
* noarg
)
616 statscollector_t collect
;
617 if (pending_exception(pObj
))
619 if (!pObj
->externalTimer
)
620 collect
.factor
= hpTimerUnit();
621 else if (pObj
->externalTimerUnit
> 0.0)
622 collect
.factor
= pObj
->externalTimerUnit
;
624 collect
.factor
= 1.0 / DOUBLE_TIMER_PRECISION
;
625 collect
.list
= PyList_New(0);
626 if (collect
.list
== NULL
)
628 if (RotatingTree_Enum(pObj
->profilerEntries
, statsForEntry
, &collect
)
630 Py_DECREF(collect
.list
);
637 setSubcalls(ProfilerObject
*pObj
, int nvalue
)
640 pObj
->flags
&= ~POF_SUBCALLS
;
642 pObj
->flags
|= POF_SUBCALLS
;
647 setBuiltins(ProfilerObject
*pObj
, int nvalue
)
650 pObj
->flags
&= ~POF_BUILTINS
;
651 else if (nvalue
> 0) {
652 #ifndef PyTrace_C_CALL
653 PyErr_SetString(PyExc_ValueError
,
654 "builtins=True requires Python >= 2.4");
657 pObj
->flags
|= POF_BUILTINS
;
663 PyDoc_STRVAR(enable_doc
, "\
664 enable(subcalls=True, builtins=True)\n\
666 Start collecting profiling information.\n\
667 If 'subcalls' is True, also records for each function\n\
668 statistics separated according to its current caller.\n\
669 If 'builtins' is True, records the time spent in\n\
670 built-in functions separately from their caller.\n\
674 profiler_enable(ProfilerObject
*self
, PyObject
*args
, PyObject
*kwds
)
678 static const char *kwlist
[] = {"subcalls", "builtins", 0};
679 if (!PyArg_ParseTupleAndKeywords(args
, kwds
, "|ii:enable",
680 kwlist
, &subcalls
, &builtins
))
682 if (setSubcalls(self
, subcalls
) < 0 || setBuiltins(self
, builtins
) < 0)
684 PyEval_SetProfile(profiler_callback
, (PyObject
*)self
);
685 self
->flags
|= POF_ENABLED
;
691 flush_unmatched(ProfilerObject
*pObj
)
693 while (pObj
->currentProfilerContext
) {
694 ProfilerContext
*pContext
= pObj
->currentProfilerContext
;
695 ProfilerEntry
*profEntry
= pContext
->ctxEntry
;
697 Stop(pObj
, pContext
, profEntry
);
699 pObj
->currentProfilerContext
= pContext
->previous
;
706 PyDoc_STRVAR(disable_doc
, "\
709 Stop collecting profiling information.\n\
713 profiler_disable(ProfilerObject
*self
, PyObject
* noarg
)
715 self
->flags
&= ~POF_ENABLED
;
716 PyEval_SetProfile(NULL
, NULL
);
717 flush_unmatched(self
);
718 if (pending_exception(self
))
724 PyDoc_STRVAR(clear_doc
, "\
727 Clear all profiling information collected so far.\n\
731 profiler_clear(ProfilerObject
*pObj
, PyObject
* noarg
)
739 profiler_dealloc(ProfilerObject
*op
)
741 if (op
->flags
& POF_ENABLED
)
742 PyEval_SetProfile(NULL
, NULL
);
745 Py_XDECREF(op
->externalTimer
);
746 op
->ob_type
->tp_free(op
);
750 profiler_init(ProfilerObject
*pObj
, PyObject
*args
, PyObject
*kw
)
753 PyObject
*timer
= NULL
;
754 double timeunit
= 0.0;
756 #ifdef PyTrace_C_CALL
761 static const char *kwlist
[] = {"timer", "timeunit",
762 "subcalls", "builtins", 0};
764 if (!PyArg_ParseTupleAndKeywords(args
, kw
, "|Odii:Profiler", kwlist
,
766 &subcalls
, &builtins
))
769 if (setSubcalls(pObj
, subcalls
) < 0 || setBuiltins(pObj
, builtins
) < 0)
771 o
= pObj
->externalTimer
;
772 pObj
->externalTimer
= timer
;
775 pObj
->externalTimerUnit
= timeunit
;
779 static PyMethodDef profiler_methods
[] = {
780 {"getstats", (PyCFunction
)profiler_getstats
,
781 METH_NOARGS
, getstats_doc
},
782 {"enable", (PyCFunction
)profiler_enable
,
783 METH_VARARGS
| METH_KEYWORDS
, enable_doc
},
784 {"disable", (PyCFunction
)profiler_disable
,
785 METH_NOARGS
, disable_doc
},
786 {"clear", (PyCFunction
)profiler_clear
,
787 METH_NOARGS
, clear_doc
},
791 PyDoc_STRVAR(profiler_doc
, "\
792 Profiler(custom_timer=None, time_unit=None, subcalls=True, builtins=True)\n\
794 Builds a profiler object using the specified timer function.\n\
795 The default timer is a fast built-in one based on real time.\n\
796 For custom timer functions returning integers, time_unit can\n\
797 be a float specifying a scale (i.e. how long each integer unit\n\
801 statichere PyTypeObject PyProfiler_Type
= {
802 PyObject_HEAD_INIT(NULL
)
804 "_lsprof.Profiler", /* tp_name */
805 sizeof(ProfilerObject
), /* tp_basicsize */
807 (destructor
)profiler_dealloc
, /* tp_dealloc */
813 0, /* tp_as_number */
814 0, /* tp_as_sequence */
815 0, /* tp_as_mapping */
821 0, /* tp_as_buffer */
822 Py_TPFLAGS_DEFAULT
| Py_TPFLAGS_BASETYPE
, /* tp_flags */
823 profiler_doc
, /* tp_doc */
826 0, /* tp_richcompare */
827 0, /* tp_weaklistoffset */
830 profiler_methods
, /* tp_methods */
835 0, /* tp_descr_get */
836 0, /* tp_descr_set */
837 0, /* tp_dictoffset */
838 (initproc
)profiler_init
, /* tp_init */
839 PyType_GenericAlloc
, /* tp_alloc */
840 PyType_GenericNew
, /* tp_new */
841 PyObject_Del
, /* tp_free */
844 static PyMethodDef moduleMethods
[] = {
851 PyObject
*module
, *d
;
852 module
= Py_InitModule3("_lsprof", moduleMethods
, "Fast profiler");
853 d
= PyModule_GetDict(module
);
854 if (PyType_Ready(&PyProfiler_Type
) < 0)
856 PyDict_SetItemString(d
, "Profiler", (PyObject
*)&PyProfiler_Type
);
858 PyStructSequence_InitType(&StatsEntryType
, &profiler_entry_desc
);
859 PyStructSequence_InitType(&StatsSubEntryType
, &profiler_subentry_desc
);
860 Py_INCREF((PyObject
*) &StatsEntryType
);
861 Py_INCREF((PyObject
*) &StatsSubEntryType
);
862 PyModule_AddObject(module
, "profiler_entry",
863 (PyObject
*) &StatsEntryType
);
864 PyModule_AddObject(module
, "profiler_subentry",
865 (PyObject
*) &StatsSubEntryType
);
866 empty_tuple
= PyTuple_New(0);