Revision history [back]

click to hide/show revision 1
initial version

Spark Kilo Nova Fails to Deploy:

Hi
Trying to deploy a 4-node spark cluster, 1 master and 3 slaves, and am running into scheduler problem:

    # tail -f /var/log/nova/nova-conductor.log
    2015-06-13 00:13:14.119 1030 INFO oslo_messaging._drivers.impl_rabbit [req-62362f47-167e-4a23-8c9b-c50d94448cbf fcbce29fa1eb4b42921a20055afdc024 8f3633c4ba1640abbab3be608b6bcc88 - - -] Connecting to AMQP server on 10.4.0.60:5672
2015-06-13 00:13:14.140 1030 INFO oslo_messaging._drivers.impl_rabbit [req-62362f47-167e-4a23-8c9b-c50d94448cbf fcbce29fa1eb4b42921a20055afdc024 8f3633c4ba1640abbab3be608b6bcc88 - - -] Connected to AMQP server on 10.4.0.60:5672
2015-06-13 00:13:20.750 1025 INFO oslo_messaging._drivers.impl_rabbit [req-27b42398-5b52-4762-abef-3baa75624b3e fcbce29fa1eb4b42921a20055afdc024 8f3633c4ba1640abbab3be608b6bcc88 - - -] Connecting to AMQP server on 10.4.0.60:5672
2015-06-13 00:13:20.763 1025 INFO oslo_messaging._drivers.impl_rabbit [req-27b42398-5b52-4762-abef-3baa75624b3e fcbce29fa1eb4b42921a20055afdc024 8f3633c4ba1640abbab3be608b6bcc88 - - -] Connected to AMQP server on 10.4.0.60:5672
2015-06-13 00:13:20.793 1025 WARNING nova.scheduler.utils [req-27b42398-5b52-4762-abef-3baa75624b3e fcbce29fa1eb4b42921a20055afdc024 8f3633c4ba1640abbab3be608b6bcc88 - - -] Failed to compute_task_build_instances: No valid host was found. There are not enough hosts available.
Traceback (most recent call last):

  File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 142, in inner
    return func(*args, **kwargs)

  File "/usr/lib/python2.7/dist-packages/nova/scheduler/manager.py", line 86, in select_destinations
    filter_properties)

  File "/usr/lib/python2.7/dist-packages/nova/scheduler/filter_scheduler.py", line 80, in select_destinations
    raise exception.NoValidHost(reason=reason)

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

2015-06-13 00:13:20.794 1025 WARNING nova.scheduler.utils [req-27b42398-5b52-4762-abef-3baa75624b3e fcbce29fa1eb4b42921a20055afdc024 8f3633c4ba1640abbab3be608b6bcc88 - - -] [instance: c752241f-f07d-46cd-8844-f1747575e8a2] Setting instance to ERROR state.

And sahara log:

# tail -f /var/log/sahara.log  -n 350 | more
  2015-06-13 00:12:57.774 1968 DEBUG keystonemiddleware.auth_token [-] Removing headers from request environment: X-Service-Catalog,X-Identity-Status,X-Service-Identity-Status,X-Roles,X-Service-Roles,X-Domain-Name,X-Service-Domain-Name,X-Project-Id,X-Service-Project-Id,X-Project-Domain-Name,X-Service-Project-Domain-Name,X-User-Id,X-Service-User-Id,X-User-Name,X-Service-User-Name,X-Project-Name,X-Service-Project-Name,X-User-Domain-Id,X-Service-User-Domain-Id,X-Domain-Id,X-Service-Domain-Id,X-User-Domain-Name,X-Service-User-Domain-Name,X-Project-Domain-Id,X-Service-Project-Domain-Id,X-Role,X-User,X-Tenant-Name,X-Tenant-Id,X-Tenant _remove_auth_headers /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/keystonemiddleware/auth_token/__init__.py:672
2015-06-13 00:12:57.775 1968 DEBUG keystonemiddleware.auth_token [-] Authenticating user token __call__ /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/keystonemiddleware/auth_token/__init__.py:581
2015-06-13 00:12:57.776 1968 DEBUG keystoneclient.session [-] REQ: curl -g -i -X GET http://10.4.0.61:35357/v3/auth/tokens -H "X-Subject-Token: {SHA1}9774f30871278b81c54e43e1d87e51915f38a60d" -H "User-Agent: python-keystoneclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}964e5e4bfa51abcd0c3f254409db775b35e3ce9c" _http_log_request /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/keystoneclient/session.py:195
2015-06-13 00:12:57.940 1968 DEBUG keystoneclient.session [-] RESP: [200] content-length: 6583 x-subject-token: {SHA1}9774f30871278b81c54e43e1d87e51915f38a60d vary: X-Auth-Token x-distribution: Ubuntu connection: keep-alive date: Sat, 13 Jun 2015 00:12:57 GMT content-type: application/json x-openstack-request-id: req-f2857800-c607-4410-ba2a-c8ffc97b5351 
RESP BODY: {"token": {"methods": ["password", "token"], "roles": [{"id": "9fe2ff9ee4384b1894a90878d3e92bab", "name": "_member_"}, {"id": "f5c52968f8af4111bbfccd39ef500edd", "name": "Admin"}], "expires_at": "2015-06-13T01:12:57.000000Z", "project": {"domain": {"id": "default", "name": "Default"}, "id": "8f3633c4ba1640abbab3be608b6bcc88", "name": "admin"}, "catalog": "<removed>", "extras": {}, "user": {"domain": {"id": "default", "name": "Default"}, "id": "fcbce29fa1eb4b42921a20055afdc024", "name": "admin"}, "audit_ids": ["6jslb2MQS-2ySURQMeLvDw"], "issued_at": "2015-06-13T00:12:57.643005"}}
 _http_log_response /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/keystoneclient/session.py:224
2015-06-13 00:12:57.941 1968 DEBUG keystonemiddleware.auth_token [-] Storing token in cache store /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/keystonemiddleware/auth_token/_cache.py:192
2015-06-13 00:12:57.943 1968 DEBUG keystonemiddleware.auth_token [-] Authenticating service token __call__ /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/keystonemiddleware/auth_token/__init__.py:603
2015-06-13 00:12:57.943 1968 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id fcbce29fa1eb4b42921a20055afdc024, project_id 8f3633c4ba1640abbab3be608b6bcc88, roles _member_,Admin service: user_id None, project_id None, roles None __call__ /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/keystonemiddleware/auth_token/__init__.py:632
2015-06-13 00:12:57.944 1968 DEBUG sahara.utils.api [-] Rest.route.decorator.handler, kwargs={'tenant_id': u'8f3633c4ba1640abbab3be608b6bcc88'} handler /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/sahara/utils/api.py:67
2015-06-13 00:13:01.876 1968 DEBUG oslo_concurrency.processutils [-] Running cmd (subprocess): ssh-keygen -q -N  -t rsa -f /tmp/tmp604VpX/tempkey -C Generated by Sahara -b 2048 execute /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/oslo_concurrency/processutils.py:199
2015-06-13 00:13:02.073 1968 DEBUG oslo_concurrency.processutils [-] CMD "ssh-keygen -q -N  -t rsa -f /tmp/tmp604VpX/tempkey -C Generated by Sahara -b 2048" returned: 0 in 0.197s execute /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/oslo_concurrency/processutils.py:225
2015-06-13 00:13:02.582 1968 INFO sahara.utils.general [-] Cluster status has been changed: id=805a4938-8ae4-4463-b5f8-743ab3830af5, New status=Validating
2015-06-13 00:13:03.139 1968 DEBUG neutronclient.client [-] 
REQ: curl -i http://10.4.0.67:9696/v2.0/quotas/8f3633c4ba1640abbab3be608b6bcc88.json -X GET -H "User-Agent: python-neutronclient" -H "X-Auth-Token: 3c6ce4b897c145648ce1cc70346f316a"
 http_log_req /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/neutronclient/common/utils.py:130
2015-06-13 00:13:03.153 1968 DEBUG neutronclient.client [-] RESP:200 {'date': 'Sat, 13 Jun 2015 00:13:03 GMT', 'connection': 'keep-alive', 'content-type': 'application/json; charset=UTF-8', 'content-length': '276', 'x-openstack-request-id': 'req-557764d8-bca2-4db0-8681-2b2d9fd94c25'} {"quota": {"subnet": 10, "ikepolicy": -1, "network": 10, "ipsec_site_connection": -1, "health_monitor": -1, "ipsecpolicy": -1, "security_group_rule": 100, "vip": 10, "vpnservice": -1, "floatingip": 50, "security_group": 10, "router": 10, "port": 50, "pool": 10, "member": -1}}
 http_log_resp /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/neutronclient/common/utils.py:139
2015-06-13 00:13:03.154 1968 DEBUG neutronclient.client [-] 
REQ: curl -i http://10.4.0.67:9696/v2.0/floatingips.json?tenant_id=8f3633c4ba1640abbab3be608b6bcc88 -X GET -H "User-Agent: python-neutronclient" -H "X-Auth-Token: 3c6ce4b897c145648ce1cc70346f316a"
 http_log_req /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/neutronclient/common/utils.py:130
2015-06-13 00:13:03.168 1968 DEBUG neutronclient.client [-] RESP:200 {'date': 'Sat, 13 Jun 2015 00:13:03 GMT', 'connection': 'keep-alive', 'content-type': 'application/json; charset=UTF-8', 'content-length': '294', 'x-openstack-request-id': 'req-cbb988de-a1a6-4a17-969e-2678ddd094b2'} {"floatingips": [{"floating_network_id": "77e86970-5428-426e-9494-fd5af65cd831", "router_id": null, "fixed_ip_address": null, "floating_ip_address": "10.4.50.60", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "status": "DOWN", "port_id": null, "id": "dae236a4-5200-4a16-828b-9ea0e8f663ea"}]}
 http_log_resp /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/neutronclient/common/utils.py:139
2015-06-13 00:13:03.169 1968 DEBUG neutronclient.client [-] 
REQ: curl -i http://10.4.0.67:9696/v2.0/security-groups.json?tenant_id=8f3633c4ba1640abbab3be608b6bcc88 -X GET -H "User-Agent: python-neutronclient" -H "X-Auth-Token: 3c6ce4b897c145648ce1cc70346f316a"
 http_log_req /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/neutronclient/common/utils.py:130
2015-06-13 00:13:03.416 1968 DEBUG neutronclient.client [-] RESP:200 {'date': 'Sat, 13 Jun 2015 00:13:03 GMT', 'connection': 'keep-alive', 'content-type': 'application/json; charset=UTF-8', 'content-length': '2159', 'x-openstack-request-id': 'req-4ca9a4c9-2cec-4698-9159-9e6953172154'} {"security_groups": [{"tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "description": "Default security group", "id": "4af1e7f5-1cee-4869-8ef4-c51a41b5fe43", "security_group_rules": [{"remote_group_id": null, "direction": "ingress", "remote_ip_prefix": "0.0.0.0/0", "protocol": "tcp", "ethertype": "IPv4", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "port_range_max": 65535, "port_range_min": 1, "id": "761a614b-434a-4bda-8c78-301b673e8e0f", "security_group_id": "4af1e7f5-1cee-4869-8ef4-c51a41b5fe43"}, {"remote_group_id": null, "direction": "egress", "remote_ip_prefix": "0.0.0.0/0", "protocol": "tcp", "ethertype": "IPv4", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "port_range_max": 65535, "port_range_min": 1, "id": "77803de7-d96b-4295-9dce-b59a3b51b412", "security_group_id": "4af1e7f5-1cee-4869-8ef4-c51a41b5fe43"}, {"remote_group_id": null, "direction": "ingress", "remote_ip_prefix": "0.0.0.0/0", "protocol": "icmp", "ethertype": "IPv4", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "port_range_max": null, "port_range_min": null, "id": "a59601ad-cb42-44e3-9de9-dfe989edd314", "security_group_id": "4af1e7f5-1cee-4869-8ef4-c51a41b5fe43"}, {"remote_group_id": null, "direction": "ingress", "remote_ip_prefix": "0.0.0.0/0", "protocol": "udp", "ethertype": "IPv4", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "port_range_max": 65535, "port_range_min": 1, "id": "a76045f7-3881-420b-9e04-d7ed46f42e8d", "security_group_id": "4af1e7f5-1cee-4869-8ef4-c51a41b5fe43"}, {"remote_group_id": null, "direction": "ingress", "remote_ip_prefix": "0.0.0.0/0", "protocol": "tcp", "ethertype": "IPv4", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "port_range_max": 22, "port_range_min": 22, "id": "a7eef13c-07c7-4846-a496-8e98c0cf9456", "security_group_id": "4af1e7f5-1cee-4869-8ef4-c51a41b5fe43"}, {"remote_group_id": null, "direction": "egress", "remote_ip_prefix": "0.0.0.0/0", "protocol": "udp", "ethertype": "IPv4", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "port_range_max": 65535, "port_range_min": 1, "id": "ad909553-33fb-4046-9efe-bdc8c1581417", "security_group_id": "4af1e7f5-1cee-4869-8ef4-c51a41b5fe43"}], "name": "default"}]}
 http_log_resp /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/neutronclient/common/utils.py:139
2015-06-13 00:13:03.417 1968 DEBUG neutronclient.client [-] 
REQ: curl -i http://10.4.0.67:9696/v2.0/security-group-rules.json?tenant_id=8f3633c4ba1640abbab3be608b6bcc88 -X GET -H "User-Agent: python-neutronclient" -H "X-Auth-Token: 3c6ce4b897c145648ce1cc70346f316a"
 http_log_req /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/neutronclient/common/utils.py:130
2015-06-13 00:13:03.626 1968 DEBUG neutronclient.client [-] RESP:200 {'date': 'Sat, 13 Jun 2015 00:13:03 GMT', 'connection': 'keep-alive', 'content-type': 'application/json; charset=UTF-8', 'content-length': '1981', 'x-openstack-request-id': 'req-8d50d1c0-6349-4c2d-9746-aa244f673e2f'} {"security_group_rules": [{"remote_group_id": null, "direction": "ingress", "remote_ip_prefix": "0.0.0.0/0", "protocol": "tcp", "ethertype": "IPv4", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "port_range_max": 65535, "port_range_min": 1, "id": "761a614b-434a-4bda-8c78-301b673e8e0f", "security_group_id": "4af1e7f5-1cee-4869-8ef4-c51a41b5fe43"}, {"remote_group_id": null, "direction": "egress", "remote_ip_prefix": "0.0.0.0/0", "protocol": "tcp", "ethertype": "IPv4", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "port_range_max": 65535, "port_range_min": 1, "id": "77803de7-d96b-4295-9dce-b59a3b51b412", "security_group_id": "4af1e7f5-1cee-4869-8ef4-c51a41b5fe43"}, {"remote_group_id": null, "direction": "ingress", "remote_ip_prefix": "0.0.0.0/0", "protocol": "icmp", "ethertype": "IPv4", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "port_range_max": null, "port_range_min": null, "id": "a59601ad-cb42-44e3-9de9-dfe989edd314", "security_group_id": "4af1e7f5-1cee-4869-8ef4-c51a41b5fe43"}, {"remote_group_id": null, "direction": "ingress", "remote_ip_prefix": "0.0.0.0/0", "protocol": "udp", "ethertype": "IPv4", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "port_range_max": 65535, "port_range_min": 1, "id": "a76045f7-3881-420b-9e04-d7ed46f42e8d", "security_group_id": "4af1e7f5-1cee-4869-8ef4-c51a41b5fe43"}, {"remote_group_id": null, "direction": "ingress", "remote_ip_prefix": "0.0.0.0/0", "protocol": "tcp", "ethertype": "IPv4", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "port_range_max": 22, "port_range_min": 22, "id": "a7eef13c-07c7-4846-a496-8e98c0cf9456", "security_group_id": "4af1e7f5-1cee-4869-8ef4-c51a41b5fe43"}, {"remote_group_id": null, "direction": "egress", "remote_ip_prefix": "0.0.0.0/0", "protocol": "udp", "ethertype": "IPv4", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "port_range_max": 65535, "port_range_min": 1, "id": "ad909553-33fb-4046-9efe-bdc8c1581417", "security_group_id": "4af1e7f5-1cee-4869-8ef4-c51a41b5fe43"}]}
 http_log_resp /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/neutronclient/common/utils.py:139
2015-06-13 00:13:03.627 1968 DEBUG neutronclient.client [-] 
REQ: curl -i http://10.4.0.67:9696/v2.0/ports.json?tenant_id=8f3633c4ba1640abbab3be608b6bcc88 -X GET -H "User-Agent: python-neutronclient" -H "X-Auth-Token: 3c6ce4b897c145648ce1cc70346f316a"
 http_log_req /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/neutronclient/common/utils.py:130
2015-06-13 00:13:04.048 1968 DEBUG neutronclient.client [-] RESP:200 {'date': 'Sat, 13 Jun 2015 00:13:04 GMT', 'connection': 'keep-alive', 'content-type': 'application/json; charset=UTF-8', 'content-length': '2877', 'x-openstack-request-id': 'req-f926587e-7dff-4018-b302-73f01b93ac67'} {"ports": [{"status": "DOWN", "binding:host_id": "lab-cn01", "allowed_address_pairs": [], "extra_dhcp_opts": [], "device_owner": "compute:nova", "binding:profile": {}, "fixed_ips": [{"subnet_id": "15714b51-8150-4659-9a5f-dcdf43d0d8f2", "ip_address": "10.40.50.15"}], "id": "2dca0fd3-11ec-4d63-a612-a994ca073895", "security_groups": ["4af1e7f5-1cee-4869-8ef4-c51a41b5fe43"], "device_id": "7aa48409-d75b-4a61-b865-eda1f21b4bdd", "name": "", "admin_state_up": true, "network_id": "1b036b8e-56cb-4d06-afe0-1b5c28587eaf", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "mac_address": "fa:16:3e:3f:75:0d"}, {"status": "ACTIVE", "binding:host_id": "lab-nw01", "allowed_address_pairs": [], "extra_dhcp_opts": [], "device_owner": "network:dhcp", "binding:profile": {}, "fixed_ips": [{"subnet_id": "15714b51-8150-4659-9a5f-dcdf43d0d8f2", "ip_address": "10.40.50.12"}], "id": "4f45880b-d52c-403c-b9cd-1d015597dbc6", "security_groups": [], "device_id": "dhcp199b4e0a-7a78-5b99-9174-beecc1089bc5-1b036b8e-56cb-4d06-afe0-1b5c28587eaf", "name": "", "admin_state_up": true, "network_id": "1b036b8e-56cb-4d06-afe0-1b5c28587eaf", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "mac_address": "fa:16:3e:a0:75:a7"}, {"status": "ACTIVE", "binding:host_id": "lab-nw01", "allowed_address_pairs": [], "extra_dhcp_opts": [], "device_owner": "network:router_interface", "binding:profile": {}, "fixed_ips": [{"subnet_id": "15714b51-8150-4659-9a5f-dcdf43d0d8f2", "ip_address": "10.40.50.1"}], "id": "a807c2a9-4ecb-410c-8691-70194cd6c88f", "security_groups": [], "device_id": "dcd1a3c4-a34b-459c-903f-93e6a57d3f9b", "name": "", "admin_state_up": true, "network_id": "1b036b8e-56cb-4d06-afe0-1b5c28587eaf", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "mac_address": "fa:16:3e:12:bd:53"}, {"status": "ACTIVE", "binding:host_id": "lab-cn01", "allowed_address_pairs": [], "extra_dhcp_opts": [], "device_owner": "compute:nova", "binding:profile": {}, "fixed_ips": [{"subnet_id": "15714b51-8150-4659-9a5f-dcdf43d0d8f2", "ip_address": "10.40.50.14"}], "id": "ce1c9a64-553a-4367-9d2b-fe55aa41c962", "security_groups": ["4af1e7f5-1cee-4869-8ef4-c51a41b5fe43"], "device_id": "7f0484c2-d893-4d3e-b7c2-8062ceac7c02", "name": "", "admin_state_up": true, "network_id": "1b036b8e-56cb-4d06-afe0-1b5c28587eaf", "tenant_id": "8f3633c4ba1640abbab3be608b6bcc88", "binding:vif_details": {"port_filter": true, "ovs_hybrid_plug": true}, "binding:vnic_type": "normal", "binding:vif_type": "ovs", "mac_address": "fa:16:3e:b2:c4:aa"}]}
 http_log_resp /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/neutronclient/common/utils.py:139
2015-06-13 00:13:04.475 1968 INFO sahara.utils.wsgi [-] 10.4.0.51 - - [13/Jun/2015 00:13:04] "POST /v1.1/8f3633c4ba1640abbab3be608b6bcc88/clusters HTTP/1.1" 202 2615 6.700047
2015-06-13 00:13:07.232 1968 INFO sahara.utils.general [-] Cluster status has been changed: id=805a4938-8ae4-4463-b5f8-743ab3830af5, New status=InfraUpdating
2015-06-13 00:13:07.551 1968 INFO sahara.utils.general [-] Cluster status has been changed: id=805a4938-8ae4-4463-b5f8-743ab3830af5, New status=Spawning
2015-06-13 00:13:16.510 1968 DEBUG sahara.openstack.common.periodic_task [-] Running periodic task SaharaPeriodicTasks.update_job_statuses run_periodic_tasks /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/sahara/openstack/common/periodic_task.py:219
2015-06-13 00:13:16.511 1968 DEBUG sahara.service.periodic [-] Updating job statuses update_job_statuses /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/sahara/service/periodic.py:123
2015-06-13 00:13:16.516 1968 DEBUG sahara.openstack.common.loopingcall [-] Dynamic looping call <bound method SaharaPeriodicTasks.run_periodic_tasks of <sahara.service.periodic.SaharaPeriodicTasks object at 0x7f30ba452fd0>> sleeping for 27.94 seconds _inner /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/sahara/openstack/common/loopingcall.py:132
2015-06-13 00:13:21.338 1968 INFO sahara.utils.general [-] Cluster status has been changed: id=805a4938-8ae4-4463-b5f8-743ab3830af5, New status=Waiting
2015-06-13 00:13:23.669 1968 ERROR sahara.service.ops [-] Error during operating on cluster cluster-1 (reason: Node cluster-1-workers-003 has error status
Error ID: 1578e0e2-5c9b-4c5c-bf62-746705275fb8)
2015-06-13 00:13:28.455 1968 DEBUG sahara.service.direct_engine [-] Instance cluster-1-master-001 is deleted _check_deleted /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/sahara/service/direct_engine.py:465
2015-06-13 00:13:28.586 1968 DEBUG sahara.utils.poll_utils [-] Operation with name Wait for instances to be deleted was executed successfully in timeout 10800 poll /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/sahara/utils/poll_utils.py:134
2015-06-13 00:13:32.174 1968 DEBUG sahara.service.direct_engine [-] Instance cluster-1-workers-003 is deleted _check_deleted /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/sahara/service/direct_engine.py:465
2015-06-13 00:13:33.459 1968 DEBUG sahara.service.direct_engine [-] Instance cluster-1-workers-001 is deleted _check_deleted /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/sahara/service/direct_engine.py:465
2015-06-13 00:13:34.906 1968 DEBUG sahara.service.direct_engine [-] Instance cluster-1-workers-002 is deleted _check_deleted /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/sahara/service/direct_engine.py:465
2015-06-13 00:13:35.017 1968 DEBUG sahara.utils.poll_utils [-] Operation with name Wait for instances to be deleted was executed successfully in timeout 10800 poll /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/sahara/utils/poll_utils.py:134
2015-06-13 00:13:35.705 1968 WARNING sahara.service.direct_engine [-] Cluster cluster-1 creation rollback (reason: Node cluster-1-workers-003 has error status
Error ID: 1578e0e2-5c9b-4c5c-bf62-746705275fb8)
2015-06-13 00:13:36.210 1968 INFO sahara.utils.general [-] Cluster status has been changed: id=805a4938-8ae4-4463-b5f8-743ab3830af5, New status=Error
2015-06-13 00:13:44.461 1968 DEBUG sahara.openstack.common.periodic_task [-] Running periodic task SaharaPeriodicTasks.terminate_unneeded_transient_clusters run_periodic_tasks /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/sahara/openstack/common/periodic_task.py:219
2015-06-13 00:13:44.462 1968 DEBUG sahara.service.periodic [-] Terminating unneeded transient clusters terminate_unneeded_transient_clusters /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/sahara/service/periodic.py:131
2015-06-13 00:13:44.501 1968 DEBUG sahara.openstack.common.loopingcall [-] Dynamic looping call <bound method SaharaPeriodicTasks.run_periodic_tasks of <sahara.service.periodic.SaharaPeriodicTasks object at 0x7f30ba452fd0>> sleeping for 16.98 seconds _inner /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/sahara/openstack/common/loopingcall.py:132
2015-06-13 00:14:01.499 1968 DEBUG sahara.openstack.common.periodic_task [-] Running periodic task SaharaPeriodicTasks.update_job_statuses run_periodic_tasks /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/sahara/openstack/common/periodic_task.py:219
2015-06-13 00:14:01.499 1968 DEBUG sahara.service.periodic [-] Updating job statuses update_job_statuses /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/sahara/service/periodic.py:123
2015-06-13 00:14:01.521 1968 DEBUG sahara.openstack.common.loopingcall [-] Dynamic looping call <bound method SaharaPeriodicTasks.run_periodic_tasks of <sahara.service.periodic.SaharaPeriodicTasks object at 0x7f30ba452fd0>> sleeping for 45.00 seconds _inner /opt/sahara/sahara-venv-stable-kilo/local/lib/python2.7/site-packages/sahara/openstack/common/loopingcall.py:132

What is bizarre is that none of the compute nodes get a request to instantiate any VMs. The only entry in compute nodes is:

~# tail -f /var/log/nova/nova-compute.log -n 80
2015-06-13 00:13:39.084 3363 WARNING nova.virt.libvirt.imagecache [req-358fe114-b4ea-480f-8646-f25a58c5145c - - - - -] Unknown base file: /var/lib/nova/instances/_base/c8089b1a2a772755116acfc4635f30cc43d09265

(BTW, nodes are fully capable of honouring such requests:

~# nova hypervisor-stats
+----------------------+--------+
| Property             | Value  |
+----------------------+--------+
| count                | 3      |
| current_workload     | 0      |
| disk_available_least | 2570   |
| free_disk_gb         | 2745   |
| free_ram_mb          | 191257 |
| local_gb             | 2745   |
| local_gb_used        | 0      |
| memory_mb            | 192793 |
| memory_mb_used       | 1536   |
| running_vms          | 0      |
| vcpus                | 216    |
| vcpus_used           | 0      |
+----------------------+--------+

) Also, I am able to manually instantiate 4 nodes using the same flavour and image, manually.
Sahara version:

~# sahara-all --version
2015.1.1

on Ubuntu 14.04.
Any thoughts?
Cheers,