You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "René Moser (JIRA)" <ji...@apache.org> on 2017/11/16 17:14:00 UTC
[jira] [Updated] (CLOUDSTACK-10144) NPE in listVlanIpRanges
[ https://issues.apache.org/jira/browse/CLOUDSTACK-10144?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
René Moser updated CLOUDSTACK-10144:
------------------------------------
Description:
After deletion of a project with dedicated public IPs without errors, the listVlanIpRanges fails.
In the log, we see this null pointer exception:
2017-11-16 10:21:15,047 ERROR [cloud.api.ApiServer] (catalina-exec-15:ctx-8dab3c6e ctx-b242a5df) unhandled exception executing api command: [Ljava.lang.String;@3c71540
java.lang.NullPointerException
at com.cloud.api.ApiResponseHelper.populateAccount(ApiResponseHelper.java:2198)
at com.cloud.api.ApiResponseHelper.createVlanIpRangeResponse(ApiResponseHelper.java:620)
at org.apache.cloudstack.api.command.admin.vlan.ListVlanIpRangesCmd.execute(ListVlanIpRangesCmd.java:149)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:141)
at com.cloud.api.ApiServer.queueCommand(ApiServer.java:704)
at com.cloud.api.ApiServer.handleRequest(ApiServer.java:529)
at com.cloud.api.ApiServlet.processRequestInContext(ApiServlet.java:288)
at com.cloud.api.ApiServlet$1.run(ApiServlet.java:119)
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:116)
at com.cloud.api.ApiServlet.doGet(ApiServlet.java:78)
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)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:299)
at org.apache.coyote.http11.Http11NioProcessor.process(Http11NioProcessor.java:889)
at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:732)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:2274)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
The related code is:
2193 private void populateAccount(ControlledEntityResponse response, long accountId) {
2194 Account account = ApiDBUtils.findAccountById(accountId);
2195 if (account.getType() == Account.ACCOUNT_TYPE_PROJECT) {
2196 // find the project
2197 Project project = ApiDBUtils.findProjectByProjectAccountId(account.getId());
2198 response.setProjectId(project.getUuid());
2199 response.setProjectName(project.getName());
2200 response.setAccountName(account.getAccountName());
2201 } else {
2202 response.setAccountName(account.getAccountName());
2203 }
2204 }
So the null pointer is the project which can not be found. It seems that the project deletion cleanup didn't process the vlanIpRange correctly. And because the project is deleted findProjectByProjectAccountId can not find the project.
When we go further the log below to trace the project deletion, we see a rollback in releaseAccountSpecificVirtualRanges. However, unfortunately we don't see the reason of the rollback.
2017-11-16 09:16:59,055 INFO [jobs.impl.AsyncJobMonitor] (API-Job-Executor-121:ctx-56a662aa job-1371174) Add job-1371174 into job monitoring
2017-11-16 09:16:59,060 DEBUG [jobs.impl.AsyncJobManagerImpl] (catalina-exec-63:ctx-242e4ae4 ctx-140e1822) submit async job-1371174, details: AsyncJobVO {id:1371174, userId: 222, accountId: 122, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.user.project.DeleteProjectCmd, cmdInfo: {"id":"6049f66d-e0a4-45ff-a1cc-19ad523996b3","response":"json","ctxDetails":"{\"com.cloud.projects.Project\":\"6049f66d-e0a4-45ff-a1cc-19ad523996b3\"}","cmdEventType":"PROJECT.DELETE","ctxUserId":"222","httpmethod":"GET","_":"1510820218991","uuid":"6049f66d-e0a4-45ff-a1cc-19ad523996b3","ctxAccountId":"122","ctxStartEventId":"5426789"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345050593418, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2017-11-16 09:16:59,061 DEBUG [jobs.impl.AsyncJobManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174) Executing AsyncJobVO {id:1371174, userId: 222, accountId: 122, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.user.project.DeleteProjectCmd, cmdInfo: {"id":"6049f66d-e0a4-45ff-a1cc-19ad523996b3","response":"json","ctxDetails":"{\"com.cloud.projects.Project\":\"6049f66d-e0a4-45ff-a1cc-19ad523996b3\"}","cmdEventType":"PROJECT.DELETE","ctxUserId":"222","httpmethod":"GET","_":"1510820218991","uuid":"6049f66d-e0a4-45ff-a1cc-19ad523996b3","ctxAccountId":"122","ctxStartEventId":"5426789"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345050593418, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2017-11-16 09:16:59,080 DEBUG [cloud.projects.ProjectManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Marking project id=74 with state Disabled as a part of project delete...
2017-11-16 09:16:59,097 DEBUG [cloud.projects.ProjectManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Deleting projects Project[74|name=CLAVISIT_CLOUD_REPOSITORY_PROD|domainid=311] internal account id=490 as a part of project cleanup...
2017-11-16 09:16:59,109 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Removed account 490
2017-11-16 09:16:59,118 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Successfully deleted snapshots directories for all volumes under account 490 across all zones
2017-11-16 09:16:59,143 INFO [cloud.template.HypervisorTemplateAdapter] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Delete template from image store: 5aa44ccb-0ca9-4806-9d18-0de47dffd947
2017-11-16 09:16:59,145 DEBUG [storage.image.TemplateDataFactoryImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) template 962 is already in store:3, type:Image
2017-11-16 09:16:59,160 DEBUG [agent.transport.Request] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Seq 104-2582814386297057482: Sending { Cmd , MgmtId: 345050593418, via: 104(s-5878-VM), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/490/962/27e74739-4b54-3493-9250-2f211119327e.ova","origUrl":"http://install.clavisnet.com/raw.ova","uuid":"c15544f0-0b4b-479c-a436-46689ef1a67d","id":962,"format":"OVA","accountId":490,"checksum":"8b230e9f9cabb4369281edc2abc344e4","hvm":true,"displayText":"w2k8r2 Kofax Test AD Srv OS","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://b-cs-secstor.stor.int//ifs/eco/virt/cloud/fs_cs_zone01_secstor","_role":"Image"}},"name":"962-490-17aff0ef-3225-3fbf-af31-f7aab56f3253","hypervisorType":"VMware"}},"wait":0}}] }
2017-11-16 09:16:59,607 DEBUG [agent.transport.Request] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Seq 104-2582814386297057482: Received: { Ans: , MgmtId: 345050593418, via: 104, Ver: v1, Flags: 10, { Answer } }
2017-11-16 09:16:59,642 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Access granted to Acct[3b9e83ea-4ae1-4c65-8995-7b67e82e4500-stxt-adm] to Domain:311/Drittkunden/clavisit/ by AffinityGroupAccessChecker
2017-11-16 09:16:59,656 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Expunging # of vms (accountId=490): 0
2017-11-16 09:16:59,684 INFO [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) deleteAccount: Deleted 1 network groups for account 490
2017-11-16 09:16:59,685 INFO [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) deleteAccount: Deleted 0 affinity groups for account 490
2017-11-16 09:16:59,685 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Deleting networks for account 490
2017-11-16 09:16:59,687 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Deleting vpcs for account 490
2017-11-16 09:16:59,690 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Deleting site-to-site VPN customer gateways for account 490
2017-11-16 09:16:59,705 DEBUG [db.Transaction.Transaction] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Rolling back the transaction: Time = 4 Name = API-Job-Executor-121; called by -TransactionLegacy.rollback:902-TransactionLegacy.removeUpTo:845-TransactionLegacy.close:669-Transaction.execute:49-Transaction.execute:54-ConfigurationManagerImpl.releaseAccountSpecificVirtualRanges:4791-GeneratedMethodAccessor3033.invoke:-1-DelegatingMethodAccessorImpl.invoke:43-Method.invoke:606-AopUtils.invokeJoinpointUsingReflection:317-ReflectiveMethodInvocation.invokeJoinpoint:183-ReflectiveMethodInvocation.proceed:150
2017-11-16 09:16:59,706 WARN [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Failed to cleanup account Acct[6fb2528e-71ae-4603-97b7-0d2f65a442c4-PrjAcct-INVENTORY_PRODUCTION-311] due to
2017-11-16 09:16:59,707 INFO [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Cleanup for account 490 is needed.
2017-11-16 09:16:59,712 DEBUG [cloud.projects.ProjectManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Unassigning all accounts from project Project[74|name=CLAVISIT_CLOUD_REPOSITORY_PROD|domainid=311] as a part of project cleanup...
2017-11-16 09:16:59,715 DEBUG [cloud.projects.ProjectManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Removing all invitations for the project Project[74|name=CLAVISIT_CLOUD_REPOSITORY_PROD|domainid=311] as a part of project cleanup...
2017-11-16 09:16:59,715 DEBUG [projects.dao.ProjectInvitationDaoImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Removed 0 invitations for project id=74
2017-11-16 09:16:59,717 DEBUG [cloud.projects.ProjectManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Accounts are unassign successfully from project Project[74|name=CLAVISIT_CLOUD_REPOSITORY_PROD|domainid=311] as a part of project cleanup...
2017-11-16 09:16:59,731 DEBUG [jobs.impl.AsyncJobManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Complete async job-1371174, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.SuccessResponse/null/{"success":true}
2017-11-16 09:16:59,733 DEBUG [jobs.impl.AsyncJobManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Publish async job-1371174 complete on message bus
2017-11-16 09:16:59,733 DEBUG [jobs.impl.AsyncJobManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Wake up jobs related to job-1371174
2017-11-16 09:16:59,733 DEBUG [jobs.impl.AsyncJobManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Update db status for job-1371174
2017-11-16 09:16:59,735 DEBUG [jobs.impl.AsyncJobManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Wake up jobs joined with job-1371174 and disjoin all subjobs created from job- 1371174
2017-11-16 09:16:59,738 DEBUG [jobs.impl.AsyncJobManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174) Done executing org.apache.cloudstack.api.command.user.project.DeleteProjectCmd for job-1371174
2017-11-16 09:16:59,739 INFO [jobs.impl.AsyncJobMonitor] (API-Job-Executor-121:ctx-56a662aa job-1371174) Remove job-1371174 from job monitoring
was:
After deletion of a project with dedicated public IPs without errors, the listVlanIpRanges fails.
In the log, we see this null pointer exception:
2017-11-16 10:21:15,047 ERROR [cloud.api.ApiServer] (catalina-exec-15:ctx-8dab3c6e ctx-b242a5df) unhandled exception executing api command: [Ljava.lang.String;@3c71540
java.lang.NullPointerException
at com.cloud.api.ApiResponseHelper.populateAccount(ApiResponseHelper.java:2198)
at com.cloud.api.ApiResponseHelper.createVlanIpRangeResponse(ApiResponseHelper.java:620)
at org.apache.cloudstack.api.command.admin.vlan.ListVlanIpRangesCmd.execute(ListVlanIpRangesCmd.java:149)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:141)
at com.cloud.api.ApiServer.queueCommand(ApiServer.java:704)
at com.cloud.api.ApiServer.handleRequest(ApiServer.java:529)
at com.cloud.api.ApiServlet.processRequestInContext(ApiServlet.java:288)
at com.cloud.api.ApiServlet$1.run(ApiServlet.java:119)
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:116)
at com.cloud.api.ApiServlet.doGet(ApiServlet.java:78)
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)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:299)
at org.apache.coyote.http11.Http11NioProcessor.process(Http11NioProcessor.java:889)
at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:732)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:2274)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
The related code is:
2193 private void populateAccount(ControlledEntityResponse response, long accountId) {
2194 Account account = ApiDBUtils.findAccountById(accountId);
2195 if (account.getType() == Account.ACCOUNT_TYPE_PROJECT) {
2196 // find the project
2197 Project project = ApiDBUtils.findProjectByProjectAccountId(account.getId());
2198 response.setProjectId(project.getUuid());
2199 response.setProjectName(project.getName());
2200 response.setAccountName(account.getAccountName());
2201 } else {
2202 response.setAccountName(account.getAccountName());
2203 }
2204 }
So the null pointer is the project which can not be found. It seems that the project deletion cleanup didn't process the vlanIpRange correctly. And because the project is deleted findProjectByProjectAccountId can not find the project.
When we go further the log below to trace the project deletion, we see a rollback in releaseAccountSpecificVirtualRanges. However, unfortunately we don't see the reason of the rollback.
2017-11-16 09:16:59,055 INFO [jobs.impl.AsyncJobMonitor] (API-Job-Executor-121:ctx-56a662aa job-1371174) Add job-1371174 into job monitoring
2017-11-16 09:16:59,060 DEBUG [jobs.impl.AsyncJobManagerImpl] (catalina-exec-63:ctx-242e4ae4 ctx-140e1822) submit async job-1371174, details: AsyncJobVO {id:1371174, userId: 222, accountId: 122, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.user.project.DeleteProjectCmd, cmdInfo: {"id":"6049f66d-e0a4-45ff-a1cc-19ad523996b3","response":"json","ctxDetails":"{\"com.cloud.projects.Project\":\"6049f66d-e0a4-45ff-a1cc-19ad523996b3\"}","cmdEventType":"PROJECT.DELETE","ctxUserId":"222","httpmethod":"GET","_":"1510820218991","uuid":"6049f66d-e0a4-45ff-a1cc-19ad523996b3","ctxAccountId":"122","ctxStartEventId":"5426789"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345050593418, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2017-11-16 09:16:59,061 DEBUG [jobs.impl.AsyncJobManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174) Executing AsyncJobVO {id:1371174, userId: 222, accountId: 122, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.user.project.DeleteProjectCmd, cmdInfo: {"id":"6049f66d-e0a4-45ff-a1cc-19ad523996b3","response":"json","ctxDetails":"{\"com.cloud.projects.Project\":\"6049f66d-e0a4-45ff-a1cc-19ad523996b3\"}","cmdEventType":"PROJECT.DELETE","ctxUserId":"222","httpmethod":"GET","_":"1510820218991","uuid":"6049f66d-e0a4-45ff-a1cc-19ad523996b3","ctxAccountId":"122","ctxStartEventId":"5426789"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345050593418, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2017-11-16 09:16:59,080 DEBUG [cloud.projects.ProjectManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Marking project id=74 with state Disabled as a part of project delete...
2017-11-16 09:16:59,097 DEBUG [cloud.projects.ProjectManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Deleting projects Project[74|name=CLAVISIT_CLOUD_REPOSITORY_PROD|domainid=311] internal account id=490 as a part of project cleanup...
2017-11-16 09:16:59,109 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Removed account 490
2017-11-16 09:16:59,118 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Successfully deleted snapshots directories for all volumes under account 490 across all zones
2017-11-16 09:16:59,143 INFO [cloud.template.HypervisorTemplateAdapter] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Delete template from image store: 5aa44ccb-0ca9-4806-9d18-0de47dffd947
2017-11-16 09:16:59,145 DEBUG [storage.image.TemplateDataFactoryImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) template 962 is already in store:3, type:Image
2017-11-16 09:16:59,160 DEBUG [agent.transport.Request] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Seq 104-2582814386297057482: Sending { Cmd , MgmtId: 345050593418, via: 104(s-5878-VM), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/490/962/27e74739-4b54-3493-9250-2f211119327e.ova","origUrl":"http://install.clavisnet.com/raw.ova","uuid":"c15544f0-0b4b-479c-a436-46689ef1a67d","id":962,"format":"OVA","accountId":490,"checksum":"8b230e9f9cabb4369281edc2abc344e4","hvm":true,"displayText":"w2k8r2 Kofax Test AD Srv OS","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://b-cs-secstor.stor.int//ifs/eco/virt/cloud/fs_cs_zone01_secstor","_role":"Image"}},"name":"962-490-17aff0ef-3225-3fbf-af31-f7aab56f3253","hypervisorType":"VMware"}},"wait":0}}] }
2017-11-16 09:16:59,607 DEBUG [agent.transport.Request] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Seq 104-2582814386297057482: Received: { Ans: , MgmtId: 345050593418, via: 104, Ver: v1, Flags: 10, { Answer } }
2017-11-16 09:16:59,642 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Access granted to Acct[3b9e83ea-4ae1-4c65-8995-7b67e82e4500-stxt-adm] to Domain:311/Drittkunden/clavisit/ by AffinityGroupAccessChecker
2017-11-16 09:16:59,656 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Expunging # of vms (accountId=490): 0
2017-11-16 09:16:59,684 INFO [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) deleteAccount: Deleted 1 network groups for account 490
2017-11-16 09:16:59,685 INFO [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) deleteAccount: Deleted 0 affinity groups for account 490
2017-11-16 09:16:59,685 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Deleting networks for account 490
2017-11-16 09:16:59,687 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Deleting vpcs for account 490
2017-11-16 09:16:59,690 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Deleting site-to-site VPN customer gateways for account 490
2017-11...
> NPE in listVlanIpRanges
> -----------------------
>
> Key: CLOUDSTACK-10144
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-10144
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the default.)
> Components: API
> Reporter: René Moser
> Assignee: René Moser
>
> After deletion of a project with dedicated public IPs without errors, the listVlanIpRanges fails.
> In the log, we see this null pointer exception:
> 2017-11-16 10:21:15,047 ERROR [cloud.api.ApiServer] (catalina-exec-15:ctx-8dab3c6e ctx-b242a5df) unhandled exception executing api command: [Ljava.lang.String;@3c71540
> java.lang.NullPointerException
> at com.cloud.api.ApiResponseHelper.populateAccount(ApiResponseHelper.java:2198)
> at com.cloud.api.ApiResponseHelper.createVlanIpRangeResponse(ApiResponseHelper.java:620)
> at org.apache.cloudstack.api.command.admin.vlan.ListVlanIpRangesCmd.execute(ListVlanIpRangesCmd.java:149)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:141)
> at com.cloud.api.ApiServer.queueCommand(ApiServer.java:704)
> at com.cloud.api.ApiServer.handleRequest(ApiServer.java:529)
> at com.cloud.api.ApiServlet.processRequestInContext(ApiServlet.java:288)
> at com.cloud.api.ApiServlet$1.run(ApiServlet.java:119)
> 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:116)
> at com.cloud.api.ApiServlet.doGet(ApiServlet.java:78)
> 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)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:299)
> at org.apache.coyote.http11.Http11NioProcessor.process(Http11NioProcessor.java:889)
> at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:732)
> at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:2274)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
> The related code is:
> 2193 private void populateAccount(ControlledEntityResponse response, long accountId) {
> 2194 Account account = ApiDBUtils.findAccountById(accountId);
> 2195 if (account.getType() == Account.ACCOUNT_TYPE_PROJECT) {
> 2196 // find the project
> 2197 Project project = ApiDBUtils.findProjectByProjectAccountId(account.getId());
> 2198 response.setProjectId(project.getUuid());
> 2199 response.setProjectName(project.getName());
> 2200 response.setAccountName(account.getAccountName());
> 2201 } else {
> 2202 response.setAccountName(account.getAccountName());
> 2203 }
> 2204 }
> So the null pointer is the project which can not be found. It seems that the project deletion cleanup didn't process the vlanIpRange correctly. And because the project is deleted findProjectByProjectAccountId can not find the project.
> When we go further the log below to trace the project deletion, we see a rollback in releaseAccountSpecificVirtualRanges. However, unfortunately we don't see the reason of the rollback.
> 2017-11-16 09:16:59,055 INFO [jobs.impl.AsyncJobMonitor] (API-Job-Executor-121:ctx-56a662aa job-1371174) Add job-1371174 into job monitoring
> 2017-11-16 09:16:59,060 DEBUG [jobs.impl.AsyncJobManagerImpl] (catalina-exec-63:ctx-242e4ae4 ctx-140e1822) submit async job-1371174, details: AsyncJobVO {id:1371174, userId: 222, accountId: 122, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.user.project.DeleteProjectCmd, cmdInfo: {"id":"6049f66d-e0a4-45ff-a1cc-19ad523996b3","response":"json","ctxDetails":"{\"com.cloud.projects.Project\":\"6049f66d-e0a4-45ff-a1cc-19ad523996b3\"}","cmdEventType":"PROJECT.DELETE","ctxUserId":"222","httpmethod":"GET","_":"1510820218991","uuid":"6049f66d-e0a4-45ff-a1cc-19ad523996b3","ctxAccountId":"122","ctxStartEventId":"5426789"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345050593418, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2017-11-16 09:16:59,061 DEBUG [jobs.impl.AsyncJobManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174) Executing AsyncJobVO {id:1371174, userId: 222, accountId: 122, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.user.project.DeleteProjectCmd, cmdInfo: {"id":"6049f66d-e0a4-45ff-a1cc-19ad523996b3","response":"json","ctxDetails":"{\"com.cloud.projects.Project\":\"6049f66d-e0a4-45ff-a1cc-19ad523996b3\"}","cmdEventType":"PROJECT.DELETE","ctxUserId":"222","httpmethod":"GET","_":"1510820218991","uuid":"6049f66d-e0a4-45ff-a1cc-19ad523996b3","ctxAccountId":"122","ctxStartEventId":"5426789"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 345050593418, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2017-11-16 09:16:59,080 DEBUG [cloud.projects.ProjectManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Marking project id=74 with state Disabled as a part of project delete...
> 2017-11-16 09:16:59,097 DEBUG [cloud.projects.ProjectManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Deleting projects Project[74|name=CLAVISIT_CLOUD_REPOSITORY_PROD|domainid=311] internal account id=490 as a part of project cleanup...
> 2017-11-16 09:16:59,109 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Removed account 490
> 2017-11-16 09:16:59,118 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Successfully deleted snapshots directories for all volumes under account 490 across all zones
> 2017-11-16 09:16:59,143 INFO [cloud.template.HypervisorTemplateAdapter] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Delete template from image store: 5aa44ccb-0ca9-4806-9d18-0de47dffd947
> 2017-11-16 09:16:59,145 DEBUG [storage.image.TemplateDataFactoryImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) template 962 is already in store:3, type:Image
> 2017-11-16 09:16:59,160 DEBUG [agent.transport.Request] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Seq 104-2582814386297057482: Sending { Cmd , MgmtId: 345050593418, via: 104(s-5878-VM), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/490/962/27e74739-4b54-3493-9250-2f211119327e.ova","origUrl":"http://install.clavisnet.com/raw.ova","uuid":"c15544f0-0b4b-479c-a436-46689ef1a67d","id":962,"format":"OVA","accountId":490,"checksum":"8b230e9f9cabb4369281edc2abc344e4","hvm":true,"displayText":"w2k8r2 Kofax Test AD Srv OS","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://b-cs-secstor.stor.int//ifs/eco/virt/cloud/fs_cs_zone01_secstor","_role":"Image"}},"name":"962-490-17aff0ef-3225-3fbf-af31-f7aab56f3253","hypervisorType":"VMware"}},"wait":0}}] }
> 2017-11-16 09:16:59,607 DEBUG [agent.transport.Request] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Seq 104-2582814386297057482: Received: { Ans: , MgmtId: 345050593418, via: 104, Ver: v1, Flags: 10, { Answer } }
> 2017-11-16 09:16:59,642 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Access granted to Acct[3b9e83ea-4ae1-4c65-8995-7b67e82e4500-stxt-adm] to Domain:311/Drittkunden/clavisit/ by AffinityGroupAccessChecker
> 2017-11-16 09:16:59,656 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Expunging # of vms (accountId=490): 0
> 2017-11-16 09:16:59,684 INFO [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) deleteAccount: Deleted 1 network groups for account 490
> 2017-11-16 09:16:59,685 INFO [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) deleteAccount: Deleted 0 affinity groups for account 490
> 2017-11-16 09:16:59,685 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Deleting networks for account 490
> 2017-11-16 09:16:59,687 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Deleting vpcs for account 490
> 2017-11-16 09:16:59,690 DEBUG [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Deleting site-to-site VPN customer gateways for account 490
> 2017-11-16 09:16:59,705 DEBUG [db.Transaction.Transaction] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Rolling back the transaction: Time = 4 Name = API-Job-Executor-121; called by -TransactionLegacy.rollback:902-TransactionLegacy.removeUpTo:845-TransactionLegacy.close:669-Transaction.execute:49-Transaction.execute:54-ConfigurationManagerImpl.releaseAccountSpecificVirtualRanges:4791-GeneratedMethodAccessor3033.invoke:-1-DelegatingMethodAccessorImpl.invoke:43-Method.invoke:606-AopUtils.invokeJoinpointUsingReflection:317-ReflectiveMethodInvocation.invokeJoinpoint:183-ReflectiveMethodInvocation.proceed:150
> 2017-11-16 09:16:59,706 WARN [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Failed to cleanup account Acct[6fb2528e-71ae-4603-97b7-0d2f65a442c4-PrjAcct-INVENTORY_PRODUCTION-311] due to
> 2017-11-16 09:16:59,707 INFO [cloud.user.AccountManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Cleanup for account 490 is needed.
> 2017-11-16 09:16:59,712 DEBUG [cloud.projects.ProjectManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Unassigning all accounts from project Project[74|name=CLAVISIT_CLOUD_REPOSITORY_PROD|domainid=311] as a part of project cleanup...
> 2017-11-16 09:16:59,715 DEBUG [cloud.projects.ProjectManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Removing all invitations for the project Project[74|name=CLAVISIT_CLOUD_REPOSITORY_PROD|domainid=311] as a part of project cleanup...
> 2017-11-16 09:16:59,715 DEBUG [projects.dao.ProjectInvitationDaoImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Removed 0 invitations for project id=74
> 2017-11-16 09:16:59,717 DEBUG [cloud.projects.ProjectManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Accounts are unassign successfully from project Project[74|name=CLAVISIT_CLOUD_REPOSITORY_PROD|domainid=311] as a part of project cleanup...
> 2017-11-16 09:16:59,731 DEBUG [jobs.impl.AsyncJobManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Complete async job-1371174, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.SuccessResponse/null/{"success":true}
> 2017-11-16 09:16:59,733 DEBUG [jobs.impl.AsyncJobManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Publish async job-1371174 complete on message bus
> 2017-11-16 09:16:59,733 DEBUG [jobs.impl.AsyncJobManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Wake up jobs related to job-1371174
> 2017-11-16 09:16:59,733 DEBUG [jobs.impl.AsyncJobManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Update db status for job-1371174
> 2017-11-16 09:16:59,735 DEBUG [jobs.impl.AsyncJobManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174 ctx-3afdce4f) Wake up jobs joined with job-1371174 and disjoin all subjobs created from job- 1371174
> 2017-11-16 09:16:59,738 DEBUG [jobs.impl.AsyncJobManagerImpl] (API-Job-Executor-121:ctx-56a662aa job-1371174) Done executing org.apache.cloudstack.api.command.user.project.DeleteProjectCmd for job-1371174
> 2017-11-16 09:16:59,739 INFO [jobs.impl.AsyncJobMonitor] (API-Job-Executor-121:ctx-56a662aa job-1371174) Remove job-1371174 from job monitoring
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)