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 ProfilerContexts */
307 if (pObj
->currentProfilerContext
) {
308 free(pObj
->currentProfilerContext
);
309 pObj
->currentProfilerContext
= NULL
;
311 while (pObj
->freelistProfilerContext
) {
312 ProfilerContext
*c
= pObj
->freelistProfilerContext
;
313 pObj
->freelistProfilerContext
= c
->previous
;
316 pObj
->freelistProfilerContext
= NULL
;
320 initContext(ProfilerObject
*pObj
, ProfilerContext
*self
, ProfilerEntry
*entry
)
322 self
->ctxEntry
= entry
;
324 self
->previous
= pObj
->currentProfilerContext
;
325 pObj
->currentProfilerContext
= self
;
326 ++entry
->recursionLevel
;
327 if ((pObj
->flags
& POF_SUBCALLS
) && self
->previous
) {
328 /* find or create an entry for me in my caller's entry */
329 ProfilerEntry
*caller
= self
->previous
->ctxEntry
;
330 ProfilerSubEntry
*subentry
= getSubEntry(pObj
, caller
, entry
);
331 if (subentry
== NULL
)
332 subentry
= newSubEntry(pObj
, caller
, entry
);
334 ++subentry
->recursionLevel
;
336 self
->t0
= CALL_TIMER(pObj
);
340 Stop(ProfilerObject
*pObj
, ProfilerContext
*self
, ProfilerEntry
*entry
)
342 PY_LONG_LONG tt
= CALL_TIMER(pObj
) - self
->t0
;
343 PY_LONG_LONG it
= tt
- self
->subt
;
345 self
->previous
->subt
+= tt
;
346 pObj
->currentProfilerContext
= self
->previous
;
347 if (--entry
->recursionLevel
== 0)
350 ++entry
->recursivecallcount
;
353 if ((pObj
->flags
& POF_SUBCALLS
) && self
->previous
) {
354 /* find or create an entry for me in my caller's entry */
355 ProfilerEntry
*caller
= self
->previous
->ctxEntry
;
356 ProfilerSubEntry
*subentry
= getSubEntry(pObj
, caller
, entry
);
358 if (--subentry
->recursionLevel
== 0)
361 ++subentry
->recursivecallcount
;
363 ++subentry
->callcount
;
369 ptrace_enter_call(PyObject
*self
, void *key
, PyObject
*userObj
)
371 /* entering a call to the function identified by 'key'
372 (which can be a PyCodeObject or a PyMethodDef pointer) */
373 ProfilerObject
*pObj
= (ProfilerObject
*)self
;
374 ProfilerEntry
*profEntry
;
375 ProfilerContext
*pContext
;
377 /* In the case of entering a generator expression frame via a
378 * throw (gen_send_ex(.., 1)), we may already have an
379 * Exception set here. We must not mess around with this
380 * exception, and some of the code under here assumes that
381 * PyErr_* is its own to mess around with, so we have to
382 * save and restore any current exception. */
383 PyObject
*last_type
, *last_value
, *last_tb
;
384 PyErr_Fetch(&last_type
, &last_value
, &last_tb
);
386 profEntry
= getEntry(pObj
, key
);
387 if (profEntry
== NULL
) {
388 profEntry
= newProfilerEntry(pObj
, key
, userObj
);
389 if (profEntry
== NULL
)
392 /* grab a ProfilerContext out of the free list */
393 pContext
= pObj
->freelistProfilerContext
;
395 pObj
->freelistProfilerContext
= pContext
->previous
;
398 /* free list exhausted, allocate a new one */
399 pContext
= (ProfilerContext
*)
400 malloc(sizeof(ProfilerContext
));
401 if (pContext
== NULL
) {
402 pObj
->flags
|= POF_NOMEMORY
;
406 initContext(pObj
, pContext
, profEntry
);
409 PyErr_Restore(last_type
, last_value
, last_tb
);
413 ptrace_leave_call(PyObject
*self
, void *key
)
415 /* leaving a call to the function identified by 'key' */
416 ProfilerObject
*pObj
= (ProfilerObject
*)self
;
417 ProfilerEntry
*profEntry
;
418 ProfilerContext
*pContext
;
420 pContext
= pObj
->currentProfilerContext
;
421 if (pContext
== NULL
)
423 profEntry
= getEntry(pObj
, key
);
425 Stop(pObj
, pContext
, profEntry
);
428 pObj
->currentProfilerContext
= pContext
->previous
;
430 /* put pContext into the free list */
431 pContext
->previous
= pObj
->freelistProfilerContext
;
432 pObj
->freelistProfilerContext
= pContext
;
436 profiler_callback(PyObject
*self
, PyFrameObject
*frame
, int what
,
441 /* the 'frame' of a called function is about to start its execution */
443 ptrace_enter_call(self
, (void *)frame
->f_code
,
444 (PyObject
*)frame
->f_code
);
447 /* the 'frame' of a called function is about to finish
448 (either normally or with an exception) */
450 ptrace_leave_call(self
, (void *)frame
->f_code
);
453 /* case PyTrace_EXCEPTION:
454 If the exception results in the function exiting, a
455 PyTrace_RETURN event will be generated, so we don't need to
458 #ifdef PyTrace_C_CALL /* not defined in Python <= 2.3 */
459 /* the Python function 'frame' is issuing a call to the built-in
462 if ((((ProfilerObject
*)self
)->flags
& POF_BUILTINS
)
463 && PyCFunction_Check(arg
)) {
464 ptrace_enter_call(self
,
465 ((PyCFunctionObject
*)arg
)->m_ml
,
470 /* the call to the built-in function 'arg' is returning into its
472 case PyTrace_C_RETURN
: /* ...normally */
473 case PyTrace_C_EXCEPTION
: /* ...with an exception set */
474 if ((((ProfilerObject
*)self
)->flags
& POF_BUILTINS
)
475 && PyCFunction_Check(arg
)) {
476 ptrace_leave_call(self
,
477 ((PyCFunctionObject
*)arg
)->m_ml
);
489 pending_exception(ProfilerObject
*pObj
)
491 if (pObj
->flags
& POF_NOMEMORY
) {
492 pObj
->flags
-= POF_NOMEMORY
;
493 PyErr_SetString(PyExc_MemoryError
,
494 "memory was exhausted while profiling");
500 /************************************************************/
502 static PyStructSequence_Field profiler_entry_fields
[] = {
503 {"code", "code object or built-in function name"},
504 {"callcount", "how many times this was called"},
505 {"reccallcount", "how many times called recursively"},
506 {"totaltime", "total time in this entry"},
507 {"inlinetime", "inline time in this entry (not in subcalls)"},
508 {"calls", "details of the calls"},
512 static PyStructSequence_Field profiler_subentry_fields
[] = {
513 {"code", "called code object or built-in function name"},
514 {"callcount", "how many times this is called"},
515 {"reccallcount", "how many times this is called recursively"},
516 {"totaltime", "total time spent in this call"},
517 {"inlinetime", "inline time (not in further subcalls)"},
521 static PyStructSequence_Desc profiler_entry_desc
= {
522 "_lsprof.profiler_entry", /* name */
524 profiler_entry_fields
,
528 static PyStructSequence_Desc profiler_subentry_desc
= {
529 "_lsprof.profiler_subentry", /* name */
531 profiler_subentry_fields
,
535 static int initialized
;
536 static PyTypeObject StatsEntryType
;
537 static PyTypeObject StatsSubEntryType
;
546 static int statsForSubEntry(rotating_node_t
*node
, void *arg
)
548 ProfilerSubEntry
*sentry
= (ProfilerSubEntry
*) node
;
549 statscollector_t
*collect
= (statscollector_t
*) arg
;
550 ProfilerEntry
*entry
= (ProfilerEntry
*) sentry
->header
.key
;
553 sinfo
= PyObject_CallFunction((PyObject
*) &StatsSubEntryType
,
557 sentry
->recursivecallcount
,
558 collect
->factor
* sentry
->tt
,
559 collect
->factor
* sentry
->it
);
562 err
= PyList_Append(collect
->sublist
, sinfo
);
567 static int statsForEntry(rotating_node_t
*node
, void *arg
)
569 ProfilerEntry
*entry
= (ProfilerEntry
*) node
;
570 statscollector_t
*collect
= (statscollector_t
*) arg
;
573 if (entry
->callcount
== 0)
576 if (entry
->calls
!= EMPTY_ROTATING_TREE
) {
577 collect
->sublist
= PyList_New(0);
578 if (collect
->sublist
== NULL
)
580 if (RotatingTree_Enum(entry
->calls
,
581 statsForSubEntry
, collect
) != 0) {
582 Py_DECREF(collect
->sublist
);
588 collect
->sublist
= Py_None
;
591 info
= PyObject_CallFunction((PyObject
*) &StatsEntryType
,
595 entry
->recursivecallcount
,
596 collect
->factor
* entry
->tt
,
597 collect
->factor
* entry
->it
,
599 Py_DECREF(collect
->sublist
);
602 err
= PyList_Append(collect
->list
, info
);
607 PyDoc_STRVAR(getstats_doc
, "\
608 getstats() -> list of profiler_entry objects\n\
610 Return all information collected by the profiler.\n\
611 Each profiler_entry is a tuple-like object with the\n\
612 following attributes:\n\
615 callcount how many times this was called\n\
616 reccallcount how many times called recursively\n\
617 totaltime total time in this entry\n\
618 inlinetime inline time in this entry (not in subcalls)\n\
619 calls details of the calls\n\
621 The calls attribute is either None or a list of\n\
622 profiler_subentry objects:\n\
624 code called code object\n\
625 callcount how many times this is called\n\
626 reccallcount how many times this is called recursively\n\
627 totaltime total time spent in this call\n\
628 inlinetime inline time (not in further subcalls)\n\
632 profiler_getstats(ProfilerObject
*pObj
, PyObject
* noarg
)
634 statscollector_t collect
;
635 if (pending_exception(pObj
))
637 if (!pObj
->externalTimer
)
638 collect
.factor
= hpTimerUnit();
639 else if (pObj
->externalTimerUnit
> 0.0)
640 collect
.factor
= pObj
->externalTimerUnit
;
642 collect
.factor
= 1.0 / DOUBLE_TIMER_PRECISION
;
643 collect
.list
= PyList_New(0);
644 if (collect
.list
== NULL
)
646 if (RotatingTree_Enum(pObj
->profilerEntries
, statsForEntry
, &collect
)
648 Py_DECREF(collect
.list
);
655 setSubcalls(ProfilerObject
*pObj
, int nvalue
)
658 pObj
->flags
&= ~POF_SUBCALLS
;
660 pObj
->flags
|= POF_SUBCALLS
;
665 setBuiltins(ProfilerObject
*pObj
, int nvalue
)
668 pObj
->flags
&= ~POF_BUILTINS
;
669 else if (nvalue
> 0) {
670 #ifndef PyTrace_C_CALL
671 PyErr_SetString(PyExc_ValueError
,
672 "builtins=True requires Python >= 2.4");
675 pObj
->flags
|= POF_BUILTINS
;
681 PyDoc_STRVAR(enable_doc
, "\
682 enable(subcalls=True, builtins=True)\n\
684 Start collecting profiling information.\n\
685 If 'subcalls' is True, also records for each function\n\
686 statistics separated according to its current caller.\n\
687 If 'builtins' is True, records the time spent in\n\
688 built-in functions separately from their caller.\n\
692 profiler_enable(ProfilerObject
*self
, PyObject
*args
, PyObject
*kwds
)
696 static char *kwlist
[] = {"subcalls", "builtins", 0};
697 if (!PyArg_ParseTupleAndKeywords(args
, kwds
, "|ii:enable",
698 kwlist
, &subcalls
, &builtins
))
700 if (setSubcalls(self
, subcalls
) < 0 || setBuiltins(self
, builtins
) < 0)
702 PyEval_SetProfile(profiler_callback
, (PyObject
*)self
);
703 self
->flags
|= POF_ENABLED
;
709 flush_unmatched(ProfilerObject
*pObj
)
711 while (pObj
->currentProfilerContext
) {
712 ProfilerContext
*pContext
= pObj
->currentProfilerContext
;
713 ProfilerEntry
*profEntry
= pContext
->ctxEntry
;
715 Stop(pObj
, pContext
, profEntry
);
717 pObj
->currentProfilerContext
= pContext
->previous
;
724 PyDoc_STRVAR(disable_doc
, "\
727 Stop collecting profiling information.\n\
731 profiler_disable(ProfilerObject
*self
, PyObject
* noarg
)
733 self
->flags
&= ~POF_ENABLED
;
734 PyEval_SetProfile(NULL
, NULL
);
735 flush_unmatched(self
);
736 if (pending_exception(self
))
742 PyDoc_STRVAR(clear_doc
, "\
745 Clear all profiling information collected so far.\n\
749 profiler_clear(ProfilerObject
*pObj
, PyObject
* noarg
)
757 profiler_dealloc(ProfilerObject
*op
)
759 if (op
->flags
& POF_ENABLED
)
760 PyEval_SetProfile(NULL
, NULL
);
763 Py_XDECREF(op
->externalTimer
);
764 Py_TYPE(op
)->tp_free(op
);
768 profiler_init(ProfilerObject
*pObj
, PyObject
*args
, PyObject
*kw
)
771 PyObject
*timer
= NULL
;
772 double timeunit
= 0.0;
774 #ifdef PyTrace_C_CALL
779 static char *kwlist
[] = {"timer", "timeunit",
780 "subcalls", "builtins", 0};
782 if (!PyArg_ParseTupleAndKeywords(args
, kw
, "|Odii:Profiler", kwlist
,
784 &subcalls
, &builtins
))
787 if (setSubcalls(pObj
, subcalls
) < 0 || setBuiltins(pObj
, builtins
) < 0)
789 o
= pObj
->externalTimer
;
790 pObj
->externalTimer
= timer
;
793 pObj
->externalTimerUnit
= timeunit
;
797 static PyMethodDef profiler_methods
[] = {
798 {"getstats", (PyCFunction
)profiler_getstats
,
799 METH_NOARGS
, getstats_doc
},
800 {"enable", (PyCFunction
)profiler_enable
,
801 METH_VARARGS
| METH_KEYWORDS
, enable_doc
},
802 {"disable", (PyCFunction
)profiler_disable
,
803 METH_NOARGS
, disable_doc
},
804 {"clear", (PyCFunction
)profiler_clear
,
805 METH_NOARGS
, clear_doc
},
809 PyDoc_STRVAR(profiler_doc
, "\
810 Profiler(custom_timer=None, time_unit=None, subcalls=True, builtins=True)\n\
812 Builds a profiler object using the specified timer function.\n\
813 The default timer is a fast built-in one based on real time.\n\
814 For custom timer functions returning integers, time_unit can\n\
815 be a float specifying a scale (i.e. how long each integer unit\n\
819 static PyTypeObject PyProfiler_Type
= {
820 PyVarObject_HEAD_INIT(NULL
, 0)
821 "_lsprof.Profiler", /* tp_name */
822 sizeof(ProfilerObject
), /* tp_basicsize */
824 (destructor
)profiler_dealloc
, /* tp_dealloc */
830 0, /* tp_as_number */
831 0, /* tp_as_sequence */
832 0, /* tp_as_mapping */
838 0, /* tp_as_buffer */
839 Py_TPFLAGS_DEFAULT
| Py_TPFLAGS_BASETYPE
, /* tp_flags */
840 profiler_doc
, /* tp_doc */
843 0, /* tp_richcompare */
844 0, /* tp_weaklistoffset */
847 profiler_methods
, /* tp_methods */
852 0, /* tp_descr_get */
853 0, /* tp_descr_set */
854 0, /* tp_dictoffset */
855 (initproc
)profiler_init
, /* tp_init */
856 PyType_GenericAlloc
, /* tp_alloc */
857 PyType_GenericNew
, /* tp_new */
858 PyObject_Del
, /* tp_free */
861 static PyMethodDef moduleMethods
[] = {
866 static struct PyModuleDef _lsprofmodule
= {
867 PyModuleDef_HEAD_INIT
,
881 PyObject
*module
, *d
;
882 module
= PyModule_Create(&_lsprofmodule
);
885 d
= PyModule_GetDict(module
);
886 if (PyType_Ready(&PyProfiler_Type
) < 0)
888 PyDict_SetItemString(d
, "Profiler", (PyObject
*)&PyProfiler_Type
);
891 PyStructSequence_InitType(&StatsEntryType
,
892 &profiler_entry_desc
);
893 PyStructSequence_InitType(&StatsSubEntryType
,
894 &profiler_subentry_desc
);
896 Py_INCREF((PyObject
*) &StatsEntryType
);
897 Py_INCREF((PyObject
*) &StatsSubEntryType
);
898 PyModule_AddObject(module
, "profiler_entry",
899 (PyObject
*) &StatsEntryType
);
900 PyModule_AddObject(module
, "profiler_subentry",
901 (PyObject
*) &StatsSubEntryType
);
902 empty_tuple
= PyTuple_New(0);