/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

  • Committer: John Arbash Meinel
  • Date: 2010-01-12 22:51:31 UTC
  • mto: This revision was merged to the branch mainline in revision 4955.
  • Revision ID: john@arbash-meinel.com-20100112225131-he8h411p6aeeb947
Delay grabbing an output stream until we actually go to show a diff.

This makes the test suite happy, but it also seems to be reasonable.
If we aren't going to write anything, we don't need to hold an
output stream open.

Show diffs side-by-side

added added

removed removed

Lines of Context:
profile_imports.py
 
1
# Copyright (C) 2006 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
import sre
 
21
import sys
 
22
import time
 
23
 
 
24
 
 
25
_parent_stack = []
 
26
_total_stack = {}
 
27
_info = {}
 
28
_cur_id = 0
 
29
_timer = time.time
 
30
if sys.platform == 'win32':
 
31
    _timer = time.clock
 
32
 
 
33
 
 
34
def stack_add(name, frame_name, frame_lineno, scope_name=None):
 
35
    """Start a new record on the stack"""
 
36
    global _cur_id
 
37
    _cur_id += 1
 
38
    this_stack = (_cur_id, name)
 
39
 
 
40
    if _parent_stack:
 
41
        _total_stack[_parent_stack[-1]].append(this_stack)
 
42
    _total_stack[this_stack] = []
 
43
    _parent_stack.append(this_stack)
 
44
    _info[this_stack] = [len(_parent_stack)-1, frame_name, frame_lineno, scope_name]
 
45
 
 
46
    return this_stack
 
47
 
 
48
 
 
49
def stack_finish(this, cost):
 
50
    """Finish a given entry, and record its cost in time"""
 
51
    global _parent_stack
 
52
 
 
53
    assert _parent_stack[-1] == this, \
 
54
        'import stack does not end with this %s: %s' % (this, _parent_stack)
 
55
    _parent_stack.pop()
 
56
    _info[this].append(cost)
 
57
 
 
58
 
 
59
def log_stack_info(out_file, sorted=True, hide_fast=True):
 
60
    # Find all of the roots with import = 0
 
61
    out_file.write(' cum  inline name\t\t\t\t\t\tframe\n')
 
62
    todo = [(value[-1], key) for key,value in _info.iteritems() if value[0] == 0]
 
63
 
 
64
    if sorted:
 
65
        todo.sort()
 
66
 
 
67
    while todo:
 
68
        cum_time, cur = todo.pop()
 
69
        children = _total_stack[cur]
 
70
 
 
71
        c_times = []
 
72
 
 
73
        info = _info[cur]
 
74
        if hide_fast and info[-1] < 0.0001:
 
75
            continue
 
76
 
 
77
        # Compute the module time by removing the children times
 
78
        mod_time = info[-1]
 
79
        for child in children:
 
80
            c_info = _info[child]
 
81
            mod_time -= c_info[-1]
 
82
            c_times.append((c_info[-1], child))
 
83
 
 
84
        # indent, cum_time, mod_time, name,
 
85
        # scope_name, frame_name, frame_lineno
 
86
        out_file.write('%5.1f %5.1f %s %-35s\t@ %s:%d\n'
 
87
            % (info[-1]*1000., mod_time*1000., '+'*info[0], 
 
88
               cur[1][:35], info[1], info[2]))
 
89
 
 
90
        if sorted:
 
91
            c_times.sort()
 
92
        else:
 
93
            c_times.reverse()
 
94
        todo.extend(c_times)
 
95
 
 
96
 
 
97
_real_import = __import__
 
98
 
 
99
def timed_import(name, globals, locals, fromlist):
 
100
    """Wrap around standard importer to log import time"""
 
101
 
 
102
    scope_name = globals.get('__name__', None)
 
103
    if scope_name is None:
 
104
        scope_name = globals.get('__file__', None)
 
105
    if scope_name is None:
 
106
        scope_name = globals.keys()
 
107
    else:
 
108
        # Trim out paths before bzrlib
 
109
        loc = scope_name.find('bzrlib')
 
110
        if loc != -1:
 
111
            scope_name = scope_name[loc:]
 
112
        # For stdlib, trim out early paths
 
113
        loc = scope_name.find('python2.4')
 
114
        if loc != -1:
 
115
            scope_name = scope_name[loc:]
 
116
 
 
117
    # Figure out the frame that is doing the importing
 
118
    frame = sys._getframe(1)
 
119
    frame_name = frame.f_globals.get('__name__', '<unknown>')
 
120
    extra = ''
 
121
    if frame_name.endswith('demandload'):
 
122
        # If this was demandloaded, we have 3 frames to ignore
 
123
        extra = '(demandload) '
 
124
        frame = sys._getframe(4)
 
125
        frame_name = frame.f_globals.get('__name__', '<unknown>')
 
126
    elif frame_name.endswith('lazy_import'):
 
127
        # If this was lazily imported, we have 3 frames to ignore
 
128
        extra = '[l] '
 
129
        frame = sys._getframe(4)
 
130
        frame_name = frame.f_globals.get('__name__', '<unknown>')
 
131
    if fromlist:
 
132
        extra += ' [%s]' % (', '.join(map(str, fromlist)),)
 
133
    frame_lineno = frame.f_lineno
 
134
 
 
135
    this = stack_add(extra + name, frame_name, frame_lineno, scope_name)
 
136
 
 
137
    tstart = _timer()
 
138
    try:
 
139
        # Do the import
 
140
        mod = _real_import(name, globals, locals, fromlist)
 
141
    finally:
 
142
        tload = _timer()-tstart
 
143
        stack_finish(this, tload)
 
144
 
 
145
    return mod
 
146
 
 
147
 
 
148
_real_compile = sre._compile
 
149
 
 
150
def timed_compile(*args, **kwargs):
 
151
    """Log how long it takes to compile a regex"""
 
152
 
 
153
    # And who is requesting this?
 
154
    frame = sys._getframe(2)
 
155
    frame_name = frame.f_globals.get('__name__', '<unknown>')
 
156
 
 
157
    extra = ''
 
158
    if frame_name.endswith('lazy_regex'):
 
159
        # If this was lazily compiled, we have 3 more frames to ignore
 
160
        extra = '[l] '
 
161
        frame = sys._getframe(5)
 
162
        frame_name = frame.f_globals.get('__name__', '<unknown>')
 
163
    frame_lineno = frame.f_lineno
 
164
    this = stack_add(extra+repr(args[0]), frame_name, frame_lineno)
 
165
 
 
166
    tstart = _timer()
 
167
    try:
 
168
        # Measure the compile time
 
169
        comp = _real_compile(*args, **kwargs)
 
170
    finally:
 
171
        tcompile = _timer() - tstart
 
172
        stack_finish(this, tcompile)
 
173
 
 
174
    return comp
 
175
 
 
176
 
 
177
def install():
 
178
    """Install the hooks for measuring import and regex compile time."""
 
179
    __builtins__['__import__'] = timed_import
 
180
    sre._compile = timed_compile
 
181
 
 
182
 
 
183
def uninstall():
 
184
    """Remove the import and regex compile timing hooks."""
 
185
    __builtins__['__import__'] = _real_import
 
186
    sre._compile = _real_compile
 
187