cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Sanjeev N (JIRA)" <j...@apache.org>
Subject [jira] [Created] (CLOUDSTACK-4204) [Object_store_refactor] Snapshot created from volume in zone2 is copying to secondary staging storages in zone1
Date Fri, 09 Aug 2013 07:14:47 GMT
Sanjeev N created CLOUDSTACK-4204:
-------------------------------------

             Summary: [Object_store_refactor] Snapshot created from volume in zone2 is copying
to secondary staging storages in zone1
                 Key: CLOUDSTACK-4204
                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4204
             Project: CloudStack
          Issue Type: Bug
      Security Level: Public (Anyone can view this level - this is the default.)
          Components: Snapshot, Storage Controller
    Affects Versions: 4.2.0
         Environment: Latest build from ACS 4.2 branch.
zones: min of two zones with staging secondary storages
            Reporter: Sanjeev N
            Priority: Critical
             Fix For: 4.2.0


Snapshot created from volume in zone2 is copying to secondary staging storages in zone1

Steps to Reproduce:
=================
1.Bring up CS with two zones
zone1: xen cluster with staging secondary storage with NFS
zone2: vmware cluster with staging secondary storage with NFS
Secondary storage: S3 
2.Deploy guest vm in zone2 with both root and data disk
3.Create snapshot on the root/data disk

Result:
======
Snapshot creation was successful and got copied to S3 but during the snapshot creation process
copyCommand copies the snapshot from primary to secondary staging storage. So it copied to
secondary staging storage in zone1.

Log snippet:
=========
Following is the log snippet from SSVM in vmware zone:

2013-08-09 02:28:24,937 DEBUG [agent.transport.Request] (Job-Executor-58:job-57 = [ ed3d0135-5cbf-4c2c-86c7-bcf9642e2f39
]) Seq 7-983236628: Sending  { Cmd , MgmtId: 6615759585382, via: 7, Ver: v1, Flags: 100011,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"6c91e440-6407-413d-abb7-e27c94abc7b5","volume":{"uuid":"120ec744-88f0-4008-a4ba-17a8bbe9ceda","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b845e7d4-562a-3b2d-8e59-b1df565f99e5","id":4,"poolType":"VMFS","host":"VMFS
datastore: /sanjeev/openFiler","path":"/sanjeev/openFiler","port":0}},"name":"cent53-upload","size":459320832,"path":"c1457d19bf0d4c9bb9e3ef80f916ad93","volumeId":21,"vmName":"i-2-14-VM","accountId":2,"format":"OVA","id":21,"hypervisorType":"VMware"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b845e7d4-562a-3b2d-8e59-b1df565f99e5","id":4,"poolType":"VMFS","host":"VMFS
datastore: /sanjeev/openFiler","path":"/sanjeev/openFiler","port":0}},"vmName":"i-2-14-VM","name":"v1-s1_cent53-upload_20130809062824","hypervisorType":"VMware","id":2}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/21","volume":{"uuid":"120ec744-88f0-4008-a4ba-17a8bbe9ceda","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b845e7d4-562a-3b2d-8e59-b1df565f99e5","id":4,"poolType":"VMFS","host":"VMFS
datastore: /sanjeev/openFiler","path":"/sanjeev/openFiler","port":0}},"name":"cent53-upload","size":459320832,"path":"c1457d19bf0d4c9bb9e3ef80f916ad93","volumeId":21,"vmName":"i-2-14-VM","accountId":2,"format":"OVA","id":21,"hypervisorType":"VMware"},"dataStore":{"com.cloud.agent.api.to.S3TO":{"id":6,"uuid":"4f8c91be-94ce-4e44-a05d-f08584f1d56d","endPoint":"10.147.29.56:8080","bucketName":"imagestore","httpsFlag":false,"created":"Aug
8, 2013 6:25:36 AM","enableRRS":false}},"vmName":"i-2-14-VM","name":"v1-s1_cent53-upload_20130809062824","hypervisorType":"VMware","id":2}},"cacheTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/21","volume":{"uuid":"120ec744-88f0-4008-a4ba-17a8bbe9ceda","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b845e7d4-562a-3b2d-8e59-b1df565f99e5","id":4,"poolType":"VMFS","host":"VMFS
datastore: /sanjeev/openFiler","path":"/sanjeev/openFiler","port":0}},"name":"cent53-upload","size":459320832,"path":"c1457d19bf0d4c9bb9e3ef80f916ad93","volumeId":21,"vmName":"i-2-14-VM","accountId":2,"format":"OVA","id":21,"hypervisorType":"VMware"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/sanjeev/sec_xen_os","_role":"ImageCache"}},"vmName":"i-2-14-VM","name":"v1-s1_cent53-upload_20130809062824","hypervisorType":"VMware","id":2}},"executeInSequence":false,"wait":21600}}]
}
2013-08-09 06:28:24,987 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing
command: org.apache.cloudstack.storage.command.CopyCommand
2013-08-09 06:28:25,137 WARN  [storage.resource.VmwareSecondaryStorageResourceHandler] (agentRequest-Handler-5:null)
Context validation failed due to Exception: java.lang.NullPointerException
Message: null

2013-08-09 06:28:26,174 WARN  [vmware.util.VmwareContext] (agentRequest-Handler-5:null) Unexpected
exception:
javax.xml.ws.soap.SOAPFaultException: The session is not authenticated.
        at com.sun.xml.internal.ws.fault.SOAP11Fault.getProtocolException(SOAP11Fault.java:178)
        at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:119)
        at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:108)
        at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:78)
        at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:107)
        at sun.proxy.$Proxy36.logout(Unknown Source)
        at com.cloud.hypervisor.vmware.util.VmwareClient.disconnect(VmwareClient.java:164)
        at com.cloud.hypervisor.vmware.util.VmwareContext.close(VmwareContext.java:599)
        at com.cloud.storage.resource.VmwareSecondaryStorageContextFactory.invalidate(VmwareSecondaryStorageContextFactory.java:71)
        at com.cloud.storage.resource.VmwareSecondaryStorageResourceHandler.invalidateServiceContext(VmwareSecondaryStorageResourceHandler.java:226)
        at com.cloud.storage.resource.VmwareSecondaryStorageResourceHandler.getServiceContext(VmwareSecondaryStorageResourceHandler.java:209)
        at com.cloud.storage.resource.VmwareStorageProcessor.backupSnapshot(VmwareStorageProcessor.java:1035)
        at com.cloud.storage.resource.VmwareStorageSubsystemCommandHandler.execute(VmwareStorageSubsystemCommandHandler.java:113)
        at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49)
        at com.cloud.storage.resource.VmwareSecondaryStorageResourceHandler.executeRequest(VmwareSecondaryStorageResourceHandler.java:95)
        at com.cloud.storage.resource.PremiumSecondaryStorageResource.executeRequest(PremiumSecondaryStorageResource.java:56)
        at com.cloud.agent.Agent.processRequest(Agent.java:525)
        at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)
        at com.cloud.utils.nio.Task.run(Task.java:83)
        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-08-09 06:28:38,198 DEBUG [storage.resource.VmwareSecondaryStorageResourceHandler] (agentRequest-Handler-5:null)
Context validation succeeded. Validated via host: 10.147.40.13, guid: HostSystem:host-3509@10.147.60.13
2013-08-09 06:28:38,330 INFO  [storage.resource.VmwareSecondaryStorageResourceHandler] (agentRequest-Handler-5:null)
Setup firewall rule for host: 10.147.40.13
2013-08-09 06:28:38,373 DEBUG [vmware.mo.HostMO] (agentRequest-Handler-5:null) find VM i-2-14-VM
on host
2013-08-09 06:28:38,373 INFO  [vmware.mo.HostMO] (agentRequest-Handler-5:null) VM i-2-14-VM
not found in host cache
2013-08-09 06:28:38,373 DEBUG [vmware.mo.HostMO] (agentRequest-Handler-5:null) load VM cache
on host
2013-08-09 06:28:47,637 DEBUG [storage.resource.VmwareStorageProcessor] (agentRequest-Handler-5:null)
Executing: mkdir -p /mnt/SecStorage/1f24310b-8f0b-3563-aecc-779179564245/snapshots/2/21/84e927e7-ba89-4430-a8f8-79a2ec438206
2013-08-09 06:28:47,671 DEBUG [storage.resource.VmwareStorageProcessor] (agentRequest-Handler-5:null)
Execution is successful.
2013-08-09 06:28:47,721 INFO  [vmware.mo.VirtualMachineMO] (agentRequest-Handler-5:null) Look
for disk device info from volume : c1457d19bf0d4c9bb9e3ef80f916ad93
2013-08-09 06:28:47,721 INFO  [vmware.mo.VirtualMachineMO] (agentRequest-Handler-5:null) Test
against disk device, controller key: 200, unit number: 1
2013-08-09 06:28:47,721 INFO  [vmware.mo.VirtualMachineMO] (agentRequest-Handler-5:null) Test
against disk backing : [openFiler] i-2-14-VM/ROOT-14-000001.vmdk
2013-08-09 06:28:47,725 INFO  [vmware.mo.VirtualMachineMO] (agentRequest-Handler-5:null) Test
against disk backing : [openFiler] i-2-14-VM/ROOT-14.vmdk
2013-08-09 06:28:47,725 INFO  [vmware.mo.VirtualMachineMO] (agentRequest-Handler-5:null) Test
against disk backing : [openFiler] 9d7d596309e634c8ab7c42aed595543f/9d7d596309e634c8ab7c42aed595543f.vmdk
2013-08-09 06:28:47,732 INFO  [vmware.mo.VirtualMachineMO] (agentRequest-Handler-5:null) Test
against disk device, controller key: 1000, unit number: 0
2013-08-09 06:28:47,732 INFO  [vmware.mo.VirtualMachineMO] (agentRequest-Handler-5:null) Test
against disk backing : [openFiler] i-2-14-VM/c1457d19bf0d4c9bb9e3ef80f916ad93-000001.vmdk
2013-08-09 06:28:47,733 INFO  [vmware.mo.VirtualMachineMO] (agentRequest-Handler-5:null) Disk
backing : [openFiler] i-2-14-VM/c1457d19bf0d4c9bb9e3ef80f916ad93-000001.vmdk matches ==>
scsi0:0
2013-08-09 06:28:47,763 INFO  [vmware.util.VmwareContext] (agentRequest-Handler-5:null) Connected,
conn: sun.net.www.protocol.https.DelegateHttpsURLConnection:https://10.147.60.13/folder/i-2-14-VM/i-2-14-VM.vmsd?dcPath=sanjeev&dsName=openFiler,
retry: 0
2013-08-09 06:28:48,835 INFO  [vmware.mo.SnapshotDescriptor] (agentRequest-Handler-5:null)
Parse snapshot file content: .encoding = "UTF-8"
2013-08-09 06:28:48,836 INFO  [vmware.mo.SnapshotDescriptor] (agentRequest-Handler-5:null)
Parse snapshot file content: snapshot.lastUID = "1"
2013-08-09 06:28:48,836 INFO  [vmware.mo.SnapshotDescriptor] (agentRequest-Handler-5:null)
Parse snapshot file content: snapshot.current = "1"
2013-08-09 06:28:48,836 INFO  [vmware.mo.SnapshotDescriptor] (agentRequest-Handler-5:null)
Parse snapshot file content: snapshot0.uid = "1"
2013-08-09 06:28:48,843 INFO  [vmware.mo.SnapshotDescriptor] (agentRequest-Handler-5:null)
Parse snapshot file content: snapshot0.filename = "i-2-14-VM-Snapshot1.vmsn"
2013-08-09 06:28:48,843 INFO  [vmware.mo.SnapshotDescriptor] (agentRequest-Handler-5:null)
Parse snapshot file content: snapshot0.displayName = "6c91e440-6407-413d-abb7-e27c94abc7b5"
2013-08-09 06:28:48,844 INFO  [vmware.mo.SnapshotDescriptor] (agentRequest-Handler-5:null)
Parse snapshot file content: snapshot0.description = "Snapshot taken for v1-s1_cent53-upload_20130809062824"
2013-08-09 06:28:48,844 INFO  [vmware.mo.SnapshotDescriptor] (agentRequest-Handler-5:null)
Parse snapshot file content: snapshot0.createTimeHigh = "320381"
2013-08-09 06:28:48,844 INFO  [vmware.mo.SnapshotDescriptor] (agentRequest-Handler-5:null)
Parse snapshot file content: snapshot0.createTimeLow = "-230977079"
2013-08-09 06:28:48,844 INFO  [vmware.mo.SnapshotDescriptor] (agentRequest-Handler-5:null)
Parse snapshot file content: snapshot0.numDisks = "2"
2013-08-09 06:28:48,844 INFO  [vmware.mo.SnapshotDescriptor] (agentRequest-Handler-5:null)
Parse snapshot file content: snapshot0.disk0.fileName = "ROOT-14.vmdk"
2013-08-09 06:28:48,844 INFO  [vmware.mo.SnapshotDescriptor] (agentRequest-Handler-5:null)
Parse snapshot file content: snapshot0.disk0.node = "ide0:1"
2013-08-09 06:28:48,845 INFO  [vmware.mo.SnapshotDescriptor] (agentRequest-Handler-5:null)
Parse snapshot file content: snapshot0.disk1.fileName = "c1457d19bf0d4c9bb9e3ef80f916ad93.vmdk"
2013-08-09 06:28:48,853 INFO  [vmware.mo.SnapshotDescriptor] (agentRequest-Handler-5:null)
Parse snapshot file content: snapshot0.disk1.node = "scsi0:0"

2013-08-09 06:28:48,853 INFO  [vmware.mo.VirtualMachineMO] (agentRequest-Handler-5:null) Convert
snapshot disk file name to datastore path. c1457d19bf0d4c9bb9e3ef80f916ad93.vmdk->[openFiler]
i-2-14-VM/c1457d19bf0d4c9bb9e3ef80f916ad93.vmdk
2013-08-09 06:28:48,890 INFO  [vmware.mo.HypervisorHostHelper] (agentRequest-Handler-5:null)
Create blank VM. cpuCount: 1, cpuSpeed(MHz): 0, mem(Mb): 4
2013-08-09 06:28:55,376 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 7-1164:
 { Cmd , MgmtId: -1, via: 7, Ver: v1, Flags: 11, [{"com.cloud.agent.api.PingStorageCommand":{"changes":{},"hostType":"Storage","hostId":7,"wait":0}}]
}
2013-08-09 06:28:55,419 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null) Received response:
Seq 7-1164:  { Ans: , MgmtId: 6615759585382, via: 7, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Storage","hostId":7,"wait":0},"result":true,"wait":0}}]
}
2013-08-09 06:28:56,496 DEBUG [vmware.mo.HostMO] (agentRequest-Handler-5:null) find VM 14559b74c77c4af2b3b67ce26581f870
on host
2013-08-09 06:28:56,496 INFO  [vmware.mo.HostMO] (agentRequest-Handler-5:null) VM 14559b74c77c4af2b3b67ce26581f870
not found in host cache
2013-08-09 06:28:56,496 DEBUG [vmware.mo.HostMO] (agentRequest-Handler-5:null) load VM cache
on host
2013-08-09 06:28:56,752 DEBUG [vmware.mo.HostMO] (agentRequest-Handler-5:null) find VM 14559b74c77c4af2b3b67ce26581f870
on host
2013-08-09 06:28:56,752 DEBUG [vmware.mo.HostMO] (agentRequest-Handler-5:null) VM 14559b74c77c4af2b3b67ce26581f870
found in host cache
2013-08-09 06:29:01,650 DEBUG [vmware.mo.HostMO] (agentRequest-Handler-5:null) find VM 14559b74c77c4af2b3b67ce26581f870
on host
2013-08-09 06:29:01,651 INFO  [vmware.mo.HostMO] (agentRequest-Handler-5:null) VM 14559b74c77c4af2b3b67ce26581f870
not found in host cache
2013-08-09 06:29:01,651 DEBUG [vmware.mo.HostMO] (agentRequest-Handler-5:null) load VM cache
on host
2013-08-09 06:29:01,998 INFO  [vmware.mo.VirtualMachineMO] (agentRequest-Handler-5:null) volss:
copy vmdk and ovf file starts 1376029741998
2013-08-09 06:29:01,999 INFO  [vmware.mo.HypervisorHostHelper] (agentRequest-Handler-5:null)
Resolving host name in url through vCenter, url: https://10.147.40.13/nfc/52f73813-e314-13af-200b-dce199ed38fc/disk-0.vmdk
2013-08-09 06:29:01,999 INFO  [vmware.mo.HypervisorHostHelper] (agentRequest-Handler-5:null)
host name in url is already in IP address, url: https://10.147.40.13/nfc/52f73813-e314-13af-200b-dce199ed38fc/disk-0.vmdk
2013-08-09 06:29:02,005 INFO  [vmware.mo.VirtualMachineMO] (agentRequest-Handler-5:null) Download
VMDK file for export. url: https://10.147.40.13/nfc/52f73813-e314-13af-200b-dce199ed38fc/disk-0.vmdk
2013-08-09 06:29:02,024 INFO  [vmware.util.VmwareContext] (agentRequest-Handler-5:null) Connected,
conn: sun.net.www.protocol.https.DelegateHttpsURLConnection:https://10.147.40.13/nfc/52f73813-e314-13af-200b-dce199ed38fc/disk-0.vmdk,
retry: 0
2013-08-09 06:30:55,948 DEBUG [vmware.manager.VmwareStorageManagerImpl] (agentRequest-Handler-5:null)
Executing: sudo sync
2013-08-09 06:30:56,377 DEBUG [vmware.manager.VmwareStorageManagerImpl] (agentRequest-Handler-5:null)
Execution is successful.
2013-08-09 06:30:56,377 INFO  [vmware.manager.VmwareStorageManagerImpl] (agentRequest-Handler-5:null)
Package OVA with commmand: tar -cf 84e927e7-ba89-4430-a8f8-79a2ec438206.ova 84e927e7-ba89-4430-a8f8-79a2ec438206.ovf
84e927e7-ba89-4430-a8f8-79a2ec438206-disk0.vmdk
2013-08-09 06:30:56,391 DEBUG [vmware.manager.VmwareStorageManagerImpl] (agentRequest-Handler-5:null)
Executing: tar -cf 84e927e7-ba89-4430-a8f8-79a2ec438206.ova 84e927e7-ba89-4430-a8f8-79a2ec438206.ovf
84e927e7-ba89-4430-a8f8-79a2ec438206-disk0.vmdk
2013-08-09 06:31:51,550 DEBUG [vmware.manager.VmwareStorageManagerImpl] (agentRequest-Handler-5:null)
Execution is successful.
2013-08-09 06:31:51,754 DEBUG [cloud.utils.S3Utils] (agentRequest-Handler-5:null) Sending
file 84e927e7-ba89-4430-a8f8-79a2ec438206.ova as S3 object snapshots/2/21/84e927e7-ba89-4430-a8f8-79a2ec438206.ova
in bucket imagestore
2013-08-09 06:31:51,754 DEBUG [cloud.utils.S3Utils] (agentRequest-Handler-5:null) Creating
S3 client with configuration: [protocol: http, connectionTimeOut: 50000, maxErrorRetry: 3,
socketTimeout: 50000]
2013-08-09 06:31:52,246 DEBUG [cloud.utils.S3Utils] (agentRequest-Handler-5:null) Setting
the end point for S3 client com.amazonaws.services.s3.AmazonS3Client@19ade0a to 10.147.29.56:8080.
2013-08-09 06:31:55,380 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 7-1167:
 { Cmd , MgmtId: -1, via: 7, Ver: v1, Flags: 11, [{"com.cloud.agent.api.PingStorageCommand":{"changes":{},"hostType":"Storage","hostId":7,"wait":0}}]
}
2013-08-09 06:31:55,428 DEBUG [cloud.agent.Agent] (Agent-Handler-3:null) Received response:
Seq 7-1167:  { Ans: , MgmtId: 6615759585382, via: 7, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Storage","hostId":7,"wait":0},"result":true,"wait":0}}]
}
2013-08-09 06:32:55,415 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 7-1168:
 { Cmd , MgmtId: -1, via: 7, Ver: v1, Flags: 11, [{"com.cloud.agent.api.PingStorageCommand":{"changes":{},"hostType":"Storage","hostId":7,"wait":0}}]
}
2013-08-09 06:32:55,495 DEBUG [cloud.agent.Agent] (Agent-Handler-4:null) Received response:
Seq 7-1168:  { Ans: , MgmtId: 6615759585382, via: 7, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Storage","hostId":7,"wait":0},"result":true,"wait":0}}]
}
2013-08-09 06:33:05,528 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Seq 7-983236628:
 { Ans: , MgmtId: 6615759585382, via: 7, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/21/84e927e7-ba89-4430-a8f8-79a2ec438206.ova","id":0}},"result":true,"wait":0}}]
}


Attaching management server log, cloud.log from SSVM and 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

Mime
View raw message