← Back to branch summary

~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to profile_imports.py

  • Committer: John Arbash Meinel
  • Date: 2007-03-15 22:35:35 UTC
  • mto: This revision was merged to the branch mainline in revision 2363.
  • Revision ID: john@arbash-meinel.com-20070315223535-d3d4964oe1hc8zhg
Add an overzealous test, for Unicode support of _iter_changes.
For both knowns and unknowns.
And include a basic, if suboptimal, fix.
I would rather defer the decoding until we've determined that we are going to return the tuple.
There is still something broken with added files, but I'll get to that.

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