← Back to team overview

yahoo-eng-team team mailing list archive

[Bug 1282841] Re: Cannot spawn VMs when using ML2 ODL

 

[Expired for neutron because there has been no activity for 60 days.]

** Changed in: neutron
       Status: Incomplete => Expired

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/1282841

Title:
  Cannot spawn VMs when using ML2 ODL

Status in OpenStack Neutron (virtual network service):
  Expired

Bug description:
  When testing out the latest ODL (Opendaylight) and Openstack
  integration, I'm not able to spawn VMs. I see different traces when I
  attempt to spawn VMs on different compute nodes. The traces are pasted
  below:

  
  When trying to create a VM on the controller node doubling up as a compute node:

  
  2014-02-19 09:19:24.892 39653 DEBUG oslo.messaging._drivers.amqp [-] UNIQUE_ID is 6ede9d9d237447c3b5fe0007d1237497. _add_unique_id /opt/stack/oslo.messaging/oslo/messaging/_drivers/amqp.py:333
  2014-02-19 09:19:24.894 ERROR nova.compute.manager [req-764e4d40-902f-42ff-995e-548c9ce7c96c admin demo] [instance: 36df418b-699b-4d94-a6a5-fa138399845f] Error: 500-{u'NeutronError': {u'message': u'create
  _port_postcommit failed.', u'type': u'MechanismDriverError', u'detail': u''}}
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f] Traceback (most recent call last):
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/nova/nova/compute/manager.py", line 1070, in _build_instance
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     set_access_ip=set_access_ip)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/nova/nova/compute/manager.py", line 357, in decorated_function
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     return function(self, context, *args, **kwargs)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/nova/nova/compute/manager.py", line 1478, in _spawn
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     LOG.exception(_('Instance failed to spawn'), instance=instance)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/nova/nova/openstack/common/excutils.py", line 68, in __exit__
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     six.reraise(self.type_, self.value, self.tb)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/nova/nova/compute/manager.py", line 1475, in _spawn
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     block_device_info)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 2207, in spawn
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     admin_pass=admin_password)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 2572, in _create_image
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     content=files, extra_md=extra_md, network_info=network_info)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/nova/nova/api/metadata/base.py", line 163, in __init__
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     ec2utils.get_ip_info_for_instance_from_nw_info(network_info)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/nova/nova/api/ec2/ec2utils.py", line 147, in get_ip_info_for_instance_from_nw_info
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     fixed_ips = nw_info.fixed_ips()
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/nova/nova/network/model.py", line 366, in _sync_wrapper
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     self.wait()
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/nova/nova/network/model.py", line 398, in wait
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     self[:] = self._gt.wait()
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/usr/lib/python2.7/dist-packages/eventlet/greenthread.py", line 168, in wait
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     return self._exit_event.wait()
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/usr/lib/python2.7/dist-packages/eventlet/event.py", line 120, in wait
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     current.throw(*self._exc)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/usr/lib/python2.7/dist-packages/eventlet/greenthread.py", line 194, in main
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     result = function(*args, **kwargs)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/nova/nova/compute/manager.py", line 1256, in _allocate_network_async
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     dhcp_options=dhcp_options)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/nova/nova/network/neutronv2/api.py", line 342, in allocate_for_instance
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     LOG.exception(msg, port_id)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/nova/nova/openstack/common/excutils.py", line 68, in __exit__
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     six.reraise(self.type_, self.value, self.tb)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/nova/nova/network/neutronv2/api.py", line 319, in allocate_for_instance
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     security_group_ids, available_macs, dhcp_opts))
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/nova/nova/network/neutronv2/api.py", line 170, in _create_port
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     port_id = port_client.create_port(port_req_body)['port']['id']
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/python-neutronclient/neutronclient/v2_0/client.py", line 111, in with_params
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     ret = self.function(instance, *args, **kwargs)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/python-neutronclient/neutronclient/v2_0/client.py", line 316, in create_port
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     return self.post(self.ports_path, body=body)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/python-neutronclient/neutronclient/v2_0/client.py", line 1241, in post
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     headers=headers, params=params)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/python-neutronclient/neutronclient/v2_0/client.py", line 1164, in do_request
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     self._handle_fault_response(status_code, replybody)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/python-neutronclient/neutronclient/v2_0/client.py", line 1134, in _handle_fault_response
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     exception_handler_v20(status_code, des_error_body)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]   File "/opt/stack/python-neutronclient/neutronclient/v2_0/client.py", line 96, in exception_handler_v20
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]     message=msg)
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f] NeutronClientException: 500-{u'NeutronError': {u'message': u'create_port_postcommit failed.', u'type': u'MechanismDriverError', u'detail': u''}}
  2014-02-19 09:19:24.894 39653 TRACE nova.compute.manager [instance: 36df418b-699b-4d94-a6a5-fa138399845f]
  2014-02-19 09:19:24.896 DEBUG nova.openstack.common.lockutils [req-764e4d40-902f-42ff-995e-548c9ce7c96c admin demo] Semaphore / lock released "do_run_instance" inner /opt/stack/nova/nova/openstack/common/lockutils.py:252
  2014-02-19 09:19:24.896 39653 DEBUG oslo.messaging._drivers.amqpdriver [-] MSG_ID is 81630975aa834823ac19106ac8af13e0 _send /opt/stack/oslo.messaging/oslo/messaging/_drivers/amqpdriver.py:361
  2014-02-19 09:19:24.896 39653 DEBUG oslo.messaging._drivers.amqp [-] UNIQUE_ID is 0661781a14f6487ab8c5aa8fb515653e. _add_unique_id /opt/stack/oslo.messaging/oslo/messaging/_drivers/amqp.py:333
  2014-02-19 09:19:24.908 39653 DEBUG oslo.messaging._drivers.amqp [-] UNIQUE_ID is 36c5e21ec5224728b62b4f28865f7a58. _add_unique_id /opt/stack/oslo.messaging/oslo/messaging/_drivers/amqp.py:333
  2014-02-19 09:19:24.908 39653 DEBUG oslo.messaging._drivers.amqp [-] UNIQUE_ID is 4aa99e4317d94c549f1c97a4548c0423. _add_unique_id /opt/stack/oslo.messaging/oslo/messaging/_drivers/amqp.py:333
  2014-02-19 09:19:34.422 39653 DEBUG oslo.messaging._drivers.amqpdriver [-] MSG_ID is 40369d4d8e2c4c4b8edf3334146528ae _send /opt/stack/oslo.messaging/oslo/messaging/_drivers/amqpdriver.py:361
  2014-02-19 09:19:34.422 39653 DEBUG oslo.messaging._drivers.amqp [-] UNIQUE_ID is 36c130e867a14953a0e25106e0b958bb. _add_unique_id /opt/stack/oslo.messaging/oslo/messaging/_drivers/amqp.py:333
  2014-02-19 09:19:44.422 39653 DEBUG oslo.messaging._drivers.amqpdriver [-] MSG_ID is 110ee0a95904403b934c17873332df46 _send /opt/stack/oslo.messaging/oslo/messaging/_drivers/amqpdriver.py:361
  2014-02-19 09:19:44.422 39653 DEBUG oslo.messaging._drivers.amqp [-] UNIQUE_ID is 8174211ed6b54175b74423e2f550c872. _add_unique_id /opt/stack/oslo.messaging/oslo/messaging/_drivers/amqp.py:333
  2014-02-19 09:19:44.480 39653 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /opt/stack/nova/nova/openstack/common/periodic_task.py:178


  When trying to create a VM on a second compute node:


  
  2014-02-19 09:25:17.770 28205 DEBUG oslo.messaging._drivers.amqp [-] unpacked context: {'project_name': u'admin', 'user_id': u'0ffe610c7eda490e997d37cd46c77f6c', 'roles': [u'admin'], 'timestamp': u'2014-02-19T17:25:17.499844', 'auth_token': '<SANITIZED>', 'remote_address': u'192.168.216.50', 'quota_class': None, 'is_admin': True, 'tenant': u'414e5c7207374f8ca180bd88d97c06c6', 'service_catalog': [{u'endpoints_links': [], u'endpoints': [{u'adminURL': u'http://192.168.216.50:8776/v1/414e5c7207374f8ca180bd88d97c06c6', u'region': u'RegionOne', u'publicURL': u'http://192.168.216.50:8776/v1/414e5c7207374f8ca180bd88d97c06c6', u'internalURL': u'http://192.168.216.50:8776/v1/414e5c7207374f8ca180bd88d97c06c6', u'id': u'1ddd4e4de0184f76b1b12a3a317658b4'}], u'type': u'volume', u'name': u'cinder'}], 'request_id': u'req
  -d3cd0692-0871-40f4-9117-b2f5ca17c042', 'instance_lock_checked': False, 'project_id': u'414e5c7207374f8ca180bd88d97c06c6', 'user_name': u'admin', 'read_deleted': u'no', 'user': u'0ffe610c7eda490e997d37cd46c77f6c'} _safe_log /opt/stack/oslo.messaging/oslo/messaging/_drivers/common.py:289
  2014-02-19 09:25:17.772 AUDIT nova.compute.manager [req-d3cd0692-0871-40f4-9117-b2f5ca17c042 admin admin] [instance: 5eb053ec-03f0-4aa7-8fc7-e678ed262bc2] Get console output
  2014-02-19 09:25:17.773 28205 ERROR oslo.messaging.rpc.dispatcher [-] Exception during message handling: Instance instance-00000003 could not be found.
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 133, in _dispatch_and_reply
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher     incoming.message))
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher     return self._do_dispatch(endpoint, method, ctxt, args)
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher     result = getattr(endpoint, method)(ctxt, **new_args)
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/oslo.messaging/oslo/messaging/rpc/server.py", line 139, in inner
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher     return func(*args, **kwargs)
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/exception.py", line 88, in wrapped
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher     payload)
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/openstack/common/excutils.py", line 68, in __exit__
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/exception.py", line 71, in wrapped
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher     return f(self, context, *args, **kw)
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/compute/manager.py", line 256, in decorated_function
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/compute/manager.py", line 3670, in get_console_output
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher     output = self.driver.get_console_output(context, instance)
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 2245, in get_console_output
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher     virt_dom = self._lookup_by_name(instance.name)
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 3369, in _lookup_by_name
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher     raise exception.InstanceNotFound(instance_id=instance_name)
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher InstanceNotFound: Instance instance-00000003 could not be found.
  2014-02-19 09:25:17.773 28205 TRACE oslo.messaging.rpc.dispatcher
  2014-02-19 09:25:17.776 28205 ERROR oslo.messaging._drivers.common [-] Returning exception Instance instance-00000003 could not be found. to caller
  2014-02-19 09:25:17.776 28205 ERROR oslo.messaging._drivers.common [-] ['Traceback (most recent call last):\n', '  File "/opt/stack/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 133, in _dispatch_and_reply\n    incoming.message))\n', '  File "/opt/stack/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch\n    return self._do_dispatch(endpoint, method, ctxt, args)\n', '  File "/opt/stack/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch\n    result = getattr(endpoint, method)(ctxt, **new_args)\n', '  File "/opt/stack/oslo.messaging/oslo/messaging/rpc/server.py", line 139, in inner\n    return func(*args, **kwargs)\n', '  File "/opt/stack/nova/nova/exception.py", line 88, in wrapped\n    payload)\n', '  File "/opt/stack/nova/nova/openstack/common/excutils.py", line 68, in __exit__\n    six.reraise(self.type_, self.value, self.tb)\n', '  File "/opt/stack/nova/nova/exception.py", line 71, in wrapped\n    return f(self, context, *args, **kw)\n', '  File "/opt/stack/nova/nova/compute/manager.py", line 256, in decorated_function\n    return function(self, context, *args, **kwargs)\n', '  File "/opt/stack/nova/nova/compute/manager.py", line 3670, in get_console_output\n    output = self.driver.get_console_output(context, instance)\n', '  File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 2245, in get_console_output\n    virt_dom = self._lookup_by_name(
  instance.name)\n', '  File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 3369, in _lookup_by_name\n    raise exception.InstanceNotFound(instance_id=instance_name)\n', 'InstanceNotFound: Instance ins
  tance-00000003 could not be found.\n']


  For the steps to reproduce this, do the following:

  1. Install Ubuntu 13.10, install git/maven/openvswitch-switch/pip related packages and so on, whatever is required for devstack and ODL. Do *not* install mysql-server - allow devstack to do that for you, else you will run into a lot of issues with mysql. Create two such VMs, one intended to run as ctrl and the other as compute.
  2. Install and run ODL with Openflow 1.3 as per the instructions given on the ODL wiki.
  3. Run devstack to bring up both control and compute nodes. Attempt to spawn VMs, and see if you hit the above exception.

  For instructions on setting up devstack with ODL, look at Kyle's
  blogpost:

  http://www.siliconloons.com/?p=523

To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/1282841/+subscriptions


References