_hotshot.c 45.4 KB
Newer Older
1 2 3 4
/*
 * This is the High Performance Python Profiler portion of HotShot.
 */

5 6 7 8 9
#include "Python.h"
#include "compile.h"
#include "eval.h"
#include "frameobject.h"
#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
#include <direct.h>    /* for getcwd() */
18 19 20 21 22 23
typedef __int64 hs_time;
#define GETTIMEOFDAY(P_HS_TIME) \
	{ LARGE_INTEGER _temp; \
	  QueryPerformanceCounter(&_temp); \
	  *(P_HS_TIME) = _temp.QuadPart; }
	  
24

25 26 27 28
#else
#ifndef HAVE_GETTIMEOFDAY
#error "This module requires gettimeofday() on non-Windows platforms!"
#endif
29
#if defined(macintosh) || (defined(PYOS_OS2) && defined(PYCC_GCC))
30 31
#include <sys/time.h>
#else
32 33
#include <sys/resource.h>
#include <sys/times.h>
34
#endif
35 36 37 38 39 40 41 42 43 44 45 46 47 48 49
typedef struct timeval hs_time;
#endif

#if !defined(__cplusplus) && !defined(inline)
#ifdef __GNUC__
#define inline __inline
#endif
#endif

#ifndef inline
#define inline
#endif

#define BUFFERSIZE 10240

50 51 52 53
#ifdef macintosh
#define PATH_MAX 254
#endif

54 55 56 57
#if defined(PYOS_OS2) && defined(PYCC_GCC)
#define PATH_MAX 260
#endif

58 59 60 61 62 63
#if defined(__sgi) && _COMPILER_VERSION>700 && !defined(PATH_MAX)
/* fix PATH_MAX not being defined with MIPSPro 7.x
   if mode is ANSI C (default) */
#define PATH_MAX 1024
#endif

64 65 66
#ifndef PATH_MAX
#   ifdef MAX_PATH
#       define PATH_MAX MAX_PATH
67 68
#   elif defined (_POSIX_PATH_MAX)
#       define PATH_MAX _POSIX_PATH_MAX
69 70 71 72 73
#   else
#       error "Need a defn. for PATH_MAX in _hotshot.c"
#   endif
#endif

74 75 76 77 78 79 80 81 82
typedef struct {
    PyObject_HEAD
    PyObject *filemap;
    PyObject *logfilename;
    int index;
    unsigned char buffer[BUFFERSIZE];
    FILE *logfp;
    int lineevents;
    int linetimings;
83
    int frametimings;
84 85 86 87 88 89 90 91
    /* size_t filled; */
    int active;
    int next_fileno;
    hs_time prev_timeofday;
} ProfilerObject;

typedef struct {
    PyObject_HEAD
92
    PyObject *info;
93 94
    FILE *logfp;
    int linetimings;
95
    int frametimings;
96 97 98 99 100
} LogReaderObject;

static PyObject * ProfilerError = NULL;


101
#ifndef MS_WINDOWS
102 103 104 105 106 107 108 109 110 111
#ifdef GETTIMEOFDAY_NO_TZ
#define GETTIMEOFDAY(ptv) gettimeofday((ptv))
#else
#define GETTIMEOFDAY(ptv) gettimeofday((ptv), (struct timezone *)NULL)
#endif
#endif


/* The log reader... */

112
PyDoc_STRVAR(logreader_close__doc__,
113
"close()\n"
114
"Close the log file, preventing additional records from being read.");
115 116 117 118

static PyObject *
logreader_close(LogReaderObject *self, PyObject *args)
{
119 120 121
    if (self->logfp != NULL) {
        fclose(self->logfp);
        self->logfp = NULL;
122
    }
123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141
    Py_INCREF(Py_None);

    return Py_None;
}

PyDoc_STRVAR(logreader_fileno__doc__,
"fileno() -> file descriptor\n"
"Returns the file descriptor for the log file, if open.\n"
"Raises ValueError if the log file is closed.");

static PyObject *
logreader_fileno(LogReaderObject *self)
{
    if (self->logfp == NULL) {
        PyErr_SetString(PyExc_ValueError,
                        "logreader's file object already closed");
        return NULL;
    }
    return PyInt_FromLong(fileno(self->logfp));
142 143 144 145 146 147 148 149 150 151 152 153 154 155
}


/* Log File Format
 * ---------------
 *
 * The log file consists of a sequence of variable-length records.
 * Each record is identified with a record type identifier in two
 * bits of the first byte.  The two bits are the "least significant"
 * bits of the byte.
 *
 * Low bits:    Opcode:        Meaning:
 *       0x00         ENTER     enter a frame
 *       0x01          EXIT     exit a frame
Michael W. Hudson's avatar
Michael W. Hudson committed
156
 *       0x02        LINENO     execution moved onto a different line
157 158 159 160 161 162 163 164 165 166 167 168 169 170
 *       0x03         OTHER     more bits are needed to deecode
 *
 * If the type is OTHER, the record is not packed so tightly, and the
 * remaining bits are used to disambiguate the record type.  These
 * records are not used as frequently so compaction is not an issue.
 * Each of the first three record types has a highly tailored
 * structure that allows it to be packed tightly.
 *
 * The OTHER records have the following identifiers:
 *
 * First byte:  Opcode:        Meaning:
 *       0x13      ADD_INFO     define a key/value pair
 *       0x23   DEFINE_FILE     define an int->filename mapping
 *       0x33    LINE_TIMES     indicates if LINENO events have tdeltas
171 172
 *       0x43   DEFINE_FUNC     define a (fileno,lineno)->funcname mapping
 *       0x53   FRAME_TIMES     indicates if ENTER/EXIT events have tdeltas
173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193
 *
 * Packed Integers
 *
 * "Packed integers" are non-negative integer values encoded as a
 * sequence of bytes.  Each byte is encoded such that the most
 * significant bit is set if the next byte is also part of the
 * integer.  Each byte provides bits to the least-significant end of
 * the result; the accumulated value must be shifted up to place the
 * new bits into the result.
 *
 * "Modified packed integers" are packed integers where only a portion
 * of the first byte is used.  In the rest of the specification, these
 * are referred to as "MPI(n,name)", where "n" is the number of bits
 * discarded from the least-signicant positions of the byte, and
 * "name" is a name being given to those "discarded" bits, since they
 * are a field themselves.
 *
 * ENTER records:
 *
 *      MPI(2,type)  fileno          -- type is 0x00
 *      PI           lineno
194
 *      PI           tdelta          -- iff frame times are enabled
195 196 197
 *
 * EXIT records
 *
198 199
 *      MPI(2,type)  tdelta          -- type is 0x01; tdelta will be 0
 *                                      if frame times are disabled
200 201 202 203 204 205 206 207
 *
 * LINENO records
 *
 *      MPI(2,type)  lineno          -- type is 0x02
 *      PI           tdelta          -- iff LINENO includes it
 *
 * ADD_INFO records
 *
208
 *      BYTE         type            -- always 0x13
209 210 211 212 213 214 215
 *      PI           len1            -- length of first string
 *      BYTE         string1[len1]   -- len1 bytes of string data
 *      PI           len2            -- length of second string
 *      BYTE         string2[len2]   -- len2 bytes of string data
 *
 * DEFINE_FILE records
 *
216
 *      BYTE         type            -- always 0x23
217 218 219 220
 *      PI           fileno
 *      PI           len             -- length of filename
 *      BYTE         filename[len]   -- len bytes of string data
 *
221 222 223 224 225 226 227 228
 * DEFINE_FUNC records
 *
 *      BYTE         type            -- always 0x43
 *      PI           fileno
 *      PI           lineno
 *      PI           len             -- length of funcname
 *      BYTE         funcname[len]   -- len bytes of string data
 *
229
 * LINE_TIMES records
230 231 232 233 234 235 236
 *
 * This record can be used only before the start of ENTER/EXIT/LINENO
 * records.  If have_tdelta is true, LINENO records will include the
 * tdelta field, otherwise it will be omitted.  If this record is not
 * given, LINENO records will not contain the tdelta field.
 *
 *      BYTE         type            -- always 0x33
237 238
 *      BYTE         have_tdelta     -- 0 if LINENO does *not* have
 *                                      timing information
239 240 241 242 243 244 245 246 247 248 249
 * FRAME_TIMES records
 *
 * This record can be used only before the start of ENTER/EXIT/LINENO
 * records.  If have_tdelta is true, ENTER and EXIT records will
 * include the tdelta field, otherwise it will be omitted.  If this
 * record is not given, ENTER and EXIT records will contain the tdelta
 * field.
 *
 *      BYTE         type            -- always 0x53
 *      BYTE         have_tdelta     -- 0 if ENTER/EXIT do *not* have
 *                                      timing information
250 251 252 253 254 255 256 257 258
 */

#define WHAT_ENTER        0x00
#define WHAT_EXIT         0x01
#define WHAT_LINENO       0x02
#define WHAT_OTHER        0x03  /* only used in decoding */
#define WHAT_ADD_INFO     0x13
#define WHAT_DEFINE_FILE  0x23
#define WHAT_LINE_TIMES   0x33
259 260
#define WHAT_DEFINE_FUNC  0x43
#define WHAT_FRAME_TIMES  0x53
261 262 263 264

#define ERR_NONE          0
#define ERR_EOF          -1
#define ERR_EXCEPTION    -2
265
#define ERR_BAD_RECTYPE  -3
266 267 268 269 270 271 272 273 274 275 276 277 278 279

#define PISIZE            (sizeof(int) + 1)
#define MPISIZE           (PISIZE + 1)

/* Maximum size of "normal" events -- nothing that contains string data */
#define MAXEVENTSIZE      (MPISIZE + PISIZE*2)


/* Unpack a packed integer; if "discard" is non-zero, unpack a modified
 * packed integer with "discard" discarded bits.
 */
static int
unpack_packed_int(LogReaderObject *self, int *pvalue, int discard)
{
280
    int c;
281 282 283 284 285 286
    int accum = 0;
    int bits = 0;
    int cont;

    do {
        /* read byte */
287 288 289
	if ((c = fgetc(self->logfp)) == EOF)
            return ERR_EOF;
        accum |= ((c & 0x7F) >> discard) << bits;
290
        bits += (7 - discard);
291
        cont = c & 0x80;
292 293 294 295 296 297 298 299 300 301 302 303 304 305
        discard = 0;
    } while (cont);

    *pvalue = accum;

    return 0;
}

/* Unpack a string, which is encoded as a packed integer giving the
 * length of the string, followed by the string data.
 */
static int
unpack_string(LogReaderObject *self, PyObject **pvalue)
{
306
    int i;
307
    int len;
308
    int err;
309
    int ch;
310 311 312 313 314 315 316
    char *buf;
    
    if ((err = unpack_packed_int(self, &len, 0)))
        return err;

    buf = malloc(len);
    for (i=0; i < len; i++) {
317 318 319
        ch = fgetc(self->logfp);
	buf[i] = ch;
        if (ch == EOF) {
320 321
            free(buf);
            return ERR_EOF;
322 323
        }
    }
324 325 326 327 328 329
    *pvalue = PyString_FromStringAndSize(buf, len);
    free(buf);
    if (*pvalue == NULL) {
        return ERR_EXCEPTION;
    }
    return 0;
330 331 332
}


333
static int
334
unpack_add_info(LogReaderObject *self)
335 336 337 338 339 340 341 342 343 344 345 346 347 348 349 350 351 352 353 354 355 356 357 358 359 360 361 362 363 364 365 366 367 368 369
{
    PyObject *key;
    PyObject *value = NULL;
    int err;

    err = unpack_string(self, &key);
    if (!err) {
        err = unpack_string(self, &value);
        if (err)
            Py_DECREF(key);
        else {
            PyObject *list = PyDict_GetItem(self->info, key);
            if (list == NULL) {
                list = PyList_New(0);
                if (list == NULL) {
                    err = ERR_EXCEPTION;
                    goto finally;
                }
                if (PyDict_SetItem(self->info, key, list)) {
                    err = ERR_EXCEPTION;
                    goto finally;
                }
            }
            if (PyList_Append(list, value))
                err = ERR_EXCEPTION;
        }
    }
 finally:
    Py_XDECREF(key);
    Py_XDECREF(value);
    return err;
}


static void
370
eof_error(LogReaderObject *self)
371
{
372 373
    fclose(self->logfp);
    self->logfp = NULL;
374 375 376 377
    PyErr_SetString(PyExc_EOFError,
                    "end of file with incomplete profile record");
}

378 379 380
static PyObject *
logreader_tp_iternext(LogReaderObject *self)
{
381 382
    int c;
    int what;
383 384 385 386 387 388 389 390 391 392 393 394 395 396 397
    int err = ERR_NONE;
    int lineno = -1;
    int fileno = -1;
    int tdelta = -1;
    PyObject *s1 = NULL, *s2 = NULL;
    PyObject *result = NULL;
#if 0
    unsigned char b0, b1;
#endif

    if (self->logfp == NULL) {
        PyErr_SetString(ProfilerError,
                        "cannot iterate over closed LogReader object");
        return NULL;
    }
398

399 400
restart:
    /* decode the record type */
401 402 403
    if ((c = fgetc(self->logfp)) == EOF) {
        fclose(self->logfp);
        self->logfp = NULL;
404
        return NULL;
405
    }
406 407 408 409 410
    what = c & WHAT_OTHER;
    if (what == WHAT_OTHER)
        what = c; /* need all the bits for type */
    else
        ungetc(c, self->logfp); /* type byte includes packed int */
411 412 413 414 415

    switch (what) {
    case WHAT_ENTER:
        err = unpack_packed_int(self, &fileno, 2);
        if (!err) {
416 417 418
            err = unpack_packed_int(self, &lineno, 0);
            if (self->frametimings && !err)
                err = unpack_packed_int(self, &tdelta, 0);
419 420 421 422 423 424 425 426 427 428 429
        }
        break;
    case WHAT_EXIT:
        err = unpack_packed_int(self, &tdelta, 2);
        break;
    case WHAT_LINENO:
        err = unpack_packed_int(self, &lineno, 2);
        if (self->linetimings && !err)
            err = unpack_packed_int(self, &tdelta, 0);
        break;
    case WHAT_ADD_INFO:
430
        err = unpack_add_info(self);
431 432 433 434 435 436 437 438 439 440 441
        break;
    case WHAT_DEFINE_FILE:
        err = unpack_packed_int(self, &fileno, 0);
        if (!err) {
            err = unpack_string(self, &s1);
            if (!err) {
                Py_INCREF(Py_None);
                s2 = Py_None;
            }
        }
        break;
442 443 444 445 446 447 448 449
    case WHAT_DEFINE_FUNC:
        err = unpack_packed_int(self, &fileno, 0);
        if (!err) {
            err = unpack_packed_int(self, &lineno, 0);
            if (!err)
                err = unpack_string(self, &s1);
        }
        break;
450
    case WHAT_LINE_TIMES:
451
        if ((c = fgetc(self->logfp)) == EOF)
452 453
            err = ERR_EOF;
        else {
454 455 456
            self->linetimings = c ? 1 : 0;
	    goto restart;
	}
457
        break;
458
    case WHAT_FRAME_TIMES:
459
        if ((c = fgetc(self->logfp)) == EOF)
460 461
            err = ERR_EOF;
        else {
462 463 464
            self->frametimings = c ? 1 : 0;
	    goto restart;
	}
465
        break;
466
    default:
467
        err = ERR_BAD_RECTYPE;
468
    }
469 470 471 472 473
    if (err == ERR_BAD_RECTYPE) {
        PyErr_SetString(PyExc_ValueError,
                        "unknown record type in log file");
    }
    else if (err == ERR_EOF) {
474
        eof_error(self);
475 476 477 478 479
    }
    else if (!err) {
        result = PyTuple_New(4);
        PyTuple_SET_ITEM(result, 0, PyInt_FromLong(what));
        PyTuple_SET_ITEM(result, 2, PyInt_FromLong(fileno));
480
        if (s1 == NULL)
481
            PyTuple_SET_ITEM(result, 1, PyInt_FromLong(tdelta));
482
        else
483
            PyTuple_SET_ITEM(result, 1, s1);
484 485 486
        if (s2 == NULL)
            PyTuple_SET_ITEM(result, 3, PyInt_FromLong(lineno));
        else
487 488 489 490 491 492 493 494 495 496 497 498 499 500 501 502 503 504 505 506 507 508 509 510 511 512 513 514 515 516 517 518 519 520 521 522 523 524 525 526 527 528 529 530 531 532 533 534 535 536 537 538 539
            PyTuple_SET_ITEM(result, 3, s2);
    }
    /* The only other case is err == ERR_EXCEPTION, in which case the
     * exception is already set.
     */
#if 0
    b0 = self->buffer[self->index];
    b1 = self->buffer[self->index + 1];
    if (b0 & 1) {
        /* This is a line-number event. */
        what = PyTrace_LINE;
        lineno = ((b0 & ~1) << 7) + b1;
        self->index += 2;
    }
    else {
        what = (b0 & 0x0E) >> 1;
        tdelta = ((b0 & 0xF0) << 4) + b1;
        if (what == PyTrace_CALL) {
            /* we know there's a 2-byte file ID & 2-byte line number */
            fileno = ((self->buffer[self->index + 2] << 8)
                      + self->buffer[self->index + 3]);
            lineno = ((self->buffer[self->index + 4] << 8)
                      + self->buffer[self->index + 5]);
            self->index += 6;
        }
        else
            self->index += 2;
    }
#endif
    return result;
}

static void
logreader_dealloc(LogReaderObject *self)
{
    if (self->logfp != NULL) {
        fclose(self->logfp);
        self->logfp = NULL;
    }
    PyObject_Del(self);
}

static PyObject *
logreader_sq_item(LogReaderObject *self, int index)
{
    PyObject *result = logreader_tp_iternext(self);
    if (result == NULL && !PyErr_Occurred()) {
        PyErr_SetString(PyExc_IndexError, "no more events in log");
        return NULL;
    }
    return result;
}

540 541
static void
do_stop(ProfilerObject *self);
542 543 544 545 546 547

static int
flush_data(ProfilerObject *self)
{
    /* Need to dump data to the log file... */
    size_t written = fwrite(self->buffer, 1, self->index, self->logfp);
548
    if (written == (size_t)self->index)
549 550 551 552 553 554 555 556
        self->index = 0;
    else {
        memmove(self->buffer, &self->buffer[written],
                self->index - written);
        self->index -= written;
        if (written == 0) {
            char *s = PyString_AsString(self->logfilename);
            PyErr_SetFromErrnoWithFilename(PyExc_IOError, s);
557
            do_stop(self);
558 559 560 561 562 563 564
            return -1;
        }
    }
    if (written > 0) {
        if (fflush(self->logfp)) {
            char *s = PyString_AsString(self->logfilename);
            PyErr_SetFromErrnoWithFilename(PyExc_IOError, s);
565
            do_stop(self);
566 567 568 569 570 571
            return -1;
        }
    }
    return 0;
}

572
static inline int
573 574 575 576 577 578 579 580 581 582 583 584
pack_packed_int(ProfilerObject *self, int value)
{
    unsigned char partial;

    do {
        partial = value & 0x7F;
        value >>= 7;
        if (value)
            partial |= 0x80;
        self->buffer[self->index] = partial;
        self->index++;
    } while (value);
585
    return 0;
586 587 588 589 590 591
}

/* Encode a modified packed integer, with a subfield of modsize bits
 * containing the value "subfield".  The value of subfield is not
 * checked to ensure it actually fits in modsize bits.
 */
592
static inline int
593 594 595 596 597 598 599 600 601 602 603 604 605
pack_modified_packed_int(ProfilerObject *self, int value,
                         int modsize, int subfield)
{
    const int maxvalues[] = {-1, 1, 3, 7, 15, 31, 63, 127};

    int bits = 7 - modsize;
    int partial = value & maxvalues[bits];
    unsigned char b = subfield | (partial << modsize);

    if (partial != value) {
        b |= 0x80;
        self->buffer[self->index] = b;
        self->index++;
606
        return pack_packed_int(self, value >> bits);
607
    }
608 609 610
    self->buffer[self->index] = b;
    self->index++;
    return 0;
611 612
}

613
static int
614
pack_string(ProfilerObject *self, const char *s, int len)
615
{
616 617 618 619 620 621
    if (len + PISIZE + self->index >= BUFFERSIZE) {
        if (flush_data(self) < 0)
            return -1;
    }
    if (pack_packed_int(self, len) < 0)
        return -1;
622 623
    memcpy(self->buffer + self->index, s, len);
    self->index += len;
624
    return 0;
625 626
}

627
static int
628 629 630 631 632
pack_add_info(ProfilerObject *self, const char *s1, const char *s2)
{
    int len1 = strlen(s1);
    int len2 = strlen(s2);

633 634 635 636
    if (len1 + len2 + PISIZE*2 + 1 + self->index >= BUFFERSIZE) {
        if (flush_data(self) < 0)
            return -1;
    }
637 638
    self->buffer[self->index] = WHAT_ADD_INFO;
    self->index++;
639 640 641
    if (pack_string(self, s1, len1) < 0)
        return -1;
    return pack_string(self, s2, len2);
642 643
}

644
static int
645 646 647 648
pack_define_file(ProfilerObject *self, int fileno, const char *filename)
{
    int len = strlen(filename);

649 650 651 652
    if (len + PISIZE*2 + 1 + self->index >= BUFFERSIZE) {
        if (flush_data(self) < 0)
            return -1;
    }
653 654
    self->buffer[self->index] = WHAT_DEFINE_FILE;
    self->index++;
655 656 657
    if (pack_packed_int(self, fileno) < 0)
        return -1;
    return pack_string(self, filename, len);
658 659
}

660
static int
661 662 663 664 665
pack_define_func(ProfilerObject *self, int fileno, int lineno,
                 const char *funcname)
{
    int len = strlen(funcname);

666 667 668 669
    if (len + PISIZE*3 + 1 + self->index >= BUFFERSIZE) {
        if (flush_data(self) < 0)
            return -1;
    }
670 671
    self->buffer[self->index] = WHAT_DEFINE_FUNC;
    self->index++;
672 673 674 675 676
    if (pack_packed_int(self, fileno) < 0)
        return -1;
    if (pack_packed_int(self, lineno) < 0)
        return -1;
    return pack_string(self, funcname, len);
677 678
}

679
static int
680 681
pack_line_times(ProfilerObject *self)
{
682 683 684 685
    if (2 + self->index >= BUFFERSIZE) {
        if (flush_data(self) < 0)
            return -1;
    }
686 687 688
    self->buffer[self->index] = WHAT_LINE_TIMES;
    self->buffer[self->index + 1] = self->linetimings ? 1 : 0;
    self->index += 2;
689
    return 0;
690 691
}

692
static int
693 694
pack_frame_times(ProfilerObject *self)
{
695 696 697 698
    if (2 + self->index >= BUFFERSIZE) {
        if (flush_data(self) < 0)
            return -1;
    }
699 700 701
    self->buffer[self->index] = WHAT_FRAME_TIMES;
    self->buffer[self->index + 1] = self->frametimings ? 1 : 0;
    self->index += 2;
702
    return 0;
703 704
}

705
static inline int
706 707
pack_enter(ProfilerObject *self, int fileno, int tdelta, int lineno)
{
708 709 710 711
    if (MPISIZE + PISIZE*2 + self->index >= BUFFERSIZE) {
        if (flush_data(self) < 0)
            return -1;
    }
712 713
    pack_modified_packed_int(self, fileno, 2, WHAT_ENTER);
    pack_packed_int(self, lineno);
714
    if (self->frametimings)
715 716 717
        return pack_packed_int(self, tdelta);
    else
        return 0;
718 719
}

720
static inline int
721 722
pack_exit(ProfilerObject *self, int tdelta)
{
723 724 725
    if (MPISIZE + self->index >= BUFFERSIZE) {
        if (flush_data(self) < 0)
            return -1;
726
    }
727 728 729 730 731
    if (self->frametimings)
        return pack_modified_packed_int(self, tdelta, 2, WHAT_EXIT);
    self->buffer[self->index] = WHAT_EXIT;
    self->index++;
    return 0;
732 733
}

734
static inline int
735 736
pack_lineno(ProfilerObject *self, int lineno)
{
737 738 739 740 741
    if (MPISIZE + self->index >= BUFFERSIZE) {
        if (flush_data(self) < 0)
            return -1;
    }
    return pack_modified_packed_int(self, lineno, 2, WHAT_LINENO);
742 743
}

744
static inline int
745 746
pack_lineno_tdelta(ProfilerObject *self, int lineno, int tdelta)
{
747 748 749 750 751 752 753
    if (MPISIZE + PISIZE + self->index >= BUFFERSIZE) {
        if (flush_data(self) < 0)
            return 0;
    }
    if (pack_modified_packed_int(self, lineno, 2, WHAT_LINENO) < 0)
        return -1;
    return pack_packed_int(self, tdelta);
754 755 756 757 758
}

static inline int
get_fileno(ProfilerObject *self, PyCodeObject *fcode)
{
759 760 761 762
    /* This is only used for ENTER events. */

    PyObject *obj;
    PyObject *dict;
763 764
    int fileno;

765 766
    obj = PyDict_GetItem(self->filemap, fcode->co_filename);
    if (obj == NULL) {
767
        /* first sighting of this file */
768 769 770 771
        dict = PyDict_New();
        if (dict == NULL) {
            return -1;
        }
772
        fileno = self->next_fileno;
773 774
        obj = Py_BuildValue("iN", fileno, dict);
        if (obj == NULL) {
775 776
            return -1;
        }
777 778
        if (PyDict_SetItem(self->filemap, fcode->co_filename, obj)) {
            Py_DECREF(obj);
779 780 781
            return -1;
        }
        self->next_fileno++;
782
        Py_DECREF(obj);
783 784 785
        if (pack_define_file(self, fileno,
                             PyString_AS_STRING(fcode->co_filename)) < 0)
            return -1;
786 787 788
    }
    else {
        /* already know this ID */
789 790 791 792 793 794 795 796 797 798 799 800
        fileno = PyInt_AS_LONG(PyTuple_GET_ITEM(obj, 0));
        dict = PyTuple_GET_ITEM(obj, 1);
    }
    /* make sure we save a function name for this (fileno, lineno) */
    obj = PyInt_FromLong(fcode->co_firstlineno);
    if (obj == NULL) {
        /* We just won't have it saved; too bad. */
        PyErr_Clear();
    }
    else {
        PyObject *name = PyDict_GetItem(dict, obj);
        if (name == NULL) {
801 802 803
            if (pack_define_func(self, fileno, fcode->co_firstlineno,
                                 PyString_AS_STRING(fcode->co_name)) < 0)
                return -1;
804 805 806
            if (PyDict_SetItem(dict, obj, fcode->co_name))
                return -1;
        }
807 808 809 810 811 812 813 814
    }
    return fileno;
}

static inline int
get_tdelta(ProfilerObject *self)
{
    int tdelta;
815
#ifdef MS_WINDOWS
816
    hs_time tv;
817
    hs_time diff;
818

819 820 821
    GETTIMEOFDAY(&tv);
    diff = tv - self->prev_timeofday;
    tdelta = (int)diff;
822 823 824 825 826 827 828 829 830 831 832 833 834 835 836 837 838 839 840 841 842 843
#else
    struct timeval tv;

    GETTIMEOFDAY(&tv);

    if (tv.tv_sec == self->prev_timeofday.tv_sec)
        tdelta = tv.tv_usec - self->prev_timeofday.tv_usec;
    else
        tdelta = ((tv.tv_sec - self->prev_timeofday.tv_sec) * 1000000
                  + tv.tv_usec);
#endif
    self->prev_timeofday = tv;
    return tdelta;
}


/* The workhorse:  the profiler callback function. */

static int
profiler_callback(ProfilerObject *self, PyFrameObject *frame, int what,
                  PyObject *arg)
{
844
    int tdelta = -1;
845 846
    int fileno;

847 848
    if (self->frametimings)
        tdelta = get_tdelta(self);
849 850 851 852 853
    switch (what) {
    case PyTrace_CALL:
        fileno = get_fileno(self, frame->f_code);
        if (fileno < 0)
            return -1;
854 855 856
        if (pack_enter(self, fileno, tdelta,
                       frame->f_code->co_firstlineno) < 0)
            return -1;
857 858
        break;
    case PyTrace_RETURN:
859 860
        if (pack_exit(self, tdelta) < 0)
            return -1;
861 862 863 864 865 866 867 868 869 870 871 872 873 874 875 876 877 878 879 880 881 882
        break;
    default:
        /* should never get here */
        break;
    }
    return 0;
}


/* Alternate callback when we want PyTrace_LINE events */

static int
tracer_callback(ProfilerObject *self, PyFrameObject *frame, int what,
                PyObject *arg)
{
    int fileno;

    switch (what) {
    case PyTrace_CALL:
        fileno = get_fileno(self, frame->f_code);
        if (fileno < 0)
            return -1;
883 884 885 886
        return pack_enter(self, fileno,
                          self->frametimings ? get_tdelta(self) : -1,
                          frame->f_code->co_firstlineno);

887
    case PyTrace_RETURN:
888 889
        return pack_exit(self, get_tdelta(self));

890
    case PyTrace_LINE:
891
        if (self->linetimings)
892
            return pack_lineno_tdelta(self, frame->f_lineno,
Michael W. Hudson's avatar
Michael W. Hudson committed
893
				      get_tdelta(self));
894
        else
895
            return pack_lineno(self, frame->f_lineno);
896

897 898 899 900 901 902 903 904 905 906
    default:
        /* ignore PyTrace_EXCEPTION */
        break;
    }
    return 0;
}


/* A couple of useful helper functions. */

907
#ifdef MS_WINDOWS
908
static LARGE_INTEGER frequency = {0, 0};
909 910 911 912 913 914 915 916 917 918
#endif

static unsigned long timeofday_diff = 0;
static unsigned long rusage_diff = 0;

static void
calibrate(void)
{
    hs_time tv1, tv2;

919
#ifdef MS_WINDOWS
920
    hs_time diff;
921 922 923 924 925 926
    QueryPerformanceFrequency(&frequency);
#endif

    GETTIMEOFDAY(&tv1);
    while (1) {
        GETTIMEOFDAY(&tv2);
927
#ifdef MS_WINDOWS
928 929 930
        diff = tv2 - tv1;
        if (diff != 0) {
            timeofday_diff = (unsigned long)diff;
931 932 933 934 935 936 937 938 939 940 941 942
            break;
        }
#else
        if (tv1.tv_sec != tv2.tv_sec || tv1.tv_usec != tv2.tv_usec) {
            if (tv1.tv_sec == tv2.tv_sec)
                timeofday_diff = tv2.tv_usec - tv1.tv_usec;
            else
                timeofday_diff = (1000000 - tv1.tv_usec) + tv2.tv_usec;
            break;
        }
#endif
    }
943 944
#if defined(MS_WINDOWS) || defined(macintosh) || defined(PYOS_OS2) || \
    defined(__VMS)
945 946 947 948 949 950 951 952 953 954 955 956 957 958 959 960 961 962 963 964 965 966 967 968 969 970 971 972 973 974 975 976 977 978 979 980 981 982 983 984 985 986 987 988 989 990 991 992 993 994 995 996 997 998 999 1000 1001 1002 1003 1004 1005 1006 1007 1008 1009 1010 1011 1012 1013 1014 1015 1016 1017 1018 1019
    rusage_diff = -1;
#else
    {
        struct rusage ru1, ru2;

        getrusage(RUSAGE_SELF, &ru1);
        while (1) {
            getrusage(RUSAGE_SELF, &ru2);
            if (ru1.ru_utime.tv_sec != ru2.ru_utime.tv_sec) {
                rusage_diff = ((1000000 - ru1.ru_utime.tv_usec)
                               + ru2.ru_utime.tv_usec);
                break;
            }
            else if (ru1.ru_utime.tv_usec != ru2.ru_utime.tv_usec) {
                rusage_diff = ru2.ru_utime.tv_usec - ru1.ru_utime.tv_usec;
                break;
            }
            else if (ru1.ru_stime.tv_sec != ru2.ru_stime.tv_sec) {
                rusage_diff = ((1000000 - ru1.ru_stime.tv_usec)
                               + ru2.ru_stime.tv_usec);
                break;
            }
            else if (ru1.ru_stime.tv_usec != ru2.ru_stime.tv_usec) {
                rusage_diff = ru2.ru_stime.tv_usec - ru1.ru_stime.tv_usec;
                break;
            }
        }
    }
#endif
}

static void
do_start(ProfilerObject *self)
{
    self->active = 1;
    GETTIMEOFDAY(&self->prev_timeofday);
    if (self->lineevents)
        PyEval_SetTrace((Py_tracefunc) tracer_callback, (PyObject *)self);
    else
        PyEval_SetProfile((Py_tracefunc) profiler_callback, (PyObject *)self);
}

static void
do_stop(ProfilerObject *self)
{
    if (self->active) {
        self->active = 0;
        if (self->lineevents)
            PyEval_SetTrace(NULL, NULL);
        else
            PyEval_SetProfile(NULL, NULL);
    }
    if (self->index > 0) {
        /* Best effort to dump out any remaining data. */
        flush_data(self);
    }
}

static int
is_available(ProfilerObject *self)
{
    if (self->active) {
        PyErr_SetString(ProfilerError, "profiler already active");
        return 0;
    }
    if (self->logfp == NULL) {
        PyErr_SetString(ProfilerError, "profiler already closed");
        return 0;
    }
    return 1;
}


/* Profiler object interface methods. */

1020
PyDoc_STRVAR(addinfo__doc__,
1021
"addinfo(key, value)\n"
1022
"Insert an ADD_INFO record into the log.");
1023 1024 1025 1026 1027 1028 1029 1030 1031 1032 1033

static PyObject *
profiler_addinfo(ProfilerObject *self, PyObject *args)
{
    PyObject *result = NULL;
    char *key, *value;

    if (PyArg_ParseTuple(args, "ss:addinfo", &key, &value)) {
        if (self->logfp == NULL)
            PyErr_SetString(ProfilerError, "profiler already closed");
        else {
1034 1035 1036 1037
            if (pack_add_info(self, key, value) == 0) {
                result = Py_None;
                Py_INCREF(result);
            }
1038 1039 1040 1041 1042
        }
    }
    return result;
}

1043
PyDoc_STRVAR(close__doc__,
1044
"close()\n"
1045
"Shut down this profiler and close the log files, even if its active.");
1046 1047

static PyObject *
1048
profiler_close(ProfilerObject *self)
1049
{
1050 1051 1052 1053 1054 1055 1056 1057
    do_stop(self);
    if (self->logfp != NULL) {
        fclose(self->logfp);
        self->logfp = NULL;
    }
    Py_INCREF(Py_None);
    return Py_None;
}
1058

1059 1060 1061 1062 1063 1064 1065 1066 1067
#define fileno__doc__ logreader_fileno__doc__

static PyObject *
profiler_fileno(ProfilerObject *self)
{
    if (self->logfp == NULL) {
        PyErr_SetString(PyExc_ValueError,
                        "profiler's file object already closed");
        return NULL;
1068
    }
1069
    return PyInt_FromLong(fileno(self->logfp));
1070 1071
}

1072
PyDoc_STRVAR(runcall__doc__,
1073
"runcall(callable[, args[, kw]]) -> callable()\n"
1074
"Profile a specific function call, returning the result of that call.");
1075 1076 1077 1078 1079 1080 1081 1082 1083 1084 1085 1086 1087 1088 1089 1090 1091 1092 1093 1094

static PyObject *
profiler_runcall(ProfilerObject *self, PyObject *args)
{
    PyObject *result = NULL;
    PyObject *callargs = NULL;
    PyObject *callkw = NULL;
    PyObject *callable;

    if (PyArg_ParseTuple(args, "O|OO:runcall",
                         &callable, &callargs, &callkw)) {
        if (is_available(self)) {
            do_start(self);
            result = PyEval_CallObjectWithKeywords(callable, callargs, callkw);
            do_stop(self);
        }
    }
    return result;
}

1095
PyDoc_STRVAR(runcode__doc__,
1096 1097
"runcode(code, globals[, locals])\n"
"Execute a code object while collecting profile data.  If locals is\n"
1098
"omitted, globals is used for the locals as well.");
1099 1100 1101 1102 1103 1104 1105 1106 1107 1108 1109 1110 1111 1112 1113 1114 1115 1116 1117 1118 1119 1120 1121 1122 1123 1124 1125 1126 1127 1128 1129 1130 1131 1132 1133

static PyObject *
profiler_runcode(ProfilerObject *self, PyObject *args)
{
    PyObject *result = NULL;
    PyCodeObject *code;
    PyObject *globals;
    PyObject *locals = NULL;

    if (PyArg_ParseTuple(args, "O!O!|O:runcode",
                         &PyCode_Type, &code,
                         &PyDict_Type, &globals,
                         &locals)) {
        if (is_available(self)) {
            if (locals == NULL || locals == Py_None)
                locals = globals;
            else if (!PyDict_Check(locals)) {
                PyErr_SetString(PyExc_TypeError,
                                "locals must be a dictionary or None");
                return NULL;
            }
            do_start(self);
            result = PyEval_EvalCode(code, globals, locals);
            do_stop(self);
#if 0
            if (!PyErr_Occurred()) {
                result = Py_None;
                Py_INCREF(result);
            }
#endif
        }
    }
    return result;
}

1134
PyDoc_STRVAR(start__doc__,
1135
"start()\n"
1136
"Install this profiler for the current thread.");
1137 1138 1139 1140 1141 1142

static PyObject *
profiler_start(ProfilerObject *self, PyObject *args)
{
    PyObject *result = NULL;

1143 1144 1145 1146
    if (is_available(self)) {
        do_start(self);
        result = Py_None;
        Py_INCREF(result);
1147 1148 1149 1150
    }
    return result;
}

1151
PyDoc_STRVAR(stop__doc__,
1152
"stop()\n"
1153
"Remove this profiler from the current thread.");
1154 1155 1156 1157 1158 1159

static PyObject *
profiler_stop(ProfilerObject *self, PyObject *args)
{
    PyObject *result = NULL;

1160 1161 1162 1163 1164 1165
    if (!self->active)
        PyErr_SetString(ProfilerError, "profiler not active");
    else {
        do_stop(self);
        result = Py_None;
        Py_INCREF(result);
1166 1167 1168 1169 1170 1171 1172 1173 1174 1175 1176 1177 1178 1179 1180 1181 1182 1183 1184
    }
    return result;
}


/* Python API support. */

static void
profiler_dealloc(ProfilerObject *self)
{
    do_stop(self);
    if (self->logfp != NULL)
        fclose(self->logfp);
    Py_XDECREF(self->filemap);
    Py_XDECREF(self->logfilename);
    PyObject_Del((PyObject *)self);
}

static PyMethodDef profiler_methods[] = {
1185
    {"addinfo", (PyCFunction)profiler_addinfo, METH_VARARGS, addinfo__doc__},
1186 1187
    {"close",   (PyCFunction)profiler_close,   METH_NOARGS,  close__doc__},
    {"fileno",  (PyCFunction)profiler_fileno,  METH_NOARGS,  fileno__doc__},
1188 1189
    {"runcall", (PyCFunction)profiler_runcall, METH_VARARGS, runcall__doc__},
    {"runcode", (PyCFunction)profiler_runcode, METH_VARARGS, runcode__doc__},
1190 1191
    {"start",   (PyCFunction)profiler_start,   METH_NOARGS,  start__doc__},
    {"stop",    (PyCFunction)profiler_stop,    METH_NOARGS,  stop__doc__},
1192 1193 1194
    {NULL, NULL}
};

1195
static PyMemberDef profiler_members[] = {
1196 1197 1198
    {"frametimings", T_LONG, offsetof(ProfilerObject, linetimings), READONLY},
    {"lineevents",   T_LONG, offsetof(ProfilerObject, lineevents), READONLY},
    {"linetimings",  T_LONG, offsetof(ProfilerObject, linetimings), READONLY},
1199 1200 1201 1202
    {NULL}
};

static PyObject *
1203
profiler_get_closed(ProfilerObject *self, void *closure)
1204
{
1205 1206
    PyObject *result = (self->logfp == NULL) ? Py_True : Py_False;
    Py_INCREF(result);
1207 1208 1209
    return result;
}

1210
static PyGetSetDef profiler_getsets[] = {
1211
    {"closed", (getter)profiler_get_closed, NULL,
1212
     PyDoc_STR("True if the profiler's output file has already been closed.")},
1213 1214 1215
    {NULL}
};

1216

1217
PyDoc_STRVAR(profiler_object__doc__,
1218 1219 1220 1221
"High-performance profiler object.\n"
"\n"
"Methods:\n"
"\n"
1222
"close():      Stop the profiler and close the log files.\n"
1223
"fileno():     Returns the file descriptor of the log file.\n"
1224 1225 1226 1227
"runcall():    Run a single function call with profiling enabled.\n"
"runcode():    Execute a code object with profiling enabled.\n"
"start():      Install the profiler and return.\n"
"stop():       Remove the profiler.\n"
1228 1229 1230
"\n"
"Attributes (read-only):\n"
"\n"
1231 1232
"closed:       True if the profiler has already been closed.\n"
"frametimings: True if ENTER/EXIT events collect timing information.\n"
Michael W. Hudson's avatar
Michael W. Hudson committed
1233 1234
"lineevents:   True if line events are reported to the profiler.\n"
"linetimings:  True if line events collect timing information.");
1235 1236 1237 1238

static PyTypeObject ProfilerType = {
    PyObject_HEAD_INIT(NULL)
    0,					/* ob_size		*/
1239
    "_hotshot.ProfilerType",		/* tp_name		*/
1240 1241 1242 1243
    (int) sizeof(ProfilerObject),	/* tp_basicsize		*/
    0,					/* tp_itemsize		*/
    (destructor)profiler_dealloc,	/* tp_dealloc		*/
    0,					/* tp_print		*/
1244
    0,					/* tp_getattr		*/
1245 1246 1247 1248 1249 1250 1251 1252 1253
    0,					/* tp_setattr		*/
    0,					/* tp_compare		*/
    0,					/* tp_repr		*/
    0,					/* tp_as_number		*/
    0,					/* tp_as_sequence	*/
    0,					/* tp_as_mapping	*/
    0,					/* tp_hash		*/
    0,					/* tp_call		*/
    0,					/* tp_str		*/
1254
    PyObject_GenericGetAttr,		/* tp_getattro		*/
1255 1256
    0,					/* tp_setattro		*/
    0,					/* tp_as_buffer		*/
1257
    Py_TPFLAGS_DEFAULT,			/* tp_flags		*/
1258
    profiler_object__doc__,		/* tp_doc		*/
1259 1260 1261 1262 1263 1264 1265 1266 1267 1268 1269 1270 1271
    0,					/* tp_traverse		*/
    0,					/* tp_clear		*/
    0,					/* tp_richcompare	*/
    0,					/* tp_weaklistoffset	*/
    0,					/* tp_iter		*/
    0,					/* tp_iternext		*/
    profiler_methods,			/* tp_methods		*/
    profiler_members,			/* tp_members		*/
    profiler_getsets,			/* tp_getset		*/
    0,					/* tp_base		*/
    0,					/* tp_dict		*/
    0,					/* tp_descr_get		*/
    0,					/* tp_descr_set		*/
1272 1273 1274 1275
};


static PyMethodDef logreader_methods[] = {
1276
    {"close",   (PyCFunction)logreader_close,  METH_NOARGS,
1277
     logreader_close__doc__},
1278 1279
    {"fileno",  (PyCFunction)logreader_fileno, METH_NOARGS,
     logreader_fileno__doc__},
1280 1281 1282
    {NULL, NULL}
};

1283
static PyMemberDef logreader_members[] = {
1284 1285
    {"info", T_OBJECT, offsetof(LogReaderObject, info), RO,
     PyDoc_STR("Dictionary mapping informational keys to lists of values.")},
1286 1287
    {NULL}
};
1288 1289


1290 1291 1292
PyDoc_STRVAR(logreader__doc__,
"logreader(filename) --> log-iterator\n\
Create a log-reader for the timing information file.");
1293 1294 1295 1296 1297 1298 1299 1300 1301 1302 1303 1304 1305 1306

static PySequenceMethods logreader_as_sequence = {
    0,					/* sq_length */
    0,					/* sq_concat */
    0,					/* sq_repeat */
    (intargfunc)logreader_sq_item,	/* sq_item */
    0,					/* sq_slice */
    0,					/* sq_ass_item */
    0,					/* sq_ass_slice */
    0,					/* sq_contains */
    0,					/* sq_inplace_concat */
    0,					/* sq_inplace_repeat */
};

1307 1308 1309 1310 1311 1312 1313 1314 1315 1316 1317 1318 1319 1320
static PyObject *
logreader_get_closed(LogReaderObject *self, void *closure)
{
    PyObject *result = (self->logfp == NULL) ? Py_True : Py_False;
    Py_INCREF(result);
    return result;
}

static PyGetSetDef logreader_getsets[] = {
    {"closed", (getter)logreader_get_closed, NULL,
     PyDoc_STR("True if the logreader's input file has already been closed.")},
    {NULL}
};

1321 1322 1323
static PyTypeObject LogReaderType = {
    PyObject_HEAD_INIT(NULL)
    0,					/* ob_size		*/
1324
    "_hotshot.LogReaderType",		/* tp_name		*/
1325 1326 1327 1328
    (int) sizeof(LogReaderObject),	/* tp_basicsize		*/
    0,					/* tp_itemsize		*/
    (destructor)logreader_dealloc,	/* tp_dealloc		*/
    0,					/* tp_print		*/
1329
    0,					/* tp_getattr		*/
1330 1331 1332 1333 1334 1335 1336 1337 1338
    0,					/* tp_setattr		*/
    0,					/* tp_compare		*/
    0,					/* tp_repr		*/
    0,					/* tp_as_number		*/
    &logreader_as_sequence,		/* tp_as_sequence	*/
    0,					/* tp_as_mapping	*/
    0,					/* tp_hash		*/
    0,					/* tp_call		*/
    0,					/* tp_str		*/
1339
    PyObject_GenericGetAttr,		/* tp_getattro		*/
1340 1341
    0,					/* tp_setattro		*/
    0,					/* tp_as_buffer		*/
1342
    Py_TPFLAGS_DEFAULT,			/* tp_flags		*/
1343 1344 1345 1346 1347
    logreader__doc__,			/* tp_doc		*/
    0,					/* tp_traverse		*/
    0,					/* tp_clear		*/
    0,					/* tp_richcompare	*/
    0,					/* tp_weaklistoffset	*/
1348
    PyObject_GenericGetIter,		/* tp_iter		*/
1349
    (iternextfunc)logreader_tp_iternext,/* tp_iternext		*/
1350 1351
    logreader_methods,			/* tp_methods		*/
    logreader_members,			/* tp_members		*/
1352
    logreader_getsets,			/* tp_getset		*/
1353 1354 1355 1356
    0,					/* tp_base		*/
    0,					/* tp_dict		*/
    0,					/* tp_descr_get		*/
    0,					/* tp_descr_set		*/
1357 1358 1359 1360 1361 1362 1363
};

static PyObject *
hotshot_logreader(PyObject *unused, PyObject *args)
{
    LogReaderObject *self = NULL;
    char *filename;
1364 1365
    int c;
    int err = 0;
1366 1367 1368 1369

    if (PyArg_ParseTuple(args, "s:logreader", &filename)) {
        self = PyObject_New(LogReaderObject, &LogReaderType);
        if (self != NULL) {
1370
            self->frametimings = 1;
1371
            self->linetimings = 0;
1372
            self->info = NULL;
1373 1374 1375 1376 1377
            self->logfp = fopen(filename, "rb");
            if (self->logfp == NULL) {
                PyErr_SetFromErrnoWithFilename(PyExc_IOError, filename);
                Py_DECREF(self);
                self = NULL;
1378 1379 1380 1381 1382 1383 1384
                goto finally;
            }
            self->info = PyDict_New();
            if (self->info == NULL) {
                Py_DECREF(self);
                goto finally;
            }
1385 1386 1387
            /* read initial info */
            for (;;) {
                if ((c = fgetc(self->logfp)) == EOF) {
1388
                    eof_error(self);
1389 1390 1391 1392 1393 1394 1395
                    break;
                }
                if (c != WHAT_ADD_INFO) {
                    ungetc(c, self->logfp);
                    break;
                }
                err = unpack_add_info(self);
1396 1397
                if (err) {
                    if (err == ERR_EOF)
1398
                        eof_error(self);
1399 1400 1401 1402 1403
                    else
                        PyErr_SetString(PyExc_RuntimeError,
                                        "unexpected error");
                    break;
                }
1404 1405 1406
            }
        }
    }
1407
 finally:
1408 1409 1410 1411 1412 1413 1414 1415 1416 1417 1418 1419 1420 1421 1422 1423 1424
    return (PyObject *) self;
}


/* Return a Python string that represents the version number without the
 * extra cruft added by revision control, even if the right options were
 * given to the "cvs export" command to make it not include the extra
 * cruft.
 */
static char *
get_version_string(void)
{
    static char *rcsid = "$Revision$";
    char *rev = rcsid;
    char *buffer;
    int i = 0;

1425
    while (*rev && !isdigit((int)*rev))
1426 1427 1428 1429 1430 1431 1432 1433 1434 1435 1436 1437 1438 1439 1440 1441 1442 1443 1444 1445 1446 1447 1448 1449 1450 1451 1452
        ++rev;
    while (rev[i] != ' ' && rev[i] != '\0')
        ++i;
    buffer = malloc(i + 1);
    if (buffer != NULL) {
        memmove(buffer, rev, i);
        buffer[i] = '\0';
    }
    return buffer;
}

/* Write out a RFC 822-style header with various useful bits of
 * information to make the output easier to manage.
 */
static int
write_header(ProfilerObject *self)
{
    char *buffer;
    char cwdbuffer[PATH_MAX];
    PyObject *temp;
    int i, len;

    buffer = get_version_string();
    if (buffer == NULL) {
        PyErr_NoMemory();
        return -1;
    }
1453 1454 1455 1456
    pack_add_info(self, "hotshot-version", buffer);
    pack_add_info(self, "requested-frame-timings",
                  (self->frametimings ? "yes" : "no"));
    pack_add_info(self, "requested-line-events",
1457
                  (self->lineevents ? "yes" : "no"));
1458 1459 1460 1461
    pack_add_info(self, "requested-line-timings",
                  (self->linetimings ? "yes" : "no"));
    pack_add_info(self, "platform", Py_GetPlatform());
    pack_add_info(self, "executable", Py_GetProgramFullPath());
1462
    free(buffer);
1463 1464 1465 1466
    buffer = (char *) Py_GetVersion();
    if (buffer == NULL)
        PyErr_Clear();
    else
1467
        pack_add_info(self, "executable-version", buffer);
1468

1469
#ifdef MS_WINDOWS
1470
    PyOS_snprintf(cwdbuffer, sizeof(cwdbuffer), "%I64d", frequency.QuadPart);
1471
    pack_add_info(self, "reported-performance-frequency", cwdbuffer);
1472
#else
1473
    PyOS_snprintf(cwdbuffer, sizeof(cwdbuffer), "%lu", rusage_diff);
1474
    pack_add_info(self, "observed-interval-getrusage", cwdbuffer);
1475
    PyOS_snprintf(cwdbuffer, sizeof(cwdbuffer), "%lu", timeofday_diff);
1476
    pack_add_info(self, "observed-interval-gettimeofday", cwdbuffer);
1477 1478
#endif

1479
    pack_add_info(self, "current-directory",
1480 1481 1482 1483 1484 1485 1486
                  getcwd(cwdbuffer, sizeof cwdbuffer));

    temp = PySys_GetObject("path");
    len = PyList_GET_SIZE(temp);
    for (i = 0; i < len; ++i) {
        PyObject *item = PyList_GET_ITEM(temp, i);
        buffer = PyString_AsString(item);
1487 1488 1489 1490 1491 1492 1493
        if (buffer == NULL) {
            pack_add_info(self, "sys-path-entry", "<non-string-path-entry>");
            PyErr_Clear();
        }
        else {
            pack_add_info(self, "sys-path-entry", buffer);
        }
1494
    }
1495 1496 1497
    pack_frame_times(self);
    pack_line_times(self);

1498 1499 1500
    return 0;
}

1501 1502 1503
PyDoc_STRVAR(profiler__doc__,
"profiler(logfilename[, lineevents[, linetimes]]) -> profiler\n\
Create a new profiler object.");
1504 1505 1506 1507 1508 1509 1510 1511 1512 1513 1514 1515 1516 1517

static PyObject *
hotshot_profiler(PyObject *unused, PyObject *args)
{
    char *logfilename;
    ProfilerObject *self = NULL;
    int lineevents = 0;
    int linetimings = 1;

    if (PyArg_ParseTuple(args, "s|ii:profiler", &logfilename,
                         &lineevents, &linetimings)) {
        self = PyObject_New(ProfilerObject, &ProfilerType);
        if (self == NULL)
            return NULL;
1518
        self->frametimings = 1;
1519 1520 1521 1522 1523
        self->lineevents = lineevents ? 1 : 0;
        self->linetimings = (lineevents && linetimings) ? 1 : 0;
        self->index = 0;
        self->active = 0;
        self->next_fileno = 0;
1524
        self->logfp = NULL;
1525 1526 1527 1528 1529 1530 1531 1532 1533 1534 1535 1536 1537 1538 1539 1540 1541 1542 1543 1544 1545 1546 1547 1548 1549 1550 1551 1552 1553
        self->logfilename = PyTuple_GET_ITEM(args, 0);
        Py_INCREF(self->logfilename);
        self->filemap = PyDict_New();
        if (self->filemap == NULL) {
            Py_DECREF(self);
            return NULL;
        }
        self->logfp = fopen(logfilename, "wb");
        if (self->logfp == NULL) {
            Py_DECREF(self);
            PyErr_SetFromErrnoWithFilename(PyExc_IOError, logfilename);
            return NULL;
        }
        if (timeofday_diff == 0) {
            /* Run this several times since sometimes the first
             * doesn't give the lowest values, and we're really trying
             * to determine the lowest.
             */
            calibrate();
            calibrate();
            calibrate();
        }
        if (write_header(self))
            /* some error occurred, exception has been set */
            self = NULL;
    }
    return (PyObject *) self;
}

1554 1555
PyDoc_STRVAR(coverage__doc__,
"coverage(logfilename) -> profiler\n\
1556
Returns a profiler that doesn't collect any timing information, which is\n\
1557
useful in building a coverage analysis tool.");
1558 1559 1560 1561 1562 1563 1564 1565 1566 1567 1568 1569 1570 1571 1572 1573 1574 1575 1576

static PyObject *
hotshot_coverage(PyObject *unused, PyObject *args)
{
    char *logfilename;
    PyObject *result = NULL;

    if (PyArg_ParseTuple(args, "s:coverage", &logfilename)) {
        result = hotshot_profiler(unused, args);
        if (result != NULL) {
            ProfilerObject *self = (ProfilerObject *) result;
            self->frametimings = 0;
            self->linetimings = 0;
            self->lineevents = 1;
        }
    }
    return result;
}

1577
PyDoc_VAR(resolution__doc__) = 
1578
#ifdef MS_WINDOWS
1579
PyDoc_STR(
1580 1581 1582
"resolution() -> (performance-counter-ticks, update-frequency)\n"
"Return the resolution of the timer provided by the QueryPerformanceCounter()\n"
"function.  The first value is the smallest observed change, and the second\n"
1583 1584
"is the result of QueryPerformanceFrequency()."
)
1585
#else
1586
PyDoc_STR(
1587 1588
"resolution() -> (gettimeofday-usecs, getrusage-usecs)\n"
"Return the resolution of the timers provided by the gettimeofday() and\n"
1589 1590
"getrusage() system calls, or -1 if the call is not supported."
)
1591
#endif
1592
;
1593 1594 1595 1596 1597 1598 1599 1600 1601 1602 1603 1604

static PyObject *
hotshot_resolution(PyObject *unused, PyObject *args)
{
    PyObject *result = NULL;

    if (PyArg_ParseTuple(args, ":resolution")) {
        if (timeofday_diff == 0) {
            calibrate();
            calibrate();
            calibrate();
        }
1605
#ifdef MS_WINDOWS
1606 1607 1608 1609 1610 1611 1612 1613 1614 1615
        result = Py_BuildValue("ii", timeofday_diff, frequency.LowPart);
#else
        result = Py_BuildValue("ii", timeofday_diff, rusage_diff);
#endif
    }
    return result;
}


static PyMethodDef functions[] = {
1616
    {"coverage",   hotshot_coverage,   METH_VARARGS, coverage__doc__},
1617 1618 1619 1620 1621 1622 1623 1624 1625 1626 1627 1628 1629 1630 1631 1632 1633 1634 1635 1636 1637 1638 1639 1640 1641 1642 1643 1644 1645 1646 1647 1648 1649 1650 1651 1652 1653 1654 1655 1656
    {"profiler",   hotshot_profiler,   METH_VARARGS, profiler__doc__},
    {"logreader",  hotshot_logreader,  METH_VARARGS, logreader__doc__},
    {"resolution", hotshot_resolution, METH_VARARGS, resolution__doc__},
    {NULL, NULL}
};


void
init_hotshot(void)
{
    PyObject *module;

    LogReaderType.ob_type = &PyType_Type;
    ProfilerType.ob_type = &PyType_Type;
    module = Py_InitModule("_hotshot", functions);
    if (module != NULL) {
        char *s = get_version_string();

        PyModule_AddStringConstant(module, "__version__", s);
        free(s);
        Py_INCREF(&LogReaderType);
        PyModule_AddObject(module, "LogReaderType",
                           (PyObject *)&LogReaderType);
        Py_INCREF(&ProfilerType);
        PyModule_AddObject(module, "ProfilerType",
                           (PyObject *)&ProfilerType);

        if (ProfilerError == NULL)
            ProfilerError = PyErr_NewException("hotshot.ProfilerError",
                                               NULL, NULL);
        if (ProfilerError != NULL) {
            Py_INCREF(ProfilerError);
            PyModule_AddObject(module, "ProfilerError", ProfilerError);
        }
        PyModule_AddIntConstant(module, "WHAT_ENTER", WHAT_ENTER);
        PyModule_AddIntConstant(module, "WHAT_EXIT", WHAT_EXIT);
        PyModule_AddIntConstant(module, "WHAT_LINENO", WHAT_LINENO);
        PyModule_AddIntConstant(module, "WHAT_OTHER", WHAT_OTHER);
        PyModule_AddIntConstant(module, "WHAT_ADD_INFO", WHAT_ADD_INFO);
        PyModule_AddIntConstant(module, "WHAT_DEFINE_FILE", WHAT_DEFINE_FILE);
1657
        PyModule_AddIntConstant(module, "WHAT_DEFINE_FUNC", WHAT_DEFINE_FUNC);
1658 1659 1660
        PyModule_AddIntConstant(module, "WHAT_LINE_TIMES", WHAT_LINE_TIMES);
    }
}