"Fossies" - the Fresh Open Source Software Archive

Member "cheetah3-3.2.6.post2/Cheetah/Utils/statprof.py" (20 Apr 2021, 10121 Bytes) of package /linux/www/cheetah3-3.2.6.post2.tar.gz:


As a special service "Fossies" has tried to format the requested source page into HTML format using (guessed) Python source code syntax highlighting (style: standard) with prefixed line numbers. Alternatively you can here view or download the uninterpreted source code file. For more information about "statprof.py" see the Fossies "Dox" file reference documentation and the last Fossies "Diffs" side-by-side code changes report: 3-3.1.0_vs_3-3.2.0.

    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 """
   23 statprof is intended to be a fairly simple statistical profiler for
   24 python. It was ported directly from a statistical profiler for guile,
   25 also named statprof, available from guile-lib [0].
   26 
   27 [0] http://wingolog.org/software/guile-lib/statprof/
   28 
   29 To start profiling, call statprof.start():
   30 >>> start()
   31 
   32 Then run whatever it is that you want to profile, for example:
   33 >>> import test.pystone; test.pystone.pystones()
   34 
   35 Then 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 
   48 All of the numerical data with the exception of the calls column is
   49 statistically approximate. In the following column descriptions, and
   50 in all of statprof, "time" refers to execution time (both user and
   51 system), not wall clock time.
   52 
   53 % time
   54     The percent of the time spent inside the procedure itself (not
   55     counting children).
   56 
   57 cumulative seconds
   58     The total number of seconds spent in the procedure, including
   59     children.
   60 
   61 self seconds
   62     The total number of seconds spent in the procedure itself (not
   63     counting children).
   64 
   65 name
   66     The name of the procedure.
   67 
   68 By default statprof keeps the data collected from previous runs. If you
   69 want to clear the collected data, call reset():
   70 >>> reset()
   71 
   72 reset() can also be used to change the sampling frequency. For example,
   73 to tell statprof to sample 50 times a second:
   74 >>> reset(50)
   75 
   76 This means that statprof will sample the call stack after every 1/50 of
   77 a second of user + system time spent running on behalf of the python
   78 process. When your process is idle (for example, blocking in a read(),
   79 as is the case at the listener), the clock does not advance. For this
   80 reason statprof is not currently not suitable for profiling io-bound
   81 operations.
   82 
   83 The profiler uses the hash of the code object itself to identify the
   84 procedures, so it won't confuse different procedures with the same name.
   85 They will show up as two different rows in the output.
   86 
   87 Right now the profiler is quite simplistic.  I cannot provide
   88 call-graphs or other higher level information.  What you see in the
   89 table is pretty much all there is. Patches are welcome :-)
   90 
   91 
   92 Threading
   93 ---------
   94 
   95 Because signals only get delivered to the main thread in Python,
   96 statprof only profiles the main thread. However because the time
   97 reporting function uses per-process timers, the results can be
   98 significantly off if other threads' work patterns are not similar to the
   99 main thread's work patterns.
  100 
  101 
  102 Implementation notes
  103 --------------------
  104 
  105 The profiler works by setting the unix profiling signal ITIMER_PROF to
  106 go off after the interval you define in the call to reset(). When the
  107 signal fires, a sampling routine is run which looks at the current
  108 procedure that's executing, and then crawls up the stack, and for each
  109 frame encountered, increments that frame's code object's sample count.
  110 Note that if a procedure is encountered multiple times on a given stack,
  111 it is only counted once. After the sampling is complete, the profiler
  112 resets profiling timer to fire again after the appropriate interval.
  113 
  114 Meanwhile, the profiler keeps track, via os.times(), how much CPU time
  115 (system and user -- which is also what ITIMER_PROF tracks), has elapsed
  116 while code has been executing within a start()/stop() block.
  117 
  118 The profiler also tries to avoid counting or timing its own code as
  119 much as possible.
  120 """
  121 
  122 
  123 try:
  124     import itimer
  125 except ImportError:
  126     raise ImportError('''statprof requires the itimer python extension.
  127 To install it, enter the following commands from a terminal:
  128 
  129 wget http://www.cute.fi/~torppa/py-itimer/py-itimer.tar.gz
  130 tar zxvf py-itimer.tar.gz
  131 cd py-itimer
  132 sudo python setup.py install
  133 ''')
  134 
  135 import signal
  136 import os
  137 
  138 
  139 __all__ = ['start', 'stop', 'reset', 'display']
  140 
  141 
  142 ###########################################################################
  143 # Utils
  144 
  145 def clock():
  146     times = os.times()
  147     return times[0] + times[1]
  148 
  149 
  150 ###########################################################################
  151 # Collection data structures
  152 
  153 class ProfileState(object):
  154     def __init__(self, frequency=None):
  155         self.reset(frequency)
  156 
  157     def reset(self, frequency=None):
  158         # total so far
  159         self.accumulated_time = 0.0
  160         # start_time when timer is active
  161         self.last_start_time = None
  162         # total count of sampler calls
  163         self.sample_count = 0
  164         # a float
  165         if frequency:
  166             self.sample_interval = 1.0 / frequency
  167         elif not hasattr(self, 'sample_interval'):
  168             # default to 100 Hz
  169             self.sample_interval = 1.0 / 100.0
  170         else:
  171             # leave the frequency as it was
  172             pass
  173         self.remaining_prof_time = None
  174         # for user start/stop nesting
  175         self.profile_level = 0
  176         # whether to catch apply-frame
  177         self.count_calls = False
  178         # gc time between start() and stop()
  179         self.gc_time_taken = 0
  180 
  181     def accumulate_time(self, stop_time):
  182         self.accumulated_time += stop_time - self.last_start_time
  183 
  184 
  185 state = ProfileState()
  186 
  187 # call_data := { code object: CallData }
  188 call_data = {}
  189 
  190 
  191 class CallData(object):
  192     def __init__(self, code):
  193         self.name = code.co_name
  194         self.filename = code.co_filename
  195         self.lineno = code.co_firstlineno
  196         self.call_count = 0
  197         self.cum_sample_count = 0
  198         self.self_sample_count = 0
  199         call_data[code] = self
  200 
  201 
  202 def get_call_data(code):
  203     return call_data.get(code, None) or CallData(code)
  204 
  205 
  206 ###########################################################################
  207 # SIGPROF handler
  208 
  209 def sample_stack_procs(frame):
  210     state.sample_count += 1
  211     get_call_data(frame.f_code).self_sample_count += 1
  212 
  213     code_seen = {}
  214     while frame:
  215         code_seen[frame.f_code] = True
  216         frame = frame.f_back
  217     for code in code_seen:
  218         get_call_data(code).cum_sample_count += 1
  219 
  220 
  221 def profile_signal_handler(signum, frame):
  222     if state.profile_level > 0:
  223         state.accumulate_time(clock())
  224         sample_stack_procs(frame)
  225         itimer.setitimer(itimer.ITIMER_PROF, state.sample_interval, 0.0)
  226         state.last_start_time = clock()
  227 
  228 
  229 ###########################################################################
  230 # Profiling API
  231 
  232 def is_active():
  233     return state.profile_level > 0
  234 
  235 
  236 def start():
  237     state.profile_level += 1
  238     if state.profile_level == 1:
  239         state.last_start_time = clock()
  240         rpt = state.remaining_prof_time
  241         state.remaining_prof_time = None
  242         signal.signal(signal.SIGPROF, profile_signal_handler)
  243         itimer.setitimer(itimer.ITIMER_PROF,
  244                          rpt or state.sample_interval, 0.0)
  245         state.gc_time_taken = 0  # dunno
  246 
  247 
  248 def stop():
  249     state.profile_level -= 1
  250     if state.profile_level == 0:
  251         state.accumulate_time(clock())
  252         state.last_start_time = None
  253         rpt = itimer.setitimer(itimer.ITIMER_PROF, 0.0, 0.0)
  254         signal.signal(signal.SIGPROF, signal.SIG_IGN)
  255         state.remaining_prof_time = rpt[0]
  256         state.gc_time_taken = 0  # dunno
  257 
  258 
  259 def reset(frequency=None):
  260     assert state.profile_level == 0, "Can't reset() while statprof is running"
  261     call_data.clear()
  262     state.reset(frequency)
  263 
  264 
  265 ###########################################################################
  266 # Reporting API
  267 
  268 class CallStats(object):
  269     def __init__(self, call_data):
  270         self_samples = call_data.self_sample_count
  271         cum_samples = call_data.cum_sample_count
  272         nsamples = state.sample_count
  273         secs_per_sample = state.accumulated_time / nsamples
  274         basename = os.path.basename(call_data.filename)
  275 
  276         self.name = '%s:%d:%s' % (basename, call_data.lineno, call_data.name)
  277         self.pcnt_time_in_proc = self_samples / nsamples * 100
  278         self.cum_secs_in_proc = cum_samples * secs_per_sample
  279         self.self_secs_in_proc = self_samples * secs_per_sample
  280         self.num_calls = None
  281         self.self_secs_per_call = None
  282         self.cum_secs_per_call = None
  283 
  284     def display(self):
  285         print('%6.2f %9.2f %9.2f  %s' % (self.pcnt_time_in_proc,
  286                                          self.cum_secs_in_proc,
  287                                          self.self_secs_in_proc,
  288                                          self.name))
  289 
  290 
  291 def display():
  292     if state.sample_count == 0:
  293         print('No samples recorded.')
  294         return
  295 
  296     _l = [CallStats(x) for x in call_data.values()]
  297     _l = [(x.self_secs_in_proc, x.cum_secs_in_proc, x) for x in _l]
  298     _l.sort(reverse=True)
  299     _l = [x[2] for x in _l]
  300 
  301     print('%5.5s %10.10s   %7.7s  %-8.8s' % ('%  ', 'cumulative', 'self', ''))
  302     print('%5.5s  %9.9s  %8.8s  %-8.8s'
  303           % ("time", "seconds", "seconds", "name"))
  304 
  305     for x in _l:
  306         x.display()
  307 
  308     print('---')
  309     print('Sample count: %d' % state.sample_count)
  310     print('Total time: %f seconds' % state.accumulated_time)