[RM] routetable cannot handle concurrent add

Question

[RM] routetable cannot handle concurrent add

yanmo96 opened this issue 4 years ago · 3 comments

From the following test on 169. And watch log from routemanager

rally --config-file /root/rally.conf task start ym_create_and_delete_subnets.json

2021-06-29 18:16:14.473 DEBUG 1 --- [nio-8080-exec-7] o.a.coyote.http11.Http11InputBuffer : Received [DELETE /project/4ea3496b3119457ba318b917b118de66/subnets/a68d33d9-3e44-43bc-a9fe-4f6e8cf0d8dc/routetable HTTP/1.1
Accept: /
User-Agent: Java/11.0.8
Host: routemanager-service.default.svc.cluster.local:9003
Connection: keep-alive

]
2021-06-29 18:16:14.474 DEBUG 1 --- [nio-8080-exec-7] o.apache.catalina.valves.RemoteIpValve : Incoming request /project/4ea3496b3119457ba318b917b118de66/subnets/a68d33d9-3e44-43bc-a9fe-4f6e8cf0d8dc/routetable with originalRemoteAddr [172.16.247.243], originalRemoteHost=[172.16.247.243], originalSecure=[false], originalScheme=[http], originalServerName=[routemanager-service.default.svc.cluster.local], originalServerPort=[9003] will be seen as newRemoteAddr=[172.16.247.243], newRemoteHost=[172.16.247.243], newSecure=[false], newScheme=[http], newServerName=[routemanager-service.default.svc.cluster.local], newServerPort=[9003]
2021-06-29 18:16:14.474 DEBUG 1 --- [nio-8080-exec-7] o.a.c.authenticator.AuthenticatorBase : Security checking request DELETE /project/4ea3496b3119457ba318b917b118de66/subnets/a68d33d9-3e44-43bc-a9fe-4f6e8cf0d8dc/routetable
2021-06-29 18:16:14.474 DEBUG 1 --- [nio-8080-exec-7] org.apache.catalina.realm.RealmBase : No applicable constraints defined
2021-06-29 18:16:14.474 DEBUG 1 --- [nio-8080-exec-7] o.a.c.authenticator.AuthenticatorBase : Not subject to any constraint
2021-06-29 18:16:14.475 DEBUG 1 --- [nio-8080-exec-7] c.f.alcor.common.stats.StatisticsAspect : Calculating duration of com.futurewei.alcor.route.controller.RouterController.deleteSubnetRouteTable()...
2021-06-29 18:16:14.475 DEBUG 1 --- [nio-8080-exec-7] c.f.alcor.common.stats.StatisticsAspect : Calculating duration of com.futurewei.alcor.route.dao.RouteTableRepository.findAllItems()...
2021-06-29 18:16:14.478 INFO 1 --- [nio-8080-exec-7] c.f.alcor.common.stats.StatisticsAspect : com.futurewei.alcor.route.dao.RouteTableRepository.findAllItems() startTime: 27368378977816212ns, endTime: 27368378981184692ns, duration: 3ms
2021-06-29 18:16:14.478 DEBUG 1 --- [nio-8080-exec-7] c.f.alcor.common.stats.StatisticsAspect : Calculating duration of com.futurewei.alcor.route.service.Impl.RouteTableDatabaseServiceImpl.addRouteTable()...
2021-06-29 18:16:14.479 DEBUG 1 --- [nio-8080-exec-7] c.f.alcor.common.stats.StatisticsAspect : Calculating duration of com.futurewei.alcor.route.dao.RouteTableRepository.addItem()...
2021-06-29 18:16:14.479 WARN 1 --- [nio-8080-exec-7] global : IgniteTransaction start error:A transaction has already been started by the current thread.
2021-06-29 18:16:14.481 DEBUG 1 --- [nio-8080-exec-7] o.a.c.loader.WebappClassLoaderBase : findClass(jdk.internal.reflect.GeneratedMethodAccessor58)
2021-06-29 18:16:14.481 DEBUG 1 --- [nio-8080-exec-7] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException
2021-06-29 18:16:14.482 ERROR 1 --- [nio-8080-exec-7] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is com.futurewei.alcor.common.exception.DatabasePersistenceException] with root cause

com.futurewei.alcor.common.exception.DatabasePersistenceException: null
at com.futurewei.alcor.route.service.Impl.RouteTableDatabaseServiceImpl.addRouteTable(RouteTableDatabaseServiceImpl.java:67) ~[classes!/:0.1.0-SNAPSHOT]
at com.futurewei.alcor.route.service.Impl.RouteTableDatabaseServiceImpl$$FastClassBySpringCGLIB$$e253d8db.invoke() ~[classes!/:0.1.0-SNAPSHOT]
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:769) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:747) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:88) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at com.futurewei.alcor.common.stats.StatisticsAspect.durationStatistics(StatisticsAspect.java:47) ~[common-0.1.0-SNAPSHOT.jar!/:0.1.0-SNAPSHOT]
at jdk.internal.reflect.GeneratedMethodAccessor58.invoke(Unknown Source) ~[na:na]
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
at java.base/java.lang.reflect.Method.invoke(Method.java:566) ~[na:na]
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:633) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:747) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:95) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:747) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at com.futurewei.alcor.route.service.Impl.RouteTableDatabaseServiceImpl$$EnhancerBySpringCGLIB$$7d911736.addRouteTable() ~[classes!/:0.1.0-SNAPSHOT]
at com.futurewei.alcor.route.service.Impl.NeutronRouterServiceImpl.updateRoutingRule(NeutronRouterServiceImpl.java:667) ~[classes!/:0.1.0-SNAPSHOT]
at com.futurewei.alcor.route.controller.RouterController.deleteSubnetRouteTable(RouterController.java:486) ~[classes!/:0.1.0-SNAPSHOT]
at com.futurewei.alcor.route.controller.RouterController$$FastClassBySpringCGLIB$$274d9bc.invoke() ~[classes!/:0.1.0-SNAPSHOT]
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:769) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:747) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:88) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at com.futurewei.alcor.common.stats.StatisticsAspect.durationStatistics(StatisticsAspect.java:47) ~[common-0.1.0-SNAPSHOT.jar!/:0.1.0-SNAPSHOT]
at jdk.internal.reflect.GeneratedMethodAccessor58.invoke(Unknown Source) ~[na:na]
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
at java.base/java.lang.reflect.Method.invoke(Method.java:566) ~[na:na]
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:633) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:747) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:95) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:747) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at com.futurewei.alcor.route.controller.RouterController$$EnhancerBySpringCGLIB$$b6472e79.deleteSubnetRouteTable() ~[classes!/:0.1.0-SNAPSHOT]
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:na]
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
at java.base/java.lang.reflect.Method.invoke(Method.java:566) ~[na:na]
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190) ~[spring-web-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138) ~[spring-web-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106) ~[spring-webmvc-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:879) ~[spring-webmvc-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:793) ~[spring-webmvc-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040) ~[spring-webmvc-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943) ~[spring-webmvc-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) ~[spring-webmvc-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.web.servlet.FrameworkServlet.doDelete(FrameworkServlet.java:931) ~[spring-webmvc-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:666) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) ~[spring-webmvc-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:741) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) ~[tomcat-embed-websocket-9.0.31.jar!/:9.0.31]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:109) ~[spring-boot-actuator-2.2.5.RELEASE.jar!/:2.2.5.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:747) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:367) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1639) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-9.0.31.jar!/:9.0.31]
at java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]

Answer 1 · 2021-06-30T00:16:33.000Z

The implementation of RouterRepository.java and RouteTableRepository.java seems not right.

    @Override
    @DurationStatistics
    public void addItem(RouteTable routeTable) throws CacheException {
        try (Transaction tx = cache.getTransaction().start()) {

            logger.log(Level.INFO, "Add route table, route table Id:" + routeTable.getId());
            cache.put(routeTable.getId(), routeTable);

            tx.commit();
        } catch (Exception e) {
            throw new CacheException();
        }
    }

The catch part will block concurrent requests.

But if we remove the catch part, the compilation will fail. Since this class inherents from IcacheRepository, and it needs to override a function throws a CacheException.

The suggestion fix is referring to PortRepository in PM and rename the function addItem and throws Exception. Such as:

@Repository
public class RouteTableRepository
... 
    @DurationStatistics
    public synchronized void addRouteTable(RouteTable routeTable) throws Exception {
        try (Transaction tx = cache.getTransaction().start()) {

            logger.log(Level.INFO, "Add route table, route table Id:" + routeTable.getId());
            cache.put(routeTable.getId(), routeTable);

            tx.commit();
        }
    }

Answer 2 · 2021-06-30T20:21:03.000Z

@xieus Can you comment on this issue?

Answer 3 · 2021-06-30T21:51:21.000Z

@yanmo96 Please modify RouterRepository.java and RouteTableRepository.java.
Remove all

try (Transaction tx = cache.getTransaction().start()) {

tx.commit();

} catch (Exception e) {
            throw new CacheException();
        }