← Back to branch summary

~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to profile_imports.py

  • Committer: mbp at sourcefrog
  • Date: 2005-03-21 22:29:49 UTC
  • Revision ID: mbp@sourcefrog.net-20050321222949-232c2093a6eadd80
fixup doctest for new module structure

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][:40], 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 = ' (lazy)'
126
 
        frame = sys._getframe(4)
127
 
        frame_name = frame.f_globals.get('__name__', '<unknown>')
128
 
    frame_lineno = frame.f_lineno
129
 
 
130
 
    this = stack_add(name+extra, frame_name, frame_lineno, scope_name)
131
 
 
132
 
    tstart = time.time()
133
 
    try:
134
 
        # Do the import
135
 
        mod = _real_import(name, globals, locals, fromlist)
136
 
    finally:
137
 
        tload = time.time()-tstart
138
 
        stack_finish(this, tload)
139
 
 
140
 
    return mod
141
 
 
142
 
 
143
 
_real_compile = sre._compile
144
 
 
145
 
def timed_compile(*args, **kwargs):
146
 
    """Log how long it takes to compile a regex"""
147
 
 
148
 
    # And who is requesting this?
149
 
    frame = sys._getframe(2)
150
 
    frame_name = frame.f_globals.get('__name__', '<unknown>')
151
 
    frame_lineno = frame.f_lineno
152
 
 
153
 
    this = stack_add(repr(args[0]), frame_name, frame_lineno)
154
 
 
155
 
    tstart = time.time()
156
 
    try:
157
 
        # Measure the compile time
158
 
        comp = _real_compile(*args, **kwargs)
159
 
    finally:
160
 
        tcompile = time.time() - tstart
161
 
        stack_finish(this, tcompile)
162
 
 
163
 
    return comp
164
 
 
165
 
 
166
 
def install():
167
 
    """Install the hooks for measuring import and regex compile time."""
168
 
    __builtins__['__import__'] = timed_import
169
 
    sre._compile = timed_compile
170
 
 
171
 
 
172
 
def uninstall():
173
 
    """Remove the import and regex compile timing hooks."""
174
 
    __builtins__['__import__'] = _real_import
175
 
    sre._compile = _real_compile
176