/brz/remove-bazaar

To get this branch, use:
bzr branch http://gegoxaren.bato24.eu/bzr/brz/remove-bazaar

« back to all changes in this revision

Viewing changes to profile_imports.py

[merge] robertc's integration, updated tests to check for retcode=3

Show diffs side-by-side

added added

removed removed

Lines of Context:
1
 
# Copyright (C) 2006, 2008, 2009, 2010 by Canonical Ltd
2
 
# Written by John Arbash Meinel <john@arbash-meinel.com>
3
 
#
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.
8
 
#
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.
13
 
#
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
17
 
 
18
 
"""A custom importer and regex compiler which logs time spent."""
19
 
 
20
 
from __future__ import absolute_import
21
 
 
22
 
import re
23
 
import sys
24
 
import time
25
 
 
26
 
 
27
 
_parent_stack = []
28
 
_total_stack = {}
29
 
_info = {}
30
 
_cur_id = 0
31
 
_timer = time.time
32
 
if sys.platform == 'win32':
33
 
    _timer = time.clock
34
 
 
35
 
 
36
 
def stack_add(name, frame_name, frame_lineno, scope_name=None):
37
 
    """Start a new record on the stack"""
38
 
    global _cur_id
39
 
    _cur_id += 1
40
 
    this_stack = (_cur_id, name)
41
 
 
42
 
    if _parent_stack:
43
 
        _total_stack[_parent_stack[-1]].append(this_stack)
44
 
    _total_stack[this_stack] = []
45
 
    _parent_stack.append(this_stack)
46
 
    _info[this_stack] = [len(_parent_stack) - 1, frame_name, frame_lineno,
47
 
                         scope_name]
48
 
 
49
 
    return this_stack
50
 
 
51
 
 
52
 
def stack_finish(this, cost):
53
 
    """Finish a given entry, and record its cost in time"""
54
 
    global _parent_stack
55
 
 
56
 
    assert _parent_stack[-1] == this, \
57
 
        'import stack does not end with this %s: %s' % (this, _parent_stack)
58
 
    _parent_stack.pop()
59
 
    _info[this].append(cost)
60
 
 
61
 
 
62
 
def log_stack_info(out_file, sorted=True, hide_fast=True):
63
 
    # Find all of the roots with import = 0
64
 
    out_file.write(
65
 
        '%5s %5s %-40s @ %s:%s\n'
66
 
        % ('cum', 'local', 'name', 'file', 'line'))
67
 
    todo = [(value[-1], key) for key, value in _info.items() if value[0] == 0]
68
 
 
69
 
    if sorted:
70
 
        todo.sort()
71
 
 
72
 
    while todo:
73
 
        cum_time, cur = todo.pop()
74
 
        children = _total_stack[cur]
75
 
 
76
 
        c_times = []
77
 
 
78
 
        info = _info[cur]
79
 
        if hide_fast and info[-1] < 0.0001:
80
 
            continue
81
 
 
82
 
        # Compute the module time by removing the children times
83
 
        mod_time = info[-1]
84
 
        for child in children:
85
 
            c_info = _info[child]
86
 
            mod_time -= c_info[-1]
87
 
            c_times.append((c_info[-1], child))
88
 
 
89
 
        # indent, cum_time, mod_time, name,
90
 
        # scope_name, frame_name, frame_lineno
91
 
        out_file.write(
92
 
            '%5.1f %5.1f %-40s @ %s:%d\n' % (
93
 
                info[-1] * 1000., mod_time * 1000.,
94
 
                ('+' * info[0] + cur[1]), info[1], info[2]))
95
 
 
96
 
        if sorted:
97
 
            c_times.sort()
98
 
        else:
99
 
            c_times.reverse()
100
 
        todo.extend(c_times)
101
 
 
102
 
 
103
 
_real_import = __import__
104
 
 
105
 
def timed_import(name, globals=None, locals=None, fromlist=None, level=0):
106
 
    """Wrap around standard importer to log import time"""
107
 
    # normally there are 4, but if this is called as __import__ eg by
108
 
    # /usr/lib/python2.6/email/__init__.py then there may be only one
109
 
    # parameter
110
 
    # level has different default between Python 2 and 3, but codebase
111
 
    # uses `from __future__ import absolute_import` so can just use 0.
112
 
 
113
 
    if globals is None:
114
 
        # can't determine the scope name afaics; we could peek up the stack to
115
 
        # see where this is being called from, but it should be a rare case.
116
 
        scope_name = None
117
 
    else:
118
 
        scope_name = globals.get('__name__', None)
119
 
        if scope_name is None:
120
 
            scope_name = globals.get('__file__', None)
121
 
        if scope_name is None:
122
 
            scope_name = globals.keys()
123
 
        else:
124
 
            # Trim out paths before breezy
125
 
            loc = scope_name.find('breezy')
126
 
            if loc != -1:
127
 
                scope_name = scope_name[loc:]
128
 
 
129
 
    # Figure out the frame that is doing the importing
130
 
    frame = sys._getframe(1)
131
 
    frame_name = frame.f_globals.get('__name__', '<unknown>')
132
 
    extra = ''
133
 
    if frame_name.endswith('demandload'):
134
 
        # If this was demandloaded, we have 3 frames to ignore
135
 
        extra = '(demandload) '
136
 
        frame = sys._getframe(4)
137
 
        frame_name = frame.f_globals.get('__name__', '<unknown>')
138
 
    elif frame_name.endswith('lazy_import'):
139
 
        # If this was lazily imported, we have 3 frames to ignore
140
 
        extra = '[l] '
141
 
        frame = sys._getframe(4)
142
 
        frame_name = frame.f_globals.get('__name__', '<unknown>')
143
 
    if fromlist:
144
 
        extra += ' [%s]' % (', '.join(map(str, fromlist)),)
145
 
    frame_lineno = frame.f_lineno
146
 
 
147
 
    this = stack_add(extra + name, frame_name, frame_lineno, scope_name)
148
 
 
149
 
    tstart = _timer()
150
 
    try:
151
 
        # Do the import
152
 
        return _real_import(name, globals, locals, fromlist, level=level)
153
 
    finally:
154
 
        tload = _timer() - tstart
155
 
        stack_finish(this, tload)
156
 
 
157
 
 
158
 
def _repr_regexp(pattern, max_len=30):
159
 
    """Present regexp pattern for logging, truncating if over max_len."""
160
 
    if len(pattern) > max_len:
161
 
        return repr(pattern[:max_len - 3]) + "..."
162
 
    return repr(pattern)
163
 
 
164
 
 
165
 
_real_compile = re._compile
166
 
 
167
 
 
168
 
def timed_compile(*args, **kwargs):
169
 
    """Log how long it takes to compile a regex"""
170
 
 
171
 
    # And who is requesting this?
172
 
    frame = sys._getframe(2)
173
 
    frame_name = frame.f_globals.get('__name__', '<unknown>')
174
 
 
175
 
    extra = ''
176
 
    if frame_name.endswith('lazy_regex'):
177
 
        # If this was lazily compiled, we have 3 more frames to ignore
178
 
        extra = '[l] '
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_regexp(args[0]), frame_name, frame_lineno)
183
 
 
184
 
    tstart = _timer()
185
 
    try:
186
 
        # Measure the compile time
187
 
        comp = _real_compile(*args, **kwargs)
188
 
    finally:
189
 
        tcompile = _timer() - tstart
190
 
        stack_finish(this, tcompile)
191
 
 
192
 
    return comp
193
 
 
194
 
 
195
 
def install():
196
 
    """Install the hooks for measuring import and regex compile time."""
197
 
    __builtins__['__import__'] = timed_import
198
 
    re._compile = timed_compile
199
 
 
200
 
 
201
 
def uninstall():
202
 
    """Remove the import and regex compile timing hooks."""
203
 
    __builtins__['__import__'] = _real_import
204
 
    re._compile = _real_compile