1
# Copyright (C) 2006, 2008, 2009, 2010 by Canonical Ltd
2
# Written by John Arbash Meinel <john@arbash-meinel.com>
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.
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.
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
18
"""A custom importer and regex compiler which logs time spent."""
20
from __future__ import absolute_import
32
if sys.platform == 'win32':
36
def stack_add(name, frame_name, frame_lineno, scope_name=None):
37
"""Start a new record on the stack"""
40
this_stack = (_cur_id, name)
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,
52
def stack_finish(this, cost):
53
"""Finish a given entry, and record its cost in time"""
56
assert _parent_stack[-1] == this, \
57
'import stack does not end with this %s: %s' % (this, _parent_stack)
59
_info[this].append(cost)
62
def log_stack_info(out_file, sorted=True, hide_fast=True):
63
# Find all of the roots with import = 0
65
'%5s %5s %-40s @ %s:%s\n'
66
% ('cum', 'local', 'name', 'file', 'line'))
67
todo = [(value[-1], key) for key, value in _info.items() if value[0] == 0]
73
cum_time, cur = todo.pop()
74
children = _total_stack[cur]
79
if hide_fast and info[-1] < 0.0001:
82
# Compute the module time by removing the children times
84
for child in children:
86
mod_time -= c_info[-1]
87
c_times.append((c_info[-1], child))
89
# indent, cum_time, mod_time, name,
90
# scope_name, frame_name, frame_lineno
92
'%5.1f %5.1f %-40s @ %s:%d\n' % (
93
info[-1] * 1000., mod_time * 1000.,
94
('+' * info[0] + cur[1]), info[1], info[2]))
103
_real_import = __import__
105
def timed_import(name, globals=None, locals=None, fromlist=None, level=0):
106
"""Wrap around standard importer to log import time"""
107
# normally there are 4, but if this is called as __import__ eg by
108
# /usr/lib/python2.6/email/__init__.py then there may be only one
110
# level has different default between Python 2 and 3, but codebase
111
# uses `from __future__ import absolute_import` so can just use 0.
114
# can't determine the scope name afaics; we could peek up the stack to
115
# see where this is being called from, but it should be a rare case.
118
scope_name = globals.get('__name__', None)
119
if scope_name is None:
120
scope_name = globals.get('__file__', None)
121
if scope_name is None:
122
scope_name = globals.keys()
124
# Trim out paths before breezy
125
loc = scope_name.find('breezy')
127
scope_name = scope_name[loc:]
129
# Figure out the frame that is doing the importing
130
frame = sys._getframe(1)
131
frame_name = frame.f_globals.get('__name__', '<unknown>')
133
if frame_name.endswith('demandload'):
134
# If this was demandloaded, we have 3 frames to ignore
135
extra = '(demandload) '
136
frame = sys._getframe(4)
137
frame_name = frame.f_globals.get('__name__', '<unknown>')
138
elif frame_name.endswith('lazy_import'):
139
# If this was lazily imported, we have 3 frames to ignore
141
frame = sys._getframe(4)
142
frame_name = frame.f_globals.get('__name__', '<unknown>')
144
extra += ' [%s]' % (', '.join(map(str, fromlist)),)
145
frame_lineno = frame.f_lineno
147
this = stack_add(extra + name, frame_name, frame_lineno, scope_name)
152
return _real_import(name, globals, locals, fromlist, level=level)
154
tload = _timer() - tstart
155
stack_finish(this, tload)
158
def _repr_regexp(pattern, max_len=30):
159
"""Present regexp pattern for logging, truncating if over max_len."""
160
if len(pattern) > max_len:
161
return repr(pattern[:max_len - 3]) + "..."
165
_real_compile = re._compile
168
def timed_compile(*args, **kwargs):
169
"""Log how long it takes to compile a regex"""
171
# And who is requesting this?
172
frame = sys._getframe(2)
173
frame_name = frame.f_globals.get('__name__', '<unknown>')
176
if frame_name.endswith('lazy_regex'):
177
# If this was lazily compiled, we have 3 more frames to ignore
179
frame = sys._getframe(5)
180
frame_name = frame.f_globals.get('__name__', '<unknown>')
181
frame_lineno = frame.f_lineno
182
this = stack_add(extra + _repr_regexp(args[0]), frame_name, frame_lineno)
186
# Measure the compile time
187
comp = _real_compile(*args, **kwargs)
189
tcompile = _timer() - tstart
190
stack_finish(this, tcompile)
196
"""Install the hooks for measuring import and regex compile time."""
197
__builtins__['__import__'] = timed_import
198
re._compile = timed_compile
202
"""Remove the import and regex compile timing hooks."""
203
__builtins__['__import__'] = _real_import
204
re._compile = _real_compile