root/galaxy-central/eggs/Cheetah-2.2.2-py2.6-macosx-10.6-universal-ucs2.egg/Cheetah/Utils/statprof.py

リビジョン 3, 9.9 KB (コミッタ: kohda, 14 年 前)

Install Unix tools  http://hannonlab.cshl.edu/galaxy_unix_tools/galaxy.html

行番号 
1## statprof.py
2## Copyright (C) 2004,2005 Andy Wingo <wingo at pobox dot com>
3## Copyright (C) 2001 Rob Browning <rlb at defaultvalue dot org>
4
5## This library is free software; you can redistribute it and/or
6## modify it under the terms of the GNU Lesser General Public
7## License as published by the Free Software Foundation; either
8## version 2.1 of the License, or (at your option) any later version.
9##
10## This library is distributed in the hope that it will be useful,
11## but WITHOUT ANY WARRANTY; without even the implied warranty of
12## MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
13## Lesser General Public License for more details.
14##
15## You should have received a copy of the GNU Lesser General Public
16## License along with this program; if not, contact:
17##
18## Free Software Foundation           Voice:  +1-617-542-5942
19## 59 Temple Place - Suite 330        Fax:    +1-617-542-2652
20## Boston, MA  02111-1307,  USA       gnu@gnu.org
21
22"""
23statprof is intended to be a fairly simple statistical profiler for
24python. It was ported directly from a statistical profiler for guile,
25also named statprof, available from guile-lib [0].
26
27[0] http://wingolog.org/software/guile-lib/statprof/
28
29To start profiling, call statprof.start():
30>>> start()
31
32Then run whatever it is that you want to profile, for example:
33>>> import test.pystone; test.pystone.pystones()
34
35Then stop the profiling and print out the results:
36>>> stop()
37>>> display()
38  %   cumulative      self         
39 time    seconds   seconds  name   
40 26.72      1.40      0.37  pystone.py:79:Proc0
41 13.79      0.56      0.19  pystone.py:133:Proc1
42 13.79      0.19      0.19  pystone.py:208:Proc8
43 10.34      0.16      0.14  pystone.py:229:Func2
44  6.90      0.10      0.10  pystone.py:45:__init__
45  4.31      0.16      0.06  pystone.py:53:copy
46    ...
47
48All of the numerical data with the exception of the calls column is
49statistically approximate. In the following column descriptions, and
50in all of statprof, "time" refers to execution time (both user and
51system), not wall clock time.
52
53% time
54    The percent of the time spent inside the procedure itself (not
55    counting children).
56
57cumulative seconds
58    The total number of seconds spent in the procedure, including
59    children.
60
61self seconds
62    The total number of seconds spent in the procedure itself (not
63    counting children).
64
65name
66    The name of the procedure.
67
68By default statprof keeps the data collected from previous runs. If you
69want to clear the collected data, call reset():
70>>> reset()
71
72reset() can also be used to change the sampling frequency. For example,
73to tell statprof to sample 50 times a second:
74>>> reset(50)
75
76This means that statprof will sample the call stack after every 1/50 of
77a second of user + system time spent running on behalf of the python
78process. When your process is idle (for example, blocking in a read(),
79as is the case at the listener), the clock does not advance. For this
80reason statprof is not currently not suitable for profiling io-bound
81operations.
82
83The profiler uses the hash of the code object itself to identify the
84procedures, so it won't confuse different procedures with the same name.
85They will show up as two different rows in the output.
86
87Right now the profiler is quite simplistic.  I cannot provide
88call-graphs or other higher level information.  What you see in the
89table is pretty much all there is. Patches are welcome :-)
90
91
92Threading
93---------
94
95Because signals only get delivered to the main thread in Python,
96statprof only profiles the main thread. However because the time
97reporting function uses per-process timers, the results can be
98significantly off if other threads' work patterns are not similar to the
99main thread's work patterns.
100
101
102Implementation notes
103--------------------
104
105The profiler works by setting the unix profiling signal ITIMER_PROF to
106go off after the interval you define in the call to reset(). When the
107signal fires, a sampling routine is run which looks at the current
108procedure that's executing, and then crawls up the stack, and for each
109frame encountered, increments that frame's code object's sample count.
110Note that if a procedure is encountered multiple times on a given stack,
111it is only counted once. After the sampling is complete, the profiler
112resets profiling timer to fire again after the appropriate interval.
113
114Meanwhile, the profiler keeps track, via os.times(), how much CPU time
115(system and user -- which is also what ITIMER_PROF tracks), has elapsed
116while code has been executing within a start()/stop() block.
117
118The profiler also tries to avoid counting or timing its own code as
119much as possible.
120"""
121
122
123from __future__ import division
124
125try:
126    import itimer
127except ImportError:
128    raise ImportError('''statprof requires the itimer python extension.
129To install it, enter the following commands from a terminal:
130
131wget http://www.cute.fi/~torppa/py-itimer/py-itimer.tar.gz
132tar zxvf py-itimer.tar.gz
133cd py-itimer
134sudo python setup.py install
135''')
136
137import signal
138import os
139
140
141__all__ = ['start', 'stop', 'reset', 'display']
142
143
144###########################################################################
145## Utils
146
147def clock():
148    times = os.times()
149    return times[0] + times[1]
150
151
152###########################################################################
153## Collection data structures
154
155class ProfileState(object):
156    def __init__(self, frequency=None):
157        self.reset(frequency)
158
159    def reset(self, frequency=None):
160        # total so far
161        self.accumulated_time = 0.0
162        # start_time when timer is active
163        self.last_start_time = None
164        # total count of sampler calls
165        self.sample_count = 0
166        # a float
167        if frequency:
168            self.sample_interval = 1.0/frequency
169        elif not hasattr(self, 'sample_interval'):
170            # default to 100 Hz
171            self.sample_interval = 1.0/100.0
172        else:
173            # leave the frequency as it was
174            pass
175        self.remaining_prof_time = None
176        # for user start/stop nesting
177        self.profile_level = 0
178        # whether to catch apply-frame
179        self.count_calls = False
180        # gc time between start() and stop()
181        self.gc_time_taken = 0
182
183    def accumulate_time(self, stop_time):
184        self.accumulated_time += stop_time - self.last_start_time
185
186state = ProfileState()
187
188## call_data := { code object: CallData }
189call_data = {}
190class CallData(object):
191    def __init__(self, code):
192        self.name = code.co_name
193        self.filename = code.co_filename
194        self.lineno = code.co_firstlineno
195        self.call_count = 0
196        self.cum_sample_count = 0
197        self.self_sample_count = 0
198        call_data[code] = self
199
200def get_call_data(code):
201    return call_data.get(code, None) or CallData(code)
202
203
204###########################################################################
205## SIGPROF handler
206
207def sample_stack_procs(frame):
208    state.sample_count += 1
209    get_call_data(frame.f_code).self_sample_count += 1
210
211    code_seen = {}
212    while frame:
213        code_seen[frame.f_code] = True
214        frame = frame.f_back
215    for code in code_seen.iterkeys():
216        get_call_data(code).cum_sample_count += 1
217
218def profile_signal_handler(signum, frame):
219    if state.profile_level > 0:
220        state.accumulate_time(clock())
221        sample_stack_procs(frame)
222        itimer.setitimer(itimer.ITIMER_PROF,
223            state.sample_interval, 0.0)
224        state.last_start_time = clock()
225
226
227###########################################################################
228## Profiling API
229
230def is_active():
231    return state.profile_level > 0
232
233def start():
234    state.profile_level += 1
235    if state.profile_level == 1:
236        state.last_start_time = clock()
237        rpt = state.remaining_prof_time
238        state.remaining_prof_time = None
239        signal.signal(signal.SIGPROF, profile_signal_handler)
240        itimer.setitimer(itimer.ITIMER_PROF,
241            rpt or state.sample_interval, 0.0)
242        state.gc_time_taken = 0 # dunno
243 
244def stop():
245    state.profile_level -= 1
246    if state.profile_level == 0:
247        state.accumulate_time(clock())
248        state.last_start_time = None
249        rpt = itimer.setitimer(itimer.ITIMER_PROF, 0.0, 0.0)
250        signal.signal(signal.SIGPROF, signal.SIG_IGN)
251        state.remaining_prof_time = rpt[0]
252        state.gc_time_taken = 0 # dunno
253   
254def reset(frequency=None):
255    assert state.profile_level == 0, "Can't reset() while statprof is running"
256    call_data.clear()
257    state.reset(frequency)
258   
259
260###########################################################################
261## Reporting API
262
263class CallStats(object):
264    def __init__(self, call_data):
265        self_samples = call_data.self_sample_count
266        cum_samples = call_data.cum_sample_count
267        nsamples = state.sample_count
268        secs_per_sample = state.accumulated_time / nsamples
269        basename = os.path.basename(call_data.filename)
270
271        self.name = '%s:%d:%s' % (basename, call_data.lineno, call_data.name)
272        self.pcnt_time_in_proc = self_samples / nsamples * 100
273        self.cum_secs_in_proc = cum_samples * secs_per_sample
274        self.self_secs_in_proc = self_samples * secs_per_sample
275        self.num_calls = None
276        self.self_secs_per_call = None
277        self.cum_secs_per_call = None
278
279    def display(self):
280        print '%6.2f %9.2f %9.2f  %s' % (self.pcnt_time_in_proc,
281                                         self.cum_secs_in_proc,
282                                         self.self_secs_in_proc,
283                                         self.name)
284
285
286def display():
287    if state.sample_count == 0:
288        print 'No samples recorded.'
289        return
290
291    l = [CallStats(x) for x in call_data.itervalues()]
292    l = [(x.self_secs_in_proc, x.cum_secs_in_proc, x) for x in l]
293    l.sort(reverse=True)
294    l = [x[2] for x in l]
295
296    print '%5.5s %10.10s   %7.7s  %-8.8s' % ('%  ', 'cumulative', 'self', '')
297    print '%5.5s  %9.9s  %8.8s  %-8.8s' % ("time", "seconds", "seconds", "name")
298
299    for x in l:
300        x.display()
301
302    print '---'
303    print 'Sample count: %d' % state.sample_count
304    print 'Total time: %f seconds' % state.accumulated_time
Note: リポジトリブラウザについてのヘルプは TracBrowser を参照してください。