Comment 6 for bug 1655567

Revision history for this message
Miguel Lavalle (minsel) wrote :

Looking at this instance of the bug:

http://logs.openstack.org/20/464020/5/check/gate-tempest-dsvm-neutron-linuxbridge-ubuntu-xenial/a4d35a8/console.html

1) The test case being executed is test_dhcpv6_64_subnets. Code is: https://github.com/openstack/tempest/blob/master/tempest/api/network/test_dhcp_ipv6.py#L217

2) The second iteration is starting. All the subnets created by the first iteration have been deleted. In other words, the project / tenant has no subnets.

3) The failure occurs when create IPv6 subnet in the second iteration. The request req-e628a3d3-3c24-4ced-81b0-ec28993ef6f8 fails as follows:

2017-05-16 17:51:53.594710 | 2017-05-16 17:43:05,251 29583 INFO [tempest.lib.common.rest_client] Request (NetworksTestDHCPv6:test_dhcpv6_64_subnets): 409 POST https://10.37.255.77:9696/v2.0/subnets 1.054s
2017-05-16 17:51:53.594753 | 2017-05-16 17:43:05,251 29583 DEBUG [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'X-Auth-Token': '<omitted>', 'Accept': 'application/json'}
2017-05-16 17:51:53.594805 | Body: {"subnet": {"gateway_ip": "2003::1", "network_id": "da25ac93-a061-4ea8-bbf9-2c4e01112034", "ip_version": 6, "ipv6_ra_mode": "dhcpv6-stateless", "cidr": "2003::/64", "ipv6_address_mode": "dhcpv6-stateless"}}
2017-05-16 17:51:53.594877 | Response - Headers: {u'x-openstack-request-id': 'req-e628a3d3-3c24-4ced-81b0-ec28993ef6f8', u'content-type': 'application/json', u'server': 'Apache/2.4.18 (Ubuntu)', u'connection': 'close', 'content-location': 'https://10.37.255.77:9696/v2.0/subnets', u'date': 'Tue, 16 May 2017 17:43:05 GMT', u'content-length': '185', 'status': '409'}
2017-05-16 17:51:53.594922 | Body: {"NeutronError": {"message": "IP address 2003::f816:3eff:fe20:97dd already allocated in subnet 9fd8d6ef-eb85-468c-8453-6c532c61a433", "type": "IpAddressAlreadyAllocated", "detail": ""}}

4) Tracking req-e628a3d3-3c24-4ced-81b0-ec28993ef6f8 in the Neutron server log: http://paste.openstack.org/show/609968/. There are DB retries in this request

5) The id of the subnet being created is 9fd8d6ef-eb85-468c-8453-6c532c61a433. While the subnet creation is taking place (point 4 above), an Update DHCP port is received for the subnet in parallel (req-269ba7b0-a6ab-4549-aa3e-e8136710bbec).

6) Tracking req-269ba7b0-a6ab-4549-aa3e-e8136710bbec in the Neutron server log: http://paste.openstack.org/show/609969/. This request is successful. Note that the IPv6 address assigned to the DHCP port (2003::f816:3eff:fe20:97dd) is the same that is reported by the IpAddressAlreadyAllocated exception in the subnet creation (see point 3 above).

So it seems that the subnet creation is tripped by the the DHCP port creation on it.

Will continue digging.