Sanjeev N created CLOUDSTACK-2537: ------------------------------------- Summary: [Object_Store_Refactor] System vms failed to come up with S3 as storage provider Key: CLOUDSTACK-2537 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-2537 Project: CloudStack Issue Type: Bug Security Level: Public (Anyone can view this level - this is the default.) Components: Management Server Affects Versions: 4.2.0 Environment: Build from object_store branch Reporter: Sanjeev N Priority: Blocker Fix For: 4.2.0
System vms failed to come up with S3 as storage provider Repro steps: ========== 1.Bring CS in advanced zone with S3 as secondary storage provider 2.Enable the zone Expected Result: ============= As and when S3 gets added to CS, it should download system template to S3 and bring up system vms. Actual Result: =========== System template was successfuly downloaded to S3 but failed to bring up system vms. Observations: ============ 1.After step 1 system template was successfully downloaded to s3 bucket. 2013-05-16 10:40:49,434 INFO [storage.template.S3TemplateDownloader] (pool-2-thread-1:null) No credentials configured for host=10.147.28.7:80 2013-05-16 10:40:49,620 INFO [storage.template.S3TemplateDownloader] (pool-1-thread-1:null) Starting download from http://10.147.28.7/templates/acton/acton-systemvm-02062012.vhd.bz2 to s3 bucket imagestore remoteSize=140616708 , max size=53687091200 2013-05-16 10:40:49,638 DEBUG [cloud.utils.S3Utils] (pool-1-thread-1:null) Creating S3 client with configuration: [protocol: http, connectionTimeOut: 100, maxErrorRetry: 3, socketTimeout: 100] 2013-05-16 10:40:49,995 DEBUG [cloud.utils.S3Utils] (pool-1-thread-1:null) Setting the end point for S3 client com.amazonaws.services.s3.AmazonS3Client@470edb99 to 10.147.29.56:8080. 2013-05-16 10:40:58,970 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) HostStatsCollector is running... 2013-05-16 10:40:58,972 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) VmStatsCollector is running... 2013-05-16 10:40:58,974 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) StorageCollector is running... 2013-05-16 10:40:59,036 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-4:null) Seq 1-1911750666: Executing request 2013-05-16 10:40:59,045 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-5:null) Seq 1-1911750667: Executing request 2013-05-16 10:40:59,271 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-4:null) Seq 1-1911750666: Response Received: 2013-05-16 10:40:59,272 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 1-1911750666: Received: { Ans: , MgmtId: 7332683579487, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } } 2013-05-16 10:40:59,356 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-5:null) Seq 1-1911750667: Response Received: 2013-05-16 10:40:59,357 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 1-1911750667: Received: { Ans: , MgmtId: 7332683579487, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } } 2013-05-16 10:41:01,014 INFO [storage.template.S3TemplateDownloader] (pool-1-thread-1:null) download completed 2013-05-16 10:41:01,016 INFO [storage.template.DownloadManagerImpl] (pool-1-thread-1:null) Download Completion for jobId: 46e0c43d-a743-461f-8b88-16a57ac4bbb8, status=DOWNLOAD_FINISHED 2013-05-16 10:41:01,016 INFO [storage.template.DownloadManagerImpl] (pool-1-thread-1:null) local: template/tmpl/1/1/routing-1/acton-systemvm-02062012.vhd.bz2, bytes=140616708, error= , pct=100 2.After step2 CS tried to bring up the system vms. But failed to create volumes with following exceptions: 2013-05-16 10:43:44,843 DEBUG [cloud.storage.VolumeManagerImpl] (secstorage-1:null) Checking if we need to prepare 1 volumes for VM[SecondaryStorageVm|s-1-VM] 2013-05-16 10:43:45,016 ERROR [storage.resource.NfsSecondaryStorageResource] (secstorage-1:null) Unable to create directory download directory 1 for download from S3. 2013-05-16 10:43:45,025 DEBUG [cloud.storage.VolumeManagerImpl] (secstorage-1:null) Unable to create Vol[1|vm=1|ROOT]:java.lang.NullPointerException 2013-05-16 10:43:45,026 INFO [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Unable to contact resource. com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is unreachable: Unable to create Vol[1|vm=1|ROOT]:java.lang.NullPointerException at com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2355) at com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2404) at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:812) at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:529) at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:522) at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:259) at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:672) at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1282) 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:1146) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:679) 2013-05-16 10:43:45,033 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Cleaning up resources for the vm VM[SecondaryStorageVm|s-1-VM] in Starting state 2013-05-16 10:43:45,036 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-1911750674: Sending { Cmd , MgmtId: 7332683579487, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"vmName":"s-1-VM","wait":0}}] } 2013-05-16 10:43:45,226 WARN [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Exception while trying to start secondary storage vm com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[SecondaryStorageVm|s-1-VM]Scope=interface com.cloud.dc.DataCenter; id=1 at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:782) at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:529) at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:522) at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:259) at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:672) at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1282) 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:1146) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:679) 2013-05-16 10:43:45,227 INFO [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Unable to start secondary storage vm for standby capacity, secStorageVm vm Id : 1, will recycle it and start a new one 2013-05-16 10:43:45,236 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) VM is already stopped: VM[SecondaryStorageVm|s-1-VM] 2013-05-16 10:43:45,244 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) VM state transitted from :Stopped to Expunging with event: ExpungeOperationvm's original host id: null new host id: null host id before state transition: null mysql> select * from image_store\G; *************************** 1. row *************************** id: 1 name: nfs://10.147.28.7/export/home/sanjeev/sec_xen_os image_provider_name: NFS protocol: nfs url: nfs://10.147.28.7/export/home/sanjeev/sec_xen_os data_center_id: 1 scope: ZONE role: ImageCache uuid: fec804a2-c2d9-402e-a04d-1a879b0b0f30 parent: NULL created: 2013-05-16 14:40:38 removed: NULL total_size: NULL *************************** 2. row *************************** id: 2 name: cb4b622e-b292-4d90-99d3-855eaa206999 image_provider_name: S3 protocol: http url: NULL data_center_id: NULL scope: REGION role: Image uuid: cb4b622e-b292-4d90-99d3-855eaa206999 parent: NULL created: 2013-05-16 14:40:38 removed: NULL total_size: NULL 2 rows in set (0.00 sec) ERROR: No query specified mysql> select * from storage_pool\G *************************** 1. row *************************** id: 1 name: pri_xen_os uuid: c65a038a-750c-3b4f-bf26-7ce3b74e1c85 pool_type: NetworkFilesystem port: 2049 data_center_id: 1 pod_id: 1 cluster_id: 1 available_bytes: 3030686924800 capacity_bytes: 5902284816384 host_address: 10.147.28.7 user_info: NULL path: /export/home/sanjeev/pri_xen_os created: 2013-05-16 14:40:28 removed: NULL update_time: NULL status: Up storage_provider_name: DefaultPrimary scope: CLUSTER 1 row in set (0.00 sec) Template status in cloud DB: -- 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