Open Stack

Hi all,

I'm trying to setup Juno on five hosts (CentOS 7), following along the
three-node setup guide as close as possible. My setup differs in that I
have separate nodes for storage (cinder, glance) and network (neutron)
and two compute hosts:

Here's a list of the services that run on each host, hostname aliases in
parentheses

os484001 (db mq ntp horizon keystone neutron-controller nova-controller)
  dnsmasq (for name resolution in management network)
  ntp
  mariadb
  memcached
  httpd (horizon)
  rabbitmq-server
  keystone
  nova-api
  nova-cert
  nova-condictor
  nova-consoleauth
  nova-novncproxy
  nova-scheduler
  neutron-server
os403801 (cinder cinder01 glance)
  cinder-api
  cinder-scheduler
  cinder-volume
  glance-api
  glance-registry
  target
os483601 (neutron)
  neutron-dhcp-agent
  neutron-l3-agent
  neutron-metadata-agent
  neutron-openvswitch-agent
  neutron-ovs-cleanup
  openvswitch
os483401 and os483201 (nova01 and nova02)
  libvirtd
  openstack-nova-compute
  openvswitch

I have come as far as as installing cinder (chapter 8) and then ran into
the following issue: every time I try to start a new instance Horizon
shows a popup "No valid host was found". I didn't try to start an
instance before.

neutron server.log on the controller node (os484001) shows:

2014-11-26 11:09:56.363 5137 WARNING neutron.plugins.ml2.managers
[req-c40eb39a-ea68-4e0f-a901-bf267befd050 None] Failed to bind port
3cfcfa07-ab38-4ff3-8615-974334e6944e on host nova01

nova-compute.log from the hypervisor show:

2014-11-26 11:09:52.981 5436 DEBUG nova.compute.resources.vcpu
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Total CPUs: 8 VCPUs,
used: 0.00 VCPUs test
/usr/lib/python2.7/site-packages/nova/compute/resources/vcpu.py:51
2014-11-26 11:09:52.982 5436 DEBUG nova.compute.resources.vcpu
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] CPUs limit not
specified, defaulting to unlimited test
/usr/lib/python2.7/site-packages/nova/compute/resources/vcpu.py:55
2014-11-26 11:09:52.982 5436 AUDIT nova.compute.claims
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac] Claim successful
2014-11-26 11:09:53.092 5436 INFO nova.scheduler.client.report
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Compute_service record
updated for ('nova01', 'os483401.localnet')
2014-11-26 11:09:53.204 5436 INFO nova.scheduler.client.report
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Compute_service record
updated for ('nova01', 'os483401.localnet')
2014-11-26 11:09:53.207 5436 DEBUG nova.compute.manager [-] [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac] Allocating IP information in the
background. _allocate_network_async
/usr/lib/python2.7/site-packages/nova/compute/manager.py:1627
2014-11-26 11:09:53.208 5436 DEBUG nova.network.neutronv2.api [-]
[instance: 5ac622df-fcbf-4e41-bac9-001ca00d43ac] allocate_for_instance()
allocate_for_instance
/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:279
2014-11-26 11:09:53.208 5436 DEBUG neutronclient.client [-]
REQ: curl -i
http://neutron-controller:9696/v2.0/networks.json?id=1206629d-045d-4c3a-b83f-f0bf5dbb0add
-X GET -H "X-Auth-Token: c63d5bcad5924a7ea8a9eaf2ff0c8156" -H
"User-Agent: python-neutronclient"
 http_log_req
/usr/lib/python2.7/site-packages/neutronclient/common/utils.py:140
2014-11-26 11:09:53.240 5436 DEBUG neutronclient.client [-] RESP:200
{'date': 'Wed, 26 Nov 2014 10:09:56 GMT', 'content-length': '271',
'content-type': 'application/json; charset=UTF-8',
'x-openstack-request-id': 'req-bdea570d-d713-434e-9e93-129cb98d8c32'}
{"networks": [{"status": "ACTIVE", "subnets":
["cc4d4225-bf18-4e02-a752-e4dbf381f250"], "name": "demo-net",
"router:external": false, "tenant_id":
"5d3a5bbf404c4db28067929f40ba170e", "admin_state_up": true, "shared":
false, "id": "1206629d-045d-4c3a-b83f-f0bf5dbb0add"}]}
 http_log_resp
/usr/lib/python2.7/site-packages/neutronclient/common/utils.py:149
2014-11-26 11:09:53.240 5436 DEBUG neutronclient.client [-]
REQ: curl -i
http://neutron-controller:9696/v2.0/security-groups.json?tenant_id=5d3a5bbf404c4db28067929f40ba170e
-X GET -H "X-Auth-Token: c63d5bcad5924a7ea8a9eaf2ff0c8156" -H
"User-Agent: python-neutronclient"
 http_log_req
/usr/lib/python2.7/site-packages/neutronclient/common/utils.py:140
2014-11-26 11:09:53.259 5436 DEBUG neutronclient.client [-] RESP:200
{'date': 'Wed, 26 Nov 2014 10:09:56 GMT', 'content-length': '1535',
'content-type': 'application/json; charset=UTF-8',
'x-openstack-request-id': 'req-a1cad97a-7266-4d5c-837e-06a57475f047'}
{"security_groups": [{"tenant_id": "5d3a5bbf404c4db28067929f40ba170e",
"description": "default", "id": "b84f3a98-58b7-4de8-8a78-6e1b56433a8b",
"security_group_rules": [{"remote_group_id": null, "direction":
"egress", "remote_ip_prefix": null, "protocol": null, "ethertype":
"IPv4", "tenant_id": "5d3a5bbf404c4db28067929f40ba170e",
"port_range_max": null, "port_range_min": null, "id":
"08fe4d2c-3475-4efe-baa6-5d3f1200b964", "security_group_id":
"b84f3a98-58b7-4de8-8a78-6e1b56433a8b"}, {"remote_group_id": null,
"direction": "egress", "remote_ip_prefix": null, "protocol": null,
"ethertype": "IPv6", "tenant_id": "5d3a5bbf404c4db28067929f40ba170e",
"port_range_max": null, "port_range_min": null, "id":
"390f124d-d357-4348-897a-c055c7b81375", "security_group_id":
"b84f3a98-58b7-4de8-8a78-6e1b56433a8b"}, {"remote_group_id":
"b84f3a98-58b7-4de8-8a78-6e1b56433a8b", "direction": "ingress",
"remote_ip_prefix": null, "protocol": null, "ethertype": "IPv4",
"tenant_id": "5d3a5bbf404c4db28067929f40ba170e", "port_range_max": null,
"port_range_min": null, "id": "66b6e33e-3972-4e87-9d3c-97623ae74bcb",
"security_group_id": "b84f3a98-58b7-4de8-8a78-6e1b56433a8b"},
{"remote_group_id": "b84f3a98-58b7-4de8-8a78-6e1b56433a8b", "direction":
"ingress", "remote_ip_prefix": null, "protocol": null, "ethertype":
"IPv6", "tenant_id": "5d3a5bbf404c4db28067929f40ba170e",
"port_range_max": null, "port_range_min": null, "id":
"6ad70f09-28b6-4b08-b860-997565b3e4b0", "security_group_id":
"b84f3a98-58b7-4de8-8a78-6e1b56433a8b"}], "name": "default"}]}
 http_log_resp
/usr/lib/python2.7/site-packages/neutronclient/common/utils.py:149
2014-11-26 11:09:53.260 5436 DEBUG neutronclient.client [-]
REQ: curl -i http://neutron-controller:9696/v2.0/extensions.json -X GET
-H "X-Auth-Token: c63d5bcad5924a7ea8a9eaf2ff0c8156" -H "User-Agent:
python-neutronclient"
 http_log_req
/usr/lib/python2.7/site-packages/neutronclient/common/utils.py:140
2014-11-26 11:09:53.267 5436 DEBUG neutronclient.client [-] RESP:200
{'date': 'Wed, 26 Nov 2014 10:09:56 GMT', 'content-length': '4111',
'content-type': 'application/json; charset=UTF-8',
'x-openstack-request-id': 'req-f52c371f-7dc5-4fbb-8cba-f68387b19be3'}
{"extensions": [{"updated": "2012-10-05T10:00:00-00:00", "name":
"security-group", "links": [], "namespace":
"http://docs.openstack.org/ext/securitygroups/api/v2.0", "alias":
"security-group", "description": "The security groups extension."},
{"updated": "2013-02-07T10:00:00-00:00", "name": "L3 Agent Scheduler",
"links": [], "namespace":
"http://docs.openstack.org/ext/l3_agent_scheduler/api/v1.0", "alias":
"l3_agent_scheduler", "description": "Schedule routers among l3
agents"}, {"updated": "2013-03-28T10:00:00-00:00", "name": "Neutron L3
Configurable external gateway mode", "links": [], "namespace":
"http://docs.openstack.org/ext/neutron/ext-gw-mode/api/v1.0", "alias":
"ext-gw-mode", "description": "Extension of the router abstraction for
specifying whether SNAT should occur on the external gateway"},
{"updated": "2014-02-03T10:00:00-00:00", "name": "Port Binding",
"links": [], "namespace":
"http://docs.openstack.org/ext/binding/api/v1.0", "alias": "binding",
"description": "Expose port bindings of a virtual port to external
application"}, {"updated": "2012-09-07T10:00:00-00:00", "name":
"Provider Network", "links": [], "namespace":
"http://docs.openstack.org/ext/provider/api/v1.0", "alias": "provider",
"description": "Expose mapping of virtual networks to physical
networks"}, {"updated": "2013-02-03T10:00:00-00:00", "name": "agent",
"links": [], "namespace":
"http://docs.openstack.org/ext/agent/api/v2.0", "alias": "agent",
"description": "The agent management extension."}, {"updated":
"2012-07-29T10:00:00-00:00", "name": "Quota management support",
"links": [], "namespace":
"http://docs.openstack.org/network/ext/quotas-sets/api/v2.0", "alias":
"quotas", "description": "Expose functions for quotas management per
tenant"}, {"updated": "2013-02-07T10:00:00-00:00", "name": "DHCP Agent
Scheduler", "links": [], "namespace":
"http://docs.openstack.org/ext/dhcp_agent_scheduler/api/v1.0", "alias":
"dhcp_agent_scheduler", "description": "Schedule networks among dhcp
agents"}, {"updated": "2014-04-26T00:00:00-00:00", "name": "HA Router
extension", "links": [], "namespace": "", "alias": "l3-ha",
"description": "Add HA capability to routers."}, {"updated":
"2013-06-27T10:00:00-00:00", "name": "Multi Provider Network", "links":
[], "namespace":
"http://docs.openstack.org/ext/multi-provider/api/v1.0", "alias":
"multi-provider", "description": "Expose mapping of virtual networks to
multiple physical networks"}, {"updated": "2013-01-14T10:00:00-00:00",
"name": "Neutron external network", "links": [], "namespace":
"http://docs.openstack.org/ext/neutron/external_net/api/v1.0", "alias":
"external-net", "description": "Adds external network attribute to
network resource."}, {"updated": "2012-07-20T10:00:00-00:00", "name":
"Neutron L3 Router", "links": [], "namespace":
"http://docs.openstack.org/ext/neutron/router/api/v1.0", "alias":
"router", "description": "Router abstraction for basic L3 forwarding
between L2 Neutron networks and access to external networks via a NAT
gateway."}, {"updated": "2013-07-23T10:00:00-00:00", "name": "Allowed
Address Pairs", "links": [], "namespace":
"http://docs.openstack.org/ext/allowedaddresspairs/api/v2.0", "alias":
"allowed-address-pairs", "description": "Provides allowed address
pairs"}, {"updated": "2013-02-01T10:00:00-00:00", "name": "Neutron Extra
Route", "links": [], "namespace":
"http://docs.openstack.org/ext/neutron/extraroutes/api/v1.0", "alias":
"extraroute", "description": "Extra routes configuration for L3
router"}, {"updated": "2013-03-17T12:00:00-00:00", "name": "Neutron
Extra DHCP opts", "links": [], "namespace":
"http://docs.openstack.org/ext/neutron/extra_dhcp_opt/api/v1.0",
"alias": "extra_dhcp_opt", "description": "Extra options configuration
for DHCP. For example PXE boot options to DHCP clients can be specified
(e.g. tftp-server, server-ip-address, bootfile-name)"}, {"updated":
"2014-06-1T10:00:00-00:00", "name": "Distributed Virtual Router",
"links": [], "namespace": "http://docs.openstack.org/ext/dvr/api/v1.0",
"alias": "dvr", "description": "Enables configuration of Distributed
Virtual Routers."}]}
 http_log_resp
/usr/lib/python2.7/site-packages/neutronclient/common/utils.py:149
2014-11-26 11:09:53.272 5436 DEBUG neutronclient.client [-]
REQ: curl -i http://neutron-controller:9696/v2.0/ports.json -X POST -H
"X-Auth-Token: eac96c62e33d439bb2f4af52fe0e963c" -H "User-Agent:
python-neutronclient" -d '{"port": {"binding:host_id": "nova01",
"admin_state_up": true, "network_id":
"1206629d-045d-4c3a-b83f-f0bf5dbb0add", "tenant_id":
"5d3a5bbf404c4db28067929f40ba170e", "device_owner": "compute:nova",
"security_groups": ["b84f3a98-58b7-4de8-8a78-6e1b56433a8b"],
"device_id": "5ac622df-fcbf-4e41-bac9-001ca00d43ac"}}'
 http_log_req
/usr/lib/python2.7/site-packages/neutronclient/common/utils.py:140
2014-11-26 11:09:53.300 5436 DEBUG nova.block_device
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] block_device_list []
volume_in_mapping /usr/lib/python2.7/site-packages/nova/block_device.py:555
2014-11-26 11:09:53.440 5436 DEBUG nova.block_device
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] block_device_list []
volume_in_mapping /usr/lib/python2.7/site-packages/nova/block_device.py:555
2014-11-26 11:09:53.441 5436 INFO nova.virt.libvirt.driver
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac] Creating image
2014-11-26 11:09:53.444 5436 DEBUG nova.openstack.common.processutils
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Running cmd
(subprocess): env LC_ALL=C LANG=C qemu-img info
/var/lib/nova/instances/_base/3d07303977c640ff3d0e46b4566187db9ca7389b
execute
/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py:161
2014-11-26 11:09:53.472 5436 DEBUG nova.openstack.common.processutils
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Result was 0 execute
/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py:195
2014-11-26 11:09:53.475 5436 DEBUG nova.openstack.common.processutils
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Running cmd
(subprocess): env LC_ALL=C LANG=C qemu-img info
/var/lib/nova/instances/_base/3d07303977c640ff3d0e46b4566187db9ca7389b
execute
/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py:161
2014-11-26 11:09:53.500 5436 DEBUG nova.openstack.common.processutils
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Result was 0 execute
/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py:195
2014-11-26 11:09:53.501 5436 DEBUG nova.openstack.common.processutils
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Running cmd
(subprocess): qemu-img create -f qcow2 -o
backing_file=/var/lib/nova/instances/_base/3d07303977c640ff3d0e46b4566187db9ca7389b
/var/lib/nova/instances/5ac622df-fcbf-4e41-bac9-001ca00d43ac/disk
execute
/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py:161
2014-11-26 11:09:53.524 5436 DEBUG neutronclient.client [-] RESP:201
{'date': 'Wed, 26 Nov 2014 10:09:56 GMT', 'content-length': '697',
'content-type': 'application/json; charset=UTF-8',
'x-openstack-request-id': 'req-c40eb39a-ea68-4e0f-a901-bf267befd050'}
{"port": {"status": "DOWN", "binding:host_id": "nova01",
"allowed_address_pairs": [], "extra_dhcp_opts": [], "device_owner":
"compute:nova", "binding:profile": {}, "fixed_ips": [{"subnet_id":
"cc4d4225-bf18-4e02-a752-e4dbf381f250", "ip_address":
"192.168.200.12"}], "id": "3cfcfa07-ab38-4ff3-8615-974334e6944e",
"security_groups": ["b84f3a98-58b7-4de8-8a78-6e1b56433a8b"],
"device_id": "5ac622df-fcbf-4e41-bac9-001ca00d43ac", "name": "",
"admin_state_up": true, "network_id":
"1206629d-045d-4c3a-b83f-f0bf5dbb0add", "tenant_id":
"5d3a5bbf404c4db28067929f40ba170e", "binding:vif_details": {},
"binding:vnic_type": "normal", "binding:vif_type": "binding_failed",
"mac_address": "fa:16:3e:41:de:fa"}}
 http_log_resp
/usr/lib/python2.7/site-packages/neutronclient/common/utils.py:149
2014-11-26 11:09:53.528 5436 DEBUG nova.network.neutronv2.api [-]
[instance: 5ac622df-fcbf-4e41-bac9-001ca00d43ac] Successfully created
port: 3cfcfa07-ab38-4ff3-8615-974334e6944e _create_port
/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:216
2014-11-26 11:09:53.528 5436 DEBUG nova.network.neutronv2.api [-]
[instance: 5ac622df-fcbf-4e41-bac9-001ca00d43ac] get_instance_nw_info()
_get_instance_nw_info
/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py:610
2014-11-26 11:09:53.531 5436 DEBUG neutronclient.client [-]
REQ: curl -i
http://neutron-controller:9696/v2.0/ports.json?tenant_id=5d3a5bbf404c4db28067929f40ba170e&device_id=5ac622df-fcbf-4e41-bac9-001ca00d43ac
-X GET -H "X-Auth-Token: eac96c62e33d439bb2f4af52fe0e963c" -H
"User-Agent: python-neutronclient"
 http_log_req
/usr/lib/python2.7/site-packages/neutronclient/common/utils.py:140
2014-11-26 11:09:53.534 5436 DEBUG nova.openstack.common.processutils
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Result was 0 execute
/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py:195
2014-11-26 11:09:53.535 5436 DEBUG nova.virt.disk.api
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Checking if we can
resize image
/var/lib/nova/instances/5ac622df-fcbf-4e41-bac9-001ca00d43ac/disk.
size=1073741824 can_resize_image
/usr/lib/python2.7/site-packages/nova/virt/disk/api.py:192
2014-11-26 11:09:53.535 5436 DEBUG nova.openstack.common.processutils
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Running cmd
(subprocess): env LC_ALL=C LANG=C qemu-img info
/var/lib/nova/instances/5ac622df-fcbf-4e41-bac9-001ca00d43ac/disk
execute
/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py:161
2014-11-26 11:09:53.561 5436 DEBUG neutronclient.client [-] RESP:200
{'date': 'Wed, 26 Nov 2014 10:09:56 GMT', 'content-length': '700',
'content-type': 'application/json; charset=UTF-8',
'x-openstack-request-id': 'req-9db7630a-7434-43e6-989c-d617e2e339c7'}
{"ports": [{"status": "DOWN", "binding:host_id": "nova01",
"allowed_address_pairs": [], "extra_dhcp_opts": [], "device_owner":
"compute:nova", "binding:profile": {}, "fixed_ips": [{"subnet_id":
"cc4d4225-bf18-4e02-a752-e4dbf381f250", "ip_address":
"192.168.200.12"}], "id": "3cfcfa07-ab38-4ff3-8615-974334e6944e",
"security_groups": ["b84f3a98-58b7-4de8-8a78-6e1b56433a8b"],
"device_id": "5ac622df-fcbf-4e41-bac9-001ca00d43ac", "name": "",
"admin_state_up": true, "network_id":
"1206629d-045d-4c3a-b83f-f0bf5dbb0add", "tenant_id":
"5d3a5bbf404c4db28067929f40ba170e", "binding:vif_details": {},
"binding:vnic_type": "normal", "binding:vif_type": "binding_failed",
"mac_address": "fa:16:3e:41:de:fa"}]}
 http_log_resp
/usr/lib/python2.7/site-packages/neutronclient/common/utils.py:149
2014-11-26 11:09:53.568 5436 DEBUG neutronclient.client [-]
REQ: curl -i
http://neutron-controller:9696/v2.0/floatingips.json?fixed_ip_address=192.168.200.12&port_id=3cfcfa07-ab38-4ff3-8615-974334e6944e
-X GET -H "X-Auth-Token: eac96c62e33d439bb2f4af52fe0e963c" -H
"User-Agent: python-neutronclient"
 http_log_req
/usr/lib/python2.7/site-packages/neutronclient/common/utils.py:140
2014-11-26 11:09:53.571 5436 DEBUG nova.openstack.common.processutils
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Result was 0 execute
/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py:195
2014-11-26 11:09:53.572 5436 DEBUG nova.openstack.common.processutils
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Running cmd
(subprocess): qemu-img resize
/var/lib/nova/instances/5ac622df-fcbf-4e41-bac9-001ca00d43ac/disk
1073741824 execute
/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py:161
2014-11-26 11:09:53.596 5436 DEBUG neutronclient.client [-] RESP:200
{'date': 'Wed, 26 Nov 2014 10:09:56 GMT', 'content-length': '19',
'content-type': 'application/json; charset=UTF-8',
'x-openstack-request-id': 'req-a80708cf-2528-44fa-b4f0-48d362109cbe'}
{"floatingips": []}
 http_log_resp
/usr/lib/python2.7/site-packages/neutronclient/common/utils.py:149
2014-11-26 11:09:53.602 5436 DEBUG neutronclient.client [-]
REQ: curl -i
http://neutron-controller:9696/v2.0/subnets.json?id=cc4d4225-bf18-4e02-a752-e4dbf381f250
-X GET -H "X-Auth-Token: c63d5bcad5924a7ea8a9eaf2ff0c8156" -H
"User-Agent: python-neutronclient"
 http_log_req
/usr/lib/python2.7/site-packages/neutronclient/common/utils.py:140
2014-11-26 11:09:53.606 5436 DEBUG nova.openstack.common.processutils
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Result was 0 execute
/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py:195
2014-11-26 11:09:53.607 5436 DEBUG nova.virt.disk.api
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Checking if we can
resize filesystem inside
/var/lib/nova/instances/5ac622df-fcbf-4e41-bac9-001ca00d43ac/disk.
CoW=True is_image_partitionless
/usr/lib/python2.7/site-packages/nova/virt/disk/api.py:206
2014-11-26 11:09:53.607 5436 DEBUG nova.virt.disk.vfs.api
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Instance for image
imgfile=/var/lib/nova/instances/5ac622df-fcbf-4e41-bac9-001ca00d43ac/disk imgfmt=qcow2
partition=None instance_for_image
/usr/lib/python2.7/site-packages/nova/virt/disk/vfs/api.py:45
2014-11-26 11:09:53.607 5436 DEBUG nova.virt.disk.vfs.api
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Using primary VFSGuestFS
instance_for_image
/usr/lib/python2.7/site-packages/nova/virt/disk/vfs/api.py:49
2014-11-26 11:09:53.607 5436 DEBUG nova.virt.disk.vfs.guestfs
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Setting up appliance for
/var/lib/nova/instances/5ac622df-fcbf-4e41-bac9-001ca00d43ac/disk qcow2
setup /usr/lib/python2.7/site-packages/nova/virt/disk/vfs/guestfs.py:137
2014-11-26 11:09:53.608 5436 WARNING nova.virt.disk.vfs.guestfs
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Unable to force TCG
mode, libguestfs too old? 'GuestFS' object has no attribute
'set_backend_settings'
2014-11-26 11:09:53.623 5436 DEBUG neutronclient.client [-] RESP:200
{'date': 'Wed, 26 Nov 2014 10:09:56 GMT', 'content-length': '453',
'content-type': 'application/json; charset=UTF-8',
'x-openstack-request-id': 'req-c3ccd45f-3029-4af5-9952-6000667e78c3'}
{"subnets": [{"name": "demo-subnet", "enable_dhcp": true, "network_id":
"1206629d-045d-4c3a-b83f-f0bf5dbb0add", "tenant_id":
"5d3a5bbf404c4db28067929f40ba170e", "dns_nameservers": [], "gateway_ip":
"192.168.200.254", "ipv6_ra_mode": null, "allocation_pools": [{"start":
"192.168.200.1", "end": "192.168.200.253"}], "host_routes": [],
"ip_version": 4, "ipv6_address_mode": null, "cidr": "192.168.200.0/24",
"id": "cc4d4225-bf18-4e02-a752-e4dbf381f250"}]}
 http_log_resp
/usr/lib/python2.7/site-packages/neutronclient/common/utils.py:149
2014-11-26 11:09:53.624 5436 DEBUG neutronclient.client [-]
REQ: curl -i
http://neutron-controller:9696/v2.0/ports.json?network_id=1206629d-045d-4c3a-b83f-f0bf5dbb0add&device_owner=network%3Adhcp
-X GET -H "X-Auth-Token: c63d5bcad5924a7ea8a9eaf2ff0c8156" -H
"User-Agent: python-neutronclient"
 http_log_req
/usr/lib/python2.7/site-packages/neutronclient/common/utils.py:140
2014-11-26 11:09:53.654 5436 DEBUG neutronclient.client [-] RESP:200
{'date': 'Wed, 26 Nov 2014 10:09:56 GMT', 'content-length': '585',
'content-type': 'application/json; charset=UTF-8',
'x-openstack-request-id': 'req-1fb5195c-4c2f-421a-912b-77ff4c441e3b'}
{"ports": [{"status": "DOWN", "name": "", "allowed_address_pairs": [],
"admin_state_up": true, "network_id":
"1206629d-045d-4c3a-b83f-f0bf5dbb0add", "tenant_id":
"5d3a5bbf404c4db28067929f40ba170e", "extra_dhcp_opts": [],
"binding:vnic_type": "normal", "device_owner": "network:dhcp",
"mac_address": "fa:16:3e:09:a0:e0", "fixed_ips": [{"subnet_id":
"cc4d4225-bf18-4e02-a752-e4dbf381f250", "ip_address": "192.168.200.7"}],
"id": "9a654803-c082-4e3f-ba17-05572a51601e", "security_groups": [],
"device_id":
"dhcpab855245-c8d0-5774-a10d-facfbf4f3939-1206629d-045d-4c3a-b83f-f0bf5dbb0add"}]}
 http_log_resp
/usr/lib/python2.7/site-packages/neutronclient/common/utils.py:149
2014-11-26 11:09:53.655 5436 DEBUG nova.network.base_api [-] Updating
cache with info: [VIF({'profile': {}, 'ovs_interfaceid': None,
'network': Network({'bridge': None, 'subnets': [Subnet({'ips':
[FixedIP({'meta': {}, 'version': 4, 'type': 'fixed', 'floating_ips': [],
'address': u'192.168.200.12'})], 'version': 4, 'meta': {'dhcp_server':
u'192.168.200.7'}, 'dns': [], 'routes': [], 'cidr': u'192.168.200.0/24',
'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address':
u'192.168.200.254'})})], 'meta': {'injected': False, 'tenant_id':
u'5d3a5bbf404c4db28067929f40ba170e'}, 'id':
u'1206629d-045d-4c3a-b83f-f0bf5dbb0add', 'label': u'demo-net'}),
'devname': u'tap3cfcfa07-ab', 'vnic_type': u'normal', 'qbh_params':
None, 'meta': {}, 'details': {}, 'address': u'fa:16:3e:41:de:fa',
'active': False, 'type': u'binding_failed', 'id':
u'3cfcfa07-ab38-4ff3-8615-974334e6944e', 'qbg_params': None})]
update_instance_cache_with_nw_info
/usr/lib/python2.7/site-packages/nova/network/base_api.py:40
2014-11-26 11:09:53.671 5436 DEBUG nova.compute.manager [-] [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac] Instance network_info:
|[VIF({'profile': {}, 'ovs_interfaceid': None, 'network':
Network({'bridge': None, 'subnets': [Subnet({'ips': [FixedIP({'meta':
{}, 'version': 4, 'type': 'fixed', 'floating_ips': [], 'address':
u'192.168.200.12'})], 'version': 4, 'meta': {'dhcp_server':
u'192.168.200.7'}, 'dns': [], 'routes': [], 'cidr': u'192.168.200.0/24',
'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address':
u'192.168.200.254'})})], 'meta': {'injected': False, 'tenant_id':
u'5d3a5bbf404c4db28067929f40ba170e'}, 'id':
u'1206629d-045d-4c3a-b83f-f0bf5dbb0add', 'label': u'demo-net'}),
'devname': u'tap3cfcfa07-ab', 'vnic_type': u'normal', 'qbh_params':
None, 'meta': {}, 'details': {}, 'address': u'fa:16:3e:41:de:fa',
'active': False, 'type': u'binding_failed', 'id':
u'3cfcfa07-ab38-4ff3-8615-974334e6944e', 'qbg_params': None})]|
_allocate_network_async
/usr/lib/python2.7/site-packages/nova/compute/manager.py:1644
2014-11-26 11:09:53.798 5436 INFO nova.scheduler.client.report [-]
Compute_service record updated for ('nova01', 'os483401.localnet')
2014-11-26 11:09:58.215 5436 DEBUG nova.virt.disk.vfs.guestfs
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Mount guest OS image
/var/lib/nova/instances/5ac622df-fcbf-4e41-bac9-001ca00d43ac/disk
partition None setup_os_static
/usr/lib/python2.7/site-packages/nova/virt/disk/vfs/guestfs.py:83
2014-11-26 11:09:58.260 5436 DEBUG nova.virt.disk.vfs.guestfs
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Tearing down appliance
teardown /usr/lib/python2.7/site-packages/nova/virt/disk/vfs/guestfs.py:185
2014-11-26 11:09:58.262 5436 WARNING nova.virt.disk.vfs.guestfs
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Failed to close augeas
aug_close: do_aug_close: you must call 'aug-init' first to initialize Augeas
2014-11-26 11:09:58.317 5436 DEBUG nova.virt.disk.api
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Unable to mount image
/var/lib/nova/instances/5ac622df-fcbf-4e41-bac9-001ca00d43ac/disk with
error Error mounting
/var/lib/nova/instances/5ac622df-fcbf-4e41-bac9-001ca00d43ac/disk with
libguestfs (mount_options: /dev/sda on / (options: ''): mount: /dev/sda
is write-protected, mounting read-only
mount: unknown filesystem type '(null)'). Cannot resize.
is_image_partitionless
/usr/lib/python2.7/site-packages/nova/virt/disk/api.py:218
2014-11-26 11:09:58.319 5436 DEBUG nova.virt.libvirt.driver
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac] Start _get_guest_xml
network_info=[VIF({'profile': {}, 'ovs_interfaceid': None, 'network':
Network({'bridge': None, 'subnets': [Subnet({'ips': [FixedIP({'meta':
{}, 'version': 4, 'type': 'fixed', 'floating_ips': [], 'address':
u'192.168.200.12'})], 'version': 4, 'meta': {'dhcp_server':
u'192.168.200.7'}, 'dns': [], 'routes': [], 'cidr': u'192.168.200.0/24',
'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address':
u'192.168.200.254'})})], 'meta': {'injected': False, 'tenant_id':
u'5d3a5bbf404c4db28067929f40ba170e'}, 'id':
u'1206629d-045d-4c3a-b83f-f0bf5dbb0add', 'label': u'demo-net'}),
'devname': u'tap3cfcfa07-ab', 'vnic_type': u'normal', 'qbh_params':
None, 'meta': {}, 'details': {}, 'address': u'fa:16:3e:41:de:fa',
'active': False, 'type': u'binding_failed', 'id':
u'3cfcfa07-ab38-4ff3-8615-974334e6944e', 'qbg_params': None})]
disk_info={'disk_bus': 'virtio', 'cdrom_bus': 'ide', 'mapping': {'disk':
{'bus': 'virtio', 'boot_index': '1', 'type': 'disk', 'dev': u'vda'},
'root': {'bus': 'virtio', 'boot_index': '1', 'type': 'disk', 'dev':
u'vda'}}} image_meta={u'status': u'active', u'deleted': False,
u'container_format': u'bare', u'min_ram': 0, u'updated_at':
u'2014-11-18T10:30:54.000000', u'min_disk': 0, u'owner':
u'eded32b718c9481f9e8d4f19185b766c', u'is_public': True, u'deleted_at':
None, u'properties': {}, u'size': 13200896, u'name':
u'cirros-0.3.3-x86_64', u'checksum':
u'133eae9fb1c98f45894a4e60d8736619', u'created_at':
u'2014-11-18T10:30:53.000000', u'disk_format': u'qcow2', u'id':
u'2d7d75c2-17b7-4483-9182-f82295b97088'} rescue=None
block_device_info={'block_device_mapping': [], 'root_device_name':
u'/dev/vda', 'ephemerals': [], 'swap': None} _get_guest_xml
/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:4147
2014-11-26 11:09:58.351 5436 DEBUG nova.virt.libvirt.driver
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] CPU mode 'host-model'
model '' was chosen _get_guest_cpu_model_config
/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:3361
2014-11-26 11:09:58.351 5436 DEBUG nova.virt.hardware
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Getting desirable
topologies for flavor
Flavor(created_at=None,deleted=False,deleted_at=None,disabled=False,ephemeral_gb=0,extra_specs={},flavorid='1',id=2,is_public=True,memory_mb=512,name='m1.tiny',projects=<?>,root_gb=1,rxtx_factor=1.0,swap=0,updated_at=None,vcpu_weight=0,vcpus=1)
and image_meta {u'status': u'active', u'deleted': False,
u'container_format': u'bare', u'min_ram': 0, u'updated_at':
u'2014-11-18T10:30:54.000000', u'min_disk': 0, u'owner':
u'eded32b718c9481f9e8d4f19185b766c', u'is_public': True, u'deleted_at':
None, u'properties': {}, u'size': 13200896, u'name':
u'cirros-0.3.3-x86_64', u'checksum':
u'133eae9fb1c98f45894a4e60d8736619', u'created_at':
u'2014-11-18T10:30:53.000000', u'disk_format': u'qcow2', u'id':
u'2d7d75c2-17b7-4483-9182-f82295b97088'} get_desirable_configs
/usr/lib/python2.7/site-packages/nova/virt/hardware.py:501
2014-11-26 11:09:58.352 5436 DEBUG nova.virt.hardware
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Flavor limits
65536:65536:65536 get_topology_constraints
/usr/lib/python2.7/site-packages/nova/virt/hardware.py:295
2014-11-26 11:09:58.352 5436 DEBUG nova.virt.hardware
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Image limits
65536:65536:65536 get_topology_constraints
/usr/lib/python2.7/site-packages/nova/virt/hardware.py:308
2014-11-26 11:09:58.353 5436 DEBUG nova.virt.hardware
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Flavor pref -1:-1:-1
get_topology_constraints
/usr/lib/python2.7/site-packages/nova/virt/hardware.py:331
2014-11-26 11:09:58.353 5436 DEBUG nova.virt.hardware
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Image pref -1:-1:-1
get_topology_constraints
/usr/lib/python2.7/site-packages/nova/virt/hardware.py:353
2014-11-26 11:09:58.353 5436 DEBUG nova.virt.hardware
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Chosen -1:-1:-1 limits
65536:65536:65536 get_topology_constraints
/usr/lib/python2.7/site-packages/nova/virt/hardware.py:382
2014-11-26 11:09:58.353 5436 DEBUG nova.virt.hardware
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Build topologies for 1
vcpu(s) 1:1:1 get_possible_topologies
/usr/lib/python2.7/site-packages/nova/virt/hardware.py:418
2014-11-26 11:09:58.354 5436 DEBUG nova.virt.hardware
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] Got 1 possible
topologies get_possible_topologies
/usr/lib/python2.7/site-packages/nova/virt/hardware.py:441
2014-11-26 11:09:58.357 5436 DEBUG nova.virt.libvirt.vif
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] vif_type=binding_failed
instance=Instance(access_ip_v4=None,access_ip_v6=None,architecture=None,auto_disk_config=True,availability_zone='nova',cell_name=None,cleaned=False,config_drive='',created_at=2014-11-26T10:09:55Z,default_ephemeral_device=None,default_swap_device=None,deleted=False,deleted_at=None,disable_terminate=False,display_description='cirros-test-1',display_name='cirros-test-1',ephemeral_gb=0,ephemeral_key_uuid=None,fault=<?>,host='nova01',hostname='cirros-test-1',id=10,image_ref='2d7d75c2-17b7-4483-9182-f82295b97088',info_cache=InstanceInfoCache,instance_type_id=2,kernel_id='',key_data=None,key_name=None,launch_index=0,launched_at=None,launched_on='nova01',locked=False,locked_by=None,memory_mb=512,metadata={},node='os483401.localnet',numa_topology=None,os_type=None,pci_devices=<?>,power_state=0,progress=0,project_id='5d3a5bbf404c4db28067929f40ba170e',ramdisk_id='',reservation_id='r-yngmwn2d',root_device_name='/dev/vda',root_gb=1,scheduled_at=None,security_groups=SecurityGroupList,shutdown_termi
nate=False,system_metadata={image_base_image_ref='2d7d75c2-17b7-4483-9182-f82295b97088',image_container_format='bare',image_disk_format='qcow2',image_min_disk='1',image_min_ram='0',instance_type_ephemeral_gb='0',instance_type_flavorid='1',instance_type_id='2',instance_type_memory_mb='512',instance_type_name='m1.tiny',instance_type_root_gb='1',instance_type_rxtx_factor='1.0',instance_type_swap='0',instance_type_vcpu_weight=None,instance_type_vcpus='1',network_allocated='True'},task_state='spawning',terminated_at=None,updated_at=2014-11-26T10:09:56Z,user_data=None,user_id='0c6d9637e6d24fc78ee3bce2ceedcfe7',uuid=5ac622df-fcbf-4e41-bac9-001ca00d43ac,vcpus=1,vm_mode=None,vm_state='building')
vif=VIF({'profile': {}, 'ovs_interfaceid': None, 'network':
Network({'bridge': None, 'subnets': [Subnet({'ips': [FixedIP({'meta':
{}, 'version': 4, 'type': 'fixed', 'floating_ips': [], 'address':
u'192.168.200.12'})], 'version': 4, 'meta': {'dhcp_server':
u'192.168.200.7'}, 'dns': [], 'routes': [], 'cidr': u'192.168.200.0/24',
'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address':
u'192.168.200.254'})})], 'meta': {'injected': False, 'tenant_id':
u'5d3a5bbf404c4db28067929f40ba170e'}, 'id':
u'1206629d-045d-4c3a-b83f-f0bf5dbb0add', 'label': u'demo-net'}),
'devname': u'tap3cfcfa07-ab', 'vnic_type': u'normal', 'qbh_params':
None, 'meta': {}, 'details': {}, 'address': u'fa:16:3e:41:de:fa',
'active': False, 'type': u'binding_failed', 'id':
u'3cfcfa07-ab38-4ff3-8615-974334e6944e', 'qbg_params': None})
virt_typeqemu get_config
/usr/lib/python2.7/site-packages/nova/virt/libvirt/vif.py:342
2014-11-26 11:09:58.359 5436 ERROR nova.compute.manager
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac] Instance failed to spawn
2014-11-26 11:09:58.359 5436 TRACE nova.compute.manager [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac] Traceback (most recent call last):
2014-11-26 11:09:58.359 5436 TRACE nova.compute.manager [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac]   File
"/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2231,
in _build_resources
2014-11-26 11:09:58.359 5436 TRACE nova.compute.manager [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac]     yield resources
2014-11-26 11:09:58.359 5436 TRACE nova.compute.manager [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac]   File
"/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2101,
in _build_and_run_instance
2014-11-26 11:09:58.359 5436 TRACE nova.compute.manager [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac]
block_device_info=block_device_info)
2014-11-26 11:09:58.359 5436 TRACE nova.compute.manager [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac]   File
"/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line
2619, in spawn
2014-11-26 11:09:58.359 5436 TRACE nova.compute.manager [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac]     write_to_disk=True)
2014-11-26 11:09:58.359 5436 TRACE nova.compute.manager [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac]   File
"/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line
4150, in _get_guest_xml
2014-11-26 11:09:58.359 5436 TRACE nova.compute.manager [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac]     context)
2014-11-26 11:09:58.359 5436 TRACE nova.compute.manager [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac]   File
"/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line
3936, in _get_guest_config
2014-11-26 11:09:58.359 5436 TRACE nova.compute.manager [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac]     flavor, CONF.libvirt.virt_type)
2014-11-26 11:09:58.359 5436 TRACE nova.compute.manager [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac]   File
"/usr/lib/python2.7/site-packages/nova/virt/libvirt/vif.py", line 352,
in get_config
2014-11-26 11:09:58.359 5436 TRACE nova.compute.manager [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac]     _("Unexpected vif_type=%s") %
vif_type)
2014-11-26 11:09:58.359 5436 TRACE nova.compute.manager [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac] NovaException: Unexpected
vif_type=binding_failed
2014-11-26 11:09:58.359 5436 TRACE nova.compute.manager [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac]
2014-11-26 11:09:58.360 5436 AUDIT nova.compute.manager
[req-ab961686-99ab-4112-8755-a9f2326b9a5b None] [instance:
5ac622df-fcbf-4e41-bac9-001ca00d43ac] Terminating instance
2014-11-26 11:09:58.365 5436 WARNING nova.virt.libvirt.driver [-]
[instance: 5ac622df-fcbf-4e41-bac9-001ca00d43ac] During wait destroy,
instance disappeared.



Any ideas what's wrong or where I have to investigate further? What more
info do you need to help?

Thanks in advance,

	Uwe