1
 
# Copyright (C) 2006, 2008, 2009, 2010 by Canonical Ltd
 
2
 
# Written by John Arbash Meinel <john@arbash-meinel.com>
 
4
 
# This program is free software; you can redistribute it and/or modify
 
5
 
# it under the terms of the GNU General Public License as published by
 
6
 
# the Free Software Foundation; either version 2 of the License, or
 
7
 
# (at your option) any later version.
 
9
 
# This program is distributed in the hope that it will be useful,
 
10
 
# but WITHOUT ANY WARRANTY; without even the implied warranty of
 
11
 
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 
12
 
# GNU General Public License for more details.
 
14
 
# You should have received a copy of the GNU General Public License
 
15
 
# along with this program; if not, write to the Free Software
 
16
 
# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
 
18
 
"""A custom importer and regex compiler which logs time spent."""
 
24
 
if sys.version_info < (2, 5, 0):
 
36
 
if sys.platform == 'win32':
 
40
 
def stack_add(name, frame_name, frame_lineno, scope_name=None):
 
41
 
    """Start a new record on the stack"""
 
44
 
    this_stack = (_cur_id, name)
 
47
 
        _total_stack[_parent_stack[-1]].append(this_stack)
 
48
 
    _total_stack[this_stack] = []
 
49
 
    _parent_stack.append(this_stack)
 
50
 
    _info[this_stack] = [len(_parent_stack)-1, frame_name, frame_lineno, scope_name]
 
55
 
def stack_finish(this, cost):
 
56
 
    """Finish a given entry, and record its cost in time"""
 
59
 
    assert _parent_stack[-1] == this, \
 
60
 
        'import stack does not end with this %s: %s' % (this, _parent_stack)
 
62
 
    _info[this].append(cost)
 
65
 
def log_stack_info(out_file, sorted=True, hide_fast=True):
 
66
 
    # Find all of the roots with import = 0
 
67
 
    out_file.write('%5s %5s %-40s @ %s:%s\n'
 
68
 
        % ('cum', 'inline', 'name', 'file', 'line'))
 
69
 
    todo = [(value[-1], key) for key,value in _info.iteritems() if value[0] == 0]
 
75
 
        cum_time, cur = todo.pop()
 
76
 
        children = _total_stack[cur]
 
81
 
        if hide_fast and info[-1] < 0.0001:
 
84
 
        # Compute the module time by removing the children times
 
86
 
        for child in children:
 
88
 
            mod_time -= c_info[-1]
 
89
 
            c_times.append((c_info[-1], child))
 
91
 
        # indent, cum_time, mod_time, name,
 
92
 
        # scope_name, frame_name, frame_lineno
 
93
 
        out_file.write('%5.1f %5.1f %-40s @ %s:%d\n'
 
94
 
            % (info[-1]*1000., mod_time*1000.,
 
95
 
               ('+'*info[0] + cur[1]),
 
105
 
_real_import = __import__
 
107
 
def timed_import(name, globals=None, locals=None, fromlist=None, level=None):
 
108
 
    """Wrap around standard importer to log import time"""
 
109
 
    # normally there are 4, but if this is called as __import__ eg by
 
110
 
    # /usr/lib/python2.6/email/__init__.py then there may be only one
 
112
 
    # level is only passed by python2.6
 
115
 
        # can't determine the scope name afaics; we could peek up the stack to
 
116
 
        # see where this is being called from, but it should be a rare case.
 
119
 
        scope_name = globals.get('__name__', None)
 
120
 
        if scope_name is None:
 
121
 
            scope_name = globals.get('__file__', None)
 
122
 
        if scope_name is None:
 
123
 
            scope_name = globals.keys()
 
125
 
            # Trim out paths before bzrlib
 
126
 
            loc = scope_name.find('bzrlib')
 
128
 
                scope_name = scope_name[loc:]
 
129
 
            # For stdlib, trim out early paths
 
130
 
            loc = scope_name.find('python2.4')
 
132
 
                scope_name = scope_name[loc:]
 
134
 
    # Figure out the frame that is doing the importing
 
135
 
    frame = sys._getframe(1)
 
136
 
    frame_name = frame.f_globals.get('__name__', '<unknown>')
 
138
 
    if frame_name.endswith('demandload'):
 
139
 
        # If this was demandloaded, we have 3 frames to ignore
 
140
 
        extra = '(demandload) '
 
141
 
        frame = sys._getframe(4)
 
142
 
        frame_name = frame.f_globals.get('__name__', '<unknown>')
 
143
 
    elif frame_name.endswith('lazy_import'):
 
144
 
        # If this was lazily imported, we have 3 frames to ignore
 
146
 
        frame = sys._getframe(4)
 
147
 
        frame_name = frame.f_globals.get('__name__', '<unknown>')
 
149
 
        extra += ' [%s]' % (', '.join(map(str, fromlist)),)
 
150
 
    frame_lineno = frame.f_lineno
 
152
 
    this = stack_add(extra + name, frame_name, frame_lineno, scope_name)
 
157
 
        mod = _real_import(name, globals, locals, fromlist)
 
159
 
        tload = _timer()-tstart
 
160
 
        stack_finish(this, tload)
 
165
 
_real_compile = re._compile
 
168
 
def timed_compile(*args, **kwargs):
 
169
 
    """Log how long it takes to compile a regex"""
 
171
 
    # And who is requesting this?
 
172
 
    frame = sys._getframe(2)
 
173
 
    frame_name = frame.f_globals.get('__name__', '<unknown>')
 
176
 
    if frame_name.endswith('lazy_regex'):
 
177
 
        # If this was lazily compiled, we have 3 more frames to ignore
 
179
 
        frame = sys._getframe(5)
 
180
 
        frame_name = frame.f_globals.get('__name__', '<unknown>')
 
181
 
    frame_lineno = frame.f_lineno
 
182
 
    this = stack_add(extra+repr(args[0]), frame_name, frame_lineno)
 
186
 
        # Measure the compile time
 
187
 
        comp = _real_compile(*args, **kwargs)
 
189
 
        tcompile = _timer() - tstart
 
190
 
        stack_finish(this, tcompile)
 
196
 
    """Install the hooks for measuring import and regex compile time."""
 
197
 
    __builtins__['__import__'] = timed_import
 
198
 
    re._compile = timed_compile
 
202
 
    """Remove the import and regex compile timing hooks."""
 
203
 
    __builtins__['__import__'] = _real_import
 
204
 
    re._compile = _real_compile