Mani Prashanth Varma Manthena created CLOUDSTACK-9443:
---------------------------------------------------------
Summary: ACS master: Concurrent creation of networks ACLs fails
with a DB exception
Key: CLOUDSTACK-9443
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-9443
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Management Server, VPC
Reporter: Mani Prashanth Varma Manthena
Priority: Critical
We hit the following issue when we concurrently create Network ACLs
(thread_count=50) in a VPC:
Entity already exists DB exception error log:
{noformat}
2016-07-28 00:46:36,434 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(catalina-exec-78:ctx-ac712b15 ctx-183595f5 ctx-b05f5eb3) (logid:4c892f5a)
submit async job-423, details: AsyncJobVO {id:423, userId: 2, accountId: 2,
instanceType: None, instanceId: 42, cmd:
org.apache.cloudstack.api.command.user.network.CreateNetworkACLCmd, cmdInfo:
{"protocol":"TCP","cmdEventType":"NETWORK.ACL.ITEM.CREATE","ctxUserId":"2","traffictype":"Ingress","httpmethod":"GET","startport":"8045","endport":"8045","apiKey":"StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ","response":"json","id":"42","ctxDetails":"{\"interface
com.cloud.network.Network\":\"1a444787-80a3-4d69-934d-f758c8ec9eb2\",\"interface
com.cloud.network.vpc.NetworkACLItem\":\"30becdcf-0ecd-4dd1-a4a4-3c85641495a6\"}","action":"Allow","cidrlist":"0.0.0.0/0","uuid":"30becdcf-0ecd-4dd1-a4a4-3c85641495a6","ctxAccountId":"2","networkid":"1a444787-80a3-4d69-934d-f758c8ec9eb2","ctxStartEventId":"1272","signature":"MXuAVNgfaNxgdV+q75cxlDPJdHE\u003d"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 275619427391488, completeMsid: null, lastUpdated: null,
lastPolled: null, created: null}
2016-07-28 00:46:36,431 DEBUG [c.c.a.ApiServlet] (catalina-exec-57:ctx-108659d9
ctx-178bac21 ctx-72debd6e) (logid:1b76234b) ===END=== 10.30.37.11 -- GET
jobid=8fe39265-67c0-41b6-8da6-7def9daae4d1&apiKey=StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ&command=queryAsyncJobResult&response=json&signature=FC6tQry%2F7b9Nac5%2FYOPpnvw4ZGE%3D
2016-07-28 00:46:36,437 DEBUG [c.c.a.ApiServlet] (catalina-exec-78:ctx-ac712b15
ctx-183595f5 ctx-b05f5eb3) (logid:4c892f5a) ===END=== 10.30.37.11 -- GET
networkid=1a444787-80a3-4d69-934d-f758c8ec9eb2&apiKey=StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ&protocol=TCP&endport=8045&cidrlist=0.0.0.0%2F0&traffictype=Ingress&command=createNetworkACL&signature=MXuAVNgfaNxgdV%2Bq75cxlDPJdHE%3D&action=Allow&startport=8045&response=json
2016-07-28 00:46:36,430 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-107:ctx-ccfd6b25 job-423) (logid:4e94b140) Add job-423 into
job monitoring
2016-07-28 00:46:36,430 ERROR [c.c.a.ApiServer] (catalina-exec-79:ctx-3ae9d7dc
ctx-cf3cf3ca ctx-91488c23) (logid:1e4ccb05) unhandled exception executing api
command: [Ljava.lang.String;@2f1474df
javax.persistence.EntityExistsException: Entity already exists:
at com.cloud.utils.db.GenericDaoBase.persist(GenericDaoBase.java:1425)
at
com.cloud.network.vpc.dao.NetworkACLItemDaoImpl.persist(NetworkACLItemDaoImpl.java:155)
at
com.cloud.network.vpc.dao.NetworkACLItemDaoImpl.persist(NetworkACLItemDaoImpl.java:39)
at sun.reflect.GeneratedMethodAccessor79.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at
com.cloud.utils.db.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:34)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy219.persist(Unknown Source)
at
com.cloud.network.vpc.NetworkACLManagerImpl$1.doInTransaction(NetworkACLManagerImpl.java:253)
at
com.cloud.network.vpc.NetworkACLManagerImpl$1.doInTransaction(NetworkACLManagerImpl.java:238)
at com.cloud.utils.db.Transaction$2.doInTransaction(Transaction.java:50)
at com.cloud.utils.db.Transaction.execute(Transaction.java:40)
at com.cloud.utils.db.Transaction.execute(Transaction.java:47)
at
com.cloud.network.vpc.NetworkACLManagerImpl.createNetworkACLItem(NetworkACLManagerImpl.java:238)
at sun.reflect.GeneratedMethodAccessor510.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at
org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:106)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
at
com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy220.createNetworkACLItem(Unknown Source)
at
com.cloud.network.vpc.NetworkACLServiceImpl.createNetworkACLItem(NetworkACLServiceImpl.java:382)
at sun.reflect.GeneratedMethodAccessor508.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy348.createNetworkACLItem(Unknown Source)
at
org.apache.cloudstack.api.command.user.network.CreateNetworkACLCmd.create(CreateNetworkACLCmd.java:232)
at
com.cloud.api.dispatch.CommandCreationWorker.handle(CommandCreationWorker.java:47)
at com.cloud.api.dispatch.DispatchChain.dispatch(DispatchChain.java:37)
at com.cloud.api.ApiDispatcher.dispatchCreateCmd(ApiDispatcher.java:84)
at com.cloud.api.ApiServer.queueCommand(ApiServer.java:632)
at com.cloud.api.ApiServer.handleRequest(ApiServer.java:532)
at com.cloud.api.ApiServlet.processRequestInContext(ApiServlet.java:299)
at com.cloud.api.ApiServlet$1.run(ApiServlet.java:129)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at com.cloud.api.ApiServlet.processRequest(ApiServlet.java:126)
at com.cloud.api.ApiServlet.doGet(ApiServlet.java:88)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:620)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:501)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
at
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1040)
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607)
at
org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:314)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)
Caused by:
com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException:
Duplicate entry '8-1' for key 'acl_id'
at sun.reflect.GeneratedConstructorAccessor154.newInstance(Unknown
Source)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
... 95 more
2016-07-28 00:46:36,427 DEBUG [c.c.a.ApiServlet]
(catalina-exec-46:ctx-bb54761a) (logid:80c339b1) ===START=== 10.30.37.11 --
GET
jobid=1c90fcc1-189a-4295-ac25-6be038cf067a&apiKey=StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ&command=queryAsyncJobResult&response=json&signature=b6%2B3tqxV1VoRTOD%2BYeuQhlt0CcQ%3D
2016-07-28 00:46:36,426 DEBUG [h.w.header] (DirectAgent-140:ctx-ef6b3b17)
(logid:d616fdb1) >> "GET /nuage/api/v3_2/enterprises HTTP/1.1[\r][\n]"
2016-07-28 00:46:36,439 DEBUG [o.a.c.h.HttpMethodBase]
(DirectAgent-140:ctx-ef6b3b17) (logid:d616fdb1) Adding Host request header
2016-07-28 00:46:36,439 DEBUG [h.w.header] (DirectAgent-140:ctx-ef6b3b17)
(logid:d616fdb1) >> "Authorization: Basic
Y2xvdWRzdGFja3VzZXIxOjQxMDkwZTBjLWQwYzMtNDU3My1hNzViLWRlYmJmMzg3Y2RjNg==[\r][\n]"
2016-07-28 00:46:36,439 DEBUG [h.w.header] (DirectAgent-140:ctx-ef6b3b17)
(logid:d616fdb1) >> "content-type: application/json[\r][\n]"
2016-07-28 00:46:36,425 DEBUG [c.c.a.ApiServlet]
(catalina-exec-67:ctx-65cf1160) (logid:b38fe770) ===START=== 10.30.37.11 --
GET
jobid=9c42231c-c6a3-4545-84e4-fdcd707c3896&apiKey=StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ&command=queryAsyncJobResult&response=json&signature=xqxi8elRPiQE7So%2BDBRg8jt%2B0Xs%3D
2016-07-28 00:46:36,425 DEBUG [o.a.c.h.MultiThreadedHttpConnectionManager]
(DirectAgent-137:ctx-f01e458f) (logid:8bb5c915)
HttpConnectionManager.getConnection: config =
HostConfiguration[host=https://10.30.37.5], timeout = 0
2016-07-28 00:46:36,439 DEBUG [h.w.header] (DirectAgent-140:ctx-ef6b3b17)
(logid:d616fdb1) >> "X-Nuage-Organization: CSP[\r][\n]"
2016-07-28 00:46:36,438 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-108:ctx-f3b6a6aa job-424) (logid:d6f24070) Add job-424 into
job monitoring
2016-07-28 00:46:36,442 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-107:ctx-ccfd6b25 job-423) (logid:03c4419e) Executing
AsyncJobVO {id:423, userId: 2, accountId: 2, instanceType: None, instanceId:
42, cmd: org.apache.cloudstack.api.command.user.network.CreateNetworkACLCmd,
cmdInfo:
{"protocol":"TCP","cmdEventType":"NETWORK.ACL.ITEM.CREATE","ctxUserId":"2","traffictype":"Ingress","httpmethod":"GET","startport":"8045","endport":"8045","apiKey":"StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ","response":"json","id":"42","ctxDetails":"{\"interface
com.cloud.network.Network\":\"1a444787-80a3-4d69-934d-f758c8ec9eb2\",\"interface
com.cloud.network.vpc.NetworkACLItem\":\"30becdcf-0ecd-4dd1-a4a4-3c85641495a6\"}","action":"Allow","cidrlist":"0.0.0.0/0","uuid":"30becdcf-0ecd-4dd1-a4a4-3c85641495a6","ctxAccountId":"2","networkid":"1a444787-80a3-4d69-934d-f758c8ec9eb2","ctxStartEventId":"1272","signature":"MXuAVNgfaNxgdV+q75cxlDPJdHE\u003d"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 275619427391488, completeMsid: null, lastUpdated: null,
lastPolled: null, created: null}
{noformat}
Steps to reproduce:
1) Create a VPC network (tier) in a VPC.
2) Create a Network ACL list in the VPC and assign it to the VPC network (tier).
3) Concurrently create Network ACLs in the Network ACL list with a thread count
of 50.
Note: If needed, I can also share my Marvin test script that reproduces this
issue.
Let me know, if you need more information from my side.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
