← 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-06-29 16:16:46 UTC
  • mto: This revision was merged to the branch mainline in revision 2614.
  • Revision ID: john@arbash-meinel.com-20070629161646-ufelk4s0m1ig5md8
Don't suppress the TypeError if it doesn't match our requirements.

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