You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "prashant kumar mishra (JIRA)" <ji...@apache.org> on 2013/09/17 11:58:52 UTC
[jira] [Comment Edited] (CLOUDSTACK-4641) Create volume form
snapshot command times out exactly after 1 hour in case of KVM hosts.
[ https://issues.apache.org/jira/browse/CLOUDSTACK-4641?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13769377#comment-13769377 ]
prashant kumar mishra edited comment on CLOUDSTACK-4641 at 9/17/13 9:58 AM:
----------------------------------------------------------------------------
Tested on top of commit 5e52a86a2ac8783141c99e8ab34a96fb21b8826a ,it took 3 hour to create volume from snapshot ,went successful
Log
------
-->start time 7:28
2013-09-17 07:28:39,087 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===START=== 10.252.192.86 -- GET command=createVolume&response=json&sessionkey=fP7mNpuqEmQhAS2IgT8UbBXHOwI%3D&snapshotid=40cf4a09-ff00-4caa-87ab-0df36e2fbea9&name=timeout&_=1379397971935
2013-09-17 07:28:39,473 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-10:null) submit async job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ], details: AsyncJobVO {id:53, userId: 2, accountId: 2, sessionKey: null, instanceType: Volume, instanceId: 27, cmd: org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd, cmdOriginator: null, cmdInfo: {"id":"27","response":"json","sessionkey":"fP7mNpuqEmQhAS2IgT8UbBXHOwI\u003d","cmdEventType":"VOLUME.CREATE","ctxUserId":"2","snapshotid":"40cf4a09-ff00-4caa-87ab-0df36e2fbea9","name":"timeout","httpmethod":"GET","_":"1379397971935","ctxAccountId":"2","ctxStartEventId":"221"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 6895939092538, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-09-17 07:28:39,478 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===END=== 10.252.192.86 -- GET command=createVolume&response=json&sessionkey=fP7mNpuqEmQhAS2IgT8UbBXHOwI%3D&snapshotid=40cf4a09-ff00-4caa-87ab-0df36e2fbea9&name=timeout&_=1379397971935
2013-09-17 07:28:39,481 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Executing org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd for job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]
2013-09-17 07:28:39,714 DEBUG [storage.allocator.LocalStoragePoolAllocator] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2013-09-17 07:28:39,719 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Checking if storage pool is suitable, name: null ,poolId: 2
2013-09-17 07:28:39,724 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Checking pool 2 for storage, totalSize: 52844687360, usedBytes: 8709701632, usedPct: 0.16481697720465047, disable threshold: 1.0
2013-09-17 07:28:39,734 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Checking pool: 2 for volume allocation [Vol[27|vm=null|DATADISK]], maxSize : 52844687360, totalAllocatedSize : 8589934592, askingSize : 322122547200, allocated disable threshold: 1.0
2013-09-17 07:28:39,735 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Insufficient un-allocated capacity on: 2 for volume allocation: [Vol[27|vm=null|DATADISK]] since its allocated percentage: 6.258197338533748 has crossed the allocated pool.storage.allocated.capacity.disablethreshold: 1.0, skipping this pool
2013-09-17 07:28:39,737 DEBUG [storage.allocator.LocalStoragePoolAllocator] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) LocalStoragePoolAllocator returning 0 suitable storage pools
2013-09-17 07:28:39,737 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) ClusterScopeStoragePoolAllocator looking for storage pool
2013-09-17 07:28:39,737 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Looking for pools in dc: 1 pod:1 cluster:null
2013-09-17 07:28:39,741 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) No storage pools available for local volume allocation, returning
2013-09-17 07:28:39,742 DEBUG [storage.allocator.ZoneWideStoragePoolAllocator] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) ZoneWideStoragePoolAllocator to find storage pool
-->completion time 10.28
2013-09-17 10:28:40,842 DEBUG [agent.transport.Request] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Seq 1-1699480600: Received: { Ans: , MgmtId: 6895939092538, via: 1, Ver: v1, Flags: 110, { CopyCmdAnswer } }
2013-09-17 10:28:40,847 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-12:null) Seq 1-1699480600: No more commands found
2013-09-17 10:28:40,933 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Complete async job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ], jobStatus: 1, resultCode: 0, result: org.apache.cloudstack.api.response.VolumeResponse@503345a2
2013-09-17 10:28:40,997 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Done executing org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd for job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]
2013-09-17 10:28:41,019 DEBUG [cloud.api.ApiServlet] (catalina-exec-21:null) ===START=== 10.252.192.86 -- GET command=queryAsyncJobResult&jobId=620f6a05-14f0-4906-b113-91e881029cdc&response=json&sessionkey=fP7mNpuqEmQhAS2IgT8UbBXHOwI%3D&_=1379408774322
2013-09-17 10:28:41,037 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-21:null) Async job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ] completed
was (Author: prashantkm):
Tested on top of commit 5e52a86a2ac8783141c99e8ab34a96fb21b8826a
Log
------
2013-09-17 07:28:39,087 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===START=== 10.252.192.86 -- GET command=createVolume&response=json&sessionkey=fP7mNpuqEmQhAS2IgT8UbBXHOwI%3D&snapshotid=40cf4a09-ff00-4caa-87ab-0df36e2fbea9&name=timeout&_=1379397971935
2013-09-17 07:28:39,473 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-10:null) submit async job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ], details: AsyncJobVO {id:53, userId: 2, accountId: 2, sessionKey: null, instanceType: Volume, instanceId: 27, cmd: org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd, cmdOriginator: null, cmdInfo: {"id":"27","response":"json","sessionkey":"fP7mNpuqEmQhAS2IgT8UbBXHOwI\u003d","cmdEventType":"VOLUME.CREATE","ctxUserId":"2","snapshotid":"40cf4a09-ff00-4caa-87ab-0df36e2fbea9","name":"timeout","httpmethod":"GET","_":"1379397971935","ctxAccountId":"2","ctxStartEventId":"221"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 6895939092538, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-09-17 07:28:39,478 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===END=== 10.252.192.86 -- GET command=createVolume&response=json&sessionkey=fP7mNpuqEmQhAS2IgT8UbBXHOwI%3D&snapshotid=40cf4a09-ff00-4caa-87ab-0df36e2fbea9&name=timeout&_=1379397971935
2013-09-17 07:28:39,481 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Executing org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd for job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]
2013-09-17 07:28:39,714 DEBUG [storage.allocator.LocalStoragePoolAllocator] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2013-09-17 07:28:39,719 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Checking if storage pool is suitable, name: null ,poolId: 2
2013-09-17 07:28:39,724 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Checking pool 2 for storage, totalSize: 52844687360, usedBytes: 8709701632, usedPct: 0.16481697720465047, disable threshold: 1.0
2013-09-17 07:28:39,734 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Checking pool: 2 for volume allocation [Vol[27|vm=null|DATADISK]], maxSize : 52844687360, totalAllocatedSize : 8589934592, askingSize : 322122547200, allocated disable threshold: 1.0
2013-09-17 07:28:39,735 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Insufficient un-allocated capacity on: 2 for volume allocation: [Vol[27|vm=null|DATADISK]] since its allocated percentage: 6.258197338533748 has crossed the allocated pool.storage.allocated.capacity.disablethreshold: 1.0, skipping this pool
2013-09-17 07:28:39,737 DEBUG [storage.allocator.LocalStoragePoolAllocator] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) LocalStoragePoolAllocator returning 0 suitable storage pools
2013-09-17 07:28:39,737 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) ClusterScopeStoragePoolAllocator looking for storage pool
2013-09-17 07:28:39,737 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Looking for pools in dc: 1 pod:1 cluster:null
2013-09-17 07:28:39,741 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) No storage pools available for local volume allocation, returning
2013-09-17 07:28:39,742 DEBUG [storage.allocator.ZoneWideStoragePoolAllocator] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) ZoneWideStoragePoolAllocator to find storage pool
2013-09-17 10:28:40,842 DEBUG [agent.transport.Request] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Seq 1-1699480600: Received: { Ans: , MgmtId: 6895939092538, via: 1, Ver: v1, Flags: 110, { CopyCmdAnswer } }
2013-09-17 10:28:40,847 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-12:null) Seq 1-1699480600: No more commands found
2013-09-17 10:28:40,933 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Complete async job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ], jobStatus: 1, resultCode: 0, result: org.apache.cloudstack.api.response.VolumeResponse@503345a2
2013-09-17 10:28:40,997 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-15:job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]) Done executing org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd for job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ]
2013-09-17 10:28:41,019 DEBUG [cloud.api.ApiServlet] (catalina-exec-21:null) ===START=== 10.252.192.86 -- GET command=queryAsyncJobResult&jobId=620f6a05-14f0-4906-b113-91e881029cdc&response=json&sessionkey=fP7mNpuqEmQhAS2IgT8UbBXHOwI%3D&_=1379408774322
2013-09-17 10:28:41,037 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-21:null) Async job-53 = [ 620f6a05-14f0-4906-b113-91e881029cdc ] completed
> Create volume form snapshot command times out exactly after 1 hour in case of KVM hosts.
> ----------------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-4641
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4641
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the default.)
> Components: KVM
> Affects Versions: 4.2.0
> Reporter: edison su
> Assignee: edison su
> Priority: Critical
>
> KVMStoragePoolManager->copyPhysicalDisk doesn't use timeout parameter passed from mgt server during the copy physical disk
--
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