yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1578734] Re: Instance Creation fails because of Timeout and Duplicate Hostname for Bindings on NSX Edge (DHCP)

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Matt Riedemann <mriedem@xxxxxxxxxx>
Date: Sat, 14 May 2016 15:57:53 -0000
Reply-to: Bug 1578734 <1578734@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Tags added: neutron vmware

** Also affects: vmware-nsx
   Importance: Undecided
       Status: New

** Changed in: nova
       Status: New => Invalid

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1578734

Title:
  Instance Creation fails because of Timeout and Duplicate Hostname for
  Bindings on NSX Edge (DHCP)

Status in OpenStack Compute (nova):
  Invalid
Status in vmware-nsx:
  New

Bug description:
  Using Openstack Liberty with VMware Driver / NSX Integration.

  When deploying a Template with Heat (3 Instances, with 3 Security Groups, own Network)
  The creation failes with an Error: no Hosts available.

  But the main reason is a Timeout that occures between nova and neutron.
  See the logs below.

  For me it seems that Nova creates with Neutron a new Port in NSX
  (Create DHCP reservation) , this times out, but the port gets created.

  2016-05-05 15:53:33.165 8705 ERROR nova.compute.manager [instance: 6129429c-803b-47bb-a5cd-afb0419e2a12] RequestTimeout: Request to http://172.17.99.211:9696/v2.0/ports/4832456a-c007-4c06-bcbe-718cf9346a93.json timed out (HTTP 408)
  29c-803b-47bb-a5cd-afb0419e2a12] Error from last host: vcenter-MirantisLiberty (node domain-c197.11160f6a-be80-4025-a0be-b915de612a16): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/dist-packages/nova/compu
  te/manager.py", line 1907, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 2059, in _build_and_run_instance\n    instance_uuid=instance.uuid, reaso
  n=six.text_type(e))\n', u'RescheduledException: Build of instance 6129429c-803b-47bb-a5cd-afb0419e2a12 was re-scheduled: Request to http://172.17.99.211:9696/v2.0/ports/4832456a-c007-4c06-bcbe-718cf9346a93.json timed out (HTTP 408)
  \n']

  I can see, that the Edge DHCP, that has been created with HEAT,  has
  also created a reservation for this machine.

  Then, as the instance creation is rescheduled, it tries again to
  create that port but fails, as the port is alredy configured on the
  Edge:

  
  2016-05-05 15:54:51.191 8705 ERROR nova.compute.manager [instance: 18c9db8e-1a89-4ac6-a432-3ca75e92dbf2] InternalServerError: Request https://172.17.99.8/api/4.0/edges/edge-115/dhcp/config/bindings is Bad, response {"details":"[Dhcp] Duplicate hostname for binding 4832456a-c007-4c06-bcbe-718cf9346a93 : VmId null and VnicId null.","errorCode":12504,"moduleName":"vShield Edge"}

  
  The environment consists of following:

  Vsphere Version: 6.0.2
  Openstack Liberty (Deployed from Mirantis)
  There is only one Controller which includes all the Parts of Openstack (Nova, Neutron, Cinder, Glance, Horizon)

  Thanks for any help to solve the Problem.


  Here are Logs in Detail:

  
  83a2-445a-b43a-4a0b59b8e3f5] Claim successful
  <179>May  5 15:53:44 node-3 nova-compute: 2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager [-] Instance failed network setup after 1 attempt(s)
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager Traceback (most recent call last):
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 1566, in _allocate_network_async
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager     bind_host_id=bind_host_id)
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py", line 727, in allocate_for_instance
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager     self._delete_ports(neutron, instance, created_port_ids)
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 195, in __exit__
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager     six.reraise(self.type_, self.value, self.tb)
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py", line 712, in allocate_for_instance
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager     port_client.update_port(port['id'], port_req_body)
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 102, in with_params
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager     ret = self.function(instance, *args, **kwargs)
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 562, in update_port
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager     return self.put(self.port_path % (port), body=body)
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 302, in put
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager     headers=headers, params=params)
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 270, in retry_request
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager     headers=headers, params=params)
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 211, in do_request
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager     self._handle_fault_response(status_code, replybody)
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 185, in _handle_fault_response
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager     exception_handler_v20(status_code, des_error_body)
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 70, in exception_handler_v20
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager     status_code=status_code)
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager InternalServerError: Request https://172.17.99.8/api/4.0/edges/edge-115/dhcp/config/bindings is Bad, response {"details":"[Dhcp] Duplicate hostname for binding 4832456a-c007-4c06-bcbe-718cf9346a93 : VmId null and VnicId null.","errorCode":12504,"moduleName":"vShield Edge"}
  2016-05-05 15:53:44.592 8705 ERROR nova.compute.manager
  <182>May  5 15:53:44 node-3 nova-api: 2016-05-05 15:53:44.708 6386 INFO nova.osapi_compute.wsgi.server [req-7de220d2-3ddb-429a-8429-1c5e2eb7516b 02d474c44fb44732a2fa1032e2634e9b aac24994050a4252b3d7a2450b8ca6cf - - -] 172.17.99.211 "GET /v2/aac24994050a4252b3d7a2450b8ca6cf/servers/52366566-19ca-455a-91e0-563781ade687 HTTP/1.1" status: 200 len: 2051 time: 0.1466730
  <179>May  5 15:53:44 node-3 nova-compute: 2016-05-05 15:53:44.731 8705 ERROR nova.compute.manager [req-e3108c74-9e5d-4a26-9383-54f3e4bc8b2c 02d474c44fb44732a2fa1032e2634e9b aac24994050a4252b3d7a2450b8ca6cf - - -] [instance: cde38026-83a2-445a-b43a-4a0b59b8e3f5] Instance failed to spawn

  
  <182>May  5 15:53:32 node-3 nova-compute: 2016-05-05 15:53:32.482 8705 INFO nova.compute.resource_tracker [req-c3485140-d059-4a25-a466-1a2fd7d4af14 - - - - -] Compute_service record updated for vcenter-MirantisLiberty:domain-c197.1
  1160f6a-be80-4025-a0be-b915de612a16
  <179>May  5 15:53:33 node-3 nova-compute: 2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager [-] Instance failed network setup after 1 attempt(s)
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager Traceback (most recent call last):
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 1566, in _allocate_network_async
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager     bind_host_id=bind_host_id)
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py", line 727, in allocate_for_instance
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager     self._delete_ports(neutron, instance, created_port_ids)
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 195, in __exit__
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager     six.reraise(self.type_, self.value, self.tb)
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/nova/network/neutronv2/api.py", line 712, in allocate_for_instance
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager     port_client.update_port(port['id'], port_req_body)
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 102, in with_params
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager     ret = self.function(instance, *args, **kwargs)
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 562, in update_port
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager     return self.put(self.port_path % (port), body=body)
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 302, in put
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager     headers=headers, params=params)
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 270, in retry_request
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager     headers=headers, params=params)
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line 200, in do_request
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager     content_type=self.content_type())
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/neutronclient/client.py", line 306, in do_request
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager     return self.request(url, method, **kwargs)
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/neutronclient/client.py", line 294, in request
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager     resp = super(SessionClient, self).request(*args, **kwargs)
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/keystoneclient/adapter.py", line 95, in request
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager     return self.session.request(url, method, **kwargs)
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/keystoneclient/utils.py", line 337, in inner
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager     return func(*args, **kwargs)
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/keystoneclient/session.py", line 386, in request
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager     resp = send(**kwargs)
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager   File "/usr/lib/python2.7/dist-packages/keystoneclient/session.py", line 427, in _send_request
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager     raise exceptions.RequestTimeout(msg)
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager RequestTimeout: Request to http://172.17.99.211:9696/v2.0/ports/4832456a-c007-4c06-bcbe-718cf9346a93.json timed out (HTTP 408)
  2016-05-05 15:53:33.162 8705 ERROR nova.compute.manager
  <179>May  5 15:53:33 node-3 nova-compute: 2016-05-05 15:53:33.165 8705 ERROR nova.compute.manager [req-735f9ded-dec2-4302-8e58-2fc8f58a1cec 02d474c44fb44732a2fa1032e2634e9b aac24994050a4252b3d7a2450b8ca6cf - - -] [instance: 6129429
  c-803b-47bb-a5cd-afb0419e2a12] Instance failed to spawn

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1578734/+subscriptions
References

[Bug 1578734] [NEW] Instance Creation fails because of Timeout and Duplicate Settings on NSX Edge (DHCP)
From: Daniel Weber, 2016-05-05