Abhinav Roy created CLOUDSTACK-5489:
---------------------------------------
Summary: [Hyper-V] Cloud user doesn't have permissions to create
systemvm folder, due to which systemvm creation fails
Key: CLOUDSTACK-5489
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5489
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Install and Setup, Management Server
Affects Versions: 4.3.0
Environment: Hyper-V, Advanced zone, packaged build
Reporter: Abhinav Roy
Priority: Critical
Fix For: 4.3.0
Ater the installation and configuration of management server when we enable the
zone, system vms fail to come up with the following error :
2013-12-13 14:04:18,460 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-0c3b570c) Seq
1-1091502205: Executing: { Cmd , MgmtId: 280320865129348, via:
1(10.102.192.9), Ver: v1, Flags100011,
[{"com.cloud.agent.api.StartCommand":{"vm":{"id":11,"name":"s-11-VM","type":"SecondaryStorageVm","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":268435456,"maxRam":2685456,"arch":"i686","os":"Debian
GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP type=secstorage
host=10.102.192.125 port=8250 name=s-11-VM zone=1 pod=1 guid=s-11-VM
resourccom.cloud.storage.resource.PremiumSecondaryStorageResource
instance=SecStorage sslcopy=true role=templateProcessor mtu=1500
eth2ip=10.102.196.205 eth2mask=255.255.255.0 gatewa10.102.196.1
public.network.device=eth2 eth0ip=169.254.3.186 eth0mask=255.255.0.0
eth1ip=10.102.195.30 eth1mask=255.255.252.0 mgmtcidr=10.102.192.0/22
localgw=10.102.192.1 prite.network.device=eth1 eth3ip=10.102.195.27
eth3mask=255.255.252.0 storageip=10.102.195.27 storagenetmask=255.255.252.0
storagegateway=10.102.192.1 internaldns1=10.140.50.5
dn=10.140.50.5","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"76b3a66ab7be16c9","params":{},"uuid":"72e8e9fc-c01b-46-9738-07df0ecb2300","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"70d82fc6-6bf5-4cb5-9d84-72079210661b","volumeType":"ROOT","dataStore":{"org.aphe.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"ce50406b-9038-37ba-9b72-6228d5eb0858","id":2,"poolType":"NetworkFilesystem","host":"10.102.192.19","path":"/HYPERV-SMB/abnav-hyperv-ps1?user=abhinav&password=freebsd@123&domain=BLR","port":445,"url":"NetworkFilesystem://10.102.192.19//HYPERV-SMB/abhinav-hyperv-ps1?user=abhinav&password=freebsd@1&domain=BLR/?ROLE=Primary&STOREUUID=ce50406b-9038-37ba-9b72-6228d5eb0858"}},"name":"ROOT-11","size":0,"volumeId":11,"vmName":"s-11-VM","accountId":1,"id":11,"deviceId":0,"hypeisorType":"Hyperv"}},"diskSeq":0,"type":"ROOT","_details":{"managed":"false","storagePort":"445","storageHost":"10.102.192.19","volumeSize":"0"}}],"nics":[{"deviceId":2,"netwoRateMbps":-1,"defaultNic":true,"uuid":"9dc59cab-1ff9-4d69-9af7-f8af8857940f","ip":"10.102.196.205","netmask":"255.255.255.0","gateway":"10.102.196.1","mac":"06:89:44:00:00:1b"dns1":"10.140.50.5","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://100","isolationUri":"vlan://100","isSecurityGroupEnabled":false},{"deviceId":0,"networkRateMb":-1,"defaultNic":false,"uuid":"3ffaa543-69cd-49be-8a3f-1c27b5957694","ip":"169.254.3.186","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:03:ba","broadcastpe":"LinkLocal","type":"Control","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"066ab264-f2ae-4c28-8cf3-ad9247438de6","ip":"10.1.195.30","netmask":"255.255.252.0","gateway":"10.102.192.1","mac":"06:3a:68:00:00:14","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false},{"deviceId":"networkRateMbps":-1,"defaultNic":false,"uuid":"2c822c1b-c5dc-4be5-af51-3a21940526aa","ip":"10.102.195.27","netmask":"255.255.252.0","gateway":"10.102.192.1","mac":"06:18:12:000:11","broadcastType":"Native","type":"Storage","isSecurityGroupEnabled":false}]},"hostIp":"10.102.192.9","executeInSequence":false,"wait":0}},{"com.cloud.agent.api.check.CheSshCommand":{"ip":"169.254.3.186","port":3922,"interval":6,"retries":100,"name":"s-11-VM","wait":0}}]
}
2013-12-13 14:04:18,460 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-66:ctx-d217a482) Seq 1-1091502205: Executing request
2013-12-13 14:04:18,466 ERROR [c.c.h.h.m.HypervManagerImpl]
(DirectAgent-66:ctx-d217a482) Unable to create systemvm folder on secondary
storage. location: /var/cloudstack/mnt//280320865129348.13b62623/systemvm
2013-12-13 14:04:18,466 WARN [c.c.a.m.DirectAgentAttache]
(DirectAgent-66:ctx-d217a482) Seq 1-1091502205: Exception Caught while
executing command
com.cloud.utils.exception.CloudRuntimeException: Unable to create systemvm
folder on secondary storage. location:
/var/cloudstack/mnt/VM/280320865129348.13b62623/systemvm
at
com.cloud.hypervisor.hyperv.manager.HypervManagerImpl.prepareSecondaryStorageStore(HypervManagerImpl.java:160)
at
com.cloud.hypervisor.hyperv.manager.HypervManagerImpl.prepareSecondaryStorageStore(HypervManagerImpl.java:128)
at
com.cloud.hypervisor.hyperv.resource.HypervDirectConnectResource.executeRequest(HypervDirectConnectResource.java:433)
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)
2013-12-13 14:04:18,467 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-66:ctx-d217a482) Seq 1-1091502205: Cancelling because one of the
answers is false and it is stop on err.
2013-12-13 14:04:18,467 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-66:ctx-d217a482) Seq 1-1091502205: Response Received:
2013-12-13 14:04:18,467 DEBUG [c.c.a.t.Request] (DirectAgent-66:ctx-d217a482)
Seq 1-1091502205: Processing: { Ans: , MgmtId: 280320865129348, via: 1, Ver:
v1, Flags: 10,
[{"c.cloud.agent.api.Answer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException:
Unable to create systemvm folder on secondary storage. location:
/var/cloutack/mnt/VM/280320865129348.13b62623/systemvm","wait":0}}] }
2013-12-13 14:04:18,467 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-0c3b570c) Seq
1-1091502205: Received: { Ans: , MgmtId: 280320865129348, via: 1, Ver: v1,
Flags: 10, { Answer }
2013-12-13 14:04:18,471 ERROR [c.c.v.VirtualMachineManagerImpl]
(secstorage-1:ctx-0c3b570c) Failed to start instance
VM[SecondaryStorageVm|s-11-VM]
com.cloud.utils.exception.CloudRuntimeException: Unable to get answer that is
of class com.cloud.agent.api.StartAnswer
at com.cloud.agent.manager.Commands.getAnswer(Commands.java:80)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:932)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:707)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:697)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:261)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:693)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1265)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:123)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50)
at
com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:111)
at
com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:35)
at
com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:88)
at
com.cloud.vm.SystemVmLoadScanner$1.runInContext(SystemVmLoadScanner.java:79)
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$201(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
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)
2013-12-13 14:04:18,475 DEBUG [c.c.v.VirtualMachineManagerImpl]
(secstorage-1:ctx-0c3b570c) Cleaning up resources for the vm
VM[SecondaryStorageVm|s-11-VM] in Starting state
2013-12-13 14:04:18,477 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-0c3b570c) Seq
1-1091502206: Sending { Cmd , MgmtId: 280320865129348, via: 1(10.102.192.9),
Ver: v1, Flags: 1011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"s-11-VM","wait":0}}]
}
2013-12-13 14:04:18,477 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-0c3b570c) Seq
1-1091502206: Executing: { Cmd , MgmtId: 280320865129348, via:
1(10.102.192.9), Ver: v1, Flags100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"s-11-VM","wait":0}}]
}
2013-12-13 14:04:18,478 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-67:ctx-e1e9a8cc) Seq 1-1091502206: Executing request
2013-12-13 14:04:18,478 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-67:ctx-e1e9a8cc) POST request
tohttp://10.102.192.9:8250/api/HypervResource/com.cloud.agent.i.StopCommand
with
contents{"isProxy":false,"executeInSequence":false,"vmName":"s-11-VM","contextMap":{},"wait":0}
2013-12-13 14:04:18,478 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-67:ctx-e1e9a8cc) Sending cmd to
http://10.102.192.9:8250/api/HypervResource/com.cloud.agent.i.StopCommand cmd
data:{"isProxy":false,"executeInSequence":false,"vmName":"s-11-VM","contextMap":{},"wait":0}
2013-12-13 14:04:18,497 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-67:ctx-e1e9a8cc) POST response
is[{"com.cloud.agent.api.StopAnswer":{"result":true,"details"ull,"vm":null,"contextMap":{}}}]
2013-12-13 14:04:18,497 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-67:ctx-e1e9a8cc) executeRequest received response
[{"com.cloud.agent.api.StopAnswer":{"resul:true,"contextMap":{},"wait":0}}]
2013-12-13 14:04:18,497 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-67:ctx-e1e9a8cc) Seq 1-1091502206: Response Received:
2013-12-13 14:04:18,497 DEBUG [c.c.a.t.Request] (DirectAgent-67:ctx-e1e9a8cc)
Seq 1-1091502206: Processing: { Ans: , MgmtId: 280320865129348, via: 1, Ver:
v1, Flags: 10, [{"c.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2013-12-13 14:04:18,497 DEBUG [c.c.a.t.Request] (secstorage-1:ctx-0c3b570c) Seq
1-1091502206: Received: { Ans: , MgmtId: 280320865129348, via: 1, Ver: v1,
Flags: 10, { StopAner } }
2013-12-13 14:04:18,509 DEBUG [c.c.n.g.ControlNetworkGuru]
(secstorage-1:ctx-0c3b570c) Released nic: NicProfile[41-11-null-null-null
2013-12-13 14:04:18,517 DEBUG [c.c.d.d.DataCenterIpAddressDaoImpl]
(secstorage-1:ctx-0c3b570c) Releasing ip address for
reservationId=2a8a38fd-3ef9-4d03-a140-31b799970b6a, insnce=42
2013-12-13 14:04:18,518 DEBUG [c.c.n.g.PodBasedNetworkGuru]
(secstorage-1:ctx-0c3b570c) Released nic: NicProfile[42-11-null-null-null
2013-12-13 14:04:18,545 DEBUG [c.c.d.d.DataCenterIpAddressDaoImpl]
(secstorage-1:ctx-0c3b570c) Releasing ip address for
reservationId=2a8a38fd-3ef9-4d03-a140-31b799970b6a, insnce=43
2013-12-13 14:04:18,545 DEBUG [c.c.n.g.PodBasedNetworkGuru]
(secstorage-1:ctx-0c3b570c) Released nic: NicProfile[43-11-null-null-null
2013-12-13 14:04:18,550 DEBUG [c.c.v.VirtualMachineManagerImpl]
(secstorage-1:ctx-0c3b570c) Successfully released network resources for the vm
VM[SecondaryStorageVm|s-11-VM]
2013-12-13 14:04:18,550 DEBUG [c.c.v.VirtualMachineManagerImpl]
(secstorage-1:ctx-0c3b570c) Successfully cleanued up resources for the vm
VM[SecondaryStorageVm|s-11-VM] in Staing state
2013-12-13 14:04:18,556 DEBUG [c.c.c.CapacityManagerImpl]
(secstorage-1:ctx-0c3b570c) VM state transitted from :Starting to Stopped with
event: OperationFailedvm's original ho id: null new host id: null host id
before state transition: 1
2013-12-13 14:04:18,560 DEBUG [c.c.c.CapacityManagerImpl]
(secstorage-1:ctx-0c3b570c) Hosts's actual total CPU: 9576 and CPU after
applying overprovisioning: 9576
2013-12-13 14:04:18,560 DEBUG [c.c.c.CapacityManagerImpl]
(secstorage-1:ctx-0c3b570c) Hosts's actual total RAM: 17166323712 and RAM after
applying overprovisioning: 1716632371
2013-12-13 14:04:18,560 DEBUG [c.c.c.CapacityManagerImpl]
(secstorage-1:ctx-0c3b570c) release cpu from host: 1, old used: 500,reserved:
0, actual total: 9576, total with overpvisioning: 9576; new used: 0,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2013-12-13 14:04:18,560 DEBUG [c.c.c.CapacityManagerImpl]
(secstorage-1:ctx-0c3b570c) release mem from host: 1, old used:
268435456,reserved: 0, total: 17166323712; new used: reserved:0;
movedfromreserved: false,moveToReserveredfalse
2013-12-13 14:04:18,582 WARN [c.c.s.s.SecondaryStorageManagerImpl]
(secstorage-1:ctx-0c3b570c) Exception while trying to start secondary storage vm
com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
unreachable: Host 1: Unable to start instance due to Unable to get answer that
is of class com.cloud.agent.i.StartAnswer
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1012)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:707)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:697)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:261)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:693)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1265)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:123)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50)
at
com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:111)
at
com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:35)
at
com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:88)
at
com.cloud.vm.SystemVmLoadScanner$1.runInContext(SystemVmLoadScanner.java:79)
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$201(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
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)
Caused by: com.cloud.utils.exception.CloudRuntimeException: Unable to get
answer that is of class com.cloud.agent.api.StartAnswer
at com.cloud.agent.manager.Commands.getAnswer(Commands.java:80)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:932)
... 24 more
2013-12-13 14:04:18,586 INFO [c.c.s.s.SecondaryStorageManagerImpl]
(secstorage-1:ctx-0c3b570c) Unable to start secondary storage vm for standby
capacity, secStorageVm vm Id :1, will recycle it and start a new one
Note : As compared to https://issues.apache.org/jira/browse/CLOUDSTACK-5248 ,
here atleast the mount point which is created is the correct one
/var/cloudstack/mnt/VM/280320865129348.13b62623 .
But the cloud user is not having permissions to write in this directory, due to
which it is not able to create systemvm folder and copy the systemvm iso. It
is working with Root user but not with Cloud user
--
This message was sent by Atlassian JIRA
(v6.1.4#6159)
