yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1316365] [NEW] NSX: stacktrace during port creation

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Armando Migliaccio <1316365@xxxxxxxxxxxxxxxxxx>
Date: Tue, 06 May 2014 00:17:48 -0000
Reply-to: Bug 1316365 <1316365@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

When using NSX-DHCP the following stack trace can be caused if a port is
created with a non-empty device id, on a subnet with disabled dhcp
services:

2014-05-05 17:12:22.099 18224 DEBUG neutron.openstack.common.rpc.amqp [req-06840c8e-e091-4627-b221-5faeecd1402f None] Sending port.create.start on notifications.info notify /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:622
2014-05-05 17:12:22.099 18224 DEBUG neutron.openstack.common.rpc.amqp [req-06840c8e-e091-4627-b221-5faeecd1402f None] UNIQUE_ID is 64e9e5271fae43a9b5e195ba697eed19. _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342
2014-05-05 17:12:22.105 18224 DEBUG neutron.api.v2.base [req-06840c8e-e091-4627-b221-5faeecd1402f None] Request body: {u'port': {u'binding:host_id': u'cidevstack', u'admin_state_up': True, u'network_id': u'3e47abe7-610f-4816-9263-25126996c0bd', u't
enant_id': u'e9f4059f41534834b6edcb9280caa6af', u'device_owner': u'compute:None', u'rxtx_factor': 1.0, u'security_groups': [u'9fdac141-4d02-48d9-b9cf-7d50cdd272e9'], u'device_id': u'ce873c29-ed36-486b-a560-a615685848df'}} prepare_request_body /opt/
stack/neutron/neutron/api/v2/base.py:561
2014-05-05 17:12:22.148 18224 DEBUG neutron.db.db_base_plugin_v2 [req-06840c8e-e091-4627-b221-5faeecd1402f None] Generated mac for network 3e47abe7-610f-4816-9263-25126996c0bd is fa:16:3e:f0:cf:9b _generate_mac /opt/stack/neutron/neutron/db/db_base
_plugin_v2.py:308
2014-05-05 17:12:22.165 18224 DEBUG neutron.db.db_base_plugin_v2 [req-06840c8e-e091-4627-b221-5faeecd1402f None] Allocated IP - 10.100.0.2 from 10.100.0.2 to 10.100.0.14 _try_generate_ip /opt/stack/neutron/neutron/db/db_base_plugin_v2.py:374
2014-05-05 17:12:22.166 18224 DEBUG neutron.notifiers.nova [req-06840c8e-e091-4627-b221-5faeecd1402f None] Ignoring state change previous_port_status: symbol('NO_VALUE') current_port_status: DOWN port_id b0449d81-be9d-4e5e-9ead-13681d923fd1 record_
port_status_changed /opt/stack/neutron/neutron/notifiers/nova.py:199
2014-05-05 17:12:22.167 18224 DEBUG neutron.db.db_base_plugin_v2 [req-06840c8e-e091-4627-b221-5faeecd1402f None] Allocated IP 10.100.0.2 (3e47abe7-610f-4816-9263-25126996c0bd/f08cf80c-3c1d-4738-b231-9b0adc13973b/b0449d81-be9d-4e5e-9ead-13681d923fd1
) create_port /opt/stack/neutron/neutron/db/db_base_plugin_v2.py:1390
2014-05-05 17:12:22.191 18224 INFO neutron.plugins.vmware.dhcp_meta.nsx [req-06840c8e-e091-4627-b221-5faeecd1402f None] Configuring metadata entry for port {'status': 'DOWN', 'name': '', 'admin_state_up': True, 'network_id': u'3e47abe7-610f-4816-92
63-25126996c0bd', 'tenant_id': u'e9f4059f41534834b6edcb9280caa6af', 'device_owner': u'compute:None', 'mac_address': 'fa:16:3e:f0:cf:9b', 'fixed_ips': [{'subnet_id': u'f08cf80c-3c1d-4738-b231-9b0adc13973b', 'ip_address': u'10.100.0.2'}], 'id': 'b044
9d81-be9d-4e5e-9ead-13681d923fd1', 'device_id': u'ce873c29-ed36-486b-a560-a615685848df'}
2014-05-05 17:12:22.195 18224 ERROR neutron.plugins.vmware.dhcp_meta.lsnmanager [req-06840c8e-e091-4627-b221-5faeecd1402f None] Error while configuring LSN port None
2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager Traceback (most recent call last):
2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager   File "/opt/stack/neutron/neutron/plugins/vmware/dhcp_meta/lsnmanager.py", line 303, in _lsn_port_host_conf
2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager     context, network_id, subnet_id)
2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager   File "/opt/stack/neutron/neutron/plugins/vmware/dhcp_meta/lsnmanager.py", line 415, in lsn_port_get
2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager     ctxt.reraise = True
2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager   File "/opt/stack/neutron/neutron/openstack/common/excutils.py", line 82, in __exit__
2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager     six.reraise(self.type_, self.value, self.tb)
2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager   File "/opt/stack/neutron/neutron/plugins/vmware/dhcp_meta/lsnmanager.py", line 399, in lsn_port_get
2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager     context, subnet_id, raise_on_err=raise_on_err)
2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager   File "/opt/stack/neutron/neutron/plugins/vmware/dbexts/lsn_db.py", line 111, in lsn_port_get_for_subnet
2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager     entity_id=subnet_id)
2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager LsnPortNotFound: Unable to find port for LSN None and subnet f08cf80c-3c1d-4738-b231-9b0adc13973b
2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager
2014-05-05 17:12:22.198 18224 ERROR root [-] Original exception being dropped: ['Traceback (most recent call last):\n', '  File "/opt/stack/neutron/neutron/plugins/vmware/dhcp_meta/nsx.py", line 291, in handle_port_metadata_access\n    handler(cont
ext, network_id, subnet_id, host_data)\n', '  File "/opt/stack/neutron/neutron/plugins/vmware/dhcp_meta/lsnmanager.py", line 324, in lsn_port_meta_host_add\n    lsn_api.lsn_port_metadata_host_add)\n', '  File "/opt/stack/neutron/neutron/plugins/vmw
are/dhcp_meta/lsnmanager.py", line 309, in _lsn_port_host_conf\n    net_id=network_id, lsn_id=lsn_id, port_id=lsn_port_id)\n', 'PortConfigurationError: An error occurred while connecting LSN None and network 3e47abe7-610f-4816-9263-25126996c0bd via
 port None\n']

This is because the LSN port has not been set up and the management code
for setting up metadata does not account of that.

** Affects: neutron
     Importance: Undecided
     Assignee: Armando Migliaccio (armando-migliaccio)
         Status: New


** Tags: icehouse-backport-potential vmware

** Changed in: neutron
     Assignee: (unassigned) => Armando Migliaccio (armando-migliaccio)

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

Title:
  NSX: stacktrace during port creation

Status in OpenStack Neutron (virtual network service):
  New

Bug description:
  When using NSX-DHCP the following stack trace can be caused if a port
  is created with a non-empty device id, on a subnet with disabled dhcp
  services:

  2014-05-05 17:12:22.099 18224 DEBUG neutron.openstack.common.rpc.amqp [req-06840c8e-e091-4627-b221-5faeecd1402f None] Sending port.create.start on notifications.info notify /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:622
  2014-05-05 17:12:22.099 18224 DEBUG neutron.openstack.common.rpc.amqp [req-06840c8e-e091-4627-b221-5faeecd1402f None] UNIQUE_ID is 64e9e5271fae43a9b5e195ba697eed19. _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342
  2014-05-05 17:12:22.105 18224 DEBUG neutron.api.v2.base [req-06840c8e-e091-4627-b221-5faeecd1402f None] Request body: {u'port': {u'binding:host_id': u'cidevstack', u'admin_state_up': True, u'network_id': u'3e47abe7-610f-4816-9263-25126996c0bd', u't
  enant_id': u'e9f4059f41534834b6edcb9280caa6af', u'device_owner': u'compute:None', u'rxtx_factor': 1.0, u'security_groups': [u'9fdac141-4d02-48d9-b9cf-7d50cdd272e9'], u'device_id': u'ce873c29-ed36-486b-a560-a615685848df'}} prepare_request_body /opt/
  stack/neutron/neutron/api/v2/base.py:561
  2014-05-05 17:12:22.148 18224 DEBUG neutron.db.db_base_plugin_v2 [req-06840c8e-e091-4627-b221-5faeecd1402f None] Generated mac for network 3e47abe7-610f-4816-9263-25126996c0bd is fa:16:3e:f0:cf:9b _generate_mac /opt/stack/neutron/neutron/db/db_base
  _plugin_v2.py:308
  2014-05-05 17:12:22.165 18224 DEBUG neutron.db.db_base_plugin_v2 [req-06840c8e-e091-4627-b221-5faeecd1402f None] Allocated IP - 10.100.0.2 from 10.100.0.2 to 10.100.0.14 _try_generate_ip /opt/stack/neutron/neutron/db/db_base_plugin_v2.py:374
  2014-05-05 17:12:22.166 18224 DEBUG neutron.notifiers.nova [req-06840c8e-e091-4627-b221-5faeecd1402f None] Ignoring state change previous_port_status: symbol('NO_VALUE') current_port_status: DOWN port_id b0449d81-be9d-4e5e-9ead-13681d923fd1 record_
  port_status_changed /opt/stack/neutron/neutron/notifiers/nova.py:199
  2014-05-05 17:12:22.167 18224 DEBUG neutron.db.db_base_plugin_v2 [req-06840c8e-e091-4627-b221-5faeecd1402f None] Allocated IP 10.100.0.2 (3e47abe7-610f-4816-9263-25126996c0bd/f08cf80c-3c1d-4738-b231-9b0adc13973b/b0449d81-be9d-4e5e-9ead-13681d923fd1
  ) create_port /opt/stack/neutron/neutron/db/db_base_plugin_v2.py:1390
  2014-05-05 17:12:22.191 18224 INFO neutron.plugins.vmware.dhcp_meta.nsx [req-06840c8e-e091-4627-b221-5faeecd1402f None] Configuring metadata entry for port {'status': 'DOWN', 'name': '', 'admin_state_up': True, 'network_id': u'3e47abe7-610f-4816-92
  63-25126996c0bd', 'tenant_id': u'e9f4059f41534834b6edcb9280caa6af', 'device_owner': u'compute:None', 'mac_address': 'fa:16:3e:f0:cf:9b', 'fixed_ips': [{'subnet_id': u'f08cf80c-3c1d-4738-b231-9b0adc13973b', 'ip_address': u'10.100.0.2'}], 'id': 'b044
  9d81-be9d-4e5e-9ead-13681d923fd1', 'device_id': u'ce873c29-ed36-486b-a560-a615685848df'}
  2014-05-05 17:12:22.195 18224 ERROR neutron.plugins.vmware.dhcp_meta.lsnmanager [req-06840c8e-e091-4627-b221-5faeecd1402f None] Error while configuring LSN port None
  2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager Traceback (most recent call last):
  2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager   File "/opt/stack/neutron/neutron/plugins/vmware/dhcp_meta/lsnmanager.py", line 303, in _lsn_port_host_conf
  2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager     context, network_id, subnet_id)
  2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager   File "/opt/stack/neutron/neutron/plugins/vmware/dhcp_meta/lsnmanager.py", line 415, in lsn_port_get
  2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager     ctxt.reraise = True
  2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager   File "/opt/stack/neutron/neutron/openstack/common/excutils.py", line 82, in __exit__
  2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager     six.reraise(self.type_, self.value, self.tb)
  2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager   File "/opt/stack/neutron/neutron/plugins/vmware/dhcp_meta/lsnmanager.py", line 399, in lsn_port_get
  2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager     context, subnet_id, raise_on_err=raise_on_err)
  2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager   File "/opt/stack/neutron/neutron/plugins/vmware/dbexts/lsn_db.py", line 111, in lsn_port_get_for_subnet
  2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager     entity_id=subnet_id)
  2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager LsnPortNotFound: Unable to find port for LSN None and subnet f08cf80c-3c1d-4738-b231-9b0adc13973b
  2014-05-05 17:12:22.195 18224 TRACE neutron.plugins.vmware.dhcp_meta.lsnmanager
  2014-05-05 17:12:22.198 18224 ERROR root [-] Original exception being dropped: ['Traceback (most recent call last):\n', '  File "/opt/stack/neutron/neutron/plugins/vmware/dhcp_meta/nsx.py", line 291, in handle_port_metadata_access\n    handler(cont
  ext, network_id, subnet_id, host_data)\n', '  File "/opt/stack/neutron/neutron/plugins/vmware/dhcp_meta/lsnmanager.py", line 324, in lsn_port_meta_host_add\n    lsn_api.lsn_port_metadata_host_add)\n', '  File "/opt/stack/neutron/neutron/plugins/vmw
  are/dhcp_meta/lsnmanager.py", line 309, in _lsn_port_host_conf\n    net_id=network_id, lsn_id=lsn_id, port_id=lsn_port_id)\n', 'PortConfigurationError: An error occurred while connecting LSN None and network 3e47abe7-610f-4816-9263-25126996c0bd via
   port None\n']

  This is because the LSN port has not been set up and the management
  code for setting up metadata does not account of that.

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

[Bug 1316365] Re: NSX: stacktrace during port creation
From: Thierry Carrez, 2014-06-12
[Bug 1316365] Re: NSX: stacktrace during port creation
From: Alan Pevec, 2014-06-07
[Bug 1316365] Re: NSX: stacktrace during port creation
From: Alan Pevec, 2014-06-05
[Bug 1316365] [NEW] NSX: stacktrace during port creation
From: Armando Migliaccio, 2014-05-06
References

[Bug 1316365] [NEW] NSX: stacktrace during port creation
From: Armando Migliaccio, 2014-05-06