cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Justyn Shull (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (CLOUDSTACK-7775) Xen S3 backed secondary storage - local volume snapshots fail
Date Mon, 17 Nov 2014 14:31:34 GMT

    [ https://issues.apache.org/jira/browse/CLOUDSTACK-7775?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14214691#comment-14214691
] 

Justyn Shull commented on CLOUDSTACK-7775:
------------------------------------------

This is also an issue for us.   The errors/logs we get are almost the same as in this ticket,
but please let me know if there is any more information needed.  

In the meantime, I was able to workaround this error by editing /etc/xapi.d/plugins/s3xen
on the hypervisor, and adding this line to the s3 function:
{code}
filename = "%s.vhd" % filename.replace('/dev/VG_XenStorage-', '/var/run/sr-mount/').replace('VHD-',
‘')
{code}

It just changes the filename to what it would be set to if isISCSI returned false in *plugins/hypervisors/xenserver/src/com/cloud/hypervisor/xenserver/resource/XenServerStorageProcessor.java*
around line 1070.   The IsISCSI function returns true for SRType.LVM which is what I’d be
using with local storage - is that intended?

> Xen S3 backed secondary storage - local volume snapshots fail
> -------------------------------------------------------------
>
>                 Key: CLOUDSTACK-7775
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-7775
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>    Affects Versions: 4.4.0, 4.3.1
>            Reporter: CS User
>
> Xenserver, 6.01 latest hotfixes, cloudstack 4.3 and 4.4. Snapshot of volume on local
disk, to be transferred to S3. When the xenhost attemps the PUT request, the snapshot is no
longer present and so the request fails. Snapshots of volumes stored on Primary storage work
fine and are uploaded to the S3 backed secondary storage as expected. 
> Also tried upgrading the hosts to Xenserver 6.2, however it still has the same issue.
On another environment with cloudstack 4.3, with Xenserver 6.01 (no recent xen hotfixes and
no S3 backed secondary storage), local snapshots work fine. 
> We see this in the management server logs:
> (I have removed references to any hosts from the logs and amended IP's)
> {noformat}
> 2014-10-21 12:36:55,332 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-235:ctx-55338794)
Task failed! Task record:                 uuid: c520bf5a-1bc1-57ca-f9d0-960179118118
>            nameLabel: Async.host.call_plugin
>      nameDescription:
>    allowedOperations: []
>    currentOperations: {}
>              created: Tue Oct 21 12:36:56 BST 2014
>             finished: Tue Oct 21 12:36:56 BST 2014
>               status: failure
>           residentOn: com.xensource.xenapi.Host@1dd85be5
>             progress: 1.0
>                 type: <none/>
>               result:
>            errorInfo: [XENAPI_PLUGIN_FAILURE, getSnapshotSize, CommandException, 2]
>          otherConfig: {}
>            subtaskOf: com.xensource.xenapi.Task@aaf13f6f
>             subtasks: []
> 2014-10-21 12:36:55,386 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-235:ctx-55338794)
callHostPlugin failed for cmd: getSnapshotSize with args snapshotUuid: 0cef2f39-03e8-458d-bf19-7a2294c40ac7,
isISCSI: true, primaryStorageSRUuid: b1802ff2-5a63-d1e7-04de-dea7ba7eab27,  due to Task failed!
Task record:                 uuid: c520bf5a-1bc1-57ca-f9d0-960179118118
>            nameLabel: Async.host.call_plugin
>      nameDescription:
>    allowedOperations: []
>    currentOperations: {}
>              created: Tue Oct 21 12:36:56 BST 2014
>             finished: Tue Oct 21 12:36:56 BST 2014
>               status: failure
>           residentOn: com.xensource.xenapi.Host@1dd85be5
>             progress: 1.0
>                 type: <none/>
>               result:
>            errorInfo: [XENAPI_PLUGIN_FAILURE, getSnapshotSize, CommandException, 2]
>          otherConfig: {}
>            subtaskOf: com.xensource.xenapi.Task@aaf13f6f
>             subtasks: []
> Task failed! Task record:                 uuid: c520bf5a-1bc1-57ca-f9d0-960179118118
>            nameLabel: Async.host.call_plugin
>      nameDescription:
>    allowedOperations: []
>    currentOperations: {}
>              created: Tue Oct 21 12:36:56 BST 2014
>             finished: Tue Oct 21 12:36:56 BST 2014
>               status: failure
>           residentOn: com.xensource.xenapi.Host@1dd85be5
>             progress: 1.0
>                 type: <none/>
>               result:
>            errorInfo: [XENAPI_PLUGIN_FAILURE, getSnapshotSize, CommandException, 2]
>          otherConfig: {}
>            subtaskOf: com.xensource.xenapi.Task@aaf13f6f
>             subtasks: []
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3293)
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.callHostPluginAsync(CitrixResourceBase.java:3507)
>         at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.getSnapshotSize(XenServerStorageProcessor.java:1211)
>         at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.backupSnapshot(XenServerStorageProcessor.java:1401)
>         at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:94)
>         at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:52)
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:546)
>         at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:61)
>         at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:102)
>         at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
>         at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
>         at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
>         at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
>         at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
>         at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
>         at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>         at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:166)
>         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
>         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
>         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:722)
> 2014-10-21 12:36:55,391 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-235:ctx-55338794)
unable to destroy task(com.xensource.xenapi.Task@84832980) on host(45026915-2bf9-4ec1-8b57-f211194ff29b)
due to
> You gave an invalid object reference.  The object may have recently been deleted.  The
class parameter gives the type of reference given, and the handle parameter echoes the bad
value given.
>         at com.xensource.xenapi.Types.checkResponse(Types.java:693)
>         at com.xensource.xenapi.Connection.dispatch(Connection.java:350)
>         at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:456)
>         at com.xensource.xenapi.Task.destroy(Task.java:616)
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.callHostPluginAsync(CitrixResourceBase.java:3523)
>         at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.getSnapshotSize(XenServerStorageProcessor.java:1211)
>         at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.backupSnapshot(XenServerStorageProcessor.java:1401)
>         at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:94)
>         at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:52)
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:546)
>         at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:61)
>         at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:102)
>         at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
>         at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
>         at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
>         at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
>         at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
>         at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
>         at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>         at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:166)
>         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
>         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
>         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:722)
> 2014-10-21 12:36:56,777 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-12:null)
SeqA 132-143: Processing Seq 132-143:  { Cmd , MgmtId: -1, via: 132, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":64,"_loadInfo":"{\n
 \"connections\": []\n}","wait":0}}] }
> 2014-10-21 12:36:56,804 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-235:ctx-55338794)
Host 192.14.225.18 OpaqueRef:a0fd0b23-f978-5f67-b626-1eadc343a141: Removing SR
> 2014-10-21 12:36:56,808 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-12:null)
SeqA 132-143: Sending Seq 132-143:  { Ans: , MgmtId: 345052759949, via: 132, Ver: v1, Flags:
100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2014-10-21 12:36:56,818 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-235:ctx-55338794)
Host 192.14.225.18 OpaqueRef:b02a715a-229e-3758-f4e4-88a7709810b5: Unplugging pbd
> 2014-10-21 12:36:57,488 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-235:ctx-55338794)
Host 192.14.225.18 OpaqueRef:a0fd0b23-f978-5f67-b626-1eadc343a141: Forgetting
> 2014-10-21 12:36:57,504 WARN  [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-235:ctx-55338794)
BackupSnapshot Failed due to S3 upload of snapshots 0cef2f39-03e8-458d-bf19-7a2294c40ac7 failed
> com.cloud.utils.exception.CloudRuntimeException: S3 upload of snapshots 0cef2f39-03e8-458d-bf19-7a2294c40ac7
failed
>         at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.backupSnapshot(XenServerStorageProcessor.java:1421)
>         at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:94)
>         at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:52)
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:546)
>         at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:61)
>         at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:102)
>         at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
>         at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
>         at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
>         at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
>         at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
>         at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
>         at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>         at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:166)
>         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
>         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
>         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:722)
> 2014-10-21 12:36:57,885 DEBUG [c.c.a.ApiServlet] (catalina-exec-11:ctx-3e69dc37) ===START===
 192.168.20.10 -- GET  command=queryAsyncJobResult&jobId=436e0dd3-283a-471c-aba1-5ecbdd19e0e5&response=json&sessionkey=bC690U9amEIq2aZn5caH5oi0Tog%3D&_=1413891416702
> {noformat}
> On the xenserver we see the following in the /var/log/cloud/vmops.log file:
> {noformat}
> 2014-10-21 12:36:11    DEBUG [root] #### VMOPS enter  create_secondary_storage_folder
####
> 2014-10-21 12:36:11    DEBUG [root] create_secondary_storage_folder, args: {'newFolder':
'snapshots/2/257', 'remoteMountPath': 'hostname.fake.net:/CS_TEST_SEC_01'}
> 2014-10-21 12:36:11    DEBUG [root] Successfully mounted hostname.fake.net:/CS_TEST_SEC_01
to /var/run/cloud_mount/17652326-6d41-44fc-b7e5-7ea0ab7e2d4d
> 2014-10-21 12:36:11    DEBUG [root] Successfully unmounted /var/run/cloud_mount/17652326-6d41-44fc-b7e5-7ea0ab7e2d4d
> 2014-10-21 12:36:11    DEBUG [root] #### VMOPS exit  create_secondary_storage_folder
####
> 2014-10-21 12:36:31    DEBUG [root] #### VMOPS enter  get_rule_logs_for_vms ####
> 2014-10-21 12:36:31    DEBUG [root] #### VMOPS enter  network_rules_for_rebooted_vm ####
> 2014-10-21 12:36:31    DEBUG [root] #### VMOPS enter  check_domid_changed ####
> 2014-10-21 12:36:31    DEBUG [root] #### VMOPS exit  check_domid_changed ####
> 2014-10-21 12:36:31    DEBUG [root] #### VMOPS exit  network_rules_for_rebooted_vm ####
> 2014-10-21 12:36:31    DEBUG [root] #### VMOPS enter  network_rules_for_rebooted_vm ####
> 2014-10-21 12:36:31    DEBUG [root] #### VMOPS enter  check_domid_changed ####
> 2014-10-21 12:36:31    DEBUG [root] #### VMOPS exit  check_domid_changed ####
> 2014-10-21 12:36:31    DEBUG [root] #### VMOPS exit  network_rules_for_rebooted_vm ####
> 2014-10-21 12:36:31    DEBUG [root] #### VMOPS exit  get_rule_logs_for_vms ####
> 2014-10-21 12:36:56    DEBUG [root] primarySRPath: /dev/VG_XenStorage-b1802ff2-5a63-d1e7-04de-dea7ba7eab27
> 2014-10-21 12:36:58    DEBUG [root] #### VMOPS enter  deleteSnapshotBackup ####
> 2014-10-21 12:36:58    DEBUG [root] Calling deleteSnapshotBackup with {'localMountPoint':
'/var/run/cloud_mount/ccd200be-0636-32f6-ad98-fb8e2fa8c70c', 'backupUUID': '0cef2f39-03e8-458d-bf19-7a2294c40ac7',
'secondaryStora
> geMountPath': 'hostname.fake.net:/CS_TEST_SEC_01', 'path': 'snapshots/2/257'}
> 2014-10-21 12:36:58    DEBUG [root] Successfully mounted hostname.fake.net:/CS_TEST_SEC_01/snapshots
to /var/run/cloud_mount/ccd200be-0636-32f6-ad98-fb8e2fa8c70c
> 2014-10-21 12:36:58    DEBUG [root] Chdired to /var/run/cloud_mount/ccd200be-0636-32f6-ad98-fb8e2fa8c70c/2/257
> 2014-10-21 12:36:58    DEBUG [root] checking existence of 0cef2f39-03e8-458d-bf19-7a2294c40ac7.vhd
> 2014-10-21 12:36:58    DEBUG [root] backupVHD 0cef2f39-03e8-458d-bf19-7a2294c40ac7.vhd
exists.
> 2014-10-21 12:36:58    DEBUG [root] #### VMOPS exit  deleteSnapshotBackup ####
> {noformat}
> On the xenserver we see the following in the /var/log/cloud/s3xen.log file:
> {noformat}
> 2014-10-21 12:36:57    DEBUG [root] #### VMOPS enter s3 #### ####
> 2014-10-21 12:36:57    DEBUG [root] #### VMOPS Operation put on file /dev/VG_XenStorage-b1802ff2-5a63-d1e7-04de-dea7ba7eab27/VHD-0cef2f39-03e8-458d-bf19-7a2294c40ac7
from/in bucket CS_TEST_SEC_01 key snapshots/2/257/VHD-0cef2f39-03e8-458d-bf19-7a2294c40ac7
####
> 2014-10-21 12:36:57    DEBUG [root] #### VMOPS Traceback (most recent call last):
>   File "/etc/xapi.d/plugins/s3xen", line 414, in s3
>     client.put(bucket, key, filename, maxSingleUploadBytes)
>   File "/etc/xapi.d/plugins/s3xen", line 325, in put
>     raise Exception(
> Exception: Attempt to put /dev/VG_XenStorage-b1802ff2-5a63-d1e7-04de-dea7ba7eab27/VHD-0cef2f39-03e8-458d-bf19-7a2294c40ac7
that does not exist.
>  ####
> 2014-10-21 12:36:57    DEBUG [root] #### VMOPS exit s3 with result false ####
> {noformat}
> It appears that Xen is deleting the file on the local filesystem before the S3 script
has a chance to upload it, however the snapshot does appear to have been successfully transferred
to the secondary storage staging area, after which the S3 transfer is attempted from the local
lvm volume. When this fails the snapshot is deleted, as you can see from the above logs. 
> It appears that either the issue with Xen deleting the snapshot needs to be resolved
(has this behavior changed recently?) or the PUT request to S3 needs to send the file which
is located in the staging area, rather than the file on local disk, as happens with the primary
storage volume snapshots. 



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message