Skip to content

Instantly share code, notes, and snippets.

@jimrollenhagen

jimrollenhagen/compute.manager.py.diff Secret

Last active August 29, 2015 14:19
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save jimrollenhagen/c6b4926d605d9b4e8da9 to your computer and use it in GitHub Desktop.
Save jimrollenhagen/c6b4926d605d9b4e8da9 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
compute.manager.py.diff
diff --git a/nova/compute/manager.py b/nova/compute/manager.py
index e694b53..d6d3bfa 100644
--- a/nova/compute/manager.py
+++ b/nova/compute/manager.py
@@ -2186,6 +2186,7 @@ class ComputeManager(manager.Manager):
retry['exc'] = traceback.format_exception(*sys.exc_info())
# NOTE(comstud): Deallocate networks if the driver wants
# us to do so.
+ LOG.debug('rm12321 pre deallocated network_allocated: {}'.format(instance.system_metadata.get('network_allocated')), instance=instance)
if self.driver.deallocate_networks_on_reschedule(instance):
self._cleanup_allocated_networks(context, instance,
requested_networks)
@@ -2198,7 +2199,10 @@ class ComputeManager(manager.Manager):
context, instance, self.host)
instance.task_state = task_states.SCHEDULING
+ LOG.debug('rm12321 post deallocated network_allocated: {}'.format(instance.system_metadata.get('network_allocated')), instance=instance)
+ LOG.debug('rm12321 post deallocated what changed: {}'.format(instance.obj_what_changed()), instance=instance)
instance.save()
+ LOG.debug('rm12321 post save deallocated network_allocated: {}'.format(instance.system_metadata.get('network_allocated')), instance=instance)
self.compute_task_api.build_instances(context, [instance],
image, filter_properties, admin_password,
@@ -2448,9 +2452,10 @@ class ComputeManager(manager.Manager):
LOG.exception(msg, instance=instance)
return
- system_metadata = instance.system_metadata
- system_metadata['network_allocated'] = 'False'
- instance.system_metadata = system_metadata
+ instance.system_metadata['network_allocated'] = 'False'
+
+ LOG.debug('rm12321 _cleanup_allocated_networks what changed: {}'.format(instance.obj_what_changed()), instance=instance)
+ LOG.debug('rm12321 _cleanup_allocated_networks sysmeta: {}; old_sysmeta: {}'.format(instance.system_metadata, instance._orig_system_metadata), instance=instance)
try:
instance.save()
Raw
nova-compute.log
jim@syslog:/logs/preprod-ord$ grep 9daa9c77-d801-4138-87b7-184c40cac6e5 nova_compute.log
Apr 23 23:53:09 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:09.119 9094 DEBUG oslo_concurrency.lockutils [-] Lock "9daa9c77-d801-4138-87b7-184c40cac6e5" acquired by "_locked_do_build_and_run_instance" :: waited 0.000s inner /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:444
Apr 23 23:53:09 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:09.138 9094 INFO nova.compute.manager [req-59c335d9-a84c-49c5-933b-d3b5b6b65cd0 a73e7267b25141fbb82975956598aebf 5956437 - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Starting instance...
Apr 23 23:53:10 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:09.227 9094 INFO nova.objects.instance [-] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x7a59c50> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x7ea3e10>
Apr 23 23:53:10 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:09.323 9094 INFO nova.compute.claims [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Attempting claim: memory 32768 MB, disk 32 GB
Apr 23 23:53:10 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:09.324 9094 INFO nova.compute.claims [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Total memory: 32768 MB, used: 0.00 MB
Apr 23 23:53:10 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:09.324 9094 INFO nova.compute.claims [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] memory limit not specified, defaulting to unlimited
Apr 23 23:53:10 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:09.325 9094 INFO nova.compute.claims [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Total disk: 32 GB, used: 0.00 GB
Apr 23 23:53:10 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:09.325 9094 INFO nova.compute.claims [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] disk limit not specified, defaulting to unlimited
Apr 23 23:53:10 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:09.333 9094 INFO nova.compute.claims [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Claim successful
Apr 23 23:53:10 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:09.417 9094 DEBUG nova.objects.instance [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] Lazy-loading `flavor' on Instance uuid 9daa9c77-d801-4138-87b7-184c40cac6e5 obj_load_attr /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/objects/instance.py:994
Apr 23 23:53:10 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:09.469 9094 DEBUG nova.objects.instance [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] Lazy-loading `metadata' on Instance uuid 9daa9c77-d801-4138-87b7-184c40cac6e5 obj_load_attr /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/objects/instance.py:994
Apr 23 23:53:10 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:09.516 9094 DEBUG nova.objects.instance [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] Lazy-loading `info_cache' on Instance uuid 9daa9c77-d801-4138-87b7-184c40cac6e5 obj_load_attr /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/objects/instance.py:994
Apr 23 23:53:10 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:09.825 9094 INFO nova.objects.instance [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x9c3efd0> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x995d1d0>
Apr 23 23:53:10 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:09.892 9094 DEBUG nova.compute.manager [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Allocating IP information in the background. _allocate_network_async /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:1761
Apr 23 23:53:10 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:09.895 9094 DEBUG nova.network.neutronv2.api [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] allocate_for_instance() allocate_for_instance /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/network/neutronv2/api.py:405
Apr 23 23:53:10 ironic-compute01.m0002.preprod-ord.ohthree.com REQ: curl -i http://neutron-api-vip.m0002.preprod-ord.ohthree.com:9696/v2.0/ports.json -X POST -H "User-Agent: python-neutronclient" -H "X-Roles: identity:user-admin,object-store:default,compute:default" -H "X-Auth-Token: 7bc82c922b1d48a6af22c011e1bda4c0" -d '{"port": {"binding:host_id": "ironic-compute", "admin_state_up": true, "network_id": "00000000-0000-0000-0000-000000000000", "tenant_id": "5956437", "device_owner": "compute:None", "mac_address": "a0:36:9f:2c:ec:98", "device_id": "9daa9c77-d801-4138-87b7-184c40cac6e5"}}'
Apr 23 23:53:10 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.023 9094 INFO nova.objects.instance [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x97e5090> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x80ac510>
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.319 9094 DEBUG neutronclient.client [-] RESP:201 {'date': 'Thu, 23 Apr 2015 23:53:10 GMT', 'content-length': '760', 'content-type': 'application/json; charset=UTF-8'} {"port": {"status": "DOWN", "binding:host_id": "ironic-compute", "allowed_address_pairs": [], "extra_dhcp_opts": [], "switch:hardware_id": null, "device_owner": "compute:None", "binding:profile": {}, "trunked": false, "fixed_ips": [{"subnet_id": "3ee44b7b-ac79-4430-a422-0490b4bb4849", "ip_address": "50.57.63.13"}], "id": "b1abb739-b004-4488-83fa-8c5418f88c24", "security_groups": ["c3e2d506-72f5-4269-8cb6-bbbc55d49e35"], "device_id": "9daa9c77-d801-4138-87b7-184c40cac6e5", "name": "", "admin_state_up": true, "network_id": "00000000-0000-0000-0000-000000000000", "tenant_id": "5956437", "binding:vif_details": {}, "binding:vnic_type": "normal", "binding:vif_type": "binding_failed", "switch:ports": [], "mac_address": "a0:36:9f:2c:ec:98", "commit": false}}
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.324 9094 DEBUG nova.network.neutronv2.api [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Successfully created port: b1abb739-b004-4488-83fa-8c5418f88c24 _create_port /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/network/neutronv2/api.py:297
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com REQ: curl -i http://neutron-api-vip.m0002.preprod-ord.ohthree.com:9696/v2.0/ports.json -X POST -H "User-Agent: python-neutronclient" -H "X-Roles: identity:user-admin,object-store:default,compute:default" -H "X-Auth-Token: 7bc82c922b1d48a6af22c011e1bda4c0" -d '{"port": {"binding:host_id": "ironic-compute", "admin_state_up": true, "network_id": "11111111-1111-1111-1111-111111111111", "tenant_id": "5956437", "device_owner": "compute:None", "mac_address": "a0:36:9f:2c:ec:99", "device_id": "9daa9c77-d801-4138-87b7-184c40cac6e5"}}'
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.445 9094 INFO nova.objects.instance [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x7eb8910> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x9380850>
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.513 9094 ERROR nova.virt.ironic.driver [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] PROFESSOR CHAOS MONKEY, MWHAHAHAH
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.514 9094 ERROR nova.compute.manager [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Instance failed to spawn
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.514 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Traceback (most recent call last):
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.514 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] File "/opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py", line 2425, in _build_resources
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.514 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] yield resources
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.514 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] File "/opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py", line 2281, in _build_and_run_instance
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.514 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] block_device_info=block_device_info)
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.514 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] File "/opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py", line 670, in spawn
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.514 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] raise Exception('PROFESSOR CHAOS MONKEY, MWHAHAHAH')
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.514 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Exception: PROFESSOR CHAOS MONKEY, MWHAHAHAH
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.514 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5]
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.595 9094 DEBUG neutronclient.client [-] RESP:201 {'date': 'Thu, 23 Apr 2015 23:53:10 GMT', 'content-length': '763', 'content-type': 'application/json; charset=UTF-8'} {"port": {"status": "DOWN", "binding:host_id": "ironic-compute", "allowed_address_pairs": [], "extra_dhcp_opts": [], "switch:hardware_id": null, "device_owner": "compute:None", "binding:profile": {}, "trunked": false, "fixed_ips": [{"subnet_id": "93013f73-23c3-4f19-8e83-56916cdc24d0", "ip_address": "10.184.255.209"}], "id": "620cdde5-04cd-4a3d-920c-0aedf00f36f0", "security_groups": ["c3e2d506-72f5-4269-8cb6-bbbc55d49e35"], "device_id": "9daa9c77-d801-4138-87b7-184c40cac6e5", "name": "", "admin_state_up": true, "network_id": "11111111-1111-1111-1111-111111111111", "tenant_id": "5956437", "binding:vif_details": {}, "binding:vnic_type": "normal", "binding:vif_type": "binding_failed", "switch:ports": [], "mac_address": "a0:36:9f:2c:ec:99", "commit": false}}
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.601 9094 DEBUG nova.network.neutronv2.api [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Successfully created port: 620cdde5-04cd-4a3d-920c-0aedf00f36f0 _create_port /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/network/neutronv2/api.py:297
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.601 9094 DEBUG oslo_concurrency.lockutils [-] Acquired semaphore "refresh_cache-9daa9c77-d801-4138-87b7-184c40cac6e5" lock /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:391
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.601 9094 DEBUG nova.network.neutronv2.api [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] _get_instance_nw_info() _get_instance_nw_info /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/network/neutronv2/api.py:745
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com REQ: curl -i http://neutron-api-vip.m0002.preprod-ord.ohthree.com:9696/v2.0/ports.json?tenant_id=5956437&device_id=9daa9c77-d801-4138-87b7-184c40cac6e5 -X GET -H "User-Agent: python-neutronclient" -H "X-Roles: identity:user-admin,object-store:default,compute:default" -H "X-Auth-Token: 7bc82c922b1d48a6af22c011e1bda4c0"
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.691 9094 DEBUG neutronclient.client [-] RESP:200 {'date': 'Thu, 23 Apr 2015 23:53:10 GMT', 'content-length': '1518', 'content-type': 'application/json; charset=UTF-8'} {"ports": [{"status": "DOWN", "binding:host_id": "ironic-compute", "allowed_address_pairs": [], "extra_dhcp_opts": [], "switch:hardware_id": null, "device_owner": "compute:None", "binding:profile": {}, "trunked": false, "fixed_ips": [{"subnet_id": "93013f73-23c3-4f19-8e83-56916cdc24d0", "ip_address": "10.184.255.209"}], "id": "620cdde5-04cd-4a3d-920c-0aedf00f36f0", "security_groups": ["c3e2d506-72f5-4269-8cb6-bbbc55d49e35"], "device_id": "9daa9c77-d801-4138-87b7-184c40cac6e5", "name": "", "admin_state_up": true, "network_id": "11111111-1111-1111-1111-111111111111", "tenant_id": "5956437", "binding:vif_details": {}, "binding:vnic_type": "normal", "binding:vif_type": "binding_failed", "switch:ports": [], "mac_address": "a0:36:9f:2c:ec:99", "commit": false}, {"status": "DOWN", "binding:host_id": "ironic-compute", "allowed_address_pairs": [], "extra_dhcp_opts": [], "switch:hardware_id": null, "device_owner": "compute:None", "binding:profile": {}, "trunked": false, "fixed_ips": [{"subnet_id": "3ee44b7b-ac79-4430-a422-0490b4bb4849", "ip_address": "50.57.63.13"}], "id": "b1abb739-b004-4488-83fa-8c5418f88c24", "security_groups": ["c3e2d506-72f5-4269-8cb6-bbbc55d49e35"], "device_id": "9daa9c77-d801-4138-87b7-184c40cac6e5", "name": "", "admin_state_up": true, "network_id": "00000000-0000-0000-0000-000000000000", "tenant_id": "5956437", "binding:vif_details": {}, "binding:vnic_type": "normal", "binding:vif_type": "binding_failed", "switch:ports": [], "mac_address": "a0:36:9f:2c:ec:98", "commit": false}]}
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.696 9094 DEBUG nova.network.neutronv2.api [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Instance cache missing network info. _get_preexisting_port_ids /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1473
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.966 9094 DEBUG oslo_concurrency.lockutils [-] Releasing semaphore "refresh_cache-9daa9c77-d801-4138-87b7-184c40cac6e5" lock /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:404
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:10.966 9094 DEBUG nova.compute.manager [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Instance network_info: |[VIF({'profile': {}, 'ovs_interfaceid': None, 'preserve_on_delete': False, 'network': Network({'bridge': None, 'subnets': [Subnet({'ips': [FixedIP({'meta': {}, 'version': 4, 'type': 'fixed', 'floating_ips': [], 'address': u'50.57.63.13'})], 'version': 4, 'meta': {}, 'dns': [IP({'meta': {}, 'version': 4, 'type': 'dns', 'address': u'173.203.4.8'}), IP({'meta': {}, 'version': 4, 'type': 'dns', 'address': u'173.203.4.9'})], 'routes': [], 'cidr': u'50.57.63.0/25', 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'50.57.63.1'})})], 'meta': {'injected': True, 'tenant_id': u'onmetal', 'vlan_id': 101}, 'id': u'00000000-0000-0000-0000-000000000000', 'label': u'public'}), 'devname': u'tapb1abb739-b0', 'vnic_type': u'normal', 'qbh_params': None, 'meta': {}, 'details': {}, 'address': u'a0:36:9f:2c:ec:98', 'active': False, 'type': u'binding_failed', 'id': u'b1abb739-b004-4488-83fa-8c5418f88c24', 'qbg_params': None}), VIF({'profile': {}, 'ovs_interfaceid': None, 'preserve_on_delete': False, 'network': Network({'bridge': None, 'subnets': [Subnet({'ips': [FixedIP({'meta': {}, 'version': 4, 'type': 'fixed', 'floating_ips': [], 'address': u'10.184.255.209'})], 'version': 4, 'meta': {}, 'dns': [], 'routes': [Route({'interface': None, 'cidr': u'10.176.0.0/12', 'meta': {}, 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'10.184.255.129'})}), Route({'interface': None, 'cidr': u'10.208.0.0/12', 'meta': {}, 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'10.184.255.129'})})], 'cidr': u'10.184.255.128/25', 'gateway': IP({'meta': {}, 'version': None, 'type': 'gateway', 'address': None})})], 'meta': {'injected': True, 'tenant_id': u'onmetal', 'vlan_id': 499}, 'id': u'11111111-1111-1111-1111-111111111111', 'label': u'private'}), 'devname': u'tap620cdde5-04', 'vnic_type': u'normal', 'qbh_params': None, 'meta': {}, 'details': {}, 'address': u'a0:36:9f:2c:ec:99', 'active': False, 'type': u'binding_failed', 'id': u'620cdde5-04cd-4a3d-920c-0aedf00f36f0', 'qbg_params': None})]| _allocate_network_async /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:1779
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:11.040 9094 DEBUG nova.objects.instance [-] Lazy-loading `flavor' on Instance uuid 9daa9c77-d801-4138-87b7-184c40cac6e5 obj_load_attr /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/objects/instance.py:994
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:11.094 9094 DEBUG nova.objects.instance [-] Lazy-loading `metadata' on Instance uuid 9daa9c77-d801-4138-87b7-184c40cac6e5 obj_load_attr /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/objects/instance.py:994
Apr 23 23:53:11 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:11.142 9094 DEBUG nova.objects.instance [req-0f98bc78-bead-4421-bddd-e69f0715c06e - - - - -] Lazy-loading `info_cache' on Instance uuid 9daa9c77-d801-4138-87b7-184c40cac6e5 obj_load_attr /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/objects/instance.py:994
Apr 23 23:53:12 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:11.455 9094 INFO nova.compute.manager [req-59c335d9-a84c-49c5-933b-d3b5b6b65cd0 a73e7267b25141fbb82975956598aebf 5956437 - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Terminating instance
Apr 23 23:53:12 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:11.512 9094 WARNING nova.virt.ironic.driver [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] Destroy called on non-existing instance 9daa9c77-d801-4138-87b7-184c40cac6e5.
Apr 23 23:53:12 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:11.537 9094 DEBUG nova.compute.claims [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Aborting claim: [Claim: 32768 MB memory, 32 GB disk] abort /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/claims.py:130
Apr 23 23:53:12 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:11.557 9094 DEBUG nova.compute.utils [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] PROFESSOR CHAOS MONKEY, MWHAHAHAH notify_about_instance_usage /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/utils.py:346
Apr 23 23:53:12 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:11.598 9094 DEBUG nova.compute.manager [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Build of instance 9daa9c77-d801-4138-87b7-184c40cac6e5 was re-scheduled: PROFESSOR CHAOS MONKEY, MWHAHAHAH _do_build_and_run_instance /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:2185
Apr 23 23:53:12 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:11.598 9094 DEBUG nova.compute.manager [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] rm12321 pre deallocated network_allocated: True _do_build_and_run_instance /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:2189
Apr 23 23:53:12 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:11.599 9094 DEBUG nova.compute.manager [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Deallocating network for instance _deallocate_network /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:2034
Apr 23 23:53:12 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:11.600 9094 DEBUG nova.network.neutronv2.api [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] deallocate_for_instance() deallocate_for_instance /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/network/neutronv2/api.py:650
Apr 23 23:53:12 ironic-compute01.m0002.preprod-ord.ohthree.com REQ: curl -i http://neutron-api-vip.m0002.preprod-ord.ohthree.com:9696/v2.0/ports.json?device_id=9daa9c77-d801-4138-87b7-184c40cac6e5 -X GET -H "User-Agent: python-neutronclient" -H "X-Roles: identity:user-admin,object-store:default,compute:default" -H "X-Auth-Token: 99114baf23644b4ab691f89abb5a8441"
Apr 23 23:53:12 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:11.680 9094 DEBUG neutronclient.client [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] RESP:200 {'date': 'Thu, 23 Apr 2015 23:53:11 GMT', 'content-length': '1322', 'content-type': 'application/json; charset=UTF-8'} {"ports": [{"status": "DOWN", "name": "", "allowed_address_pairs": [], "admin_state_up": true, "network_id": "11111111-1111-1111-1111-111111111111", "tenant_id": "5956437", "extra_dhcp_opts": [], "switch:ports": [], "binding:vif_details": {}, "switch:hardware_id": null, "device_owner": "compute:None", "mac_address": "a0:36:9f:2c:ec:99", "commit": false, "trunked": false, "binding:vnic_type": "normal", "fixed_ips": [{"subnet_id": "93013f73-23c3-4f19-8e83-56916cdc24d0", "ip_address": "10.184.255.209"}], "id": "620cdde5-04cd-4a3d-920c-0aedf00f36f0", "security_groups": ["c3e2d506-72f5-4269-8cb6-bbbc55d49e35"], "device_id": "9daa9c77-d801-4138-87b7-184c40cac6e5"}, {"status": "DOWN", "name": "", "allowed_address_pairs": [], "admin_state_up": true, "network_id": "00000000-0000-0000-0000-000000000000", "tenant_id": "5956437", "extra_dhcp_opts": [], "switch:ports": [], "binding:vif_details": {}, "switch:hardware_id": null, "device_owner": "compute:None", "mac_address": "a0:36:9f:2c:ec:98", "commit": false, "trunked": false, "binding:vnic_type": "normal", "fixed_ips": [{"subnet_id": "3ee44b7b-ac79-4430-a422-0490b4bb4849", "ip_address": "50.57.63.13"}], "id": "b1abb739-b004-4488-83fa-8c5418f88c24", "security_groups": ["c3e2d506-72f5-4269-8cb6-bbbc55d49e35"], "device_id": "9daa9c77-d801-4138-87b7-184c40cac6e5"}]}
Apr 23 23:53:12 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:11.681 9094 DEBUG nova.network.neutronv2.api [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Instance cache missing network info. _get_preexisting_port_ids /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1473
Apr 23 23:53:12 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:12.166 9094 DEBUG nova.compute.manager [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] rm12321 _cleanup_allocated_networks what changed: set(['flavor', 'system_metadata']) _cleanup_allocated_networks /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:2457
Apr 23 23:53:12 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:12.167 9094 DEBUG nova.compute.manager [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] rm12321 _cleanup_allocated_networks sysmeta: {u'image_com.rackspace__1__build_managed': u'1', u'image_com.rackspace__1__visible_rackconnect': u'1', u'image_cache_in_nova': u'True', u'image_com.rackspace__1__source': u'kickstart', u'image_com.rackspace__1__visible_core': u'1', u'image_min_ram': u'512', u'image_os_distro': u'ubuntu', u'image_com.rackspace__1__options': u'0', 'network_allocated': 'False', u'image_org.openstack__1__os_version': u'14.10', u'image_org.openstack__1__os_distro': u'com.ubuntu', u'image_org.openstack__1__architecture': u'x64', u'image_base_image_ref': u'f84002b9-5dbb-4fc4-819b-1d6337c18eed', u'image_os_type': u'linux', u'image_com.rackspace__1__release_version': u'4', u'image_com.rackspace__1__build_core': u'1', u'image_image_type': u'base', u'image_com.rackspace__1__build_rackconnect': u'1', u'image_auto_disk_config': u'disabled', u'image_disk_format': u'qcow2', u'image_com.rackspace__1__platform_target': u'PublicCloud', u'image_vm_mode': u'metal', u'image_com.rackspace__1__visible_managed': u'1', u'image_com.rackspace__1__release_build_date': u'2015-03-20_19-36-59', u'image_flavor_classes': u'onmetal', u'image_com.rackspace__1__release_id': u'1008', u'image_container_format': u'bare', u'image_min_disk': u'32'}; old_sysmeta: {u'image_os_type': u'linux', u'image_com.rackspace__1__release_version': u'4', u'image_com.rackspace__1__build_managed': u'1', u'image_com.rackspace__1__build_core': u'1', u'image_com.rackspace__1__visible_rackconnect': u'1', u'image_com.rackspace__1__options': u'0', u'image_com.rackspace__1__source': u'kickstart', u'image_image_type': u'base', u'image_com.rackspace__1__release_id': u'1008', u'image_auto_disk_config': u'disabled', u'image_com.rackspace__1__visible_core': u'1', u'image_min_ram': u'512', u'image_disk_format': u'qcow2', u'image_com.rackspace__1__platform_target': u'PublicCloud', u'image_com.rackspace__1__build_rackconnect': u'1', u'image_os_distro': u'ubuntu', u'image_vm_mode': u'metal', u'image_com.rackspace__1__visible_managed': u'1', u'image_min_disk': u'32', u'image_flavor_classes': u'onmetal', u'image_cache_in_nova': u'True', u'image_org.openstack__1__os_version': u'14.10', u'image_org.openstack__1__os_distro': u'com.ubuntu', u'image_container_format': u'bare', u'image_org.openstack__1__architecture': u'x64', u'image_com.rackspace__1__release_build_date': u'2015-03-20_19-36-59', u'image_base_image_ref': u'f84002b9-5dbb-4fc4-819b-1d6337c18eed'} _cleanup_allocated_networks /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:2458
Apr 23 23:53:13 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:12.269 9094 INFO nova.objects.instance [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x7ccabd0> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x95e7710>
Apr 23 23:53:13 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:12.408 9094 DEBUG nova.compute.manager [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] rm12321 post deallocated network_allocated: False _do_build_and_run_instance /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:2202
Apr 23 23:53:13 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:12.410 9094 DEBUG nova.compute.manager [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] rm12321 post deallocated what changed: set(['flavor', 'task_state']) _do_build_and_run_instance /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:2203
Apr 23 23:53:13 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:12.501 9094 INFO nova.objects.instance [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x95e2450> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x9cbf510>
Apr 23 23:53:13 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:12.636 9094 DEBUG nova.compute.manager [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] rm12321 post save deallocated network_allocated: False _do_build_and_run_instance /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:2205
Apr 23 23:53:13 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:12.663 9094 DEBUG oslo_concurrency.lockutils [req-ff055338-d975-4b15-89ab-d10bc7a8a62d - - - - -] Lock "9daa9c77-d801-4138-87b7-184c40cac6e5" released by "_locked_do_build_and_run_instance" :: held 3.544s inner /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:456
Apr 23 23:53:13 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:12.664 9094 ERROR nova.scheduler.utils [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Error from last host: ironic-compute (node c1ef6656-2998-4bf3-9c44-7c30b4cb8a35): ['Traceback (most recent call last):\n', ' File "/opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py", line 2171, in _do_build_and_run_instance\n filter_properties)\n', ' File "/opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py", line 2329, in _build_and_run_instance\n instance_uuid=instance.uuid, reason=six.text_type(e))\n', 'RescheduledException: Build of instance 9daa9c77-d801-4138-87b7-184c40cac6e5 was re-scheduled: PROFESSOR CHAOS MONKEY, MWHAHAHAH\n']
Apr 23 23:53:13 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:12.970 9094 DEBUG oslo_concurrency.lockutils [-] Lock "9daa9c77-d801-4138-87b7-184c40cac6e5" acquired by "_locked_do_build_and_run_instance" :: waited 0.000s inner /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:444
Apr 23 23:53:13 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:12.987 9094 INFO nova.compute.manager [req-59c335d9-a84c-49c5-933b-d3b5b6b65cd0 a73e7267b25141fbb82975956598aebf 5956437 - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Starting instance...
Apr 23 23:53:13 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:13.087 9094 INFO nova.objects.instance [-] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x85be150> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x91aa8d0>
Apr 23 23:53:13 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:13.171 9094 WARNING nova.compute.resource_tracker [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Host field should not be set on the instance until resources have been claimed.
Apr 23 23:53:13 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:13.171 9094 WARNING nova.compute.resource_tracker [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Node field should not be set on the instance until resources have been claimed.
Apr 23 23:53:14 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:13.175 9094 INFO nova.compute.claims [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Attempting claim: memory 32768 MB, disk 32 GB
Apr 23 23:53:14 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:13.176 9094 INFO nova.compute.claims [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Total memory: 32768 MB, used: 0.00 MB
Apr 23 23:53:14 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:13.176 9094 INFO nova.compute.claims [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] memory limit not specified, defaulting to unlimited
Apr 23 23:53:14 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:13.177 9094 INFO nova.compute.claims [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Total disk: 32 GB, used: 0.00 GB
Apr 23 23:53:14 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:13.177 9094 INFO nova.compute.claims [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] disk limit not specified, defaulting to unlimited
Apr 23 23:53:14 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:13.187 9094 INFO nova.compute.claims [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Claim successful
Apr 23 23:53:14 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:13.254 9094 DEBUG nova.objects.instance [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] Lazy-loading `flavor' on Instance uuid 9daa9c77-d801-4138-87b7-184c40cac6e5 obj_load_attr /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/objects/instance.py:994
Apr 23 23:53:14 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:13.461 9094 DEBUG nova.objects.instance [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] Lazy-loading `metadata' on Instance uuid 9daa9c77-d801-4138-87b7-184c40cac6e5 obj_load_attr /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/objects/instance.py:994
Apr 23 23:53:14 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:13.498 9094 DEBUG nova.objects.instance [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] Lazy-loading `info_cache' on Instance uuid 9daa9c77-d801-4138-87b7-184c40cac6e5 obj_load_attr /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/objects/instance.py:994
Apr 23 23:53:14 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:13.785 9094 INFO nova.objects.instance [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x95c9bd0> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x8b1e450>
Apr 23 23:53:14 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:13.873 9094 DEBUG nova.compute.manager [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Allocating IP information in the background. _allocate_network_async /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:1761
Apr 23 23:53:14 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:13.876 9094 DEBUG nova.network.neutronv2.api [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] allocate_for_instance() allocate_for_instance /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/network/neutronv2/api.py:405
Apr 23 23:53:14 ironic-compute01.m0002.preprod-ord.ohthree.com REQ: curl -i http://neutron-api-vip.m0002.preprod-ord.ohthree.com:9696/v2.0/ports.json -X POST -H "User-Agent: python-neutronclient" -H "X-Roles: identity:user-admin,object-store:default,compute:default" -H "X-Auth-Token: 7bc82c922b1d48a6af22c011e1bda4c0" -d '{"port": {"binding:host_id": "ironic-compute", "admin_state_up": true, "network_id": "00000000-0000-0000-0000-000000000000", "tenant_id": "5956437", "device_owner": "compute:None", "mac_address": "a0:36:9f:2c:ec:38", "device_id": "9daa9c77-d801-4138-87b7-184c40cac6e5"}}'
Apr 23 23:53:14 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:13.970 9094 INFO nova.objects.instance [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x9c4bd10> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x86dd110>
Apr 23 23:53:15 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:14.294 9094 DEBUG neutronclient.client [-] RESP:201 {'date': 'Thu, 23 Apr 2015 23:53:14 GMT', 'content-length': '760', 'content-type': 'application/json; charset=UTF-8'} {"port": {"status": "DOWN", "binding:host_id": "ironic-compute", "allowed_address_pairs": [], "extra_dhcp_opts": [], "switch:hardware_id": null, "device_owner": "compute:None", "binding:profile": {}, "trunked": false, "fixed_ips": [{"subnet_id": "3ee44b7b-ac79-4430-a422-0490b4bb4849", "ip_address": "50.57.63.14"}], "id": "6c42bfd4-954e-41db-ad99-927bb4a655ad", "security_groups": ["c3e2d506-72f5-4269-8cb6-bbbc55d49e35"], "device_id": "9daa9c77-d801-4138-87b7-184c40cac6e5", "name": "", "admin_state_up": true, "network_id": "00000000-0000-0000-0000-000000000000", "tenant_id": "5956437", "binding:vif_details": {}, "binding:vnic_type": "normal", "binding:vif_type": "binding_failed", "switch:ports": [], "mac_address": "a0:36:9f:2c:ec:38", "commit": false}}
Apr 23 23:53:15 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:14.298 9094 DEBUG nova.network.neutronv2.api [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Successfully created port: 6c42bfd4-954e-41db-ad99-927bb4a655ad _create_port /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/network/neutronv2/api.py:297
Apr 23 23:53:15 ironic-compute01.m0002.preprod-ord.ohthree.com REQ: curl -i http://neutron-api-vip.m0002.preprod-ord.ohthree.com:9696/v2.0/ports.json -X POST -H "User-Agent: python-neutronclient" -H "X-Roles: identity:user-admin,object-store:default,compute:default" -H "X-Auth-Token: 7bc82c922b1d48a6af22c011e1bda4c0" -d '{"port": {"binding:host_id": "ironic-compute", "admin_state_up": true, "network_id": "11111111-1111-1111-1111-111111111111", "tenant_id": "5956437", "device_owner": "compute:None", "mac_address": "a0:36:9f:2c:ec:39", "device_id": "9daa9c77-d801-4138-87b7-184c40cac6e5"}}'
Apr 23 23:53:15 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:14.307 9094 INFO nova.objects.instance [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x8965850> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x8b41690>
Apr 23 23:53:15 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:14.399 9094 DEBUG nova.virt.ironic.driver [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Updating progress to 14 _update_instance_progress /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:649
Apr 23 23:53:15 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:14.503 9094 INFO nova.objects.instance [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x83cc190> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x9ca51d0>
Apr 23 23:53:15 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:14.543 9094 DEBUG neutronclient.client [-] RESP:201 {'date': 'Thu, 23 Apr 2015 23:53:14 GMT', 'content-length': '763', 'content-type': 'application/json; charset=UTF-8'} {"port": {"status": "DOWN", "binding:host_id": "ironic-compute", "allowed_address_pairs": [], "extra_dhcp_opts": [], "switch:hardware_id": null, "device_owner": "compute:None", "binding:profile": {}, "trunked": false, "fixed_ips": [{"subnet_id": "93013f73-23c3-4f19-8e83-56916cdc24d0", "ip_address": "10.184.255.210"}], "id": "8f4b2c35-b0f5-447d-9731-2093346edc81", "security_groups": ["c3e2d506-72f5-4269-8cb6-bbbc55d49e35"], "device_id": "9daa9c77-d801-4138-87b7-184c40cac6e5", "name": "", "admin_state_up": true, "network_id": "11111111-1111-1111-1111-111111111111", "tenant_id": "5956437", "binding:vif_details": {}, "binding:vnic_type": "normal", "binding:vif_type": "binding_failed", "switch:ports": [], "mac_address": "a0:36:9f:2c:ec:39", "commit": false}}
Apr 23 23:53:15 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:14.549 9094 DEBUG nova.network.neutronv2.api [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Successfully created port: 8f4b2c35-b0f5-447d-9731-2093346edc81 _create_port /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/network/neutronv2/api.py:297
Apr 23 23:53:15 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:14.550 9094 DEBUG oslo_concurrency.lockutils [-] Acquired semaphore "refresh_cache-9daa9c77-d801-4138-87b7-184c40cac6e5" lock /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:391
Apr 23 23:53:15 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:14.550 9094 DEBUG nova.network.neutronv2.api [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] _get_instance_nw_info() _get_instance_nw_info /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/network/neutronv2/api.py:745
Apr 23 23:53:15 ironic-compute01.m0002.preprod-ord.ohthree.com REQ: curl -i http://neutron-api-vip.m0002.preprod-ord.ohthree.com:9696/v2.0/ports.json?tenant_id=5956437&device_id=9daa9c77-d801-4138-87b7-184c40cac6e5 -X GET -H "User-Agent: python-neutronclient" -H "X-Roles: identity:user-admin,object-store:default,compute:default" -H "X-Auth-Token: 7bc82c922b1d48a6af22c011e1bda4c0"
Apr 23 23:53:15 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:14.701 9094 DEBUG neutronclient.client [-] RESP:200 {'date': 'Thu, 23 Apr 2015 23:53:14 GMT', 'content-length': '1518', 'content-type': 'application/json; charset=UTF-8'} {"ports": [{"status": "DOWN", "binding:host_id": "ironic-compute", "allowed_address_pairs": [], "extra_dhcp_opts": [], "switch:hardware_id": null, "device_owner": "compute:None", "binding:profile": {}, "trunked": false, "fixed_ips": [{"subnet_id": "3ee44b7b-ac79-4430-a422-0490b4bb4849", "ip_address": "50.57.63.14"}], "id": "6c42bfd4-954e-41db-ad99-927bb4a655ad", "security_groups": ["c3e2d506-72f5-4269-8cb6-bbbc55d49e35"], "device_id": "9daa9c77-d801-4138-87b7-184c40cac6e5", "name": "", "admin_state_up": true, "network_id": "00000000-0000-0000-0000-000000000000", "tenant_id": "5956437", "binding:vif_details": {}, "binding:vnic_type": "normal", "binding:vif_type": "binding_failed", "switch:ports": [], "mac_address": "a0:36:9f:2c:ec:38", "commit": false}, {"status": "DOWN", "binding:host_id": "ironic-compute", "allowed_address_pairs": [], "extra_dhcp_opts": [], "switch:hardware_id": null, "device_owner": "compute:None", "binding:profile": {}, "trunked": false, "fixed_ips": [{"subnet_id": "93013f73-23c3-4f19-8e83-56916cdc24d0", "ip_address": "10.184.255.210"}], "id": "8f4b2c35-b0f5-447d-9731-2093346edc81", "security_groups": ["c3e2d506-72f5-4269-8cb6-bbbc55d49e35"], "device_id": "9daa9c77-d801-4138-87b7-184c40cac6e5", "name": "", "admin_state_up": true, "network_id": "11111111-1111-1111-1111-111111111111", "tenant_id": "5956437", "binding:vif_details": {}, "binding:vnic_type": "normal", "binding:vif_type": "binding_failed", "switch:ports": [], "mac_address": "a0:36:9f:2c:ec:39", "commit": false}]}
Apr 23 23:53:15 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:14.709 9094 DEBUG nova.network.neutronv2.api [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Instance cache missing network info. _get_preexisting_port_ids /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1473
Apr 23 23:53:15 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:15.103 9094 DEBUG oslo_concurrency.lockutils [-] Releasing semaphore "refresh_cache-9daa9c77-d801-4138-87b7-184c40cac6e5" lock /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:404
Apr 23 23:53:15 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:15.104 9094 DEBUG nova.compute.manager [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Instance network_info: |[VIF({'profile': {}, 'ovs_interfaceid': None, 'preserve_on_delete': False, 'network': Network({'bridge': None, 'subnets': [Subnet({'ips': [FixedIP({'meta': {}, 'version': 4, 'type': 'fixed', 'floating_ips': [], 'address': u'50.57.63.14'})], 'version': 4, 'meta': {}, 'dns': [IP({'meta': {}, 'version': 4, 'type': 'dns', 'address': u'173.203.4.8'}), IP({'meta': {}, 'version': 4, 'type': 'dns', 'address': u'173.203.4.9'})], 'routes': [], 'cidr': u'50.57.63.0/25', 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'50.57.63.1'})})], 'meta': {'injected': True, 'tenant_id': u'onmetal', 'vlan_id': 101}, 'id': u'00000000-0000-0000-0000-000000000000', 'label': u'public'}), 'devname': u'tap6c42bfd4-95', 'vnic_type': u'normal', 'qbh_params': None, 'meta': {}, 'details': {}, 'address': u'a0:36:9f:2c:ec:38', 'active': False, 'type': u'binding_failed', 'id': u'6c42bfd4-954e-41db-ad99-927bb4a655ad', 'qbg_params': None}), VIF({'profile': {}, 'ovs_interfaceid': None, 'preserve_on_delete': False, 'network': Network({'bridge': None, 'subnets': [Subnet({'ips': [FixedIP({'meta': {}, 'version': 4, 'type': 'fixed', 'floating_ips': [], 'address': u'10.184.255.210'})], 'version': 4, 'meta': {}, 'dns': [], 'routes': [Route({'interface': None, 'cidr': u'10.176.0.0/12', 'meta': {}, 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'10.184.255.129'})}), Route({'interface': None, 'cidr': u'10.208.0.0/12', 'meta': {}, 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': u'10.184.255.129'})})], 'cidr': u'10.184.255.128/25', 'gateway': IP({'meta': {}, 'version': None, 'type': 'gateway', 'address': None})})], 'meta': {'injected': True, 'tenant_id': u'onmetal', 'vlan_id': 499}, 'id': u'11111111-1111-1111-1111-111111111111', 'label': u'private'}), 'devname': u'tap8f4b2c35-b0', 'vnic_type': u'normal', 'qbh_params': None, 'meta': {}, 'details': {}, 'address': u'a0:36:9f:2c:ec:39', 'active': False, 'type': u'binding_failed', 'id': u'8f4b2c35-b0f5-447d-9731-2093346edc81', 'qbg_params': None})]| _allocate_network_async /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:1779
Apr 23 23:53:16 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:15.182 9094 DEBUG nova.objects.instance [-] Lazy-loading `flavor' on Instance uuid 9daa9c77-d801-4138-87b7-184c40cac6e5 obj_load_attr /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/objects/instance.py:994
Apr 23 23:53:16 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:15.231 9094 DEBUG nova.objects.instance [-] Lazy-loading `metadata' on Instance uuid 9daa9c77-d801-4138-87b7-184c40cac6e5 obj_load_attr /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/objects/instance.py:994
Apr 23 23:53:16 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:53:15.266 9094 DEBUG nova.objects.instance [req-22ba19cd-82bf-4559-9ec4-971e1ba1405d - - - - -] Lazy-loading `info_cache' on Instance uuid 9daa9c77-d801-4138-87b7-184c40cac6e5 obj_load_attr /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/objects/instance.py:994
Apr 23 23:54:41 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:54:40.416 9094 DEBUG nova.compute.manager [req-c8841865-5384-4ad6-a9bb-6a64faa3dcba - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Skipping network cache update for instance because it is Building. _heal_instance_info_cache /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:5701
Apr 23 23:56:42 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:56:41.847 9094 DEBUG nova.compute.manager [req-c8841865-5384-4ad6-a9bb-6a64faa3dcba - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Skipping network cache update for instance because it is Building. _heal_instance_info_cache /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:5701
Apr 23 23:58:42 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:58:42.402 9094 DEBUG nova.compute.manager [req-c8841865-5384-4ad6-a9bb-6a64faa3dcba - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Skipping network cache update for instance because it is Building. _heal_instance_info_cache /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:5701
Apr 23 23:59:28 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-23 23:59:28.612 9094 DEBUG nova.compute.manager [req-c8841865-5384-4ad6-a9bb-6a64faa3dcba - - - - -] Triggering sync for uuid 9daa9c77-d801-4138-87b7-184c40cac6e5 _sync_power_states /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:6152
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.198 9094 ERROR nova.compute.manager [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Instance failed to spawn
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.198 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Traceback (most recent call last):
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.198 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] File "/opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py", line 2425, in _build_resources
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.198 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] yield resources
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.198 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] File "/opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py", line 2281, in _build_and_run_instance
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.198 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] block_device_info=block_device_info)
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.198 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] File "/opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py", line 686, in spawn
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.198 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] self._add_driver_fields(node, instance, image_meta, flavor)
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.198 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] File "/opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py", line 333, in _add_driver_fields
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.198 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] self.ironicclient.call('node.update', node.uuid, patch)
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.198 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] File "/opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/client_wrapper.py", line 142, in call
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.198 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] raise exception.NovaException(msg)
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.198 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] NovaException: Error contacting Ironic server for 'node.update'. Attempt 50 of 50
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.198 9094 TRACE nova.compute.manager [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5]
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.200 9094 INFO nova.compute.manager [req-59c335d9-a84c-49c5-933b-d3b5b6b65cd0 a73e7267b25141fbb82975956598aebf 5956437 - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Terminating instance
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.248 9094 WARNING nova.virt.ironic.driver [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] Destroy called on non-existing instance 9daa9c77-d801-4138-87b7-184c40cac6e5.
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.275 9094 DEBUG nova.compute.claims [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Aborting claim: [Claim: 32768 MB memory, 32 GB disk] abort /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/claims.py:130
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.298 9094 DEBUG nova.compute.utils [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Error contacting Ironic server for 'node.update'. Attempt 50 of 50 notify_about_instance_usage /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/utils.py:346
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.324 9094 DEBUG nova.compute.manager [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Build of instance 9daa9c77-d801-4138-87b7-184c40cac6e5 was re-scheduled: Error contacting Ironic server for 'node.update'. Attempt 50 of 50 _do_build_and_run_instance /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:2185
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.325 9094 DEBUG nova.compute.manager [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] rm12321 pre deallocated network_allocated: True _do_build_and_run_instance /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:2189
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.326 9094 DEBUG nova.compute.manager [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Deallocating network for instance _deallocate_network /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:2034
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.326 9094 DEBUG nova.network.neutronv2.api [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] deallocate_for_instance() deallocate_for_instance /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/network/neutronv2/api.py:650
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com REQ: curl -i http://neutron-api-vip.m0002.preprod-ord.ohthree.com:9696/v2.0/ports.json?device_id=9daa9c77-d801-4138-87b7-184c40cac6e5 -X GET -H "User-Agent: python-neutronclient" -H "X-Roles: identity:user-admin,object-store:default,compute:default" -H "X-Auth-Token: 99114baf23644b4ab691f89abb5a8441"
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.400 9094 DEBUG neutronclient.client [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] RESP:200 {'date': 'Fri, 24 Apr 2015 00:01:36 GMT', 'content-length': '1322', 'content-type': 'application/json; charset=UTF-8'} {"ports": [{"status": "DOWN", "name": "", "allowed_address_pairs": [], "admin_state_up": true, "network_id": "00000000-0000-0000-0000-000000000000", "tenant_id": "5956437", "extra_dhcp_opts": [], "switch:ports": [], "binding:vif_details": {}, "switch:hardware_id": null, "device_owner": "compute:None", "mac_address": "a0:36:9f:2c:ec:38", "commit": false, "trunked": false, "binding:vnic_type": "normal", "fixed_ips": [{"subnet_id": "3ee44b7b-ac79-4430-a422-0490b4bb4849", "ip_address": "50.57.63.14"}], "id": "6c42bfd4-954e-41db-ad99-927bb4a655ad", "security_groups": ["c3e2d506-72f5-4269-8cb6-bbbc55d49e35"], "device_id": "9daa9c77-d801-4138-87b7-184c40cac6e5"}, {"status": "DOWN", "name": "", "allowed_address_pairs": [], "admin_state_up": true, "network_id": "11111111-1111-1111-1111-111111111111", "tenant_id": "5956437", "extra_dhcp_opts": [], "switch:ports": [], "binding:vif_details": {}, "switch:hardware_id": null, "device_owner": "compute:None", "mac_address": "a0:36:9f:2c:ec:39", "commit": false, "trunked": false, "binding:vnic_type": "normal", "fixed_ips": [{"subnet_id": "93013f73-23c3-4f19-8e83-56916cdc24d0", "ip_address": "10.184.255.210"}], "id": "8f4b2c35-b0f5-447d-9731-2093346edc81", "security_groups": ["c3e2d506-72f5-4269-8cb6-bbbc55d49e35"], "device_id": "9daa9c77-d801-4138-87b7-184c40cac6e5"}]}
Apr 24 00:01:36 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.401 9094 DEBUG nova.network.neutronv2.api [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Instance cache missing network info. _get_preexisting_port_ids /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1473
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.918 9094 DEBUG nova.compute.manager [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] rm12321 _cleanup_allocated_networks what changed: set(['flavor']) _cleanup_allocated_networks /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:2457
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.918 9094 DEBUG nova.compute.manager [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] rm12321 _cleanup_allocated_networks sysmeta: {u'image_com.rackspace__1__build_managed': u'1', u'image_com.rackspace__1__visible_rackconnect': u'1', u'image_cache_in_nova': u'True', u'image_com.rackspace__1__source': u'kickstart', u'image_com.rackspace__1__visible_core': u'1', u'image_min_ram': u'512', u'image_os_distro': u'ubuntu', u'image_com.rackspace__1__options': u'0', u'network_allocated': 'False', u'image_org.openstack__1__os_version': u'14.10', u'image_org.openstack__1__os_distro': u'com.ubuntu', u'image_org.openstack__1__architecture': u'x64', u'image_base_image_ref': u'f84002b9-5dbb-4fc4-819b-1d6337c18eed', u'image_os_type': u'linux', u'image_com.rackspace__1__release_version': u'4', u'image_com.rackspace__1__build_core': u'1', u'image_image_type': u'base', u'image_com.rackspace__1__build_rackconnect': u'1', u'image_auto_disk_config': u'disabled', u'image_disk_format': u'qcow2', u'image_com.rackspace__1__platform_target': u'PublicCloud', u'image_vm_mode': u'metal', u'image_com.rackspace__1__visible_managed': u'1', u'image_com.rackspace__1__release_build_date': u'2015-03-20_19-36-59', u'image_flavor_classes': u'onmetal', u'image_com.rackspace__1__release_id': u'1008', u'image_container_format': u'bare', u'image_min_disk': u'32'}; old_sysmeta: {u'image_os_type': u'linux', u'image_com.rackspace__1__release_version': u'4', u'image_com.rackspace__1__build_managed': u'1', u'image_com.rackspace__1__build_core': u'1', u'image_com.rackspace__1__visible_rackconnect': u'1', u'image_com.rackspace__1__options': u'0', u'image_com.rackspace__1__source': u'kickstart', u'image_image_type': u'base', u'image_com.rackspace__1__release_id': u'1008', u'image_auto_disk_config': u'disabled', u'image_com.rackspace__1__visible_core': u'1', u'image_min_ram': u'512', u'image_disk_format': u'qcow2', u'image_com.rackspace__1__platform_target': u'PublicCloud', u'image_com.rackspace__1__build_rackconnect': u'1', u'image_os_distro': u'ubuntu', u'image_vm_mode': u'metal', u'image_com.rackspace__1__visible_managed': u'1', u'image_min_disk': u'32', u'image_flavor_classes': u'onmetal', u'image_cache_in_nova': u'True', u'network_allocated': u'False', u'image_org.openstack__1__os_version': u'14.10', u'image_org.openstack__1__os_distro': u'com.ubuntu', u'image_container_format': u'bare', u'image_org.openstack__1__architecture': u'x64', u'image_com.rackspace__1__release_build_date': u'2015-03-20_19-36-59', u'image_base_image_ref': u'f84002b9-5dbb-4fc4-819b-1d6337c18eed'} _cleanup_allocated_networks /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:2458
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.939 9094 DEBUG nova.compute.manager [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] rm12321 post deallocated network_allocated: False _do_build_and_run_instance /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:2202
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:36.940 9094 DEBUG nova.compute.manager [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] rm12321 post deallocated what changed: set(['flavor', 'task_state']) _do_build_and_run_instance /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:2203
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.032 9094 INFO nova.objects.instance [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x96a2790> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x9cf4e10>
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.073 9094 DEBUG nova.compute.manager [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] rm12321 post save deallocated network_allocated: True _do_build_and_run_instance /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:2205
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.098 9094 DEBUG oslo_concurrency.lockutils [req-229ecea1-4628-4303-b357-4ffd7644f74f - - - - -] Lock "9daa9c77-d801-4138-87b7-184c40cac6e5" released by "_locked_do_build_and_run_instance" :: held 504.128s inner /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:456
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.099 9094 ERROR nova.scheduler.utils [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Error from last host: ironic-compute (node e5340743-e91b-4d64-8f82-429b65271c2b): ['Traceback (most recent call last):\n', ' File "/opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py", line 2171, in _do_build_and_run_instance\n filter_properties)\n', ' File "/opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py", line 2329, in _build_and_run_instance\n instance_uuid=instance.uuid, reason=six.text_type(e))\n', "RescheduledException: Build of instance 9daa9c77-d801-4138-87b7-184c40cac6e5 was re-scheduled: Error contacting Ironic server for 'node.update'. Attempt 50 of 50\n"]
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.102 9094 DEBUG oslo_concurrency.lockutils [-] Lock "9daa9c77-d801-4138-87b7-184c40cac6e5" acquired by "query_driver_power_state_and_sync" :: waited 128.479s inner /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:444
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.103 9094 INFO nova.compute.manager [-] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] During sync_power_state the instance has a pending task (spawning). Skip.
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.103 9094 DEBUG oslo_concurrency.lockutils [-] Lock "9daa9c77-d801-4138-87b7-184c40cac6e5" released by "query_driver_power_state_and_sync" :: held 0.001s inner /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:456
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.331 9094 DEBUG oslo_concurrency.lockutils [-] Lock "9daa9c77-d801-4138-87b7-184c40cac6e5" acquired by "_locked_do_build_and_run_instance" :: waited 0.000s inner /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:444
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.350 9094 INFO nova.compute.manager [req-59c335d9-a84c-49c5-933b-d3b5b6b65cd0 a73e7267b25141fbb82975956598aebf 5956437 - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Starting instance...
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.426 9094 INFO nova.objects.instance [-] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x8ee9b50> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x97e9290>
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.511 9094 WARNING nova.compute.resource_tracker [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Host field should not be set on the instance until resources have been claimed.
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.511 9094 WARNING nova.compute.resource_tracker [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Node field should not be set on the instance until resources have been claimed.
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.515 9094 INFO nova.compute.claims [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Attempting claim: memory 32768 MB, disk 32 GB
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.515 9094 INFO nova.compute.claims [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Total memory: 32768 MB, used: 0.00 MB
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.516 9094 INFO nova.compute.claims [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] memory limit not specified, defaulting to unlimited
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.516 9094 INFO nova.compute.claims [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Total disk: 32 GB, used: 0.00 GB
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.517 9094 INFO nova.compute.claims [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] disk limit not specified, defaulting to unlimited
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.524 9094 INFO nova.compute.claims [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Claim successful
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.594 9094 DEBUG nova.objects.instance [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] Lazy-loading `flavor' on Instance uuid 9daa9c77-d801-4138-87b7-184c40cac6e5 obj_load_attr /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/objects/instance.py:994
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.637 9094 DEBUG nova.objects.instance [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] Lazy-loading `metadata' on Instance uuid 9daa9c77-d801-4138-87b7-184c40cac6e5 obj_load_attr /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/objects/instance.py:994
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.672 9094 DEBUG nova.objects.instance [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] Lazy-loading `info_cache' on Instance uuid 9daa9c77-d801-4138-87b7-184c40cac6e5 obj_load_attr /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/objects/instance.py:994
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com REQ: curl -i http://neutron-api-vip.m0002.preprod-ord.ohthree.com:9696/v2.0/ports.json?tenant_id=5956437&device_id=9daa9c77-d801-4138-87b7-184c40cac6e5 -X GET -H "User-Agent: python-neutronclient" -H "X-Roles: identity:user-admin,object-store:default,compute:default" -H "X-Auth-Token: 7bc82c922b1d48a6af22c011e1bda4c0"
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.823 9094 DEBUG oslo_concurrency.lockutils [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] Acquired semaphore "refresh_cache-9daa9c77-d801-4138-87b7-184c40cac6e5" lock /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:391
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.823 9094 DEBUG nova.network.neutronv2.api [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] _get_instance_nw_info() _get_instance_nw_info /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/network/neutronv2/api.py:745
Apr 24 00:01:37 ironic-compute01.m0002.preprod-ord.ohthree.com REQ: curl -i http://neutron-api-vip.m0002.preprod-ord.ohthree.com:9696/v2.0/ports.json?tenant_id=5956437&device_id=9daa9c77-d801-4138-87b7-184c40cac6e5 -X GET -H "User-Agent: python-neutronclient" -H "X-Roles: identity:user-admin,object-store:default,compute:default" -H "X-Auth-Token: 7bc82c922b1d48a6af22c011e1bda4c0"
Apr 24 00:01:38 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:37.992 9094 DEBUG nova.network.neutronv2.api [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Instance cache missing network info. _get_preexisting_port_ids /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1473
Apr 24 00:01:38 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:38.005 9094 DEBUG oslo_concurrency.lockutils [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] Releasing semaphore "refresh_cache-9daa9c77-d801-4138-87b7-184c40cac6e5" lock /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:404
Apr 24 00:01:38 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:38.099 9094 INFO nova.objects.instance [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x7dcd810> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x7fb5650>
Apr 24 00:01:38 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:38.232 9094 INFO nova.objects.instance [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x89606d0> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x9a40cd0>
Apr 24 00:01:38 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:38.306 9094 DEBUG nova.virt.ironic.driver [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Updating progress to 14 _update_instance_progress /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:649
Apr 24 00:01:38 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:38.392 9094 INFO nova.objects.instance [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x7eb2810> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x9e3d8d0>
Apr 24 00:01:38 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:38.546 9094 DEBUG nova.virt.ironic.driver [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Updating progress to 29 _update_instance_progress /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:649
Apr 24 00:01:38 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:38.781 9094 INFO nova.objects.instance [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x9fb58d0> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0xa089b50>
Apr 24 00:01:39 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:39.301 9094 DEBUG nova.virt.ironic.driver [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Updating progress to 43 _update_instance_progress /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:649
Apr 24 00:01:39 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:39.401 9094 INFO nova.objects.instance [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x9a55d90> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x9199d10>
Apr 24 00:01:39 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:39.441 9094 DEBUG nova.virt.ironic.driver [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] plug: instance_uuid=9daa9c77-d801-4138-87b7-184c40cac6e5 vif=[] _plug_vifs /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:1051
Apr 24 00:01:39 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:39.442 9094 DEBUG nova.virt.ironic.driver [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] unplug: instance_uuid=9daa9c77-d801-4138-87b7-184c40cac6e5 vif=[] _unplug_vifs /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:1083
Apr 24 00:01:39 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:39.491 9094 DEBUG nova.virt.ironic.driver [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Updating progress to 57 _update_instance_progress /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:649
Apr 24 00:01:39 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:39.581 9094 INFO nova.objects.instance [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x7eb8610> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x9c18ad0>
Apr 24 00:01:39 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:39.744 9094 INFO nova.virt.ironic.driver [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] Config drive for instance 9daa9c77-d801-4138-87b7-184c40cac6e5 on baremetal node 1ca7b231-554f-4561-beec-dda9852c2e4f created.
Apr 24 00:01:39 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:39.745 9094 DEBUG nova.virt.ironic.driver [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Updating progress to 71 _update_instance_progress /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:649
Apr 24 00:01:39 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:39.864 9094 INFO nova.objects.instance [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x9c37910> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x9371410>
Apr 24 00:01:40 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:40.226 9094 DEBUG nova.virt.ironic.driver [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Updating progress to 86 _update_instance_progress /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:649
Apr 24 00:01:40 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:40.326 9094 INFO nova.objects.instance [req-36733154-6648-4eb9-821f-a7f2eb77f66f - - - - -] rm12321 9daa9c77-d801-4138-87b7-184c40cac6e5 instance.save, old ref: <nova.db.sqlalchemy.models.Instance object at 0x8ec2d10> inst_ref: <nova.db.sqlalchemy.models.Instance object at 0x9bcbcd0>
Apr 24 00:01:40 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:40.397 9094 DEBUG nova.virt.ironic.driver [req-59c335d9-a84c-49c5-933b-d3b5b6b65cd0 a73e7267b25141fbb82975956598aebf 5956437 - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Still waiting for ironic node 1ca7b231-554f-4561-beec-dda9852c2e4f to become ACTIVE: power_state="power on", target_power_state=None, provision_state="wait call-back", target_provision_state="active" _log_ironic_polling /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:162
Apr 24 00:01:45 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:45.820 9094 DEBUG nova.compute.manager [req-c8841865-5384-4ad6-a9bb-6a64faa3dcba - - - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Skipping network cache update for instance because it is Building. _heal_instance_info_cache /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/compute/manager.py:5701
Apr 24 00:01:50 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:01:50.400 9094 DEBUG nova.virt.ironic.driver [req-59c335d9-a84c-49c5-933b-d3b5b6b65cd0 a73e7267b25141fbb82975956598aebf 5956437 - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Still waiting for ironic node 1ca7b231-554f-4561-beec-dda9852c2e4f to become ACTIVE: power_state="power on", target_power_state=None, provision_state="deploying", target_provision_state="active" _log_ironic_polling /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:162
Apr 24 00:02:00 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:02:00.395 9094 DEBUG nova.virt.ironic.driver [req-59c335d9-a84c-49c5-933b-d3b5b6b65cd0 a73e7267b25141fbb82975956598aebf 5956437 - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Still waiting for ironic node 1ca7b231-554f-4561-beec-dda9852c2e4f to become ACTIVE: power_state="power on", target_power_state=None, provision_state="deploying", target_provision_state="active" _log_ironic_polling /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:162
Apr 24 00:02:10 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:02:10.396 9094 DEBUG nova.virt.ironic.driver [req-59c335d9-a84c-49c5-933b-d3b5b6b65cd0 a73e7267b25141fbb82975956598aebf 5956437 - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Still waiting for ironic node 1ca7b231-554f-4561-beec-dda9852c2e4f to become ACTIVE: power_state="power on", target_power_state=None, provision_state="deploying", target_provision_state="active" _log_ironic_polling /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:162
Apr 24 00:02:20 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:02:20.399 9094 DEBUG nova.virt.ironic.driver [req-59c335d9-a84c-49c5-933b-d3b5b6b65cd0 a73e7267b25141fbb82975956598aebf 5956437 - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Still waiting for ironic node 1ca7b231-554f-4561-beec-dda9852c2e4f to become ACTIVE: power_state="power on", target_power_state=None, provision_state="deploying", target_provision_state="active" _log_ironic_polling /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:162
Apr 24 00:02:30 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:02:30.405 9094 DEBUG nova.virt.ironic.driver [req-59c335d9-a84c-49c5-933b-d3b5b6b65cd0 a73e7267b25141fbb82975956598aebf 5956437 - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Still waiting for ironic node 1ca7b231-554f-4561-beec-dda9852c2e4f to become ACTIVE: power_state="power on", target_power_state=None, provision_state="deploying", target_provision_state="active" _log_ironic_polling /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:162
Apr 24 00:02:40 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:02:40.402 9094 DEBUG nova.virt.ironic.driver [req-59c335d9-a84c-49c5-933b-d3b5b6b65cd0 a73e7267b25141fbb82975956598aebf 5956437 - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Still waiting for ironic node 1ca7b231-554f-4561-beec-dda9852c2e4f to become ACTIVE: power_state="power on", target_power_state=None, provision_state="deploying", target_provision_state="active" _log_ironic_polling /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:162
Apr 24 00:02:51 ironic-compute01.m0002.preprod-ord.ohthree.com 2015-04-24 00:02:50.398 9094 DEBUG nova.virt.ironic.driver [req-59c335d9-a84c-49c5-933b-d3b5b6b65cd0 a73e7267b25141fbb82975956598aebf 5956437 - - -] [instance: 9daa9c77-d801-4138-87b7-184c40cac6e5] Still waiting for ironic node 1ca7b231-554f-4561-beec-dda9852c2e4f to become ACTIVE: power_state="power on", target_power_state=None, provision_state="deploying", target_provision_state="active" _log_ironic_polling /opt/rackstack/rackstack.228.26/nova/lib/python2.7/site-packages/nova/virt/ironic/driver.py:162
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment