You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by Osay Osman Yuuni <oy...@gmail.com> on 2014/03/14 09:36:27 UTC

4.2.1 Secondary Storage and System VMs Not Working

Hi,
I have previously worked with version 3.0.2 of CloudStack and things worked
very well for me.  I have recently installed 4.2.1 using Xenserver 6.2 (SP1
and SP1002 applied) as hypervisor.  The install from rpm and deb went well
(I had marven issues compiling from source).  When I try creating a zone
all goes well until I get to the deployment and starting of system VMs.
Here the system just keeps going without end.  When I refresh the browser
it takes me into the dashboard, however there system VMs are stopped.  When
I try starting them they fail.  I also see from the dashboard that
secondary storage has 00.00/00.00 as capacity.

The logs show that the secondary storage vm is unable to communicate with
the management server (both are using the same CIDR).  Funny enough there
are no visible VMs in the hypervisor but when I do a xe vm-list I see two
VMs listed with the status of running.

I have used both Ubuntu 12.04.3 LTS and CentOS 6.5 as management server OS
with the very same results.  I have Googled the issue and seen others that
occurred in earlier versions of CS but none of them helped.  I've used an
EMC VNX data mover as NFS for primary storage, and it shows up.  I have
used the management server as the NFS server as well as a separate NFS
server but none works.

I also notice that the ssvm-check.sh script does not exist on the install.
I had to run it from the source and I get the following

First DNS server is  192.168.40.42
PING 192.168.40.42 (192.168.40.42) 56(84) bytes of data.
64 bytes from 192.168.40.42: icmp_req=1 ttl=128 time=42.0 ms
64 bytes from 192.168.40.42: icmp_req=2 ttl=128 time=0.631 ms

--- 192.168.40.42 ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1001ms
rtt min/avg/max/mdev = 0.631/21.322/42.013/20.691 ms
Good: Can ping DNS server
================================================
Good: DNS resolves download.cloud.com
================================================
NFS is currently mounted
Mount point is /proc/fs/nfsd
touch: cannot touch `/proc/fs/nfsd/foo': Permission denied
ERROR: Cannot write to mount point
You need to export with norootsquash
================================================
Management server is . Checking connectivity.
ERROR: Cannot connect to  port 8250
./services/secondary-storage/scripts/ssvm-check.sh: line 111: socat:
command not found

The management server log shows the following:

2014-03-14 10:32:08,281 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Cleaning up resources for the vm
VM[ConsoleProxy|v-2-VM] in Starting state
2014-03-14 10:32:08,286 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-334565838: Sending  { Cmd , MgmtId:
165382419840769, via: 1, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"v-2-VM","wait":0}}]
}
2014-03-14 10:32:08,287 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-334565838: Executing:  { Cmd , MgmtId:
165382419840769, via: 1, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"v-2-VM","wait":0}}]
}
2014-03-14 10:32:08,287 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-274:null) Seq 1-334565838: Executing request
2014-03-14 10:32:08,419 INFO  [xen.resource.CitrixResourceBase]
(DirectAgent-274:null) VM does not exist on
XenServer26eab541-6ced-4e04-b277-badeaff2628a
2014-03-14 10:32:08,419 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-274:null) Seq 1-334565838: Response Received:
2014-03-14 10:32:08,420 DEBUG [agent.transport.Request]
(DirectAgent-274:null) Seq 1-334565838: Processing:  { Ans: , MgmtId:
165382419840769, via: 1, Ver: v1, Flags: 110,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM does not
exist","wait":0}}] }
2014-03-14 10:32:08,420 DEBUG [agent.manager.AgentAttache]
(DirectAgent-274:null) Seq 1-334565838: No more commands found
2014-03-14 10:32:08,420 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-334565838: Received:  { Ans: , MgmtId:
165382419840769, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
2014-03-14 10:32:08,464 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to release
Nic[5-2-a43ac3dd-4191-4a32-8466-a8f181175ddc-192.168.40.180]
2014-03-14 10:32:08,472 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to release
Nic[5-2-a43ac3dd-4191-4a32-8466-a8f181175ddc-192.168.40.180]
2014-03-14 10:32:08,480 DEBUG [network.guru.ControlNetworkGuru]
(consoleproxy-1:null) Released nic: NicProfile[6-2-null-null-null
2014-03-14 10:32:08,499 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
(consoleproxy-1:null) Releasing ip address for
reservationId=a43ac3dd-4191-4a32-8466-a8f181175ddc, instance=7
2014-03-14 10:32:08,501 DEBUG [network.guru.PodBasedNetworkGuru]
(consoleproxy-1:null) Released nic: NicProfile[7-2-null-null-null
2014-03-14 10:32:08,511 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Successfully released network resources for the vm
VM[ConsoleProxy|v-2-VM]
2014-03-14 10:32:08,512 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Successfully cleanued up resources for the vm
VM[ConsoleProxy|v-2-VM] in Starting state
2014-03-14 10:32:08,534 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) VM state transitted from :Starting to Stopped with
event: OperationFailedvm's original host id: 1 new host id: null host id
before state transition: 1
2014-03-14 10:32:08,553 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) Hosts's actual total CPU: 160000 and CPU after
applying overprovisioning: 160000
2014-03-14 10:32:08,554 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) Hosts's actual total RAM: 536778789120 and RAM after
applying overprovisioning: 536778801152
2014-03-14 10:32:08,554 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) release cpu from host: 1, old used: 500,reserved: 0,
actual total: 160000, total with overprovisioning: 160000; new used:
0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-03-14 10:32:08,554 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) release mem from host: 1, old used:
1073741824,reserved: 0, total: 536778801152; new used: 0,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2014-03-14 10:32:08,565 WARN  [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Exception while trying to start console proxy
com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
unreachable: Host 1: Unable to start instance due to null
        at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:999)
        at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:577)
        at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:570)
        at
com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:556)
        at
com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:928)
        at
com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1672)
        at
com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
        at
com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:111)
        at
com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
        at
com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
        at
com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
        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:1146)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:701)
Caused by: java.lang.NullPointerException
        at
org.apache.cloudstack.storage.volume.VolumeServiceImpl.createBaseImageAsync(VolumeServiceImpl.java:428)
        at
org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromTemplateAsync(VolumeServiceImpl.java:575)
        at
com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2577)
        at
com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2641)
        at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:888)
        ... 19 more
2014-03-14 10:32:10,873 DEBUG [cloud.server.StatsCollector]
(StatsCollector-3:null) HostStatsCollector is running...
2014-03-14 10:32:10,895 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-66:null) Seq 1-334565839: Executing request
2014-03-14 10:32:11,257 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-66:null) Seq 1-334565839: Response Received:
2014-03-14 10:32:11,257 DEBUG [agent.transport.Request]
(StatsCollector-3:null) Seq 1-334565839: Received:  { Ans: , MgmtId:
165382419840769, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
2014-03-14 10:32:11,275 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-289:null) Seq 2-1235423719: Executing request
2014-03-14 10:32:11,756 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-289:null) Seq 2-1235423719: Response Received:
2014-03-14 10:32:11,757 DEBUG [agent.transport.Request]
(StatsCollector-3:null) Seq 2-1235423719: Received:  { Ans: , MgmtId:
165382419840769, via: 2, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
2014-03-14 10:32:13,969 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-169:null) Ping from 1
2014-03-14 10:32:15,587 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-169:null) Ping from 2
2014-03-14 10:32:17,014 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-498:null) Seq 1-334561287: Executing request
2014-03-14 10:32:17,429 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-498:null) Seq 1-334561287: Response Received:
2014-03-14 10:32:17,431 DEBUG [agent.transport.Request]
(DirectAgent-498:null) Seq 1-334561287: Processing:  { Ans: , MgmtId:
165382419840769, via: 1, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}]
}
2014-03-14 10:32:17,965 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-281:null) Seq 2-1235419141: Executing request
2014-03-14 10:32:18,154 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-281:null) Seq 2-1235419141: Response Received:
2014-03-14 10:32:18,155 DEBUG [agent.transport.Request]
(DirectAgent-281:null) Seq 2-1235419141: Processing:  { Ans: , MgmtId:
165382419840769, via: 2, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] }
2014-03-14 10:32:25,897 DEBUG [cloud.server.StatsCollector]
(StatsCollector-1:null) StorageCollector is running...
2014-03-14 10:32:25,910 INFO  [storage.endpoint.DefaultEndPointSelector]
(StatsCollector-1:null) No running ssvm is found, so command will be sent
to LocalHostEndPoint
2014-03-14 10:32:25,929 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-126:null) Seq 2-1235423720: Executing request


I have repeated the installation from scratch at least three times with the
same results.  I seem to be stuck now.

BTW I also noted something, which I'm not sure if it's a bug or something
else.  When I use the basic zone wizard and try to use a presetup primary
storage, the protocol does not list anything except NFS.  When I do it
without the wizard then I'm able to select presetup.

TIA

Osay