From 25335618bf8755ce6b116ee14f47f5a1f2c821e9 Mon Sep 17 00:00:00 2001 From: Lorry Date: Wed, 22 Aug 2012 15:47:16 +0100 Subject: Tarball conversion --- profile_imports.py | 201 +++++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 201 insertions(+) create mode 100644 profile_imports.py (limited to 'profile_imports.py') diff --git a/profile_imports.py b/profile_imports.py new file mode 100644 index 0000000..d12ee48 --- /dev/null +++ b/profile_imports.py @@ -0,0 +1,201 @@ +# Copyright (C) 2006, 2008, 2009, 2010 by Canonical Ltd +# Written by John Arbash Meinel +# +# This program is free software; you can redistribute it and/or modify +# it under the terms of the GNU General Public License as published by +# the Free Software Foundation; either version 2 of the License, or +# (at your option) any later version. +# +# This program is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. +# +# You should have received a copy of the GNU General Public License +# along with this program; if not, write to the Free Software +# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA + +"""A custom importer and regex compiler which logs time spent.""" + +import sys +import time + + +import re + + +_parent_stack = [] +_total_stack = {} +_info = {} +_cur_id = 0 +_timer = time.time +if sys.platform == 'win32': + _timer = time.clock + + +def stack_add(name, frame_name, frame_lineno, scope_name=None): + """Start a new record on the stack""" + global _cur_id + _cur_id += 1 + this_stack = (_cur_id, name) + + if _parent_stack: + _total_stack[_parent_stack[-1]].append(this_stack) + _total_stack[this_stack] = [] + _parent_stack.append(this_stack) + _info[this_stack] = [len(_parent_stack)-1, frame_name, frame_lineno, scope_name] + + return this_stack + + +def stack_finish(this, cost): + """Finish a given entry, and record its cost in time""" + global _parent_stack + + assert _parent_stack[-1] == this, \ + 'import stack does not end with this %s: %s' % (this, _parent_stack) + _parent_stack.pop() + _info[this].append(cost) + + +def log_stack_info(out_file, sorted=True, hide_fast=True): + # Find all of the roots with import = 0 + out_file.write('%5s %5s %-40s @ %s:%s\n' + % ('cum', 'inline', 'name', 'file', 'line')) + todo = [(value[-1], key) for key,value in _info.iteritems() if value[0] == 0] + + if sorted: + todo.sort() + + while todo: + cum_time, cur = todo.pop() + children = _total_stack[cur] + + c_times = [] + + info = _info[cur] + if hide_fast and info[-1] < 0.0001: + continue + + # Compute the module time by removing the children times + mod_time = info[-1] + for child in children: + c_info = _info[child] + mod_time -= c_info[-1] + c_times.append((c_info[-1], child)) + + # indent, cum_time, mod_time, name, + # scope_name, frame_name, frame_lineno + out_file.write('%5.1f %5.1f %-40s @ %s:%d\n' + % (info[-1]*1000., mod_time*1000., + ('+'*info[0] + cur[1]), + info[1], info[2])) + + if sorted: + c_times.sort() + else: + c_times.reverse() + todo.extend(c_times) + + +_real_import = __import__ + +def timed_import(name, globals=None, locals=None, fromlist=None, level=None): + """Wrap around standard importer to log import time""" + # normally there are 4, but if this is called as __import__ eg by + # /usr/lib/python2.6/email/__init__.py then there may be only one + # parameter + # level is only passed by python2.6 + + if globals is None: + # can't determine the scope name afaics; we could peek up the stack to + # see where this is being called from, but it should be a rare case. + scope_name = None + else: + scope_name = globals.get('__name__', None) + if scope_name is None: + scope_name = globals.get('__file__', None) + if scope_name is None: + scope_name = globals.keys() + else: + # Trim out paths before bzrlib + loc = scope_name.find('bzrlib') + if loc != -1: + scope_name = scope_name[loc:] + # For stdlib, trim out early paths + loc = scope_name.find('python2.4') + if loc != -1: + scope_name = scope_name[loc:] + + # Figure out the frame that is doing the importing + frame = sys._getframe(1) + frame_name = frame.f_globals.get('__name__', '') + extra = '' + if frame_name.endswith('demandload'): + # If this was demandloaded, we have 3 frames to ignore + extra = '(demandload) ' + frame = sys._getframe(4) + frame_name = frame.f_globals.get('__name__', '') + elif frame_name.endswith('lazy_import'): + # If this was lazily imported, we have 3 frames to ignore + extra = '[l] ' + frame = sys._getframe(4) + frame_name = frame.f_globals.get('__name__', '') + if fromlist: + extra += ' [%s]' % (', '.join(map(str, fromlist)),) + frame_lineno = frame.f_lineno + + this = stack_add(extra + name, frame_name, frame_lineno, scope_name) + + tstart = _timer() + try: + # Do the import + mod = _real_import(name, globals, locals, fromlist) + finally: + tload = _timer()-tstart + stack_finish(this, tload) + + return mod + + +_real_compile = re._compile + + +def timed_compile(*args, **kwargs): + """Log how long it takes to compile a regex""" + + # And who is requesting this? + frame = sys._getframe(2) + frame_name = frame.f_globals.get('__name__', '') + + extra = '' + if frame_name.endswith('lazy_regex'): + # If this was lazily compiled, we have 3 more frames to ignore + extra = '[l] ' + frame = sys._getframe(5) + frame_name = frame.f_globals.get('__name__', '') + frame_lineno = frame.f_lineno + this = stack_add(extra+repr(args[0]), frame_name, frame_lineno) + + tstart = _timer() + try: + # Measure the compile time + comp = _real_compile(*args, **kwargs) + finally: + tcompile = _timer() - tstart + stack_finish(this, tcompile) + + return comp + + +def install(): + """Install the hooks for measuring import and regex compile time.""" + __builtins__['__import__'] = timed_import + re._compile = timed_compile + + +def uninstall(): + """Remove the import and regex compile timing hooks.""" + __builtins__['__import__'] = _real_import + re._compile = _real_compile + -- cgit v1.2.1