You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Sanjeev N (JIRA)" <ji...@apache.org> on 2013/07/04 13:11:47 UTC
[jira] [Created] (CLOUDSTACK-3359) [Object_Store_Refactor] Failed
to bring up System VMs with s3 as the storage provider
Sanjeev N created CLOUDSTACK-3359:
-------------------------------------
Summary: [Object_Store_Refactor] Failed to bring up System VMs with s3 as the storage provider
Key: CLOUDSTACK-3359
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-3359
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Install and Setup
Affects Versions: 4.2.0
Environment: Latest build from master branch
CloudStack-non-OSS-MASTER-506-rhel6.3.tar.gz
Reporter: Sanjeev N
Priority: Blocker
Fix For: 4.2.0
Attachments: management-server.rar
Failed to bring up System VMs with s3 as the storage provider
Steps to Reproduce:
==================
1.Bring up CS in advanced zone with S3 as the storage provider with xen cluster
After adding s3 provider , system template was successfully downloaded to S3 image store. However bringing up system vms failed with following exceptions:
2013-07-04 12:12:07,762 INFO [storage.template.S3TemplateDownloader] (pool-15-thread-1:null) Starting download from http://10.147.28.7/templates/newsysvmtemp/systemvmtemplate-2013-06-23-master-xen.vhd.bz2 to s3 bucket imagestore remoteSize=222905783 , max size=53687091200
2013-07-04 12:12:07,764 DEBUG [cloud.utils.S3Utils] (pool-15-thread-1:null) Creating S3 client with configuration: [protocol: http, connectionTimeOut: 50000, maxErrorRetry: 3, socketTimeout: 50000]
2013-07-04 12:12:07,790 DEBUG [cloud.utils.S3Utils] (pool-15-thread-1:null) Setting the end point for S3 client com.amazonaws.services.s3.AmazonS3Client@33cc26b8 to 10.147.29.57:8080.
2013-07-04 12:12:19,921 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) VmStatsCollector is running...
2013-07-04 12:12:23,760 INFO [storage.template.S3TemplateDownloader] (s3-transfer-manager-worker-1:null) download completed
2013-07-04 12:12:23,767 INFO [storage.template.S3TemplateDownloader] (s3-transfer-manager-worker-1:null) download completed
2013-07-04 12:12:23,767 INFO [storage.template.DownloadManagerImpl] (pool-15-thread-1:null) Download Completion for jobId: 873e9285-5ec4-48eb-a8c6-597d63ee5cbe, status=DOWNLOAD_FINISHED
2013-07-04 12:12:23,767 INFO [storage.template.DownloadManagerImpl] (pool-15-thread-1:null) local: template/tmpl/1/1/routing-1/systemvmtemplate-2013-06-23-master-xen.vhd.bz2, bytes=222905783, error= , pct=100
2013-07-04 12:13:30,844 DEBUG [storage.motion.AncientDataMotionStrategy] (secstorage-1:null) copy object failed: com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@11aa9e9f: SELECT template_store_ref.id, template_store_ref.store_id, template_store_ref.template_id, template_store_ref.store_role, template_store_ref.created, template_store_ref.last_updated, template_store_ref.download_pct, template_store_ref.size, template_store_ref.physical_size, template_store_ref.download_state, template_store_ref.local_path, template_store_ref.error_str, template_store_ref.job_id, template_store_ref.install_path, template_store_ref.url, template_store_ref.is_copy, template_store_ref.destroyed, template_store_ref.update_count, template_store_ref.updated, template_store_ref.state, template_store_ref.ref_cnt FROM template_store_ref WHERE template_store_ref.store_id = 1 AND template_store_ref.template_id = 1 AND template_store_ref.destroyed = 0 ORDER BY RAND() LIMIT 1
2013-07-04 12:13:30,846 DEBUG [storage.motion.AncientDataMotionStrategy] (secstorage-1:null) copy failed
com.cloud.utils.exception.CloudRuntimeException: com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@11aa9e9f: SELECT template_store_ref.id, template_store_ref.store_id, template_store_ref.template_id, template_store_ref.store_role, template_store_ref.created, template_store_ref.last_updated, template_store_ref.download_pct, template_store_ref.size, template_store_ref.physical_size, template_store_ref.download_state, template_store_ref.local_path, template_store_ref.error_str, template_store_ref.job_id, template_store_ref.install_path, template_store_ref.url, template_store_ref.is_copy, template_store_ref.destroyed, template_store_ref.update_count, template_store_ref.updated, template_store_ref.state, template_store_ref.ref_cnt FROM template_store_ref WHERE template_store_ref.store_id = 1 AND template_store_ref.template_id = 1 AND template_store_ref.destroyed = 0 ORDER BY RAND() LIMIT 1
at org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyObject(AncientDataMotionStrategy.java:204)
at org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyAsync(AncientDataMotionStrategy.java:351)
at org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:55)
at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createBaseImageAsync(VolumeServiceImpl.java:390)
at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromTemplateAsync(VolumeServiceImpl.java:490)
at com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2485)
at com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2542)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:852)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:557)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:550)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:260)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:683)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1290)
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:104)
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:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
2013-07-04 12:13:30,850 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) Checking if storage pool is suitable, name: null ,poolId: 1
2013-07-04 12:13:30,863 DEBUG [cloud.storage.VolumeManagerImpl] (secstorage-1:null) Unable to create Vol[51|vm=51|ROOT]:com.cloud.utils.exception.CloudRuntimeException: com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@11aa9e9f: SELECT template_store_ref.id, template_store_ref.store_id, template_store_ref.template_id, template_store_ref.store_role, template_store_ref.created, template_store_ref.last_updated, template_store_ref.download_pct, template_store_ref.size, template_store_ref.physical_size, template_store_ref.download_state, template_store_ref.local_path, template_store_ref.error_str, template_store_ref.job_id, template_store_ref.install_path, template_store_ref.url, template_store_ref.is_copy, template_store_ref.destroyed, template_store_ref.update_count, template_store_ref.updated, template_store_ref.state, template_store_ref.ref_cnt FROM template_store_ref WHERE template_store_ref.store_id = 1 AND template_store_ref.template_id = 1 AND template_store_ref.destroyed = 0 ORDER BY RAND() LIMIT 1
2013-07-04 12:13:30,864 INFO [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is unreachable: Unable to create Vol[51|vm=51|ROOT]:com.cloud.utils.exception.CloudRuntimeException: com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@11aa9e9f: SELECT template_store_ref.id, template_store_ref.store_id, template_store_ref.template_id, template_store_ref.store_role, template_store_ref.created, template_store_ref.last_updated, template_store_ref.download_pct, template_store_ref.size, template_store_ref.physical_size, template_store_ref.download_state, template_store_ref.local_path, template_store_ref.error_str, template_store_ref.job_id, template_store_ref.install_path, template_store_ref.url, template_store_ref.is_copy, template_store_ref.destroyed, template_store_ref.update_count, template_store_ref.updated, template_store_ref.state, template_store_ref.ref_cnt FROM template_store_ref WHERE template_store_ref.store_id = 1 AND template_store_ref.template_id = 1 AND template_store_ref.destroyed = 0 ORDER BY RAND() LIMIT 1
at com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2493)
at com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2542)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:852)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:557)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:550)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:260)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:683)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1290)
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:104)
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:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
2013-07-04 12:13:30,862 DEBUG [cloud.storage.StorageManagerImpl] (consoleproxy-1:null) Checking pool 1 for storage, totalSize: 5902284816384, usedBytes: 3571783729152, usedPct: 0.6051527231009215, disable threshold: 0.85
2013-07-04 12:13:30,870 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Cleaning up resources for the vm VM[SecondaryStorageVm|s-51-VM] in Starting state
2013-07-04 12:13:30,873 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-1357447677: Sending { Cmd , MgmtId: 6615759585382, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"s-51-VM","wait":0}}] }
2013-07-04 12:13:30,874 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-1357447677: Executing: { Cmd , MgmtId: 6615759585382, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"s-51-VM","wait":0}}] }
Image store details:
================
mysql> select * from image_store where removed is null;
+----+--------------------------------------------------+---------------------+----------+--------------------------------------------------+----------------+--------+------------+--------------------------------------+--------+---------------------+---------+------------+------------+
| id | name | image_provider_name | protocol | url | data_center_id | scope | role | uuid | parent | created | removed | total_size | used_bytes |
+----+--------------------------------------------------+---------------------+----------+--------------------------------------------------+----------------+--------+------------+--------------------------------------+--------+---------------------+---------+------------+------------+
| 1 | nfs://10.147.28.7/export/home/sanjeev/sec_xen_os | NFS | nfs | nfs://10.147.28.7/export/home/sanjeev/sec_xen_os | 1 | ZONE | ImageCache | ac765666-9d65-4342-a60f-fa57c8c4ef3a | NULL | 2013-07-04 13:21:56 | NULL | NULL | NULL |
| 3 | obj_store | S3 | http | NULL | NULL | REGION | Image | 61b196ef-e946-4a41-bc86-77b499f398e9 | NULL | 2013-07-04 16:11:57 | NULL | NULL | NULL |
+----+--------------------------------------------------+---------------------+----------+--------------------------------------------------+----------------+--------+------------+--------------------------------------+--------+---------------------+---------+------------+------------+
2 rows in set (0.00 sec)
--
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