diff options
| -rw-r--r-- | Doc/library/debug.rst | 1 | ||||
| -rw-r--r-- | Doc/library/hotshot.rst | 144 | ||||
| -rw-r--r-- | Doc/library/profile.rst | 8 | ||||
| -rw-r--r-- | Lib/hotshot/__init__.py | 76 | ||||
| -rw-r--r-- | Lib/hotshot/log.py | 192 | ||||
| -rw-r--r-- | Lib/hotshot/stats.py | 93 | ||||
| -rw-r--r-- | Lib/hotshot/stones.py | 31 | ||||
| -rw-r--r-- | Lib/test/test_hotshot.py | 132 | ||||
| -rw-r--r-- | Makefile.pre.in | 2 | ||||
| -rw-r--r-- | Misc/NEWS | 10 | ||||
| -rw-r--r-- | Modules/_hotshot.c | 1645 | ||||
| -rw-r--r-- | Tools/scripts/hotshotmain.py | 60 | ||||
| -rw-r--r-- | setup.py | 3 |
13 files changed, 14 insertions, 2383 deletions
diff --git a/Doc/library/debug.rst b/Doc/library/debug.rst index 7480087..b2ee4fa 100644 --- a/Doc/library/debug.rst +++ b/Doc/library/debug.rst @@ -12,6 +12,5 @@ allowing you to identify bottlenecks in your programs. bdb.rst pdb.rst profile.rst - hotshot.rst timeit.rst trace.rst
\ No newline at end of file diff --git a/Doc/library/hotshot.rst b/Doc/library/hotshot.rst deleted file mode 100644 index f10facd..0000000 --- a/Doc/library/hotshot.rst +++ /dev/null @@ -1,144 +0,0 @@ - -:mod:`hotshot` --- High performance logging profiler -==================================================== - -.. module:: hotshot - :synopsis: High performance logging profiler, mostly written in C. -.. moduleauthor:: Fred L. Drake, Jr. <fdrake@acm.org> -.. sectionauthor:: Anthony Baxter <anthony@interlink.com.au> - - -This module provides a nicer interface to the :mod:`_hotshot` C module. Hotshot -is a replacement for the existing :mod:`profile` module. As it's written mostly -in C, it should result in a much smaller performance impact than the existing -:mod:`profile` module. - -.. note:: - - The :mod:`hotshot` module focuses on minimizing the overhead while profiling, at - the expense of long data post-processing times. For common usages it is - recommended to use :mod:`cProfile` instead. :mod:`hotshot` is not maintained and - might be removed from the standard library in the future. - -.. warning:: - - The :mod:`hotshot` profiler does not yet work well with threads. It is useful to - use an unthreaded script to run the profiler over the code you're interested in - measuring if at all possible. - - -.. class:: Profile(logfile[, lineevents[, linetimings]]) - - The profiler object. The argument *logfile* is the name of a log file to use for - logged profile data. The argument *lineevents* specifies whether to generate - events for every source line, or just on function call/return. It defaults to - ``0`` (only log function call/return). The argument *linetimings* specifies - whether to record timing information. It defaults to ``1`` (store timing - information). - - -.. _hotshot-objects: - -Profile Objects ---------------- - -Profile objects have the following methods: - - -.. method:: Profile.addinfo(key, value) - - Add an arbitrary labelled value to the profile output. - - -.. method:: Profile.close() - - Close the logfile and terminate the profiler. - - -.. method:: Profile.fileno() - - Return the file descriptor of the profiler's log file. - - -.. method:: Profile.run(cmd) - - Profile an :func:`exec`\ -compatible string in the script environment. The - globals from the :mod:`__main__` module are used as both the globals and locals - for the script. - - -.. method:: Profile.runcall(func, *args, **keywords) - - Profile a single call of a callable. Additional positional and keyword arguments - may be passed along; the result of the call is returned, and exceptions are - allowed to propagate cleanly, while ensuring that profiling is disabled on the - way out. - - -.. method:: Profile.runctx(cmd, globals, locals) - - Profile an :func:`exec`\ -compatible string in a specific environment. The - string is compiled before profiling begins. - - -.. method:: Profile.start() - - Start the profiler. - - -.. method:: Profile.stop() - - Stop the profiler. - - -Using hotshot data ------------------- - -.. module:: hotshot.stats - :synopsis: Statistical analysis for Hotshot - - -This module loads hotshot profiling data into the standard :mod:`pstats` Stats -objects. - - -.. function:: load(filename) - - Load hotshot data from *filename*. Returns an instance of the - :class:`pstats.Stats` class. - - -.. seealso:: - - Module :mod:`profile` - The :mod:`profile` module's :class:`Stats` class - - -.. _hotshot-example: - -Example Usage -------------- - -Note that this example runs the python "benchmark" pystones. It can take some -time to run, and will produce large output files. :: - - >>> import hotshot, hotshot.stats, test.pystone - >>> prof = hotshot.Profile("stones.prof") - >>> benchtime, stones = prof.runcall(test.pystone.pystones) - >>> prof.close() - >>> stats = hotshot.stats.load("stones.prof") - >>> stats.strip_dirs() - >>> stats.sort_stats('time', 'calls') - >>> stats.print_stats(20) - 850004 function calls in 10.090 CPU seconds - - Ordered by: internal time, call count - - ncalls tottime percall cumtime percall filename:lineno(function) - 1 3.295 3.295 10.090 10.090 pystone.py:79(Proc0) - 150000 1.315 0.000 1.315 0.000 pystone.py:203(Proc7) - 50000 1.313 0.000 1.463 0.000 pystone.py:229(Func2) - . - . - . - diff --git a/Doc/library/profile.rst b/Doc/library/profile.rst index 0cbbd86..cc02436 100644 --- a/Doc/library/profile.rst +++ b/Doc/library/profile.rst @@ -57,7 +57,7 @@ This profiler provides :dfn:`deterministic profiling` of any Python programs. It also provides a series of report generation tools to allow users to rapidly examine the results of a profile operation. -The Python standard library provides three different profilers: +The Python standard library provides two different profilers: #. :mod:`profile`, a pure Python module, described in the sequel. Copyright © 1994, by InfoSeek Corporation. @@ -66,15 +66,11 @@ The Python standard library provides three different profilers: it suitable for profiling long-running programs. Based on :mod:`lsprof`, contributed by Brett Rosen and Ted Czotter. -#. :mod:`hotshot`, a C module focusing on minimizing the overhead while - profiling, at the expense of long data post-processing times. - The :mod:`profile` and :mod:`cProfile` modules export the same interface, so they are mostly interchangeables; :mod:`cProfile` has a much lower overhead but is not so far as well-tested and might not be available on all systems. :mod:`cProfile` is really a compatibility layer on top of the internal -:mod:`_lsprof` module. The :mod:`hotshot` module is reserved to specialized -usages. +:mod:`_lsprof` module. .. % \section{How Is This Profiler Different From The Old Profiler?} .. % \nodename{Profiler Changes} diff --git a/Lib/hotshot/__init__.py b/Lib/hotshot/__init__.py deleted file mode 100644 index b9f7866..0000000 --- a/Lib/hotshot/__init__.py +++ /dev/null @@ -1,76 +0,0 @@ -"""High-perfomance logging profiler, mostly written in C.""" - -import _hotshot - -from _hotshot import ProfilerError - - -class Profile: - def __init__(self, logfn, lineevents=0, linetimings=1): - self.lineevents = lineevents and 1 or 0 - self.linetimings = (linetimings and lineevents) and 1 or 0 - self._prof = p = _hotshot.profiler( - logfn, self.lineevents, self.linetimings) - - # Attempt to avoid confusing results caused by the presence of - # Python wrappers around these functions, but only if we can - # be sure the methods have not been overridden or extended. - if self.__class__ is Profile: - self.close = p.close - self.start = p.start - self.stop = p.stop - self.addinfo = p.addinfo - - def close(self): - """Close the logfile and terminate the profiler.""" - self._prof.close() - - def fileno(self): - """Return the file descriptor of the profiler's log file.""" - return self._prof.fileno() - - def start(self): - """Start the profiler.""" - self._prof.start() - - def stop(self): - """Stop the profiler.""" - self._prof.stop() - - def addinfo(self, key, value): - """Add an arbitrary labelled value to the profile log.""" - self._prof.addinfo(key, value) - - # These methods offer the same interface as the profile.Profile class, - # but delegate most of the work to the C implementation underneath. - - def run(self, cmd): - """Profile an exec-compatible string in the script - environment. - - The globals from the __main__ module are used as both the - globals and locals for the script. - """ - import __main__ - dict = __main__.__dict__ - return self.runctx(cmd, dict, dict) - - def runctx(self, cmd, globals, locals): - """Evaluate an exec-compatible string in a specific - environment. - - The string is compiled before profiling begins. - """ - code = compile(cmd, "<string>", "exec") - self._prof.runcode(code, globals, locals) - return self - - def runcall(self, func, *args, **kw): - """Profile a single call of a callable. - - Additional positional and keyword arguments may be passed - along; the result of the call is returned, and exceptions are - allowed to propogate cleanly, while ensuring that profiling is - disabled on the way out. - """ - return self._prof.runcall(func, args, kw) diff --git a/Lib/hotshot/log.py b/Lib/hotshot/log.py deleted file mode 100644 index b211825..0000000 --- a/Lib/hotshot/log.py +++ /dev/null @@ -1,192 +0,0 @@ -import _hotshot -import os.path -import parser -import symbol -import sys - -from _hotshot import \ - WHAT_ENTER, \ - WHAT_EXIT, \ - WHAT_LINENO, \ - WHAT_DEFINE_FILE, \ - WHAT_DEFINE_FUNC, \ - WHAT_ADD_INFO - - -__all__ = ["LogReader", "ENTER", "EXIT", "LINE"] - - -ENTER = WHAT_ENTER -EXIT = WHAT_EXIT -LINE = WHAT_LINENO - - -class LogReader: - def __init__(self, logfn): - # fileno -> filename - self._filemap = {} - # (fileno, lineno) -> filename, funcname - self._funcmap = {} - - self._reader = _hotshot.logreader(logfn) - self._nextitem = self._reader.__next__ - self._info = self._reader.info - if 'current-directory' in self._info: - self.cwd = self._info['current-directory'] - else: - self.cwd = None - - # This mirrors the call stack of the profiled code as the log - # is read back in. It contains tuples of the form: - # - # (file name, line number of function def, function name) - # - self._stack = [] - self._append = self._stack.append - self._pop = self._stack.pop - - def close(self): - self._reader.close() - - def fileno(self): - """Return the file descriptor of the log reader's log file.""" - return self._reader.fileno() - - def addinfo(self, key, value): - """This method is called for each additional ADD_INFO record. - - This can be overridden by applications that want to receive - these events. The default implementation does not need to be - called by alternate implementations. - - The initial set of ADD_INFO records do not pass through this - mechanism; this is only needed to receive notification when - new values are added. Subclasses can inspect self._info after - calling LogReader.__init__(). - """ - pass - - def get_filename(self, fileno): - try: - return self._filemap[fileno] - except KeyError: - raise ValueError("unknown fileno") - - def get_filenames(self): - return self._filemap.values() - - def get_fileno(self, filename): - filename = os.path.normcase(os.path.normpath(filename)) - for fileno, name in self._filemap.items(): - if name == filename: - return fileno - raise ValueError("unknown filename") - - def get_funcname(self, fileno, lineno): - try: - return self._funcmap[(fileno, lineno)] - except KeyError: - raise ValueError("unknown function location") - - # Iteration support: - # This adds an optional (& ignored) parameter to next() so that the - # same bound method can be used as the __getitem__() method -- this - # avoids using an additional method call which kills the performance. - - def __next__(self, index=0): - while 1: - # This call may raise StopIteration: - what, tdelta, fileno, lineno = self._nextitem() - - # handle the most common cases first - - if what == WHAT_ENTER: - filename, funcname = self._decode_location(fileno, lineno) - t = (filename, lineno, funcname) - self._append(t) - return what, t, tdelta - - if what == WHAT_EXIT: - return what, self._pop(), tdelta - - if what == WHAT_LINENO: - filename, firstlineno, funcname = self._stack[-1] - return what, (filename, lineno, funcname), tdelta - - if what == WHAT_DEFINE_FILE: - filename = os.path.normcase(os.path.normpath(tdelta)) - self._filemap[fileno] = filename - elif what == WHAT_DEFINE_FUNC: - filename = self._filemap[fileno] - self._funcmap[(fileno, lineno)] = (filename, tdelta) - elif what == WHAT_ADD_INFO: - # value already loaded into self.info; call the - # overridable addinfo() handler so higher-level code - # can pick up the new value - if tdelta == 'current-directory': - self.cwd = lineno - self.addinfo(tdelta, lineno) - else: - raise ValueError("unknown event type") - - def __iter__(self): - return self - - # - # helpers - # - - def _decode_location(self, fileno, lineno): - try: - return self._funcmap[(fileno, lineno)] - except KeyError: - # - # This should only be needed when the log file does not - # contain all the DEFINE_FUNC records needed to allow the - # function name to be retrieved from the log file. - # - if self._loadfile(fileno): - filename = funcname = None - try: - filename, funcname = self._funcmap[(fileno, lineno)] - except KeyError: - filename = self._filemap.get(fileno) - funcname = None - self._funcmap[(fileno, lineno)] = (filename, funcname) - return filename, funcname - - def _loadfile(self, fileno): - try: - filename = self._filemap[fileno] - except KeyError: - print("Could not identify fileId", fileno) - return 1 - if filename is None: - return 1 - absname = os.path.normcase(os.path.join(self.cwd, filename)) - - try: - fp = open(absname) - except IOError: - return - st = parser.suite(fp.read()) - fp.close() - - # Scan the tree looking for def and lambda nodes, filling in - # self._funcmap with all the available information. - funcdef = symbol.funcdef - lambdef = symbol.lambdef - - stack = [st.totuple(1)] - - while stack: - tree = stack.pop() - try: - sym = tree[0] - except (IndexError, TypeError): - continue - if sym == funcdef: - self._funcmap[(fileno, tree[2][2])] = filename, tree[2][1] - elif sym == lambdef: - self._funcmap[(fileno, tree[1][2])] = filename, "<lambda>" - stack.extend(list(tree[1:])) diff --git a/Lib/hotshot/stats.py b/Lib/hotshot/stats.py deleted file mode 100644 index e927bd5..0000000 --- a/Lib/hotshot/stats.py +++ /dev/null @@ -1,93 +0,0 @@ -"""Statistics analyzer for HotShot.""" - -import profile -import pstats - -import hotshot.log - -from hotshot.log import ENTER, EXIT - - -def load(filename): - return StatsLoader(filename).load() - - -class StatsLoader: - def __init__(self, logfn): - self._logfn = logfn - self._code = {} - self._stack = [] - self.pop_frame = self._stack.pop - - def load(self): - # The timer selected by the profiler should never be used, so make - # sure it doesn't work: - p = Profile() - p.get_time = _brokentimer - log = hotshot.log.LogReader(self._logfn) - taccum = 0 - for event in log: - what, (filename, lineno, funcname), tdelta = event - if tdelta > 0: - taccum += tdelta - - # We multiply taccum to convert from the microseconds we - # have to the seconds that the profile/pstats module work - # with; this allows the numbers to have some basis in - # reality (ignoring calibration issues for now). - - if what == ENTER: - frame = self.new_frame(filename, lineno, funcname) - p.trace_dispatch_call(frame, taccum * .000001) - taccum = 0 - - elif what == EXIT: - frame = self.pop_frame() - p.trace_dispatch_return(frame, taccum * .000001) - taccum = 0 - - # no further work for line events - - assert not self._stack - return pstats.Stats(p) - - def new_frame(self, *args): - # args must be filename, firstlineno, funcname - # our code objects are cached since we don't need to create - # new ones every time - try: - code = self._code[args] - except KeyError: - code = FakeCode(*args) - self._code[args] = code - # frame objects are create fresh, since the back pointer will - # vary considerably - if self._stack: - back = self._stack[-1] - else: - back = None - frame = FakeFrame(code, back) - self._stack.append(frame) - return frame - - -class Profile(profile.Profile): - def simulate_cmd_complete(self): - pass - - -class FakeCode: - def __init__(self, filename, firstlineno, funcname): - self.co_filename = filename - self.co_firstlineno = firstlineno - self.co_name = self.__name__ = funcname - - -class FakeFrame: - def __init__(self, code, back): - self.f_back = back - self.f_code = code - - -def _brokentimer(): - raise RuntimeError("this timer should not be called") diff --git a/Lib/hotshot/stones.py b/Lib/hotshot/stones.py deleted file mode 100644 index 8f974b9..0000000 --- a/Lib/hotshot/stones.py +++ /dev/null @@ -1,31 +0,0 @@ -import errno -import hotshot -import hotshot.stats -import os -import sys -import test.pystone - -def main(logfile): - p = hotshot.Profile(logfile) - benchtime, stones = p.runcall(test.pystone.pystones) - p.close() - - print("Pystone(%s) time for %d passes = %g" % \ - (test.pystone.__version__, test.pystone.LOOPS, benchtime)) - print("This machine benchmarks at %g pystones/second" % stones) - - stats = hotshot.stats.load(logfile) - stats.strip_dirs() - stats.sort_stats('time', 'calls') - try: - stats.print_stats(20) - except IOError as e: - if e.errno != errno.EPIPE: - raise - -if __name__ == '__main__': - if sys.argv[1:]: - main(sys.argv[1]) - else: - import tempfile - main(tempfile.NamedTemporaryFile().name) diff --git a/Lib/test/test_hotshot.py b/Lib/test/test_hotshot.py deleted file mode 100644 index e0d88f7..0000000 --- a/Lib/test/test_hotshot.py +++ /dev/null @@ -1,132 +0,0 @@ -import hotshot -import hotshot.log -import os -import pprint -import unittest - -from test import test_support - -from hotshot.log import ENTER, EXIT, LINE - - -def shortfilename(fn): - # We use a really shortened filename since an exact match is made, - # and the source may be either a Python source file or a - # pre-compiled bytecode file. - if fn: - return os.path.splitext(os.path.basename(fn))[0] - else: - return fn - - -class UnlinkingLogReader(hotshot.log.LogReader): - """Extend the LogReader so the log file is unlinked when we're - done with it.""" - - def __init__(self, logfn): - self.__logfn = logfn - hotshot.log.LogReader.__init__(self, logfn) - - def next(self, index=None): - try: - return hotshot.log.LogReader.next(self) - except StopIteration: - self.close() - os.unlink(self.__logfn) - raise - - -class HotShotTestCase(unittest.TestCase): - def new_profiler(self, lineevents=0, linetimings=1): - self.logfn = test_support.TESTFN - return hotshot.Profile(self.logfn, lineevents, linetimings) - - def get_logreader(self): - return UnlinkingLogReader(self.logfn) - - def get_events_wotime(self): - L = [] - for event in self.get_logreader(): - what, (filename, lineno, funcname), tdelta = event - L.append((what, (shortfilename(filename), lineno, funcname))) - return L - - def check_events(self, expected): - events = self.get_events_wotime() - if events != expected: - self.fail( - "events did not match expectation; got:\n%s\nexpected:\n%s" - % (pprint.pformat(events), pprint.pformat(expected))) - - def run_test(self, callable, events, profiler=None): - if profiler is None: - profiler = self.new_profiler() - self.failUnless(not profiler._prof.closed) - profiler.runcall(callable) - self.failUnless(not profiler._prof.closed) - profiler.close() - self.failUnless(profiler._prof.closed) - self.check_events(events) - - def test_addinfo(self): - def f(p): - p.addinfo("test-key", "test-value") - profiler = self.new_profiler() - profiler.runcall(f, profiler) - profiler.close() - log = self.get_logreader() - info = log._info - list(log) - self.assertEqual(info["test-key"], ["test-value"]) - - def test_line_numbers(self): - def f(): - y = 2 - x = 1 - def g(): - f() - f_lineno = f.__code__.co_firstlineno - g_lineno = g.__code__.co_firstlineno - events = [(ENTER, ("test_hotshot", g_lineno, "g")), - (LINE, ("test_hotshot", g_lineno+1, "g")), - (ENTER, ("test_hotshot", f_lineno, "f")), - (LINE, ("test_hotshot", f_lineno+1, "f")), - (LINE, ("test_hotshot", f_lineno+2, "f")), - (EXIT, ("test_hotshot", f_lineno, "f")), - (EXIT, ("test_hotshot", g_lineno, "g")), - ] - self.run_test(g, events, self.new_profiler(lineevents=1)) - - def test_start_stop(self): - # Make sure we don't return NULL in the start() and stop() - # methods when there isn't an error. Bug in 2.2 noted by - # Anthony Baxter. - profiler = self.new_profiler() - profiler.start() - profiler.stop() - profiler.close() - os.unlink(self.logfn) - - def test_bad_sys_path(self): - import sys - import os - orig_path = sys.path - coverage = hotshot._hotshot.coverage - try: - # verify we require a list for sys.path - sys.path = 'abc' - self.assertRaises(RuntimeError, coverage, test_support.TESTFN) - # verify that we require sys.path exists - del sys.path - self.assertRaises(RuntimeError, coverage, test_support.TESTFN) - finally: - sys.path = orig_path - if os.path.exists(test_support.TESTFN): - os.remove(test_support.TESTFN) - -def test_main(): - test_support.run_unittest(HotShotTestCase) - - -if __name__ == "__main__": - test_main() diff --git a/Makefile.pre.in b/Makefile.pre.in index 5df03f5..45f771a 100644 --- a/Makefile.pre.in +++ b/Makefile.pre.in @@ -737,7 +737,7 @@ PLATMACDIRS= plat-mac plat-mac/Carbon plat-mac/lib-scriptpackages \ PLATMACPATH=:plat-mac:plat-mac/lib-scriptpackages LIBSUBDIRS= lib-tk site-packages test test/output test/data \ test/decimaltestdata \ - encodings hotshot \ + encodings \ email email/mime email/test email/test/data \ sqlite3 sqlite3/test \ logging bsddb bsddb/test csv wsgiref \ @@ -4,6 +4,16 @@ Python News (editors: check NEWS.help for information about editing NEWS using ReST.) +What's New in Python 3.0a2? + +*Unreleased* + +Extension Modules +----------------- + +- The `hotshot` profiler has been removed; use `cProfile` instead. + + What's New in Python 3.0a1? ========================== diff --git a/Modules/_hotshot.c b/Modules/_hotshot.c deleted file mode 100644 index b34c543..0000000 --- a/Modules/_hotshot.c +++ /dev/null @@ -1,1645 +0,0 @@ -/* - * This is the High Performance Python Profiler portion of HotShot. - */ - -#include "Python.h" -#include "code.h" -#include "eval.h" -#include "frameobject.h" -#include "structmember.h" - -/* - * Which timer to use should be made more configurable, but that should not - * be difficult. This will do for now. - */ -#ifdef MS_WINDOWS -#include <windows.h> - -#ifdef HAVE_DIRECT_H -#include <direct.h> /* for getcwd() */ -#endif - -typedef __int64 hs_time; -#define GETTIMEOFDAY(P_HS_TIME) \ - { LARGE_INTEGER _temp; \ - QueryPerformanceCounter(&_temp); \ - *(P_HS_TIME) = _temp.QuadPart; } - - -#else -#ifndef HAVE_GETTIMEOFDAY -#error "This module requires gettimeofday() on non-Windows platforms!" -#endif -#if (defined(PYOS_OS2) && defined(PYCC_GCC)) || defined(__QNX__) -#include <sys/time.h> -#else -#include <sys/resource.h> -#include <sys/times.h> -#endif -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 - -#if defined(PYOS_OS2) && defined(PYCC_GCC) -#define PATH_MAX 260 -#endif - -#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 - -#ifndef PATH_MAX -# ifdef MAX_PATH -# define PATH_MAX MAX_PATH -# elif defined (_POSIX_PATH_MAX) -# define PATH_MAX _POSIX_PATH_MAX -# else -# error "Need a defn. for PATH_MAX in _hotshot.c" -# endif -#endif - -typedef struct { - PyObject_HEAD - PyObject *filemap; - PyObject *logfilename; - Py_ssize_t index; - unsigned char buffer[BUFFERSIZE]; - FILE *logfp; - int lineevents; - int linetimings; - int frametimings; - /* size_t filled; */ - int active; - int next_fileno; - hs_time prev_timeofday; -} ProfilerObject; - -typedef struct { - PyObject_HEAD - PyObject *info; - FILE *logfp; - int linetimings; - int frametimings; -} LogReaderObject; - -static PyObject * ProfilerError = NULL; - - -#ifndef MS_WINDOWS -#ifdef GETTIMEOFDAY_NO_TZ -#define GETTIMEOFDAY(ptv) gettimeofday((ptv)) -#else -#define GETTIMEOFDAY(ptv) gettimeofday((ptv), (struct timezone *)NULL) -#endif -#endif - - -/* The log reader... */ - -PyDoc_STRVAR(logreader_close__doc__, -"close()\n" -"Close the log file, preventing additional records from being read."); - -static PyObject * -logreader_close(LogReaderObject *self, PyObject *args) -{ - if (self->logfp != NULL) { - fclose(self->logfp); - self->logfp = NULL; - } - 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)); -} - - -/* 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 - * 0x02 LINENO execution moved onto a different line - * 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 - * 0x43 DEFINE_FUNC define a (fileno,lineno)->funcname mapping - * 0x53 FRAME_TIMES indicates if ENTER/EXIT events have tdeltas - * - * 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 - * PI tdelta -- iff frame times are enabled - * - * EXIT records - * - * MPI(2,type) tdelta -- type is 0x01; tdelta will be 0 - * if frame times are disabled - * - * LINENO records - * - * MPI(2,type) lineno -- type is 0x02 - * PI tdelta -- iff LINENO includes it - * - * ADD_INFO records - * - * BYTE type -- always 0x13 - * 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 - * - * BYTE type -- always 0x23 - * PI fileno - * PI len -- length of filename - * BYTE filename[len] -- len bytes of string data - * - * DEFINE_FUNC records - * - * BYTE type -- always 0x43 - * PI fileno - * PI lineno - * PI len -- length of funcname - * BYTE funcname[len] -- len bytes of string data - * - * LINE_TIMES records - * - * 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 - * BYTE have_tdelta -- 0 if LINENO does *not* have - * timing information - * 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 - */ - -#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 -#define WHAT_DEFINE_FUNC 0x43 -#define WHAT_FRAME_TIMES 0x53 - -#define ERR_NONE 0 -#define ERR_EOF -1 -#define ERR_EXCEPTION -2 -#define ERR_BAD_RECTYPE -3 - -#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) -{ - int c; - int accum = 0; - int bits = 0; - int cont; - - do { - /* read byte */ - if ((c = fgetc(self->logfp)) == EOF) - return ERR_EOF; - accum |= ((c & 0x7F) >> discard) << bits; - bits += (7 - discard); - cont = c & 0x80; - 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) -{ - int i; - int len; - int err; - int ch; - char *buf; - - if ((err = unpack_packed_int(self, &len, 0))) - return err; - - buf = (char *)malloc(len); - if (!buf) { - PyErr_NoMemory(); - return ERR_EXCEPTION; - } - - for (i=0; i < len; i++) { - ch = fgetc(self->logfp); - buf[i] = ch; - if (ch == EOF) { - free(buf); - return ERR_EOF; - } - } - *pvalue = PyString_FromStringAndSize(buf, len); - free(buf); - if (*pvalue == NULL) { - return ERR_EXCEPTION; - } - return 0; -} - - -static int -unpack_add_info(LogReaderObject *self) -{ - 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)) { - Py_DECREF(list); - err = ERR_EXCEPTION; - goto finally; - } - Py_DECREF(list); - } - if (PyList_Append(list, value)) - err = ERR_EXCEPTION; - } - } - finally: - Py_XDECREF(key); - Py_XDECREF(value); - return err; -} - - -static void -eof_error(LogReaderObject *self) -{ - fclose(self->logfp); - self->logfp = NULL; - PyErr_SetString(PyExc_EOFError, - "end of file with incomplete profile record"); -} - -static PyObject * -logreader_tp_iternext(LogReaderObject *self) -{ - int c; - int what; - 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; - } - -restart: - /* decode the record type */ - if ((c = fgetc(self->logfp)) == EOF) { - fclose(self->logfp); - self->logfp = NULL; - return NULL; - } - 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 */ - - switch (what) { - case WHAT_ENTER: - err = unpack_packed_int(self, &fileno, 2); - if (!err) { - err = unpack_packed_int(self, &lineno, 0); - if (self->frametimings && !err) - err = unpack_packed_int(self, &tdelta, 0); - } - 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: - err = unpack_add_info(self); - 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; - 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; - case WHAT_LINE_TIMES: - if ((c = fgetc(self->logfp)) == EOF) - err = ERR_EOF; - else { - self->linetimings = c ? 1 : 0; - goto restart; - } - break; - case WHAT_FRAME_TIMES: - if ((c = fgetc(self->logfp)) == EOF) - err = ERR_EOF; - else { - self->frametimings = c ? 1 : 0; - goto restart; - } - break; - default: - err = ERR_BAD_RECTYPE; - } - if (err == ERR_BAD_RECTYPE) { - PyErr_SetString(PyExc_ValueError, - "unknown record type in log file"); - } - else if (err == ERR_EOF) { - eof_error(self); - } - else if (!err) { - result = PyTuple_New(4); - if (result == NULL) - return NULL; - PyTuple_SET_ITEM(result, 0, PyInt_FromLong(what)); - PyTuple_SET_ITEM(result, 2, PyInt_FromLong(fileno)); - if (s1 == NULL) - PyTuple_SET_ITEM(result, 1, PyInt_FromLong(tdelta)); - else - PyTuple_SET_ITEM(result, 1, s1); - if (s2 == NULL) - PyTuple_SET_ITEM(result, 3, PyInt_FromLong(lineno)); - else - 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; - } - Py_XDECREF(self->info); - PyObject_Del(self); -} - -static PyObject * -logreader_sq_item(LogReaderObject *self, Py_ssize_t 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; -} - -static void -do_stop(ProfilerObject *self); - -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); - if (written == (size_t)self->index) - 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); - do_stop(self); - return -1; - } - } - if (written > 0) { - if (fflush(self->logfp)) { - char *s = PyString_AsString(self->logfilename); - PyErr_SetFromErrnoWithFilename(PyExc_IOError, s); - do_stop(self); - return -1; - } - } - return 0; -} - -static inline int -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); - return 0; -} - -/* 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. - */ -static inline int -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++; - return pack_packed_int(self, value >> bits); - } - self->buffer[self->index] = b; - self->index++; - return 0; -} - -static int -pack_string(ProfilerObject *self, const char *s, Py_ssize_t len) -{ - if (len + PISIZE + self->index >= BUFFERSIZE) { - if (flush_data(self) < 0) - return -1; - } - assert(len < INT_MAX); - if (pack_packed_int(self, (int)len) < 0) - return -1; - memcpy(self->buffer + self->index, s, len); - self->index += len; - return 0; -} - -static int -pack_add_info(ProfilerObject *self, const char *s1, const char *s2) -{ - Py_ssize_t len1 = strlen(s1); - Py_ssize_t len2 = strlen(s2); - - if (len1 + len2 + PISIZE*2 + 1 + self->index >= BUFFERSIZE) { - if (flush_data(self) < 0) - return -1; - } - self->buffer[self->index] = WHAT_ADD_INFO; - self->index++; - if (pack_string(self, s1, len1) < 0) - return -1; - return pack_string(self, s2, len2); -} - -static int -pack_define_file(ProfilerObject *self, int fileno, const char *filename) -{ - Py_ssize_t len = strlen(filename); - - if (len + PISIZE*2 + 1 + self->index >= BUFFERSIZE) { - if (flush_data(self) < 0) - return -1; - } - self->buffer[self->index] = WHAT_DEFINE_FILE; - self->index++; - if (pack_packed_int(self, fileno) < 0) - return -1; - return pack_string(self, filename, len); -} - -static int -pack_define_func(ProfilerObject *self, int fileno, int lineno, - const char *funcname) -{ - Py_ssize_t len = strlen(funcname); - - if (len + PISIZE*3 + 1 + self->index >= BUFFERSIZE) { - if (flush_data(self) < 0) - return -1; - } - self->buffer[self->index] = WHAT_DEFINE_FUNC; - self->index++; - if (pack_packed_int(self, fileno) < 0) - return -1; - if (pack_packed_int(self, lineno) < 0) - return -1; - return pack_string(self, funcname, len); -} - -static int -pack_line_times(ProfilerObject *self) -{ - if (2 + self->index >= BUFFERSIZE) { - if (flush_data(self) < 0) - return -1; - } - self->buffer[self->index] = WHAT_LINE_TIMES; - self->buffer[self->index + 1] = self->linetimings ? 1 : 0; - self->index += 2; - return 0; -} - -static int -pack_frame_times(ProfilerObject *self) -{ - if (2 + self->index >= BUFFERSIZE) { - if (flush_data(self) < 0) - return -1; - } - self->buffer[self->index] = WHAT_FRAME_TIMES; - self->buffer[self->index + 1] = self->frametimings ? 1 : 0; - self->index += 2; - return 0; -} - -static inline int -pack_enter(ProfilerObject *self, int fileno, int tdelta, int lineno) -{ - if (MPISIZE + PISIZE*2 + self->index >= BUFFERSIZE) { - if (flush_data(self) < 0) - return -1; - } - pack_modified_packed_int(self, fileno, 2, WHAT_ENTER); - pack_packed_int(self, lineno); - if (self->frametimings) - return pack_packed_int(self, tdelta); - else - return 0; -} - -static inline int -pack_exit(ProfilerObject *self, int tdelta) -{ - if (MPISIZE + self->index >= BUFFERSIZE) { - if (flush_data(self) < 0) - return -1; - } - if (self->frametimings) - return pack_modified_packed_int(self, tdelta, 2, WHAT_EXIT); - self->buffer[self->index] = WHAT_EXIT; - self->index++; - return 0; -} - -static inline int -pack_lineno(ProfilerObject *self, int lineno) -{ - if (MPISIZE + self->index >= BUFFERSIZE) { - if (flush_data(self) < 0) - return -1; - } - return pack_modified_packed_int(self, lineno, 2, WHAT_LINENO); -} - -static inline int -pack_lineno_tdelta(ProfilerObject *self, int lineno, int tdelta) -{ - 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); -} - -static inline int -get_fileno(ProfilerObject *self, PyCodeObject *fcode) -{ - /* This is only used for ENTER events. */ - - PyObject *obj; - PyObject *dict; - int fileno; - - obj = PyDict_GetItem(self->filemap, fcode->co_filename); - if (obj == NULL) { - /* first sighting of this file */ - dict = PyDict_New(); - if (dict == NULL) { - return -1; - } - fileno = self->next_fileno; - obj = Py_BuildValue("iN", fileno, dict); - if (obj == NULL) { - return -1; - } - if (PyDict_SetItem(self->filemap, fcode->co_filename, obj)) { - Py_DECREF(obj); - return -1; - } - self->next_fileno++; - Py_DECREF(obj); - if (pack_define_file(self, fileno, - PyString_AS_STRING(fcode->co_filename)) < 0) - return -1; - } - else { - /* already know this ID */ - 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) { - if (pack_define_func(self, fileno, fcode->co_firstlineno, - PyUnicode_AsString(fcode->co_name)) < 0) { - Py_DECREF(obj); - return -1; - } - if (PyDict_SetItem(dict, obj, fcode->co_name)) { - Py_DECREF(obj); - return -1; - } - } - Py_DECREF(obj); - } - return fileno; -} - -static inline int -get_tdelta(ProfilerObject *self) -{ - int tdelta; -#ifdef MS_WINDOWS - hs_time tv; - hs_time diff; - - GETTIMEOFDAY(&tv); - diff = tv - self->prev_timeofday; - tdelta = (int)diff; -#else - struct timeval tv; - - GETTIMEOFDAY(&tv); - - tdelta = tv.tv_usec - self->prev_timeofday.tv_usec; - if (tv.tv_sec != self->prev_timeofday.tv_sec) - tdelta += (tv.tv_sec - self->prev_timeofday.tv_sec) * 1000000; -#endif - /* time can go backwards on some multiprocessor systems or by NTP */ - if (tdelta < 0) - return 0; - - self->prev_timeofday = tv; - return tdelta; -} - - -/* The workhorse: the profiler callback function. */ - -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; - return pack_enter(self, fileno, - self->frametimings ? get_tdelta(self) : -1, - frame->f_code->co_firstlineno); - - case PyTrace_RETURN: - return pack_exit(self, get_tdelta(self)); - - case PyTrace_LINE: /* we only get these events if we asked for them */ - if (self->linetimings) - return pack_lineno_tdelta(self, frame->f_lineno, - get_tdelta(self)); - else - return pack_lineno(self, frame->f_lineno); - - default: - /* ignore PyTrace_EXCEPTION */ - break; - } - return 0; -} - - -/* A couple of useful helper functions. */ - -#ifdef MS_WINDOWS -static LARGE_INTEGER frequency = {0, 0}; -#endif - -static unsigned long timeofday_diff = 0; -static unsigned long rusage_diff = 0; - -static void -calibrate(void) -{ - hs_time tv1, tv2; - -#ifdef MS_WINDOWS - hs_time diff; - QueryPerformanceFrequency(&frequency); -#endif - - GETTIMEOFDAY(&tv1); - while (1) { - GETTIMEOFDAY(&tv2); -#ifdef MS_WINDOWS - diff = tv2 - tv1; - if (diff != 0) { - timeofday_diff = (unsigned long)diff; - 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 - } -#if defined(MS_WINDOWS) || defined(PYOS_OS2) || \ - defined(__VMS) || defined (__QNX__) - 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) tracer_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. */ - -PyDoc_STRVAR(addinfo__doc__, -"addinfo(key, value)\n" -"Insert an ADD_INFO record into the log."); - -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 { - if (pack_add_info(self, key, value) == 0) { - result = Py_None; - Py_INCREF(result); - } - } - } - return result; -} - -PyDoc_STRVAR(close__doc__, -"close()\n" -"Shut down this profiler and close the log files, even if its active."); - -static PyObject * -profiler_close(ProfilerObject *self) -{ - do_stop(self); - if (self->logfp != NULL) { - fclose(self->logfp); - self->logfp = NULL; - } - Py_INCREF(Py_None); - return Py_None; -} - -#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; - } - return PyInt_FromLong(fileno(self->logfp)); -} - -PyDoc_STRVAR(runcall__doc__, -"runcall(callable[, args[, kw]]) -> callable()\n" -"Profile a specific function call, returning the result of that call."); - -static PyObject * -profiler_runcall(ProfilerObject *self, PyObject *args) -{ - PyObject *result = NULL; - PyObject *callargs = NULL; - PyObject *callkw = NULL; - PyObject *callable; - - if (PyArg_UnpackTuple(args, "runcall", 1, 3, - &callable, &callargs, &callkw)) { - if (is_available(self)) { - do_start(self); - result = PyEval_CallObjectWithKeywords(callable, callargs, callkw); - do_stop(self); - } - } - return result; -} - -PyDoc_STRVAR(runcode__doc__, -"runcode(code, globals[, locals])\n" -"Execute a code object while collecting profile data. If locals is\n" -"omitted, globals is used for the locals as well."); - -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; -} - -PyDoc_STRVAR(start__doc__, -"start()\n" -"Install this profiler for the current thread."); - -static PyObject * -profiler_start(ProfilerObject *self, PyObject *args) -{ - PyObject *result = NULL; - - if (is_available(self)) { - do_start(self); - result = Py_None; - Py_INCREF(result); - } - return result; -} - -PyDoc_STRVAR(stop__doc__, -"stop()\n" -"Remove this profiler from the current thread."); - -static PyObject * -profiler_stop(ProfilerObject *self, PyObject *args) -{ - PyObject *result = NULL; - - if (!self->active) - PyErr_SetString(ProfilerError, "profiler not active"); - else { - do_stop(self); - result = Py_None; - Py_INCREF(result); - } - 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[] = { - {"addinfo", (PyCFunction)profiler_addinfo, METH_VARARGS, addinfo__doc__}, - {"close", (PyCFunction)profiler_close, METH_NOARGS, close__doc__}, - {"fileno", (PyCFunction)profiler_fileno, METH_NOARGS, fileno__doc__}, - {"runcall", (PyCFunction)profiler_runcall, METH_VARARGS, runcall__doc__}, - {"runcode", (PyCFunction)profiler_runcode, METH_VARARGS, runcode__doc__}, - {"start", (PyCFunction)profiler_start, METH_NOARGS, start__doc__}, - {"stop", (PyCFunction)profiler_stop, METH_NOARGS, stop__doc__}, - {NULL, NULL} -}; - -static PyMemberDef profiler_members[] = { - {"frametimings", T_LONG, offsetof(ProfilerObject, linetimings), READONLY}, - {"lineevents", T_LONG, offsetof(ProfilerObject, lineevents), READONLY}, - {"linetimings", T_LONG, offsetof(ProfilerObject, linetimings), READONLY}, - {NULL} -}; - -static PyObject * -profiler_get_closed(ProfilerObject *self, void *closure) -{ - PyObject *result = (self->logfp == NULL) ? Py_True : Py_False; - Py_INCREF(result); - return result; -} - -static PyGetSetDef profiler_getsets[] = { - {"closed", (getter)profiler_get_closed, NULL, - PyDoc_STR("True if the profiler's output file has already been closed.")}, - {NULL} -}; - - -PyDoc_STRVAR(profiler_object__doc__, -"High-performance profiler object.\n" -"\n" -"Methods:\n" -"\n" -"close(): Stop the profiler and close the log files.\n" -"fileno(): Returns the file descriptor of the log file.\n" -"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" -"\n" -"Attributes (read-only):\n" -"\n" -"closed: True if the profiler has already been closed.\n" -"frametimings: True if ENTER/EXIT events collect timing information.\n" -"lineevents: True if line events are reported to the profiler.\n" -"linetimings: True if line events collect timing information."); - -static PyTypeObject ProfilerType = { - PyVarObject_HEAD_INIT(NULL, 0) - "_hotshot.ProfilerType", /* tp_name */ - (int) sizeof(ProfilerObject), /* tp_basicsize */ - 0, /* tp_itemsize */ - (destructor)profiler_dealloc, /* tp_dealloc */ - 0, /* tp_print */ - 0, /* tp_getattr */ - 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 */ - PyObject_GenericGetAttr, /* tp_getattro */ - 0, /* tp_setattro */ - 0, /* tp_as_buffer */ - Py_TPFLAGS_DEFAULT, /* tp_flags */ - profiler_object__doc__, /* tp_doc */ - 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 */ -}; - - -static PyMethodDef logreader_methods[] = { - {"close", (PyCFunction)logreader_close, METH_NOARGS, - logreader_close__doc__}, - {"fileno", (PyCFunction)logreader_fileno, METH_NOARGS, - logreader_fileno__doc__}, - {NULL, NULL} -}; - -static PyMemberDef logreader_members[] = { - {"info", T_OBJECT, offsetof(LogReaderObject, info), READONLY, - PyDoc_STR("Dictionary mapping informational keys to lists of values.")}, - {NULL} -}; - - -PyDoc_STRVAR(logreader__doc__, -"logreader(filename) --> log-iterator\n\ -Create a log-reader for the timing information file."); - -static PySequenceMethods logreader_as_sequence = { - 0, /* sq_length */ - 0, /* sq_concat */ - 0, /* sq_repeat */ - (ssizeargfunc)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 */ -}; - -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} -}; - -static PyTypeObject LogReaderType = { - PyVarObject_HEAD_INIT(NULL, 0) - "_hotshot.LogReaderType", /* tp_name */ - (int) sizeof(LogReaderObject), /* tp_basicsize */ - 0, /* tp_itemsize */ - (destructor)logreader_dealloc, /* tp_dealloc */ - 0, /* tp_print */ - 0, /* tp_getattr */ - 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 */ - PyObject_GenericGetAttr, /* tp_getattro */ - 0, /* tp_setattro */ - 0, /* tp_as_buffer */ - Py_TPFLAGS_DEFAULT, /* tp_flags */ - logreader__doc__, /* tp_doc */ - 0, /* tp_traverse */ - 0, /* tp_clear */ - 0, /* tp_richcompare */ - 0, /* tp_weaklistoffset */ - PyObject_SelfIter, /* tp_iter */ - (iternextfunc)logreader_tp_iternext,/* tp_iternext */ - logreader_methods, /* tp_methods */ - logreader_members, /* tp_members */ - logreader_getsets, /* tp_getset */ - 0, /* tp_base */ - 0, /* tp_dict */ - 0, /* tp_descr_get */ - 0, /* tp_descr_set */ -}; - -static PyObject * -hotshot_logreader(PyObject *unused, PyObject *args) -{ - LogReaderObject *self = NULL; - char *filename; - int c; - int err = 0; - - if (PyArg_ParseTuple(args, "s:logreader", &filename)) { - self = PyObject_New(LogReaderObject, &LogReaderType); - if (self != NULL) { - self->frametimings = 1; - self->linetimings = 0; - self->info = NULL; - self->logfp = fopen(filename, "rb"); - if (self->logfp == NULL) { - PyErr_SetFromErrnoWithFilename(PyExc_IOError, filename); - Py_DECREF(self); - self = NULL; - goto finally; - } - self->info = PyDict_New(); - if (self->info == NULL) { - Py_DECREF(self); - goto finally; - } - /* read initial info */ - for (;;) { - if ((c = fgetc(self->logfp)) == EOF) { - eof_error(self); - break; - } - if (c != WHAT_ADD_INFO) { - ungetc(c, self->logfp); - break; - } - err = unpack_add_info(self); - if (err) { - if (err == ERR_EOF) - eof_error(self); - else - PyErr_SetString(PyExc_RuntimeError, - "unexpected error"); - break; - } - } - } - } - finally: - 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; - - while (*rev && !isdigit(Py_CHARMASK(*rev))) - ++rev; - while (rev[i] != ' ' && rev[i] != '\0') - ++i; - buffer = (char *)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; - Py_ssize_t i, len; - - buffer = get_version_string(); - if (buffer == NULL) { - PyErr_NoMemory(); - return -1; - } - 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", - (self->lineevents ? "yes" : "no")); - 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()); - free(buffer); - buffer = (char *) Py_GetVersion(); - if (buffer == NULL) - PyErr_Clear(); - else - pack_add_info(self, "executable-version", buffer); - -#ifdef MS_WINDOWS - PyOS_snprintf(cwdbuffer, sizeof(cwdbuffer), "%I64d", frequency.QuadPart); - pack_add_info(self, "reported-performance-frequency", cwdbuffer); -#else - PyOS_snprintf(cwdbuffer, sizeof(cwdbuffer), "%lu", rusage_diff); - pack_add_info(self, "observed-interval-getrusage", cwdbuffer); - PyOS_snprintf(cwdbuffer, sizeof(cwdbuffer), "%lu", timeofday_diff); - pack_add_info(self, "observed-interval-gettimeofday", cwdbuffer); -#endif - - pack_add_info(self, "current-directory", - getcwd(cwdbuffer, sizeof cwdbuffer)); - - temp = PySys_GetObject("path"); - if (temp == NULL || !PyList_Check(temp)) { - PyErr_SetString(PyExc_RuntimeError, "sys.path must be a list"); - return -1; - } - len = PyList_GET_SIZE(temp); - for (i = 0; i < len; ++i) { - PyObject *item = PyList_GET_ITEM(temp, i); - buffer = PyString_AsString(item); - 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); - } - } - pack_frame_times(self); - pack_line_times(self); - - return 0; -} - -PyDoc_STRVAR(profiler__doc__, -"profiler(logfilename[, lineevents[, linetimes]]) -> profiler\n\ -Create a new profiler object."); - -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; - self->frametimings = 1; - self->lineevents = lineevents ? 1 : 0; - self->linetimings = (lineevents && linetimings) ? 1 : 0; - self->index = 0; - self->active = 0; - self->next_fileno = 0; - self->logfp = NULL; - 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 */ - Py_DECREF(self); - self = NULL; - } - } - return (PyObject *) self; -} - -PyDoc_STRVAR(coverage__doc__, -"coverage(logfilename) -> profiler\n\ -Returns a profiler that doesn't collect any timing information, which is\n\ -useful in building a coverage analysis tool."); - -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; -} - -PyDoc_VAR(resolution__doc__) = -#ifdef MS_WINDOWS -PyDoc_STR( -"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" -"is the result of QueryPerformanceFrequency()." -) -#else -PyDoc_STR( -"resolution() -> (gettimeofday-usecs, getrusage-usecs)\n" -"Return the resolution of the timers provided by the gettimeofday() and\n" -"getrusage() system calls, or -1 if the call is not supported." -) -#endif -; - -static PyObject * -hotshot_resolution(PyObject *self, PyObject *unused) -{ - if (timeofday_diff == 0) { - calibrate(); - calibrate(); - calibrate(); - } -#ifdef MS_WINDOWS - return Py_BuildValue("ii", timeofday_diff, frequency.LowPart); -#else - return Py_BuildValue("ii", timeofday_diff, rusage_diff); -#endif -} - - -static PyMethodDef functions[] = { - {"coverage", hotshot_coverage, METH_VARARGS, coverage__doc__}, - {"profiler", hotshot_profiler, METH_VARARGS, profiler__doc__}, - {"logreader", hotshot_logreader, METH_VARARGS, logreader__doc__}, - {"resolution", hotshot_resolution, METH_NOARGS, resolution__doc__}, - {NULL, NULL} -}; - - -void -init_hotshot(void) -{ - PyObject *module; - - Py_Type(&LogReaderType) = &PyType_Type; - Py_Type(&ProfilerType) = &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); - PyModule_AddIntConstant(module, "WHAT_DEFINE_FUNC", WHAT_DEFINE_FUNC); - PyModule_AddIntConstant(module, "WHAT_LINE_TIMES", WHAT_LINE_TIMES); - } -} diff --git a/Tools/scripts/hotshotmain.py b/Tools/scripts/hotshotmain.py deleted file mode 100644 index 7e39d98..0000000 --- a/Tools/scripts/hotshotmain.py +++ /dev/null @@ -1,60 +0,0 @@ -#!/usr/bin/env python -# -*- coding: iso-8859-1 -*- - -""" -Run a Python script under hotshot's control. - -Adapted from a posting on python-dev by Walter Dörwald - -usage %prog [ %prog args ] filename [ filename args ] - -Any arguments after the filename are used as sys.argv for the filename. -""" - -import sys -import optparse -import os -import hotshot -import hotshot.stats - -PROFILE = "hotshot.prof" - -def run_hotshot(filename, profile, args): - prof = hotshot.Profile(profile) - sys.path.insert(0, os.path.dirname(filename)) - sys.argv = [filename] + args - fp = open(filename) - try: - script = fp.read() - finally: - fp.close() - prof.run("exec(%r)" % script) - prof.close() - stats = hotshot.stats.load(profile) - stats.sort_stats("time", "calls") - - # print_stats uses unadorned print statements, so the only way - # to force output to stderr is to reassign sys.stdout temporarily - save_stdout = sys.stdout - sys.stdout = sys.stderr - stats.print_stats() - sys.stdout = save_stdout - - return 0 - -def main(args): - parser = optparse.OptionParser(__doc__) - parser.disable_interspersed_args() - parser.add_option("-p", "--profile", action="store", default=PROFILE, - dest="profile", help='Specify profile file to use') - (options, args) = parser.parse_args(args) - - if len(args) == 0: - parser.print_help("missing script to execute") - return 1 - - filename = args[0] - return run_hotshot(filename, options.profile, args[1:]) - -if __name__ == "__main__": - sys.exit(main(sys.argv[1:])) @@ -413,8 +413,7 @@ class PyBuildExt(build_ext): exts.append( Extension("atexit", ["atexitmodule.c"]) ) # Python C API test module exts.append( Extension('_testcapi', ['_testcapimodule.c']) ) - # profilers (_lsprof is for cProfile.py) - exts.append( Extension('_hotshot', ['_hotshot.c']) ) + # profiler (_lsprof is for cProfile.py) exts.append( Extension('_lsprof', ['_lsprof.c', 'rotatingtree.c']) ) # static Unicode character database exts.append( Extension('unicodedata', ['unicodedata.c']) ) |