[
https://issues.apache.org/jira/browse/CLOUDSTACK-7604?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Chandan Purushothama updated CLOUDSTACK-7604:
---------------------------------------------
Attachment: management-server.zip
> [Automation] NPE during deletion of Volume
> ------------------------------------------
>
> Key: CLOUDSTACK-7604
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-7604
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: Automation, Test, Volumes
> Affects Versions: 4.5.0
> Reporter: Chandan Purushothama
> Priority: Critical
> Fix For: 4.5.0
>
> Attachments: management-server.zip
>
>
> *Null Pointer Exception:*
> {noformat}
> 2014-09-21 16:19:44,090 DEBUG [c.c.v.UserVmManagerImpl]
> (API-Job-Executor-16:ctx-3978d571 job-3320 ctx-d788d20d) Removed vm id=325
> from all load balancers as a part of expunge process
> 2014-09-21 16:19:44,091 DEBUG [c.c.v.UserVmManagerImpl]
> (API-Job-Executor-16:ctx-3978d571 job-3320 ctx-d788d20d) Successfully cleaned
> up vm VM[User|i-163-325-VM] resources as a part of expunge process
> 2014-09-21 16:19:44,098 INFO [c.c.s.VolumeApiServiceImpl]
> (API-Job-Executor-16:ctx-3978d571 job-3320 ctx-d788d20d) Expunging volume 362
> from primary data store
> 2014-09-21 16:19:44,116 DEBUG [c.c.a.t.Request]
> (API-Job-Executor-16:ctx-3978d571 job-3320 ctx-d788d20d) Seq
> 1-5202783469519768584: Sending { Cmd , MgmtId: 16226561876200, via:
> 1(xrtuk-02-05), Ver: v1, Flags: 100011,
> [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"53c820f0-13f4-4fcf-8bf5-ccb2967453a5","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"3161f583-6550-363c-9d0b-44aede011126","id":1,"poolType":"NetworkFilesystem","host":"10.81.24.13","path":"/vol/xenrtnfs/836249-z1NhU1","port":2049,"url":"NetworkFilesystem://10.81.24.13/vol/xenrtnfs/836249-z1NhU1/?ROLE=Primary&STOREUUID=3161f583-6550-363c-9d0b-44aede011126"}},"name":"ROOT-320","size":5368709120,"path":"827d2dae-4b86-4e75-a298-084d70553395","volumeId":362,"accountId":163,"format":"VHD","provisioningType":"THIN","id":362,"hypervisorType":"XenServer"}},"wait":0}}]
> }
> 2014-09-21 16:19:44,117 DEBUG [c.c.a.t.Request]
> (API-Job-Executor-16:ctx-3978d571 job-3320 ctx-d788d20d) Seq
> 1-5202783469519768584: Executing: { Cmd , MgmtId: 16226561876200, via:
> 1(xrtuk-02-05), Ver: v1, Flags: 100011,
> [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"53c820f0-13f4-4fcf-8bf5-ccb2967453a5","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"3161f583-6550-363c-9d0b-44aede011126","id":1,"poolType":"NetworkFilesystem","host":"10.81.24.13","path":"/vol/xenrtnfs/836249-z1NhU1","port":2049,"url":"NetworkFilesystem://10.81.24.13/vol/xenrtnfs/836249-z1NhU1/?ROLE=Primary&STOREUUID=3161f583-6550-363c-9d0b-44aede011126"}},"name":"ROOT-320","size":5368709120,"path":"827d2dae-4b86-4e75-a298-084d70553395","volumeId":362,"accountId":163,"format":"VHD","provisioningType":"THIN","id":362,"hypervisorType":"XenServer"}},"wait":0}}]
> }
> 2014-09-21 16:19:44,117 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-273:ctx-25b5c023) Seq 1-5202783469519768584: Executing request
> 2014-09-21 16:19:44,236 DEBUG [c.c.a.ApiServlet]
> (catalina-exec-7:ctx-2837c726) ===START=== 10.81.29.29 -- GET
> jobid=908d3367-c7db-4bdd-90d6-ebaff799ecd3&apiKey=mLrTCdYRf3-d4xO7DnO-QXw1Uqrdae1uxenHTEPj_ulDpIYTaujsXwkNzARz222s6M4xChsTAE2W-TUur5bKNQ&command=queryAsyncJobResult&response=json&signature=TgBQLMCJxcuRj%2BNOZFHatiLZSzw%3D
> 2014-09-21 16:19:44,253 DEBUG [c.c.a.ApiServlet]
> (catalina-exec-7:ctx-2837c726 ctx-8f7c1e09 ctx-c08f5999) ===END===
> 10.81.29.29 -- GET
> jobid=908d3367-c7db-4bdd-90d6-ebaff799ecd3&apiKey=mLrTCdYRf3-d4xO7DnO-QXw1Uqrdae1uxenHTEPj_ulDpIYTaujsXwkNzARz222s6M4xChsTAE2W-TUur5bKNQ&command=queryAsyncJobResult&response=json&signature=TgBQLMCJxcuRj%2BNOZFHatiLZSzw%3D
> 2014-09-21 16:19:44,517 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-273:ctx-25b5c023) Seq 1-5202783469519768584: Response Received:
> 2014-09-21 16:19:44,517 DEBUG [c.c.a.t.Request]
> (DirectAgent-273:ctx-25b5c023) Seq 1-5202783469519768584: Processing: { Ans:
> , MgmtId: 16226561876200, via: 1, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] }
> 2014-09-21 16:19:44,517 DEBUG [c.c.a.t.Request]
> (API-Job-Executor-16:ctx-3978d571 job-3320 ctx-d788d20d) Seq
> 1-5202783469519768584: Received: { Ans: , MgmtId: 16226561876200, via: 1,
> Ver: v1, Flags: 10, { Answer } }
> 2014-09-21 16:19:44,524 INFO [o.a.c.s.v.VolumeServiceImpl]
> (API-Job-Executor-16:ctx-3978d571 job-3320 ctx-d788d20d) Volume 362 is not
> referred anywhere, remove it from volumes table
> 2014-09-21 16:19:44,534 DEBUG [c.c.h.x.r.XenServerStorageProcessor]
> (DirectAgent-488:ctx-5364176a) Failed to delete volume
> You gave an invalid object reference. The object may have recently been
> deleted. The class parameter gives the type of reference given, and the
> handle parameter echoes the bad value given.
> at com.xensource.xenapi.Types.checkResponse(Types.java:693)
> at com.xensource.xenapi.Connection.dispatch(Connection.java:395)
> at
> com.cloud.hypervisor.xenserver.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:463)
> at com.xensource.xenapi.VDI.destroy(VDI.java:416)
> at
> com.cloud.hypervisor.xenserver.resource.XenServerStorageProcessor.deleteVDI(XenServerStorageProcessor.java:439)
> at
> com.cloud.hypervisor.xenserver.resource.XenServerStorageProcessor.deleteVolume(XenServerStorageProcessor.java:503)
> at
> com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:124)
> at
> com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:57)
> at
> com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:530)
> at
> com.cloud.hypervisor.xenserver.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:64)
> at
> com.cloud.hypervisor.xenserver.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:87)
> at
> com.cloud.hypervisor.xenserver.resource.XenServer620SP1Resource.executeRequest(XenServer620SP1Resource.java:65)
> at
> com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:302)
> at
> org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
> 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
> org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
> at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:722)
> 2014-09-21 16:19:44,539 INFO [c.c.u.AccountManagerImpl]
> (API-Job-Executor-16:ctx-3978d571 job-3320 ctx-d788d20d) deleteAccount:
> Deleted 1 network groups for account 163
> 2014-09-21 16:19:44,542 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-488:ctx-5364176a) Seq 2-5748563449361730931: Response Received:
> 2014-09-21 16:19:44,543 DEBUG [c.c.a.t.Request]
> (DirectAgent-488:ctx-5364176a) Seq 2-5748563449361730931: Processing: { Ans:
> , MgmtId: 16226561876200, via: 2, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.Answer":{"result":false,"details":"You gave an invalid
> object reference. The object may have recently been deleted. The class
> parameter gives the type of reference given, and the handle parameter echoes
> the bad value given.","wait":0}}] }
> 2014-09-21 16:19:44,543 DEBUG [c.c.a.t.Request]
> (StorageManager-Scavenger-2:ctx-ac357425) Seq 2-5748563449361730931:
> Received: { Ans: , MgmtId: 16226561876200, via: 2, Ver: v1, Flags: 10, {
> Answer } }
> 2014-09-21 16:19:44,543 DEBUG [o.a.c.s.v.VolumeObject]
> (StorageManager-Scavenger-2:ctx-ac357425) Failed to update state
> java.lang.NullPointerException
> at com.cloud.utils.fsm.StateMachine2.transitTo(StateMachine2.java:101)
> at
> org.apache.cloudstack.storage.volume.VolumeObject.stateTransit(VolumeObject.java:185)
> at
> org.apache.cloudstack.storage.volume.VolumeObject.processEvent(VolumeObject.java:325)
> at
> org.apache.cloudstack.storage.volume.VolumeServiceImpl.deleteVolumeCallback(VolumeServiceImpl.java:339)
> at sun.reflect.GeneratedMethodAccessor408.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:601)
> at
> org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.dispatch(AsyncCallbackDispatcher.java:148)
> at
> org.apache.cloudstack.framework.async.InplaceAsyncCallbackDriver.performCompletionCallback(InplaceAsyncCallbackDriver.java:25)
> at
> org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.complete(AsyncCallbackDispatcher.java:126)
> at
> org.apache.cloudstack.storage.datastore.driver.CloudStackPrimaryDataStoreDriverImpl.deleteAsync(CloudStackPrimaryDataStoreDriverImpl.java:222)
> at
> org.apache.cloudstack.storage.volume.VolumeServiceImpl.expungeVolumeAsync(VolumeServiceImpl.java:323)
> at
> com.cloud.storage.StorageManagerImpl.cleanupStorage(StorageManagerImpl.java:1058)
> at
> com.cloud.storage.StorageManagerImpl$StorageGarbageCollector.runInContext(StorageManagerImpl.java:1280)
> at
> org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
> 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
> org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at
> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:722)
> 2014-09-21 16:19:44,544 DEBUG [o.a.c.s.v.VolumeServiceImpl]
> (StorageManager-Scavenger-2:ctx-ac357425) ignore delete volume status update
> failure, it will be picked up by storage clean up thread later
> java.lang.NullPointerException
> at
> org.apache.cloudstack.storage.volume.VolumeObject.processEvent(VolumeObject.java:331)
> at
> org.apache.cloudstack.storage.volume.VolumeServiceImpl.deleteVolumeCallback(VolumeServiceImpl.java:339)
> at sun.reflect.GeneratedMethodAccessor408.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:601)
> at
> org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.dispatch(AsyncCallbackDispatcher.java:148)
> at
> org.apache.cloudstack.framework.async.InplaceAsyncCallbackDriver.performCompletionCallback(InplaceAsyncCallbackDriver.java:25)
> at
> org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.complete(AsyncCallbackDispatcher.java:126)
> at
> org.apache.cloudstack.storage.datastore.driver.CloudStackPrimaryDataStoreDriverImpl.deleteAsync(CloudStackPrimaryDataStoreDriverImpl.java:222)
> at
> org.apache.cloudstack.storage.volume.VolumeServiceImpl.expungeVolumeAsync(VolumeServiceImpl.java:323)
> at
> com.cloud.storage.StorageManagerImpl.cleanupStorage(StorageManagerImpl.java:1058)
> at
> com.cloud.storage.StorageManagerImpl$StorageGarbageCollector.runInContext(StorageManagerImpl.java:1280)
> at
> org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
> 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
> org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at
> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:722)
> 2014-09-21 16:19:44,545 INFO [c.c.u.AccountManagerImpl]
> (API-Job-Executor-16:ctx-3978d571 job-3320 ctx-d788d20d) deleteAccount:
> Deleted 0 affinity groups for account 163
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
