Port creation fails with error IP already allocated but the IP is available

[Giuseppe Petralia]

Description:
=================
When trying to create a new port using an available IP in the allocation pool of a VLAN neutron network, creation fails with error:
IP address 10.41.8.3 already allocated in subnet afb678c6-a152-4f1d-8d77-03b9167520cc

Precondition:
=================
A port using the same IP was previously created and then deleted.

How to reproduce:
=================
I have the following network:

$ openstack network show e30b938b-210d-45c2-894c-95c0c5d08f79
+---------------------------+------------------------------------------------------------------------------------------------------------------------------------------------+
| Field | Value |
+---------------------------+------------------------------------------------------------------------------------------------------------------------------------------------+
| admin_state_up | UP |
| availability_zone_hints | |
| availability_zones | |
| created_at | 2020-11-25T10:55:32Z |
| description | |
| dns_domain | |
| id | e30b938b-210d-45c2-894c-95c0c5d08f79 |
| ipv4_address_scope | None |
| ipv6_address_scope | None |
| is_default | False |
| is_vlan_transparent | None |
| location | cloud='', project.domain_id=, project.domain_name=, project.id='606e529ab1bc4b18a6d5dbf8735b9815', project.name=, region_name='us-test', zone= |
| mtu | 1500 |
| name | test |
| port_security_enabled | True |
| project_id | 606e529ab1bc4b18a6d5dbf8735b9815 |
| provider:network_type | vlan |
| provider:physical_network | physnet1 |
| provider:segmentation_id | 2220 |
| qos_policy_id | None |
| revision_number | 11 |
| router:external | External |
| segments | None |
| shared | False |
| status | ACTIVE |
| subnets | afb678c6-a152-4f1d-8d77-03b9167520cc |
| tags | |
| updated_at | 2021-01-20T11:27:57Z |
+---------------------------+------------------------------------------------------------------------------------------------------------------------------------------------+

And a subnet
$ openstack subnet show afb678c6-a152-4f1d-8d77-03b9167520cc
+----------------------+------------------------------------------------------------------------------------------------------------------------------------------------+
| Field | Value |
+----------------------+------------------------------------------------------------------------------------------------------------------------------------------------+
| allocation_pools | 10.41.8.3-10.41.8.4 |
| cidr | 10.41.8.0/29 |
| created_at | 2020-11-25T10:55:34Z |
| description | |
| dns_nameservers | |
| dns_publish_fixed_ip | None |
| enable_dhcp | True |
| gateway_ip | 10.41.8.1 |
| host_routes | |
| id | afb678c6-a152-4f1d-8d77-03b9167520cc |
| ip_version | 4 |
| ipv6_address_mode | None |
| ipv6_ra_mode | None |
| location | cloud='', project.domain_id=, project.domain_name=, project.id='606e529ab1bc4b18a6d5dbf8735b9815', project.name=, region_name='us-test', zone= |
| name | test-subnet |
| network_id | e30b938b-210d-45c2-894c-95c0c5d08f79 |
| prefix_length | None |
| project_id | 606e529ab1bc4b18a6d5dbf8735b9815 |
| revision_number | 9 |
| segment_id | None |
| service_types | |
| subnetpool_id | None |
| tags | |
| updated_at | 2021-01-20T11:27:57Z |
+----------------------+------------------------------------------------------------------------------------------------------------------------------------------------+

Create a port with a fixed ip:
$ openstack port create --debug --network e30b938b-210d-45c2-894c-95c0c5d08f79 --fixed-ip subnet=test-subnet,ip-address=10.41.8.3 test-port

Delete the same port
$ openstack port delete a7a37bbf-129a-4980-a6e8-268c62ea552d

Try to create again the same port with same IP and creation fail
$ openstack port create --debug --network e30b938b-210d-45c2-894c-95c0c5d08f79 --fixed-ip subnet=test-subnet,ip-address=10.41.8.3 test-port
ConflictException: 409: Client Error for url: https://neutron.test.com:9696/v2.0/ports, IP address 10.41.8.3 already allocated in subnet afb678c6-a152-4f1d-8d77-03b9167520cc

ipallocations table show that the IP is actually available:

mysql> select * from ipallocations where network_id="e30b938b-210d-45c2-894c-95c0c5d08f79";
+--------------------------------------+------------+--------------------------------------+--------------------------------------+
| port_id | ip_address | subnet_id | network_id |
+--------------------------------------+------------+--------------------------------------+--------------------------------------+
| 319c6b0d-1970-485a-ade6-914b3fa6abc9 | 10.41.8.4 | afb678c6-a152-4f1d-8d77-03b9167520cc | e30b938b-210d-45c2-894c-95c0c5d08f79 |
+--------------------------------------+------------+--------------------------------------+--------------------------------------+
1 row in set (0.00 sec)

mysql> select * from ipallocations where subnet_id="afb678c6-a152-4f1d-8d77-03b9167520cc";
+--------------------------------------+------------+--------------------------------------+--------------------------------------+
| port_id | ip_address | subnet_id | network_id |
+--------------------------------------+------------+--------------------------------------+--------------------------------------+
| 319c6b0d-1970-485a-ade6-914b3fa6abc9 | 10.41.8.4 | afb678c6-a152-4f1d-8d77-03b9167520cc | e30b938b-210d-45c2-894c-95c0c5d08f79 |
+--------------------------------------+------------+--------------------------------------+--------------------------------------+
1 row in set (0.00 sec)

Expected output
=================
Port is created successfully

Actual output
=================
Port creation fails with:
ConflictException: 409: Client Error for url: https://neutron.test.com:9696/v2.0/ports, IP address 10.41.8.3 already allocated in subnet afb678c6-a152-4f1d-8d77-03b9167520cc

Version:
=================
This is a cloud bionic-ussuri using ovn deployed using charmed OpenStack

Charms revisions:

charm-neutron-api rev 288
charm-neutron-api-plugin-ovn rev 1
charm-ovn-central rev 1
charm-ovn-chassis rev 4

neutron pkgs versions:
ii neutron-common 2:16.1.0-0ubuntu1~cloud0
ii neutron-fwaas-common 1:16.0.0-0ubuntu0.20.04.1~cloud0
ii neutron-plugin-ml2 2:16.1.0-0ubuntu1~cloud0
ii neutron-server 2:16.1.0-0ubuntu1~cloud0

Perceived severity
=================
Critical

[Dorina Timbur (dorina-t)]

If possible, it would be helpful to come up with a workaround, while waiting for a proper resolution.

[Bence Romsics (bence-romsics)]

I could not reproduce this in an ml2/ovs devstack, so I'm building an ml2/ovn devstack to see if this bug is ovn specific. If this is reproducible then it looks like a neutron bug, not a bug of the charm.

How fast do you try to re-create the port with the same IP? Does the error go away if you wait longer? (Wondering if some cleanup is missed or delayed...)

[Giuseppe Petralia (peppepetra)]

Customer reported that the port was deleted the day before and from that time we were not able to re-create the port with the same IP.

[Bence Romsics (bence-romsics)]

I have just built an ml2/ovn devstack. However I'm not able to reproduce this bug yet. I'm doing this:

openstack network create --external --provider-network-type vlan --provider-physical-network physnet0 --provider-segment 100 net0
# same 2-ip allocation pool
openstack subnet create --network net0 --subnet-range 10.0.4.0/29 --allocation-pool start=10.0.4.3,end=10.0.4.4 subnet0
openstack port create --network net0 --fixed-ip subnet=subnet0,ip-address=10.0.4.3 port0
# an extra port to reproduce the other allocation you're showing in the db
openstack port create --network net0 --fixed-ip subnet=subnet0,ip-address=10.0.4.4 port1
openstack port delete port0
openstack port create --network net0 --fixed-ip subnet=subnet0,ip-address=10.0.4.3 port0

and everything succeeds as expected.

On the other hand I'm using current master, that is:

neutron 4184bae651b459
neutron-lib 8c626fe039a5c

$ ovn-controller --version
ovn-controller 20.03.1
Open vSwitch Library 2.13.1
OpenFlow versions 0x4:0x4

Are you able to reproduce this bug or do you only have a report of it? If you can reproduce it, does it occur with every new port or only with that one the customer found?

[Billy Olsen (billy-olsen)]

Looking at the exception, that's raised due to the entry being in the ipamallocations table, not the ipallocations table. I suspect you'll find it residing in the other table.

Why it would be occurring, I'm not yet sure. However, at first glance it does not appear to be an issue with the charms (per @bence-romsics commentary as well).

A possible work around, if it truly is not allocated somewhere, would be to remove it from the ipamallocations table - but editing the database is not without risk. The subnet id is in there as well, so you could probably cross-reference the subnet id to see if its in existence or if it has been removed.

[Billy Olsen (billy-olsen)]

Since this doesn't appear to be an issue with the charms, I'm going to remove the project from being affected by this bug and the field critical designation. However, feel free to re-add it should evidence present itself otherwise.

[Giuseppe Petralia (peppepetra)]

we have found that the IP result to be allocated in the ipamallocations table

=========================
mysql> select * from ipamallocations where ip_address="10.41.8.3";
+------------+-----------+--------------------------------------+
| ip_address | status | ipam_subnet_id |
+------------+-----------+--------------------------------------+
| 10.41.8.3 | ALLOCATED | 51d8f2b5-6eeb-4a2d-a705-8307cadb8640 |
+------------+-----------+--------------------------------------+
1 row in set (0.00 sec)
=========================

but this is referring to a different subnet.

We have asked to the customer to clarify if the whole network and subnet was recreated.
Maybe this can help us identify the correct steps to reproduce it.

[Rodrigo Barbieri (rodrigo-barbieri2010)]

Perhaps somewhat related to the issue:

sosreport-xxx/var/log/neutron/neutron-server.log.3:107672:2021-01-19 22:16:26.449 998071 DEBUG neutron.db.ipam_pluggable_backend [req-08fcf912-018f-4e05-a84c-5879046b7559 b1fedeb91c7e4a70abf1434eb41a1233 f08af276def24be295cd724f51faf7b0 - e7a5476fc8da4ab996b3f365d3cc469b e7a5476fc8da4ab996b3f365d3cc469b] Subnet was not found on ip deallocation: <neutron.db.models_v2.IPAllocation[object at 7ff7f0861240] {port_id=None, ip_address='10.41.8.3', subnet_id='afb678c6-a152-4f1d-8d77-03b9167520cc', network_id='e30b938b-210d-45c2-894c-95c0c5d08f79'}> _ipam_deallocate_ips /usr/lib/python3/dist-packages/neutron/db/ipam_pluggable_backend.py:91

two things of interest here:

1) port_id is None. I wasn't able to reproduce in the lab, and reading the code this doesn't seem to be possible.

2) "Subnet was not found on ip deallocation". That is message raised by SubnetNotFound exception. However, in most cases another LOG.error message is printed just before, and in this case there wasn't any, which leaves us with only a few other possibilities that also seem impossible, as subnet afb678c6-a152-4f1d-8d77-03b9167520cc clearly exists.

[Launchpad Janitor (janitor)]

[Expired for neutron because there has been no activity for 60 days.]