[
https://issues.apache.org/jira/browse/CLOUDSTACK-9059?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Remi Bergsma updated CLOUDSTACK-9059:
-------------------------------------
Description:
- Create a vm
- make snapshot
Verify it works and makes it to S3. This should work.
- make another snapshot
It fails: Failed to create snapshot due to an internal error creating snapshot
for volume 220
Logs from management:
2015-11-12 16:26:15,103 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Add job-1669 into job monitoring
2015-11-12 16:26:15,107 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Executing AsyncJobVO {id:1669,
userId: 4, accountId: 2, instanceType: Snapshot, instanceId: 12, cmd: org.apa
che.cloudstack.api.command.user.snapshot.CreateSnapshotCmd, cmdInfo:
{"quiescevm":"false","httpmethod":"GET","ctxAccountId":"2","uuid":"2a2b67ce-e6a5-4dd3-85f5-823f14d9fbbe","cmdEventType":"SNAPSHOT.CREATE","respons
e":"json","ctxUserId":"4","volumeId":"0137c81d-aedb-469a-bcbb-cf7df2985c82","name":"nog
een","ctxStartEventId":"2906","id":"12","ctxDetails":"{\"interface
com.cloud.storage.Snapshot\":\"2a2b67ce-e6a5-4dd3-85f5-823f1
4d9fbbe\",\"interface
com.cloud.storage.Volume\":\"0137c81d-aedb-469a-bcbb-cf7df2985c82\"}","_":"1447341974884"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 28867301
26, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2015-11-12 16:26:15,109 DEBUG [c.c.a.ApiServlet]
(http-bio-8080-exec-26:ctx-f0fd7270 ctx-2f203261) ===END=== 10.200.22.3 -- GET
command=createSnapshot&response=json&volumeId=0137c81d-aedb-469a-bcbb-cf7df2985c82&qu
iescevm=false&name=nog+een&_=1447341974884
2015-11-12 16:26:15,181 INFO [o.a.c.a.c.u.s.CreateSnapshotCmd]
(API-Job-Executor-3:ctx-a1e712e2 job-1669 ctx-2f94ce7b) VOLSS:
createSnapshotCmd starts:1447341975181
2015-11-12 16:26:15,231 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-3:ctx-a1e712e2 job-1669 ctx-2f94ce7b) Sync job-1670 execution
on object VmWorkJobQueue.220
2015-11-12 16:26:18,143 DEBUG [c.c.a.ApiServlet]
(http-bio-8080-exec-17:ctx-0304676c) ===START=== 10.200.22.3 -- GET
command=queryAsyncJobResult&jobId=5a6748af-cb5f-41b6-82c6-a17971c63d09&response=json&_=144734197
8124
2015-11-12 16:26:18,178 DEBUG [c.c.a.ApiServlet]
(http-bio-8080-exec-17:ctx-0304676c ctx-321af332) ===END=== 10.200.22.3 -- GET
command=queryAsyncJobResult&jobId=5a6748af-cb5f-41b6-82c6-a17971c63d09&response=json&
_=1447341978124
2015-11-12 16:26:19,497 DEBUG [c.c.s.StatsCollector]
(StatsCollector-4:ctx-4fd0fb68) AutoScaling Monitor is running...
2015-11-12 16:26:21,180 DEBUG [c.c.a.ApiServlet]
(http-bio-8080-exec-14:ctx-7690a426) ===START=== 10.200.22.3 -- GET
command=queryAsyncJobResult&jobId=5a6748af-cb5f-41b6-82c6-a17971c63d09&response=json&_=144734198
1124
2015-11-12 16:26:21,216 DEBUG [c.c.a.ApiServlet]
(http-bio-8080-exec-14:ctx-7690a426 ctx-61c72bab) ===END=== 10.200.22.3 -- GET
command=queryAsyncJobResult&jobId=5a6748af-cb5f-41b6-82c6-a17971c63d09&response=json&
_=1447341981124
2015-11-12 16:26:21,316 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Complete async job-1669, jobStatus:
FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.Exce
ptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed to create
snapshot due to an internal error creating snapshot for volume 220"}
2015-11-12 16:26:21,318 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Publish async job-1669 complete on
message bus
2015-11-12 16:26:21,318 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Wake up jobs related to job-1669
2015-11-12 16:26:21,318 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Update db status for job-1669
2015-11-12 16:26:21,321 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Wake up jobs joined with job-1669
and disjoin all subjobs created from job- 1669
2015-11-12 16:26:21,326 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Done executing
org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd for job-1669
2015-11-12 16:26:21,326 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Remove job-1669 from job monitoring
2015-11-12 16:26:18,280 ERROR [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-3:ctx-fbda09ad job-1669/job-1670) Unable to complete
AsyncJobVO {id:1670, userId: 4, accountId: 2, instanceType: null, instanceId:
null, c
md: com.cloud.vm.VmWorkTakeVolumeSnapshot, cmdInfo:
rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrVGFrZVZvbHVtZVNuYXBzaG90BL5gG4Li1c8CAARaAAlxdWllc2NlVm1MAAhwb2xpY3lJZHQAEExqYXZhL2xhbmcvTG9uZztMAApzbmFwc2hvdElkcQB-AAFMAAh2b2x
1bWVJZHEAfgABeHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAUAAAAAAAAABAAAAAAAAADcdAAUVm9sdW1lQXBpU2VydmljZUltcGwAc3IADm
phdmEubGFuZy5Mb25nO4vkkMyPI98CAAFKAAV2YWx1ZXhyABBqYXZhLmxhbmcuTnVtYmVyhqyVHQuU4IsCAAB4cAAAAAAAAAAAc3EAfgAGAAAAAAAAAAxzcQB-AAYAAAAAAAAA3A,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 2886730126, completeMsid: null, lastUpdated: null, lastPolled:
null, created: Thu Nov 12 16:26:15 CET 2015}, job origin:1669
com.cloud.utils.exception.CloudRuntimeException: Failed to take snapshot
at
org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1594)
at
com.cloud.storage.VolumeApiServiceImpl.orchestrateTakeVolumeSnapshot(VolumeApiServiceImpl.java:2078)
at
com.cloud.storage.VolumeApiServiceImpl.orchestrateTakeVolumeSnapshot(VolumeApiServiceImpl.java:2865)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.storage.VolumeApiServiceImpl.handleVmWorkJob(VolumeApiServiceImpl.java:2873)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy197.handleVmWorkJob(Unknown Source)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:537)
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
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:494)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: com.cloud.utils.exception.CloudRuntimeException: Failed to create
snapshot
at
com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1025)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
... 42 more
Caused by: com.cloud.utils.exception.CloudRuntimeException: BackupSnapshot
Failed due to S3 upload of snapshots null failed
at
org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:285)
at
org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:155)
at
org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:322)
... 45 more
2015-11-12 16:26:18,155 WARN [c.c.h.x.r.XenServerStorageProcessor]
(DirectAgent-109:ctx-23c1fe16) BackupSnapshot Failed due to S3 upload of
snapshots null failed
com.cloud.utils.exception.CloudRuntimeException: S3 upload of snapshots null
failed
at
com.cloud.hypervisor.xenserver.resource.Xenserver625StorageProcessor.backupSnapshot(Xenserver625StorageProcessor.java:525)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:99)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:54)
at
com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixStorageSubSystemCommandWrapper.execute(CitrixStorageSubSystemCommandWrapper.java:36)
at
com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixStorageSubSystemCommandWrapper.execute(CitrixStorageSubSystemCommandWrapper.java:30)
at
com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(CitrixRequestWrapper.java:122)
at
com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:1676)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:302)
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:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2015-11-12 16:26:18,156 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-109:ctx-23c1fe16) Seq 8-8143352551215989060: Response Received:
2015-11-12 16:26:18,156 DEBUG [c.c.a.t.Request] (DirectAgent-109:ctx-23c1fe16)
Seq 8-8143352551215989060: Processing: { Ans: , MgmtId: 90520741485751, via:
8(mccxpod01-hv07), Ver: v1, Flags: 110, [{"org.apache.clou
dstack.storage.command.CopyCmdAnswer":{"result":false,"details":"BackupSnapshot
Failed due to S3 upload of snapshots null failed","wait":0}}] }
2015-11-12 16:26:18,156 DEBUG [c.c.a.m.AgentAttache]
(DirectAgent-109:ctx-23c1fe16) Seq 8-8143352551215989060: No more commands found
2015-11-12 16:26:18,156 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-3:ctx-fbda09ad job-1669/job-1670 ctx-d2d8b8ab) Seq
8-8143352551215989060: Received: { Ans: , MgmtId: 90520741485751, via:
8(mccxpod01-hv07), Ver: v
1, Flags: 110, { CopyCmdAnswer } }
2015-11-12 16:26:18,177 ERROR [o.a.c.s.i.BaseImageStoreDriverImpl]
(Work-Job-Executor-3:ctx-fbda09ad job-1669/job-1670 ctx-d2d8b8ab) No remote
endpoint to send command, check if host or ssvm is down?
Logs from XenServer /var/log/cloud/s3xen.log:
2015-11-12 16:26:17 DEBUG [root] #### VMOPS enter s3 #### ####
2015-11-12 16:26:17 DEBUG [root] #### VMOPS Operation put on file
/var/run/sr-mount/2dcb90fe-1068-2e9f-6963-7de833f109f0/null.vhd from/in bucket
mccx-nl2 key snapshots/5/220/null.vhd ####
2015-11-12 16:26:17 DEBUG [root] #### VMOPS Traceback (most recent call
last):
File "/etc/xapi.d/plugins/s3xenserver", line 414, in s3
client.put(bucket, key, filename, maxSingleUploadBytes)
File "/etc/xapi.d/plugins/s3xenserver", line 325, in put
raise Exception(
Exception: Attempt to put
/var/run/sr-mount/2dcb90fe-1068-2e9f-6963-7de833f109f0/null.vhd that does not
exist.
####
2015-11-12 16:26:17 DEBUG [root] #### VMOPS exit s3 with result false ####
In xensource.log you see it call the s3xenserver plugin:
Nov 12 19:22:16 mccxpod01-hv08 xapi:
[debug|mccxpod01-hv08|2166532|Async.host.call_plugin R:36173a97bfdc|audit]
Host.call_plugin host = '5d4cc523-ced7-4324-9dfb-fb81cb225899
(mccxpod01-hv07)'; plugin = 's3xenserver'; fn = 's3'; args = [ maxErrorRetry:
10; secretKey: x; connectionTtl: null; iSCSIFlag: false;
maxSingleUploadSizeInBytes: 5368709120; bucket: mccx-nl2; endPoint:
s3.x.schubergphilis.com; filename:
/var/run/sr-mount/e914d2c5-f74f-4818-9dc5-c2f2f6f909f1/4b9295bd-779c-4212-84b7-9b79520cf42e.vhd;
accessKey: x; socketTimeout: null; https: false; connectionTimeout: 300000;
operation: put; key: snapshots/5/215/4b9295bd-779c-4212-84b7-9b79520cf42e.vhd;
useTCPKeepAlive: null ]
Nov 12 19:29:29 mccxpod01-hv08 xapi:
[debug|mccxpod01-hv08|2168571|Async.host.call_plugin R:988800b3c267|audit]
Host.call_plugin host = '552570ac-1a04-4576-8615-2af7767803b6
(mccxpod01-hv08)'; plugin = 's3xenserver'; fn = 's3'; args = [ maxErrorRetry:
10; secretKey: +x; connectionTtl: null; iSCSIFlag: false;
maxSingleUploadSizeInBytes: 5368709120; bucket: mccx-nl2; endPoint:
This one doesn't work because it doesn't exist:
s3.x.schubergphilis.com; filename:
/var/run/sr-mount/2dcb90fe-1068-2e9f-6963-7de833f109f0/null.vhd; accessKey: x;
socketTimeout: null; https: false; connectionTimeout: 300000; operation: put;
key: snapshots/5/215/null.vhd; useTCPKeepAlive: null ]
was:
- Create a vm
- make snapshot
Verify it works and makes it to S3. This should work.
- make another snapshot
It fails: Failed to create snapshot due to an internal error creating snapshot
for volume 220
Logs from management:
2015-11-12 16:26:15,103 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Add job-1669 into job monitoring
2015-11-12 16:26:15,107 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Executing AsyncJobVO {id:1669,
userId: 4, accountId: 2, instanceType: Snapshot, instanceId: 12, cmd: org.apa
che.cloudstack.api.command.user.snapshot.CreateSnapshotCmd, cmdInfo:
{"quiescevm":"false","httpmethod":"GET","ctxAccountId":"2","uuid":"2a2b67ce-e6a5-4dd3-85f5-823f14d9fbbe","cmdEventType":"SNAPSHOT.CREATE","respons
e":"json","ctxUserId":"4","volumeId":"0137c81d-aedb-469a-bcbb-cf7df2985c82","name":"nog
een","ctxStartEventId":"2906","id":"12","ctxDetails":"{\"interface
com.cloud.storage.Snapshot\":\"2a2b67ce-e6a5-4dd3-85f5-823f1
4d9fbbe\",\"interface
com.cloud.storage.Volume\":\"0137c81d-aedb-469a-bcbb-cf7df2985c82\"}","_":"1447341974884"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 28867301
26, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2015-11-12 16:26:15,109 DEBUG [c.c.a.ApiServlet]
(http-bio-8080-exec-26:ctx-f0fd7270 ctx-2f203261) ===END=== 10.200.22.3 -- GET
command=createSnapshot&response=json&volumeId=0137c81d-aedb-469a-bcbb-cf7df2985c82&qu
iescevm=false&name=nog+een&_=1447341974884
2015-11-12 16:26:15,181 INFO [o.a.c.a.c.u.s.CreateSnapshotCmd]
(API-Job-Executor-3:ctx-a1e712e2 job-1669 ctx-2f94ce7b) VOLSS:
createSnapshotCmd starts:1447341975181
2015-11-12 16:26:15,231 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-3:ctx-a1e712e2 job-1669 ctx-2f94ce7b) Sync job-1670 execution
on object VmWorkJobQueue.220
2015-11-12 16:26:18,143 DEBUG [c.c.a.ApiServlet]
(http-bio-8080-exec-17:ctx-0304676c) ===START=== 10.200.22.3 -- GET
command=queryAsyncJobResult&jobId=5a6748af-cb5f-41b6-82c6-a17971c63d09&response=json&_=144734197
8124
2015-11-12 16:26:18,178 DEBUG [c.c.a.ApiServlet]
(http-bio-8080-exec-17:ctx-0304676c ctx-321af332) ===END=== 10.200.22.3 -- GET
command=queryAsyncJobResult&jobId=5a6748af-cb5f-41b6-82c6-a17971c63d09&response=json&
_=1447341978124
2015-11-12 16:26:19,497 DEBUG [c.c.s.StatsCollector]
(StatsCollector-4:ctx-4fd0fb68) AutoScaling Monitor is running...
2015-11-12 16:26:21,180 DEBUG [c.c.a.ApiServlet]
(http-bio-8080-exec-14:ctx-7690a426) ===START=== 10.200.22.3 -- GET
command=queryAsyncJobResult&jobId=5a6748af-cb5f-41b6-82c6-a17971c63d09&response=json&_=144734198
1124
2015-11-12 16:26:21,216 DEBUG [c.c.a.ApiServlet]
(http-bio-8080-exec-14:ctx-7690a426 ctx-61c72bab) ===END=== 10.200.22.3 -- GET
command=queryAsyncJobResult&jobId=5a6748af-cb5f-41b6-82c6-a17971c63d09&response=json&
_=1447341981124
2015-11-12 16:26:21,316 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Complete async job-1669, jobStatus:
FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.Exce
ptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed to create
snapshot due to an internal error creating snapshot for volume 220"}
2015-11-12 16:26:21,318 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Publish async job-1669 complete on
message bus
2015-11-12 16:26:21,318 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Wake up jobs related to job-1669
2015-11-12 16:26:21,318 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Update db status for job-1669
2015-11-12 16:26:21,321 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Wake up jobs joined with job-1669
and disjoin all subjobs created from job- 1669
2015-11-12 16:26:21,326 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Done executing
org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd for job-1669
2015-11-12 16:26:21,326 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-3:ctx-a1e712e2 job-1669) Remove job-1669 from job monitoring
2015-11-12 16:26:18,280 ERROR [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-3:ctx-fbda09ad job-1669/job-1670) Unable to complete
AsyncJobVO {id:1670, userId: 4, accountId: 2, instanceType: null, instanceId:
null, c
md: com.cloud.vm.VmWorkTakeVolumeSnapshot, cmdInfo:
rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrVGFrZVZvbHVtZVNuYXBzaG90BL5gG4Li1c8CAARaAAlxdWllc2NlVm1MAAhwb2xpY3lJZHQAEExqYXZhL2xhbmcvTG9uZztMAApzbmFwc2hvdElkcQB-AAFMAAh2b2x
1bWVJZHEAfgABeHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAUAAAAAAAAABAAAAAAAAADcdAAUVm9sdW1lQXBpU2VydmljZUltcGwAc3IADm
phdmEubGFuZy5Mb25nO4vkkMyPI98CAAFKAAV2YWx1ZXhyABBqYXZhLmxhbmcuTnVtYmVyhqyVHQuU4IsCAAB4cAAAAAAAAAAAc3EAfgAGAAAAAAAAAAxzcQB-AAYAAAAAAAAA3A,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 2886730126, completeMsid: null, lastUpdated: null, lastPolled:
null, created: Thu Nov 12 16:26:15 CET 2015}, job origin:1669
com.cloud.utils.exception.CloudRuntimeException: Failed to take snapshot
at
org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1594)
at
com.cloud.storage.VolumeApiServiceImpl.orchestrateTakeVolumeSnapshot(VolumeApiServiceImpl.java:2078)
at
com.cloud.storage.VolumeApiServiceImpl.orchestrateTakeVolumeSnapshot(VolumeApiServiceImpl.java:2865)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.storage.VolumeApiServiceImpl.handleVmWorkJob(VolumeApiServiceImpl.java:2873)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy197.handleVmWorkJob(Unknown Source)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:537)
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
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:494)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: com.cloud.utils.exception.CloudRuntimeException: Failed to create
snapshot
at
com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1025)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
... 42 more
Caused by: com.cloud.utils.exception.CloudRuntimeException: BackupSnapshot
Failed due to S3 upload of snapshots null failed
at
org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:285)
at
org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:155)
at
org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:322)
... 45 more
2015-11-12 16:26:18,155 WARN [c.c.h.x.r.XenServerStorageProcessor]
(DirectAgent-109:ctx-23c1fe16) BackupSnapshot Failed due to S3 upload of
snapshots null failed
com.cloud.utils.exception.CloudRuntimeException: S3 upload of snapshots null
failed
at
com.cloud.hypervisor.xenserver.resource.Xenserver625StorageProcessor.backupSnapshot(Xenserver625StorageProcessor.java:525)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:99)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:54)
at
com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixStorageSubSystemCommandWrapper.execute(CitrixStorageSubSystemCommandWrapper.java:36)
at
com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixStorageSubSystemCommandWrapper.execute(CitrixStorageSubSystemCommandWrapper.java:30)
at
com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(CitrixRequestWrapper.java:122)
at
com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:1676)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:302)
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:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2015-11-12 16:26:18,156 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-109:ctx-23c1fe16) Seq 8-8143352551215989060: Response Received:
2015-11-12 16:26:18,156 DEBUG [c.c.a.t.Request] (DirectAgent-109:ctx-23c1fe16)
Seq 8-8143352551215989060: Processing: { Ans: , MgmtId: 90520741485751, via:
8(mccxpod01-hv07), Ver: v1, Flags: 110, [{"org.apache.clou
dstack.storage.command.CopyCmdAnswer":{"result":false,"details":"BackupSnapshot
Failed due to S3 upload of snapshots null failed","wait":0}}] }
2015-11-12 16:26:18,156 DEBUG [c.c.a.m.AgentAttache]
(DirectAgent-109:ctx-23c1fe16) Seq 8-8143352551215989060: No more commands found
2015-11-12 16:26:18,156 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-3:ctx-fbda09ad job-1669/job-1670 ctx-d2d8b8ab) Seq
8-8143352551215989060: Received: { Ans: , MgmtId: 90520741485751, via:
8(mccxpod01-hv07), Ver: v
1, Flags: 110, { CopyCmdAnswer } }
2015-11-12 16:26:18,177 ERROR [o.a.c.s.i.BaseImageStoreDriverImpl]
(Work-Job-Executor-3:ctx-fbda09ad job-1669/job-1670 ctx-d2d8b8ab) No remote
endpoint to send command, check if host or ssvm is down?
Logs from XenServer /var/log/cloud/s3xen.log:
2015-11-12 16:26:17 DEBUG [root] #### VMOPS enter s3 #### ####
2015-11-12 16:26:17 DEBUG [root] #### VMOPS Operation put on file
/var/run/sr-mount/2dcb90fe-1068-2e9f-6963-7de833f109f0/null.vhd from/in bucket
mccx-nl2 key snapshots/5/220/null.vhd ####
2015-11-12 16:26:17 DEBUG [root] #### VMOPS Traceback (most recent call
last):
File "/etc/xapi.d/plugins/s3xenserver", line 414, in s3
client.put(bucket, key, filename, maxSingleUploadBytes)
File "/etc/xapi.d/plugins/s3xenserver", line 325, in put
raise Exception(
Exception: Attempt to put
/var/run/sr-mount/2dcb90fe-1068-2e9f-6963-7de833f109f0/null.vhd that does not
exist.
####
2015-11-12 16:26:17 DEBUG [root] #### VMOPS exit s3 with result false ####
> Snapshot on S3 fails when delta is zero
> ---------------------------------------
>
> Key: CLOUDSTACK-9059
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-9059
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: Snapshot
> Affects Versions: 4.6.0
> Environment: XenServer and S3
> Reporter: Remi Bergsma
> Priority: Critical
>
> - Create a vm
> - make snapshot
> Verify it works and makes it to S3. This should work.
> - make another snapshot
> It fails: Failed to create snapshot due to an internal error creating
> snapshot for volume 220
> Logs from management:
> 2015-11-12 16:26:15,103 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (API-Job-Executor-3:ctx-a1e712e2 job-1669) Add job-1669 into job monitoring
> 2015-11-12 16:26:15,107 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-3:ctx-a1e712e2 job-1669) Executing AsyncJobVO {id:1669,
> userId: 4, accountId: 2, instanceType: Snapshot, instanceId: 12, cmd: org.apa
> che.cloudstack.api.command.user.snapshot.CreateSnapshotCmd, cmdInfo:
> {"quiescevm":"false","httpmethod":"GET","ctxAccountId":"2","uuid":"2a2b67ce-e6a5-4dd3-85f5-823f14d9fbbe","cmdEventType":"SNAPSHOT.CREATE","respons
> e":"json","ctxUserId":"4","volumeId":"0137c81d-aedb-469a-bcbb-cf7df2985c82","name":"nog
> een","ctxStartEventId":"2906","id":"12","ctxDetails":"{\"interface
> com.cloud.storage.Snapshot\":\"2a2b67ce-e6a5-4dd3-85f5-823f1
> 4d9fbbe\",\"interface
> com.cloud.storage.Volume\":\"0137c81d-aedb-469a-bcbb-cf7df2985c82\"}","_":"1447341974884"},
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
> null, initMsid: 28867301
> 26, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2015-11-12 16:26:15,109 DEBUG [c.c.a.ApiServlet]
> (http-bio-8080-exec-26:ctx-f0fd7270 ctx-2f203261) ===END=== 10.200.22.3 --
> GET
> command=createSnapshot&response=json&volumeId=0137c81d-aedb-469a-bcbb-cf7df2985c82&qu
> iescevm=false&name=nog+een&_=1447341974884
> 2015-11-12 16:26:15,181 INFO [o.a.c.a.c.u.s.CreateSnapshotCmd]
> (API-Job-Executor-3:ctx-a1e712e2 job-1669 ctx-2f94ce7b) VOLSS:
> createSnapshotCmd starts:1447341975181
> 2015-11-12 16:26:15,231 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-3:ctx-a1e712e2 job-1669 ctx-2f94ce7b) Sync job-1670
> execution on object VmWorkJobQueue.220
> 2015-11-12 16:26:18,143 DEBUG [c.c.a.ApiServlet]
> (http-bio-8080-exec-17:ctx-0304676c) ===START=== 10.200.22.3 -- GET
> command=queryAsyncJobResult&jobId=5a6748af-cb5f-41b6-82c6-a17971c63d09&response=json&_=144734197
> 8124
> 2015-11-12 16:26:18,178 DEBUG [c.c.a.ApiServlet]
> (http-bio-8080-exec-17:ctx-0304676c ctx-321af332) ===END=== 10.200.22.3 --
> GET
> command=queryAsyncJobResult&jobId=5a6748af-cb5f-41b6-82c6-a17971c63d09&response=json&
> _=1447341978124
> 2015-11-12 16:26:19,497 DEBUG [c.c.s.StatsCollector]
> (StatsCollector-4:ctx-4fd0fb68) AutoScaling Monitor is running...
> 2015-11-12 16:26:21,180 DEBUG [c.c.a.ApiServlet]
> (http-bio-8080-exec-14:ctx-7690a426) ===START=== 10.200.22.3 -- GET
> command=queryAsyncJobResult&jobId=5a6748af-cb5f-41b6-82c6-a17971c63d09&response=json&_=144734198
> 1124
> 2015-11-12 16:26:21,216 DEBUG [c.c.a.ApiServlet]
> (http-bio-8080-exec-14:ctx-7690a426 ctx-61c72bab) ===END=== 10.200.22.3 --
> GET
> command=queryAsyncJobResult&jobId=5a6748af-cb5f-41b6-82c6-a17971c63d09&response=json&
> _=1447341981124
> 2015-11-12 16:26:21,316 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-3:ctx-a1e712e2 job-1669) Complete async job-1669,
> jobStatus: FAILED, resultCode: 530, result:
> org.apache.cloudstack.api.response.Exce
> ptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed to
> create snapshot due to an internal error creating snapshot for volume 220"}
> 2015-11-12 16:26:21,318 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-3:ctx-a1e712e2 job-1669) Publish async job-1669 complete on
> message bus
> 2015-11-12 16:26:21,318 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-3:ctx-a1e712e2 job-1669) Wake up jobs related to job-1669
> 2015-11-12 16:26:21,318 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-3:ctx-a1e712e2 job-1669) Update db status for job-1669
> 2015-11-12 16:26:21,321 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-3:ctx-a1e712e2 job-1669) Wake up jobs joined with job-1669
> and disjoin all subjobs created from job- 1669
> 2015-11-12 16:26:21,326 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-3:ctx-a1e712e2 job-1669) Done executing
> org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd for job-1669
> 2015-11-12 16:26:21,326 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (API-Job-Executor-3:ctx-a1e712e2 job-1669) Remove job-1669 from job monitoring
> 2015-11-12 16:26:18,280 ERROR [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-3:ctx-fbda09ad job-1669/job-1670) Unable to complete
> AsyncJobVO {id:1670, userId: 4, accountId: 2, instanceType: null, instanceId:
> null, c
> md: com.cloud.vm.VmWorkTakeVolumeSnapshot, cmdInfo:
> rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrVGFrZVZvbHVtZVNuYXBzaG90BL5gG4Li1c8CAARaAAlxdWllc2NlVm1MAAhwb2xpY3lJZHQAEExqYXZhL2xhbmcvTG9uZztMAApzbmFwc2hvdElkcQB-AAFMAAh2b2x
> 1bWVJZHEAfgABeHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAUAAAAAAAAABAAAAAAAAADcdAAUVm9sdW1lQXBpU2VydmljZUltcGwAc3IADm
> phdmEubGFuZy5Mb25nO4vkkMyPI98CAAFKAAV2YWx1ZXhyABBqYXZhLmxhbmcuTnVtYmVyhqyVHQuU4IsCAAB4cAAAAAAAAAAAc3EAfgAGAAAAAAAAAAxzcQB-AAYAAAAAAAAA3A,
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
> null, initMsid: 2886730126, completeMsid: null, lastUpdated: null,
> lastPolled: null, created: Thu Nov 12 16:26:15 CET 2015}, job origin:1669
> com.cloud.utils.exception.CloudRuntimeException: Failed to take snapshot
> at
> org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1594)
> at
> com.cloud.storage.VolumeApiServiceImpl.orchestrateTakeVolumeSnapshot(VolumeApiServiceImpl.java:2078)
> at
> com.cloud.storage.VolumeApiServiceImpl.orchestrateTakeVolumeSnapshot(VolumeApiServiceImpl.java:2865)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at
> com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
> at
> com.cloud.storage.VolumeApiServiceImpl.handleVmWorkJob(VolumeApiServiceImpl.java:2873)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at
> org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
> at
> org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
> at
> org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
> at com.sun.proxy.$Proxy197.handleVmWorkJob(Unknown Source)
> at
> com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
> at
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:537)
> 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
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:494)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: com.cloud.utils.exception.CloudRuntimeException: Failed to create
> snapshot
> at
> com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1025)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> ... 42 more
> Caused by: com.cloud.utils.exception.CloudRuntimeException: BackupSnapshot
> Failed due to S3 upload of snapshots null failed
> at
> org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:285)
> at
> org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:155)
> at
> org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:322)
> ... 45 more
> 2015-11-12 16:26:18,155 WARN [c.c.h.x.r.XenServerStorageProcessor]
> (DirectAgent-109:ctx-23c1fe16) BackupSnapshot Failed due to S3 upload of
> snapshots null failed
> com.cloud.utils.exception.CloudRuntimeException: S3 upload of snapshots null
> failed
> at
> com.cloud.hypervisor.xenserver.resource.Xenserver625StorageProcessor.backupSnapshot(Xenserver625StorageProcessor.java:525)
> at
> com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:99)
> at
> com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:54)
> at
> com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixStorageSubSystemCommandWrapper.execute(CitrixStorageSubSystemCommandWrapper.java:36)
> at
> com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixStorageSubSystemCommandWrapper.execute(CitrixStorageSubSystemCommandWrapper.java:30)
> at
> com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(CitrixRequestWrapper.java:122)
> at
> com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:1676)
> at
> com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:302)
> 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:511)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> 2015-11-12 16:26:18,156 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-109:ctx-23c1fe16) Seq 8-8143352551215989060: Response Received:
> 2015-11-12 16:26:18,156 DEBUG [c.c.a.t.Request]
> (DirectAgent-109:ctx-23c1fe16) Seq 8-8143352551215989060: Processing: { Ans:
> , MgmtId: 90520741485751, via: 8(mccxpod01-hv07), Ver: v1, Flags: 110,
> [{"org.apache.clou
> dstack.storage.command.CopyCmdAnswer":{"result":false,"details":"BackupSnapshot
> Failed due to S3 upload of snapshots null failed","wait":0}}] }
> 2015-11-12 16:26:18,156 DEBUG [c.c.a.m.AgentAttache]
> (DirectAgent-109:ctx-23c1fe16) Seq 8-8143352551215989060: No more commands
> found
> 2015-11-12 16:26:18,156 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-3:ctx-fbda09ad job-1669/job-1670 ctx-d2d8b8ab) Seq
> 8-8143352551215989060: Received: { Ans: , MgmtId: 90520741485751, via:
> 8(mccxpod01-hv07), Ver: v
> 1, Flags: 110, { CopyCmdAnswer } }
> 2015-11-12 16:26:18,177 ERROR [o.a.c.s.i.BaseImageStoreDriverImpl]
> (Work-Job-Executor-3:ctx-fbda09ad job-1669/job-1670 ctx-d2d8b8ab) No remote
> endpoint to send command, check if host or ssvm is down?
> Logs from XenServer /var/log/cloud/s3xen.log:
> 2015-11-12 16:26:17 DEBUG [root] #### VMOPS enter s3 #### ####
> 2015-11-12 16:26:17 DEBUG [root] #### VMOPS Operation put on file
> /var/run/sr-mount/2dcb90fe-1068-2e9f-6963-7de833f109f0/null.vhd from/in
> bucket mccx-nl2 key snapshots/5/220/null.vhd ####
> 2015-11-12 16:26:17 DEBUG [root] #### VMOPS Traceback (most recent call
> last):
> File "/etc/xapi.d/plugins/s3xenserver", line 414, in s3
> client.put(bucket, key, filename, maxSingleUploadBytes)
> File "/etc/xapi.d/plugins/s3xenserver", line 325, in put
> raise Exception(
> Exception: Attempt to put
> /var/run/sr-mount/2dcb90fe-1068-2e9f-6963-7de833f109f0/null.vhd that does not
> exist.
> ####
> 2015-11-12 16:26:17 DEBUG [root] #### VMOPS exit s3 with result false ####
> In xensource.log you see it call the s3xenserver plugin:
> Nov 12 19:22:16 mccxpod01-hv08 xapi:
> [debug|mccxpod01-hv08|2166532|Async.host.call_plugin R:36173a97bfdc|audit]
> Host.call_plugin host = '5d4cc523-ced7-4324-9dfb-fb81cb225899
> (mccxpod01-hv07)'; plugin = 's3xenserver'; fn = 's3'; args = [ maxErrorRetry:
> 10; secretKey: x; connectionTtl: null; iSCSIFlag: false;
> maxSingleUploadSizeInBytes: 5368709120; bucket: mccx-nl2; endPoint:
> s3.x.schubergphilis.com; filename:
> /var/run/sr-mount/e914d2c5-f74f-4818-9dc5-c2f2f6f909f1/4b9295bd-779c-4212-84b7-9b79520cf42e.vhd;
> accessKey: x; socketTimeout: null; https: false; connectionTimeout: 300000;
> operation: put; key:
> snapshots/5/215/4b9295bd-779c-4212-84b7-9b79520cf42e.vhd; useTCPKeepAlive:
> null ]
> Nov 12 19:29:29 mccxpod01-hv08 xapi:
> [debug|mccxpod01-hv08|2168571|Async.host.call_plugin R:988800b3c267|audit]
> Host.call_plugin host = '552570ac-1a04-4576-8615-2af7767803b6
> (mccxpod01-hv08)'; plugin = 's3xenserver'; fn = 's3'; args = [ maxErrorRetry:
> 10; secretKey: +x; connectionTtl: null; iSCSIFlag: false;
> maxSingleUploadSizeInBytes: 5368709120; bucket: mccx-nl2; endPoint:
> This one doesn't work because it doesn't exist:
> s3.x.schubergphilis.com; filename:
> /var/run/sr-mount/2dcb90fe-1068-2e9f-6963-7de833f109f0/null.vhd; accessKey:
> x; socketTimeout: null; https: false; connectionTimeout: 300000; operation:
> put; key: snapshots/5/215/null.vhd; useTCPKeepAlive: null ]
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
