log/profile repeated imports; policy for imports

[Martin Pool]

I just tried this quick hack, which produces a log of every time the
import statement runs.  The output is like this


'codecs'             'bzrlib.trace'       None
'stat'               'bzrlib.trace'       None
'bzrlib.ui'          'bzrlib.commands'    None
'sys'                'bzrlib.ui'          None
'bzrlib.lazy_import' 'bzrlib.ui'          ('lazy_import',)
'bzrlib.ui.text'     'bzrlib.commands'    ('TextUIFactory',)
'sys'                'bzrlib.ui.text'     None
'bzrlib.lazy_import' 'bzrlib.ui.text'     ('lazy_import',)

showing the module imported, the place that imported it, and the
'from' list of the import statement, if any.

While --profile-imports shows only when modules are actually loaded,
this includes the times when the module was found in the interpreter's
cache.  This is a bit interesting because it takes a small amount of
time to hit in the cache, including an (apparently unnecessary) futex
syscall on Linux.

When running the test suite we do several hundred thousand imports,
which is clearly excessive.  However for the most common local
operations like status or diff there is little redundancy.

However there could be a small useful cleanup for someone to search
for imports within methods and change them to lazy imports at the top
level.  Or for things that we know are going to be loaded on all
nontrivial invocations (commands, builtins, errors, workingtree,
bzrdir) we might as well just go ahead and load them directly.


=== modified file 'bzr'
--- bzr	2007-09-12 01:29:21 +0000
+++ bzr	2007-09-20 05:20:33 +0000
@@ -94,6 +94,16 @@
             "bzrlib from %s is version %r\n"
             % (bzrlib.__path__, bzrlib.version_info))

+_import_log = file('.import.log', 'wt', buffering=1)
+_original_import = __import__
+def _new_import(name, globals=None, locals=None, fromlist=[], level=-1):
+    _import_log.write("%-20r %-20r %r\n"
+        % (name,
+           (globals or {}).get('__name__'),
+           fromlist))
+    return _original_import(name, globals, locals, fromlist, level)
+__builtins__.__import__ = _new_import
+
 if __name__ == '__main__':
     bzrlib.trace.enable_default_logging()
     exit_val = bzrlib.commands.main(sys.argv)



-- 
Martin