cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "David Mabry (JIRA)" <j...@apache.org>
Subject [jira] [Created] (CLOUDSTACK-4523) Secondary Storage was offline, but Cloudstack was still attempting to use it to create a template
Date Tue, 27 Aug 2013 19:14:51 GMT
David Mabry created CLOUDSTACK-4523:
---------------------------------------

             Summary: Secondary Storage was offline, but Cloudstack was still attempting to
use it to create a template
                 Key: CLOUDSTACK-4523
                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4523
             Project: CloudStack
          Issue Type: Bug
      Security Level: Public (Anyone can view this level - this is the default.)
          Components: KVM, Template
    Affects Versions: 4.1.1
         Environment: CentOS 6.3 KVM Host with NFS Secondary Storage.
            Reporter: David Mabry
            Priority: Minor


We had an issue with our Secondary Storage that caused it to become unavailable.  The IP wasn't
available and NFS was definitely not running.  When looking in the Cloudstack interface the
Secondary Storage still showed as enabled and showed green.  During the outage, a user attempted
to create a template from a VM and Cloudstack said that is was created successfully and sure
enough the template showed up to be used in the web interface.  Then the user tried to provision
a new VM from the template and Cloudstack returned an error on the VM creation that is detailed
in the logs below.

Once we cleared the issue, the template was still no where to be found and the user had to
recreate the template from the source VM again.

Below are what I think are relevant logs to this issue.  Please let me know if you need more
information.



====Template Creation====
2013-08-27 11:06:43,775 DEBUG [agent.transport.Request] (Job-Executor-148:job-1897) Seq 1-1768326350:
Sending  { Cmd , MgmtId: 159090354809909, via: 1, Ver: v1, Flags: 100011, [{"CreatePrivateTemplateFromVolumeCommand":{"_vmName":"i-48-359-VM","_volumePath":"a8ce8492-34d7-4ec2-86c2-fed1d8077557","_userSpecifiedName":"Wk8r2
Gold - IIS & .net4.5","_uniqueName":"41d2b232-6a60-43b4-b2d7-58e82c095f91","_templateId":317,"_accountId":48,"_primaryPool":{"id":201,"uuid":"d37a92a6-8e01-41d2-ae43-0fad35f092ad","host":"localhost","path":"/store01","port":0,"type":"CLVM"},"_secondaryStorageUrl":"nfs://172.27.15.30/nfs/cssec","primaryStoragePoolNameLabel":"d37a92a6-8e01-41d2-ae43-0fad35f092ad","wait":10800}}]
}
2013-08-27 11:15:46,557 DEBUG [agent.transport.Request] (AgentManager-Handler-8:null) Seq
1-1768326350: Processing:  { Ans: , MgmtId: 159090354809909, via: 1, Ver: v1, Flags: 10, [{"storage.CreatePrivateTemplateAnswer":{"_path":"/template/tmpl/48/317/41d2b232-6a60-43b4-b2d7-58e82c095f91.qcow2","_virtualSize":21474836480,"_physicalSize":12816744448,"_uniqueName":"41d2b232-6a60-43b4-b2d7-58e82c095f91","_format":"QCOW2","result":true,"wait":0}}]
}
2013-08-27 11:15:46,566 DEBUG [agent.transport.Request] (Job-Executor-148:job-1897) Seq 28-183400063:
Sending  { Cmd , MgmtId: 159090354809909, via: 28, Ver: v1, Flags: 100111, [{"ComputeChecksumCommand":{"templatePath":"/template/tmpl/48/317/41d2b232-6a60-43b4-b2d7-58e82c095f91.qcow2","secUrl":"nfs://192.168.15.30/nfs/cssec","wait":0}}]
}
2013-08-27 11:36:37,287 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-5:null) Access
to Tmpl[317-QCOW2-41d2b232-6a60-43b4-b2d7-58e82c095f91 granted to Acct[31-jsmith] by DomainChecker_EnhancerByCloudStack_6e37dedb
2013-08-27 11:36:37,468 DEBUG [cloud.user.AccountManagerImpl] (Job-Executor-149:job-1898)
Access to Tmpl[317-QCOW2-41d2b232-6a60-43b4-b2d7-58e82c095f91 granted to Acct[31-jsmith] by
DomainChecker_EnhancerByCloudStack_6e37dedb
2013-08-27 11:36:50,207 DEBUG [agent.transport.Request] (Job-Executor-149:job-1898) Seq 3-416367865:
Sending  { Cmd , MgmtId: 159090354809909, via: 3, Ver: v1, Flags: 100111, [{"storage.CreateCommand":{"volId":416,"pool":{"id":201,"uuid":"d37a92a6-8e01-41d2-ae43-0fad35f092ad","host":"localhost","path":"/NAzone01cluster01store01","port":0,"type":"CLVM"},"diskCharacteristics":{"size":21474836480,"tags":["prod"],"type":"ROOT","name":"ROOT-361","useLocalStorage":false,"recreatable":true,"diskOfferingId":16,"volumeId":416,"hyperType":"KVM"},"templateUrl":"nfs://192.168.15.30/nfs/cssec//template/tmpl/48/317/41d2b232-6a60-43b4-b2d7-58e82c095f91.qcow2","wait":0}}]
}

======Failed VM Deployment======
2013-08-27 11:39:12,475 DEBUG [agent.transport.Request] (Job-Executor-149:job-1898) Seq 3-416367910:
Received:  { Ans: , MgmtId: 159090354809909, via: 3, Ver: v1, Flags: 110, { StopAnswer } }
2013-08-27 11:39:12,482 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-149:job-1898)
Changing active number of nics for network id=206 on -1
2013-08-27 11:39:12,486 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-149:job-1898)
Changing active number of nics for network id=207 on -1
2013-08-27 11:39:12,487 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-149:job-1898)
Successfully released network resources for the vm VM[User|BuildTwo]
2013-08-27 11:39:12,487 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-149:job-1898)
Successfully cleanued up resources for the vm VM[User|BuildTwo] in Starting state
2013-08-27 11:39:12,489 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-149:job-1898) DeploymentPlanner
allocation algorithm: random
2013-08-27 11:39:12,489 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-149:job-1898) Trying
to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu: 4000, requested
ram: 2147483648
2013-08-27 11:39:12,489 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-149:job-1898) Is
ROOT volume READY (pool already allocated)?: No
2013-08-27 11:39:12,489 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-149:job-1898) DeploymentPlan
has host_id specified, choosing this host and making no checks on this host: 3
2013-08-27 11:39:12,490 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-149:job-1898) Looking
for suitable pools for this host under zone: 1, pod: 1, cluster: 1
2013-08-27 11:39:12,492 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-149:job-1898) Checking
suitable pools for volume (Id, Type): (416,ROOT)
2013-08-27 11:39:12,492 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-149:job-1898) We
need to allocate new storagepool for this volume
2013-08-27 11:39:12,493 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-149:job-1898) Calling
StoragePoolAllocators to find suitable pools
2013-08-27 11:39:12,493 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-149:job-1898)
Looking for pools in dc: 1  pod:1  cluster:1 having tags:[prod]
2013-08-27 11:39:12,494 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-149:job-1898)
FirstFitStoragePoolAllocator has 1 pools to check for allocation
2013-08-27 11:39:12,495 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-149:job-1898)
Checking if storage pool is suitable, name: NAzone01cluster01store01 ,poolId: 201
2013-08-27 11:39:12,495 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-149:job-1898)
StoragePool is in avoid set, skipping this pool
2013-08-27 11:39:12,495 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-149:job-1898)
FirstFitStoragePoolAllocator returning 0 suitable storage pools
2013-08-27 11:39:12,495 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-149:job-1898) No
suitable pools found for volume: Vol[416|vm=361|ROOT] under cluster: 1
2013-08-27 11:39:12,495 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-149:job-1898) No
suitable pools found
2013-08-27 11:39:12,495 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-149:job-1898) Cannnot
deploy to specified host, returning.
2013-08-27 11:39:12,498 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-149:job-1898)
VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host
id: null new host id: null host id before state transition: 3
2013-08-27 11:39:12,502 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-149:job-1898)
Hosts's actual total CPU: 60000 and CPU after applying overprovisioning: 90000
2013-08-27 11:39:12,502 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-149:job-1898)
release cpu from host: 3, old used: 60596,reserved: 0, actual total: 60000, total with overprovisioning:
90000; new used: 56596,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-08-27 11:39:12,502 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-149:job-1898)
release mem from host: 3, old used: 39132856320,reserved: 0, total: 101395275776; new used:
36985372672,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-08-27 11:39:12,505 DEBUG [cloud.vm.UserVmManagerImpl] (Job-Executor-149:job-1898) Destroying
vm VM[User|BuildTwo] as it failed to create on Host with Id:null
2013-08-27 11:39:12,510 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-149:job-1898)
VM state transitted from :Stopped to Error with event: OperationFailedToErrorvm's original
host id: null new host id: null host id before state transition: null
2013-08-27 11:39:22,592 INFO  [user.vm.DeployVMCmd] (Job-Executor-149:job-1898) com.cloud.exception.InsufficientServerCapacityException:
Unable to create a deployment for VM[User|BuildTwo]Scope=interface com.cloud.dc.DataCenter;
id=1
2013-08-27 11:39:22,592 INFO  [user.vm.DeployVMCmd] (Job-Executor-149:job-1898) Unable to
create a deployment for VM[User|BuildTwo]
2013-08-27 11:39:22,593 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-149:job-1898)
Complete async job-1898, jobStatus: 2, resultCode: 530, result: Error Code: 533 Error text:
Unable to create a deployment for VM[User|BuildTwo]



--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Mime
View raw message