VIO deployment with NSX in SoftLayer fails to start neutron

[eariasn]

Here is the error in the Vcenter web client

- With NSX Networking: Installation fails at 95% due to failure to start neutron

Ansible log in the controller goes around this: 

2015-06-29 21:11:23,601 p=504 u=jarvis |  TASK: [config-controller | grant service role to glance user on service tenant] ***

2015-06-29 21:11:24,786 p=504 u=jarvis |  ok: [10.2.18.207]

2015-06-29 21:11:24,787 p=504 u=jarvis |  TASK: [config-controller | disable glance services start on boot] *************

2015-06-29 21:11:24,938 p=504 u=jarvis |  ok: [10.2.18.207] => (item=glance-api)

2015-06-29 21:11:24,947 p=504 u=jarvis |  ok: [10.2.18.208] => (item=glance-api)

2015-06-29 21:11:25,060 p=504 u=jarvis |  ok: [10.2.18.207] => (item=glance-registry)

2015-06-29 21:11:25,067 p=504 u=jarvis |  ok: [10.2.18.208] => (item=glance-registry)

2015-06-29 21:11:25,077 p=504 u=jarvis |  TASK: [config-controller | write the fernet key file] *************************

2015-06-29 21:11:26,027 p=504 u=jarvis |  ok: [10.2.18.207]

2015-06-29 21:11:26,028 p=504 u=jarvis |  ok: [10.2.18.208]

2015-06-29 21:11:26,041 p=504 u=jarvis |  TASK: [config-controller | update neutron server] *****************************

2015-06-29 21:11:31,096 p=504 u=jarvis |  changed: [10.2.18.207]

2015-06-29 21:11:31,123 p=504 u=jarvis |  changed: [10.2.18.208]

2015-06-29 21:11:31,136 p=504 u=jarvis |  TASK: [config-controller | update neutron configuration] **********************

2015-06-29 21:11:34,334 p=504 u=jarvis |  changed: [10.2.18.207]

2015-06-29 21:11:34,338 p=504 u=jarvis |  changed: [10.2.18.208]

2015-06-29 21:11:34,350 p=504 u=jarvis |  TASK: [config-controller | initialize neutron database] ***********************

2015-06-29 21:11:35,950 p=504 u=jarvis |  changed: [10.2.18.207]

2015-06-29 21:11:35,951 p=504 u=jarvis |  TASK: [config-controller | stop neutron on all controllers] *******************

2015-06-29 21:11:36,118 p=504 u=jarvis |  ok: [10.2.18.208]

2015-06-29 21:11:36,128 p=504 u=jarvis |  changed: [10.2.18.207]

2015-06-29 21:11:36,138 p=504 u=jarvis |  TASK: [config-controller | start neutron on first controller] *****************

2015-06-29 21:11:36,386 p=504 u=jarvis |  changed: [10.2.18.207]

2015-06-29 21:11:36,387 p=504 u=jarvis |  TASK: [config-controller | wait for neutron to start on first controller for NSX] ***

2015-06-29 21:26:36,877 p=504 u=jarvis |  failed: [10.2.18.207] => {"elapsed": 900, "failed": true}

2015-06-29 21:26:36,877 p=504 u=jarvis |  msg: Timeout when waiting for 127.0.0.1:9696

2015-06-29 21:26:36,878 p=504 u=jarvis |  FATAL: all hosts have already failed -- aborting

I am also seeing,

NSXpluginException: An unexpected error occurred in the NSX plugin: Internal network creation for metadata service failed, I selected the metadata network to be in the same network as the management and in a different one to try, both times failed the same.

Any help would be great....

[admin]

send me a PM with who is your VMware account manager. If you are using NSX we can get you hands on help with VIO+NSX...

[JSchulz]

Is it possible that your management cluster is running low on resources?  See this thread, https://communities.vmware.com/thread/515158.

[eariasn]

I checked that, and added more hosts into that cluster, the first error I am seeing in the first controller in neutron log is this, which I kind of see related to the syntax of the request or similar, I wonder if for VIO 2.0, I can't run NSX 6.1.1, if that is the case I don't really know much about upgrading it.

2015-11-10 10:47:48.360 2590 INFO neutron.callbacks.manager [req-ec66d696-1be6-4d64-a55b-10d094e23e2d ] Notify callbacks for security_group, before_delete

2015-11-10 10:47:48.375 2590 INFO neutron.callbacks.manager [req-ec66d696-1be6-4d64-a55b-10d094e23e2d ] Notify callbacks for security_group, after_delete

2015-11-10 10:47:48.376 2590 DEBUG vmware_nsx.neutron.plugins.vmware.vshield.vcns [req-ec66d696-1be6-4d64-a55b-10d094e23e2d ] VcnsApiHelper('DELETE', '/api/2.0/services/securitygroup/securitygroup-552?force=true', 'null') do_request /usr/local/lib/python2.7/dist-packages/vmware_nsx/neutron/plugins/vmware/vshield/vcns.py:101

2015-11-10 10:47:48.879 2590 ERROR vmware_nsx.neutron.plugins.vmware.plugins.nsx_v [req-ec66d696-1be6-4d64-a55b-10d094e23e2d ] Failed to create security group

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v Traceback (most recent call last):

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v   File "/usr/local/lib/python2.7/dist-packages/vmware_nsx/neutron/plugins/vmware/plugins/nsx_v.py", line 1842, in create_security_group

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v     'ip', self.nsx_sg_utils.to_xml_string(section))

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v   File "/usr/local/lib/python2.7/dist-packages/vmware_nsx/neutron/plugins/vmware/vshield/vcns.py", line 506, in create_section

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v     decode=False, encode=False)

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v   File "/usr/local/lib/python2.7/dist-packages/vmware_nsx/neutron/plugins/vmware/vshield/vcns.py", line 109, in do_request

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v     headers, encodeParams)

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v   File "/usr/lib/python2.7/dist-packages/retrying.py", line 68, in wrapped_f

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v     return Retrying(*dargs, **dkw).call(f, *args, **kw)

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v   File "/usr/lib/python2.7/dist-packages/retrying.py", line 223, in call

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v     return attempt.get(self._wrap_exception)

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v   File "/usr/lib/python2.7/dist-packages/retrying.py", line 261, in get

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v     six.reraise(self.value[0], self.value[1], self.value[2])

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v   File "/usr/lib/python2.7/dist-packages/retrying.py", line 217, in call

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v     attempt = Attempt(fn(*args, **kwargs), attempt_number, False)

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v   File "/usr/local/lib/python2.7/dist-packages/vmware_nsx/neutron/plugins/vmware/vshield/vcns.py", line 95, in _client_request

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v     return client(method, uri, params, headers, encodeParams)

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v   File "/usr/local/lib/python2.7/dist-packages/vmware_nsx/neutron/plugins/vmware/vshield/common/VcnsApiClient.py", line 119, in request

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v     raise cls(uri=uri, status=status, header=header, response=response)

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v RequestBad: Request https://10.106.25.150/api/4.0/firewall/globalroot-0/config/layer3sections?autoSaveDraft=false is Bad, response <?xml version="1.0" encoding="UTF-8"?>

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v <error><details>Invalid request syntax.</details><errorCode>224</errorCode><rootCauseString>UnknownFieldException: No such field com.vmware.vshield.firewall.dto.FirewallRuleDto.packetType</rootCauseString></error>

2015-11-10 10:47:48.879 2590 TRACE vmware_nsx.neutron.plugins.vmware.plugins.nsx_v

2015-11-10 10:47:48.888 2590 DEBUG oslo_concurrency.lockutils [req-ec66d696-1be6-4d64-a55b-10d094e23e2d ] Releasing semaphore "metadata-init" lock /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:404

2015-11-10 10:47:48.889 2590 DEBUG oslo_concurrency.lockutils [req-ec66d696-1be6-4d64-a55b-10d094e23e2d ] Lock "manager" released by "_create_instance" :: held 6.831s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:456

2015-11-10 10:47:48.890 2590 ERROR neutron.service [req-ec66d696-1be6-4d64-a55b-10d094e23e2d ] Unrecoverable error: please check log for details.

2015-11-10 10:47:48.890 2590 TRACE neutron.service Traceback (most recent call last):

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/neutron/service.py", line 103, in serve_wsgi

2015-11-10 10:47:48.890 2590 TRACE neutron.service     service.start()

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/neutron/service.py", line 74, in start

2015-11-10 10:47:48.890 2590 TRACE neutron.service     self.wsgi_app = _run_wsgi(self.app_name)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/neutron/service.py", line 169, in _run_wsgi

2015-11-10 10:47:48.890 2590 TRACE neutron.service     app = config.load_paste_app(app_name)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/neutron/common/config.py", line 227, in load_paste_app

2015-11-10 10:47:48.890 2590 TRACE neutron.service     app = deploy.loadapp("config:%s" % config_path, name=app_name)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 247, in loadapp

2015-11-10 10:47:48.890 2590 TRACE neutron.service     return loadobj(APP, uri, name=name, **kw)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 272, in loadobj

2015-11-10 10:47:48.890 2590 TRACE neutron.service     return context.create()

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 710, in create

2015-11-10 10:47:48.890 2590 TRACE neutron.service     return self.object_type.invoke(self)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 144, in invoke

2015-11-10 10:47:48.890 2590 TRACE neutron.service     **context.local_conf)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/paste/deploy/util.py", line 55, in fix_call

2015-11-10 10:47:48.890 2590 TRACE neutron.service     val = callable(*args, **kw)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/paste/urlmap.py", line 28, in urlmap_factory

2015-11-10 10:47:48.890 2590 TRACE neutron.service     app = loader.get_app(app_name, global_conf=global_conf)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 350, in get_app

2015-11-10 10:47:48.890 2590 TRACE neutron.service     name=name, global_conf=global_conf).create()

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 710, in create

2015-11-10 10:47:48.890 2590 TRACE neutron.service     return self.object_type.invoke(self)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 144, in invoke

2015-11-10 10:47:48.890 2590 TRACE neutron.service     **context.local_conf)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/paste/deploy/util.py", line 55, in fix_call

2015-11-10 10:47:48.890 2590 TRACE neutron.service     val = callable(*args, **kw)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/neutron/auth.py", line 71, in pipeline_factory

2015-11-10 10:47:48.890 2590 TRACE neutron.service     app = loader.get_app(pipeline[-1])

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 350, in get_app

2015-11-10 10:47:48.890 2590 TRACE neutron.service     name=name, global_conf=global_conf).create()

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 710, in create

2015-11-10 10:47:48.890 2590 TRACE neutron.service     return self.object_type.invoke(self)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/paste/deploy/loadwsgi.py", line 146, in invoke

2015-11-10 10:47:48.890 2590 TRACE neutron.service     return fix_call(context.object, context.global_conf, **context.local_conf)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/paste/deploy/util.py", line 55, in fix_call

2015-11-10 10:47:48.890 2590 TRACE neutron.service     val = callable(*args, **kw)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/neutron/api/v2/router.py", line 71, in factory

2015-11-10 10:47:48.890 2590 TRACE neutron.service     return cls(**local_config)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/neutron/api/v2/router.py", line 75, in __init__

2015-11-10 10:47:48.890 2590 TRACE neutron.service     plugin = manager.NeutronManager.get_plugin()

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/neutron/manager.py", line 222, in get_plugin

2015-11-10 10:47:48.890 2590 TRACE neutron.service     return weakref.proxy(cls.get_instance().plugin)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/neutron/manager.py", line 216, in get_instance

2015-11-10 10:47:48.890 2590 TRACE neutron.service     cls._create_instance()

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 445, in inner

2015-11-10 10:47:48.890 2590 TRACE neutron.service     return f(*args, **kwargs)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/neutron/manager.py", line 202, in _create_instance

2015-11-10 10:47:48.890 2590 TRACE neutron.service     cls._instance = cls()

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/neutron/manager.py", line 117, in __init__

2015-11-10 10:47:48.890 2590 TRACE neutron.service     plugin_provider)

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/lib/python2.7/dist-packages/neutron/manager.py", line 143, in _get_plugin_instance

2015-11-10 10:47:48.890 2590 TRACE neutron.service     return plugin_class()

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/local/lib/python2.7/dist-packages/vmware_nsx/neutron/plugins/vmware/plugins/nsx_v.py", line 153, in __init__

2015-11-10 10:47:48.890 2590 TRACE neutron.service     nsx_v_md_proxy.NsxVMetadataProxyHandler(self))

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/local/lib/python2.7/dist-packages/vmware_nsx/neutron/plugins/vmware/plugins/nsx_v_md_proxy.py", line 98, in __init__

2015-11-10 10:47:48.890 2590 TRACE neutron.service     self._get_internal_network_and_subnet())

2015-11-10 10:47:48.890 2590 TRACE neutron.service   File "/usr/local/lib/python2.7/dist-packages/vmware_nsx/neutron/plugins/vmware/plugins/nsx_v_md_proxy.py", line 167, in _get_internal_network_and_subnet

2015-11-10 10:47:48.890 2590 TRACE neutron.service     raise nsxv_exc.NsxPluginException(err_msg=error)

2015-11-10 10:47:48.890 2590 TRACE neutron.service NsxPluginException: An unexpected error occurred in the NSX Plugin: Internal network creation for metadata service failed

2015-11-10 10:47:48.890 2590 TRACE neutron.service

2015-11-10 10:47:48.896 2590 CRITICAL neutron [req-ec66d696-1be6-4d64-a55b-10d094e23e2d ] NsxPluginException: An unexpected error occurred in the NSX Plugin: Internal network creation for metadata service failed

[eariasn · Accepted solution]

For people who might seeing something similar, it was a problem with the NSX version, it was 6.1.1 so when the VIO ansible was sending a set of instructions for Neutron service to start up, it was not supported, so I ended doing an upgrade of NSX to 6.2.