1 /*
2  * This is the High Performance Python Profiler portion of HotShot.
3  */
4 
5 #include "Python.h"
6 #include "code.h"
7 #include "eval.h"
8 #include "frameobject.h"
9 #include "structmember.h"
10 
11 /*
12  * Which timer to use should be made more configurable, but that should not
13  * be difficult.  This will do for now.
14  */
15 #ifdef MS_WINDOWS
16 #include <windows.h>
17 
18 #ifdef HAVE_DIRECT_H
19 #include <direct.h>    /* for getcwd() */
20 #endif
21 
22 typedef __int64 hs_time;
23 #define GETTIMEOFDAY(P_HS_TIME) \
24         { LARGE_INTEGER _temp; \
25           QueryPerformanceCounter(&_temp); \
26           *(P_HS_TIME) = _temp.QuadPart; }
27 
28 
29 #else
30 #ifndef HAVE_GETTIMEOFDAY
31 #error "This module requires gettimeofday() on non-Windows platforms!"
32 #endif
33 #if (defined(PYOS_OS2) && defined(PYCC_GCC)) || defined(__QNX__)
34 #include <sys/time.h>
35 #else
36 #include <sys/resource.h>
37 #include <sys/times.h>
38 #endif
39 typedef struct timeval hs_time;
40 #endif
41 
42 #if !defined(__cplusplus) && !defined(inline)
43 #ifdef __GNUC__
44 #define inline __inline
45 #endif
46 #endif
47 
48 #ifndef inline
49 #define inline
50 #endif
51 
52 #define BUFFERSIZE 10240
53 
54 #if defined(PYOS_OS2) && defined(PYCC_GCC)
55 #define PATH_MAX 260
56 #endif
57 
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) */
61 #define PATH_MAX 1024
62 #endif
63 
64 #ifndef PATH_MAX
65 #   ifdef MAX_PATH
66 #       define PATH_MAX MAX_PATH
67 #   elif defined (_POSIX_PATH_MAX)
68 #       define PATH_MAX _POSIX_PATH_MAX
69 #   else
70 #       error "Need a defn. for PATH_MAX in _hotshot.c"
71 #   endif
72 #endif
73 
74 typedef struct {
75     PyObject_HEAD
76     PyObject *filemap;
77     PyObject *logfilename;
78     Py_ssize_t index;
79     unsigned char buffer[BUFFERSIZE];
80     FILE *logfp;
81     int lineevents;
82     int linetimings;
83     int frametimings;
84     /* size_t filled; */
85     int active;
86     int next_fileno;
87     hs_time prev_timeofday;
88 } ProfilerObject;
89 
90 typedef struct {
91     PyObject_HEAD
92     PyObject *info;
93     FILE *logfp;
94     int linetimings;
95     int frametimings;
96 } LogReaderObject;
97 
98 static PyObject * ProfilerError = NULL;
99 
100 
101 #ifndef MS_WINDOWS
102 #ifdef GETTIMEOFDAY_NO_TZ
103 #define GETTIMEOFDAY(ptv) gettimeofday((ptv))
104 #else
105 #define GETTIMEOFDAY(ptv) gettimeofday((ptv), (struct timezone *)NULL)
106 #endif
107 #endif
108 
109 
110 /* The log reader... */
111 
112 PyDoc_STRVAR(logreader_close__doc__,
113 "close()\n"
114 "Close the log file, preventing additional records from being read.");
115 
116 static PyObject *
logreader_close(LogReaderObject * self,PyObject * args)117 logreader_close(LogReaderObject *self, PyObject *args)
118 {
119     if (self->logfp != NULL) {
120         fclose(self->logfp);
121         self->logfp = NULL;
122     }
123     Py_INCREF(Py_None);
124 
125     return Py_None;
126 }
127 
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.");
132 
133 static PyObject *
logreader_fileno(LogReaderObject * self)134 logreader_fileno(LogReaderObject *self)
135 {
136     if (self->logfp == NULL) {
137         PyErr_SetString(PyExc_ValueError,
138                         "logreader's file object already closed");
139         return NULL;
140     }
141     return PyInt_FromLong(fileno(self->logfp));
142 }
143 
144 
145 /* Log File Format
146  * ---------------
147  *
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"
151  * bits of the byte.
152  *
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
158  *
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.
164  *
165  * The OTHER records have the following identifiers:
166  *
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
173  *
174  * Packed Integers
175  *
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.
182  *
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.
189  *
190  * ENTER records:
191  *
192  *      MPI(2,type)  fileno          -- type is 0x00
193  *      PI           lineno
194  *      PI           tdelta          -- iff frame times are enabled
195  *
196  * EXIT records
197  *
198  *      MPI(2,type)  tdelta          -- type is 0x01; tdelta will be 0
199  *                                      if frame times are disabled
200  *
201  * LINENO records
202  *
203  *      MPI(2,type)  lineno          -- type is 0x02
204  *      PI           tdelta          -- iff LINENO includes it
205  *
206  * ADD_INFO records
207  *
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
213  *
214  * DEFINE_FILE records
215  *
216  *      BYTE         type            -- always 0x23
217  *      PI           fileno
218  *      PI           len             -- length of filename
219  *      BYTE         filename[len]   -- len bytes of string data
220  *
221  * DEFINE_FUNC records
222  *
223  *      BYTE         type            -- always 0x43
224  *      PI           fileno
225  *      PI           lineno
226  *      PI           len             -- length of funcname
227  *      BYTE         funcname[len]   -- len bytes of string data
228  *
229  * LINE_TIMES records
230  *
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.
235  *
236  *      BYTE         type            -- always 0x33
237  *      BYTE         have_tdelta     -- 0 if LINENO does *not* have
238  *                                      timing information
239  * FRAME_TIMES records
240  *
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
245  * field.
246  *
247  *      BYTE         type            -- always 0x53
248  *      BYTE         have_tdelta     -- 0 if ENTER/EXIT do *not* have
249  *                                      timing information
250  */
251 
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
261 
262 #define ERR_NONE          0
263 #define ERR_EOF          -1
264 #define ERR_EXCEPTION    -2
265 #define ERR_BAD_RECTYPE  -3
266 
267 #define PISIZE            (sizeof(int) + 1)
268 #define MPISIZE           (PISIZE + 1)
269 
270 /* Maximum size of "normal" events -- nothing that contains string data */
271 #define MAXEVENTSIZE      (MPISIZE + PISIZE*2)
272 
273 
274 /* Unpack a packed integer; if "discard" is non-zero, unpack a modified
275  * packed integer with "discard" discarded bits.
276  */
277 static int
unpack_packed_int(LogReaderObject * self,int * pvalue,int discard)278 unpack_packed_int(LogReaderObject *self, int *pvalue, int discard)
279 {
280     int c;
281     int accum = 0;
282     int bits = 0;
283     int cont;
284 
285     do {
286         /* read byte */
287         if ((c = fgetc(self->logfp)) == EOF)
288             return ERR_EOF;
289         accum |= ((c & 0x7F) >> discard) << bits;
290         bits += (7 - discard);
291         cont = c & 0x80;
292         discard = 0;
293     } while (cont);
294 
295     *pvalue = accum;
296 
297     return 0;
298 }
299 
300 /* Unpack a string, which is encoded as a packed integer giving the
301  * length of the string, followed by the string data.
302  */
303 static int
unpack_string(LogReaderObject * self,PyObject ** pvalue)304 unpack_string(LogReaderObject *self, PyObject **pvalue)
305 {
306     int i;
307     int len;
308     int err;
309     int ch;
310     char *buf;
311 
312     if ((err = unpack_packed_int(self, &len, 0)))
313         return err;
314 
315     buf = (char *)malloc(len);
316     if (!buf) {
317         PyErr_NoMemory();
318         return ERR_EXCEPTION;
319     }
320 
321     for (i=0; i < len; i++) {
322         ch = fgetc(self->logfp);
323         buf[i] = ch;
324         if (ch == EOF) {
325             free(buf);
326             return ERR_EOF;
327         }
328     }
329     *pvalue = PyString_FromStringAndSize(buf, len);
330     free(buf);
331     if (*pvalue == NULL) {
332         return ERR_EXCEPTION;
333     }
334     return 0;
335 }
336 
337 
338 static int
unpack_add_info(LogReaderObject * self)339 unpack_add_info(LogReaderObject *self)
340 {
341     PyObject *key;
342     PyObject *value = NULL;
343     int err;
344 
345     err = unpack_string(self, &key);
346     if (!err) {
347         err = unpack_string(self, &value);
348         if (err)
349             Py_DECREF(key);
350         else {
351             PyObject *list = PyDict_GetItem(self->info, key);
352             if (list == NULL) {
353                 list = PyList_New(0);
354                 if (list == NULL) {
355                     err = ERR_EXCEPTION;
356                     goto finally;
357                 }
358                 if (PyDict_SetItem(self->info, key, list)) {
359                     Py_DECREF(list);
360                     err = ERR_EXCEPTION;
361                     goto finally;
362                 }
363                 Py_DECREF(list);
364             }
365             if (PyList_Append(list, value))
366                 err = ERR_EXCEPTION;
367         }
368     }
369  finally:
370     Py_XDECREF(key);
371     Py_XDECREF(value);
372     return err;
373 }
374 
375 
376 static void
eof_error(LogReaderObject * self)377 eof_error(LogReaderObject *self)
378 {
379     fclose(self->logfp);
380     self->logfp = NULL;
381     PyErr_SetString(PyExc_EOFError,
382                     "end of file with incomplete profile record");
383 }
384 
385 static PyObject *
logreader_tp_iternext(LogReaderObject * self)386 logreader_tp_iternext(LogReaderObject *self)
387 {
388     int c;
389     int what;
390     int err = ERR_NONE;
391     int lineno = -1;
392     int fileno = -1;
393     int tdelta = -1;
394     PyObject *s1 = NULL, *s2 = NULL;
395     PyObject *result = NULL;
396 #if 0
397     unsigned char b0, b1;
398 #endif
399 
400     if (self->logfp == NULL) {
401         PyErr_SetString(ProfilerError,
402                         "cannot iterate over closed LogReader object");
403         return NULL;
404     }
405 
406 restart:
407     /* decode the record type */
408     if ((c = fgetc(self->logfp)) == EOF) {
409         fclose(self->logfp);
410         self->logfp = NULL;
411         return NULL;
412     }
413     what = c & WHAT_OTHER;
414     if (what == WHAT_OTHER)
415         what = c; /* need all the bits for type */
416     else
417         ungetc(c, self->logfp); /* type byte includes packed int */
418 
419     switch (what) {
420     case WHAT_ENTER:
421         err = unpack_packed_int(self, &fileno, 2);
422         if (!err) {
423             err = unpack_packed_int(self, &lineno, 0);
424             if (self->frametimings && !err)
425                 err = unpack_packed_int(self, &tdelta, 0);
426         }
427         break;
428     case WHAT_EXIT:
429         err = unpack_packed_int(self, &tdelta, 2);
430         break;
431     case WHAT_LINENO:
432         err = unpack_packed_int(self, &lineno, 2);
433         if (self->linetimings && !err)
434             err = unpack_packed_int(self, &tdelta, 0);
435         break;
436     case WHAT_ADD_INFO:
437         err = unpack_add_info(self);
438         break;
439     case WHAT_DEFINE_FILE:
440         err = unpack_packed_int(self, &fileno, 0);
441         if (!err) {
442             err = unpack_string(self, &s1);
443             if (!err) {
444                 Py_INCREF(Py_None);
445                 s2 = Py_None;
446             }
447         }
448         break;
449     case WHAT_DEFINE_FUNC:
450         err = unpack_packed_int(self, &fileno, 0);
451         if (!err) {
452             err = unpack_packed_int(self, &lineno, 0);
453             if (!err)
454                 err = unpack_string(self, &s1);
455         }
456         break;
457     case WHAT_LINE_TIMES:
458         if ((c = fgetc(self->logfp)) == EOF)
459             err = ERR_EOF;
460         else {
461             self->linetimings = c ? 1 : 0;
462             goto restart;
463         }
464         break;
465     case WHAT_FRAME_TIMES:
466         if ((c = fgetc(self->logfp)) == EOF)
467             err = ERR_EOF;
468         else {
469             self->frametimings = c ? 1 : 0;
470             goto restart;
471         }
472         break;
473     default:
474         err = ERR_BAD_RECTYPE;
475     }
476     if (err == ERR_BAD_RECTYPE) {
477         PyErr_SetString(PyExc_ValueError,
478                         "unknown record type in log file");
479     }
480     else if (err == ERR_EOF) {
481         eof_error(self);
482     }
483     else if (!err) {
484         result = PyTuple_New(4);
485         if (result == NULL)
486             return NULL;
487         PyTuple_SET_ITEM(result, 0, PyInt_FromLong(what));
488         PyTuple_SET_ITEM(result, 2, PyInt_FromLong(fileno));
489         if (s1 == NULL)
490             PyTuple_SET_ITEM(result, 1, PyInt_FromLong(tdelta));
491         else
492             PyTuple_SET_ITEM(result, 1, s1);
493         if (s2 == NULL)
494             PyTuple_SET_ITEM(result, 3, PyInt_FromLong(lineno));
495         else
496             PyTuple_SET_ITEM(result, 3, s2);
497     }
498     /* The only other case is err == ERR_EXCEPTION, in which case the
499      * exception is already set.
500      */
501 #if 0
502     b0 = self->buffer[self->index];
503     b1 = self->buffer[self->index + 1];
504     if (b0 & 1) {
505         /* This is a line-number event. */
506         what = PyTrace_LINE;
507         lineno = ((b0 & ~1) << 7) + b1;
508         self->index += 2;
509     }
510     else {
511         what = (b0 & 0x0E) >> 1;
512         tdelta = ((b0 & 0xF0) << 4) + b1;
513         if (what == PyTrace_CALL) {
514             /* we know there's a 2-byte file ID & 2-byte line number */
515             fileno = ((self->buffer[self->index + 2] << 8)
516                       + self->buffer[self->index + 3]);
517             lineno = ((self->buffer[self->index + 4] << 8)
518                       + self->buffer[self->index + 5]);
519             self->index += 6;
520         }
521         else
522             self->index += 2;
523     }
524 #endif
525     return result;
526 }
527 
528 static void
logreader_dealloc(LogReaderObject * self)529 logreader_dealloc(LogReaderObject *self)
530 {
531     if (self->logfp != NULL) {
532         fclose(self->logfp);
533         self->logfp = NULL;
534     }
535     Py_XDECREF(self->info);
536     PyObject_Del(self);
537 }
538 
539 static PyObject *
logreader_sq_item(LogReaderObject * self,Py_ssize_t index)540 logreader_sq_item(LogReaderObject *self, Py_ssize_t index)
541 {
542     PyObject *result = logreader_tp_iternext(self);
543     if (result == NULL && !PyErr_Occurred()) {
544         PyErr_SetString(PyExc_IndexError, "no more events in log");
545         return NULL;
546     }
547     return result;
548 }
549 
550 static void
551 do_stop(ProfilerObject *self);
552 
553 static int
flush_data(ProfilerObject * self)554 flush_data(ProfilerObject *self)
555 {
556     /* Need to dump data to the log file... */
557     size_t written = fwrite(self->buffer, 1, self->index, self->logfp);
558     if (written == (size_t)self->index)
559         self->index = 0;
560     else {
561         memmove(self->buffer, &self->buffer[written],
562                 self->index - written);
563         self->index -= written;
564         if (written == 0) {
565             char *s = PyString_AsString(self->logfilename);
566             PyErr_SetFromErrnoWithFilename(PyExc_IOError, s);
567             do_stop(self);
568             return -1;
569         }
570     }
571     if (written > 0) {
572         if (fflush(self->logfp)) {
573             char *s = PyString_AsString(self->logfilename);
574             PyErr_SetFromErrnoWithFilename(PyExc_IOError, s);
575             do_stop(self);
576             return -1;
577         }
578     }
579     return 0;
580 }
581 
582 static inline int
pack_packed_int(ProfilerObject * self,int value)583 pack_packed_int(ProfilerObject *self, int value)
584 {
585     unsigned char partial;
586 
587     do {
588         partial = value & 0x7F;
589         value >>= 7;
590         if (value)
591             partial |= 0x80;
592         self->buffer[self->index] = partial;
593         self->index++;
594     } while (value);
595     return 0;
596 }
597 
598 /* Encode a modified packed integer, with a subfield of modsize bits
599  * containing the value "subfield".  The value of subfield is not
600  * checked to ensure it actually fits in modsize bits.
601  */
602 static inline int
pack_modified_packed_int(ProfilerObject * self,int value,int modsize,int subfield)603 pack_modified_packed_int(ProfilerObject *self, int value,
604                          int modsize, int subfield)
605 {
606     const int maxvalues[] = {-1, 1, 3, 7, 15, 31, 63, 127};
607 
608     int bits = 7 - modsize;
609     int partial = value & maxvalues[bits];
610     unsigned char b = subfield | (partial << modsize);
611 
612     if (partial != value) {
613         b |= 0x80;
614         self->buffer[self->index] = b;
615         self->index++;
616         return pack_packed_int(self, value >> bits);
617     }
618     self->buffer[self->index] = b;
619     self->index++;
620     return 0;
621 }
622 
623 static int
pack_string(ProfilerObject * self,const char * s,Py_ssize_t len)624 pack_string(ProfilerObject *self, const char *s, Py_ssize_t len)
625 {
626     if (len + PISIZE + self->index >= BUFFERSIZE) {
627         if (flush_data(self) < 0)
628             return -1;
629     }
630     assert(len < INT_MAX);
631     if (pack_packed_int(self, (int)len) < 0)
632         return -1;
633     memcpy(self->buffer + self->index, s, len);
634     self->index += len;
635     return 0;
636 }
637 
638 static int
pack_add_info(ProfilerObject * self,const char * s1,const char * s2)639 pack_add_info(ProfilerObject *self, const char *s1, const char *s2)
640 {
641     Py_ssize_t len1 = strlen(s1);
642     Py_ssize_t len2 = strlen(s2);
643 
644     if (len1 + len2 + PISIZE*2 + 1 + self->index >= BUFFERSIZE) {
645         if (flush_data(self) < 0)
646             return -1;
647     }
648     self->buffer[self->index] = WHAT_ADD_INFO;
649     self->index++;
650     if (pack_string(self, s1, len1) < 0)
651         return -1;
652     return pack_string(self, s2, len2);
653 }
654 
655 static int
pack_define_file(ProfilerObject * self,int fileno,const char * filename)656 pack_define_file(ProfilerObject *self, int fileno, const char *filename)
657 {
658     Py_ssize_t len = strlen(filename);
659 
660     if (len + PISIZE*2 + 1 + self->index >= BUFFERSIZE) {
661         if (flush_data(self) < 0)
662             return -1;
663     }
664     self->buffer[self->index] = WHAT_DEFINE_FILE;
665     self->index++;
666     if (pack_packed_int(self, fileno) < 0)
667         return -1;
668     return pack_string(self, filename, len);
669 }
670 
671 static int
pack_define_func(ProfilerObject * self,int fileno,int lineno,const char * funcname)672 pack_define_func(ProfilerObject *self, int fileno, int lineno,
673                  const char *funcname)
674 {
675     Py_ssize_t len = strlen(funcname);
676 
677     if (len + PISIZE*3 + 1 + self->index >= BUFFERSIZE) {
678         if (flush_data(self) < 0)
679             return -1;
680     }
681     self->buffer[self->index] = WHAT_DEFINE_FUNC;
682     self->index++;
683     if (pack_packed_int(self, fileno) < 0)
684         return -1;
685     if (pack_packed_int(self, lineno) < 0)
686         return -1;
687     return pack_string(self, funcname, len);
688 }
689 
690 static int
pack_line_times(ProfilerObject * self)691 pack_line_times(ProfilerObject *self)
692 {
693     if (2 + self->index >= BUFFERSIZE) {
694         if (flush_data(self) < 0)
695             return -1;
696     }
697     self->buffer[self->index] = WHAT_LINE_TIMES;
698     self->buffer[self->index + 1] = self->linetimings ? 1 : 0;
699     self->index += 2;
700     return 0;
701 }
702 
703 static int
pack_frame_times(ProfilerObject * self)704 pack_frame_times(ProfilerObject *self)
705 {
706     if (2 + self->index >= BUFFERSIZE) {
707         if (flush_data(self) < 0)
708             return -1;
709     }
710     self->buffer[self->index] = WHAT_FRAME_TIMES;
711     self->buffer[self->index + 1] = self->frametimings ? 1 : 0;
712     self->index += 2;
713     return 0;
714 }
715 
716 static inline int
pack_enter(ProfilerObject * self,int fileno,int tdelta,int lineno)717 pack_enter(ProfilerObject *self, int fileno, int tdelta, int lineno)
718 {
719     if (MPISIZE + PISIZE*2 + self->index >= BUFFERSIZE) {
720         if (flush_data(self) < 0)
721             return -1;
722     }
723     pack_modified_packed_int(self, fileno, 2, WHAT_ENTER);
724     pack_packed_int(self, lineno);
725     if (self->frametimings)
726         return pack_packed_int(self, tdelta);
727     else
728         return 0;
729 }
730 
731 static inline int
pack_exit(ProfilerObject * self,int tdelta)732 pack_exit(ProfilerObject *self, int tdelta)
733 {
734     if (MPISIZE + self->index >= BUFFERSIZE) {
735         if (flush_data(self) < 0)
736             return -1;
737     }
738     if (self->frametimings)
739         return pack_modified_packed_int(self, tdelta, 2, WHAT_EXIT);
740     self->buffer[self->index] = WHAT_EXIT;
741     self->index++;
742     return 0;
743 }
744 
745 static inline int
pack_lineno(ProfilerObject * self,int lineno)746 pack_lineno(ProfilerObject *self, int lineno)
747 {
748     if (MPISIZE + self->index >= BUFFERSIZE) {
749         if (flush_data(self) < 0)
750             return -1;
751     }
752     return pack_modified_packed_int(self, lineno, 2, WHAT_LINENO);
753 }
754 
755 static inline int
pack_lineno_tdelta(ProfilerObject * self,int lineno,int tdelta)756 pack_lineno_tdelta(ProfilerObject *self, int lineno, int tdelta)
757 {
758     if (MPISIZE + PISIZE + self->index >= BUFFERSIZE) {
759         if (flush_data(self) < 0)
760             return 0;
761     }
762     if (pack_modified_packed_int(self, lineno, 2, WHAT_LINENO) < 0)
763         return -1;
764     return pack_packed_int(self, tdelta);
765 }
766 
767 static inline int
get_fileno(ProfilerObject * self,PyCodeObject * fcode)768 get_fileno(ProfilerObject *self, PyCodeObject *fcode)
769 {
770     /* This is only used for ENTER events. */
771 
772     PyObject *obj;
773     PyObject *dict;
774     int fileno;
775 
776     obj = PyDict_GetItem(self->filemap, fcode->co_filename);
777     if (obj == NULL) {
778         /* first sighting of this file */
779         dict = PyDict_New();
780         if (dict == NULL) {
781             return -1;
782         }
783         fileno = self->next_fileno;
784         obj = Py_BuildValue("iN", fileno, dict);
785         if (obj == NULL) {
786             return -1;
787         }
788         if (PyDict_SetItem(self->filemap, fcode->co_filename, obj)) {
789             Py_DECREF(obj);
790             return -1;
791         }
792         self->next_fileno++;
793         Py_DECREF(obj);
794         if (pack_define_file(self, fileno,
795                              PyString_AS_STRING(fcode->co_filename)) < 0)
796             return -1;
797     }
798     else {
799         /* already know this ID */
800         fileno = PyInt_AS_LONG(PyTuple_GET_ITEM(obj, 0));
801         dict = PyTuple_GET_ITEM(obj, 1);
802     }
803     /* make sure we save a function name for this (fileno, lineno) */
804     obj = PyInt_FromLong(fcode->co_firstlineno);
805     if (obj == NULL) {
806         /* We just won't have it saved; too bad. */
807         PyErr_Clear();
808     }
809     else {
810         PyObject *name = PyDict_GetItem(dict, obj);
811         if (name == NULL) {
812             if (pack_define_func(self, fileno, fcode->co_firstlineno,
813                                  PyString_AS_STRING(fcode->co_name)) < 0) {
814                 Py_DECREF(obj);
815                 return -1;
816             }
817             if (PyDict_SetItem(dict, obj, fcode->co_name)) {
818                 Py_DECREF(obj);
819                 return -1;
820             }
821         }
822         Py_DECREF(obj);
823     }
824     return fileno;
825 }
826 
827 static inline int
get_tdelta(ProfilerObject * self)828 get_tdelta(ProfilerObject *self)
829 {
830     int tdelta;
831 #ifdef MS_WINDOWS
832     hs_time tv;
833     hs_time diff;
834 
835     GETTIMEOFDAY(&tv);
836     diff = tv - self->prev_timeofday;
837     tdelta = (int)diff;
838 #else
839     struct timeval tv;
840 
841     GETTIMEOFDAY(&tv);
842 
843     tdelta = tv.tv_usec - self->prev_timeofday.tv_usec;
844     if (tv.tv_sec != self->prev_timeofday.tv_sec)
845         tdelta += (tv.tv_sec - self->prev_timeofday.tv_sec) * 1000000;
846 #endif
847     /* time can go backwards on some multiprocessor systems or by NTP */
848     if (tdelta < 0)
849         return 0;
850 
851     self->prev_timeofday = tv;
852     return tdelta;
853 }
854 
855 
856 /* The workhorse:  the profiler callback function. */
857 
858 static int
tracer_callback(ProfilerObject * self,PyFrameObject * frame,int what,PyObject * arg)859 tracer_callback(ProfilerObject *self, PyFrameObject *frame, int what,
860                 PyObject *arg)
861 {
862     int fileno;
863 
864     switch (what) {
865     case PyTrace_CALL:
866         fileno = get_fileno(self, frame->f_code);
867         if (fileno < 0)
868             return -1;
869         return pack_enter(self, fileno,
870                           self->frametimings ? get_tdelta(self) : -1,
871                           frame->f_code->co_firstlineno);
872 
873     case PyTrace_RETURN:
874         return pack_exit(self, get_tdelta(self));
875 
876     case PyTrace_LINE:  /* we only get these events if we asked for them */
877         if (self->linetimings)
878             return pack_lineno_tdelta(self, frame->f_lineno,
879                                       get_tdelta(self));
880         else
881             return pack_lineno(self, frame->f_lineno);
882 
883     default:
884         /* ignore PyTrace_EXCEPTION */
885         break;
886     }
887     return 0;
888 }
889 
890 
891 /* A couple of useful helper functions. */
892 
893 #ifdef MS_WINDOWS
894 static LARGE_INTEGER frequency = {0, 0};
895 #endif
896 
897 static unsigned long timeofday_diff = 0;
898 static unsigned long rusage_diff = 0;
899 
900 static void
calibrate(void)901 calibrate(void)
902 {
903     hs_time tv1, tv2;
904 
905 #ifdef MS_WINDOWS
906     hs_time diff;
907     QueryPerformanceFrequency(&frequency);
908 #endif
909 
910     GETTIMEOFDAY(&tv1);
911     while (1) {
912         GETTIMEOFDAY(&tv2);
913 #ifdef MS_WINDOWS
914         diff = tv2 - tv1;
915         if (diff != 0) {
916             timeofday_diff = (unsigned long)diff;
917             break;
918         }
919 #else
920         if (tv1.tv_sec != tv2.tv_sec || tv1.tv_usec != tv2.tv_usec) {
921             if (tv1.tv_sec == tv2.tv_sec)
922                 timeofday_diff = tv2.tv_usec - tv1.tv_usec;
923             else
924                 timeofday_diff = (1000000 - tv1.tv_usec) + tv2.tv_usec;
925             break;
926         }
927 #endif
928     }
929 #if defined(MS_WINDOWS) || defined(PYOS_OS2) || \
930     defined(__VMS) || defined (__QNX__)
931     rusage_diff = -1;
932 #else
933     {
934         struct rusage ru1, ru2;
935 
936         getrusage(RUSAGE_SELF, &ru1);
937         while (1) {
938             getrusage(RUSAGE_SELF, &ru2);
939             if (ru1.ru_utime.tv_sec != ru2.ru_utime.tv_sec) {
940                 rusage_diff = ((1000000 - ru1.ru_utime.tv_usec)
941                                + ru2.ru_utime.tv_usec);
942                 break;
943             }
944             else if (ru1.ru_utime.tv_usec != ru2.ru_utime.tv_usec) {
945                 rusage_diff = ru2.ru_utime.tv_usec - ru1.ru_utime.tv_usec;
946                 break;
947             }
948             else if (ru1.ru_stime.tv_sec != ru2.ru_stime.tv_sec) {
949                 rusage_diff = ((1000000 - ru1.ru_stime.tv_usec)
950                                + ru2.ru_stime.tv_usec);
951                 break;
952             }
953             else if (ru1.ru_stime.tv_usec != ru2.ru_stime.tv_usec) {
954                 rusage_diff = ru2.ru_stime.tv_usec - ru1.ru_stime.tv_usec;
955                 break;
956             }
957         }
958     }
959 #endif
960 }
961 
962 static void
do_start(ProfilerObject * self)963 do_start(ProfilerObject *self)
964 {
965     self->active = 1;
966     GETTIMEOFDAY(&self->prev_timeofday);
967     if (self->lineevents)
968         PyEval_SetTrace((Py_tracefunc) tracer_callback, (PyObject *)self);
969     else
970         PyEval_SetProfile((Py_tracefunc) tracer_callback, (PyObject *)self);
971 }
972 
973 static void
do_stop(ProfilerObject * self)974 do_stop(ProfilerObject *self)
975 {
976     if (self->active) {
977         self->active = 0;
978         if (self->lineevents)
979             PyEval_SetTrace(NULL, NULL);
980         else
981             PyEval_SetProfile(NULL, NULL);
982     }
983     if (self->index > 0) {
984         /* Best effort to dump out any remaining data. */
985         flush_data(self);
986     }
987 }
988 
989 static int
is_available(ProfilerObject * self)990 is_available(ProfilerObject *self)
991 {
992     if (self->active) {
993         PyErr_SetString(ProfilerError, "profiler already active");
994         return 0;
995     }
996     if (self->logfp == NULL) {
997         PyErr_SetString(ProfilerError, "profiler already closed");
998         return 0;
999     }
1000     return 1;
1001 }
1002 
1003 
1004 /* Profiler object interface methods. */
1005 
1006 PyDoc_STRVAR(addinfo__doc__,
1007 "addinfo(key, value)\n"
1008 "Insert an ADD_INFO record into the log.");
1009 
1010 static PyObject *
profiler_addinfo(ProfilerObject * self,PyObject * args)1011 profiler_addinfo(ProfilerObject *self, PyObject *args)
1012 {
1013     PyObject *result = NULL;
1014     char *key, *value;
1015 
1016     if (PyArg_ParseTuple(args, "ss:addinfo", &key, &value)) {
1017         if (self->logfp == NULL)
1018             PyErr_SetString(ProfilerError, "profiler already closed");
1019         else {
1020             if (pack_add_info(self, key, value) == 0) {
1021                 result = Py_None;
1022                 Py_INCREF(result);
1023             }
1024         }
1025     }
1026     return result;
1027 }
1028 
1029 PyDoc_STRVAR(close__doc__,
1030 "close()\n"
1031 "Shut down this profiler and close the log files, even if its active.");
1032 
1033 static PyObject *
profiler_close(ProfilerObject * self)1034 profiler_close(ProfilerObject *self)
1035 {
1036     do_stop(self);
1037     if (self->logfp != NULL) {
1038         fclose(self->logfp);
1039         self->logfp = NULL;
1040     }
1041     Py_INCREF(Py_None);
1042     return Py_None;
1043 }
1044 
1045 #define fileno__doc__ logreader_fileno__doc__
1046 
1047 static PyObject *
profiler_fileno(ProfilerObject * self)1048 profiler_fileno(ProfilerObject *self)
1049 {
1050     if (self->logfp == NULL) {
1051         PyErr_SetString(PyExc_ValueError,
1052                         "profiler's file object already closed");
1053         return NULL;
1054     }
1055     return PyInt_FromLong(fileno(self->logfp));
1056 }
1057 
1058 PyDoc_STRVAR(runcall__doc__,
1059 "runcall(callable[, args[, kw]]) -> callable()\n"
1060 "Profile a specific function call, returning the result of that call.");
1061 
1062 static PyObject *
profiler_runcall(ProfilerObject * self,PyObject * args)1063 profiler_runcall(ProfilerObject *self, PyObject *args)
1064 {
1065     PyObject *result = NULL;
1066     PyObject *callargs = NULL;
1067     PyObject *callkw = NULL;
1068     PyObject *callable;
1069 
1070     if (PyArg_UnpackTuple(args, "runcall", 1, 3,
1071                          &callable, &callargs, &callkw)) {
1072         if (is_available(self)) {
1073             do_start(self);
1074             result = PyEval_CallObjectWithKeywords(callable, callargs, callkw);
1075             do_stop(self);
1076         }
1077     }
1078     return result;
1079 }
1080 
1081 PyDoc_STRVAR(runcode__doc__,
1082 "runcode(code, globals[, locals])\n"
1083 "Execute a code object while collecting profile data.  If locals is\n"
1084 "omitted, globals is used for the locals as well.");
1085 
1086 static PyObject *
profiler_runcode(ProfilerObject * self,PyObject * args)1087 profiler_runcode(ProfilerObject *self, PyObject *args)
1088 {
1089     PyObject *result = NULL;
1090     PyCodeObject *code;
1091     PyObject *globals;
1092     PyObject *locals = NULL;
1093 
1094     if (PyArg_ParseTuple(args, "O!O!|O:runcode",
1095                          &PyCode_Type, &code,
1096                          &PyDict_Type, &globals,
1097                          &locals)) {
1098         if (is_available(self)) {
1099             if (locals == NULL || locals == Py_None)
1100                 locals = globals;
1101             else if (!PyDict_Check(locals)) {
1102                 PyErr_SetString(PyExc_TypeError,
1103                                 "locals must be a dictionary or None");
1104                 return NULL;
1105             }
1106             do_start(self);
1107             result = PyEval_EvalCode(code, globals, locals);
1108             do_stop(self);
1109 #if 0
1110             if (!PyErr_Occurred()) {
1111                 result = Py_None;
1112                 Py_INCREF(result);
1113             }
1114 #endif
1115         }
1116     }
1117     return result;
1118 }
1119 
1120 PyDoc_STRVAR(start__doc__,
1121 "start()\n"
1122 "Install this profiler for the current thread.");
1123 
1124 static PyObject *
profiler_start(ProfilerObject * self,PyObject * args)1125 profiler_start(ProfilerObject *self, PyObject *args)
1126 {
1127     PyObject *result = NULL;
1128 
1129     if (is_available(self)) {
1130         do_start(self);
1131         result = Py_None;
1132         Py_INCREF(result);
1133     }
1134     return result;
1135 }
1136 
1137 PyDoc_STRVAR(stop__doc__,
1138 "stop()\n"
1139 "Remove this profiler from the current thread.");
1140 
1141 static PyObject *
profiler_stop(ProfilerObject * self,PyObject * args)1142 profiler_stop(ProfilerObject *self, PyObject *args)
1143 {
1144     PyObject *result = NULL;
1145 
1146     if (!self->active)
1147         PyErr_SetString(ProfilerError, "profiler not active");
1148     else {
1149         do_stop(self);
1150         result = Py_None;
1151         Py_INCREF(result);
1152     }
1153     return result;
1154 }
1155 
1156 
1157 /* Python API support. */
1158 
1159 static void
profiler_dealloc(ProfilerObject * self)1160 profiler_dealloc(ProfilerObject *self)
1161 {
1162     do_stop(self);
1163     if (self->logfp != NULL)
1164         fclose(self->logfp);
1165     Py_XDECREF(self->filemap);
1166     Py_XDECREF(self->logfilename);
1167     PyObject_Del((PyObject *)self);
1168 }
1169 
1170 static PyMethodDef profiler_methods[] = {
1171     {"addinfo", (PyCFunction)profiler_addinfo, METH_VARARGS, addinfo__doc__},
1172     {"close",   (PyCFunction)profiler_close,   METH_NOARGS,  close__doc__},
1173     {"fileno",  (PyCFunction)profiler_fileno,  METH_NOARGS,  fileno__doc__},
1174     {"runcall", (PyCFunction)profiler_runcall, METH_VARARGS, runcall__doc__},
1175     {"runcode", (PyCFunction)profiler_runcode, METH_VARARGS, runcode__doc__},
1176     {"start",   (PyCFunction)profiler_start,   METH_NOARGS,  start__doc__},
1177     {"stop",    (PyCFunction)profiler_stop,    METH_NOARGS,  stop__doc__},
1178     {NULL, NULL}
1179 };
1180 
1181 static PyMemberDef profiler_members[] = {
1182     {"frametimings", T_LONG, offsetof(ProfilerObject, linetimings), READONLY},
1183     {"lineevents",   T_LONG, offsetof(ProfilerObject, lineevents), READONLY},
1184     {"linetimings",  T_LONG, offsetof(ProfilerObject, linetimings), READONLY},
1185     {NULL}
1186 };
1187 
1188 static PyObject *
profiler_get_closed(ProfilerObject * self,void * closure)1189 profiler_get_closed(ProfilerObject *self, void *closure)
1190 {
1191     PyObject *result = (self->logfp == NULL) ? Py_True : Py_False;
1192     Py_INCREF(result);
1193     return result;
1194 }
1195 
1196 static PyGetSetDef profiler_getsets[] = {
1197     {"closed", (getter)profiler_get_closed, NULL,
1198      PyDoc_STR("True if the profiler's output file has already been closed.")},
1199     {NULL}
1200 };
1201 
1202 
1203 PyDoc_STRVAR(profiler_object__doc__,
1204 "High-performance profiler object.\n"
1205 "\n"
1206 "Methods:\n"
1207 "\n"
1208 "close():      Stop the profiler and close the log files.\n"
1209 "fileno():     Returns the file descriptor of the log file.\n"
1210 "runcall():    Run a single function call with profiling enabled.\n"
1211 "runcode():    Execute a code object with profiling enabled.\n"
1212 "start():      Install the profiler and return.\n"
1213 "stop():       Remove the profiler.\n"
1214 "\n"
1215 "Attributes (read-only):\n"
1216 "\n"
1217 "closed:       True if the profiler has already been closed.\n"
1218 "frametimings: True if ENTER/EXIT events collect timing information.\n"
1219 "lineevents:   True if line events are reported to the profiler.\n"
1220 "linetimings:  True if line events collect timing information.");
1221 
1222 static PyTypeObject ProfilerType = {
1223     PyVarObject_HEAD_INIT(NULL, 0)
1224     "_hotshot.ProfilerType",            /* tp_name              */
1225     (int) sizeof(ProfilerObject),       /* tp_basicsize         */
1226     0,                                  /* tp_itemsize          */
1227     (destructor)profiler_dealloc,       /* tp_dealloc           */
1228     0,                                  /* tp_print             */
1229     0,                                  /* tp_getattr           */
1230     0,                                  /* tp_setattr           */
1231     0,                                  /* tp_compare           */
1232     0,                                  /* tp_repr              */
1233     0,                                  /* tp_as_number         */
1234     0,                                  /* tp_as_sequence       */
1235     0,                                  /* tp_as_mapping        */
1236     0,                                  /* tp_hash              */
1237     0,                                  /* tp_call              */
1238     0,                                  /* tp_str               */
1239     PyObject_GenericGetAttr,            /* tp_getattro          */
1240     0,                                  /* tp_setattro          */
1241     0,                                  /* tp_as_buffer         */
1242     Py_TPFLAGS_DEFAULT,                 /* tp_flags             */
1243     profiler_object__doc__,             /* tp_doc               */
1244     0,                                  /* tp_traverse          */
1245     0,                                  /* tp_clear             */
1246     0,                                  /* tp_richcompare       */
1247     0,                                  /* tp_weaklistoffset    */
1248     0,                                  /* tp_iter              */
1249     0,                                  /* tp_iternext          */
1250     profiler_methods,                   /* tp_methods           */
1251     profiler_members,                   /* tp_members           */
1252     profiler_getsets,                   /* tp_getset            */
1253     0,                                  /* tp_base              */
1254     0,                                  /* tp_dict              */
1255     0,                                  /* tp_descr_get         */
1256     0,                                  /* tp_descr_set         */
1257 };
1258 
1259 
1260 static PyMethodDef logreader_methods[] = {
1261     {"close",   (PyCFunction)logreader_close,  METH_NOARGS,
1262      logreader_close__doc__},
1263     {"fileno",  (PyCFunction)logreader_fileno, METH_NOARGS,
1264      logreader_fileno__doc__},
1265     {NULL, NULL}
1266 };
1267 
1268 static PyMemberDef logreader_members[] = {
1269     {"info", T_OBJECT, offsetof(LogReaderObject, info), RO,
1270      PyDoc_STR("Dictionary mapping informational keys to lists of values.")},
1271     {NULL}
1272 };
1273 
1274 
1275 PyDoc_STRVAR(logreader__doc__,
1276 "logreader(filename) --> log-iterator\n\
1277 Create a log-reader for the timing information file.");
1278 
1279 static PySequenceMethods logreader_as_sequence = {
1280     0,                                  /* sq_length */
1281     0,                                  /* sq_concat */
1282     0,                                  /* sq_repeat */
1283     (ssizeargfunc)logreader_sq_item,    /* sq_item */
1284     0,                                  /* sq_slice */
1285     0,                                  /* sq_ass_item */
1286     0,                                  /* sq_ass_slice */
1287     0,                                  /* sq_contains */
1288     0,                                  /* sq_inplace_concat */
1289     0,                                  /* sq_inplace_repeat */
1290 };
1291 
1292 static PyObject *
logreader_get_closed(LogReaderObject * self,void * closure)1293 logreader_get_closed(LogReaderObject *self, void *closure)
1294 {
1295     PyObject *result = (self->logfp == NULL) ? Py_True : Py_False;
1296     Py_INCREF(result);
1297     return result;
1298 }
1299 
1300 static PyGetSetDef logreader_getsets[] = {
1301     {"closed", (getter)logreader_get_closed, NULL,
1302      PyDoc_STR("True if the logreader's input file has already been closed.")},
1303     {NULL}
1304 };
1305 
1306 static PyTypeObject LogReaderType = {
1307     PyVarObject_HEAD_INIT(NULL, 0)
1308     "_hotshot.LogReaderType",           /* tp_name              */
1309     (int) sizeof(LogReaderObject),      /* tp_basicsize         */
1310     0,                                  /* tp_itemsize          */
1311     (destructor)logreader_dealloc,      /* tp_dealloc           */
1312     0,                                  /* tp_print             */
1313     0,                                  /* tp_getattr           */
1314     0,                                  /* tp_setattr           */
1315     0,                                  /* tp_compare           */
1316     0,                                  /* tp_repr              */
1317     0,                                  /* tp_as_number         */
1318     &logreader_as_sequence,             /* tp_as_sequence       */
1319     0,                                  /* tp_as_mapping        */
1320     0,                                  /* tp_hash              */
1321     0,                                  /* tp_call              */
1322     0,                                  /* tp_str               */
1323     PyObject_GenericGetAttr,            /* tp_getattro          */
1324     0,                                  /* tp_setattro          */
1325     0,                                  /* tp_as_buffer         */
1326     Py_TPFLAGS_DEFAULT,                 /* tp_flags             */
1327     logreader__doc__,                   /* tp_doc               */
1328     0,                                  /* tp_traverse          */
1329     0,                                  /* tp_clear             */
1330     0,                                  /* tp_richcompare       */
1331     0,                                  /* tp_weaklistoffset    */
1332     PyObject_SelfIter,                  /* tp_iter              */
1333     (iternextfunc)logreader_tp_iternext,/* tp_iternext          */
1334     logreader_methods,                  /* tp_methods           */
1335     logreader_members,                  /* tp_members           */
1336     logreader_getsets,                  /* tp_getset            */
1337     0,                                  /* tp_base              */
1338     0,                                  /* tp_dict              */
1339     0,                                  /* tp_descr_get         */
1340     0,                                  /* tp_descr_set         */
1341 };
1342 
1343 static PyObject *
hotshot_logreader(PyObject * unused,PyObject * args)1344 hotshot_logreader(PyObject *unused, PyObject *args)
1345 {
1346     LogReaderObject *self = NULL;
1347     char *filename;
1348     int c;
1349     int err = 0;
1350 
1351     if (PyArg_ParseTuple(args, "s:logreader", &filename)) {
1352         self = PyObject_New(LogReaderObject, &LogReaderType);
1353         if (self != NULL) {
1354             self->frametimings = 1;
1355             self->linetimings = 0;
1356             self->info = NULL;
1357             self->logfp = fopen(filename, "rb");
1358             if (self->logfp == NULL) {
1359                 PyErr_SetFromErrnoWithFilename(PyExc_IOError, filename);
1360                 goto error;
1361             }
1362             self->info = PyDict_New();
1363             if (self->info == NULL)
1364                 goto error;
1365             /* read initial info */
1366             for (;;) {
1367                 if ((c = fgetc(self->logfp)) == EOF) {
1368                     eof_error(self);
1369                     goto error;
1370                 }
1371                 if (c != WHAT_ADD_INFO) {
1372                     ungetc(c, self->logfp);
1373                     break;
1374                 }
1375                 err = unpack_add_info(self);
1376                 if (err) {
1377                     if (err == ERR_EOF)
1378                         eof_error(self);
1379                     else
1380                         PyErr_SetString(PyExc_RuntimeError,
1381                                         "unexpected error");
1382                     goto error;
1383                 }
1384             }
1385         }
1386     }
1387     return (PyObject *) self;
1388   error:
1389     Py_DECREF(self);
1390     return NULL;
1391 }
1392 
1393 
1394 /* Return a Python string that represents the version number without the
1395  * extra cruft added by revision control, even if the right options were
1396  * given to the "cvs export" command to make it not include the extra
1397  * cruft.
1398  */
1399 static char *
get_version_string(void)1400 get_version_string(void)
1401 {
1402     static char *rcsid = "$Revision$";
1403     char *rev = rcsid;
1404     char *buffer;
1405     int i = 0;
1406 
1407     while (*rev && !isdigit(Py_CHARMASK(*rev)))
1408         ++rev;
1409     while (rev[i] != ' ' && rev[i] != '\0')
1410         ++i;
1411     buffer = (char *)malloc(i + 1);
1412     if (buffer != NULL) {
1413         memmove(buffer, rev, i);
1414         buffer[i] = '\0';
1415     }
1416     return buffer;
1417 }
1418 
1419 /* Write out a RFC 822-style header with various useful bits of
1420  * information to make the output easier to manage.
1421  */
1422 static int
write_header(ProfilerObject * self)1423 write_header(ProfilerObject *self)
1424 {
1425     char *buffer;
1426     char cwdbuffer[PATH_MAX];
1427     PyObject *temp;
1428     Py_ssize_t i, len;
1429 
1430     buffer = get_version_string();
1431     if (buffer == NULL) {
1432         PyErr_NoMemory();
1433         return -1;
1434     }
1435     pack_add_info(self, "hotshot-version", buffer);
1436     pack_add_info(self, "requested-frame-timings",
1437                   (self->frametimings ? "yes" : "no"));
1438     pack_add_info(self, "requested-line-events",
1439                   (self->lineevents ? "yes" : "no"));
1440     pack_add_info(self, "requested-line-timings",
1441                   (self->linetimings ? "yes" : "no"));
1442     pack_add_info(self, "platform", Py_GetPlatform());
1443     pack_add_info(self, "executable", Py_GetProgramFullPath());
1444     free(buffer);
1445     buffer = (char *) Py_GetVersion();
1446     if (buffer == NULL)
1447         PyErr_Clear();
1448     else
1449         pack_add_info(self, "executable-version", buffer);
1450 
1451 #ifdef MS_WINDOWS
1452     PyOS_snprintf(cwdbuffer, sizeof(cwdbuffer), "%I64d", frequency.QuadPart);
1453     pack_add_info(self, "reported-performance-frequency", cwdbuffer);
1454 #else
1455     PyOS_snprintf(cwdbuffer, sizeof(cwdbuffer), "%lu", rusage_diff);
1456     pack_add_info(self, "observed-interval-getrusage", cwdbuffer);
1457     PyOS_snprintf(cwdbuffer, sizeof(cwdbuffer), "%lu", timeofday_diff);
1458     pack_add_info(self, "observed-interval-gettimeofday", cwdbuffer);
1459 #endif
1460 
1461     pack_add_info(self, "current-directory",
1462                   getcwd(cwdbuffer, sizeof cwdbuffer));
1463 
1464     temp = PySys_GetObject("path");
1465     if (temp == NULL || !PyList_Check(temp)) {
1466         PyErr_SetString(PyExc_RuntimeError, "sys.path must be a list");
1467         return -1;
1468     }
1469     len = PyList_GET_SIZE(temp);
1470     for (i = 0; i < len; ++i) {
1471         PyObject *item = PyList_GET_ITEM(temp, i);
1472         buffer = PyString_AsString(item);
1473         if (buffer == NULL) {
1474             pack_add_info(self, "sys-path-entry", "<non-string-path-entry>");
1475             PyErr_Clear();
1476         }
1477         else {
1478             pack_add_info(self, "sys-path-entry", buffer);
1479         }
1480     }
1481     pack_frame_times(self);
1482     pack_line_times(self);
1483 
1484     return 0;
1485 }
1486 
1487 PyDoc_STRVAR(profiler__doc__,
1488 "profiler(logfilename[, lineevents[, linetimes]]) -> profiler\n\
1489 Create a new profiler object.");
1490 
1491 static PyObject *
hotshot_profiler(PyObject * unused,PyObject * args)1492 hotshot_profiler(PyObject *unused, PyObject *args)
1493 {
1494     char *logfilename;
1495     ProfilerObject *self = NULL;
1496     int lineevents = 0;
1497     int linetimings = 1;
1498 
1499     if (PyArg_ParseTuple(args, "s|ii:profiler", &logfilename,
1500                          &lineevents, &linetimings)) {
1501         self = PyObject_New(ProfilerObject, &ProfilerType);
1502         if (self == NULL)
1503             return NULL;
1504         self->frametimings = 1;
1505         self->lineevents = lineevents ? 1 : 0;
1506         self->linetimings = (lineevents && linetimings) ? 1 : 0;
1507         self->index = 0;
1508         self->active = 0;
1509         self->next_fileno = 0;
1510         self->logfp = NULL;
1511         self->logfilename = PyTuple_GET_ITEM(args, 0);
1512         Py_INCREF(self->logfilename);
1513         self->filemap = PyDict_New();
1514         if (self->filemap == NULL) {
1515             Py_DECREF(self);
1516             return NULL;
1517         }
1518         self->logfp = fopen(logfilename, "wb");
1519         if (self->logfp == NULL) {
1520             Py_DECREF(self);
1521             PyErr_SetFromErrnoWithFilename(PyExc_IOError, logfilename);
1522             return NULL;
1523         }
1524         if (timeofday_diff == 0) {
1525             /* Run this several times since sometimes the first
1526              * doesn't give the lowest values, and we're really trying
1527              * to determine the lowest.
1528              */
1529             calibrate();
1530             calibrate();
1531             calibrate();
1532         }
1533         if (write_header(self)) {
1534             /* some error occurred, exception has been set */
1535             Py_DECREF(self);
1536             self = NULL;
1537         }
1538     }
1539     return (PyObject *) self;
1540 }
1541 
1542 PyDoc_STRVAR(coverage__doc__,
1543 "coverage(logfilename) -> profiler\n\
1544 Returns a profiler that doesn't collect any timing information, which is\n\
1545 useful in building a coverage analysis tool.");
1546 
1547 static PyObject *
hotshot_coverage(PyObject * unused,PyObject * args)1548 hotshot_coverage(PyObject *unused, PyObject *args)
1549 {
1550     char *logfilename;
1551     PyObject *result = NULL;
1552 
1553     if (PyArg_ParseTuple(args, "s:coverage", &logfilename)) {
1554         result = hotshot_profiler(unused, args);
1555         if (result != NULL) {
1556             ProfilerObject *self = (ProfilerObject *) result;
1557             self->frametimings = 0;
1558             self->linetimings = 0;
1559             self->lineevents = 1;
1560         }
1561     }
1562     return result;
1563 }
1564 
1565 PyDoc_VAR(resolution__doc__) =
1566 #ifdef MS_WINDOWS
1567 PyDoc_STR(
1568 "resolution() -> (performance-counter-ticks, update-frequency)\n"
1569 "Return the resolution of the timer provided by the QueryPerformanceCounter()\n"
1570 "function.  The first value is the smallest observed change, and the second\n"
1571 "is the result of QueryPerformanceFrequency()."
1572 )
1573 #else
1574 PyDoc_STR(
1575 "resolution() -> (gettimeofday-usecs, getrusage-usecs)\n"
1576 "Return the resolution of the timers provided by the gettimeofday() and\n"
1577 "getrusage() system calls, or -1 if the call is not supported."
1578 )
1579 #endif
1580 ;
1581 
1582 static PyObject *
hotshot_resolution(PyObject * self,PyObject * unused)1583 hotshot_resolution(PyObject *self, PyObject *unused)
1584 {
1585     if (timeofday_diff == 0) {
1586         calibrate();
1587         calibrate();
1588         calibrate();
1589     }
1590 #ifdef MS_WINDOWS
1591     return Py_BuildValue("ii", timeofday_diff, frequency.LowPart);
1592 #else
1593     return Py_BuildValue("ii", timeofday_diff, rusage_diff);
1594 #endif
1595 }
1596 
1597 
1598 static PyMethodDef functions[] = {
1599     {"coverage",   hotshot_coverage,   METH_VARARGS, coverage__doc__},
1600     {"profiler",   hotshot_profiler,   METH_VARARGS, profiler__doc__},
1601     {"logreader",  hotshot_logreader,  METH_VARARGS, logreader__doc__},
1602     {"resolution", hotshot_resolution, METH_NOARGS,  resolution__doc__},
1603     {NULL, NULL}
1604 };
1605 
1606 
1607 void
init_hotshot(void)1608 init_hotshot(void)
1609 {
1610     PyObject *module;
1611 
1612     Py_TYPE(&LogReaderType) = &PyType_Type;
1613     Py_TYPE(&ProfilerType) = &PyType_Type;
1614     module = Py_InitModule("_hotshot", functions);
1615     if (module != NULL) {
1616         char *s = get_version_string();
1617 
1618         PyModule_AddStringConstant(module, "__version__", s);
1619         free(s);
1620         Py_INCREF(&LogReaderType);
1621         PyModule_AddObject(module, "LogReaderType",
1622                            (PyObject *)&LogReaderType);
1623         Py_INCREF(&ProfilerType);
1624         PyModule_AddObject(module, "ProfilerType",
1625                            (PyObject *)&ProfilerType);
1626 
1627         if (ProfilerError == NULL)
1628             ProfilerError = PyErr_NewException("hotshot.ProfilerError",
1629                                                NULL, NULL);
1630         if (ProfilerError != NULL) {
1631             Py_INCREF(ProfilerError);
1632             PyModule_AddObject(module, "ProfilerError", ProfilerError);
1633         }
1634         PyModule_AddIntConstant(module, "WHAT_ENTER", WHAT_ENTER);
1635         PyModule_AddIntConstant(module, "WHAT_EXIT", WHAT_EXIT);
1636         PyModule_AddIntConstant(module, "WHAT_LINENO", WHAT_LINENO);
1637         PyModule_AddIntConstant(module, "WHAT_OTHER", WHAT_OTHER);
1638         PyModule_AddIntConstant(module, "WHAT_ADD_INFO", WHAT_ADD_INFO);
1639         PyModule_AddIntConstant(module, "WHAT_DEFINE_FILE", WHAT_DEFINE_FILE);
1640         PyModule_AddIntConstant(module, "WHAT_DEFINE_FUNC", WHAT_DEFINE_FUNC);
1641         PyModule_AddIntConstant(module, "WHAT_LINE_TIMES", WHAT_LINE_TIMES);
1642     }
1643 }
1644