messages when the module import fails are very misleading and not descriptive

Bug #1297261 reported by Jaroslav Henner
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
oslo.utils
Expired
Undecided
Unassigned

Bug Description

I had problem to import vmware module due to lack of it's dep. The message in log though was saying that there is no vmware module, which is far from true. The problematic code is at least:

/usr/lib/python2.6/site-packages/nova/openstack/common/importutils.py

def import_class(import_str):
...
    try:
        __import__(mod_str)
        return getattr(sys.modules[mod_str], class_str)
    except (ValueError, AttributeError):
        raise ImportError('Class %s cannot be found (%s)' %
                          (class_str,
                           traceback.format_exception(*sys.exc_info())))

Which would obfuscate the error message when some module import dies on ValueError, and:

def import_object_ns(name_space, import_str, *args, **kwargs):
    """Tries to import object from default namespace.

    Imports a class and return an instance of it, first by trying
    to find the class in a default namespace, then failing back to
    a full path if not found in the default namespace.
    """
    import_value = "%s.%s" % (name_space, import_str)
    try:
        return import_class(import_value)(*args, **kwargs)
    except ImportError:
        return import_class(import_str)(*args, **kwargs)

Which will say ImportError: Missing module import_str, but only as a result of failure of the first import in the try-except block, effectively hiding the true reason of the failure.

In other words, if the first import fails for some interesting reasons, some other, possible meaningles import is tried and only it's error is let to propagate.

+++ This bug was initially created as a clone of Bug #1080424 +++

Description of problem:
When having nova-compute alone on a node, I cannot start it (using PYTHONVERBOSE=1 and slightly modified init script for debuging purposes):

2014-03-25 11:10:42.153 10009 INFO nova.virt.driver [-] Loading compute driver 'vmwareapi.VMwareVCDriver'
import nova.virt.vmwareapi # directory /usr/lib/python2.6/site-packages/nova/virt/vmwareapi
# /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/__init__.pyc matches /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/__init__.py
import nova.virt.vmwareapi # precompiled from /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/__init__.pyc
# /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/driver.pyc matches /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/driver.py
import nova.virt.vmwareapi.driver # precompiled from /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/driver.pyc
# /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/error_util.pyc matches /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/error_util.py
import nova.virt.vmwareapi.error_util # precompiled from /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/error_util.pyc
# /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/host.pyc matches /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/host.py
import nova.virt.vmwareapi.host # precompiled from /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/host.pyc
# /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/vim_util.pyc matches /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/vim_util.py
import nova.virt.vmwareapi.vim_util # precompiled from /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/vim_util.pyc
# /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/vm_util.pyc matches /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/vm_util.py
import nova.virt.vmwareapi.vm_util # precompiled from /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/vm_util.pyc
# /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/vim.pyc matches /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/vim.py
import nova.virt.vmwareapi.vim # precompiled from /usr/lib/python2.6/site-packages/nova/virt/vmwareapi/vim.pyc
2014-03-25 11:10:42.155 10009 ERROR nova.virt.driver [-] Unable to load the virtualization driver
2014-03-25 11:10:42.155 10009 TRACE nova.virt.driver Traceback (most recent call last):
2014-03-25 11:10:42.155 10009 TRACE nova.virt.driver File "/usr/lib/python2.6/site-packages/nova/virt/driver.py", line 1115, in load_compute_driver
2014-03-25 11:10:42.155 10009 TRACE nova.virt.driver virtapi)
2014-03-25 11:10:42.155 10009 TRACE nova.virt.driver File "/usr/lib/python2.6/site-packages/nova/openstack/common/importutils.py", line 54, in import_object_ns
2014-03-25 11:10:42.155 10009 TRACE nova.virt.driver return import_class(import_str)(*args, **kwargs)
2014-03-25 11:10:42.155 10009 TRACE nova.virt.driver File "/usr/lib/python2.6/site-packages/nova/openstack/common/importutils.py", line 30, in import_class
2014-03-25 11:10:42.155 10009 TRACE nova.virt.driver __import__(mod_str)
2014-03-25 11:10:42.155 10009 TRACE nova.virt.driver ImportError: No module named vmwareapi
2014-03-25 11:10:42.155 10009 TRACE nova.virt.driver

when trying to imprort it in ipython:
In [1]: import nova.virt.vmwareapi
---------------------------------------------------------------------------
ImportError Traceback (most recent call last)
<ipython-input-1-c0f052a58780> in <module>()
----> 1 import nova.virt.vmwareapi

/usr/lib/python2.6/site-packages/nova/virt/vmwareapi/__init__.py in <module>()
     19 """
     20 # NOTE(sdague) for nicer compute_driver specification
---> 21 from nova.virt.vmwareapi import driver
     22
     23 VMwareESXDriver = driver.VMwareESXDriver

/usr/lib/python2.6/site-packages/nova/virt/vmwareapi/driver.py in <module>()
     37 from nova.virt.vmwareapi import error_util
     38 from nova.virt.vmwareapi import host
---> 39 from nova.virt.vmwareapi import vim
     40 from nova.virt.vmwareapi import vim_util
     41 from nova.virt.vmwareapi import vm_util

/usr/lib/python2.6/site-packages/nova/virt/vmwareapi/vim.py in <module>()
     25
     26 from oslo.config import cfg
---> 27 import suds
     28
     29 from nova.openstack.common.gettextutils import _

ImportError: No module named suds

Version-Release number of selected component (if applicable):
openstack-nova-compute-2013.2.2-2.el6ost.noarch
python-nova-2013.2.2-2.el6ost.noarch

How reproducible:
always

Steps to Reproduce:
1. Install nova-compute
2. do the import in the python interpret

Actual results:
ImportError: No module named suds

Expected results:
no problem

Additional info:

Tags: oslo
Revision history for this message
Jaroslav Henner (jhenner) wrote :

Bug 1080435 - messages when the module import fails are very misleading and not descriptive

summary: messages when the module import fails are very misleading and not
- describtive
+ descriptive
Dolph Mathews (dolph)
affects: python-keystoneclient → nova
Tracy Jones (tjones-i)
tags: added: compute
tags: added: oslo
removed: compute
Revision history for this message
Sean Dague (sdague) wrote :

this is an oslo issue, it's in openstack/ namespace

Changed in oslo-incubator:
status: New → Confirmed
no longer affects: nova
affects: oslo-incubator → oslo.utils
Revision history for this message
Doug Hellmann (doug-hellmann) wrote :

I'm not really sure how much we can do about this. We could probably log all of the exceptions we encounter along the way, but that seems like it would over-log "errors" that aren't really errors.

Revision history for this message
Doug Hellmann (doug-hellmann) wrote :

I believe nova is now loading drivers with stevedore, which handles import errors differently. Is this still an issue?

Changed in oslo.utils:
status: Confirmed → Incomplete
Revision history for this message
Launchpad Janitor (janitor) wrote :

[Expired for oslo.utils because there has been no activity for 60 days.]

Changed in oslo.utils:
status: Incomplete → Expired
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.