You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "urvi shah (JIRA)" <ji...@apache.org> on 2015/10/21 01:47:27 UTC

[jira] [Created] (CLOUDSTACK-8974) CloudRuntimeException DB exception when releasing a public ip twice

urvi shah created CLOUDSTACK-8974:
-------------------------------------

             Summary: CloudRuntimeException DB exception when releasing a public ip twice
                 Key: CLOUDSTACK-8974
                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-8974
             Project: CloudStack
          Issue Type: Bug
      Security Level: Public (Anyone can view this level - this is the default.)
          Components: Management Server
    Affects Versions: 4.3.0
         Environment: KVM hypervisor
            Reporter: urvi shah


have the following scenario:
# assign an public ip to a vpc
# release the ip
# release the ip again

a DB exception occurs the second time.

{code:title=management-server.log|borderStyle=solid}
2015-10-20 01:32:23,740 ERROR [c.c.a.ApiServer] (catalina-exec-25:ctx-fb72a0aa ctx-e7f3aac9 ctx-f4891dc8) unhandled exception executing api command: disassociateIpAddress
com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.PreparedStatement@36f1502f: INSERT INTO event (event.type, event.state, event.description, event.created, event.user_id, event.account_id, event.domain_id, event.level, event.start_id, event.parameters, event.uuid, event.archived) VALUES (_binary'NET.IPRELEASE', 'Scheduled', _binary'Disassociating ip address with id=3', '2015-10-20 01:32:23', 2, -1, 0, _binary'INFO', 0, null, _binary'ddaa540e-3d04-4ca1-a06a-9f441297a743', 0)
        at com.cloud.utils.db.GenericDaoBase.persist(GenericDaoBase.java:1350)
        at sun.reflect.GeneratedMethodAccessor42.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:33)
        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.$Proxy92.persist(Unknown Source)
        at com.cloud.event.ActionEventUtils.persistActionEvent(ActionEventUtils.java:167)
        at com.cloud.event.ActionEventUtils.onScheduledActionEvent(ActionEventUtils.java:91)
        at com.cloud.api.ApiServer.queueCommand(ApiServer.java:498)
        at com.cloud.api.ApiServer.handleRequest(ApiServer.java:374)
        at com.cloud.api.ApiServlet.processRequestInContext(ApiServlet.java:323)
        at com.cloud.api.ApiServlet.access$000(ApiServlet.java:53)
        at com.cloud.api.ApiServlet$1.run(ApiServlet.java:115)
        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:112)
        at com.cloud.api.ApiServlet.doGet(ApiServlet.java:74)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:555)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
{code}

The disassociate of both IP's is executed 2 times.
The first succeeds, the 2nd fails, 
because the account id of that IP has been cleared.

{noformat}
2015-10-20 01:30:42,510 DEBUG [c.c.a.ApiServlet] (catalina-exec-16:ctx-01e616c9) ===START===  0:0:0:0:0:0:0:1 -- GET  signatureversion=3&apiKey=StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ&expires=2015-10-20T01%3A40%3A42%2B0000&id=0a3a24aa-a4a5-4b24-a232-b4fb8d4e9f32&command=disassociateIpAddress&signature=hOPdXkGVvHfdXKBWjMhkZwW%2FBCA%3D&response=json
2015-10-20 01:30:42,571 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-16:ctx-01e616c9 ctx-f1a8a57a ctx-6a57837b) submit async job-155, details: AsyncJobVO {id:155, userId: 2, accountId: 2, instanceType: IpAddress, instanceId: 6, cmd: org.apache.cloudstack.api.command.user.address.DisassociateIPAddrCmd, cmdInfo: {"response":"json","id":"0a3a24aa-a4a5-4b24-a232-b4fb8d4e9f32","cmdEventType":"NET.IPRELEASE","expires":"2015-10-20T01:40:42+0000","ctxUserId":"2","signatureversion":"3","httpmethod":"GET","ctxAccountId":"2","ctxStartEventId":"644","apiKey":"StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ","signature":"hOPdXkGVvHfdXKBWjMhkZwW/BCA\u003d"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 275619427420416, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2015-10-20 01:30:42,574 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-147:ctx-5dc8d45b) Executing AsyncJobVO {id:155, userId: 2, accountId: 2, instanceType: IpAddress, instanceId: 6, cmd: org.apache.cloudstack.api.command.user.address.DisassociateIPAddrCmd, cmdInfo: {"response":"json","id":"0a3a24aa-a4a5-4b24-a232-b4fb8d4e9f32","cmdEventType":"NET.IPRELEASE","expires":"2015-10-20T01:40:42+0000","ctxUserId":"2","signatureversion":"3","httpmethod":"GET","ctxAccountId":"2","ctxStartEventId":"644","apiKey":"StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ","signature":"hOPdXkGVvHfdXKBWjMhkZwW/BCA\u003d"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 275619427420416, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2015-10-20 01:30:42,574 DEBUG [c.c.a.ApiServlet] (catalina-exec-16:ctx-01e616c9 ctx-f1a8a57a ctx-6a57837b) ===END===  0:0:0:0:0:0:0:1 -- GET  signatureversion=3&apiKey=StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ&expires=2015-10-20T01%3A40%3A42%2B0000&id=0a3a24aa-a4a5-4b24-a232-b4fb8d4e9f32&command=disassociateIpAddress&signature=hOPdXkGVvHfdXKBWjMhkZwW%2FBCA%3D&response=json
2015-10-20 01:30:59,176 DEBUG [c.c.u.NuageVspUtil] (Job-Executor-147:ctx-5dc8d45b ctx-6a57837b) IP 10.100.100.120 is associated with VM with ID = 22 and IP = 172.16.0.40
2015-10-20 01:31:12,024 DEBUG [c.c.n.v.VpcManagerImpl] (Job-Executor-147:ctx-5dc8d45b ctx-6a57837b) IP address Ip[10.100.100.120-1] is no longer associated with the network inside vpc id=5
2015-10-20 01:31:12,102 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-147:ctx-5dc8d45b) Done executing org.apache.cloudstack.api.command.user.address.DisassociateIPAddrCmd for job-155

2015-10-20 01:31:15,020 DEBUG [c.c.a.ApiServlet] (catalina-exec-8:ctx-33b7a7d1) ===START===  0:0:0:0:0:0:0:1 -- GET  signatureversion=3&apiKey=StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ&expires=2015-10-20T01%3A41%3A15%2B0000&id=3235d0f2-043b-4429-8ed8-6471cd74e72c&command=disassociateIpAddress&signature=DJgrWUF%2BUw7zditcpVnNbVx29Uk%3D&response=json
2015-10-20 01:31:16,016 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-8:ctx-33b7a7d1 ctx-fe1c54b3 ctx-44973d59) submit async job-156, details: AsyncJobVO {id:156, userId: 2, accountId: 2, instanceType: IpAddress, instanceId: 3, cmd: org.apache.cloudstack.api.command.user.address.DisassociateIPAddrCmd, cmdInfo: {"response":"json","id":"3235d0f2-043b-4429-8ed8-6471cd74e72c","cmdEventType":"NET.IPRELEASE","expires":"2015-10-20T01:41:15+0000","ctxUserId":"2","signatureversion":"3","httpmethod":"GET","ctxAccountId":"2","ctxStartEventId":"657","apiKey":"StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ","signature":"DJgrWUF+Uw7zditcpVnNbVx29Uk\u003d"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 275619427420416, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2015-10-20 01:31:16,017 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-148:ctx-98f68582) Executing AsyncJobVO {id:156, userId: 2, accountId: 2, instanceType: IpAddress, instanceId: 3, cmd: org.apache.cloudstack.api.command.user.address.DisassociateIPAddrCmd, cmdInfo: {"response":"json","id":"3235d0f2-043b-4429-8ed8-6471cd74e72c","cmdEventType":"NET.IPRELEASE","expires":"2015-10-20T01:41:15+0000","ctxUserId":"2","signatureversion":"3","httpmethod":"GET","ctxAccountId":"2","ctxStartEventId":"657","apiKey":"StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ","signature":"DJgrWUF+Uw7zditcpVnNbVx29Uk\u003d"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 275619427420416, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2015-10-20 01:31:16,018 DEBUG [c.c.a.ApiServlet] (catalina-exec-8:ctx-33b7a7d1 ctx-fe1c54b3 ctx-44973d59) ===END===  0:0:0:0:0:0:0:1 -- GET  signatureversion=3&apiKey=StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ&expires=2015-10-20T01%3A41%3A15%2B0000&id=3235d0f2-043b-4429-8ed8-6471cd74e72c&command=disassociateIpAddress&signature=DJgrWUF%2BUw7zditcpVnNbVx29Uk%3D&response=json
2015-10-20 01:31:25,743 DEBUG [c.c.u.NuageVspUtil] (Job-Executor-148:ctx-98f68582 ctx-44973d59) IP 10.100.100.117 is associated with VM with ID = 22 and IP = 172.16.0.240
2015-10-20 01:32:16,577 DEBUG [c.c.n.v.VpcManagerImpl] (Job-Executor-148:ctx-98f68582 ctx-44973d59) IP address Ip[10.100.100.117-1] is no longer associated with the network inside vpc id=5
2015-10-20 01:32:16,654 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-148:ctx-98f68582) Done executing org.apache.cloudstack.api.command.user.address.DisassociateIPAddrCmd for job-156

2015-10-20 01:32:22,747 DEBUG [c.c.a.ApiServlet] (catalina-exec-24:ctx-198d7a51) ===START===  0:0:0:0:0:0:0:1 -- GET  signatureversion=3&apiKey=StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ&expires=2015-10-20T01%3A42%3A22%2B0000&id=0a3a24aa-a4a5-4b24-a232-b4fb8d4e9f32&command=disassociateIpAddress&signature=m0QuUVuIkEfhB3QjxTnIhA56dwU%3D&response=json
2015-10-20 01:32:22,761 ERROR [c.c.a.ApiServer] (catalina-exec-24:ctx-198d7a51 ctx-bc4ff94c ctx-e6cda8e7) unhandled exception executing api command: disassociateIpAddress
2015-10-20 01:32:22,762 DEBUG [c.c.a.ApiServlet] (catalina-exec-24:ctx-198d7a51 ctx-bc4ff94c ctx-e6cda8e7) ===END===  0:0:0:0:0:0:0:1 -- GET  signatureversion=3&apiKey=StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ&expires=2015-10-20T01%3A42%3A22%2B0000&id=0a3a24aa-a4a5-4b24-a232-b4fb8d4e9f32&command=disassociateIpAddress&signature=m0QuUVuIkEfhB3QjxTnIhA56dwU%3D&response=json

2015-10-20 01:32:23,729 DEBUG [c.c.a.ApiServlet] (catalina-exec-25:ctx-fb72a0aa) ===START===  0:0:0:0:0:0:0:1 -- GET  signatureversion=3&apiKey=StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ&expires=2015-10-20T01%3A42%3A23%2B0000&id=3235d0f2-043b-4429-8ed8-6471cd74e72c&command=disassociateIpAddress&signature=FMHv9FRmUFyoBfuMfxAQTbkjz2A%3D&response=json
2015-10-20 01:32:23,740 ERROR [c.c.a.ApiServer] (catalina-exec-25:ctx-fb72a0aa ctx-e7f3aac9 ctx-f4891dc8) unhandled exception executing api command: disassociateIpAddress
2015-10-20 01:32:23,742 DEBUG [c.c.a.ApiServlet] (catalina-exec-25:ctx-fb72a0aa ctx-e7f3aac9 ctx-f4891dc8) ===END===  0:0:0:0:0:0:0:1 -- GET  signatureversion=3&apiKey=StjgrAiYEguhhZwogkx4SggkPhImhdxgSrDbfUZhLjL4As6bm4Xec8GC7WKFWuZXJmTAIl9zx_Qeh767T_yfpQ&expires=2015-10-20T01%3A42%3A23%2B0000&id=3235d0f2-043b-4429-8ed8-6471cd74e72c&command=disassociateIpAddress&signature=FMHv9FRmUFyoBfuMfxAQTbkjz2A%3D&response=json
{noformat}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)