Error/Traceback during VM deletion; fail to delete VM

Bug #1414209 reported by Danny Choi
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
networking-cisco
Fix Committed
Undecided
Robert Pothier

Bug Description

Version: staging/junoplus + Rich's single thread locking mechanism + max_connections = 500 in mysql config

Issue: Error/Traceback during VM deletion; fail to delete VM; VM stuck in "error" state and cannot be deleted.

Setup: VXLAN multi-node
Nexus 9396PX-1: qa4 (controller + network + compute), qa5 (compute)
Nexus 9396PX-2: qa6 (compute)

Steps to repro:
1. Increase nova quota: #instances = 1000, #cores = 2000
2. Increase neutron quota: #port = 5000
3. In one shot, launch 100 VMs each with 2 network interfaces (to different subnets)
4. Notices error/traceback in logs: screen-n-cond.log, screen-n-cpu.log and screen-q-svc.log
5. Despite those errors/tracebacks, all 100VMs come up
6. In Horizon, delete the VMs (20 at a time)
7. Note the error/traceback in screen-q-svc.log and a few VM failed to be deleted.

Snippet of screen-n-cond.log during VM creation:

2015-01-23 16:10:21.800 ERROR nova.scheduler.utils [req-646a7155-6285-4864-a0be-59712359abda demo demo] [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] Error
 from last host: qa4 (node qa4): [u'Traceback (most recent call last):\n', u' File "/opt/stack/nova/nova/compute/manager.py", line 2030, in _do_build_and_run_instance\n filter_properties)\n', u'
File "/opt/stack/nova/nova/compute/manager.py", line 2161, in _build_and_run_instance\n instance_uuid=instance.uuid, reason=six.text_type(e))\n', u'RescheduledException: Build of instance ec9fd6a4-
0e30-4ec5-ac1b-398b8ff90064 was re-scheduled: Request Failed: internal server error while processing your request.\n']
2015-01-23 16:10:21.820 ERROR nova.scheduler.utils [req-646a7155-6285-4864-a0be-59712359abda demo demo] [instance: c2e15f8e-9700-4b05-90e1-d7a3e99a1514] Error
 from last host: qa6 (node qa6): [u'Traceback (most recent call last):\n', u' File "/opt/stack/nova/nova/compute/manager.py", line 2030, in _do_build_and_run_instance\n filter_properties)\n', u'
File "/opt/stack/nova/nova/compute/manager.py", line 2161, in _build_and_run_instance\n instance_uuid=instance.uuid, reason=six.text_type(e))\n', u'RescheduledException: Build of instance c2e15f8e-
9700-4b05-90e1-d7a3e99a1514 was re-scheduled: Request Failed: internal server error while processing your request.\n']
2015-01-23 16:10:22.415 ERROR nova.scheduler.utils [req-646a7155-6285-4864-a0be-59712359abda demo demo] [instance: 74cc6198-897d-49ba-b750-947a937b887b] Error
 from last host: qa5 (node qa5): [u'Traceback (most recent call last):\n', u' File "/opt/stack/nova/nova/compute/manager.py", line 2030, in _do_build_and_run_instance\n filter_properties)\n', u'
File "/opt/stack/nova/nova/compute/manager.py", line 2161, in _build_and_run_instance\n instance_uuid=instance.uuid, reason=six.text_type(e))\n', u'RescheduledException: Build of instance 74cc6198-
897d-49ba-b750-947a937b887b was re-scheduled: Request Failed: internal server error while processing your request.\n']

Snippet of screen-n-cpu.log during VM creation:

2015-01-23 16:10:21.545 ERROR nova.network.neutronv2.api [-] [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] Neutron error creating port on network 1b552f4b-5e15-43
34-87e2-9c8875d2013f
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] Traceback (most recent call last):
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/api.py", line 214, in _create
_port
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] port_id = port_client.create_port(port_req_body)['port']['id']
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wra
pper
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = obj(*args, **kwargs)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py"
, line 98, in with_params
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = self.function(instance, *args, **kwargs)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py"
, line 322, in create_port
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] return self.post(self.ports_path, body=body)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wra
pper
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = obj(*args, **kwargs)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py"
, line 1325, in post
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] headers=headers, params=params)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wra
pper
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = obj(*args, **kwargs)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py"
, line 1251, in do_request
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] self._handle_fault_response(status_code, replybody)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wra
pper
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = obj(*args, **kwargs)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py"
, line 1216, in _handle_fault_response
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] exception_handler_v20(status_code, des_error_body)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py"
, line 66, in exception_handler_v20
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] status_code=status_code)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] InternalServerError: Request Failed: internal server error while processing
your request.
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064]
2015-01-23 16:10:21.547 ERROR nova.compute.manager [-] Instance failed network setup after 1 attempt(s)
2015-01-23 16:10:21.547 TRACE nova.compute.manager Traceback (most recent call last):
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/compute/manager.py", line 1643, in _allocate_network_async
2015-01-23 16:10:21.547 TRACE nova.compute.manager dhcp_options=dhcp_options)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/network/neutronv2/api.py", line 443, in allocate_for_instance
2015-01-23 16:10:21.547 TRACE nova.compute.manager self._delete_ports(neutron, instance, created_port_ids)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/openstack/common/excutils.py", line 82, in __exit__
2015-01-23 16:10:21.547 TRACE nova.compute.manager six.reraise(self.type_, self.value, self.tb)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/network/neutronv2/api.py", line 423, in allocate_for_instance
2015-01-23 16:10:21.547 TRACE nova.compute.manager security_group_ids, available_macs, dhcp_opts)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/network/neutronv2/api.py", line 236, in _create_port
2015-01-23 16:10:21.547 TRACE nova.compute.manager network_id, instance=instance)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/openstack/common/excutils.py", line 82, in __exit__
2015-01-23 16:10:21.547 TRACE nova.compute.manager six.reraise(self.type_, self.value, self.tb)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/network/neutronv2/api.py", line 214, in _create_port
2015-01-23 16:10:21.547 TRACE nova.compute.manager port_id = port_client.create_port(port_req_body)['port']['id']
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
2015-01-23 16:10:21.547 TRACE nova.compute.manager ret = obj(*args, **kwargs)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 98, in with_params
2015-01-23 16:10:21.547 TRACE nova.compute.manager ret = self.function(instance, *args, **kwargs)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 322, in create_port
2015-01-23 16:10:21.547 TRACE nova.compute.manager return self.post(self.ports_path, body=body)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
2015-01-23 16:10:21.547 TRACE nova.compute.manager ret = obj(*args, **kwargs)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 1325, in post
2015-01-23 16:10:21.547 TRACE nova.compute.manager headers=headers, params=params)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
2015-01-23 16:10:21.547 TRACE nova.compute.manager ret = obj(*args, **kwargs)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 1251, in do_request
2015-01-23 16:10:21.547 TRACE nova.compute.manager self._handle_fault_response(status_code, replybody)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
2015-01-23 16:10:21.547 TRACE nova.compute.manager ret = obj(*args, **kwargs)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 1216, in _handle_fault_response
2015-01-23 16:10:21.547 TRACE nova.compute.manager exception_handler_v20(status_code, des_error_body)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 66, in exception_handler_v20
2015-01-23 16:10:21.547 TRACE nova.compute.manager status_code=status_code)
2015-01-23 16:10:21.547 TRACE nova.compute.manager InternalServerError: Request Failed: internal server error while processing your request.
2015-01-23 16:10:21.547 TRACE nova.compute.manager
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/poll.py", line 115, in wait
    listener.cb(fileno)
  File "/usr/local/lib/python2.7/dist-packages/eventlet/greenthread.py", line 212, in main
    result = function(*args, **kwargs)
  File "/opt/stack/nova/nova/compute/manager.py", line 1643, in _allocate_network_async
    dhcp_options=dhcp_options)
  File "/opt/stack/nova/nova/network/neutronv2/api.py", line 443, in allocate_for_instance
    self._delete_ports(neutron, instance, created_port_ids)
  File "/opt/stack/nova/nova/openstack/common/excutils.py", line 82, in __exit__
    six.reraise(self.type_, self.value, self.tb)
  File "/opt/stack/nova/nova/network/neutronv2/api.py", line 423, in allocate_for_instance
    security_group_ids, available_macs, dhcp_opts)
  File "/opt/stack/nova/nova/network/neutronv2/api.py", line 236, in _create_port
    network_id, instance=instance)
  File "/opt/stack/nova/nova/openstack/common/excutils.py", line 82, in __exit__
    six.reraise(self.type_, self.value, self.tb)
  File "/opt/stack/nova/nova/network/neutronv2/api.py", line 214, in _create_port
    port_id = port_client.create_port(port_req_body)['port']['id']
  File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
    ret = obj(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 98, in with_params
    ret = self.function(instance, *args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 322, in create_port
    return self.post(self.ports_path, body=body)
  File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
    ret = obj(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 1325, in post
    headers=headers, params=params)
  File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
    ret = obj(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 1251, in do_request
    self._handle_fault_response(status_code, replybody)
  File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
    ret = obj(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 1216, in _handle_fault_response
    exception_handler_v20(status_code, des_error_body)
  File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 66, in exception_handler_v20
    status_code=status_code)
InternalServerError: Request Failed: internal server error while processing your request.
Removing descriptor: 29
2015-01-23 16:10:21.549 ERROR nova.compute.manager [-] [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] Instance failed to spawn
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] Traceback (most recent call last):
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/compute/manager.py", line 2243, in _build_resources
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] yield resources
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/compute/manager.py", line 2113, in _build_and_run_ins
tance
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] block_device_info=block_device_info)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 2617, in spawn
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] admin_pass=admin_password)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 3078, in _create_image
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] content=files, extra_md=extra_md, network_info=network_info)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/api/metadata/base.py", line 168, in __init__
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ec2utils.get_ip_info_for_instance_from_nw_info(network_info)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/api/ec2/ec2utils.py", line 151, in get_ip_info_for_in
stance_from_nw_info
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] fixed_ips = nw_info.fixed_ips()
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/model.py", line 450, in _sync_wrapper
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] self.wait()
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/model.py", line 482, in wait
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] self[:] = self._gt.wait()
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/eventlet/greenthread.py", line 173,
 in wait
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] return self._exit_event.wait()
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/eventlet/event.py", line 121, in wa
it
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] return hubs.get_hub().switch()
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/hub.py", line 293, in
 switch
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] return self.greenlet.switch()
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/eventlet/greenthread.py", line 212,
 in main
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] result = function(*args, **kwargs)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/compute/manager.py", line 1643, in _allocate_network_
async
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] dhcp_options=dhcp_options)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/api.py", line 443, in allocate_for_
instance
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] self._delete_ports(neutron, instance, created_port_ids)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/openstack/common/excutils.py", line 82, in __exit__
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] six.reraise(self.type_, self.value, self.tb)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/api.py", line 423, in allocate_for_
instance
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] security_group_ids, available_macs, dhcp_opts)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/api.py", line 236, in _create_port
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] network_id, instance=instance)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/openstack/common/excutils.py", line 82, in __exit__
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] six.reraise(self.type_, self.value, self.tb)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/api.py", line 214, in _create_port
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] port_id = port_client.create_port(port_req_body)['port']['id']
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = obj(*args, **kwargs)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
 98, in with_params
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = self.function(instance, *args, **kwargs)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
 322, in create_port
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] return self.post(self.ports_path, body=body)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = obj(*args, **kwargs)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
 1325, in post
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] headers=headers, params=params)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = obj(*args, **kwargs)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
 1251, in do_request
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] self._handle_fault_response(status_code, replybody)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = obj(*args, **kwargs)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
 1216, in _handle_fault_response
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] exception_handler_v20(status_code, des_error_body)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
 66, in exception_handler_v20
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] status_code=status_code)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] InternalServerError: Request Failed: internal server error while processing your r
equest.

Snippet of screen-q-svc.log during VM creation:

2015-01-23 16:10:21.545 ERROR nova.network.neutronv2.api [-] [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] Neutron error creating port on network 1b552f4b-5e15-43
34-87e2-9c8875d2013f
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] Traceback (most recent call last):
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/api.py", line 214, in _create
_port
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] port_id = port_client.create_port(port_req_body)['port']['id']
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wra
pper
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = obj(*args, **kwargs)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py"
, line 98, in with_params
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = self.function(instance, *args, **kwargs)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py"
, line 322, in create_port
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] return self.post(self.ports_path, body=body)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wra
pper
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = obj(*args, **kwargs)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py"
, line 1325, in post
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] headers=headers, params=params)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wra
pper
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = obj(*args, **kwargs)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py"
, line 1251, in do_request
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] self._handle_fault_response(status_code, replybody)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wra
pper
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = obj(*args, **kwargs)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py"
, line 1216, in _handle_fault_response
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] exception_handler_v20(status_code, des_error_body)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py"
, line 66, in exception_handler_v20
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] status_code=status_code)
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] InternalServerError: Request Failed: internal server error while processing
your request.
2015-01-23 16:10:21.545 TRACE nova.network.neutronv2.api [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064]
2015-01-23 16:10:21.547 ERROR nova.compute.manager [-] Instance failed network setup after 1 attempt(s)
2015-01-23 16:10:21.547 TRACE nova.compute.manager Traceback (most recent call last):
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/compute/manager.py", line 1643, in _allocate_network_async
2015-01-23 16:10:21.547 TRACE nova.compute.manager dhcp_options=dhcp_options)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/network/neutronv2/api.py", line 443, in allocate_for_instance
2015-01-23 16:10:21.547 TRACE nova.compute.manager self._delete_ports(neutron, instance, created_port_ids)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/openstack/common/excutils.py", line 82, in __exit__
2015-01-23 16:10:21.547 TRACE nova.compute.manager six.reraise(self.type_, self.value, self.tb)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/network/neutronv2/api.py", line 423, in allocate_for_instance
2015-01-23 16:10:21.547 TRACE nova.compute.manager security_group_ids, available_macs, dhcp_opts)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/network/neutronv2/api.py", line 236, in _create_port
2015-01-23 16:10:21.547 TRACE nova.compute.manager network_id, instance=instance)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/openstack/common/excutils.py", line 82, in __exit__
2015-01-23 16:10:21.547 TRACE nova.compute.manager six.reraise(self.type_, self.value, self.tb)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/network/neutronv2/api.py", line 214, in _create_port
2015-01-23 16:10:21.547 TRACE nova.compute.manager port_id = port_client.create_port(port_req_body)['port']['id']
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
2015-01-23 16:10:21.547 TRACE nova.compute.manager ret = obj(*args, **kwargs)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 98, in with_params
2015-01-23 16:10:21.547 TRACE nova.compute.manager ret = self.function(instance, *args, **kwargs)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 322, in create_port
2015-01-23 16:10:21.547 TRACE nova.compute.manager return self.post(self.ports_path, body=body)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
2015-01-23 16:10:21.547 TRACE nova.compute.manager ret = obj(*args, **kwargs)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 1325, in post
2015-01-23 16:10:21.547 TRACE nova.compute.manager headers=headers, params=params)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
2015-01-23 16:10:21.547 TRACE nova.compute.manager ret = obj(*args, **kwargs)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 1251, in do_request
2015-01-23 16:10:21.547 TRACE nova.compute.manager self._handle_fault_response(status_code, replybody)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
2015-01-23 16:10:21.547 TRACE nova.compute.manager ret = obj(*args, **kwargs)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 1216, in _handle_fault_response
2015-01-23 16:10:21.547 TRACE nova.compute.manager exception_handler_v20(status_code, des_error_body)
2015-01-23 16:10:21.547 TRACE nova.compute.manager File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 66, in exception_handler_v20
2015-01-23 16:10:21.547 TRACE nova.compute.manager status_code=status_code)
2015-01-23 16:10:21.547 TRACE nova.compute.manager InternalServerError: Request Failed: internal server error while processing your request.
2015-01-23 16:10:21.547 TRACE nova.compute.manager
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/poll.py", line 115, in wait
    listener.cb(fileno)
  File "/usr/local/lib/python2.7/dist-packages/eventlet/greenthread.py", line 212, in main
    result = function(*args, **kwargs)
  File "/opt/stack/nova/nova/compute/manager.py", line 1643, in _allocate_network_async
    dhcp_options=dhcp_options)
  File "/opt/stack/nova/nova/network/neutronv2/api.py", line 443, in allocate_for_instance
    self._delete_ports(neutron, instance, created_port_ids)
  File "/opt/stack/nova/nova/openstack/common/excutils.py", line 82, in __exit__
    six.reraise(self.type_, self.value, self.tb)
  File "/opt/stack/nova/nova/network/neutronv2/api.py", line 423, in allocate_for_instance
    security_group_ids, available_macs, dhcp_opts)
  File "/opt/stack/nova/nova/network/neutronv2/api.py", line 236, in _create_port
    network_id, instance=instance)
  File "/opt/stack/nova/nova/openstack/common/excutils.py", line 82, in __exit__
    six.reraise(self.type_, self.value, self.tb)
  File "/opt/stack/nova/nova/network/neutronv2/api.py", line 214, in _create_port
    port_id = port_client.create_port(port_req_body)['port']['id']
  File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
    ret = obj(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 98, in with_params
    ret = self.function(instance, *args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 322, in create_port
    return self.post(self.ports_path, body=body)
  File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
    ret = obj(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 1325, in post
    headers=headers, params=params)
  File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
    ret = obj(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 1251, in do_request
    self._handle_fault_response(status_code, replybody)
  File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
    ret = obj(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 1216, in _handle_fault_response
    exception_handler_v20(status_code, des_error_body)
  File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 66, in exception_handler_v20
    status_code=status_code)
InternalServerError: Request Failed: internal server error while processing your request.
Removing descriptor: 29
2015-01-23 16:10:21.549 ERROR nova.compute.manager [-] [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] Instance failed to spawn
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] Traceback (most recent call last):
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/compute/manager.py", line 2243, in _build_resources
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] yield resources
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/compute/manager.py", line 2113, in _build_and_run_ins
tance
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] block_device_info=block_device_info)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 2617, in spawn
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] admin_pass=admin_password)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 3078, in _create_image
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] content=files, extra_md=extra_md, network_info=network_info)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/api/metadata/base.py", line 168, in __init__
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ec2utils.get_ip_info_for_instance_from_nw_info(network_info)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/api/ec2/ec2utils.py", line 151, in get_ip_info_for_in
stance_from_nw_info
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] fixed_ips = nw_info.fixed_ips()
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/model.py", line 450, in _sync_wrapper
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] self.wait()
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/model.py", line 482, in wait
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] self[:] = self._gt.wait()
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/eventlet/greenthread.py", line 173,
 in wait
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] return self._exit_event.wait()
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/eventlet/event.py", line 121, in wa
it
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] return hubs.get_hub().switch()
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/hub.py", line 293, in
 switch
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] return self.greenlet.switch()
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/eventlet/greenthread.py", line 212,
 in main
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] result = function(*args, **kwargs)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/compute/manager.py", line 1643, in _allocate_network_
async
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] dhcp_options=dhcp_options)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/api.py", line 443, in allocate_for_
instance
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] self._delete_ports(neutron, instance, created_port_ids)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/openstack/common/excutils.py", line 82, in __exit__
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] six.reraise(self.type_, self.value, self.tb)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/api.py", line 423, in allocate_for_
instance
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] security_group_ids, available_macs, dhcp_opts)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/api.py", line 236, in _create_port
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] network_id, instance=instance)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/openstack/common/excutils.py", line 82, in __exit__
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] six.reraise(self.type_, self.value, self.tb)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/api.py", line 214, in _create_port
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] port_id = port_client.create_port(port_req_body)['port']['id']
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = obj(*args, **kwargs)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
 98, in with_params
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = self.function(instance, *args, **kwargs)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
 322, in create_port
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] return self.post(self.ports_path, body=body)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = obj(*args, **kwargs)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
 1325, in post
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] headers=headers, params=params)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = obj(*args, **kwargs)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
 1251, in do_request
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] self._handle_fault_response(status_code, replybody)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/opt/stack/nova/nova/network/neutronv2/__init__.py", line 84, in wrapper
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] ret = obj(*args, **kwargs)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
 1216, in _handle_fault_response
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] exception_handler_v20(status_code, des_error_body)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] File "/usr/local/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
 66, in exception_handler_v20
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] status_code=status_code)
2015-01-23 16:10:21.549 TRACE nova.compute.manager [instance: ec9fd6a4-0e30-4ec5-ac1b-398b8ff90064] InternalServerError: Request Failed: internal server error while processing your r
equest.

Snippet of screen-q-svc.log during VM deletion:

2015-01-23 16:29:33.763 ERROR neutron.plugins.ml2.managers [req-857ee67e-55ea-4a8f-a457-8ecc53f9b4ff admin a49ff033cb5a4f5a87ba1dcfb645c5bc] Mechanism driver
'cisco_nexus' failed in delete_port_precommit
2015-01-23 16:29:33.763 TRACE neutron.plugins.ml2.managers Traceback (most recent call last):
2015-01-23 16:29:33.763 TRACE neutron.plugins.ml2.managers File "/opt/stack/neutron/neutron/plugins/ml2/managers.py", line 299, in _call_on_drivers
2015-01-23 16:29:33.763 TRACE neutron.plugins.ml2.managers getattr(driver.obj, method_name)(context)
2015-01-23 16:29:33.763 TRACE neutron.plugins.ml2.managers File "/opt/stack/neutron/neutron/openstack/common/lockutils.py", line 272, in inner
2015-01-23 16:29:33.763 TRACE neutron.plugins.ml2.managers return f(*args, **kwargs)
2015-01-23 16:29:33.763 TRACE neutron.plugins.ml2.managers File "/opt/stack/neutron/neutron/plugins/ml2/drivers/cisco/nexus/mech_cisco_nexus.py", line 395, in delete_port_precommit

2015-01-23 16:29:33.763 TRACE neutron.plugins.ml2.managers self._delete_nxos_db, vni)
2015-01-23 16:29:33.763 TRACE neutron.plugins.ml2.managers File "/opt/stack/neutron/neutron/plugins/ml2/drivers/cisco/nexus/mech_cisco_nexus.py", line 308, in _port_action_vlan
2015-01-23 16:29:33.763 TRACE neutron.plugins.ml2.managers is_provider_vlan = segment.get(api.PROVIDER_SEGMENT)
2015-01-23 16:29:33.763 TRACE neutron.plugins.ml2.managers AttributeError: 'NoneType' object has no attribute 'get'
2015-01-23 16:29:33.763 TRACE neutron.plugins.ml2.managers
2015-01-23 16:29:33.764 DEBUG neutron.openstack.common.lockutils [req-857ee67e-55ea-4a8f-a457-8ecc53f9b4ff admin a49ff033cb5a4f5a87ba1dcfb645c5bc] Releasing s
emaphore "db-access" from (pid=4895) lock /opt/stack/neutron/neutron/openstack/common/lockutils.py:238
2015-01-23 16:29:33.764 ERROR neutron.api.v2.resource [req-857ee67e-55ea-4a8f-a457-8ecc53f9b4ff admin a49ff033cb5a4f5a87ba1dcfb645c5bc] delete failed
2015-01-23 16:29:33.764 TRACE neutron.api.v2.resource Traceback (most recent call last):
2015-01-23 16:29:33.764 TRACE neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/v2/resource.py", line 81, in resource
2015-01-23 16:29:33.764 TRACE neutron.api.v2.resource result = method(request=request, **args)
2015-01-23 16:29:33.764 TRACE neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/v2/base.py", line 476, in delete
2015-01-23 16:29:33.764 TRACE neutron.api.v2.resource obj_deleter(request.context, id, **kwargs)
2015-01-23 16:29:33.764 TRACE neutron.api.v2.resource File "/opt/stack/neutron/neutron/plugins/ml2/plugin.py", line 1049, in delete_port
2015-01-23 16:29:33.764 TRACE neutron.api.v2.resource self.mechanism_manager.delete_port_precommit(mech_context)
2015-01-23 16:29:33.764 TRACE neutron.api.v2.resource File "/opt/stack/neutron/neutron/plugins/ml2/managers.py", line 548, in delete_port_precommit
2015-01-23 16:29:33.764 TRACE neutron.api.v2.resource self._call_on_drivers("delete_port_precommit", context)
2015-01-23 16:29:33.764 TRACE neutron.api.v2.resource File "/opt/stack/neutron/neutron/plugins/ml2/managers.py", line 310, in _call_on_drivers
2015-01-23 16:29:33.764 TRACE neutron.api.v2.resource method=method_name
2015-01-23 16:29:33.764 TRACE neutron.api.v2.resource MechanismDriverError: delete_port_precommit failed.
2015-01-23 16:29:33.764 TRACE neutron.api.v2.resource

Tags: nexus
Changed in networking-cisco:
assignee: nobody → Robert Pothier (rpothier)
Changed in networking-cisco:
status: New → In Progress
Revision history for this message
Danny Choi (dannchoi) wrote :

Able to verify the fix.

2015-01-29 19:15:01.696 DEBUG neutron.plugins.ml2.drivers.cisco.nexus.mech_cisco_nexus [req-7bfe5450-37d8-4ef9-b576-e141949cf4b9 admin d43952dbd9e2454680ae028d3c7bc379] Nexus: Missing Required Fields is_provider vlan_id from (pid=1041) _port_action_vlan /opt/stack/neutron/neutron/plugins/ml2/drivers/cisco/nexus/mech_cisco_nexus.py:328

The "error" state VM is deleted successfully.

Henry Gessau (gessau)
tags: added: nexus
Changed in networking-cisco:
status: In Progress → Fix Committed
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.