~bzr-pqm/bzr/bzr.dev

4988.10.5 by John Arbash Meinel
Merge bzr.dev 5021 to resolve NEWS
1
# Copyright (C) 2006, 2008, 2009, 2010 by Canonical Ltd
1724.2.13 by John Arbash Meinel
Remove pprint dependency
2
# Written by John Arbash Meinel <john@arbash-meinel.com>
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
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
4183.7.1 by Sabin Iacob
update FSF mailing address
16
# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
17
1724.2.7 by John Arbash Meinel
It seems you cannot override __builtins__.__import__ in a sub-module.
18
"""A custom importer and regex compiler which logs time spent."""
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
19
20
import sys
21
import time
1724.2.7 by John Arbash Meinel
It seems you cannot override __builtins__.__import__ in a sub-module.
22
23
4792.9.2 by Martin Pool
profile_imports avoids deprecation warning by using either re or sre depending on python version
24
if sys.version_info < (2, 5, 0):
25
    import sre
26
    re = sre
27
else:
28
    import re
29
30
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
31
_parent_stack = []
32
_total_stack = {}
33
_info = {}
34
_cur_id = 0
3696.1.1 by John Arbash Meinel
Use the right timing function on win32
35
_timer = time.time
36
if sys.platform == 'win32':
37
    _timer = time.clock
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
38
39
40
def stack_add(name, frame_name, frame_lineno, scope_name=None):
41
    """Start a new record on the stack"""
42
    global _cur_id
43
    _cur_id += 1
44
    this_stack = (_cur_id, name)
45
46
    if _parent_stack:
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]
51
52
    return this_stack
53
54
55
def stack_finish(this, cost):
56
    """Finish a given entry, and record its cost in time"""
57
    global _parent_stack
58
1724.2.13 by John Arbash Meinel
Remove pprint dependency
59
    assert _parent_stack[-1] == this, \
60
        'import stack does not end with this %s: %s' % (this, _parent_stack)
61
    _parent_stack.pop()
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
62
    _info[this].append(cost)
63
64
1724.2.12 by John Arbash Meinel
Default to hiding things that take less that .1ms to keep the output clean.
65
def log_stack_info(out_file, sorted=True, hide_fast=True):
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
66
    # Find all of the roots with import = 0
5017.2.2 by Martin Pool
Add import tariff tests
67
    out_file.write('%5s %5s %-40s @ %s:%s\n'
68
        % ('cum', 'inline', 'name', 'file', 'line'))
1724.2.10 by John Arbash Meinel
More layout work
69
    todo = [(value[-1], key) for key,value in _info.iteritems() if value[0] == 0]
70
71
    if sorted:
72
        todo.sort()
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
73
74
    while todo:
1724.2.10 by John Arbash Meinel
More layout work
75
        cum_time, cur = todo.pop()
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
76
        children = _total_stack[cur]
77
1724.2.10 by John Arbash Meinel
More layout work
78
        c_times = []
79
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
80
        info = _info[cur]
1724.2.12 by John Arbash Meinel
Default to hiding things that take less that .1ms to keep the output clean.
81
        if hide_fast and info[-1] < 0.0001:
82
            continue
83
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
84
        # Compute the module time by removing the children times
85
        mod_time = info[-1]
86
        for child in children:
87
            c_info = _info[child]
88
            mod_time -= c_info[-1]
1724.2.10 by John Arbash Meinel
More layout work
89
            c_times.append((c_info[-1], child))
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
90
91
        # indent, cum_time, mod_time, name,
92
        # scope_name, frame_name, frame_lineno
5017.2.2 by Martin Pool
Add import tariff tests
93
        out_file.write('%5.1f %5.1f %-40s @ %s:%d\n'
94
            % (info[-1]*1000., mod_time*1000.,
95
               ('+'*info[0] + cur[1]),
96
               info[1], info[2]))
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
97
1724.2.10 by John Arbash Meinel
More layout work
98
        if sorted:
99
            c_times.sort()
100
        else:
101
            c_times.reverse()
102
        todo.extend(c_times)
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
103
104
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
105
_real_import = __import__
106
4792.9.3 by Martin Pool
timed_import copes with only one argument, eg when called as __import__(name)
107
def timed_import(name, globals=None, locals=None, fromlist=None, level=None):
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
108
    """Wrap around standard importer to log import time"""
4792.9.3 by Martin Pool
timed_import copes with only one argument, eg when called as __import__(name)
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
111
    # parameter
4792.9.1 by Martin Pool
Fix --profile-imports for python2.6 import hook parameters
112
    # level is only passed by python2.6
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
113
4792.9.3 by Martin Pool
timed_import copes with only one argument, eg when called as __import__(name)
114
    if globals is None:
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.
117
        scope_name = None
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
118
    else:
4792.9.3 by Martin Pool
timed_import copes with only one argument, eg when called as __import__(name)
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()
124
        else:
125
            # Trim out paths before bzrlib
126
            loc = scope_name.find('bzrlib')
127
            if loc != -1:
128
                scope_name = scope_name[loc:]
129
            # For stdlib, trim out early paths
130
            loc = scope_name.find('python2.4')
131
            if loc != -1:
132
                scope_name = scope_name[loc:]
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
133
134
    # Figure out the frame that is doing the importing
135
    frame = sys._getframe(1)
136
    frame_name = frame.f_globals.get('__name__', '<unknown>')
137
    extra = ''
138
    if frame_name.endswith('demandload'):
139
        # If this was demandloaded, we have 3 frames to ignore
2063.4.3 by John Arbash Meinel
Update profile imports to be aware of the new compiler
140
        extra = '(demandload) '
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
141
        frame = sys._getframe(4)
1996.3.2 by John Arbash Meinel
Make profile_imports aware of lazy_import stuff
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
2063.4.3 by John Arbash Meinel
Update profile imports to be aware of the new compiler
145
        extra = '[l] '
1996.3.2 by John Arbash Meinel
Make profile_imports aware of lazy_import stuff
146
        frame = sys._getframe(4)
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
147
        frame_name = frame.f_globals.get('__name__', '<unknown>')
1996.3.16 by John Arbash Meinel
Update output of --profile-imports to understand from foo import bar time
148
    if fromlist:
149
        extra += ' [%s]' % (', '.join(map(str, fromlist)),)
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
150
    frame_lineno = frame.f_lineno
151
2063.4.3 by John Arbash Meinel
Update profile imports to be aware of the new compiler
152
    this = stack_add(extra + name, frame_name, frame_lineno, scope_name)
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
153
3696.1.1 by John Arbash Meinel
Use the right timing function on win32
154
    tstart = _timer()
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
155
    try:
156
        # Do the import
157
        mod = _real_import(name, globals, locals, fromlist)
158
    finally:
3696.1.1 by John Arbash Meinel
Use the right timing function on win32
159
        tload = _timer()-tstart
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
160
        stack_finish(this, tload)
161
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
162
    return mod
163
164
4792.9.2 by Martin Pool
profile_imports avoids deprecation warning by using either re or sre depending on python version
165
_real_compile = re._compile
166
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
167
1724.2.7 by John Arbash Meinel
It seems you cannot override __builtins__.__import__ in a sub-module.
168
def timed_compile(*args, **kwargs):
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
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>')
2063.4.3 by John Arbash Meinel
Update profile imports to be aware of the new compiler
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>')
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
181
    frame_lineno = frame.f_lineno
2063.4.3 by John Arbash Meinel
Update profile imports to be aware of the new compiler
182
    this = stack_add(extra+repr(args[0]), frame_name, frame_lineno)
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
183
3696.1.1 by John Arbash Meinel
Use the right timing function on win32
184
    tstart = _timer()
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
185
    try:
186
        # Measure the compile time
187
        comp = _real_compile(*args, **kwargs)
188
    finally:
3696.1.1 by John Arbash Meinel
Use the right timing function on win32
189
        tcompile = _timer() - tstart
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
190
        stack_finish(this, tcompile)
191
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
192
    return comp
1724.2.14 by John Arbash Meinel
Refactor import stuff into separate functions. Update news
193
194
195
def install():
196
    """Install the hooks for measuring import and regex compile time."""
197
    __builtins__['__import__'] = timed_import
4792.9.2 by Martin Pool
profile_imports avoids deprecation warning by using either re or sre depending on python version
198
    re._compile = timed_compile
1724.2.14 by John Arbash Meinel
Refactor import stuff into separate functions. Update news
199
200
201
def uninstall():
202
    """Remove the import and regex compile timing hooks."""
203
    __builtins__['__import__'] = _real_import
4792.9.2 by Martin Pool
profile_imports avoids deprecation warning by using either re or sre depending on python version
204
    re._compile = _real_compile
1724.2.14 by John Arbash Meinel
Refactor import stuff into separate functions. Update news
205