Glance api service crashes but restarts infinitely

[Qwest]

Openstack release in which defect is being reported for: Mitaka

OS: CentOS7

Component: Glance

Specific: Glance-api

# rpm -qa | grep glance
python-glanceclient-2.0.0-1.el7.noarch
python-glance-store-0.13.1-1.el7.noarch
python-glance-12.0.0-1.el7.noarch
openstack-glance-12.0.0-1.el7.noarch

Glance store settings in /etc/glance/glance-api.conf

[glance_store]
# From glance.store

stores = vmware
default_store = vmware
vmware_server_host = 10.10.1.10
vmware_server_username = administrator
vmware_server_password = admin
vmware_store_image_dir = /openstack_glance
vmware_insecure = true
vmware_datastores = DC:DS01:200
vmware_datastores = DC:DS02:100

/var/log/glance/api.log (with above settings)

2016-09-13 17:50:08.636 27351 WARNING glance_store.backend [-] Failed to load driver [<module 'stevedore.driver' from '/usr/lib/python2.7/site-packages/stevedore/driver.pyc'>, NoMatches("No 'glance_store.drivers' driver found, looking for 'vsphere'",)]. The driver will be disabled
2016-09-13 17:52:08.779 27526 INFO oslo_vmware.api [-] Successfully established new session; session ID is 6d8cf.
2016-09-13 17:52:16.370 27552 INFO oslo_vmware.api [-] Successfully established new session; session ID is e4c65.
2016-09-13 17:52:24.118 27566 INFO oslo_vmware.api [-] Successfully established new session; session ID is 41c30.
2016-09-13 17:52:31.947 27580 INFO oslo_vmware.api [-] Successfully established new session; session ID is 80b67.
2016-09-13 17:52:39.598 27592 INFO oslo_vmware.api [-] Successfully established new session; session ID is c5356.
2016-09-13 17:52:47.107 27630 INFO oslo_vmware.api [-] Successfully established new session; session ID is 5d183.
2016-09-13 17:52:54.912 27644 INFO oslo_vmware.api [-] Successfully established new session; session ID is d0a10.
2016-09-13 17:53:02.620 27658 INFO oslo_vmware.api [-] Successfully established new session; session ID is f4f7f.
2016-09-13 17:53:10.404 27670 INFO oslo_vmware.api [-] Successfully established new session; session ID is 9ba5a.
2016-09-13 17:53:18.106 27708 INFO oslo_vmware.api [-] Successfully established new session; session ID is 46e93.
2016-09-13 17:53:25.602 27725 INFO oslo_vmware.api [-] Successfully established new session; session ID is 6bad2.
2016-09-13 17:53:33.135 27748 INFO oslo_vmware.api [-] Successfully established new session; session ID is 81b90.
2016-09-13 17:53:40.905 27760 INFO oslo_vmware.api [-] Successfully established new session; session ID is 04754.

Two observations from above log:

1. After changing the default_store and stores value to 'vmware' from 'vsphere', started seeing the 'Successfully established new session' messages in api.log
2. Tried investigating as to why there are multiple 'new session' in api.log. After looking into /var/log/messages witnessed the below mentioned log:

Sep 13 18:09:06 controller01 glance-api: /usr/lib/python2.7/site-packages/requests/packages/urllib3/connectionpool.py:821: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.org/en/latest/security.html
Sep 13 18:09:06 controller01 glance-api: InsecureRequestWarning)
Sep 13 18:09:06 controller01 glance-api: ERROR: Store for scheme vmware not found
Sep 13 18:09:06 controller01 systemd: openstack-glance-api.service: main process exited, code=exited, status=1/FAILURE
Sep 13 18:09:06 controller01 systemd: Unit openstack-glance-api.service entered failed state.
Sep 13 18:09:06 controller01 systemd: openstack-glance-api.service failed.
Sep 13 18:09:06 controller01 systemd: openstack-glance-api.service holdoff time over, scheduling restart.
Sep 13 18:09:06 controller01 systemd: Started OpenStack Image Service (code-named Glance) API server.
Sep 13 18:09:06 controller01 systemd: Starting OpenStack Image Service (code-named Glance) API server...
Sep 13 18:09:06 controller01 glance-api: /usr/lib/python2.7/site-packages/oslo_middleware/ssl.py:28: DeprecationWarning: The 'oslo_middleware.ssl' module usage is deprecated, please use oslo_middleware.http_proxy_to_wsgi instead

1. Remove/comment stores and retain only default_store with the value 'vmware', glance api service would crash instantly and stay in that state forever.
2. Retain both stores and default_store with the value 'vsphere', glance api service would crash instantly and stay in that state forever
3. Remove/comment stores and retain only default_store with the value 'vsphere', glance api service would crash instantly and stay in that state forever
4. Retain both stores and default_store with the value 'vmware', glance api service would crash in about 8 seconds and restart automatically, but would loop between crash and restart forever, which is the reason we keep seeing, multiple new session established messages in api.log

Backend vSphere is v5.5U2

Please let know if this is known issue in Mitaka or there needs some config changes to be done from my end

[Andrea Franceschini (afranceschini)]

Hello,

I have also this issue, and I believe the problem is in these parts of the code:

glance_store/backend.py:

def verify_default_store():
    scheme_name = CONF.glance_store.default_store

...

def add_to_backend(conf, image_id, data, size, scheme=None, context=None,
                   verifier=None):
    if scheme is None:
        scheme = conf['glance_store']['default_store']

Both seem to assume that there's an identity between store name and scheme, which is no longer true for vmware datastore.

In fact datastore name is expected to be vmware while SCHEME is vsphere.

To workaround this I've written (based on get_store_from_scheme) a new function that get datastore form its name.

+def get_store_from_name(store_name):
+ store = None
+ for scheme, store_value in location.SCHEME_TO_CLS_MAP.items():
+ if store_value['store_entry'] == store_name:
+ store = store_value['store']
+ if not store.is_capable(capabilities.BitMasks.DRIVER_REUSABLE):
+ # Driver instance isn't stateless so it can't
+ # be reused safely and need recreation.
+ store_entry = store_value['store_entry']
+ store = _load_store(store.conf, store_entry, invoke_load=True)
+ store.configure()
+ try:
+ scheme_map = {}
+ loc_cls = store.get_store_location_class()
+ for scheme in store.get_schemes():
+ scheme_map[scheme] = {
+ 'store': store,
+ 'location_class': loc_cls,
+ 'store_entry': store_entry
+ }
+ location.register_scheme_map(scheme_map)
+ except NotImplementedError:
+ store_value['store'] = store
+ if store is None:
+ raise exceptions.UnknownStore(store_name=store_name)
+ return store

and changed the above functions to use this new one:

def add_to_backend(conf, image_id, data, size, scheme=None, context=None,
                   verifier=None):
    if scheme is None:
        store_name = conf['glance_store']['default_store']
        store = get_store_from_name(store_name)
    else:
        store = get_store_from_scheme(scheme)
    return store_add_to_backend(image_id, data, size, store, context,
                                verifier)

def verify_default_store():
    store_name = CONF.glance_store.default_store
    try:
        get_store_from_name(store_name)
    except exceptions.UnknownStore:
        msg = _("Store named %s not found") % store_name
        raise RuntimeError(msg)

glance_store/exceptions.py:

+class UnknownStore(GlanceStoreException):
+ message = _("Unknown scheme '%(scheme)s' found in URI")

This way everything works, at least for me.

Hope it helps.

[Andrea Franceschini (afranceschini)]

a little correction:

glance_store/exceptions.py:

+class UnknownStore(GlanceStoreException):
+ message = _("No store named '%(store_name)s' found")

and

glance_store/backend.py:
- 'sheepdog', 'cinder', 'vsphere'),
+ 'sheepdog', 'cinder', 'vmware'),

[Andrea Franceschini (afranceschini)]

Actually the problem can be fixed just using:

default_store = vsphere

Or at least it does on pike, I'm not able to replicate it on older releases.

Bye