IP address conflicts held by public IPs of virtual routers

[vdombrovski]

ISSUE TYPE

• Bug Report

COMPONENT NAME

VR

CLOUDSTACK VERSION

4.17.2

Note: I believe this impacts releases 4.18 and 4.19 also as no relevant code changes have been made to VR code

CONFIGURATION

• Advanced zone
• Standard networking using virtual routers only
• /24 pool of "public" IPs available for the virtual routers

OS / ENVIRONMENT

Ubuntu Focal 20.04

SUMMARY

Our workflow makes it so public IPs can be assigned/unassigned/reassigned to different networks, possibly multiple times per day (mostly, but not only via https://github.com/apache/cloudstack-kubernetes-provider)

After a while, we started seeing that many unused IP addresses (according to ACS database) were actually answering to L2 ARPing. In parallel, some of our IPs are getting 2 different MACs from the ping:

ARPING XX.YY.25.156
60 bytes from 1e:00:fe:00:04:ac (XX.YY.25.156): index=0 time=306.714 usec
60 bytes from 1e:00:63:00:04:b5 (XX.YY.25.156): index=1 time=342.809 usec

Our investigation has shown these conflicts on around 10 ips in two of our /24 subnets, which looks too much to be a conicidence.

We have confirmed that both MAC addresses belong to alive and healthy virtual routers:

 [cloud]> select instance_id from nics where mac_address="1e:00:63:00:04:b5";
+-------------+
| instance_id |
+-------------+
|        5654 |
+-------------+
1 row in set (0.010 sec)

[cloud]> select instance_id from nics where mac_address="1e:00:fe:00:04:ac";
+-------------+
| instance_id |
+-------------+
|        5624 |
+-------------+
1 row in set (0.007 sec)

These routers both correctly mount the IP addresses:

ip a | grep XX.YY.25.156
    inet XX.YY.25.156/24 brd XX.YY.25.255 scope global secondary eth2

Inside the "databag" of the so called "illegitimate" router causing the conflict, we can see the IP declared (sometimes with flag add: true, sometimes with add: false):

# /etc/cloudstack/ips.json
    {
      "add": true,
      "broadcast": "XX.YY.25.255",
      "cidr": "XX.YY.25.156/24",
      "device": "eth2",
      "first_i_p": false,
      "gateway": "XX.YY.25.1",
      "is_private_gateway": false,
      "netmask": "255.255.255.0",
      "network": "XX.YY.25.0/24",
      "new_nic": false,
      "nic_dev_id": 2,
      "nw_type": "public",
      "one_to_one_nat": false,
      "public_ip": "XX.YY.25.156",
      "size": "24",
      "source_nat": false,
      "vif_mac_address": "1e:00:63:00:04:b5"
    }

To my understanding, this file is read/merged whenever a new IP state change is requested; however it's not merged properly on unassignment.

Obviously, deleting/recreating all the virtual routers would solve the issue as this cache would be cleared; however because this causes massive disruptions on the service we would like to make sure the root cause is fixed first.

STEPS TO REPRODUCE

No specific command line here, but I think trying to bounce a public IP between 2 guest routers (ofc inside separate VPCs if these are VPC networks) several time would results in this issue.

1. Create 2 guest networks A and B
2. Create 2 VMS, one inside network A, the other inside network B
3. Associate an IP address to network A, and create a loadbalancer rule for some port of VM A (should also work with port-forwarding and static NAT)
4. Release the IP, associate it to network B, and create a loadbalancer rule for some port of VM A (should also work with port-forwarding and static NAT)
5. Repeat steps 3-4 until you get an IP address conflict (or until you see invalid entries in the databag)

EXPECTED RESULTS

The IP is properly garbage collected on the router that doesn't hold it anymore

ACTUAL RESULTS

IP address conflcit

[DaanHoogland]

thanks @vdombrovski , this will (obviously) be hard to reproduce in a lab environment. the true/false flag of the databag should ensure that IPs are removed, so it not being merged properly on unassigment is the issue as you already stated.

Do you have further logging from the VR that would help identifying the culprit?

(I'll try it in a lab env, but have little hope it will be reliably reproducible)

[vdombrovski]

@DaanHoogland not sure if this helps, in /var/log/cloud.log I'm getting the same log repeated for all IPs:

2024-04-04 04:43:29,474 INFO     Add: rule=-I VPN_XX.YY.25.156 -m state --state RELATED,ESTABLISHED -j ACCEPT table=mangle
2024-04-04 04:43:29,475 INFO     Executing: iptables -t mangle -I VPN_XX.YY.25.156 -m state --state RELATED,ESTABLISHED -j ACCEPT
2024-04-04 04:43:30,158 INFO     Executing: iptables -t mangle -D VPN_XX.YY.25.156 -m state --state RELATED,ESTABLISHED -j ACCEPT
2024-04-04 04:43:30,162 INFO     Delete rule -D VPN_XX.YY.25.156 -m state --state RELATED,ESTABLISHED -j ACCEPT from table mangle
2024-04-04 04:43:36,448 INFO     Address found in DataBag ==> {u'public_ip': u'XX.YY.25.156', u'one_to_one_nat': False, u'nic_dev_id': 2, u'network': u'XX.YY.25.0/24', u'first_i_p': False, u'netmask': u'255.255.255.0', u'source_nat': False, u'broadcast': u'XX.YY.25.255', u'add': True, u'is_private_gateway': False, u'nw_type': u'public', u'device': u'eth2', u'vif_mac_address': u'1e:00:63:00:04:b5', u'cidr': u'XX.YY.25.156/24', u'gateway': u'XX.YY.25.1', u'new_nic': False, u'size': u'24'}
2024-04-04 04:43:36,448 INFO     Address XX.YY.25.156/24 on device eth2 already configured
2024-04-04 04:43:36,461 INFO     Executing: arping -c 1 -I eth2 -A -U -s XX.YY.25.156 XX.YY.25.1

Regarding DataBag logs specifically (again in /var/log/cloud.log), on some instances we are getting this WARNING, without any other explanation:

2024-04-23 13:11:27,089 WARNING  Unable to find and process databag for file: ip_associations.json.a81b47b8-2a91-42a2-a529-1de42849049c, for json type=ip_associations

I will setup a "brute-force" type test case that mirrors what I've described in "Steps to reproduce" using either CMK or Terraform; I'll let you know if I can get it to reproduce.

[DaanHoogland]

oh, that,

2024-04-23 13:11:27,089 WARNING  Unable to find and process databag for file: ip_associations.json.a81b47b8-2a91-42a2-a529-1de42849049c, for json type=ip_associations

, sounds like a weird timing issue, as if two merge deamons are tryimg to process the file at the same time and one has already moved it...???

and it seems here,

2024-04-04 04:43:30,162 INFO     Delete rule -D VPN_XX.YY.25.156 -m state --state RELATED,ESTABLISHED -j ACCEPT from table mangle
2024-04-04 04:43:36,448 INFO     Address found in DataBag ==> {u'public_ip': u'XX.YY.25.156', u'one_to_one_nat': False, u'nic_dev_id': 2, u'network': u'XX.YY.25.0/24', u'first_i_p': False, u'netmask': u'255.255.255.0', u'source_nat': False, u'broadcast': u'XX.YY.25.255', u'add': True, u'is_private_gateway': False, u'nw_type': u'public', u'device': u'eth2', u'vif_mac_address': u'1e:00:63:00:04:b5', u'cidr': u'XX.YY.25.156/24', u'gateway': u'XX.YY.25.1', u'new_nic': False, u'size': u'24'}

, that almost 0.3 second the after the deletion it is added again.

[weizhouapache]

did a quick test, everything looks good
this may need intensive testing to reproduce the issue

[vdombrovski]

@DaanHoogland here is how I successfully reproduced the issue on our QA platform:

56 bytes from 1e:00:4d:00:00:c1 (XX.YY.17.30): index=959 time=275.810 usec
56 bytes from 1e:00:6b:00:00:c2 (XX.YY.17.30): index=960 time=337.038 usec

You were right, this is a timing issue. Here is the raw cmk code to reproduce:

• Create 2 isolated networks, network-a and network-b (mine are ids c6a4bc87-93cc-499c-8fdc-4e44b4d0fca0 and 7e2aa0f1-c536-4162-be43-aea277ae80aa
• You don't need to add any VMs, only playing with virtual routers is enough to cause the issue
• Target a specific IP address, in my case XX.YY.17.30 (id=f1988f51-c9e5-46e4-9393-2a873b2610e0)
• Create 2 scripts as follows (make sure cmk works properly on your machine, I'm using 6.2.0)
• Run both scripts in parallel in a while true loop as follows:

Terminal 1:

while true; do bash ./test1.sh; done

Terminal 2:

while true; do bash ./test2.sh; done

• Test with arping on the IP (arping XX.YY.17.30), it should take around 2-3 mins on a platform with 0 load.

#test1.sh

cmk associate ipaddress projectid=05019f40-8552-4856-9cf1-02ae1b7e2621 zoneid=3adfd657-7e4e-4613-99da-49b3a0ef9db7 ipaddress=XX.YY.17.30 account=qa networkid=c6a4bc87-93cc-499c-8fdc-4e44b4d0fca0 # Network A

cmk createLoadBalancerRule algorithm=roundrobin publicipid=f1988f51-c9e5-46e4-9393-2a873b2610e0 publicport=22 privateport=22 name=vm-a

cmk disassociate ipaddress id=f1988f51-c9e5-46e4-9393-2a873b2610e0

cmk associate ipaddress projectid=05019f40-8552-4856-9cf1-02ae1b7e2621 zoneid=3adfd657-7e4e-4613-99da-49b3a0ef9db7 ipaddress=XX.YY.17.30 account=qa networkid=7e2aa0f1-c536-4162-be43-aea277ae80aa # network B

cmk createLoadBalancerRule algorithm=roundrobin publicipid=f1988f51-c9e5-46e4-9393-2a873b2610e0 publicport=22 privateport=22 name=vm-b

cmk disassociate ipaddress id=f1988f51-c9e5-46e4-9393-2a873b2610e0

#test2.sh

cmk associate ipaddress projectid=05019f40-8552-4856-9cf1-02ae1b7e2621 zoneid=3adfd657-7e4e-4613-99da-49b3a0ef9db7 ipaddress=XX.YY.17.30 account=qa networkid=c6a4bc87-93cc-499c-8fdc-4e44b4d0fca0 # Network A

cmk createLoadBalancerRule algorithm=roundrobin publicipid=f1988f51-c9e5-46e4-9393-2a873b2610e0 publicport=23 privateport=23 name=vm-a

cmk createLoadBalancerRule algorithm=roundrobin publicipid=f1988f51-c9e5-46e4-9393-2a873b2610e0 publicport=24 privateport=24 name=vm-a

cmk disassociate ipaddress id=f1988f51-c9e5-46e4-9393-2a873b2610e0

cmk associate ipaddress projectid=05019f40-8552-4856-9cf1-02ae1b7e2621 zoneid=3adfd657-7e4e-4613-99da-49b3a0ef9db7 ipaddress=XX.YY.17.30 account=qa networkid=7e2aa0f1-c536-4162-be43-aea277ae80aa # network B

cmk createLoadBalancerRule algorithm=roundrobin publicipid=f1988f51-c9e5-46e4-9393-2a873b2610e0 publicport=23 privateport=23 name=vm-b

cmk createLoadBalancerRule algorithm=roundrobin publicipid=f1988f51-c9e5-46e4-9393-2a873b2610e0 publicport=24 privateport=24 name=vm-b

cmk disassociate ipaddress id=f1988f51-c9e5-46e4-9393-2a873b2610e0

Now I understand that handling concurrency isn't really a priority for this project (see another issue from last year: #7907)

However, with the introduction of more vectors of automation (Terraform, Kubernetes), I believe that these types of issues might become really common. In our case, the IP conflicts have impacted more than 10 IPs total on a pool of 400 IPs, which is 2.5%.

[bragonznx]

Hi

We need that to be fix, how can we help ?

Best

[DaanHoogland]

Don't be putting the project down like that, concurrency is one of the main pillars of the project. We have not always been too good at it (as a project), admitted. Manpower vs priorities is the issue here, i think.

Thanks for the investigation @vdombrovski ! Can you do a test on 4.19 , or preferably main as well ?

@bragonznx , code investigation, design, PR, testing (big demand on that) are all needed. What can you offer ?

cheers guys.

[vdombrovski]

@DaanHoogland as I said, this doesn't seem to be a priority at the current time, even though it might be one of the main pillars of the project. I'm not judging here, I'm simply stating the facts based on the change logs. I also know that people working on this project have put a lot of effort recently into enabling alternative L3-L7 solutions that might be more robust than the virtual router (such as the support of VNF appliance and Tungsten Fabric's successor), which might in term enable production-grade uses without the use of proprietary components.

Regarding testing the new release, I am not able to perform these tests on other versions as we don't have a QA platform in those releases (we have put updates on hold following all the migration issues that were reported by people on the users mailing list). We are currently waiting for the 4.18.2.0 to be released as our next upgrade candidate. Maybe is there a particular commit / diff / change from the tree that catches your eye that would help in solving this issue?

In the meantime, what could prevent this bug from occurring in a lab environment? Maybe this is something that a concurrent test case might catch?

[DaanHoogland]

We are currently waiting for the 4.18.2.0 to be released as our next upgrade candidate.

it has been released ;)

As for how to prevent it, I have no ready answer. When creating the situation at fault, does cloudstack in its DB have any proof of the double assignment?

• We can make sure that VRs are being convergently reconfigured when/if the situation is found.
• Another solution would be a system wide lock, which is a performance hog and I would advise against.

[vdombrovski]

@DaanHoogland yes correct, released after I wrote my comment, which means we will surely plan our tests now.

As for proof inside the DB, I've ran more tests, and I can most definitely introduce inconsistencies. For example, my last test got an IP with allocated=NULL but state=Allocated, which in practice means this ip is now unusable until I manually reset it in the database (it cannot be assigned, it cannot be released).

select * from user_ip_address where public_ip_address="XX.YY.17.30" \G;
*************************** 1. row ***************************
                 id: 107
               uuid: f1988f51-c9e5-46e4-9393-2a873b2610e0
         account_id: NULL
          domain_id: NULL
  public_ip_address: XX.YY.17.30
     data_center_id: 1
         source_nat: 0
          allocated: NULL
         vlan_db_id: 2
     one_to_one_nat: 0
              vm_id: NULL
              state: Allocated
        mac_address: 139
  source_network_id: 200
         network_id: 225
physical_network_id: 200
          is_system: 0
             vpc_id: NULL
          dnat_vmip: NULL
        is_portable: 0
            display: 1
            removed: NULL
            created: NULL
         rule_state: NULL
       forsystemvms: 0

Note that all these cases are introduced without any modifications to my original test; I'm simply changing the timings of when I start test1.sh and test2.sh

I'll run some more tests, and report any additional anomalies I find.