~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
5848.2.1 by John Arbash Meinel
Break compatibility with python <2.6.
24
import re
4792.9.2 by Martin Pool
profile_imports avoids deprecation warning by using either re or sre depending on python version
25
26
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
27
_parent_stack = []
28
_total_stack = {}
29
_info = {}
30
_cur_id = 0
3696.1.1 by John Arbash Meinel
Use the right timing function on win32
31
_timer = time.time
32
if sys.platform == 'win32':
33
    _timer = time.clock
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
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, scope_name]
47
48
    return this_stack
49
50
51
def stack_finish(this, cost):
52
    """Finish a given entry, and record its cost in time"""
53
    global _parent_stack
54
1724.2.13 by John Arbash Meinel
Remove pprint dependency
55
    assert _parent_stack[-1] == this, \
56
        'import stack does not end with this %s: %s' % (this, _parent_stack)
57
    _parent_stack.pop()
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
58
    _info[this].append(cost)
59
60
1724.2.12 by John Arbash Meinel
Default to hiding things that take less that .1ms to keep the output clean.
61
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.
62
    # Find all of the roots with import = 0
5017.2.2 by Martin Pool
Add import tariff tests
63
    out_file.write('%5s %5s %-40s @ %s:%s\n'
64
        % ('cum', 'inline', 'name', 'file', 'line'))
1724.2.10 by John Arbash Meinel
More layout work
65
    todo = [(value[-1], key) for key,value in _info.iteritems() if value[0] == 0]
66
67
    if sorted:
68
        todo.sort()
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
69
70
    while todo:
1724.2.10 by John Arbash Meinel
More layout work
71
        cum_time, cur = todo.pop()
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
72
        children = _total_stack[cur]
73
1724.2.10 by John Arbash Meinel
More layout work
74
        c_times = []
75
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
76
        info = _info[cur]
1724.2.12 by John Arbash Meinel
Default to hiding things that take less that .1ms to keep the output clean.
77
        if hide_fast and info[-1] < 0.0001:
78
            continue
79
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
80
        # Compute the module time by removing the children times
81
        mod_time = info[-1]
82
        for child in children:
83
            c_info = _info[child]
84
            mod_time -= c_info[-1]
1724.2.10 by John Arbash Meinel
More layout work
85
            c_times.append((c_info[-1], child))
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
86
87
        # indent, cum_time, mod_time, name,
88
        # scope_name, frame_name, frame_lineno
5017.2.2 by Martin Pool
Add import tariff tests
89
        out_file.write('%5.1f %5.1f %-40s @ %s:%d\n'
90
            % (info[-1]*1000., mod_time*1000.,
91
               ('+'*info[0] + cur[1]),
92
               info[1], info[2]))
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
93
1724.2.10 by John Arbash Meinel
More layout work
94
        if sorted:
95
            c_times.sort()
96
        else:
97
            c_times.reverse()
98
        todo.extend(c_times)
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
99
100
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
101
_real_import = __import__
102
4792.9.3 by Martin Pool
timed_import copes with only one argument, eg when called as __import__(name)
103
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
104
    """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)
105
    # normally there are 4, but if this is called as __import__ eg by
106
    # /usr/lib/python2.6/email/__init__.py then there may be only one
107
    # parameter
4792.9.1 by Martin Pool
Fix --profile-imports for python2.6 import hook parameters
108
    # level is only passed by python2.6
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
109
4792.9.3 by Martin Pool
timed_import copes with only one argument, eg when called as __import__(name)
110
    if globals is None:
111
        # can't determine the scope name afaics; we could peek up the stack to
112
        # see where this is being called from, but it should be a rare case.
113
        scope_name = None
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
114
    else:
4792.9.3 by Martin Pool
timed_import copes with only one argument, eg when called as __import__(name)
115
        scope_name = globals.get('__name__', None)
116
        if scope_name is None:
117
            scope_name = globals.get('__file__', None)
118
        if scope_name is None:
119
            scope_name = globals.keys()
120
        else:
121
            # Trim out paths before bzrlib
122
            loc = scope_name.find('bzrlib')
123
            if loc != -1:
124
                scope_name = scope_name[loc:]
125
            # For stdlib, trim out early paths
126
            loc = scope_name.find('python2.4')
127
            if loc != -1:
128
                scope_name = scope_name[loc:]
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
129
130
    # Figure out the frame that is doing the importing
131
    frame = sys._getframe(1)
132
    frame_name = frame.f_globals.get('__name__', '<unknown>')
133
    extra = ''
134
    if frame_name.endswith('demandload'):
135
        # 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
136
        extra = '(demandload) '
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
137
        frame = sys._getframe(4)
1996.3.2 by John Arbash Meinel
Make profile_imports aware of lazy_import stuff
138
        frame_name = frame.f_globals.get('__name__', '<unknown>')
139
    elif frame_name.endswith('lazy_import'):
140
        # 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
141
        extra = '[l] '
1996.3.2 by John Arbash Meinel
Make profile_imports aware of lazy_import stuff
142
        frame = sys._getframe(4)
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
143
        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
144
    if fromlist:
145
        extra += ' [%s]' % (', '.join(map(str, fromlist)),)
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
146
    frame_lineno = frame.f_lineno
147
2063.4.3 by John Arbash Meinel
Update profile imports to be aware of the new compiler
148
    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.
149
3696.1.1 by John Arbash Meinel
Use the right timing function on win32
150
    tstart = _timer()
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
151
    try:
152
        # Do the import
153
        mod = _real_import(name, globals, locals, fromlist)
154
    finally:
3696.1.1 by John Arbash Meinel
Use the right timing function on win32
155
        tload = _timer()-tstart
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
156
        stack_finish(this, tload)
157
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
158
    return mod
159
160
4792.9.2 by Martin Pool
profile_imports avoids deprecation warning by using either re or sre depending on python version
161
_real_compile = re._compile
162
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
163
1724.2.7 by John Arbash Meinel
It seems you cannot override __builtins__.__import__ in a sub-module.
164
def timed_compile(*args, **kwargs):
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
165
    """Log how long it takes to compile a regex"""
166
167
    # And who is requesting this?
168
    frame = sys._getframe(2)
169
    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
170
171
    extra = ''
172
    if frame_name.endswith('lazy_regex'):
173
        # If this was lazily compiled, we have 3 more frames to ignore
174
        extra = '[l] '
175
        frame = sys._getframe(5)
176
        frame_name = frame.f_globals.get('__name__', '<unknown>')
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
177
    frame_lineno = frame.f_lineno
2063.4.3 by John Arbash Meinel
Update profile imports to be aware of the new compiler
178
    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.
179
3696.1.1 by John Arbash Meinel
Use the right timing function on win32
180
    tstart = _timer()
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
181
    try:
182
        # Measure the compile time
183
        comp = _real_compile(*args, **kwargs)
184
    finally:
3696.1.1 by John Arbash Meinel
Use the right timing function on win32
185
        tcompile = _timer() - tstart
1724.2.8 by John Arbash Meinel
New --profile-imports output which puts parents before children.
186
        stack_finish(this, tcompile)
187
1724.2.4 by John Arbash Meinel
Move the custom importers into a separate module
188
    return comp
1724.2.14 by John Arbash Meinel
Refactor import stuff into separate functions. Update news
189
190
191
def install():
192
    """Install the hooks for measuring import and regex compile time."""
193
    __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
194
    re._compile = timed_compile
1724.2.14 by John Arbash Meinel
Refactor import stuff into separate functions. Update news
195
196
197
def uninstall():
198
    """Remove the import and regex compile timing hooks."""
199
    __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
200
    re._compile = _real_compile
1724.2.14 by John Arbash Meinel
Refactor import stuff into separate functions. Update news
201