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 *

   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 *

   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

   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

   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

   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

   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 *

   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

   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 *

   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

   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

   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

   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

   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

   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

   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

   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

   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

   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

   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

   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

   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

   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

   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

   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

   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

   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

   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

   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

   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 *

  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 *

  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 *

  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 *

  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 *

  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 *

  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 }