2 * This is the High Performance Python Profiler portion of HotShot.
8 #include "frameobject.h"
9 #include "structmember.h"
12 * Which timer to use should be made more configurable, but that should not
13 * be difficult. This will do for now.
19 #include <direct.h> /* for getcwd() */
22 typedef __int64 hs_time
;
23 #define GETTIMEOFDAY(P_HS_TIME) \
24 { LARGE_INTEGER _temp; \
25 QueryPerformanceCounter(&_temp); \
26 *(P_HS_TIME) = _temp.QuadPart; }
30 #ifndef HAVE_GETTIMEOFDAY
31 #error "This module requires gettimeofday() on non-Windows platforms!"
33 #if (defined(PYOS_OS2) && defined(PYCC_GCC)) || defined(__QNX__)
36 #include <sys/resource.h>
37 #include <sys/times.h>
39 typedef struct timeval hs_time
;
42 #if !defined(__cplusplus) && !defined(inline)
44 #define inline __inline
52 #define BUFFERSIZE 10240
54 #if defined(PYOS_OS2) && defined(PYCC_GCC)
58 #if defined(__sgi) && _COMPILER_VERSION>700 && !defined(PATH_MAX)
59 /* fix PATH_MAX not being defined with MIPSPro 7.x
60 if mode is ANSI C (default) */
66 # define PATH_MAX MAX_PATH
67 # elif defined (_POSIX_PATH_MAX)
68 # define PATH_MAX _POSIX_PATH_MAX
70 # error "Need a defn. for PATH_MAX in _hotshot.c"
77 PyObject
*logfilename
;
79 unsigned char buffer
[BUFFERSIZE
];
87 hs_time prev_timeofday
;
98 static PyObject
* ProfilerError
= NULL
;
102 #ifdef GETTIMEOFDAY_NO_TZ
103 #define GETTIMEOFDAY(ptv) gettimeofday((ptv))
105 #define GETTIMEOFDAY(ptv) gettimeofday((ptv), (struct timezone *)NULL)
110 /* The log reader... */
112 PyDoc_STRVAR(logreader_close__doc__
,
114 "Close the log file, preventing additional records from being read.");
117 logreader_close(LogReaderObject
*self
, PyObject
*args
)
119 if (self
->logfp
!= NULL
) {
128 PyDoc_STRVAR(logreader_fileno__doc__
,
129 "fileno() -> file descriptor\n"
130 "Returns the file descriptor for the log file, if open.\n"
131 "Raises ValueError if the log file is closed.");
134 logreader_fileno(LogReaderObject
*self
)
136 if (self
->logfp
== NULL
) {
137 PyErr_SetString(PyExc_ValueError
,
138 "logreader's file object already closed");
141 return PyInt_FromLong(fileno(self
->logfp
));
148 * The log file consists of a sequence of variable-length records.
149 * Each record is identified with a record type identifier in two
150 * bits of the first byte. The two bits are the "least significant"
153 * Low bits: Opcode: Meaning:
154 * 0x00 ENTER enter a frame
155 * 0x01 EXIT exit a frame
156 * 0x02 LINENO execution moved onto a different line
157 * 0x03 OTHER more bits are needed to deecode
159 * If the type is OTHER, the record is not packed so tightly, and the
160 * remaining bits are used to disambiguate the record type. These
161 * records are not used as frequently so compaction is not an issue.
162 * Each of the first three record types has a highly tailored
163 * structure that allows it to be packed tightly.
165 * The OTHER records have the following identifiers:
167 * First byte: Opcode: Meaning:
168 * 0x13 ADD_INFO define a key/value pair
169 * 0x23 DEFINE_FILE define an int->filename mapping
170 * 0x33 LINE_TIMES indicates if LINENO events have tdeltas
171 * 0x43 DEFINE_FUNC define a (fileno,lineno)->funcname mapping
172 * 0x53 FRAME_TIMES indicates if ENTER/EXIT events have tdeltas
176 * "Packed integers" are non-negative integer values encoded as a
177 * sequence of bytes. Each byte is encoded such that the most
178 * significant bit is set if the next byte is also part of the
179 * integer. Each byte provides bits to the least-significant end of
180 * the result; the accumulated value must be shifted up to place the
181 * new bits into the result.
183 * "Modified packed integers" are packed integers where only a portion
184 * of the first byte is used. In the rest of the specification, these
185 * are referred to as "MPI(n,name)", where "n" is the number of bits
186 * discarded from the least-signicant positions of the byte, and
187 * "name" is a name being given to those "discarded" bits, since they
188 * are a field themselves.
192 * MPI(2,type) fileno -- type is 0x00
194 * PI tdelta -- iff frame times are enabled
198 * MPI(2,type) tdelta -- type is 0x01; tdelta will be 0
199 * if frame times are disabled
203 * MPI(2,type) lineno -- type is 0x02
204 * PI tdelta -- iff LINENO includes it
208 * BYTE type -- always 0x13
209 * PI len1 -- length of first string
210 * BYTE string1[len1] -- len1 bytes of string data
211 * PI len2 -- length of second string
212 * BYTE string2[len2] -- len2 bytes of string data
214 * DEFINE_FILE records
216 * BYTE type -- always 0x23
218 * PI len -- length of filename
219 * BYTE filename[len] -- len bytes of string data
221 * DEFINE_FUNC records
223 * BYTE type -- always 0x43
226 * PI len -- length of funcname
227 * BYTE funcname[len] -- len bytes of string data
231 * This record can be used only before the start of ENTER/EXIT/LINENO
232 * records. If have_tdelta is true, LINENO records will include the
233 * tdelta field, otherwise it will be omitted. If this record is not
234 * given, LINENO records will not contain the tdelta field.
236 * BYTE type -- always 0x33
237 * BYTE have_tdelta -- 0 if LINENO does *not* have
239 * FRAME_TIMES records
241 * This record can be used only before the start of ENTER/EXIT/LINENO
242 * records. If have_tdelta is true, ENTER and EXIT records will
243 * include the tdelta field, otherwise it will be omitted. If this
244 * record is not given, ENTER and EXIT records will contain the tdelta
247 * BYTE type -- always 0x53
248 * BYTE have_tdelta -- 0 if ENTER/EXIT do *not* have
252 #define WHAT_ENTER 0x00
253 #define WHAT_EXIT 0x01
254 #define WHAT_LINENO 0x02
255 #define WHAT_OTHER 0x03 /* only used in decoding */
256 #define WHAT_ADD_INFO 0x13
257 #define WHAT_DEFINE_FILE 0x23
258 #define WHAT_LINE_TIMES 0x33
259 #define WHAT_DEFINE_FUNC 0x43
260 #define WHAT_FRAME_TIMES 0x53
264 #define ERR_EXCEPTION -2
265 #define ERR_BAD_RECTYPE -3
267 #define PISIZE (sizeof(int) + 1)
268 #define MPISIZE (PISIZE + 1)
270 /* Maximum size of "normal" events -- nothing that contains string data */
271 #define MAXEVENTSIZE (MPISIZE + PISIZE*2)
274 /* Unpack a packed integer; if "discard" is non-zero, unpack a modified
275 * packed integer with "discard" discarded bits.
278 unpack_packed_int(LogReaderObject
*self
, int *pvalue
, int discard
)
287 if ((c
= fgetc(self
->logfp
)) == EOF
)
289 accum
|= ((c
& 0x7F) >> discard
) << bits
;
290 bits
+= (7 - discard
);
300 /* Unpack a string, which is encoded as a packed integer giving the
301 * length of the string, followed by the string data.
304 unpack_string(LogReaderObject
*self
, PyObject
**pvalue
)
312 if ((err
= unpack_packed_int(self
, &len
, 0)))
315 buf
= (char *)malloc(len
);
316 for (i
=0; i
< len
; i
++) {
317 ch
= fgetc(self
->logfp
);
324 *pvalue
= PyString_FromStringAndSize(buf
, len
);
326 if (*pvalue
== NULL
) {
327 return ERR_EXCEPTION
;
334 unpack_add_info(LogReaderObject
*self
)
337 PyObject
*value
= NULL
;
340 err
= unpack_string(self
, &key
);
342 err
= unpack_string(self
, &value
);
346 PyObject
*list
= PyDict_GetItem(self
->info
, key
);
348 list
= PyList_New(0);
353 if (PyDict_SetItem(self
->info
, key
, list
)) {
360 if (PyList_Append(list
, value
))
372 eof_error(LogReaderObject
*self
)
376 PyErr_SetString(PyExc_EOFError
,
377 "end of file with incomplete profile record");
381 logreader_tp_iternext(LogReaderObject
*self
)
389 PyObject
*s1
= NULL
, *s2
= NULL
;
390 PyObject
*result
= NULL
;
392 unsigned char b0
, b1
;
395 if (self
->logfp
== NULL
) {
396 PyErr_SetString(ProfilerError
,
397 "cannot iterate over closed LogReader object");
402 /* decode the record type */
403 if ((c
= fgetc(self
->logfp
)) == EOF
) {
408 what
= c
& WHAT_OTHER
;
409 if (what
== WHAT_OTHER
)
410 what
= c
; /* need all the bits for type */
412 ungetc(c
, self
->logfp
); /* type byte includes packed int */
416 err
= unpack_packed_int(self
, &fileno
, 2);
418 err
= unpack_packed_int(self
, &lineno
, 0);
419 if (self
->frametimings
&& !err
)
420 err
= unpack_packed_int(self
, &tdelta
, 0);
424 err
= unpack_packed_int(self
, &tdelta
, 2);
427 err
= unpack_packed_int(self
, &lineno
, 2);
428 if (self
->linetimings
&& !err
)
429 err
= unpack_packed_int(self
, &tdelta
, 0);
432 err
= unpack_add_info(self
);
434 case WHAT_DEFINE_FILE
:
435 err
= unpack_packed_int(self
, &fileno
, 0);
437 err
= unpack_string(self
, &s1
);
444 case WHAT_DEFINE_FUNC
:
445 err
= unpack_packed_int(self
, &fileno
, 0);
447 err
= unpack_packed_int(self
, &lineno
, 0);
449 err
= unpack_string(self
, &s1
);
452 case WHAT_LINE_TIMES
:
453 if ((c
= fgetc(self
->logfp
)) == EOF
)
456 self
->linetimings
= c
? 1 : 0;
460 case WHAT_FRAME_TIMES
:
461 if ((c
= fgetc(self
->logfp
)) == EOF
)
464 self
->frametimings
= c
? 1 : 0;
469 err
= ERR_BAD_RECTYPE
;
471 if (err
== ERR_BAD_RECTYPE
) {
472 PyErr_SetString(PyExc_ValueError
,
473 "unknown record type in log file");
475 else if (err
== ERR_EOF
) {
479 result
= PyTuple_New(4);
482 PyTuple_SET_ITEM(result
, 0, PyInt_FromLong(what
));
483 PyTuple_SET_ITEM(result
, 2, PyInt_FromLong(fileno
));
485 PyTuple_SET_ITEM(result
, 1, PyInt_FromLong(tdelta
));
487 PyTuple_SET_ITEM(result
, 1, s1
);
489 PyTuple_SET_ITEM(result
, 3, PyInt_FromLong(lineno
));
491 PyTuple_SET_ITEM(result
, 3, s2
);
493 /* The only other case is err == ERR_EXCEPTION, in which case the
494 * exception is already set.
497 b0
= self
->buffer
[self
->index
];
498 b1
= self
->buffer
[self
->index
+ 1];
500 /* This is a line-number event. */
502 lineno
= ((b0
& ~1) << 7) + b1
;
506 what
= (b0
& 0x0E) >> 1;
507 tdelta
= ((b0
& 0xF0) << 4) + b1
;
508 if (what
== PyTrace_CALL
) {
509 /* we know there's a 2-byte file ID & 2-byte line number */
510 fileno
= ((self
->buffer
[self
->index
+ 2] << 8)
511 + self
->buffer
[self
->index
+ 3]);
512 lineno
= ((self
->buffer
[self
->index
+ 4] << 8)
513 + self
->buffer
[self
->index
+ 5]);
524 logreader_dealloc(LogReaderObject
*self
)
526 if (self
->logfp
!= NULL
) {
530 Py_XDECREF(self
->info
);
535 logreader_sq_item(LogReaderObject
*self
, Py_ssize_t index
)
537 PyObject
*result
= logreader_tp_iternext(self
);
538 if (result
== NULL
&& !PyErr_Occurred()) {
539 PyErr_SetString(PyExc_IndexError
, "no more events in log");
546 do_stop(ProfilerObject
*self
);
549 flush_data(ProfilerObject
*self
)
551 /* Need to dump data to the log file... */
552 size_t written
= fwrite(self
->buffer
, 1, self
->index
, self
->logfp
);
553 if (written
== (size_t)self
->index
)
556 memmove(self
->buffer
, &self
->buffer
[written
],
557 self
->index
- written
);
558 self
->index
-= written
;
560 char *s
= PyString_AsString(self
->logfilename
);
561 PyErr_SetFromErrnoWithFilename(PyExc_IOError
, s
);
567 if (fflush(self
->logfp
)) {
568 char *s
= PyString_AsString(self
->logfilename
);
569 PyErr_SetFromErrnoWithFilename(PyExc_IOError
, s
);
578 pack_packed_int(ProfilerObject
*self
, int value
)
580 unsigned char partial
;
583 partial
= value
& 0x7F;
587 self
->buffer
[self
->index
] = partial
;
593 /* Encode a modified packed integer, with a subfield of modsize bits
594 * containing the value "subfield". The value of subfield is not
595 * checked to ensure it actually fits in modsize bits.
598 pack_modified_packed_int(ProfilerObject
*self
, int value
,
599 int modsize
, int subfield
)
601 const int maxvalues
[] = {-1, 1, 3, 7, 15, 31, 63, 127};
603 int bits
= 7 - modsize
;
604 int partial
= value
& maxvalues
[bits
];
605 unsigned char b
= subfield
| (partial
<< modsize
);
607 if (partial
!= value
) {
609 self
->buffer
[self
->index
] = b
;
611 return pack_packed_int(self
, value
>> bits
);
613 self
->buffer
[self
->index
] = b
;
619 pack_string(ProfilerObject
*self
, const char *s
, Py_ssize_t len
)
621 if (len
+ PISIZE
+ self
->index
>= BUFFERSIZE
) {
622 if (flush_data(self
) < 0)
625 assert(len
< INT_MAX
);
626 if (pack_packed_int(self
, (int)len
) < 0)
628 memcpy(self
->buffer
+ self
->index
, s
, len
);
634 pack_add_info(ProfilerObject
*self
, const char *s1
, const char *s2
)
636 Py_ssize_t len1
= strlen(s1
);
637 Py_ssize_t len2
= strlen(s2
);
639 if (len1
+ len2
+ PISIZE
*2 + 1 + self
->index
>= BUFFERSIZE
) {
640 if (flush_data(self
) < 0)
643 self
->buffer
[self
->index
] = WHAT_ADD_INFO
;
645 if (pack_string(self
, s1
, len1
) < 0)
647 return pack_string(self
, s2
, len2
);
651 pack_define_file(ProfilerObject
*self
, int fileno
, const char *filename
)
653 Py_ssize_t len
= strlen(filename
);
655 if (len
+ PISIZE
*2 + 1 + self
->index
>= BUFFERSIZE
) {
656 if (flush_data(self
) < 0)
659 self
->buffer
[self
->index
] = WHAT_DEFINE_FILE
;
661 if (pack_packed_int(self
, fileno
) < 0)
663 return pack_string(self
, filename
, len
);
667 pack_define_func(ProfilerObject
*self
, int fileno
, int lineno
,
668 const char *funcname
)
670 Py_ssize_t len
= strlen(funcname
);
672 if (len
+ PISIZE
*3 + 1 + self
->index
>= BUFFERSIZE
) {
673 if (flush_data(self
) < 0)
676 self
->buffer
[self
->index
] = WHAT_DEFINE_FUNC
;
678 if (pack_packed_int(self
, fileno
) < 0)
680 if (pack_packed_int(self
, lineno
) < 0)
682 return pack_string(self
, funcname
, len
);
686 pack_line_times(ProfilerObject
*self
)
688 if (2 + self
->index
>= BUFFERSIZE
) {
689 if (flush_data(self
) < 0)
692 self
->buffer
[self
->index
] = WHAT_LINE_TIMES
;
693 self
->buffer
[self
->index
+ 1] = self
->linetimings
? 1 : 0;
699 pack_frame_times(ProfilerObject
*self
)
701 if (2 + self
->index
>= BUFFERSIZE
) {
702 if (flush_data(self
) < 0)
705 self
->buffer
[self
->index
] = WHAT_FRAME_TIMES
;
706 self
->buffer
[self
->index
+ 1] = self
->frametimings
? 1 : 0;
712 pack_enter(ProfilerObject
*self
, int fileno
, int tdelta
, int lineno
)
714 if (MPISIZE
+ PISIZE
*2 + self
->index
>= BUFFERSIZE
) {
715 if (flush_data(self
) < 0)
718 pack_modified_packed_int(self
, fileno
, 2, WHAT_ENTER
);
719 pack_packed_int(self
, lineno
);
720 if (self
->frametimings
)
721 return pack_packed_int(self
, tdelta
);
727 pack_exit(ProfilerObject
*self
, int tdelta
)
729 if (MPISIZE
+ self
->index
>= BUFFERSIZE
) {
730 if (flush_data(self
) < 0)
733 if (self
->frametimings
)
734 return pack_modified_packed_int(self
, tdelta
, 2, WHAT_EXIT
);
735 self
->buffer
[self
->index
] = WHAT_EXIT
;
741 pack_lineno(ProfilerObject
*self
, int lineno
)
743 if (MPISIZE
+ self
->index
>= BUFFERSIZE
) {
744 if (flush_data(self
) < 0)
747 return pack_modified_packed_int(self
, lineno
, 2, WHAT_LINENO
);
751 pack_lineno_tdelta(ProfilerObject
*self
, int lineno
, int tdelta
)
753 if (MPISIZE
+ PISIZE
+ self
->index
>= BUFFERSIZE
) {
754 if (flush_data(self
) < 0)
757 if (pack_modified_packed_int(self
, lineno
, 2, WHAT_LINENO
) < 0)
759 return pack_packed_int(self
, tdelta
);
763 get_fileno(ProfilerObject
*self
, PyCodeObject
*fcode
)
765 /* This is only used for ENTER events. */
771 obj
= PyDict_GetItem(self
->filemap
, fcode
->co_filename
);
773 /* first sighting of this file */
778 fileno
= self
->next_fileno
;
779 obj
= Py_BuildValue("iN", fileno
, dict
);
783 if (PyDict_SetItem(self
->filemap
, fcode
->co_filename
, obj
)) {
789 if (pack_define_file(self
, fileno
,
790 PyString_AS_STRING(fcode
->co_filename
)) < 0)
794 /* already know this ID */
795 fileno
= PyInt_AS_LONG(PyTuple_GET_ITEM(obj
, 0));
796 dict
= PyTuple_GET_ITEM(obj
, 1);
798 /* make sure we save a function name for this (fileno, lineno) */
799 obj
= PyInt_FromLong(fcode
->co_firstlineno
);
801 /* We just won't have it saved; too bad. */
805 PyObject
*name
= PyDict_GetItem(dict
, obj
);
807 if (pack_define_func(self
, fileno
, fcode
->co_firstlineno
,
808 PyString_AS_STRING(fcode
->co_name
)) < 0) {
812 if (PyDict_SetItem(dict
, obj
, fcode
->co_name
)) {
823 get_tdelta(ProfilerObject
*self
)
831 diff
= tv
- self
->prev_timeofday
;
838 tdelta
= tv
.tv_usec
- self
->prev_timeofday
.tv_usec
;
839 if (tv
.tv_sec
!= self
->prev_timeofday
.tv_sec
)
840 tdelta
+= (tv
.tv_sec
- self
->prev_timeofday
.tv_sec
) * 1000000;
842 /* time can go backwards on some multiprocessor systems or by NTP */
846 self
->prev_timeofday
= tv
;
851 /* The workhorse: the profiler callback function. */
854 tracer_callback(ProfilerObject
*self
, PyFrameObject
*frame
, int what
,
861 fileno
= get_fileno(self
, frame
->f_code
);
864 return pack_enter(self
, fileno
,
865 self
->frametimings
? get_tdelta(self
) : -1,
866 frame
->f_code
->co_firstlineno
);
869 return pack_exit(self
, get_tdelta(self
));
871 case PyTrace_LINE
: /* we only get these events if we asked for them */
872 if (self
->linetimings
)
873 return pack_lineno_tdelta(self
, frame
->f_lineno
,
876 return pack_lineno(self
, frame
->f_lineno
);
879 /* ignore PyTrace_EXCEPTION */
886 /* A couple of useful helper functions. */
889 static LARGE_INTEGER frequency
= {0, 0};
892 static unsigned long timeofday_diff
= 0;
893 static unsigned long rusage_diff
= 0;
902 QueryPerformanceFrequency(&frequency
);
911 timeofday_diff
= (unsigned long)diff
;
915 if (tv1
.tv_sec
!= tv2
.tv_sec
|| tv1
.tv_usec
!= tv2
.tv_usec
) {
916 if (tv1
.tv_sec
== tv2
.tv_sec
)
917 timeofday_diff
= tv2
.tv_usec
- tv1
.tv_usec
;
919 timeofday_diff
= (1000000 - tv1
.tv_usec
) + tv2
.tv_usec
;
924 #if defined(MS_WINDOWS) || defined(PYOS_OS2) || \
925 defined(__VMS) || defined (__QNX__)
929 struct rusage ru1
, ru2
;
931 getrusage(RUSAGE_SELF
, &ru1
);
933 getrusage(RUSAGE_SELF
, &ru2
);
934 if (ru1
.ru_utime
.tv_sec
!= ru2
.ru_utime
.tv_sec
) {
935 rusage_diff
= ((1000000 - ru1
.ru_utime
.tv_usec
)
936 + ru2
.ru_utime
.tv_usec
);
939 else if (ru1
.ru_utime
.tv_usec
!= ru2
.ru_utime
.tv_usec
) {
940 rusage_diff
= ru2
.ru_utime
.tv_usec
- ru1
.ru_utime
.tv_usec
;
943 else if (ru1
.ru_stime
.tv_sec
!= ru2
.ru_stime
.tv_sec
) {
944 rusage_diff
= ((1000000 - ru1
.ru_stime
.tv_usec
)
945 + ru2
.ru_stime
.tv_usec
);
948 else if (ru1
.ru_stime
.tv_usec
!= ru2
.ru_stime
.tv_usec
) {
949 rusage_diff
= ru2
.ru_stime
.tv_usec
- ru1
.ru_stime
.tv_usec
;
958 do_start(ProfilerObject
*self
)
961 GETTIMEOFDAY(&self
->prev_timeofday
);
962 if (self
->lineevents
)
963 PyEval_SetTrace((Py_tracefunc
) tracer_callback
, (PyObject
*)self
);
965 PyEval_SetProfile((Py_tracefunc
) tracer_callback
, (PyObject
*)self
);
969 do_stop(ProfilerObject
*self
)
973 if (self
->lineevents
)
974 PyEval_SetTrace(NULL
, NULL
);
976 PyEval_SetProfile(NULL
, NULL
);
978 if (self
->index
> 0) {
979 /* Best effort to dump out any remaining data. */
985 is_available(ProfilerObject
*self
)
988 PyErr_SetString(ProfilerError
, "profiler already active");
991 if (self
->logfp
== NULL
) {
992 PyErr_SetString(ProfilerError
, "profiler already closed");
999 /* Profiler object interface methods. */
1001 PyDoc_STRVAR(addinfo__doc__
,
1002 "addinfo(key, value)\n"
1003 "Insert an ADD_INFO record into the log.");
1006 profiler_addinfo(ProfilerObject
*self
, PyObject
*args
)
1008 PyObject
*result
= NULL
;
1011 if (PyArg_ParseTuple(args
, "ss:addinfo", &key
, &value
)) {
1012 if (self
->logfp
== NULL
)
1013 PyErr_SetString(ProfilerError
, "profiler already closed");
1015 if (pack_add_info(self
, key
, value
) == 0) {
1024 PyDoc_STRVAR(close__doc__
,
1026 "Shut down this profiler and close the log files, even if its active.");
1029 profiler_close(ProfilerObject
*self
)
1032 if (self
->logfp
!= NULL
) {
1033 fclose(self
->logfp
);
1040 #define fileno__doc__ logreader_fileno__doc__
1043 profiler_fileno(ProfilerObject
*self
)
1045 if (self
->logfp
== NULL
) {
1046 PyErr_SetString(PyExc_ValueError
,
1047 "profiler's file object already closed");
1050 return PyInt_FromLong(fileno(self
->logfp
));
1053 PyDoc_STRVAR(runcall__doc__
,
1054 "runcall(callable[, args[, kw]]) -> callable()\n"
1055 "Profile a specific function call, returning the result of that call.");
1058 profiler_runcall(ProfilerObject
*self
, PyObject
*args
)
1060 PyObject
*result
= NULL
;
1061 PyObject
*callargs
= NULL
;
1062 PyObject
*callkw
= NULL
;
1065 if (PyArg_UnpackTuple(args
, "runcall", 1, 3,
1066 &callable
, &callargs
, &callkw
)) {
1067 if (is_available(self
)) {
1069 result
= PyEval_CallObjectWithKeywords(callable
, callargs
, callkw
);
1076 PyDoc_STRVAR(runcode__doc__
,
1077 "runcode(code, globals[, locals])\n"
1078 "Execute a code object while collecting profile data. If locals is\n"
1079 "omitted, globals is used for the locals as well.");
1082 profiler_runcode(ProfilerObject
*self
, PyObject
*args
)
1084 PyObject
*result
= NULL
;
1087 PyObject
*locals
= NULL
;
1089 if (PyArg_ParseTuple(args
, "O!O!|O:runcode",
1090 &PyCode_Type
, &code
,
1091 &PyDict_Type
, &globals
,
1093 if (is_available(self
)) {
1094 if (locals
== NULL
|| locals
== Py_None
)
1096 else if (!PyDict_Check(locals
)) {
1097 PyErr_SetString(PyExc_TypeError
,
1098 "locals must be a dictionary or None");
1102 result
= PyEval_EvalCode(code
, globals
, locals
);
1105 if (!PyErr_Occurred()) {
1115 PyDoc_STRVAR(start__doc__
,
1117 "Install this profiler for the current thread.");
1120 profiler_start(ProfilerObject
*self
, PyObject
*args
)
1122 PyObject
*result
= NULL
;
1124 if (is_available(self
)) {
1132 PyDoc_STRVAR(stop__doc__
,
1134 "Remove this profiler from the current thread.");
1137 profiler_stop(ProfilerObject
*self
, PyObject
*args
)
1139 PyObject
*result
= NULL
;
1142 PyErr_SetString(ProfilerError
, "profiler not active");
1152 /* Python API support. */
1155 profiler_dealloc(ProfilerObject
*self
)
1158 if (self
->logfp
!= NULL
)
1159 fclose(self
->logfp
);
1160 Py_XDECREF(self
->filemap
);
1161 Py_XDECREF(self
->logfilename
);
1162 PyObject_Del((PyObject
*)self
);
1165 static PyMethodDef profiler_methods
[] = {
1166 {"addinfo", (PyCFunction
)profiler_addinfo
, METH_VARARGS
, addinfo__doc__
},
1167 {"close", (PyCFunction
)profiler_close
, METH_NOARGS
, close__doc__
},
1168 {"fileno", (PyCFunction
)profiler_fileno
, METH_NOARGS
, fileno__doc__
},
1169 {"runcall", (PyCFunction
)profiler_runcall
, METH_VARARGS
, runcall__doc__
},
1170 {"runcode", (PyCFunction
)profiler_runcode
, METH_VARARGS
, runcode__doc__
},
1171 {"start", (PyCFunction
)profiler_start
, METH_NOARGS
, start__doc__
},
1172 {"stop", (PyCFunction
)profiler_stop
, METH_NOARGS
, stop__doc__
},
1176 static PyMemberDef profiler_members
[] = {
1177 {"frametimings", T_LONG
, offsetof(ProfilerObject
, linetimings
), READONLY
},
1178 {"lineevents", T_LONG
, offsetof(ProfilerObject
, lineevents
), READONLY
},
1179 {"linetimings", T_LONG
, offsetof(ProfilerObject
, linetimings
), READONLY
},
1184 profiler_get_closed(ProfilerObject
*self
, void *closure
)
1186 PyObject
*result
= (self
->logfp
== NULL
) ? Py_True
: Py_False
;
1191 static PyGetSetDef profiler_getsets
[] = {
1192 {"closed", (getter
)profiler_get_closed
, NULL
,
1193 PyDoc_STR("True if the profiler's output file has already been closed.")},
1198 PyDoc_STRVAR(profiler_object__doc__
,
1199 "High-performance profiler object.\n"
1203 "close(): Stop the profiler and close the log files.\n"
1204 "fileno(): Returns the file descriptor of the log file.\n"
1205 "runcall(): Run a single function call with profiling enabled.\n"
1206 "runcode(): Execute a code object with profiling enabled.\n"
1207 "start(): Install the profiler and return.\n"
1208 "stop(): Remove the profiler.\n"
1210 "Attributes (read-only):\n"
1212 "closed: True if the profiler has already been closed.\n"
1213 "frametimings: True if ENTER/EXIT events collect timing information.\n"
1214 "lineevents: True if line events are reported to the profiler.\n"
1215 "linetimings: True if line events collect timing information.");
1217 static PyTypeObject ProfilerType
= {
1218 PyObject_HEAD_INIT(NULL
)
1220 "_hotshot.ProfilerType", /* tp_name */
1221 (int) sizeof(ProfilerObject
), /* tp_basicsize */
1222 0, /* tp_itemsize */
1223 (destructor
)profiler_dealloc
, /* tp_dealloc */
1229 0, /* tp_as_number */
1230 0, /* tp_as_sequence */
1231 0, /* tp_as_mapping */
1235 PyObject_GenericGetAttr
, /* tp_getattro */
1236 0, /* tp_setattro */
1237 0, /* tp_as_buffer */
1238 Py_TPFLAGS_DEFAULT
, /* tp_flags */
1239 profiler_object__doc__
, /* tp_doc */
1240 0, /* tp_traverse */
1242 0, /* tp_richcompare */
1243 0, /* tp_weaklistoffset */
1245 0, /* tp_iternext */
1246 profiler_methods
, /* tp_methods */
1247 profiler_members
, /* tp_members */
1248 profiler_getsets
, /* tp_getset */
1251 0, /* tp_descr_get */
1252 0, /* tp_descr_set */
1256 static PyMethodDef logreader_methods
[] = {
1257 {"close", (PyCFunction
)logreader_close
, METH_NOARGS
,
1258 logreader_close__doc__
},
1259 {"fileno", (PyCFunction
)logreader_fileno
, METH_NOARGS
,
1260 logreader_fileno__doc__
},
1264 static PyMemberDef logreader_members
[] = {
1265 {"info", T_OBJECT
, offsetof(LogReaderObject
, info
), RO
,
1266 PyDoc_STR("Dictionary mapping informational keys to lists of values.")},
1271 PyDoc_STRVAR(logreader__doc__
,
1272 "logreader(filename) --> log-iterator\n\
1273 Create a log-reader for the timing information file.");
1275 static PySequenceMethods logreader_as_sequence
= {
1279 (ssizeargfunc
)logreader_sq_item
, /* sq_item */
1281 0, /* sq_ass_item */
1282 0, /* sq_ass_slice */
1283 0, /* sq_contains */
1284 0, /* sq_inplace_concat */
1285 0, /* sq_inplace_repeat */
1289 logreader_get_closed(LogReaderObject
*self
, void *closure
)
1291 PyObject
*result
= (self
->logfp
== NULL
) ? Py_True
: Py_False
;
1296 static PyGetSetDef logreader_getsets
[] = {
1297 {"closed", (getter
)logreader_get_closed
, NULL
,
1298 PyDoc_STR("True if the logreader's input file has already been closed.")},
1302 static PyTypeObject LogReaderType
= {
1303 PyObject_HEAD_INIT(NULL
)
1305 "_hotshot.LogReaderType", /* tp_name */
1306 (int) sizeof(LogReaderObject
), /* tp_basicsize */
1307 0, /* tp_itemsize */
1308 (destructor
)logreader_dealloc
, /* tp_dealloc */
1314 0, /* tp_as_number */
1315 &logreader_as_sequence
, /* tp_as_sequence */
1316 0, /* tp_as_mapping */
1320 PyObject_GenericGetAttr
, /* tp_getattro */
1321 0, /* tp_setattro */
1322 0, /* tp_as_buffer */
1323 Py_TPFLAGS_DEFAULT
, /* tp_flags */
1324 logreader__doc__
, /* tp_doc */
1325 0, /* tp_traverse */
1327 0, /* tp_richcompare */
1328 0, /* tp_weaklistoffset */
1329 PyObject_SelfIter
, /* tp_iter */
1330 (iternextfunc
)logreader_tp_iternext
,/* tp_iternext */
1331 logreader_methods
, /* tp_methods */
1332 logreader_members
, /* tp_members */
1333 logreader_getsets
, /* tp_getset */
1336 0, /* tp_descr_get */
1337 0, /* tp_descr_set */
1341 hotshot_logreader(PyObject
*unused
, PyObject
*args
)
1343 LogReaderObject
*self
= NULL
;
1348 if (PyArg_ParseTuple(args
, "s:logreader", &filename
)) {
1349 self
= PyObject_New(LogReaderObject
, &LogReaderType
);
1351 self
->frametimings
= 1;
1352 self
->linetimings
= 0;
1354 self
->logfp
= fopen(filename
, "rb");
1355 if (self
->logfp
== NULL
) {
1356 PyErr_SetFromErrnoWithFilename(PyExc_IOError
, filename
);
1361 self
->info
= PyDict_New();
1362 if (self
->info
== NULL
) {
1366 /* read initial info */
1368 if ((c
= fgetc(self
->logfp
)) == EOF
) {
1372 if (c
!= WHAT_ADD_INFO
) {
1373 ungetc(c
, self
->logfp
);
1376 err
= unpack_add_info(self
);
1381 PyErr_SetString(PyExc_RuntimeError
,
1382 "unexpected error");
1389 return (PyObject
*) self
;
1393 /* Return a Python string that represents the version number without the
1394 * extra cruft added by revision control, even if the right options were
1395 * given to the "cvs export" command to make it not include the extra
1399 get_version_string(void)
1401 static char *rcsid
= "$Revision$";
1406 while (*rev
&& !isdigit(Py_CHARMASK(*rev
)))
1408 while (rev
[i
] != ' ' && rev
[i
] != '\0')
1410 buffer
= (char *)malloc(i
+ 1);
1411 if (buffer
!= NULL
) {
1412 memmove(buffer
, rev
, i
);
1418 /* Write out a RFC 822-style header with various useful bits of
1419 * information to make the output easier to manage.
1422 write_header(ProfilerObject
*self
)
1425 char cwdbuffer
[PATH_MAX
];
1429 buffer
= get_version_string();
1430 if (buffer
== NULL
) {
1434 pack_add_info(self
, "hotshot-version", buffer
);
1435 pack_add_info(self
, "requested-frame-timings",
1436 (self
->frametimings
? "yes" : "no"));
1437 pack_add_info(self
, "requested-line-events",
1438 (self
->lineevents
? "yes" : "no"));
1439 pack_add_info(self
, "requested-line-timings",
1440 (self
->linetimings
? "yes" : "no"));
1441 pack_add_info(self
, "platform", Py_GetPlatform());
1442 pack_add_info(self
, "executable", Py_GetProgramFullPath());
1444 buffer
= (char *) Py_GetVersion();
1448 pack_add_info(self
, "executable-version", buffer
);
1451 PyOS_snprintf(cwdbuffer
, sizeof(cwdbuffer
), "%I64d", frequency
.QuadPart
);
1452 pack_add_info(self
, "reported-performance-frequency", cwdbuffer
);
1454 PyOS_snprintf(cwdbuffer
, sizeof(cwdbuffer
), "%lu", rusage_diff
);
1455 pack_add_info(self
, "observed-interval-getrusage", cwdbuffer
);
1456 PyOS_snprintf(cwdbuffer
, sizeof(cwdbuffer
), "%lu", timeofday_diff
);
1457 pack_add_info(self
, "observed-interval-gettimeofday", cwdbuffer
);
1460 pack_add_info(self
, "current-directory",
1461 getcwd(cwdbuffer
, sizeof cwdbuffer
));
1463 temp
= PySys_GetObject("path");
1464 if (temp
== NULL
|| !PyList_Check(temp
)) {
1465 PyErr_SetString(PyExc_RuntimeError
, "sys.path must be a list");
1468 len
= PyList_GET_SIZE(temp
);
1469 for (i
= 0; i
< len
; ++i
) {
1470 PyObject
*item
= PyList_GET_ITEM(temp
, i
);
1471 buffer
= PyString_AsString(item
);
1472 if (buffer
== NULL
) {
1473 pack_add_info(self
, "sys-path-entry", "<non-string-path-entry>");
1477 pack_add_info(self
, "sys-path-entry", buffer
);
1480 pack_frame_times(self
);
1481 pack_line_times(self
);
1486 PyDoc_STRVAR(profiler__doc__
,
1487 "profiler(logfilename[, lineevents[, linetimes]]) -> profiler\n\
1488 Create a new profiler object.");
1491 hotshot_profiler(PyObject
*unused
, PyObject
*args
)
1494 ProfilerObject
*self
= NULL
;
1496 int linetimings
= 1;
1498 if (PyArg_ParseTuple(args
, "s|ii:profiler", &logfilename
,
1499 &lineevents
, &linetimings
)) {
1500 self
= PyObject_New(ProfilerObject
, &ProfilerType
);
1503 self
->frametimings
= 1;
1504 self
->lineevents
= lineevents
? 1 : 0;
1505 self
->linetimings
= (lineevents
&& linetimings
) ? 1 : 0;
1508 self
->next_fileno
= 0;
1510 self
->logfilename
= PyTuple_GET_ITEM(args
, 0);
1511 Py_INCREF(self
->logfilename
);
1512 self
->filemap
= PyDict_New();
1513 if (self
->filemap
== NULL
) {
1517 self
->logfp
= fopen(logfilename
, "wb");
1518 if (self
->logfp
== NULL
) {
1520 PyErr_SetFromErrnoWithFilename(PyExc_IOError
, logfilename
);
1523 if (timeofday_diff
== 0) {
1524 /* Run this several times since sometimes the first
1525 * doesn't give the lowest values, and we're really trying
1526 * to determine the lowest.
1532 if (write_header(self
)) {
1533 /* some error occurred, exception has been set */
1538 return (PyObject
*) self
;
1541 PyDoc_STRVAR(coverage__doc__
,
1542 "coverage(logfilename) -> profiler\n\
1543 Returns a profiler that doesn't collect any timing information, which is\n\
1544 useful in building a coverage analysis tool.");
1547 hotshot_coverage(PyObject
*unused
, PyObject
*args
)
1550 PyObject
*result
= NULL
;
1552 if (PyArg_ParseTuple(args
, "s:coverage", &logfilename
)) {
1553 result
= hotshot_profiler(unused
, args
);
1554 if (result
!= NULL
) {
1555 ProfilerObject
*self
= (ProfilerObject
*) result
;
1556 self
->frametimings
= 0;
1557 self
->linetimings
= 0;
1558 self
->lineevents
= 1;
1564 PyDoc_VAR(resolution__doc__
) =
1567 "resolution() -> (performance-counter-ticks, update-frequency)\n"
1568 "Return the resolution of the timer provided by the QueryPerformanceCounter()\n"
1569 "function. The first value is the smallest observed change, and the second\n"
1570 "is the result of QueryPerformanceFrequency()."
1574 "resolution() -> (gettimeofday-usecs, getrusage-usecs)\n"
1575 "Return the resolution of the timers provided by the gettimeofday() and\n"
1576 "getrusage() system calls, or -1 if the call is not supported."
1582 hotshot_resolution(PyObject
*self
, PyObject
*unused
)
1584 if (timeofday_diff
== 0) {
1590 return Py_BuildValue("ii", timeofday_diff
, frequency
.LowPart
);
1592 return Py_BuildValue("ii", timeofday_diff
, rusage_diff
);
1597 static PyMethodDef functions
[] = {
1598 {"coverage", hotshot_coverage
, METH_VARARGS
, coverage__doc__
},
1599 {"profiler", hotshot_profiler
, METH_VARARGS
, profiler__doc__
},
1600 {"logreader", hotshot_logreader
, METH_VARARGS
, logreader__doc__
},
1601 {"resolution", hotshot_resolution
, METH_NOARGS
, resolution__doc__
},
1611 LogReaderType
.ob_type
= &PyType_Type
;
1612 ProfilerType
.ob_type
= &PyType_Type
;
1613 module
= Py_InitModule("_hotshot", functions
);
1614 if (module
!= NULL
) {
1615 char *s
= get_version_string();
1617 PyModule_AddStringConstant(module
, "__version__", s
);
1619 Py_INCREF(&LogReaderType
);
1620 PyModule_AddObject(module
, "LogReaderType",
1621 (PyObject
*)&LogReaderType
);
1622 Py_INCREF(&ProfilerType
);
1623 PyModule_AddObject(module
, "ProfilerType",
1624 (PyObject
*)&ProfilerType
);
1626 if (ProfilerError
== NULL
)
1627 ProfilerError
= PyErr_NewException("hotshot.ProfilerError",
1629 if (ProfilerError
!= NULL
) {
1630 Py_INCREF(ProfilerError
);
1631 PyModule_AddObject(module
, "ProfilerError", ProfilerError
);
1633 PyModule_AddIntConstant(module
, "WHAT_ENTER", WHAT_ENTER
);
1634 PyModule_AddIntConstant(module
, "WHAT_EXIT", WHAT_EXIT
);
1635 PyModule_AddIntConstant(module
, "WHAT_LINENO", WHAT_LINENO
);
1636 PyModule_AddIntConstant(module
, "WHAT_OTHER", WHAT_OTHER
);
1637 PyModule_AddIntConstant(module
, "WHAT_ADD_INFO", WHAT_ADD_INFO
);
1638 PyModule_AddIntConstant(module
, "WHAT_DEFINE_FILE", WHAT_DEFINE_FILE
);
1639 PyModule_AddIntConstant(module
, "WHAT_DEFINE_FUNC", WHAT_DEFINE_FUNC
);
1640 PyModule_AddIntConstant(module
, "WHAT_LINE_TIMES", WHAT_LINE_TIMES
);