eventlet/eventlet/green/profile.py

   1 # Copyright (c) 2010, CCP Games
   2 # All rights reserved.
   3 #
   4 # Redistribution and use in source and binary forms, with or without
   5 # modification, are permitted provided that the following conditions are met:
   6 #     * Redistributions of source code must retain the above copyright
   7 #       notice, this list of conditions and the following disclaimer.
   8 #     * Redistributions in binary form must reproduce the above copyright
   9 #       notice, this list of conditions and the following disclaimer in the
  10 #       documentation and/or other materials provided with the distribution.
  11 #     * Neither the name of CCP Games nor the
  12 #       names of its contributors may be used to endorse or promote products
  13 #       derived from this software without specific prior written permission.
  14 #
  15 # THIS SOFTWARE IS PROVIDED BY CCP GAMES ``AS IS'' AND ANY
  16 # EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED
  17 # WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE
  18 # DISCLAIMED. IN NO EVENT SHALL CCP GAMES BE LIABLE FOR ANY
  19 # DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES
  20 # (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES;
  21 # LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND
  22 # ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
  23 # (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS
  24 # SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
  25
  26 """This module is API-equivalent to the standard library :mod:`profile` module
  27 lbut it is greenthread-aware as well as thread-aware.  Use this module
  28 to profile Eventlet-based applications in preference to either :mod:`profile` or :mod:`cProfile`.
  29 FIXME: No testcases for this module.
  30 """
  31
  32 profile_orig = __import__('profile')
  33 __all__ = profile_orig.__all__
  34
  35 from eventlet.patcher import slurp_properties
  36 slurp_properties(profile_orig, globals(), srckeys=dir(profile_orig))
  37
  38 import sys
  39 import functools
  40
  41 from eventlet import greenthread
  42 from eventlet import patcher
  43 from eventlet.support import six
  44
  45 thread = patcher.original('thread')  # non-monkeypatched module needed
  46
  47
  48 # This class provides the start() and stop() functions
  49 class Profile(profile_orig.Profile):
  50     base = profile_orig.Profile
  51
  52     def __init__(self, timer=None, bias=None):
  53         self.current_tasklet = greenthread.getcurrent()
  54         self.thread_id = thread.get_ident()
  55         self.base.__init__(self, timer, bias)
  56         self.sleeping = {}
  57
  58     def __call__(self, *args):
  59         """make callable, allowing an instance to be the profiler"""
  60         self.dispatcher(*args)
  61
  62     def _setup(self):
  63         self._has_setup = True
  64         self.cur = None
  65         self.timings = {}
  66         self.current_tasklet = greenthread.getcurrent()
  67         self.thread_id = thread.get_ident()
  68         self.simulate_call("profiler")
  69
  70     def start(self, name="start"):
  71         if getattr(self, "running", False):
  72             return
  73         self._setup()
  74         self.simulate_call("start")
  75         self.running = True
  76         sys.setprofile(self.dispatcher)
  77
  78     def stop(self):
  79         sys.setprofile(None)
  80         self.running = False
  81         self.TallyTimings()
  82
  83     # special cases for the original run commands, makin sure to
  84     # clear the timer context.
  85     def runctx(self, cmd, globals, locals):
  86         if not getattr(self, "_has_setup", False):
  87             self._setup()
  88         try:
  89             return profile_orig.Profile.runctx(self, cmd, globals, locals)
  90         finally:
  91             self.TallyTimings()
  92
  93     def runcall(self, func, *args, **kw):
  94         if not getattr(self, "_has_setup", False):
  95             self._setup()
  96         try:
  97             return profile_orig.Profile.runcall(self, func, *args, **kw)
  98         finally:
  99             self.TallyTimings()
 100
 101     def trace_dispatch_return_extend_back(self, frame, t):
 102         """A hack function to override error checking in parent class.  It
 103         allows invalid returns (where frames weren't preveiously entered into
 104         the profiler) which can happen for all the tasklets that suddenly start
 105         to get monitored. This means that the time will eventually be attributed
 106         to a call high in the chain, when there is a tasklet switch
 107         """
 108         if isinstance(self.cur[-2], Profile.fake_frame):
 109             return False
 110             self.trace_dispatch_call(frame, 0)
 111         return self.trace_dispatch_return(frame, t)
 112
 113     def trace_dispatch_c_return_extend_back(self, frame, t):
 114         # same for c return
 115         if isinstance(self.cur[-2], Profile.fake_frame):
 116             return False  # ignore bogus returns
 117             self.trace_dispatch_c_call(frame, 0)
 118         return self.trace_dispatch_return(frame, t)
 119
 120     # Add "return safety" to the dispatchers
 121     dispatch = dict(profile_orig.Profile.dispatch)
 122     dispatch.update({
 123         "return": trace_dispatch_return_extend_back,
 124         "c_return": trace_dispatch_c_return_extend_back,
 125     })
 126
 127     def SwitchTasklet(self, t0, t1, t):
 128         # tally the time spent in the old tasklet
 129         pt, it, et, fn, frame, rcur = self.cur
 130         cur = (pt, it + t, et, fn, frame, rcur)
 131
 132         # we are switching to a new tasklet, store the old
 133         self.sleeping[t0] = cur, self.timings
 134         self.current_tasklet = t1
 135
 136         # find the new one
 137         try:
 138             self.cur, self.timings = self.sleeping.pop(t1)
 139         except KeyError:
 140             self.cur, self.timings = None, {}
 141             self.simulate_call("profiler")
 142             self.simulate_call("new_tasklet")
 143
 144     def ContextWrap(f):
 145         @functools.wraps(f)
 146         def ContextWrapper(self, arg, t):
 147             current = greenthread.getcurrent()
 148             if current != self.current_tasklet:
 149                 self.SwitchTasklet(self.current_tasklet, current, t)
 150                 t = 0.0  # the time was billed to the previous tasklet
 151             return f(self, arg, t)
 152         return ContextWrapper
 153
 154     # Add automatic tasklet detection to the callbacks.
 155     dispatch = dict([(key, ContextWrap(val)) for key, val in six.iteritems(dispatch)])
 156
 157     def TallyTimings(self):
 158         oldtimings = self.sleeping
 159         self.sleeping = {}
 160
 161         # first, unwind the main "cur"
 162         self.cur = self.Unwind(self.cur, self.timings)
 163
 164         # we must keep the timings dicts separate for each tasklet, since it contains
 165         # the 'ns' item, recursion count of each function in that tasklet.  This is
 166         # used in the Unwind dude.
 167         for tasklet, (cur, timings) in six.iteritems(oldtimings):
 168             self.Unwind(cur, timings)
 169
 170             for k, v in six.iteritems(timings):
 171                 if k not in self.timings:
 172                     self.timings[k] = v
 173                 else:
 174                     # accumulate all to the self.timings
 175                     cc, ns, tt, ct, callers = self.timings[k]
 176                     # ns should be 0 after unwinding
 177                     cc += v[0]
 178                     tt += v[2]
 179                     ct += v[3]
 180                     for k1, v1 in six.iteritems(v[4]):
 181                         callers[k1] = callers.get(k1, 0) + v1
 182                     self.timings[k] = cc, ns, tt, ct, callers
 183
 184     def Unwind(self, cur, timings):
 185         "A function to unwind a 'cur' frame and tally the results"
 186         "see profile.trace_dispatch_return() for details"
 187         # also see simulate_cmd_complete()
 188         while(cur[-1]):
 189             rpt, rit, ret, rfn, frame, rcur = cur
 190             frame_total = rit + ret
 191
 192             if rfn in timings:
 193                 cc, ns, tt, ct, callers = timings[rfn]
 194             else:
 195                 cc, ns, tt, ct, callers = 0, 0, 0, 0, {}
 196
 197             if not ns:
 198                 ct = ct + frame_total
 199                 cc = cc + 1
 200
 201             if rcur:
 202                 ppt, pit, pet, pfn, pframe, pcur = rcur
 203             else:
 204                 pfn = None
 205
 206             if pfn in callers:
 207                 callers[pfn] = callers[pfn] + 1  # hack: gather more
 208             elif pfn:
 209                 callers[pfn] = 1
 210
 211             timings[rfn] = cc, ns - 1, tt + rit, ct, callers
 212
 213             ppt, pit, pet, pfn, pframe, pcur = rcur
 214             rcur = ppt, pit + rpt, pet + frame_total, pfn, pframe, pcur
 215             cur = rcur
 216         return cur
 217
 218
 219 # run statements shamelessly stolen from profile.py
 220 def run(statement, filename=None, sort=-1):
 221     """Run statement under profiler optionally saving results in filename
 222
 223     This function takes a single argument that can be passed to the
 224     "exec" statement, and an optional file name.  In all cases this
 225     routine attempts to "exec" its first argument and gather profiling
 226     statistics from the execution. If no file name is present, then this
 227     function automatically prints a simple profiling report, sorted by the
 228     standard name string (file/line/function-name) that is presented in
 229     each line.
 230     """
 231     prof = Profile()
 232     try:
 233         prof = prof.run(statement)
 234     except SystemExit:
 235         pass
 236     if filename is not None:
 237         prof.dump_stats(filename)
 238     else:
 239         return prof.print_stats(sort)
 240
 241
 242 def runctx(statement, globals, locals, filename=None):
 243     """Run statement under profiler, supplying your own globals and locals,
 244     optionally saving results in filename.
 245
 246     statement and filename have the same semantics as profile.run
 247     """
 248     prof = Profile()
 249     try:
 250         prof = prof.runctx(statement, globals, locals)
 251     except SystemExit:
 252         pass
 253
 254     if filename is not None:
 255         prof.dump_stats(filename)
 256     else:
 257         return prof.print_stats()