Fix race condition in subnet deletion API #663

xieus · 2021-07-09T07:22:13Z

This PR proposes two issue fix

Fix concurrency issue when multiple subnets in the same VPC are deleted at the same time (tracked by Issue [Subnet Mgr] When create and delete subnet concurrently, VPC will still see deleted subnet ID #662)
Fix Ip allocation not found issue (tracked by [IP mgr]? Ip address allocation not found. 404 error #666)
Add create ignite client with cache config
Fix private IP manager with the latest ignite client in common lib

Add document about transactional semantics for Alcor Caches in general and spefically about Ignite Caches.

lgtm-com · 2021-07-09T19:39:23Z

This pull request fixes 1 alert when merging 8160d4a into 559f2bd - view on LGTM.com

fixed alerts:

1 for Boxed variable is never null

pkommoju · 2021-07-09T22:44:31Z

...anager/src/main/java/com/futurewei/alcor/vpcmanager/service/Impl/VpcDatabaseServiceImpl.java

+
+        return currentVpcState;
+    }
+
    @Override


This is good but there is a convention about the naming. The convention is to call someCache.getTransaction().start(), .commit(), .rollback() instead of wrapping the transaction calls in a method and calling it. It would be better if this code follows the convention.

Another change is required for this to actually work. Ignite configuration declare that this cache must have atomicity mode of TRANSACTIONAL. Here is the declatration.

<bean class="org.apache.ignite.configuration.CacheConfiguration">  <property name="name" value="com.futurewei.alcor.web.entity.vpc.VpcEntity"/>  <property name="atomicityMode" value="TRANSACTIONAL"/>  <property name="cacheMode" value="PARTITIONED"/> </bean>

In kubernetes/services/ignite_config.xml there is this section
under which there is tag . The above declaration should be added under the tag.
Every one needs this update to the ignite config file to not run into this issue, in addition the iginte database should be deleted. (default is <your_ignite_home>/work). If anyone has valuable data in the ignite DB, let me know we can delete just this cache.

If there are any questions about this extra work, ping me.

@pkommoju Thanks. We have updated the transaction naming and added a new cacheConfiguration for VpcRepo.

lgtm-com · 2021-07-09T23:36:02Z

This pull request fixes 1 alert when merging 639a0cd into 559f2bd - view on LGTM.com

fixed alerts:

1 for Boxed variable is never null

pkommoju · 2021-07-09T23:45:10Z

kubernetes/services/ignite_config.xml

+                 <!-- Other cache parameters. -->
+                 <property name="cacheMode" value="PARTITIONED"/>
+             </bean>
+
             <bean class="org.apache.ignite.configuration.CacheConfiguration">
                <!-- Set the cache name. -->
                <property name="name" value="dpm_nodeinfo_cache"/>


Looks good. Best to actually try to start Ignite with this change, one can never be sure about XML nestings and Ignite's naming oddities.

lgtm-com · 2021-07-10T00:04:43Z

This pull request fixes 1 alert when merging 85de8fb into 559f2bd - view on LGTM.com

fixed alerts:

1 for Boxed variable is never null

lgtm-com · 2021-07-13T19:24:33Z

This pull request fixes 1 alert when merging d6ed075 into 559f2bd - view on LGTM.com

fixed alerts:

1 for Boxed variable is never null

lgtm-com · 2021-07-22T06:02:52Z

This pull request fixes 1 alert when merging 016aaf5 into faed9db - view on LGTM.com

fixed alerts:

1 for Boxed variable is never null

lgtm-com · 2021-08-20T14:09:02Z

This pull request fixes 1 alert when merging 2ae9045 into 9887247 - view on LGTM.com

fixed alerts:

1 for Boxed variable is never null

xieus · 2021-08-20T15:31:07Z

...vate_ip_manager/src/main/java/com/futurewei/alcor/privateipmanager/repo/IpAddrRangeRepo.java

+                CacheConfiguration cfg = new CacheConfiguration();
+                cfg.setName(getIpAddrCacheName(rangeId));
+                cfg.setAtomicityMode(CacheAtomicityMode.TRANSACTIONAL);
+
                ICache<String, IpAddrAlloc> ipAddrCache =
-                        cacheFactory.getCache(IpAddrAlloc.class, getIpAddrCacheName(rangeId));
+                        cacheFactory.getCache(IpAddrAlloc.class, cfg);


@pkommoju We are hitting a IP allocation failure, likely causing by the change in this file. Could you try to reproduce this issue in your local and propose a solution (and make code directly to this branch)? Thanks.

More detailed logs from IP manager, failure at the end:

2021-08-20 08:12:44.053 INFO 32420 --- [nio-9004-exec-1] c.f.alcor.common.stats.StatisticsAspect : com.futurewei.alcor.privateipmanager.repo.IpAddrRangeRepo.createIpAddrRange() startTime: 808185834948500ns, endTime: 808186051074000ns, duration: 216ms 2021-08-20 08:12:44.054 INFO 32420 --- [nio-9004-exec-1] c.f.a.p.s.implement.IpAddrServiceImpl : Create ip address range success, request: IpAddrRangeRequest{id='44a1b42c-8c74-4fed-a9e8-f0db3b804568', vpcId='9192a4d4-ffff-4ece-b3f0-8d36e3d88038', subnetId='9192a4d4-ffff-4ece-b3f0-8d36e3d88000', ipVersion=4, firstIp='10.0.0.1', lastIp='10.0.0.254', usedIps=0, totalIps=254} 2021-08-20 08:12:44.108 INFO 32420 --- [nio-9004-exec-1] c.f.alcor.common.stats.StatisticsAspect : com.futurewei.alcor.privateipmanager.service.implement.IpAddrServiceImpl.createIpAddrRange() startTime: 808185826488100ns, endTime: 808186105872800ns, duration: 279ms 2021-08-20 08:12:44.108 INFO 32420 --- [nio-9004-exec-1] c.f.alcor.common.stats.StatisticsAspect : com.futurewei.alcor.privateipmanager.controller.IpAddrController.createIpAddrRange() startTime: 808185806863500ns, endTime: 808186106032800ns, duration: 299ms 2021-08-20 08:12:44.199 INFO 32420 --- [nio-9004-exec-1] i.j.internal.reporters.LoggingReporter : Span reported: 19c5df46e43f0868:119f40ed61423030:19c5df46e43f0868:1 - createIpAddrRange 2021-08-20 08:12:45.145 INFO 32420 --- [nio-9004-exec-2] global : Getting or creating cache IpAddrCache-44a1b42c-8c74-4fed-a9e8-f0db3b804568 AtomicityMode is TRANSACTIONAL 2021-08-20 08:12:45.266 INFO 32420 --- [nio-9004-exec-2] global : Retrieved cache IpAddrCache-44a1b42c-8c74-4fed-a9e8-f0db3b804568 AtomicityMode is TRANSACTIONAL 2021-08-20 08:12:45.441 INFO 32420 --- [nio-9004-exec-2] c.f.alcor.common.stats.StatisticsAspect : com.futurewei.alcor.privateipmanager.repo.IpAddrRangeRepo.allocateIpAddr() startTime: 808187127741900ns, endTime: 808187439280300ns, duration: 311ms 2021-08-20 08:12:45.441 INFO 32420 --- [nio-9004-exec-2] c.f.a.p.s.implement.IpAddrServiceImpl : Allocate ip address success, request: IpAddrRequest{ipVersion=4, vpcId='9192a4d4-ffff-4ece-b3f0-8d36e3d88038', subnetId='9192a4d4-ffff-4ece-b3f0-8d36e3d88000', rangeId='44a1b42c-8c74-4fed-a9e8-f0db3b804568', ip='10.0.0.1', state='activated'} 2021-08-20 08:12:45.451 INFO 32420 --- [nio-9004-exec-2] c.f.alcor.common.stats.StatisticsAspect : com.futurewei.alcor.privateipmanager.service.implement.IpAddrServiceImpl.allocateIpAddr() startTime: 808187127625600ns, endTime: 808187449775400ns, duration: 322ms 2021-08-20 08:12:45.451 INFO 32420 --- [nio-9004-exec-2] c.f.alcor.common.stats.StatisticsAspect : com.futurewei.alcor.privateipmanager.controller.IpAddrController.allocateIpAddr() startTime: 808187127480000ns, endTime: 808187450186000ns, duration: 322ms 2021-08-20 08:12:45.459 INFO 32420 --- [nio-9004-exec-2] i.j.internal.reporters.LoggingReporter : Span reported: f7abf3c5dd709f12:cdd48c47c05d4a75:1156c528c55d9674:1 - allocateIpAddr 2021-08-20 08:19:07.366 INFO 32420 --- [nio-9004-exec-5] c.f.alcor.common.stats.StatisticsAspect : com.futurewei.alcor.privateipmanager.repo.IpAddrRangeRepo.createIpAddrRange() startTime: 808569352538200ns, endTime: 808569364686900ns, duration: 12ms 2021-08-20 08:19:07.367 INFO 32420 --- [nio-9004-exec-5] c.f.a.p.s.implement.IpAddrServiceImpl : Create ip address range success, request: IpAddrRangeRequest{id='c49181bb-4ad0-4cdf-a240-3443fa00df65', vpcId='9192a4d4-ffff-4ece-b3f0-8d36e3d88038', subnetId='9192a4d4-ffff-4ece-b3f0-8d36e3d88001', ipVersion=4, firstIp='10.0.1.1', lastIp='10.0.1.254', usedIps=0, totalIps=254} 2021-08-20 08:19:07.367 INFO 32420 --- [nio-9004-exec-5] c.f.alcor.common.stats.StatisticsAspect : com.futurewei.alcor.privateipmanager.service.implement.IpAddrServiceImpl.createIpAddrRange() startTime: 808569352499400ns, endTime: 808569365131900ns, duration: 12ms 2021-08-20 08:19:07.367 INFO 32420 --- [nio-9004-exec-5] c.f.alcor.common.stats.StatisticsAspect : com.futurewei.alcor.privateipmanager.controller.IpAddrController.createIpAddrRange() startTime: 808569352336500ns, endTime: 808569365194600ns, duration: 12ms 2021-08-20 08:19:07.369 INFO 32420 --- [nio-9004-exec-5] i.j.internal.reporters.LoggingReporter : Span reported: c854d7eac6e2fd40:1ff2cfc38a8d1790:c854d7eac6e2fd40:1 - createIpAddrRange 2021-08-20 08:19:07.418 INFO 32420 --- [nio-9004-exec-6] global : Getting or creating cache IpAddrCache-44a1b42c-8c74-4fed-a9e8-f0db3b804568 AtomicityMode is TRANSACTIONAL 2021-08-20 08:19:07.420 INFO 32420 --- [nio-9004-exec-6] global : Retrieved cache IpAddrCache-44a1b42c-8c74-4fed-a9e8-f0db3b804568 AtomicityMode is TRANSACTIONAL 2021-08-20 08:19:07.424 WARN 32420 --- [nio-9004-exec-6] c.f.a.p.repo.IpAddrRangeRepo : Allocate ip address from 44a1b42c-8c74-4fed-a9e8-f0db3b804568 failed 2021-08-20 08:19:07.425 INFO 32420 --- [nio-9004-exec-6] global : Getting or creating cache IpAddrCache-c49181bb-4ad0-4cdf-a240-3443fa00df65 AtomicityMode is TRANSACTIONAL

I will work on it.

I will work on it.

Thanks. This issue was triggered when a subnet is created. SM=>PM=>Private ip manager to create a gateway port and allocate ip.

I did build and run it on Jenkins machine and it worked fine. I am doing a second run to make sure I didn't pick up wrong run environment.

I am able to reproduce it. subnet got created but the IP address range in question (in the cache named IpAddrCache-e4efed2e-33ab-4783-a7ce-0254dfd695d2) is empty. Should there be something at the point of failure or is it legitimate condition that has to be dealt with is something I am going to debug and find.

Set logging level in PIM to INFO and ping test succeeded. The IP address cache has three entries, but since this state is after the test finished, it is not clear the cache being is empty when the test failed is a legitimate state.
Since adding debug out made the test succeed, I am suspecting timing (race conditions). Need to further investigate.

It ran fine with logging=INFO three times, and once without the change. I am rerunning the Jenkins job as is now. The nature of failure suggests that there may be more race conditions which have not been uncovered (or rather this failure has uncovered).

@pkommoju Could you share a link of one Jenkins run which points to this branch? In local dev environment, we always hit the cache issue, 100%.

…oblem

pkommoju and others added 20 commits May 12, 2021 11:34

Documentation update

9645772

Add document about transactional semantics for Alcor Caches in general and spefically about Ignite Caches.

Apply changes suggested in review

183c36a

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

4896515

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

f170e1e

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

bcbf7b1

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

efc5b6e

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

c785697

Merge branch 'master' of https://github.com/pkommoju/alcor

d213c03

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

0f56454

Merge branch 'master' of https://github.com/pkommoju/alcor

4a2a382

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

7f93fe3

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

8d6dd0e

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

b19d428

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

539d0c0

Merge branch 'master' of https://github.com/pkommoju/alcor

6a9a1c6

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

19430b2

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

1d7ef7e

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

cd1fec6

Fix race condition in VPC Mgr delete subnet API

e079a44

Set subnset ip version as IPv4

4831ad6

xieus added bug Something isn't working perf testing Performance Testing labels Jul 9, 2021

xieus added this to the Version 0.17.2021.07.30 milestone Jul 9, 2021

xieus requested review from yanmo96, zzxgzgz, cj-chung and DavidLiu506 July 9, 2021 07:22

xieus self-assigned this Jul 9, 2021

pkommoju reviewed Jul 9, 2021

View reviewed changes

Fix commit transaction from different thread issue

639a0cd

Update ignite config xml to support transaction in VpcRepository

85de8fb

pkommoju reviewed Jul 9, 2021

View reviewed changes

Fix Ip mgr ignite misconfiguration

d6ed075

pkommoju and others added 4 commits July 20, 2021 13:28

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

e57abe4

Add missing file

1b63054

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

fe81008

Add create ignite client with cache config and support in ip mgr

016aaf5

xieus linked an issue Jul 22, 2021 that may be closed by this pull request

[IP mgr]? Ip address allocation not found. 404 error #666

Open

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

118dd53

yanmo96 mentioned this pull request Aug 2, 2021

Add VpcEntity cache TRANSACTIONAL to ignite_config #673

Merged

pkommoju and others added 4 commits August 2, 2021 16:05

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

7d9a2e5

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

3884a44

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

0b5cd11

Merge from master

2ae9045

xieus commented Aug 20, 2021

View reviewed changes

pkommoju added 5 commits August 26, 2021 14:06

Make all currently used caches transactional

257ef71

Merge branch 'master' of https://github.com/futurewei-cloud/alcor

c303e0b

Merge branch 'master' into all_txn

46b79f8

Make more caches to Transactional atomicity to fix subnet deletion pr…

c7809b3

…oblem

Address code review comments

70e9251

pkommoju mentioned this pull request Aug 27, 2021

Fix/subnet concurrent delete issue pkommoju/alcor#1

Merged

Merge branch 'all_txn' into fix/subnet_concurrent_delete_issue

06bc414

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix race condition in subnet deletion API #663

Fix race condition in subnet deletion API #663

xieus commented Jul 9, 2021 •

edited

Loading

lgtm-com bot commented Jul 9, 2021

pkommoju Jul 9, 2021

xieus Jul 9, 2021

lgtm-com bot commented Jul 9, 2021

pkommoju Jul 9, 2021

lgtm-com bot commented Jul 10, 2021

lgtm-com bot commented Jul 13, 2021

lgtm-com bot commented Jul 22, 2021

lgtm-com bot commented Aug 20, 2021

xieus Aug 20, 2021

pkommoju Aug 20, 2021

xieus Aug 20, 2021

pkommoju Aug 20, 2021

pkommoju Aug 20, 2021

pkommoju Aug 20, 2021

pkommoju Aug 20, 2021

xieus Aug 27, 2021

Fix race condition in subnet deletion API #663

Are you sure you want to change the base?

Fix race condition in subnet deletion API #663

Conversation

xieus commented Jul 9, 2021 • edited Loading

lgtm-com bot commented Jul 9, 2021

Choose a reason for hiding this comment

Choose a reason for hiding this comment

lgtm-com bot commented Jul 9, 2021

Choose a reason for hiding this comment

lgtm-com bot commented Jul 10, 2021

lgtm-com bot commented Jul 13, 2021

lgtm-com bot commented Jul 22, 2021

lgtm-com bot commented Aug 20, 2021

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

xieus commented Jul 9, 2021 •

edited

Loading