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) (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((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(Py_Type(self
), 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 /* 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 statichere PyTypeObject PyProfiler_Type
= {
815 PyObject_HEAD_INIT(NULL
)
817 "_lsprof.Profiler", /* tp_name */
818 sizeof(ProfilerObject
), /* tp_basicsize */
820 (destructor
)profiler_dealloc
, /* tp_dealloc */
826 0, /* tp_as_number */
827 0, /* tp_as_sequence */
828 0, /* tp_as_mapping */
834 0, /* tp_as_buffer */
835 Py_TPFLAGS_DEFAULT
| Py_TPFLAGS_BASETYPE
, /* tp_flags */
836 profiler_doc
, /* tp_doc */
839 0, /* tp_richcompare */
840 0, /* tp_weaklistoffset */
843 profiler_methods
, /* tp_methods */
848 0, /* tp_descr_get */
849 0, /* tp_descr_set */
850 0, /* tp_dictoffset */
851 (initproc
)profiler_init
, /* tp_init */
852 PyType_GenericAlloc
, /* tp_alloc */
853 PyType_GenericNew
, /* tp_new */
854 PyObject_Del
, /* tp_free */
857 static PyMethodDef moduleMethods
[] = {
864 PyObject
*module
, *d
;
865 module
= Py_InitModule3("_lsprof", moduleMethods
, "Fast profiler");
868 d
= PyModule_GetDict(module
);
869 if (PyType_Ready(&PyProfiler_Type
) < 0)
871 PyDict_SetItemString(d
, "Profiler", (PyObject
*)&PyProfiler_Type
);
874 PyStructSequence_InitType(&StatsEntryType
,
875 &profiler_entry_desc
);
876 PyStructSequence_InitType(&StatsSubEntryType
,
877 &profiler_subentry_desc
);
879 Py_INCREF((PyObject
*) &StatsEntryType
);
880 Py_INCREF((PyObject
*) &StatsSubEntryType
);
881 PyModule_AddObject(module
, "profiler_entry",
882 (PyObject
*) &StatsEntryType
);
883 PyModule_AddObject(module
, "profiler_subentry",
884 (PyObject
*) &StatsSubEntryType
);
885 empty_tuple
= PyTuple_New(0);