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 but it is greenthread-aware as well as thread-aware.  Use this module
  27 to profile Eventlet-based applications in preference to either :mod:`profile` or :mod:`cProfile`.
  28 FIXME: No testcases for this module.
  29 """
  30
  31 profile_orig = __import__('profile')
  32 __all__ = profile_orig.__all__
  33
  34 from eventlet.patcher import slurp_properties
  35 slurp_properties(profile_orig, globals(), srckeys=dir(profile_orig))
  36
  37 import new
  38 import sys
  39 import traceback
  40 import functools
  41
  42 from eventlet import greenthread
  43 from eventlet import patcher
  44 from eventlet.support import six
  45
  46 thread = patcher.original('thread')  # non-monkeypatched module needed
  47
  48
  49 # This class provides the start() and stop() functions
  50 class Profile(profile_orig.Profile):
  51     base = profile_orig.Profile
  52
  53     def __init__(self, timer=None, bias=None):
  54         self.current_tasklet = greenthread.getcurrent()
  55         self.thread_id = thread.get_ident()
  56         self.base.__init__(self, timer, bias)
  57         self.sleeping = {}
  58
  59     def __call__(self, *args):
  60         """make callable, allowing an instance to be the profiler"""
  61         r = self.dispatcher(*args)
  62
  63     def _setup(self):
  64         self._has_setup = True
  65         self.cur = None
  66         self.timings = {}
  67         self.current_tasklet = greenthread.getcurrent()
  68         self.thread_id = thread.get_ident()
  69         self.simulate_call("profiler")
  70
  71     def start(self, name="start"):
  72         if getattr(self, "running", False):
  73             return
  74         self._setup()
  75         self.simulate_call("start")
  76         self.running = True
  77         sys.setprofile(self.dispatcher)
  78
  79     def stop(self):
  80         sys.setprofile(None)
  81         self.running = False
  82         self.TallyTimings()
  83
  84     # special cases for the original run commands, makin sure to
  85     # clear the timer context.
  86     def runctx(self, cmd, globals, locals):
  87         if not getattr(self, "_has_setup", False):
  88             self._setup()
  89         try:
  90             return profile_orig.Profile.runctx(self, cmd, globals, locals)
  91         finally:
  92             self.TallyTimings()
  93
  94     def runcall(self, func, *args, **kw):
  95         if not getattr(self, "_has_setup", False):
  96             self._setup()
  97         try:
  98             return profile_orig.Profile.runcall(self, func, *args, **kw)
  99         finally:
 100             self.TallyTimings()
 101
 102     def trace_dispatch_return_extend_back(self, frame, t):
 103         """A hack function to override error checking in parent class.  It
 104         allows invalid returns (where frames weren't preveiously entered into
 105         the profiler) which can happen for all the tasklets that suddenly start
 106         to get monitored. This means that the time will eventually be attributed
 107         to a call high in the chain, when there is a tasklet switch
 108         """
 109         if isinstance(self.cur[-2], Profile.fake_frame):
 110             return False
 111             self.trace_dispatch_call(frame, 0)
 112         return self.trace_dispatch_return(frame, t)
 113
 114     def trace_dispatch_c_return_extend_back(self, frame, t):
 115         # same for c return
 116         if isinstance(self.cur[-2], Profile.fake_frame):
 117             return False  # ignore bogus returns
 118             self.trace_dispatch_c_call(frame, 0)
 119         return self.trace_dispatch_return(frame, t)
 120
 121     # Add "return safety" to the dispatchers
 122     dispatch = dict(profile_orig.Profile.dispatch)
 123     dispatch.update({
 124         "return": trace_dispatch_return_extend_back,
 125         "c_return": trace_dispatch_c_return_extend_back,
 126     })
 127
 128     def SwitchTasklet(self, t0, t1, t):
 129         # tally the time spent in the old tasklet
 130         pt, it, et, fn, frame, rcur = self.cur
 131         cur = (pt, it + t, et, fn, frame, rcur)
 132
 133         # we are switching to a new tasklet, store the old
 134         self.sleeping[t0] = cur, self.timings
 135         self.current_tasklet = t1
 136
 137         # find the new one
 138         try:
 139             self.cur, self.timings = self.sleeping.pop(t1)
 140         except KeyError:
 141             self.cur, self.timings = None, {}
 142             self.simulate_call("profiler")
 143             self.simulate_call("new_tasklet")
 144
 145     def ContextWrap(f):
 146         @functools.wraps(f)
 147         def ContextWrapper(self, arg, t):
 148             current = greenthread.getcurrent()
 149             if current != self.current_tasklet:
 150                 self.SwitchTasklet(self.current_tasklet, current, t)
 151                 t = 0.0  # the time was billed to the previous tasklet
 152             return f(self, arg, t)
 153         return ContextWrapper
 154
 155     # Add automatic tasklet detection to the callbacks.
 156     dispatch = dict([(key, ContextWrap(val)) for key, val in six.iteritems(dispatch)])
 157
 158     def TallyTimings(self):
 159         oldtimings = self.sleeping
 160         self.sleeping = {}
 161
 162         # first, unwind the main "cur"
 163         self.cur = self.Unwind(self.cur, self.timings)
 164
 165         # we must keep the timings dicts separate for each tasklet, since it contains
 166         # the 'ns' item, recursion count of each function in that tasklet.  This is
 167         # used in the Unwind dude.
 168         for tasklet, (cur, timings) in six.iteritems(oldtimings):
 169             self.Unwind(cur, timings)
 170
 171             for k, v in six.iteritems(timings):
 172                 if k not in self.timings:
 173                     self.timings[k] = v
 174                 else:
 175                     # accumulate all to the self.timings
 176                     cc, ns, tt, ct, callers = self.timings[k]
 177                     # ns should be 0 after unwinding
 178                     cc += v[0]
 179                     tt += v[2]
 180                     ct += v[3]
 181                     for k1, v1 in six.iteritems(v[4]):
 182                         callers[k1] = callers.get(k1, 0) + v1
 183                     self.timings[k] = cc, ns, tt, ct, callers
 184
 185     def Unwind(self, cur, timings):
 186         "A function to unwind a 'cur' frame and tally the results"
 187         "see profile.trace_dispatch_return() for details"
 188         # also see simulate_cmd_complete()
 189         while(cur[-1]):
 190             rpt, rit, ret, rfn, frame, rcur = cur
 191             frame_total = rit + ret
 192
 193             if rfn in timings:
 194                 cc, ns, tt, ct, callers = timings[rfn]
 195             else:
 196                 cc, ns, tt, ct, callers = 0, 0, 0, 0, {}
 197
 198             if not ns:
 199                 ct = ct + frame_total
 200                 cc = cc + 1
 201
 202             if rcur:
 203                 ppt, pit, pet, pfn, pframe, pcur = rcur
 204             else:
 205                 pfn = None
 206
 207             if pfn in callers:
 208                 callers[pfn] = callers[pfn] + 1  # hack: gather more
 209             elif pfn:
 210                 callers[pfn] = 1
 211
 212             timings[rfn] = cc, ns - 1, tt + rit, ct, callers
 213
 214             ppt, pit, pet, pfn, pframe, pcur = rcur
 215             rcur = ppt, pit + rpt, pet + frame_total, pfn, pframe, pcur
 216             cur = rcur
 217         return cur
 218
 219
 220 # run statements shamelessly stolen from profile.py
 221 def run(statement, filename=None, sort=-1):
 222     """Run statement under profiler optionally saving results in filename
 223
 224     This function takes a single argument that can be passed to the
 225     "exec" statement, and an optional file name.  In all cases this
 226     routine attempts to "exec" its first argument and gather profiling
 227     statistics from the execution. If no file name is present, then this
 228     function automatically prints a simple profiling report, sorted by the
 229     standard name string (file/line/function-name) that is presented in
 230     each line.
 231     """
 232     prof = Profile()
 233     try:
 234         prof = prof.run(statement)
 235     except SystemExit:
 236         pass
 237     if filename is not None:
 238         prof.dump_stats(filename)
 239     else:
 240         return prof.print_stats(sort)
 241
 242
 243 def runctx(statement, globals, locals, filename=None):
 244     """Run statement under profiler, supplying your own globals and locals,
 245     optionally saving results in filename.
 246
 247     statement and filename have the same semantics as profile.run
 248     """
 249     prof = Profile()
 250     try:
 251         prof = prof.runctx(statement, globals, locals)
 252     except SystemExit:
 253         pass
 254
 255     if filename is not None:
 256         prof.dump_stats(filename)
 257     else:
 258         return prof.print_stats()