[Openstack] No valid host was found. There are not enough hosts available. (Was: Create instance fails on creating block device - Block Device Mapping is Invalid)

Turbo Fredriksson turbo at bayour.com
Thu Jun 23 23:32:41 UTC 2016 

Sorry for this long mail - I think the original problem is now fixed.
I'm including the whole work/test log for posterity. And if someone
have anything to comment on it, incase I've missed something..



After six, seven hours of debugging and modifying the code to output
more information, I've found out this:

When running

  openstack server create --volume test --flavor m1.tiny \
    --nic net-id=2bb7b8e2-188f-4e46-bf4d-ef5ec81ddb4d --wait test

I get this on the Compute:

----- s n i p -----
2016-06-23 23:27:34.708 10716 ERROR nova.compute.manager [req-37cfbeac-324c-4077-8056-2efc62e80b3f 0b7e5b0653084efdad5d67b66f2cf949 2985b96e27f048cd92a18db0dd03aa23 - - -] [instance: efe13dfa-79be-49a1-8113-04830463b545] Instance failed block device setup
2016-06-23 23:27:34.708 10716 ERROR nova.compute.manager [instance: efe13dfa-79be-49a1-8113-04830463b545] Traceback (most recent call last):
2016-06-23 23:27:34.708 10716 ERROR nova.compute.manager [instance: efe13dfa-79be-49a1-8113-04830463b545]   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 1754, in _prep_block_device
2016-06-23 23:27:34.708 10716 ERROR nova.compute.manager [instance: efe13dfa-79be-49a1-8113-04830463b545]     wait_func=self._await_block_device_map_created)
2016-06-23 23:27:34.708 10716 ERROR nova.compute.manager [instance: efe13dfa-79be-49a1-8113-04830463b545]   File "/usr/lib/python2.7/dist-packages/nova/virt/block_device.py", line 518, in attach_block_devices
2016-06-23 23:27:34.708 10716 ERROR nova.compute.manager [instance: efe13dfa-79be-49a1-8113-04830463b545]     map(_log_and_attach, block_device_mapping)
2016-06-23 23:27:34.708 10716 ERROR nova.compute.manager [instance: efe13dfa-79be-49a1-8113-04830463b545]   File "/usr/lib/python2.7/dist-packages/nova/virt/block_device.py", line 516, in _log_and_attach
2016-06-23 23:27:34.708 10716 ERROR nova.compute.manager [instance: efe13dfa-79be-49a1-8113-04830463b545]     bdm.attach(*attach_args, **attach_kwargs)
2016-06-23 23:27:34.708 10716 ERROR nova.compute.manager [instance: efe13dfa-79be-49a1-8113-04830463b545]   File "/usr/lib/python2.7/dist-packages/nova/virt/block_device.py", line 54, in wrapped
2016-06-23 23:27:34.708 10716 ERROR nova.compute.manager [instance: efe13dfa-79be-49a1-8113-04830463b545]     ret_val = method(obj, context, *args, **kwargs)
2016-06-23 23:27:34.708 10716 ERROR nova.compute.manager [instance: efe13dfa-79be-49a1-8113-04830463b545]   File "/usr/lib/python2.7/dist-packages/nova/virt/block_device.py", line 261, in attach
2016-06-23 23:27:34.708 10716 ERROR nova.compute.manager [instance: efe13dfa-79be-49a1-8113-04830463b545]     connector = virt_driver.get_volume_connector(instance)
2016-06-23 23:27:34.708 10716 ERROR nova.compute.manager [instance: efe13dfa-79be-49a1-8113-04830463b545]   File "/usr/lib/python2.7/dist-packages/nova/virt/driver.py", line 1375, in get_volume_connector
2016-06-23 23:27:34.708 10716 ERROR nova.compute.manager [instance: efe13dfa-79be-49a1-8113-04830463b545]     raise NotImplementedError()
2016-06-23 23:27:34.708 10716 ERROR nova.compute.manager [instance: efe13dfa-79be-49a1-8113-04830463b545] NotImplementedError
2016-06-23 23:27:34.708 10716 ERROR nova.compute.manager [instance: efe13dfa-79be-49a1-8113-04830463b545]
2016-06-23 23:27:34.742 10716 DEBUG keystoneauth.session [req-37cfbeac-324c-4077-8056-2efc62e80b3f 0b7e5b0653084efdad5d67b66f2cf949 2985b96e27f048cd92a18db0dd03aa23 - - -] RESP: [200] Content-Type: application/json Content-Length: 639 X-Openstack-Request-Id: req-701bcf9e-e2bb-41d1-b49c-935da83f6653 Date: Thu, 23 Jun
----- s n i p -----

Following that backwards, I come to attach_block_devices():

----- s n i p -----
[..]
        else:
            LOG.info(_LI('Booting with blank volume at %(mountpoint)s'),
                     {'mountpoint': bdm['mount_device']},
                     context=context, instance=instance)

        bdm.attach(*attach_args, **attach_kwargs)		(L516)
[..]
        connector = virt_driver.get_volume_connector(instance)	(L261)
[..]
    def get_volume_connector(self, instance):
        """Get connector information for the instance for attaching to volumes.

        Connector information is a dictionary representing the ip of the
        machine that will be making the connection, the name of the iscsi
        initiator and the hostname of the machine as follows::
            {
                'ip': ip,
                'initiator': initiator,
                'host': hostname
            }
        """
        raise NotImplementedError()
----- s n i p -----

So I think I've found a bug. It seems you can't attach an empty volume like I've been
trying for days now. OR, I missed some configuration somewhere..

However, when running:

  openstack server create --image cirros --flavor m1.tiny \
    --nic net-id=2bb7b8e2-188f-4e46-bf4d-ef5ec81ddb4d --wait test

I on the other hand get:

----- s n i p -----
2016-06-23 23:39:09.326 10716 DEBUG nova.compute.manager [req-bb159c37-3033-4a36-a21a-c57acb487de2 0b7e5b0653084efdad5d67b66f2cf949 2985b96e27f048cd92a18db0dd
03aa23 - - -] [instance: 8d7241bf-71a0-466d-b0f1-26211615b777] Start spawning the instance on the hypervisor. _build_and_run_instance /usr/lib/python2.7/dist-
packages/nova/compute/manager.py:2059
2016-06-23 23:39:09.330 10716 DEBUG novadocker.virt.docker.driver [req-bb159c37-3033-4a36-a21a-c57acb487de2 0b7e5b0653084efdad5d67b66f2cf949 2985b96e27f048cd9
2a18db0dd03aa23 - - -] Image name "cirros" does not exist, fetching it... _pull_missing_image /usr/local/lib/python2.7/dist-packages/novadocker/virt/docker/dr
iver.py:384
2016-06-23 23:39:09.332 10716 DEBUG novadocker.virt.docker.driver [req-bb159c37-3033-4a36-a21a-c57acb487de2 0b7e5b0653084efdad5d67b66f2cf949 2985b96e27f048cd92a18db0dd03aa23 - - -] Fetching image with id d4d913c3-21f3-4e7d-932c-2cb35c8131e8 from glance _pull_missing_image /usr/local/lib/python2.7/dist-packages/novadocker/virt/docker/driver.py:415
2016-06-23 23:39:09.392 10716 ERROR nova.image.glance [req-bb159c37-3033-4a36-a21a-c57acb487de2 0b7e5b0653084efdad5d67b66f2cf949 2985b96e27f048cd92a18db0dd03aa23 - - -] Error contacting glance server 'http://10.0.4.3:9292' for 'data', done trying.
2016-06-23 23:39:09.392 10716 ERROR nova.image.glance Traceback (most recent call last):
2016-06-23 23:39:09.392 10716 ERROR nova.image.glance   File "/usr/lib/python2.7/dist-packages/nova/image/glance.py", line 250, in call
2016-06-23 23:39:09.392 10716 ERROR nova.image.glance     result = getattr(client.images, method)(*args, **kwargs)
2016-06-23 23:39:09.392 10716 ERROR nova.image.glance   File "/usr/lib/python2.7/dist-packages/glanceclient/v1/images.py", line 148, in data
2016-06-23 23:39:09.392 10716 ERROR nova.image.glance     % urlparse.quote(str(image_id)))
2016-06-23 23:39:09.392 10716 ERROR nova.image.glance   File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py", line 275, in get
2016-06-23 23:39:09.392 10716 ERROR nova.image.glance     return self._request('GET', url, **kwargs)
2016-06-23 23:39:09.392 10716 ERROR nova.image.glance   File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py", line 256, in _request
2016-06-23 23:39:09.392 10716 ERROR nova.image.glance     raise exc.CommunicationError(message=message)
2016-06-23 23:39:09.392 10716 ERROR nova.image.glance CommunicationError: Error finding address for http://10.0.4.3:9292/v1/images/d4d913c3-21f3-4e7d-932c-2cb35c8131e8: HTTPConnectionPool(host='10.0.4.3', port=9292): Max retries exceeded with url: /v1/images/d4d913c3-21f3-4e7d-932c-2cb35c8131e8 (Caused by NewConnectionError('<requests.packages.urllib3.connection.HTTPConnection object at 0x7fc32ac35110>: Failed to establish a new connection: [Errno 111] ECONNREFUSED',))
2016-06-23 23:39:09.392 10716 ERROR nova.image.glance 
2016-06-23 23:39:09.395 10716 WARNING novadocker.virt.docker.driver [req-bb159c37-3033-4a36-a21a-c57acb487de2 0b7e5b0653084efdad5d67b66f2cf949 2985b96e27f048cd92a18db0dd03aa23 - - -] [instance: 8d7241bf-71a0-466d-b0f1-26211615b777] Cannot load repository file: Connection to glance host http://10.0.4.3:9292 failed: Error finding address for http://10.0.4.3:9292/v1/images/d4d913c3-21f3-4e7d-932c-2cb35c8131e8: HTTPConnectionPool(host='10.0.4.3', port=9292): Max retries exceeded with url: /v1/images/d4d913c3-21f3-4e7d-932c-2cb35c8131e8 (Caused by NewConnectionError('<requests.packages.urllib3.connection.HTTPConnection object at 0x7fc32ac35110>: Failed to establish a new connection: [Errno 111] ECONNREFUSED',))
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777] Traceback (most recent call last):
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777]   File "/usr/local/lib/python2.7/dist-packages/novadocker/virt/docker/driver.py", line 417, in _pull_missing_image
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777]     instance['user_id'], instance['project_id'])
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777]   File "/usr/lib/python2.7/dist-packages/nova/virt/images.py", line 110, in fetch
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777]     IMAGE_API.download(context, image_href, dest_path=path)
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777]   File "/usr/lib/python2.7/dist-packages/nova/image/api.py", line 182, in download
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777]     dst_path=dest_path)
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777]   File "/usr/lib/python2.7/dist-packages/nova/image/glance.py", line 383, in download
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777]     _reraise_translated_image_exception(image_id)
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777]   File "/usr/lib/python2.7/dist-packages/nova/image/glance.py", line 682, in _reraise_translated_image_exception
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777]     six.reraise(new_exc, None, exc_trace)
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777]   File "/usr/lib/python2.7/dist-packages/nova/image/glance.py", line 381, in download
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777]     image_chunks = self._client.call(context, 1, 'data', image_id)
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777]   File "/usr/lib/python2.7/dist-packages/nova/image/glance.py", line 269, in call
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777]     server=str(self.api_server), reason=six.text_type(e))
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777] GlanceConnectionFailed: Connection to glance host http://10.0.4.3:9292 failed: Error finding address for http://10.0.4.3:9292/v1/images/d4d913c3-21f3-4e7d-932c-2cb35c8131e8: HTTPConnectionPool(host='10.0.4.3', port=9292): Max retries exceeded with url: /v1/images/d4d913c3-21f3-4e7d-932c-2cb35c8131e8 (Caused by NewConnectionError('<requests.packages.urllib3.connection.HTTPConnection object at 0x7fc32ac35110>: Failed to establish a new connection: [Errno 111] ECONNREFUSED',))
2016-06-23 23:39:09.395 10716 ERROR novadocker.virt.docker.driver [instance: 8d7241bf-71a0-466d-b0f1-26211615b777] 
2016-06-23 23:39:09.398 10716 ERROR nova.compute.manager [req-bb159c37-3033-4a36-a21a-c57acb487de2 0b7e5b0653084efdad5d67b66f2cf949 2985b96e27f048cd92a18db0dd03aa23 - - -] [instance: 8d7241bf-71a0-466d-b0f1-26211615b777] Instance failed to spawn
----- s n i p -----

This was because of a missing "api_servers" in nova.conf. Setting that to (using trial
and error):

  api_servers = http://control:9292

The information in the config file say:

  These should be fully qualified urls of the form "scheme://hostname:port[/path]"

However, with the/any path, it won't work. Granted, the 'endpoint list' DOES say
"http://10.0.4.1:9292", so I guess the path is optional and for special configuration.



Now it seems to go further:

----- s n i p -----
2016-06-24 00:03:09.622 14217 DEBUG novadocker.virt.docker.driver [req-867eddb0-5367-425a-8189-cdf3e5293855 0b7e5b0653084efdad5d67b66f2cf949 2985b96e27f048cd9
2a18db0dd03aa23 - - -] Loading repository file into docker cirros _pull_missing_image /usr/local/lib/python2.7/dist-packages/novadocker/virt/docker/driver.py:
419
2016-06-24 00:03:10.100 14217 DEBUG keystoneauth.session [req-867eddb0-5367-425a-8189-cdf3e5293855 0b7e5b0653084efdad5d67b66f2cf949 2985b96e27f048cd92a18db0dd
03aa23 - - -] RESP: [201] Content-Type: application/json Content-Length: 871 X-Openstack-Request-Id: req-17ccf052-d52c-401f-9cc7-3a0819e4c3fa Date: Thu, 23 Ju
n 2016 23:03:08 GMT Connection: keep-alive 
RESP BODY: {"port": {"status": "DOWN", "binding:host_id": "bladeA03b", "description": "", "allowed_address_pairs": [], "extra_dhcp_opts": [], "updated_at": "2
016-06-23T23:03:08", "device_owner": "compute:nova", "port_security_enabled": true, "binding:profile": {}, "fixed_ips": [{"subnet_id": "6ef5d993-2796-4adf-a72
4-eae5f5d1cc53", "ip_address": "10.99.0.40"}], "id": "db8bec43-9ba0-4276-9623-1a17f5857a06", "security_groups": ["c39cbc1f-99cf-4c1a-98b2-ec4f56481ccf"], "dev
ice_id": "3dd1ff63-24ea-435d-a036-e99a42ebf1b5", "name": "", "admin_state_up": true, "network_id": "2bb7b8e2-188f-4e46-bf4d-ef5ec81ddb4d", "dns_name": null, "
binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "tenant_id": "2985b96e27f048cd
92a18db0dd03aa23", "mac_address": "fa:16:3e:64:4e:18", "created_at": "2016-06-23T23:03:08"}}
 _http_log_response /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:277
2016-06-24 00:03:10.101 14217 DEBUG nova.network.neutronv2.api [req-867eddb0-5367-425a-8189-cdf3e5293855 0b7e5b0653084efdad5d67b66f2cf949 2985b96e27f048cd92a18db0dd03aa23 - - -] [instance: 3dd1ff63-24ea-435d-a036-e99a42ebf1b5] Successfully created port: db8bec43-9ba0-4276-9623-1a17f5857a06 _create_port /usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py:261
2016-06-24 00:03:10.102 14217 DEBUG oslo_concurrency.lockutils [req-867eddb0-5367-425a-8189-cdf3e5293855 0b7e5b0653084efdad5d67b66f2cf949 2985b96e27f048cd92a18db0dd03aa23 - - -] Acquired semaphore "refresh_cache-3dd1ff63-24ea-435d-a036-e99a42ebf1b5" lock /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:215
2016-06-24 00:03:10.103 14217 DEBUG nova.network.neutronv2.api [req-867eddb0-5367-425a-8189-cdf3e5293855 0b7e5b0653084efdad5d67b66f2cf949 2985b96e27f048cd92a18db0dd03aa23 - - -] [instance: 3dd1ff63-24ea-435d-a036-e99a42ebf1b5] _get_instance_nw_info() _get_instance_nw_info /usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py:910
2016-06-24 00:03:10.121 14217 DEBUG keystoneauth.session [req-867eddb0-5367-425a-8189-cdf3e5293855 0b7e5b0653084efdad5d67b66f2cf949 2985b96e27f048cd92a18db0dd03aa23 - - -] REQ: curl -g -i -X GET http://10.0.4.1:9696/v2.0/ports.json?tenant_id=2985b96e27f048cd92a18db0dd03aa23&device_id=3dd1ff63-24ea-435d-a036-e99a42ebf1b5 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}262b2c831c6ea94c09cd20bb956858e6c71671b2" _http_log_request /usr/lib/python2.7/dist-packages/keystoneauth1/session.py:248
2016-06-24 00:03:10.169 14217 WARNING novadocker.virt.docker.driver [req-867eddb0-5367-425a-8189-cdf3e5293855 0b7e5b0653084efdad5d67b66f2cf949 2985b96e27f048cd92a18db0dd03aa23 - - -] [instance: 3dd1ff63-24ea-435d-a036-e99a42ebf1b5] Cannot load repository file: ('Connection aborted.', error(32, 'Broken pipe'))
----- s n i p -----


And now I'm stuck again. Looking at the information of the instance, it now say:

  No valid host was found. There are not enough hosts available.

Although:

----- s n i p -----
bladeA01b:~# openstack endpoint list | grep nova
| a5e36f0b933c4e4da7a5737d00e7230b | europe-london | nova | compute | True | internal | http://10.0.4.1:8774/v2/%(tenant_id)s |
| b7a8e4623fbd456fb008527f9c51995f | europe-london | nova | compute | True | admin    | http://10.0.4.1:8774/v2/%(tenant_id)s |
| c3b5eda8124b4e4186f919a7944d1290 | europe-london | nova | compute | True | public   | http://10.0.4.1:8774/v2/%(tenant_id)s |
----- s n i p -----

More information about the Openstack mailing list