[
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)
