Public bug reported: Running Tempest in our internal CI we hit 3 test failures out of 1,971 tests, one was:
tempest.api.volume.test_volumes_snapshots.VolumesSnapshotTest.test_snapshot_create_with_volume_in_use This is running x86_64 RHEL 6.5 with the nova libvirt driver and neutron openvswitch. We have neutron.conf configured for nova events: [root@rhel62 ~]# cat /etc/neutron/neutron.conf | grep nova # being used in conjunction with nova security groups # allowed_rpc_exception_modules = neutron.openstack.common.exception, nova.exception nova_url = http://192.168.4.7:8774/v2 nova_region_name = RegionOne nova_admin_username = nova nova_admin_tenant_id = 11b12b24a2bd4672b6332c41b654a438 nova_admin_password = nova nova_admin_auth_url = http://192.168.4.7:5000/v2.0/ For one failure I'm seeing this in the neutron server log: 2014-03-16 05:57:36.619 8462 ERROR neutron.notifiers.nova [-] Failed to notify nova on events: [{'status': 'completed', 'tag': u'7ecd451e-2f14-4155-a237-3231f3770f1d', 'name': 'network-vif-plugged', 'server_uuid': u'2c368278-e9f4-4458-abdc-b158c5a079ea'}] 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova Traceback (most recent call last): 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/neutron/notifiers/nova.py", line 186, in send_events 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova batched_events) 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/v1_1/contrib/server_external_events.py", line 39, in create 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova return_raw=True) 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/base.py", line 152, in _create 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova _resp, body = self.api.client.post(url, body=body) 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 286, in post 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova return self._cs_request(url, 'POST', **kwargs) 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 260, in _cs_request 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova **kwargs) 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 242, in _time_request 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova resp, body = self.request(url, method, **kwargs) 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 236, in request 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova raise exceptions.from_response(resp, body, url, method) 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova BadRequest: The server could not comply with the request since it is either malformed or otherwise incorrect. (HTTP 400) 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova I correlated that server uuid to the nova-api log error here: 2014-03-16 05:57:27.770 12207 INFO nova.osapi_compute.wsgi.server [req-56dabfa1-9abe-4301-91bc-8093ded6c29c cc61e644b9224dc6918241663551996b 2a33892b41b34180ab23151dfe610990] 192.168.4.9 "GET /v2/2a33892b41b34180ab23151dfe610990/servers/2c368278-e9f4-4458-abdc-b158c5a079ea HTTP/1.1" status: 200 len: 2211 time: 0.1646261 2014-03-16 05:57:36.615 12204 ERROR nova.api.openstack.wsgi [-] Exception handling resource: multi() got an unexpected keyword argument 'body' 2014-03-16 05:57:36.615 12204 TRACE nova.api.openstack.wsgi Traceback (most recent call last): 2014-03-16 05:57:36.615 12204 TRACE nova.api.openstack.wsgi File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 983, in _process_stack 2014-03-16 05:57:36.615 12204 TRACE nova.api.openstack.wsgi action_result = self.dispatch(meth, request, action_args) 2014-03-16 05:57:36.615 12204 TRACE nova.api.openstack.wsgi File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 1070, in dispatch 2014-03-16 05:57:36.615 12204 TRACE nova.api.openstack.wsgi return method(req=request, **action_args) 2014-03-16 05:57:36.615 12204 TRACE nova.api.openstack.wsgi TypeError: multi() got an unexpected keyword argument 'body' 2014-03-16 05:57:36.615 12204 TRACE nova.api.openstack.wsgi 2014-03-16 05:57:36.616 12204 INFO nova.osapi_compute.wsgi.server [-] 127.0.0.1 "POST /None/os-server-external-events HTTP/1.1" status: 400 len: 274 time: 0.0410700 Talking with Dan Smith in IRC it sounds like maybe neutron isn't putting the nova tenant ID into the request for some reason? (4:15:57 PM) dansmith: mriedem: I think neutron sometimes gets the nova url from the context you pass it, so maybe it's related to that ... (4:17:20 PM) dansmith: mriedem: right, but arosen did some work to have neutron determine the proper nova endpoint to call back to based on the context, in the case you've got two novas sharing a neutron This is intermittent, but I do see the neutron server error showing up in community logstash, but only 7% failures: http://goo.gl/up9utR I'm not seeing the same error in logstash in nova-api logs, but that was only going back the last 48 hours. ** Affects: neutron Importance: Undecided Status: New ** Affects: nova Importance: Undecided Status: New ** Tags: network ** Also affects: nova Importance: Undecided Status: New -- You received this bug notification because you are a member of Yahoo! Engineering Team, which is subscribed to neutron. https://bugs.launchpad.net/bugs/1298640 Title: nova network-vif-plugged event fails with 400 from n-api Status in OpenStack Neutron (virtual network service): New Status in OpenStack Compute (Nova): New Bug description: Running Tempest in our internal CI we hit 3 test failures out of 1,971 tests, one was: tempest.api.volume.test_volumes_snapshots.VolumesSnapshotTest.test_snapshot_create_with_volume_in_use This is running x86_64 RHEL 6.5 with the nova libvirt driver and neutron openvswitch. We have neutron.conf configured for nova events: [root@rhel62 ~]# cat /etc/neutron/neutron.conf | grep nova # being used in conjunction with nova security groups # allowed_rpc_exception_modules = neutron.openstack.common.exception, nova.exception nova_url = http://192.168.4.7:8774/v2 nova_region_name = RegionOne nova_admin_username = nova nova_admin_tenant_id = 11b12b24a2bd4672b6332c41b654a438 nova_admin_password = nova nova_admin_auth_url = http://192.168.4.7:5000/v2.0/ For one failure I'm seeing this in the neutron server log: 2014-03-16 05:57:36.619 8462 ERROR neutron.notifiers.nova [-] Failed to notify nova on events: [{'status': 'completed', 'tag': u'7ecd451e-2f14-4155-a237-3231f3770f1d', 'name': 'network-vif-plugged', 'server_uuid': u'2c368278-e9f4-4458-abdc-b158c5a079ea'}] 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova Traceback (most recent call last): 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/neutron/notifiers/nova.py", line 186, in send_events 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova batched_events) 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/v1_1/contrib/server_external_events.py", line 39, in create 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova return_raw=True) 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/base.py", line 152, in _create 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova _resp, body = self.api.client.post(url, body=body) 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 286, in post 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova return self._cs_request(url, 'POST', **kwargs) 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 260, in _cs_request 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova **kwargs) 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 242, in _time_request 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova resp, body = self.request(url, method, **kwargs) 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 236, in request 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova raise exceptions.from_response(resp, body, url, method) 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova BadRequest: The server could not comply with the request since it is either malformed or otherwise incorrect. (HTTP 400) 2014-03-16 05:57:36.619 8462 TRACE neutron.notifiers.nova I correlated that server uuid to the nova-api log error here: 2014-03-16 05:57:27.770 12207 INFO nova.osapi_compute.wsgi.server [req-56dabfa1-9abe-4301-91bc-8093ded6c29c cc61e644b9224dc6918241663551996b 2a33892b41b34180ab23151dfe610990] 192.168.4.9 "GET /v2/2a33892b41b34180ab23151dfe610990/servers/2c368278-e9f4-4458-abdc-b158c5a079ea HTTP/1.1" status: 200 len: 2211 time: 0.1646261 2014-03-16 05:57:36.615 12204 ERROR nova.api.openstack.wsgi [-] Exception handling resource: multi() got an unexpected keyword argument 'body' 2014-03-16 05:57:36.615 12204 TRACE nova.api.openstack.wsgi Traceback (most recent call last): 2014-03-16 05:57:36.615 12204 TRACE nova.api.openstack.wsgi File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 983, in _process_stack 2014-03-16 05:57:36.615 12204 TRACE nova.api.openstack.wsgi action_result = self.dispatch(meth, request, action_args) 2014-03-16 05:57:36.615 12204 TRACE nova.api.openstack.wsgi File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 1070, in dispatch 2014-03-16 05:57:36.615 12204 TRACE nova.api.openstack.wsgi return method(req=request, **action_args) 2014-03-16 05:57:36.615 12204 TRACE nova.api.openstack.wsgi TypeError: multi() got an unexpected keyword argument 'body' 2014-03-16 05:57:36.615 12204 TRACE nova.api.openstack.wsgi 2014-03-16 05:57:36.616 12204 INFO nova.osapi_compute.wsgi.server [-] 127.0.0.1 "POST /None/os-server-external-events HTTP/1.1" status: 400 len: 274 time: 0.0410700 Talking with Dan Smith in IRC it sounds like maybe neutron isn't putting the nova tenant ID into the request for some reason? (4:15:57 PM) dansmith: mriedem: I think neutron sometimes gets the nova url from the context you pass it, so maybe it's related to that ... (4:17:20 PM) dansmith: mriedem: right, but arosen did some work to have neutron determine the proper nova endpoint to call back to based on the context, in the case you've got two novas sharing a neutron This is intermittent, but I do see the neutron server error showing up in community logstash, but only 7% failures: http://goo.gl/up9utR I'm not seeing the same error in logstash in nova-api logs, but that was only going back the last 48 hours. To manage notifications about this bug go to: https://bugs.launchpad.net/neutron/+bug/1298640/+subscriptions -- Mailing list: https://launchpad.net/~yahoo-eng-team Post to : [email protected] Unsubscribe : https://launchpad.net/~yahoo-eng-team More help : https://help.launchpad.net/ListHelp
