test_associate_ip_to_server_without_passing_floating_ip failed due to invalid assertion

[Qiu Hua Qiao]

test_associate_ip_to_server_without_passing_floating_ip and test_associate_nonexistant_floating_ip in tempest/api/compute/floating_ips/test_floating_ips_actions.py failed.

The openstack will return code 400 bad request when execute these cases, while the cases use not found(404) to do assertion:
    @attr(type=['negative', 'gate'])
    def test_associate_ip_to_server_without_passing_floating_ip(self):
        # Negative test:Association of empty floating IP to specific server
        # should raise NotFound exception
        self.assertRaises(exceptions.NotFound,
                          self.client.associate_floating_ip_to_server,
                          '', self.server_id)

----------------------------------------------------------------------
_StringException: pythonlogging:'': {{{
2013-11-28 09:11:15,651 Request: POST http://192.168.4.5:8774/v2/a3654af9cfbd4cde86aa963710054727/servers/1df5edf9-7376-4b58-9b79-c8f90415df8b/action
2013-11-28 09:11:15,653 Request Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<Token omitted>'}
2013-11-28 09:11:15,655 Request Body: {"addFloatingIp": {"address": ""}}
2013-11-28 09:11:15,778 Response Status: 400
2013-11-28 09:11:15,779 Nova request id: req-d1300fe2-b94f-41af-85ca-6038a2c18621
2013-11-28 09:11:15,781 Response Headers: {'content-length': '96', 'date': 'Thu, 28 Nov 2013 15:11:15 GMT', 'content-type': 'application/json; charset=UTF-8', 'connection': 'close'}
2013-11-28 09:11:15,782 Response Body: {"badRequest": {"message": "NV-676D697 No nw_info cache associated with instance", "code": 400}}
}}}

Traceback (most recent call last):
  File "/tmp/tempest/tempest/tempest/api/compute/floating_ips/test_floating_ips_actions.py", line 182, in test_associate_ip_to_server_without_passing_floating_ip
    '', self.server_id)
  File "/usr/lib/python2.6/site-packages/testtools/testcase.py", line 394, in assertRaises
    self.assertThat(our_callable, matcher)
  File "/usr/lib/python2.6/site-packages/testtools/testcase.py", line 406, in assertThat
    mismatch = matcher.match(matchee)
  File "/usr/lib/python2.6/site-packages/testtools/matchers/_exception.py", line 99, in match
    mismatch = self.exception_matcher.match(exc_info)
  File "/usr/lib/python2.6/site-packages/testtools/matchers/_higherorder.py", line 61, in match
    mismatch = matcher.match(matchee)
  File "/usr/lib/python2.6/site-packages/testtools/testcase.py", line 386, in match
    reraise(*matchee)
  File "/usr/lib/python2.6/site-packages/testtools/matchers/_exception.py", line 92, in match
    result = matchee()
  File "/usr/lib/python2.6/site-packages/testtools/testcase.py", line 883, in __call__
    return self._callable_object(*self._args, **self._kwargs)
  File "/tmp/tempest/tempest/tempest/services/compute/json/floating_ips_client.py", line 75, in associate_floating_ip_to_server
    resp, body = self.post(url, post_body, self.headers)
  File "/tmp/tempest/tempest/tempest/common/rest_client.py", line 302, in post
    return self.request('POST', url, headers, body)
  File "/tmp/tempest/tempest/tempest/common/rest_client.py", line 436, in request
    resp, resp_body)
  File "/tmp/tempest/tempest/tempest/common/rest_client.py", line 486, in _error_checker
    raise exceptions.BadRequest(resp_body)
BadRequest: Bad request
Details: {u'badRequest': {u'message': u'NV-676D697 No nw_info cache associated with instance', u'code': 400}}

@attr(type=['negative', 'gate'])
    def test_dissociate_nonexistant_floating_ip(self):
        # Negative test:Dissociation of a non existent floating IP should fail
        # Dissociating non existent floating IP
        self.assertRaises(exceptions.NotFound,
                          self.client.disassociate_floating_ip_from_server,
                          "0.0.0.0", self.server_id)

----------------------------------------------------------------------
_StringException: pythonlogging:'': {{{
2013-11-28 09:11:16,037 Request: POST http://192.168.4.5:8774/v2/a3654af9cfbd4cde86aa963710054727/servers/1df5edf9-7376-4b58-9b79-c8f90415df8b/action
2013-11-28 09:11:16,038 Request Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<Token omitted>'}
2013-11-28 09:11:16,040 Request Body: {"addFloatingIp": {"address": "0.0.0.0"}}
2013-11-28 09:11:16,147 Response Status: 400
2013-11-28 09:11:16,149 Nova request id: req-96de6b94-bbb0-494e-9f4a-bbfeea9188e2
2013-11-28 09:11:16,151 Response Headers: {'content-length': '96', 'date': 'Thu, 28 Nov 2013 15:11:16 GMT', 'content-type': 'application/json; charset=UTF-8', 'connection': 'close'}
2013-11-28 09:11:16,152 Response Body: {"badRequest": {"message": "NV-676D697 No nw_info cache associated with instance", "code": 400}}
}}}

Traceback (most recent call last):
  File "/tmp/tempest/tempest/tempest/api/compute/floating_ips/test_floating_ips_actions.py", line 134, in test_associate_nonexistant_floating_ip
    "0.0.0.0", self.server_id)
  File "/usr/lib/python2.6/site-packages/testtools/testcase.py", line 394, in assertRaises
    self.assertThat(our_callable, matcher)
  File "/usr/lib/python2.6/site-packages/testtools/testcase.py", line 406, in assertThat
    mismatch = matcher.match(matchee)
  File "/usr/lib/python2.6/site-packages/testtools/matchers/_exception.py", line 99, in match
    mismatch = self.exception_matcher.match(exc_info)
  File "/usr/lib/python2.6/site-packages/testtools/matchers/_higherorder.py", line 61, in match
    mismatch = matcher.match(matchee)
  File "/usr/lib/python2.6/site-packages/testtools/testcase.py", line 386, in match
    reraise(*matchee)
  File "/usr/lib/python2.6/site-packages/testtools/matchers/_exception.py", line 92, in match
    result = matchee()
  File "/usr/lib/python2.6/site-packages/testtools/testcase.py", line 883, in __call__
    return self._callable_object(*self._args, **self._kwargs)
  File "/tmp/tempest/tempest/tempest/services/compute/json/floating_ips_client.py", line 75, in associate_floating_ip_to_server
    resp, body = self.post(url, post_body, self.headers)
  File "/tmp/tempest/tempest/tempest/common/rest_client.py", line 302, in post
    return self.request('POST', url, headers, body)
  File "/tmp/tempest/tempest/tempest/common/rest_client.py", line 436, in request
    resp, resp_body)
  File "/tmp/tempest/tempest/tempest/common/rest_client.py", line 486, in _error_checker
    raise exceptions.BadRequest(resp_body)
BadRequest: Bad request
Details: {u'badRequest': {u'message': u'NV-676D697 No nw_info cache associated with instance', u'code': 400}}

[Sean Dague (sdague)]

This actually seems like a nova bug

[Matt Riedemann (mriedem)]

So my guess here is nova-network raises a 404 but the neutronv2 API raises a 400. Qiu Hua, I'm assuming you're using neutron, but which nova API? V2 or V3?

[Matt Riedemann (mriedem)]

Do you have the nova-compute and neutron-server logs when this fails?

[Matt Riedemann (mriedem)]

Actually there is no v3 API for floating IPs, so this has to be v2 api for nova. Looking at the nova-network and neutronv2 code, they both check for the floating IP on disassociate and handle/raise not found.

In the associate case, there is an explicit check for network info on the instance, which can result in "No nw_info cache associated with instance" here:

https://github.com/openstack/nova/blob/master/nova/api/openstack/compute/contrib/floating_ips.py#L227

It'd be good to have the nova-api and nova-compute logs when this fails to confirm the traceback, can you provide those?

[Qiu Hua Qiao (qhqiao)]

Yes Matt, you are right it used v2 API.
Case test_associate_nonexistant_floating_ip passed on the latest build today, but I still can recreate the problem for test_associate_ip_to_server_without_passing_floating_ip.
Attached the log.

[Sean Dague (sdague)]

long incomplete bug