diff --git a/lazy_import/__init__.py b/lazy_import/__init__.py index 32a25e4..e17a566 100644 --- a/lazy_import/__init__.py +++ b/lazy_import/__init__.py @@ -93,9 +93,15 @@ def __exit__(self, exc_type, exc_value, exc_traceback): with open(VERSION_FILE) as infile: __version__ = infile.read().strip() +# Logging +import logging _DEBUG = False if _DEBUG: import traceback + logging.basicConfig(level=logging.DEBUG) +else: + logging.basicConfig(level=logging.INFO) +logger = logging.getLogger(__name__) ################################ # Module/function registration # @@ -114,11 +120,10 @@ class LazyModule(ModuleType): # peak.util.imports sets __slots__ to (), but it seems pointless because # the base ModuleType doesn't itself set __slots__. def __getattribute__(self, attr): - if _DEBUG: - sys.stderr.write("Getting attr {} of LazyModule instance of {}\n" - .format(attr, super(LazyModule, self). - __getattribute__("__name__"))) - #traceback.print_stack() + logger.debug("Getting attr {} of LazyModule instance of {}" + .format(attr, super(LazyModule, self) + .__getattribute__("__name__"))) + #traceback.print_stack() # IPython tries to be too clever and constantly inspects, asking for # modules' attrs, which causes premature module loading and unesthetic # internal errors if the lazily-loaded module doesn't exist. @@ -127,7 +132,12 @@ def __getattribute__(self, attr): or attr == "_repr_mimebundle_") and module_basename(_caller_name()) in ('inspect', 'IPython')): raise AttributeError - if not attr in ('__name__','__class__'): + if not attr in ('__name__','__class__','__spec__'): + # __name__ and __class__ yield their values from the LazyModule; + # __spec__ causes an AttributeError. Maybe in the future it will be + # necessary to return an actual ModuleSpec object, but it works as + # it is without that now. + # If it's an already-loaded submodule, we return it without # triggering a full loading try: @@ -137,16 +147,19 @@ def __getattribute__(self, attr): # Check if it's one of the lazy callables try: return type(self)._lazy_import_callables[attr] - except (AttributeError, KeyError): + except (AttributeError, KeyError) as err: + logger.debug("Proceeding to load module {}, " + "from requested value {}" + .format(super(LazyModule, self) + .__getattribute__("__name__"), attr)) + #traceback.print_stack() _load_module(self) return super(LazyModule, self).__getattribute__(attr) def __setattr__(self, attr, value): - if _DEBUG: - sys.stderr.write("Setting attr {} to value {}, " - "in LazyModule instance of {}\n" - .format(attr, value, super(LazyModule, self). - __getattribute__("__name__"))) + logger.debug("Setting attr {} to value {}, in LazyModule instance " + "of {}".format(attr, value, super(LazyModule, self) + .__getattribute__("__name__"))) _load_module(self) return super(LazyModule, self).__setattr__(attr, value) @@ -472,8 +485,7 @@ def _load_module(module): raise TypeError("Passed module is not a LazyModule instance.") with _ImportLockContext(): parent, _, modname = module.__name__.rpartition('.') - if _DEBUG: - sys.stderr.write("loading module {}\n".format(modname)) + logger.debug("loading module {}".format(modname)) # We first identify whether this is a loadable LazyModule, then we # strip as much of lazy_import behavior as possible (keeping it cached, # in case loading fails and we need to reset the lazy state). @@ -485,15 +497,11 @@ def _load_module(module): modclass._LOADING = True try: if parent: - if _DEBUG: - sys.stderr.write("first loading parent module {}\n" - .format(parent)) - _load_module(sys.modules[parent]) + logger.debug("first loading parent module {}".format(parent)) setattr(sys.modules[parent], modname, module) if not hasattr(modclass, '_LOADING'): - if _DEBUG: - sys.stderr.write("Module {} loaded by the parent\n" - .format(modname)) + logger.debug("Module {} already loaded by the parent" + .format(modname)) # We've been loaded by the parent. Let's bail. return cached_data = _clean_lazymodule(module) @@ -502,24 +510,20 @@ def _load_module(module): reload_module(module) except: # Loading failed. We reset our lazy state. - if _DEBUG: - sys.stderr.write("Failed to load module {}. Resetting...\n" - .format(modname)) + logger.debug("Failed to load module {}. Resetting..." + .format(modname)) _reset_lazymodule(module, cached_data) raise else: # Successful load - if _DEBUG: - sys.stderr.write("Successfully loaded module {}\n" - .format(modname)) + logger.debug("Successfully loaded module {}".format(modname)) delattr(modclass, '_LOADING') _reset_lazy_submod_refs(module) except (AttributeError, ImportError) as err: - if _DEBUG: - sys.stderr.write("Failed to load {}.\n".format(modname)) - sys.stderr.write(str(err) + "\n") - #traceback.print_stack() + logger.debug("Failed to load {}.\n{}: {}" + .format(modname, err.__class__.__name__, err)) + #traceback.print_stack() # Under Python 3 reloading our dummy LazyModule instances causes an # AttributeError if the module can't be found. Would be preferrable # if we could always rely on an ImportError. As it is we vet the diff --git a/lazy_import/test_lazy.py b/lazy_import/test_lazy.py index fb92cbc..d9c36d6 100644 --- a/lazy_import/test_lazy.py +++ b/lazy_import/test_lazy.py @@ -67,7 +67,7 @@ class _TestLazyModule(lazy_import.LazyModule): _GENERATED_NAMES = [] # Modules not usually loaded on startup -NAMES_EXISTING = ("uuid", "distutils.core") +NAMES_EXISTING = ("concurrent", "distutils.core") LEVELS = ("leaf", "base") CLASSES = (_TestLazyModule, lazy_import.LazyModule) @@ -110,6 +110,17 @@ def _check_lazy_loading(modname): base = lazy_import.lazy_module(modname, level="base") assert sys.modules[basename] is base assert str(base) == "Lazily-loaded module " + basename + + # A subtle bug only rears its head if an actual import statement is done. + # Can only test that for the module names we know of + # (meaning, no random ones) + if modname in NAMES_EXISTING: + if modname == 'concurrent': + import concurrent as newmod + elif modname == 'distutils.core': + import distutils.core as newmod + assert str(newmod) == "Lazily-loaded module " + modname + # Check that all submodules are in and that submodule access works curr_name = basename curr_mod = base