|
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 } |
|
1136 |
|
1137 PyDoc_STRVAR(stop__doc__, |
|
1138 "stop()\n" |
|
1139 "Remove this profiler from the current thread."); |
|
1140 |
|
1141 static PyObject * |
|
1142 profiler_stop(ProfilerObject *self, PyObject *args) |
|
1143 { |
|
1144 PyObject *result = NULL; |
|
1145 |
|
1146 if (!self->active) |
|
1147 PyErr_SetString(ProfilerError, "profiler not active"); |
|
1148 else { |
|
1149 do_stop(self); |
|
1150 result = Py_None; |
|
1151 Py_INCREF(result); |
|
1152 } |
|
1153 return result; |
|
1154 } |
|
1155 |
|
1156 |
|
1157 /* Python API support. */ |
|
1158 |
|
1159 static void |
|
1160 profiler_dealloc(ProfilerObject *self) |
|
1161 { |
|
1162 do_stop(self); |
|
1163 if (self->logfp != NULL) |
|
1164 fclose(self->logfp); |
|
1165 Py_XDECREF(self->filemap); |
|
1166 Py_XDECREF(self->logfilename); |
|
1167 PyObject_Del((PyObject *)self); |
|
1168 } |
|
1169 |
|
1170 static PyMethodDef profiler_methods[] = { |
|
1171 {"addinfo", (PyCFunction)profiler_addinfo, METH_VARARGS, addinfo__doc__}, |
|
1172 {"close", (PyCFunction)profiler_close, METH_NOARGS, close__doc__}, |
|
1173 {"fileno", (PyCFunction)profiler_fileno, METH_NOARGS, fileno__doc__}, |
|
1174 {"runcall", (PyCFunction)profiler_runcall, METH_VARARGS, runcall__doc__}, |
|
1175 {"runcode", (PyCFunction)profiler_runcode, METH_VARARGS, runcode__doc__}, |
|
1176 {"start", (PyCFunction)profiler_start, METH_NOARGS, start__doc__}, |
|
1177 {"stop", (PyCFunction)profiler_stop, METH_NOARGS, stop__doc__}, |
|
1178 {NULL, NULL} |
|
1179 }; |
|
1180 |
|
1181 static PyMemberDef profiler_members[] = { |
|
1182 {"frametimings", T_LONG, offsetof(ProfilerObject, linetimings), READONLY}, |
|
1183 {"lineevents", T_LONG, offsetof(ProfilerObject, lineevents), READONLY}, |
|
1184 {"linetimings", T_LONG, offsetof(ProfilerObject, linetimings), READONLY}, |
|
1185 {NULL} |
|
1186 }; |
|
1187 |
|
1188 static PyObject * |
|
1189 profiler_get_closed(ProfilerObject *self, void *closure) |
|
1190 { |
|
1191 PyObject *result = (self->logfp == NULL) ? Py_True : Py_False; |
|
1192 Py_INCREF(result); |
|
1193 return result; |
|
1194 } |
|
1195 |
|
1196 static PyGetSetDef profiler_getsets[] = { |
|
1197 {"closed", (getter)profiler_get_closed, NULL, |
|
1198 PyDoc_STR("True if the profiler's output file has already been closed.")}, |
|
1199 {NULL} |
|
1200 }; |
|
1201 |
|
1202 |
|
1203 PyDoc_STRVAR(profiler_object__doc__, |
|
1204 "High-performance profiler object.\n" |
|
1205 "\n" |
|
1206 "Methods:\n" |
|
1207 "\n" |
|
1208 "close(): Stop the profiler and close the log files.\n" |
|
1209 "fileno(): Returns the file descriptor of the log file.\n" |
|
1210 "runcall(): Run a single function call with profiling enabled.\n" |
|
1211 "runcode(): Execute a code object with profiling enabled.\n" |
|
1212 "start(): Install the profiler and return.\n" |
|
1213 "stop(): Remove the profiler.\n" |
|
1214 "\n" |
|
1215 "Attributes (read-only):\n" |
|
1216 "\n" |
|
1217 "closed: True if the profiler has already been closed.\n" |
|
1218 "frametimings: True if ENTER/EXIT events collect timing information.\n" |
|
1219 "lineevents: True if line events are reported to the profiler.\n" |
|
1220 "linetimings: True if line events collect timing information."); |
|
1221 |
|
1222 static PyTypeObject ProfilerType = { |
|
1223 PyVarObject_HEAD_INIT(NULL, 0) |
|
1224 "_hotshot.ProfilerType", /* tp_name */ |
|
1225 (int) sizeof(ProfilerObject), /* tp_basicsize */ |
|
1226 0, /* tp_itemsize */ |
|
1227 (destructor)profiler_dealloc, /* tp_dealloc */ |
|
1228 0, /* tp_print */ |
|
1229 0, /* tp_getattr */ |
|
1230 0, /* tp_setattr */ |
|
1231 0, /* tp_compare */ |
|
1232 0, /* tp_repr */ |
|
1233 0, /* tp_as_number */ |
|
1234 0, /* tp_as_sequence */ |
|
1235 0, /* tp_as_mapping */ |
|
1236 0, /* tp_hash */ |
|
1237 0, /* tp_call */ |
|
1238 0, /* tp_str */ |
|
1239 PyObject_GenericGetAttr, /* tp_getattro */ |
|
1240 0, /* tp_setattro */ |
|
1241 0, /* tp_as_buffer */ |
|
1242 Py_TPFLAGS_DEFAULT, /* tp_flags */ |
|
1243 profiler_object__doc__, /* tp_doc */ |
|
1244 0, /* tp_traverse */ |
|
1245 0, /* tp_clear */ |
|
1246 0, /* tp_richcompare */ |
|
1247 0, /* tp_weaklistoffset */ |
|
1248 0, /* tp_iter */ |
|
1249 0, /* tp_iternext */ |
|
1250 profiler_methods, /* tp_methods */ |
|
1251 profiler_members, /* tp_members */ |
|
1252 profiler_getsets, /* tp_getset */ |
|
1253 0, /* tp_base */ |
|
1254 0, /* tp_dict */ |
|
1255 0, /* tp_descr_get */ |
|
1256 0, /* tp_descr_set */ |
|
1257 }; |
|
1258 |
|
1259 |
|
1260 static PyMethodDef logreader_methods[] = { |
|
1261 {"close", (PyCFunction)logreader_close, METH_NOARGS, |
|
1262 logreader_close__doc__}, |
|
1263 {"fileno", (PyCFunction)logreader_fileno, METH_NOARGS, |
|
1264 logreader_fileno__doc__}, |
|
1265 {NULL, NULL} |
|
1266 }; |
|
1267 |
|
1268 static PyMemberDef logreader_members[] = { |
|
1269 {"info", T_OBJECT, offsetof(LogReaderObject, info), RO, |
|
1270 PyDoc_STR("Dictionary mapping informational keys to lists of values.")}, |
|
1271 {NULL} |
|
1272 }; |
|
1273 |
|
1274 |
|
1275 PyDoc_STRVAR(logreader__doc__, |
|
1276 "logreader(filename) --> log-iterator\n\ |
|
1277 Create a log-reader for the timing information file."); |
|
1278 |
|
1279 static PySequenceMethods logreader_as_sequence = { |
|
1280 0, /* sq_length */ |
|
1281 0, /* sq_concat */ |
|
1282 0, /* sq_repeat */ |
|
1283 (ssizeargfunc)logreader_sq_item, /* sq_item */ |
|
1284 0, /* sq_slice */ |
|
1285 0, /* sq_ass_item */ |
|
1286 0, /* sq_ass_slice */ |
|
1287 0, /* sq_contains */ |
|
1288 0, /* sq_inplace_concat */ |
|
1289 0, /* sq_inplace_repeat */ |
|
1290 }; |
|
1291 |
|
1292 static PyObject * |
|
1293 logreader_get_closed(LogReaderObject *self, void *closure) |
|
1294 { |
|
1295 PyObject *result = (self->logfp == NULL) ? Py_True : Py_False; |
|
1296 Py_INCREF(result); |
|
1297 return result; |
|
1298 } |
|
1299 |
|
1300 static PyGetSetDef logreader_getsets[] = { |
|
1301 {"closed", (getter)logreader_get_closed, NULL, |
|
1302 PyDoc_STR("True if the logreader's input file has already been closed.")}, |
|
1303 {NULL} |
|
1304 }; |
|
1305 |
|
1306 static PyTypeObject LogReaderType = { |
|
1307 PyVarObject_HEAD_INIT(NULL, 0) |
|
1308 "_hotshot.LogReaderType", /* tp_name */ |
|
1309 (int) sizeof(LogReaderObject), /* tp_basicsize */ |
|
1310 0, /* tp_itemsize */ |
|
1311 (destructor)logreader_dealloc, /* tp_dealloc */ |
|
1312 0, /* tp_print */ |
|
1313 0, /* tp_getattr */ |
|
1314 0, /* tp_setattr */ |
|
1315 0, /* tp_compare */ |
|
1316 0, /* tp_repr */ |
|
1317 0, /* tp_as_number */ |
|
1318 &logreader_as_sequence, /* tp_as_sequence */ |
|
1319 0, /* tp_as_mapping */ |
|
1320 0, /* tp_hash */ |
|
1321 0, /* tp_call */ |
|
1322 0, /* tp_str */ |
|
1323 PyObject_GenericGetAttr, /* tp_getattro */ |
|
1324 0, /* tp_setattro */ |
|
1325 0, /* tp_as_buffer */ |
|
1326 Py_TPFLAGS_DEFAULT, /* tp_flags */ |
|
1327 logreader__doc__, /* tp_doc */ |
|
1328 0, /* tp_traverse */ |
|
1329 0, /* tp_clear */ |
|
1330 0, /* tp_richcompare */ |
|
1331 0, /* tp_weaklistoffset */ |
|
1332 PyObject_SelfIter, /* tp_iter */ |
|
1333 (iternextfunc)logreader_tp_iternext,/* tp_iternext */ |
|
1334 logreader_methods, /* tp_methods */ |
|
1335 logreader_members, /* tp_members */ |
|
1336 logreader_getsets, /* tp_getset */ |
|
1337 0, /* tp_base */ |
|
1338 0, /* tp_dict */ |
|
1339 0, /* tp_descr_get */ |
|
1340 0, /* tp_descr_set */ |
|
1341 }; |
|
1342 |
|
1343 static PyObject * |
|
1344 hotshot_logreader(PyObject *unused, PyObject *args) |
|
1345 { |
|
1346 LogReaderObject *self = NULL; |
|
1347 char *filename; |
|
1348 int c; |
|
1349 int err = 0; |
|
1350 |
|
1351 if (PyArg_ParseTuple(args, "s:logreader", &filename)) { |
|
1352 self = PyObject_New(LogReaderObject, &LogReaderType); |
|
1353 if (self != NULL) { |
|
1354 self->frametimings = 1; |
|
1355 self->linetimings = 0; |
|
1356 self->info = NULL; |
|
1357 self->logfp = fopen(filename, "rb"); |
|
1358 if (self->logfp == NULL) { |
|
1359 PyErr_SetFromErrnoWithFilename(PyExc_IOError, filename); |
|
1360 Py_DECREF(self); |
|
1361 self = NULL; |
|
1362 goto finally; |
|
1363 } |
|
1364 self->info = PyDict_New(); |
|
1365 if (self->info == NULL) { |
|
1366 Py_DECREF(self); |
|
1367 goto finally; |
|
1368 } |
|
1369 /* read initial info */ |
|
1370 for (;;) { |
|
1371 if ((c = fgetc(self->logfp)) == EOF) { |
|
1372 eof_error(self); |
|
1373 break; |
|
1374 } |
|
1375 if (c != WHAT_ADD_INFO) { |
|
1376 ungetc(c, self->logfp); |
|
1377 break; |
|
1378 } |
|
1379 err = unpack_add_info(self); |
|
1380 if (err) { |
|
1381 if (err == ERR_EOF) |
|
1382 eof_error(self); |
|
1383 else |
|
1384 PyErr_SetString(PyExc_RuntimeError, |
|
1385 "unexpected error"); |
|
1386 break; |
|
1387 } |
|
1388 } |
|
1389 } |
|
1390 } |
|
1391 finally: |
|
1392 return (PyObject *) self; |
|
1393 } |
|
1394 |
|
1395 |
|
1396 /* Return a Python string that represents the version number without the |
|
1397 * extra cruft added by revision control, even if the right options were |
|
1398 * given to the "cvs export" command to make it not include the extra |
|
1399 * cruft. |
|
1400 */ |
|
1401 static char * |
|
1402 get_version_string(void) |
|
1403 { |
|
1404 static char *rcsid = "$Revision: 64048 $"; |
|
1405 char *rev = rcsid; |
|
1406 char *buffer; |
|
1407 int i = 0; |
|
1408 |
|
1409 while (*rev && !isdigit(Py_CHARMASK(*rev))) |
|
1410 ++rev; |
|
1411 while (rev[i] != ' ' && rev[i] != '\0') |
|
1412 ++i; |
|
1413 buffer = (char *)malloc(i + 1); |
|
1414 if (buffer != NULL) { |
|
1415 memmove(buffer, rev, i); |
|
1416 buffer[i] = '\0'; |
|
1417 } |
|
1418 return buffer; |
|
1419 } |
|
1420 |
|
1421 /* Write out a RFC 822-style header with various useful bits of |
|
1422 * information to make the output easier to manage. |
|
1423 */ |
|
1424 static int |
|
1425 write_header(ProfilerObject *self) |
|
1426 { |
|
1427 char *buffer; |
|
1428 char cwdbuffer[PATH_MAX]; |
|
1429 PyObject *temp; |
|
1430 Py_ssize_t i, len; |
|
1431 |
|
1432 buffer = get_version_string(); |
|
1433 if (buffer == NULL) { |
|
1434 PyErr_NoMemory(); |
|
1435 return -1; |
|
1436 } |
|
1437 pack_add_info(self, "hotshot-version", buffer); |
|
1438 pack_add_info(self, "requested-frame-timings", |
|
1439 (self->frametimings ? "yes" : "no")); |
|
1440 pack_add_info(self, "requested-line-events", |
|
1441 (self->lineevents ? "yes" : "no")); |
|
1442 pack_add_info(self, "requested-line-timings", |
|
1443 (self->linetimings ? "yes" : "no")); |
|
1444 pack_add_info(self, "platform", Py_GetPlatform()); |
|
1445 pack_add_info(self, "executable", Py_GetProgramFullPath()); |
|
1446 free(buffer); |
|
1447 buffer = (char *) Py_GetVersion(); |
|
1448 if (buffer == NULL) |
|
1449 PyErr_Clear(); |
|
1450 else |
|
1451 pack_add_info(self, "executable-version", buffer); |
|
1452 |
|
1453 #ifdef MS_WINDOWS |
|
1454 PyOS_snprintf(cwdbuffer, sizeof(cwdbuffer), "%I64d", frequency.QuadPart); |
|
1455 pack_add_info(self, "reported-performance-frequency", cwdbuffer); |
|
1456 #else |
|
1457 PyOS_snprintf(cwdbuffer, sizeof(cwdbuffer), "%lu", rusage_diff); |
|
1458 pack_add_info(self, "observed-interval-getrusage", cwdbuffer); |
|
1459 PyOS_snprintf(cwdbuffer, sizeof(cwdbuffer), "%lu", timeofday_diff); |
|
1460 pack_add_info(self, "observed-interval-gettimeofday", cwdbuffer); |
|
1461 #endif |
|
1462 |
|
1463 pack_add_info(self, "current-directory", |
|
1464 getcwd(cwdbuffer, sizeof cwdbuffer)); |
|
1465 |
|
1466 temp = PySys_GetObject("path"); |
|
1467 if (temp == NULL || !PyList_Check(temp)) { |
|
1468 PyErr_SetString(PyExc_RuntimeError, "sys.path must be a list"); |
|
1469 return -1; |
|
1470 } |
|
1471 len = PyList_GET_SIZE(temp); |
|
1472 for (i = 0; i < len; ++i) { |
|
1473 PyObject *item = PyList_GET_ITEM(temp, i); |
|
1474 buffer = PyString_AsString(item); |
|
1475 if (buffer == NULL) { |
|
1476 pack_add_info(self, "sys-path-entry", "<non-string-path-entry>"); |
|
1477 PyErr_Clear(); |
|
1478 } |
|
1479 else { |
|
1480 pack_add_info(self, "sys-path-entry", buffer); |
|
1481 } |
|
1482 } |
|
1483 pack_frame_times(self); |
|
1484 pack_line_times(self); |
|
1485 |
|
1486 return 0; |
|
1487 } |
|
1488 |
|
1489 PyDoc_STRVAR(profiler__doc__, |
|
1490 "profiler(logfilename[, lineevents[, linetimes]]) -> profiler\n\ |
|
1491 Create a new profiler object."); |
|
1492 |
|
1493 static PyObject * |
|
1494 hotshot_profiler(PyObject *unused, PyObject *args) |
|
1495 { |
|
1496 char *logfilename; |
|
1497 ProfilerObject *self = NULL; |
|
1498 int lineevents = 0; |
|
1499 int linetimings = 1; |
|
1500 |
|
1501 if (PyArg_ParseTuple(args, "s|ii:profiler", &logfilename, |
|
1502 &lineevents, &linetimings)) { |
|
1503 self = PyObject_New(ProfilerObject, &ProfilerType); |
|
1504 if (self == NULL) |
|
1505 return NULL; |
|
1506 self->frametimings = 1; |
|
1507 self->lineevents = lineevents ? 1 : 0; |
|
1508 self->linetimings = (lineevents && linetimings) ? 1 : 0; |
|
1509 self->index = 0; |
|
1510 self->active = 0; |
|
1511 self->next_fileno = 0; |
|
1512 self->logfp = NULL; |
|
1513 self->logfilename = PyTuple_GET_ITEM(args, 0); |
|
1514 Py_INCREF(self->logfilename); |
|
1515 self->filemap = PyDict_New(); |
|
1516 if (self->filemap == NULL) { |
|
1517 Py_DECREF(self); |
|
1518 return NULL; |
|
1519 } |
|
1520 self->logfp = fopen(logfilename, "wb"); |
|
1521 if (self->logfp == NULL) { |
|
1522 Py_DECREF(self); |
|
1523 PyErr_SetFromErrnoWithFilename(PyExc_IOError, logfilename); |
|
1524 return NULL; |
|
1525 } |
|
1526 if (timeofday_diff == 0) { |
|
1527 /* Run this several times since sometimes the first |
|
1528 * doesn't give the lowest values, and we're really trying |
|
1529 * to determine the lowest. |
|
1530 */ |
|
1531 calibrate(); |
|
1532 calibrate(); |
|
1533 calibrate(); |
|
1534 } |
|
1535 if (write_header(self)) { |
|
1536 /* some error occurred, exception has been set */ |
|
1537 Py_DECREF(self); |
|
1538 self = NULL; |
|
1539 } |
|
1540 } |
|
1541 return (PyObject *) self; |
|
1542 } |
|
1543 |
|
1544 PyDoc_STRVAR(coverage__doc__, |
|
1545 "coverage(logfilename) -> profiler\n\ |
|
1546 Returns a profiler that doesn't collect any timing information, which is\n\ |
|
1547 useful in building a coverage analysis tool."); |
|
1548 |
|
1549 static PyObject * |
|
1550 hotshot_coverage(PyObject *unused, PyObject *args) |
|
1551 { |
|
1552 char *logfilename; |
|
1553 PyObject *result = NULL; |
|
1554 |
|
1555 if (PyArg_ParseTuple(args, "s:coverage", &logfilename)) { |
|
1556 result = hotshot_profiler(unused, args); |
|
1557 if (result != NULL) { |
|
1558 ProfilerObject *self = (ProfilerObject *) result; |
|
1559 self->frametimings = 0; |
|
1560 self->linetimings = 0; |
|
1561 self->lineevents = 1; |
|
1562 } |
|
1563 } |
|
1564 return result; |
|
1565 } |
|
1566 |
|
1567 PyDoc_VAR(resolution__doc__) = |
|
1568 #ifdef MS_WINDOWS |
|
1569 PyDoc_STR( |
|
1570 "resolution() -> (performance-counter-ticks, update-frequency)\n" |
|
1571 "Return the resolution of the timer provided by the QueryPerformanceCounter()\n" |
|
1572 "function. The first value is the smallest observed change, and the second\n" |
|
1573 "is the result of QueryPerformanceFrequency()." |
|
1574 ) |
|
1575 #else |
|
1576 PyDoc_STR( |
|
1577 "resolution() -> (gettimeofday-usecs, getrusage-usecs)\n" |
|
1578 "Return the resolution of the timers provided by the gettimeofday() and\n" |
|
1579 "getrusage() system calls, or -1 if the call is not supported." |
|
1580 ) |
|
1581 #endif |
|
1582 ; |
|
1583 |
|
1584 static PyObject * |
|
1585 hotshot_resolution(PyObject *self, PyObject *unused) |
|
1586 { |
|
1587 if (timeofday_diff == 0) { |
|
1588 calibrate(); |
|
1589 calibrate(); |
|
1590 calibrate(); |
|
1591 } |
|
1592 #ifdef MS_WINDOWS |
|
1593 return Py_BuildValue("ii", timeofday_diff, frequency.LowPart); |
|
1594 #else |
|
1595 return Py_BuildValue("ii", timeofday_diff, rusage_diff); |
|
1596 #endif |
|
1597 } |
|
1598 |
|
1599 |
|
1600 static PyMethodDef functions[] = { |
|
1601 {"coverage", hotshot_coverage, METH_VARARGS, coverage__doc__}, |
|
1602 {"profiler", hotshot_profiler, METH_VARARGS, profiler__doc__}, |
|
1603 {"logreader", hotshot_logreader, METH_VARARGS, logreader__doc__}, |
|
1604 {"resolution", hotshot_resolution, METH_NOARGS, resolution__doc__}, |
|
1605 {NULL, NULL} |
|
1606 }; |
|
1607 |
|
1608 |
|
1609 void |
|
1610 init_hotshot(void) |
|
1611 { |
|
1612 PyObject *module; |
|
1613 |
|
1614 Py_TYPE(&LogReaderType) = &PyType_Type; |
|
1615 Py_TYPE(&ProfilerType) = &PyType_Type; |
|
1616 module = Py_InitModule("_hotshot", functions); |
|
1617 if (module != NULL) { |
|
1618 char *s = get_version_string(); |
|
1619 |
|
1620 PyModule_AddStringConstant(module, "__version__", s); |
|
1621 free(s); |
|
1622 Py_INCREF(&LogReaderType); |
|
1623 PyModule_AddObject(module, "LogReaderType", |
|
1624 (PyObject *)&LogReaderType); |
|
1625 Py_INCREF(&ProfilerType); |
|
1626 PyModule_AddObject(module, "ProfilerType", |
|
1627 (PyObject *)&ProfilerType); |
|
1628 |
|
1629 if (ProfilerError == NULL) |
|
1630 ProfilerError = PyErr_NewException("hotshot.ProfilerError", |
|
1631 NULL, NULL); |
|
1632 if (ProfilerError != NULL) { |
|
1633 Py_INCREF(ProfilerError); |
|
1634 PyModule_AddObject(module, "ProfilerError", ProfilerError); |
|
1635 } |
|
1636 PyModule_AddIntConstant(module, "WHAT_ENTER", WHAT_ENTER); |
|
1637 PyModule_AddIntConstant(module, "WHAT_EXIT", WHAT_EXIT); |
|
1638 PyModule_AddIntConstant(module, "WHAT_LINENO", WHAT_LINENO); |
|
1639 PyModule_AddIntConstant(module, "WHAT_OTHER", WHAT_OTHER); |
|
1640 PyModule_AddIntConstant(module, "WHAT_ADD_INFO", WHAT_ADD_INFO); |
|
1641 PyModule_AddIntConstant(module, "WHAT_DEFINE_FILE", WHAT_DEFINE_FILE); |
|
1642 PyModule_AddIntConstant(module, "WHAT_DEFINE_FUNC", WHAT_DEFINE_FUNC); |
|
1643 PyModule_AddIntConstant(module, "WHAT_LINE_TIMES", WHAT_LINE_TIMES); |
|
1644 } |
|
1645 } |