[
https://issues.apache.org/jira/browse/CLOUDSTACK-5927?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Likitha Shetty updated CLOUDSTACK-5927:
---------------------------------------
Description:
Steps to reproduce
====================
1-prepare a 4.2.1 setup with vmware EXI5.1
2-deploy some vms
3-upgrade to ccp 4.3 beta build
4-stop start system vms
Expected
========
stop start vms should work as expected and the root volume of the started vm
should be from the new template
Actual
=======
htting exceptions during storage garbage collection
Observation
===========
1
===
i stopped router vm again and try to start , router vms failed to start
because
StartCommand failed due to Exception: java.lang.RuntimeException
Message: File []/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not found
java.lang.RuntimeException: File
[]/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not found
Logs:
======
system vms
------------
2014-01-21 16:19:37,321 DEBUG [c.c.a.ApiServlet] (catalina-exec-5:ctx-aca3e39e
ctx-0309374b) ===END=== 10.105.180.13 – GET
command=queryAsyncJobResult&jobId=9794da0c-1cf8-4a78-99b5-58021b7346a7&response=json&sessionkey=yBXOfAfOxr1AxfKp12GZhmA4tjE%3D&_=1390319833126
2014-01-21 16:19:37,351 INFO [c.c.h.v.m.DatastoreMO]
(DirectAgent-1:ctx-7a9c245d 10.147.40.8) Found file ROOT-1-flat.vmdk in
datastore at [b420e50b06603053ab6814850b01c333] s-1-VM/
2014-01-21 16:19:37,363 INFO [c.c.h.v.m.DatastoreMO]
(DirectAgent-1:ctx-7a9c245d 10.147.40.8) Search file ROOT-1-flat.vmdk on
[b420e50b06603053ab6814850b01c333] s-1-VM
2014-01-21 16:19:37,503 INFO [c.c.h.v.m.DatastoreMO]
(DirectAgent-1:ctx-7a9c245d 10.147.40.8) File
[b420e50b06603053ab6814850b01c333] s-1-VM/ROOT-1-flat.vmdk exists on datastore
2014-01-21 16:19:37,705 ERROR [c.c.s.r.VmwareStorageProcessor]
(DirectAgent-1:ctx-7a9c245d 10.147.40.8) delete volume failed due to Exception:
java.lang.RuntimeException
Message: Cannot delete file [b420e50b06603053ab6814850b01c333]
s-1-VM/ROOT-1-flat.vmdk
java.lang.RuntimeException: Cannot delete file
[b420e50b06603053ab6814850b01c333] s-1-VM/ROOT-1-flat.vmdk
at
com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:336)
at com.cloud.hypervisor.vmware.mo.DatastoreMO.deleteFile(DatastoreMO.java:175)
at
com.cloud.storage.resource.VmwareStorageLayoutHelper.deleteVolumeVmdkFiles(VmwareStorageLayoutHelper.java:276)
at
com.cloud.storage.resource.VmwareStorageProcessor.deleteVolume(VmwareStorageProcessor.java:1549)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:120)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:54)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:550)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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$101(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
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:679)
2014-01-21 16:19:37,707 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-1:ctx-7a9c245d) Seq 4-1019412823: Response Received:
2014-01-21 16:19:37,708 DEBUG [c.c.a.t.Request] (DirectAgent-1:ctx-7a9c245d)
Seq 4-1019412823: Processing: { Ans: , MgmtId: 7145449848920, via: 4, Ver: v1,
Flags: 10, [{"com.cloud.agent.api.Answer":{"result":false,"details":"delete
volume failed due to Exception: java.lang.RuntimeException\nMessage: Cannot
delete file [b420e50b06603053ab6814850b01c333]
s-1-VM/ROOT-1-flat.vmdk\n","wait":0}}] }
2014-01-21 16:19:37,708 DEBUG [c.c.a.t.Request]
(StorageManager-Scavenger-1:ctx-bad27911) Seq 4-1019412823: Received: { Ans: ,
MgmtId: 7145449848920, via: 4, Ver: v1, Flags: 10,
{ Answer } }
2
—
2014-01-21 16:19:47,237 INFO [c.c.h.v.m.DatastoreMO]
(DirectAgent-232:ctx-3d554e1a 10.147.40.8) File
[b420e50b06603053ab6814850b01c333] v-2-VM/ROOT-2-flat.vmdk exists on datastore
2014-01-21 16:19:47,260 ERROR [c.c.s.r.VmwareStorageProcessor]
(DirectAgent-232:ctx-3d554e1a 10.147.40.8) delete volume failed due to
Exception: java.lang.RuntimeException
Message: Cannot delete file [b420e50b06603053ab6814850b01c333]
v-2-VM/ROOT-2-flat.vmdk
java.lang.RuntimeException: Cannot delete file
[b420e50b06603053ab6814850b01c333] v-2-VM/ROOT-2-flat.vmdk
at
com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:336)
at com.cloud.hypervisor.vmware.mo.DatastoreMO.deleteFile(DatastoreMO.java:175)
at
com.cloud.storage.resource.VmwareStorageLayoutHelper.deleteVolumeVmdkFiles(VmwareStorageLayoutHelper.java:276)
at
com.cloud.storage.resource.VmwareStorageProcessor.deleteVolume(VmwareStorageProcessor.java:1549)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:120)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:54)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:550)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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$101(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
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:679)
2014-01-21 16:19:47,263 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-232:ctx-3d554e1a) Seq 4-1019412824: Response Received:
2014-01-21 16:19:47,263 DEBUG [c.c.a.t.Request] (DirectAgent-232:ctx-3d554e1a)
Seq 4-1019412824: Processing: { Ans: , MgmtId: 7145449848920, via: 4, Ver: v1,
Flags: 10, [{"com.cloud.agent.api.Answer":{"result":false,"details":"delete
volume failed due to Exception: java.lang.RuntimeException\nMessage: Cannot
delete file [b420e50b06603053ab6814850b01c333]
v-2-VM/ROOT-2-flat.vmdk\n","wait":0}}] }
2014-01-21 16:19:47,264 DEBUG [c.c.a.t.Request]
(StorageManager-Scavenger-1:ctx-bad27911) Seq 4-1019412824: Received: { Ans: ,
MgmtId: 7145449848920, via: 4, Ver: v1, Flags: 10, { Answer }
}
router vms
------------
2014-01-21 16:19:47,237 INFO [c.c.h.v.m.DatastoreMO]
(DirectAgent-232:ctx-3d554e1a 10.147.40.8) File
[b420e50b06603053ab6814850b01c333] v-2-VM/ROOT-2-flat.vmdk exists on datastore
2014-01-21 16:19:47,260 ERROR [c.c.s.r.VmwareStorageProcessor]
(DirectAgent-232:ctx-3d554e1a 10.147.40.8) delete volume failed due to
Exception: java.lang.RuntimeException
Message: Cannot delete file [b420e50b06603053ab6814850b01c333]
v-2-VM/ROOT-2-flat.vmdk
java.lang.RuntimeException: Cannot delete file
[b420e50b06603053ab6814850b01c333] v-2-VM/ROOT-2-flat.vmdk
at
com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:336)
at com.cloud.hypervisor.vmware.mo.DatastoreMO.deleteFile(DatastoreMO.java:175)
at
com.cloud.storage.resource.VmwareStorageLayoutHelper.deleteVolumeVmdkFiles(VmwareStorageLayoutHelper.java:276)
at
com.cloud.storage.resource.VmwareStorageProcessor.deleteVolume(VmwareStorageProcessor.java:1549)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:120)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:54)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:550)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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$101(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
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:679)
2014-01-21 16:19:47,263 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-232:ctx-3d554e1a) Seq 4-1019412824: Response Received:
2014-01-21 16:19:47,263 DEBUG [c.c.a.t.Request] (DirectAgent-232:ctx-3d554e1a)
Seq 4-1019412824: Processing: { Ans: , MgmtId: 7145449848920, via: 4, Ver: v1,
Flags: 10, [{"com.cloud.agent.api.Answer":{"result":false,"details":"delete
volume failed due to Exception: java.lang.RuntimeException\nMessage: Cannot
delete file [b420e50b06603053ab6814850b01c333]
v-2-VM/ROOT-2-flat.vmdk\n","wait":0}}] }
2014-01-21 16:19:47,264 DEBUG [c.c.a.t.Request]
(StorageManager-Scavenger-1:ctx-bad27911) Seq 4-1019412824: Received: { Ans: ,
MgmtId: 7145449848920, via: 4, Ver: v1, Flags: 10,
{ Answer }
}
Router vm failed to start
=========================
014-01-22 05:56:39,618 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-12:null) SeqA 3-8138: Sending Seq 3-8138: { Ans: ,
MgmtId: 7145449848920, via: 3, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2014-01-22 05:56:39,673 WARN [c.c.h.v.r.VmwareResource]
(DirectAgent-312:ctx-b4dabd99 10.147.40.8) StartCommand failed due to
Exception: java.lang.RuntimeException
Message: File []/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not found
java.lang.RuntimeException: File
[]/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not found
at
com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:336)
at
com.cloud.hypervisor.vmware.mo.VirtualMachineMO.configureVm(VirtualMachineMO.java:860)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2954)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:504)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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$101(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
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:679)
2014-01-22 05:56:39,678 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-312:ctx-b4dabd99) Seq 4-1019414064: Cancelling because one of the
answers is false and it is stop on error.
2014-01-22 05:56:39,679 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-312:ctx-b4dabd99) Seq 4-1019414064: Response Received:
2014-01-22 05:56:39,681 DEBUG [c.c.a.t.Request] (DirectAgent-312:ctx-b4dabd99)
Seq 4-1019414064: Processing: { Ans: , MgmtId: 7145449848920, via: 4, Ver: v1,
Flags: 110,
[{"com.cloud.agent.api.StartAnswer":{"vm":{"id":4,"name":"r-4-VM","bootloader":"HVM","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":134217728,"maxRam":134217728,"hostName":"r-4-VM","arch":"x86_64","os":"Debian
GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP name=r-4-VM
eth2ip=10.147.55.5 eth2mask=255.255.255.0 gateway=10.147.55.1 eth0ip=10.1.1.1
eth0mask=255.255.255.0 domain=cs2cloud.internal dhcprange=10.1.1.1
eth1ip=10.147.41.215 eth1mask=255.255.254.0 mgmtcidr=10.147.38.0/24
localgw=10.147.40.1 type=router disable_rp_filter=true extra_pubnics=2
dns1=10.140.50.6","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"2afb7fe717a18f1e","params":
{"nicAdapter":"E1000","vmware.reserve.cpu":"false","nestedVirtualizationFlag":"false","rootDiskController":"ide","vmware.reserve.mem":"false"}
,"uuid":"98942dd7-8ae2-4fd7-8af7-4f6a3b3f8a7d","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"f1cf7e15-0345-4a07-8d48-aabb72ea2e59","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b420e50b-0660-3053-ab68-14850b01c333","id":1,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/prashant/pm4","port":2049,"url":"NetworkFilesystem://10.147.28.7//export/home/prashant/pm4/?ROLE=Primary&STOREUUID=b420e50b-0660-3053-ab68-14850b01c333"}},"name":"ROOT-4","size":2097152000,"path":"ROOT-4","volumeId":10,"vmName":"r-4-VM","accountId":2,"chainInfo":"
{\"diskDeviceBusName\":\"scsi0:0\",\"diskChain\":[\"[b420e50b06603053ab6814850b01c333]
r-4-VM/ROOT-4.vmdk\"]}
","format":"OVA","id":10,"deviceId":0,"hypervisorType":"VMware"}},"diskSeq":0,"path":"ROOT-4","type":"ROOT","_details":{"managed":"false","storagePort":"2049","storageHost":"10.147.28.7","volumeSize":"2097152000"}}],"nics":[
{"deviceId":2,"networkRateMbps":200,"defaultNic":true,"uuid":"b7f441f6-769b-4eac-9cd7-667a604a90e1","ip":"10.147.55.5","netmask":"255.255.255.0","gateway":"10.147.55.1","mac":"06:94:64:00:00:0d","dns1":"10.140.50.6","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://55","isolationUri":"vlan://55","isSecurityGroupEnabled":false}
,
{"deviceId":0,"networkRateMbps":200,"defaultNic":false,"uuid":"0da8327c-e0b1-4426-b8d3-bf28addeed5f","ip":"10.1.1.1","netmask":"255.255.255.0","mac":"02:00:7f:9b:00:02","dns1":"10.140.50.6","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1104","isolationUri":"vlan://1104","isSecurityGroupEnabled":false}
,
{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"3e9ad6a2-5686-4966-8144-c7afa24445c8","ip":"10.147.41.215","netmask":"255.255.254.0","gateway":"10.147.40.1","mac":"02:00:4a:f5:00:0a","broadcastType":"Native","type":"Control","isSecurityGroupEnabled":false}
]},"result":false,"details":"StartCommand failed due to Exception:
java.lang.RuntimeException\nMessage: File
[]/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not
found\n","wait":0}}] }
2014-01-22 05:56:39,682 DEBUG [c.c.a.t.Request] (Job-Executor-14:ctx-676a27c3
ctx-b611a5f6) Seq 4-1019414064: Received: { Ans: , MgmtId: 7145449848920, via:
4, Ver: v1, Flags: 110,
{ StartAnswer }
}
2014-01-22 05:56:39,686 DEBUG [c.c.a.m.AgentAttache]
(DirectAgent-312:ctx-b4dabd99) Seq 4-1019414064: No more commands found
2014-01-22 05:56:39,693 INFO [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-14:ctx-676a27c3 ctx-b611a5f6) Unable to start VM on
Host[-4-Routing] due to StartCommand failed due to Exception:
java.lang.RuntimeException
Message: File []/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not found
was:
Steps to reproduce
====================
1-prepare a ACS 4.2.1 setup with vmware EXI5.1
2-deploy some vms
3-upgrade to ccp 4.3 beta build
4-stop start system vms
Expected
========
stop start vms should work as expected and the root volume of the started vm
should be from the new template
Actual
=======
htting exceptions during storage garbage collection
Observation
===========
1
===
i stopped router vm again and try to start , router vms failed to start
because
StartCommand failed due to Exception: java.lang.RuntimeException
Message: File []/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not found
java.lang.RuntimeException: File
[]/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not found
Logs:
======
system vms
------------
2014-01-21 16:19:37,321 DEBUG [c.c.a.ApiServlet] (catalina-exec-5:ctx-aca3e39e
ctx-0309374b) ===END=== 10.105.180.13 – GET
command=queryAsyncJobResult&jobId=9794da0c-1cf8-4a78-99b5-58021b7346a7&response=json&sessionkey=yBXOfAfOxr1AxfKp12GZhmA4tjE%3D&_=1390319833126
2014-01-21 16:19:37,351 INFO [c.c.h.v.m.DatastoreMO]
(DirectAgent-1:ctx-7a9c245d 10.147.40.8) Found file ROOT-1-flat.vmdk in
datastore at [b420e50b06603053ab6814850b01c333] s-1-VM/
2014-01-21 16:19:37,363 INFO [c.c.h.v.m.DatastoreMO]
(DirectAgent-1:ctx-7a9c245d 10.147.40.8) Search file ROOT-1-flat.vmdk on
[b420e50b06603053ab6814850b01c333] s-1-VM
2014-01-21 16:19:37,503 INFO [c.c.h.v.m.DatastoreMO]
(DirectAgent-1:ctx-7a9c245d 10.147.40.8) File
[b420e50b06603053ab6814850b01c333] s-1-VM/ROOT-1-flat.vmdk exists on datastore
2014-01-21 16:19:37,705 ERROR [c.c.s.r.VmwareStorageProcessor]
(DirectAgent-1:ctx-7a9c245d 10.147.40.8) delete volume failed due to Exception:
java.lang.RuntimeException
Message: Cannot delete file [b420e50b06603053ab6814850b01c333]
s-1-VM/ROOT-1-flat.vmdk
java.lang.RuntimeException: Cannot delete file
[b420e50b06603053ab6814850b01c333] s-1-VM/ROOT-1-flat.vmdk
at
com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:336)
at com.cloud.hypervisor.vmware.mo.DatastoreMO.deleteFile(DatastoreMO.java:175)
at
com.cloud.storage.resource.VmwareStorageLayoutHelper.deleteVolumeVmdkFiles(VmwareStorageLayoutHelper.java:276)
at
com.cloud.storage.resource.VmwareStorageProcessor.deleteVolume(VmwareStorageProcessor.java:1549)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:120)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:54)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:550)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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$101(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
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:679)
2014-01-21 16:19:37,707 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-1:ctx-7a9c245d) Seq 4-1019412823: Response Received:
2014-01-21 16:19:37,708 DEBUG [c.c.a.t.Request] (DirectAgent-1:ctx-7a9c245d)
Seq 4-1019412823: Processing: { Ans: , MgmtId: 7145449848920, via: 4, Ver: v1,
Flags: 10, [{"com.cloud.agent.api.Answer":{"result":false,"details":"delete
volume failed due to Exception: java.lang.RuntimeException\nMessage: Cannot
delete file [b420e50b06603053ab6814850b01c333]
s-1-VM/ROOT-1-flat.vmdk\n","wait":0}}] }
2014-01-21 16:19:37,708 DEBUG [c.c.a.t.Request]
(StorageManager-Scavenger-1:ctx-bad27911) Seq 4-1019412823: Received: { Ans: ,
MgmtId: 7145449848920, via: 4, Ver: v1, Flags: 10,
{ Answer } }
2
—
2014-01-21 16:19:47,237 INFO [c.c.h.v.m.DatastoreMO]
(DirectAgent-232:ctx-3d554e1a 10.147.40.8) File
[b420e50b06603053ab6814850b01c333] v-2-VM/ROOT-2-flat.vmdk exists on datastore
2014-01-21 16:19:47,260 ERROR [c.c.s.r.VmwareStorageProcessor]
(DirectAgent-232:ctx-3d554e1a 10.147.40.8) delete volume failed due to
Exception: java.lang.RuntimeException
Message: Cannot delete file [b420e50b06603053ab6814850b01c333]
v-2-VM/ROOT-2-flat.vmdk
java.lang.RuntimeException: Cannot delete file
[b420e50b06603053ab6814850b01c333] v-2-VM/ROOT-2-flat.vmdk
at
com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:336)
at com.cloud.hypervisor.vmware.mo.DatastoreMO.deleteFile(DatastoreMO.java:175)
at
com.cloud.storage.resource.VmwareStorageLayoutHelper.deleteVolumeVmdkFiles(VmwareStorageLayoutHelper.java:276)
at
com.cloud.storage.resource.VmwareStorageProcessor.deleteVolume(VmwareStorageProcessor.java:1549)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:120)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:54)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:550)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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$101(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
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:679)
2014-01-21 16:19:47,263 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-232:ctx-3d554e1a) Seq 4-1019412824: Response Received:
2014-01-21 16:19:47,263 DEBUG [c.c.a.t.Request] (DirectAgent-232:ctx-3d554e1a)
Seq 4-1019412824: Processing: { Ans: , MgmtId: 7145449848920, via: 4, Ver: v1,
Flags: 10, [{"com.cloud.agent.api.Answer":{"result":false,"details":"delete
volume failed due to Exception: java.lang.RuntimeException\nMessage: Cannot
delete file [b420e50b06603053ab6814850b01c333]
v-2-VM/ROOT-2-flat.vmdk\n","wait":0}}] }
2014-01-21 16:19:47,264 DEBUG [c.c.a.t.Request]
(StorageManager-Scavenger-1:ctx-bad27911) Seq 4-1019412824: Received: { Ans: ,
MgmtId: 7145449848920, via: 4, Ver: v1, Flags: 10, { Answer }
}
router vms
------------
2014-01-21 16:19:47,237 INFO [c.c.h.v.m.DatastoreMO]
(DirectAgent-232:ctx-3d554e1a 10.147.40.8) File
[b420e50b06603053ab6814850b01c333] v-2-VM/ROOT-2-flat.vmdk exists on datastore
2014-01-21 16:19:47,260 ERROR [c.c.s.r.VmwareStorageProcessor]
(DirectAgent-232:ctx-3d554e1a 10.147.40.8) delete volume failed due to
Exception: java.lang.RuntimeException
Message: Cannot delete file [b420e50b06603053ab6814850b01c333]
v-2-VM/ROOT-2-flat.vmdk
java.lang.RuntimeException: Cannot delete file
[b420e50b06603053ab6814850b01c333] v-2-VM/ROOT-2-flat.vmdk
at
com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:336)
at com.cloud.hypervisor.vmware.mo.DatastoreMO.deleteFile(DatastoreMO.java:175)
at
com.cloud.storage.resource.VmwareStorageLayoutHelper.deleteVolumeVmdkFiles(VmwareStorageLayoutHelper.java:276)
at
com.cloud.storage.resource.VmwareStorageProcessor.deleteVolume(VmwareStorageProcessor.java:1549)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:120)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:54)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:550)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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$101(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
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:679)
2014-01-21 16:19:47,263 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-232:ctx-3d554e1a) Seq 4-1019412824: Response Received:
2014-01-21 16:19:47,263 DEBUG [c.c.a.t.Request] (DirectAgent-232:ctx-3d554e1a)
Seq 4-1019412824: Processing: { Ans: , MgmtId: 7145449848920, via: 4, Ver: v1,
Flags: 10, [{"com.cloud.agent.api.Answer":{"result":false,"details":"delete
volume failed due to Exception: java.lang.RuntimeException\nMessage: Cannot
delete file [b420e50b06603053ab6814850b01c333]
v-2-VM/ROOT-2-flat.vmdk\n","wait":0}}] }
2014-01-21 16:19:47,264 DEBUG [c.c.a.t.Request]
(StorageManager-Scavenger-1:ctx-bad27911) Seq 4-1019412824: Received: { Ans: ,
MgmtId: 7145449848920, via: 4, Ver: v1, Flags: 10,
{ Answer }
}
Router vm failed to start
=========================
014-01-22 05:56:39,618 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-12:null) SeqA 3-8138: Sending Seq 3-8138: { Ans: ,
MgmtId: 7145449848920, via: 3, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2014-01-22 05:56:39,673 WARN [c.c.h.v.r.VmwareResource]
(DirectAgent-312:ctx-b4dabd99 10.147.40.8) StartCommand failed due to
Exception: java.lang.RuntimeException
Message: File []/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not found
java.lang.RuntimeException: File
[]/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not found
at
com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:336)
at
com.cloud.hypervisor.vmware.mo.VirtualMachineMO.configureVm(VirtualMachineMO.java:860)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2954)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:504)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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$101(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
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:679)
2014-01-22 05:56:39,678 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-312:ctx-b4dabd99) Seq 4-1019414064: Cancelling because one of the
answers is false and it is stop on error.
2014-01-22 05:56:39,679 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-312:ctx-b4dabd99) Seq 4-1019414064: Response Received:
2014-01-22 05:56:39,681 DEBUG [c.c.a.t.Request] (DirectAgent-312:ctx-b4dabd99)
Seq 4-1019414064: Processing: { Ans: , MgmtId: 7145449848920, via: 4, Ver: v1,
Flags: 110,
[{"com.cloud.agent.api.StartAnswer":{"vm":{"id":4,"name":"r-4-VM","bootloader":"HVM","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":134217728,"maxRam":134217728,"hostName":"r-4-VM","arch":"x86_64","os":"Debian
GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP name=r-4-VM
eth2ip=10.147.55.5 eth2mask=255.255.255.0 gateway=10.147.55.1 eth0ip=10.1.1.1
eth0mask=255.255.255.0 domain=cs2cloud.internal dhcprange=10.1.1.1
eth1ip=10.147.41.215 eth1mask=255.255.254.0 mgmtcidr=10.147.38.0/24
localgw=10.147.40.1 type=router disable_rp_filter=true extra_pubnics=2
dns1=10.140.50.6","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"2afb7fe717a18f1e","params":
{"nicAdapter":"E1000","vmware.reserve.cpu":"false","nestedVirtualizationFlag":"false","rootDiskController":"ide","vmware.reserve.mem":"false"}
,"uuid":"98942dd7-8ae2-4fd7-8af7-4f6a3b3f8a7d","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"f1cf7e15-0345-4a07-8d48-aabb72ea2e59","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b420e50b-0660-3053-ab68-14850b01c333","id":1,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/prashant/pm4","port":2049,"url":"NetworkFilesystem://10.147.28.7//export/home/prashant/pm4/?ROLE=Primary&STOREUUID=b420e50b-0660-3053-ab68-14850b01c333"}},"name":"ROOT-4","size":2097152000,"path":"ROOT-4","volumeId":10,"vmName":"r-4-VM","accountId":2,"chainInfo":"
{\"diskDeviceBusName\":\"scsi0:0\",\"diskChain\":[\"[b420e50b06603053ab6814850b01c333]
r-4-VM/ROOT-4.vmdk\"]}
","format":"OVA","id":10,"deviceId":0,"hypervisorType":"VMware"}},"diskSeq":0,"path":"ROOT-4","type":"ROOT","_details":{"managed":"false","storagePort":"2049","storageHost":"10.147.28.7","volumeSize":"2097152000"}}],"nics":[
{"deviceId":2,"networkRateMbps":200,"defaultNic":true,"uuid":"b7f441f6-769b-4eac-9cd7-667a604a90e1","ip":"10.147.55.5","netmask":"255.255.255.0","gateway":"10.147.55.1","mac":"06:94:64:00:00:0d","dns1":"10.140.50.6","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://55","isolationUri":"vlan://55","isSecurityGroupEnabled":false}
,
{"deviceId":0,"networkRateMbps":200,"defaultNic":false,"uuid":"0da8327c-e0b1-4426-b8d3-bf28addeed5f","ip":"10.1.1.1","netmask":"255.255.255.0","mac":"02:00:7f:9b:00:02","dns1":"10.140.50.6","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1104","isolationUri":"vlan://1104","isSecurityGroupEnabled":false}
,
{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"3e9ad6a2-5686-4966-8144-c7afa24445c8","ip":"10.147.41.215","netmask":"255.255.254.0","gateway":"10.147.40.1","mac":"02:00:4a:f5:00:0a","broadcastType":"Native","type":"Control","isSecurityGroupEnabled":false}
]},"result":false,"details":"StartCommand failed due to Exception:
java.lang.RuntimeException\nMessage: File
[]/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not
found\n","wait":0}}] }
2014-01-22 05:56:39,682 DEBUG [c.c.a.t.Request] (Job-Executor-14:ctx-676a27c3
ctx-b611a5f6) Seq 4-1019414064: Received: { Ans: , MgmtId: 7145449848920, via:
4, Ver: v1, Flags: 110,
{ StartAnswer }
}
2014-01-22 05:56:39,686 DEBUG [c.c.a.m.AgentAttache]
(DirectAgent-312:ctx-b4dabd99) Seq 4-1019414064: No more commands found
2014-01-22 05:56:39,693 INFO [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-14:ctx-676a27c3 ctx-b611a5f6) Unable to start VM on
Host[-4-Routing] due to StartCommand failed due to Exception:
java.lang.RuntimeException
Message: File []/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not found
> [UPGRADE] Storage garbage collector is trying to destroy the SSVM/CPVM root
> disk that is in use
> -----------------------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-5927
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5927
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Affects Versions: 4.3.0
> Reporter: Likitha Shetty
> Assignee: Likitha Shetty
> Priority: Critical
> Fix For: 4.3.0
>
>
> Steps to reproduce
> ====================
> 1-prepare a 4.2.1 setup with vmware EXI5.1
> 2-deploy some vms
> 3-upgrade to ccp 4.3 beta build
> 4-stop start system vms
> Expected
> ========
> stop start vms should work as expected and the root volume of the started vm
> should be from the new template
> Actual
> =======
> htting exceptions during storage garbage collection
> Observation
> ===========
> 1
> ===
> i stopped router vm again and try to start , router vms failed to start
> because
> StartCommand failed due to Exception: java.lang.RuntimeException
> Message: File []/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not
> found
> java.lang.RuntimeException: File
> []/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not found
> Logs:
> ======
> system vms
> ------------
> 2014-01-21 16:19:37,321 DEBUG [c.c.a.ApiServlet]
> (catalina-exec-5:ctx-aca3e39e ctx-0309374b) ===END=== 10.105.180.13 – GET
> command=queryAsyncJobResult&jobId=9794da0c-1cf8-4a78-99b5-58021b7346a7&response=json&sessionkey=yBXOfAfOxr1AxfKp12GZhmA4tjE%3D&_=1390319833126
> 2014-01-21 16:19:37,351 INFO [c.c.h.v.m.DatastoreMO]
> (DirectAgent-1:ctx-7a9c245d 10.147.40.8) Found file ROOT-1-flat.vmdk in
> datastore at [b420e50b06603053ab6814850b01c333] s-1-VM/
> 2014-01-21 16:19:37,363 INFO [c.c.h.v.m.DatastoreMO]
> (DirectAgent-1:ctx-7a9c245d 10.147.40.8) Search file ROOT-1-flat.vmdk on
> [b420e50b06603053ab6814850b01c333] s-1-VM
> 2014-01-21 16:19:37,503 INFO [c.c.h.v.m.DatastoreMO]
> (DirectAgent-1:ctx-7a9c245d 10.147.40.8) File
> [b420e50b06603053ab6814850b01c333] s-1-VM/ROOT-1-flat.vmdk exists on datastore
> 2014-01-21 16:19:37,705 ERROR [c.c.s.r.VmwareStorageProcessor]
> (DirectAgent-1:ctx-7a9c245d 10.147.40.8) delete volume failed due to
> Exception: java.lang.RuntimeException
> Message: Cannot delete file [b420e50b06603053ab6814850b01c333]
> s-1-VM/ROOT-1-flat.vmdk
> java.lang.RuntimeException: Cannot delete file
> [b420e50b06603053ab6814850b01c333] s-1-VM/ROOT-1-flat.vmdk
> at
> com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:336)
> at com.cloud.hypervisor.vmware.mo.DatastoreMO.deleteFile(DatastoreMO.java:175)
> at
> com.cloud.storage.resource.VmwareStorageLayoutHelper.deleteVolumeVmdkFiles(VmwareStorageLayoutHelper.java:276)
> at
> com.cloud.storage.resource.VmwareStorageProcessor.deleteVolume(VmwareStorageProcessor.java:1549)
> at
> com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:120)
> at
> com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:54)
> at
> com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:550)
> at
> com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
> 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$101(ScheduledThreadPoolExecutor.java:165)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
> 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:679)
> 2014-01-21 16:19:37,707 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-1:ctx-7a9c245d) Seq 4-1019412823: Response Received:
> 2014-01-21 16:19:37,708 DEBUG [c.c.a.t.Request] (DirectAgent-1:ctx-7a9c245d)
> Seq 4-1019412823: Processing: { Ans: , MgmtId: 7145449848920, via: 4, Ver:
> v1, Flags: 10,
> [{"com.cloud.agent.api.Answer":{"result":false,"details":"delete volume
> failed due to Exception: java.lang.RuntimeException\nMessage: Cannot delete
> file [b420e50b06603053ab6814850b01c333]
> s-1-VM/ROOT-1-flat.vmdk\n","wait":0}}] }
> 2014-01-21 16:19:37,708 DEBUG [c.c.a.t.Request]
> (StorageManager-Scavenger-1:ctx-bad27911) Seq 4-1019412823: Received: { Ans:
> , MgmtId: 7145449848920, via: 4, Ver: v1, Flags: 10,
> { Answer } }
> 2
> —
> 2014-01-21 16:19:47,237 INFO [c.c.h.v.m.DatastoreMO]
> (DirectAgent-232:ctx-3d554e1a 10.147.40.8) File
> [b420e50b06603053ab6814850b01c333] v-2-VM/ROOT-2-flat.vmdk exists on datastore
> 2014-01-21 16:19:47,260 ERROR [c.c.s.r.VmwareStorageProcessor]
> (DirectAgent-232:ctx-3d554e1a 10.147.40.8) delete volume failed due to
> Exception: java.lang.RuntimeException
> Message: Cannot delete file [b420e50b06603053ab6814850b01c333]
> v-2-VM/ROOT-2-flat.vmdk
> java.lang.RuntimeException: Cannot delete file
> [b420e50b06603053ab6814850b01c333] v-2-VM/ROOT-2-flat.vmdk
> at
> com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:336)
> at com.cloud.hypervisor.vmware.mo.DatastoreMO.deleteFile(DatastoreMO.java:175)
> at
> com.cloud.storage.resource.VmwareStorageLayoutHelper.deleteVolumeVmdkFiles(VmwareStorageLayoutHelper.java:276)
> at
> com.cloud.storage.resource.VmwareStorageProcessor.deleteVolume(VmwareStorageProcessor.java:1549)
> at
> com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:120)
> at
> com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:54)
> at
> com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:550)
> at
> com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
> 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$101(ScheduledThreadPoolExecutor.java:165)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
> 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:679)
> 2014-01-21 16:19:47,263 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-232:ctx-3d554e1a) Seq 4-1019412824: Response Received:
> 2014-01-21 16:19:47,263 DEBUG [c.c.a.t.Request]
> (DirectAgent-232:ctx-3d554e1a) Seq 4-1019412824: Processing: { Ans: , MgmtId:
> 7145449848920, via: 4, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.Answer":{"result":false,"details":"delete volume
> failed due to Exception: java.lang.RuntimeException\nMessage: Cannot delete
> file [b420e50b06603053ab6814850b01c333]
> v-2-VM/ROOT-2-flat.vmdk\n","wait":0}}] }
> 2014-01-21 16:19:47,264 DEBUG [c.c.a.t.Request]
> (StorageManager-Scavenger-1:ctx-bad27911) Seq 4-1019412824: Received: { Ans:
> , MgmtId: 7145449848920, via: 4, Ver: v1, Flags: 10, { Answer }
> }
> router vms
> ------------
> 2014-01-21 16:19:47,237 INFO [c.c.h.v.m.DatastoreMO]
> (DirectAgent-232:ctx-3d554e1a 10.147.40.8) File
> [b420e50b06603053ab6814850b01c333] v-2-VM/ROOT-2-flat.vmdk exists on datastore
> 2014-01-21 16:19:47,260 ERROR [c.c.s.r.VmwareStorageProcessor]
> (DirectAgent-232:ctx-3d554e1a 10.147.40.8) delete volume failed due to
> Exception: java.lang.RuntimeException
> Message: Cannot delete file [b420e50b06603053ab6814850b01c333]
> v-2-VM/ROOT-2-flat.vmdk
> java.lang.RuntimeException: Cannot delete file
> [b420e50b06603053ab6814850b01c333] v-2-VM/ROOT-2-flat.vmdk
> at
> com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:336)
> at com.cloud.hypervisor.vmware.mo.DatastoreMO.deleteFile(DatastoreMO.java:175)
> at
> com.cloud.storage.resource.VmwareStorageLayoutHelper.deleteVolumeVmdkFiles(VmwareStorageLayoutHelper.java:276)
> at
> com.cloud.storage.resource.VmwareStorageProcessor.deleteVolume(VmwareStorageProcessor.java:1549)
> at
> com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:120)
> at
> com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:54)
> at
> com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:550)
> at
> com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
> 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$101(ScheduledThreadPoolExecutor.java:165)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
> 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:679)
> 2014-01-21 16:19:47,263 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-232:ctx-3d554e1a) Seq 4-1019412824: Response Received:
> 2014-01-21 16:19:47,263 DEBUG [c.c.a.t.Request]
> (DirectAgent-232:ctx-3d554e1a) Seq 4-1019412824: Processing: { Ans: , MgmtId:
> 7145449848920, via: 4, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.Answer":{"result":false,"details":"delete volume
> failed due to Exception: java.lang.RuntimeException\nMessage: Cannot delete
> file [b420e50b06603053ab6814850b01c333]
> v-2-VM/ROOT-2-flat.vmdk\n","wait":0}}] }
> 2014-01-21 16:19:47,264 DEBUG [c.c.a.t.Request]
> (StorageManager-Scavenger-1:ctx-bad27911) Seq 4-1019412824: Received: { Ans:
> , MgmtId: 7145449848920, via: 4, Ver: v1, Flags: 10,
> { Answer }
> }
> Router vm failed to start
> =========================
> 014-01-22 05:56:39,618 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-12:null) SeqA 3-8138: Sending Seq 3-8138: { Ans: ,
> MgmtId: 7145449848920, via: 3, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2014-01-22 05:56:39,673 WARN [c.c.h.v.r.VmwareResource]
> (DirectAgent-312:ctx-b4dabd99 10.147.40.8) StartCommand failed due to
> Exception: java.lang.RuntimeException
> Message: File []/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not
> found
> java.lang.RuntimeException: File
> []/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not found
> at
> com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:336)
> at
> com.cloud.hypervisor.vmware.mo.VirtualMachineMO.configureVm(VirtualMachineMO.java:860)
> at
> com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2954)
> at
> com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:504)
> at
> com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
> 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$101(ScheduledThreadPoolExecutor.java:165)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
> 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:679)
> 2014-01-22 05:56:39,678 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-312:ctx-b4dabd99) Seq 4-1019414064: Cancelling because one of
> the answers is false and it is stop on error.
> 2014-01-22 05:56:39,679 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-312:ctx-b4dabd99) Seq 4-1019414064: Response Received:
> 2014-01-22 05:56:39,681 DEBUG [c.c.a.t.Request]
> (DirectAgent-312:ctx-b4dabd99) Seq 4-1019414064: Processing: { Ans: , MgmtId:
> 7145449848920, via: 4, Ver: v1, Flags: 110,
> [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":4,"name":"r-4-VM","bootloader":"HVM","type":"DomainRouter","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":134217728,"maxRam":134217728,"hostName":"r-4-VM","arch":"x86_64","os":"Debian
> GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP name=r-4-VM
> eth2ip=10.147.55.5 eth2mask=255.255.255.0 gateway=10.147.55.1 eth0ip=10.1.1.1
> eth0mask=255.255.255.0 domain=cs2cloud.internal dhcprange=10.1.1.1
> eth1ip=10.147.41.215 eth1mask=255.255.254.0 mgmtcidr=10.147.38.0/24
> localgw=10.147.40.1 type=router disable_rp_filter=true extra_pubnics=2
> dns1=10.140.50.6","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"2afb7fe717a18f1e","params":
> {"nicAdapter":"E1000","vmware.reserve.cpu":"false","nestedVirtualizationFlag":"false","rootDiskController":"ide","vmware.reserve.mem":"false"}
> ,"uuid":"98942dd7-8ae2-4fd7-8af7-4f6a3b3f8a7d","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"f1cf7e15-0345-4a07-8d48-aabb72ea2e59","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b420e50b-0660-3053-ab68-14850b01c333","id":1,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/prashant/pm4","port":2049,"url":"NetworkFilesystem://10.147.28.7//export/home/prashant/pm4/?ROLE=Primary&STOREUUID=b420e50b-0660-3053-ab68-14850b01c333"}},"name":"ROOT-4","size":2097152000,"path":"ROOT-4","volumeId":10,"vmName":"r-4-VM","accountId":2,"chainInfo":"
> {\"diskDeviceBusName\":\"scsi0:0\",\"diskChain\":[\"[b420e50b06603053ab6814850b01c333]
> r-4-VM/ROOT-4.vmdk\"]}
> ","format":"OVA","id":10,"deviceId":0,"hypervisorType":"VMware"}},"diskSeq":0,"path":"ROOT-4","type":"ROOT","_details":{"managed":"false","storagePort":"2049","storageHost":"10.147.28.7","volumeSize":"2097152000"}}],"nics":[
> {"deviceId":2,"networkRateMbps":200,"defaultNic":true,"uuid":"b7f441f6-769b-4eac-9cd7-667a604a90e1","ip":"10.147.55.5","netmask":"255.255.255.0","gateway":"10.147.55.1","mac":"06:94:64:00:00:0d","dns1":"10.140.50.6","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://55","isolationUri":"vlan://55","isSecurityGroupEnabled":false}
> ,
> {"deviceId":0,"networkRateMbps":200,"defaultNic":false,"uuid":"0da8327c-e0b1-4426-b8d3-bf28addeed5f","ip":"10.1.1.1","netmask":"255.255.255.0","mac":"02:00:7f:9b:00:02","dns1":"10.140.50.6","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1104","isolationUri":"vlan://1104","isSecurityGroupEnabled":false}
> ,
> {"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"3e9ad6a2-5686-4966-8144-c7afa24445c8","ip":"10.147.41.215","netmask":"255.255.254.0","gateway":"10.147.40.1","mac":"02:00:4a:f5:00:0a","broadcastType":"Native","type":"Control","isSecurityGroupEnabled":false}
> ]},"result":false,"details":"StartCommand failed due to Exception:
> java.lang.RuntimeException\nMessage: File
> []/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not
> found\n","wait":0}}] }
> 2014-01-22 05:56:39,682 DEBUG [c.c.a.t.Request] (Job-Executor-14:ctx-676a27c3
> ctx-b611a5f6) Seq 4-1019414064: Received: { Ans: , MgmtId: 7145449848920,
> via: 4, Ver: v1, Flags: 110,
> { StartAnswer }
> }
> 2014-01-22 05:56:39,686 DEBUG [c.c.a.m.AgentAttache]
> (DirectAgent-312:ctx-b4dabd99) Seq 4-1019414064: No more commands found
> 2014-01-22 05:56:39,693 INFO [c.c.v.VirtualMachineManagerImpl]
> (Job-Executor-14:ctx-676a27c3 ctx-b611a5f6) Unable to start VM on
> Host[-4-Routing] due to StartCommand failed due to Exception:
> java.lang.RuntimeException
> Message: File []/vmfs/volumes/719f4910-4b868123/r-4-VM/ROOT-4.vmdk was not
> found
--
This message was sent by Atlassian JIRA
(v6.1.5#6160)
