Contrail 3.2.5: neutron exception during heat stack create (resource is for network)

[Deepak Jeyaraman]

In 3.2.5, noticing occcassional failure fror network create (heat stack create)

heat-engine log:

2017-10-29 05:33:51.344 28547 DEBUG neutronclient.client [req-3b126b12-f367-418c-b0d0-f5dfcbe6ca05 - admin - default default] REQ: curl -i http://10.102.28.148:9696/v2.0/subnets/None.json -X GET -H "User-Agent: python-neutronclient" -H "X-Auth-Token: 8b43e8a79252473d90ec4f00e42b29a1" http_log_req /usr/lib/python2.7/dist-packages/neutronclient/common/utils.py:177
2017-10-29 05:33:51.386 28515 DEBUG neutronclient.client [-] RESP: 200 {'Date': 'Sun, 29 Oct 2017 12:33:51 GMT', 'Content-Length': '62', 'Content-Type': 'application/json; charset=UTF-8', 'X-Openstack-Request-Id': 'req-288b5483-ad6a-4953-a05b-4d8ba9cf70b2'} {"networks": [{"id": "c2207153-9af9-4d46-bba0-c8a195cdbdc2"}]} http_log_resp /usr/lib/python2.7/dist-packages/neutronclient/common/utils.py:186
2017-10-29 05:33:51.388 28515 DEBUG neutronclient.client [-] REQ: curl -i http://10.102.28.148:9696/v2.0/subnets.json -X POST -H "User-Agent: python-neutronclient" -H "X-Auth-Token: 8b43e8a79252473d90ec4f00e42b29a1" -d '{"subnet": {"enable_dhcp": true, "network_id": "c2207153-9af9-4d46-bba0-c8a195cdbdc2", "dns_nameservers": [], "ip_version": 4, "cidr": "16.16.27.0/24", "name": "internet-30-internet-30-subnet0-fpzyazh3aui7"}}' http_log_req /usr/lib/python2.7/dist-packages/neutronclient/common/utils.py:177
2017-10-29 05:33:51.400 28547 DEBUG neutronclient.client [req-3b126b12-f367-418c-b0d0-f5dfcbe6ca05 - admin - default default] RESP: 404 {'Date': 'Sun, 29 Oct 2017 12:33:51 GMT', 'Content-Length': '52', 'Content-Type': 'text/plain; charset=UTF-8', 'X-Openstack-Request-Id': 'req-d0e8d827-b765-4f58-a41d-771328c7433b'} 404 Not Found

The resource could not be found.

    http_log_resp /usr/lib/python2.7/dist-packages/neutronclient/common/utils.py:186
2017-10-29 05:33:51.401 28547 DEBUG neutronclient.v2_0.client [req-3b126b12-f367-418c-b0d0-f5dfcbe6ca05 - admin - default default] Error message: 404 Not Found

The resource could not be found.

    _handle_fault_response /usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py:263
2017-10-29 05:33:51.403 28547 DEBUG neutronclient.client [req-3b126b12-f367-418c-b0d0-f5dfcbe6ca05 - admin - default default] REQ: curl -i http://10.102.28.148:9696/v2.0/subnets/None.json -X GET -H "User-Agent: python-neutronclient" -H "X-Auth-Token: 8b43e8a79252473d90ec4f00e42b29a1" http_log_req /usr/lib/python2.7/dist-packages/neutronclient/common/utils.py:177
2017-10-29 05:33:51.470 28515 DEBUG neutronclient.client [-] RESP: 500 {'Date': 'Sun, 29 Oct 2017 12:33:51 GMT', 'Content-Length': '105', 'Content-Type': 'application/json; charset=UTF-8', 'X-Openstack-Request-Id': 'req-6abac9f2-2de5-486c-ac0e-c12db788f3d6'} {"NeutronError": {"message": "An unknown exception occurred.", "type": "NeutronException", "detail": ""}} http_log_resp /usr/lib/python2.7/dist-packages/neutronclient/common/utils.py:186

===

Neutron log:

2017-10-29 05:33:51.396 27623 DEBUG neutron.api.v2.base [req-6abac9f2-2de5-486c-ac0e-c12db788f3d6 9ae546c022794a178e9919a33a711d21 a90ce7fe4d884fb0a017aa9a144e9a37 - - -] Request body: {u'subnet': {u'name': u'internet-30-internet-30-subnet0-fpzyazh3aui7', u'enable_dhcp': True, u'network_id': u'c2207153-9af9-4d46-bba0-c8a195cdbdc2', u'dns_nameservers': [], u'ip_version': 4, u'cidr': u'16.16.27.0/24'}} prepare_request_body /usr/lib/python2.7/dist-packages/neutron/api/v2/base.py:662
2017-10-29 05:33:51.398 27623 INFO neutron.quota [req-6abac9f2-2de5-486c-ac0e-c12db788f3d6 9ae546c022794a178e9919a33a711d21 a90ce7fe4d884fb0a017aa9a144e9a37 - - -] Loaded quota_driver: <neutron_plugin_contrail.plugins.opencontrail.quota.driver.QuotaDriver object at 0x7f3014c34150>.
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource [req-6abac9f2-2de5-486c-ac0e-c12db788f3d6 9ae546c022794a178e9919a33a711d21 a90ce7fe4d884fb0a017aa9a144e9a37 - - -] create failed
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource Traceback (most recent call last):
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/api/v2/resource.py", line 84, in resource
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource result = method(request=request, **args)
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/api/v2/base.py", line 410, in create
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource return self._create(request, body, **kwargs)
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/oslo_db/api.py", line 148, in wrapper
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource ectxt.value = e.inner_exc
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource self.force_reraise()
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource six.reraise(self.type_, self.value, self.tb)
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/oslo_db/api.py", line 138, in wrapper
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource return f(*args, **kwargs)
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/api/v2/base.py", line 521, in _create
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource obj = do_create(body)
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/api/v2/base.py", line 503, in do_create
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource request.context, reservation.reservation_id)
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource self.force_reraise()
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource six.reraise(self.type_, self.value, self.tb)
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/api/v2/base.py", line 496, in do_create
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource return obj_creator(request.context, **kwargs)
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron_plugin_contrail/plugins/opencontrail/contrail_plugin_base.py", line 276, in create_subnet
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource subnet_created = self._create_resource('subnet', context, subnet)
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron_plugin_contrail/plugins/opencontrail/contrail_plugin.py", line 286, in _create_resource
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource obj_name=res_type)
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron_plugin_contrail/plugins/opencontrail/contrail_plugin.py", line 256, in _transform_response
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource plugin_base._raise_contrail_error(info, obj_name)
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron_plugin_contrail/plugins/opencontrail/contrail_plugin_base.py", line 111, in _raise_contrail_error
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource raise exc.NeutronException(**info)
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource NeutronException: An unknown exception occurred.
2017-10-29 05:33:51.465 27623 ERROR neutron.api.v2.resource

=====

[Sachin Bansal (sbansal)]

Could you please also provide contrail-api-0-stdout.log file?

[Deepak Jeyaraman (jdeepak)]

Sachin,

please see attached 3 files for the 3 control nodes.

Deepak

[Deepak Jeyaraman (jdeepak)]

Sachin, I am not able to reassign the PR back to you - can you pls do it.

Deepak

[Deepak Jeyaraman (jdeepak)]

Sachin, we have seen this issue one more time today in the same control node:

2017-10-30 10:59:34.814 27662 DEBUG neutron.api.v2.base [req-d2e3cd05-177b-47b7-bdca-2241fafe5ba0 d48614806c614c6186c8a447772a5421 dfbaf5a8ab774ee89c34cd9e2a64ef32 - - -] Request body: {u'subnet': {u'name': u'jd28148-corp-site-jd28148-corp-site-subnet0-jz3nmebr7fhz', u'enable_dhcp': True, u'network_id': u'a7f4c1a2-4443-4f86-8f5e-9a262e405bab', u'dns_nameservers': [], u'ip_version': 4, u'cidr': u'28.148.0.0/24'}} prepare_request_body /usr/lib/python2.7/dist-packages/neutron/api/v2/base.py:662
2017-10-30 10:59:34.816 27662 INFO neutron.quota [req-d2e3cd05-177b-47b7-bdca-2241fafe5ba0 d48614806c614c6186c8a447772a5421 dfbaf5a8ab774ee89c34cd9e2a64ef32 - - -] Loaded quota_driver: <neutron_plugin_contrail.plugins.opencontrail.quota.driver.QuotaDriver object at 0x7f3015561e10>.
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource [req-d2e3cd05-177b-47b7-bdca-2241fafe5ba0 d48614806c614c6186c8a447772a5421 dfbaf5a8ab774ee89c34cd9e2a64ef32 - - -] create failed
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource Traceback (most recent call last):
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/api/v2/resource.py", line 84, in resource
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource result = method(request=request, **args)
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/api/v2/base.py", line 410, in create
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource return self._create(request, body, **kwargs)
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/oslo_db/api.py", line 148, in wrapper
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource ectxt.value = e.inner_exc
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource self.force_reraise()
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource six.reraise(self.type_, self.value, self.tb)
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/oslo_db/api.py", line 138, in wrapper
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource return f(*args, **kwargs)
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/api/v2/base.py", line 521, in _create
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource obj = do_create(body)
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/neutron/api/v2/base.py", line 503, in do_create
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource request.context, reservation.reservation_id)
2017-10-30 10:59:34.893 27662 ERROR neutron.api.v2.resource File "/usr/lib/python2.7/dist-packages/...

[Ignatious Johnson Christopher (ijohnson-x)]

contrail-api-0.log during the failure: (from 10.102.28.116)
-------------------------------------------------------------

Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/bottle.py", line 856, in _handle
    return route.call(**args)
  File "/usr/lib/python2.7/dist-packages/bottle.py", line 1721, in wrapper
    rv = callback(*a, **ka)
  File "/usr/lib/python2.7/dist-packages/vnc_openstack/context.py", line 37, in wrapper
    return fn(*args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/vnc_openstack/__init__.py", line 1073, in handler_trap_exception
    response = handler(*args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/vnc_openstack/neutron_plugin_interface.py", line 329, in plugin_http_post_subnet
    return self.plugin_create_subnet(context, subnet)
  File "/usr/lib/python2.7/dist-packages/vnc_openstack/neutron_plugin_interface.py", line 274, in plugin_create_subnet
    subnet_info = cfgdb.subnet_create(subnet['resource'])
  File "/usr/lib/python2.7/dist-packages/vnc_openstack/neutron_plugin_db.py", line 2712, in wrapper
    return func(self, *args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/vnc_openstack/neutron_plugin_db.py", line 3013, in subnet_create
    ipam_fq_name)
  File "/usr/lib/python2.7/dist-packages/vnc_openstack/neutron_plugin_db.py", line 1525, in _subnet_vnc_to_neutron
    sn_name = subnet_vnc.get_subnet_name()
AttributeError: 'NoneType' object has no attribute 'get_subnet_name'
97.0.0.17 - - [2017-10-31 08:33:01] "POST /neutron/subnet HTTP/1.1" 500 156 0.066508

[Ignatious Johnson Christopher (ijohnson-x)]

Issue is same as the https://bugs.launchpad.net/juniperopenstack/+bug/1647835
Time was not synced in the config nodes where configdb is running.
Which resulted in Cassandra read failure, immediately after the create.

[Ignatious Johnson Christopher (ijohnson-x)]

Email thread regarding the NTP issue:
---------------------------------------

Thanks Abhay.

Dheeraj, can you please share the steps ? We tried editing the /etc/ntp.conf and restarting ntp service - it didnt seem to help.

Thanks
Deepak

From: Abhay Joshi
Sent: Monday, November 6, 2017 10:10 AM
To: Deepak Jayaraman; Ignatious Johnson
Cc: Dheeraj Gautam
Subject: Re: NTP in INIT state

Dheeraj updated the NTP config on SM and now the nodes seem to be in sync. He can share details on changes he did manually. Apparently the Ubuntu provided NTP was not accessible, he changed it to Juniper NTP server and then it worked.

Thanks,

Abhay

From: Deepak Jayaraman <email address hidden>
Date: Sunday, November 5, 2017 at 6:07 PM
To: Ignatious Johnson <email address hidden>, Abhay Joshi <email address hidden>
Subject: Re: NTP in INIT state

Ignatious, Yes I observed the same last week. We are not able to change the ntp address.

Thanks
Deepak

From: Ignatious Johnson <email address hidden>
Date: Sunday, November 5, 2017 at 1:55 PM
To: Deepak Jeyaraman <email address hidden>, Abhay Joshi <email address hidden>
Subject: Re: NTP in INIT state

>>Subject changed

Hi Abhay,

We have a 3.2.5 setup provisioned using 3.2.6 SM,

ntp is stuck in .INIT. state,
I tried to change the ntp server in ntp.conf and restart ntp service. still when checked using "ntpq -p" it picks up puppet(which resolves to ip address of SM node)

Does SM configure ntp differently?

Setup details:
contrail nodes - 10.102.28.138, 10.102.28.116, 10.102.28.139 (root/Embe1mpls)

Thanks,
Ignatious

[Ignatious Johnson Christopher (ijohnson-x)]

Hi Deepak,

You tried editing ntp.conf of target systems or SM ?

In case sm/smlite, by default SM is configured as NTP server. Also in case of SM, DHCP also provides NTP server options, and by default SM is configured there. So you may need to change /etc/cobbler/dhcp.template

For current setup, NTP servers were not responding back to SM. I edited /etc/ntp.conf on Server-Manager to add Juniper NTP server. And restarted ntp service on SM. After 10-15 mins, all nodes sync time with NTP server (SM in this case), time was synced after wards.

I added following line to /etc/ntp.conf.

server 172.21.200.60 iburst

For changing the NTP server via DHCP (SM only) , following entry could be changed to needed values inside every subnet /etc/cobbler/dhcp.template
    option ntp-servers $next_server;

-Dheeraj