cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Andrija Panic <andrija.pa...@gmail.com>
Subject Kind of urgent - snapshooting doesn't work
Date Fri, 09 May 2014 14:50:22 GMT
Hi,

I'm having an urgent situation with the production CS installation.

I'm unable to make any snapshots, due to "internal error creating
snapshot..":

Please find attached CS management logs - there is NO entry in libvirt log
on CS management server (which also hosts VMs), and there is NO entries on
the CS agent log on this same CS management server. Also there are only few
lines logged inside SSVM (yes, I have used the script
/usr/local/cloud/systemvm/ssvm-check.sh to confirm that all works fine).

Those are lines from within SSVM:/

what is also strange, those lines seems to be just repeating as the time
goes buy...
This might be some issue with SSVM "talk" to NFS Secodnary Storage server ?

2014-05-09 14:44:33,019 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null)
Received response: Seq 36-1522:  { Ans: , MgmtId: 161344838950, via: 36,
Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Storage","hostId":36,"wait":0},"result":true,"wait":0}}]
}
2014-05-09 14:44:48,035 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-1:null) Processing command:
com.cloud.agent.api.GetStorageStatsCommand
2014-05-09 14:45:32,977 DEBUG [cloud.agent.Agent] (UgentTask-5:null)
Sending ping: Seq 36-1523:  { Cmd , MgmtId: -1, via: 36, Ver: v1, Flags:
11,
[{"com.cloud.agent.api.PingStorageCommand":{"changes":{},"hostType":"Storage","hostId":36,"wait":0}}]
}
2014-05-09 14:45:33,019 DEBUG [cloud.agent.Agent] (Agent-Handler-3:null)
Received response: Seq 36-1523:  { Ans: , MgmtId: 161344838950, via: 36,
Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Storage","hostId":36,"wait":0},"result":true,"wait":0}}]
}
2014-05-09 14:45:48,941 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-4:null) Processing command:
com.cloud.agent.api.GetStorageStatsCommand
2014-05-09 14:46:32,977 DEBUG [cloud.agent.Agent] (UgentTask-5:null)
Sending ping: Seq 36-1524:  { Cmd , MgmtId: -1, via: 36, Ver: v1, Flags:
11,
[{"com.cloud.agent.api.PingStorageCommand":{"changes":{},"hostType":"Storage","hostId":36,"wait":0}}]
}
2014-05-09 14:46:33,019 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null)
Received response: Seq 36-1524:  { Ans: , MgmtId: 161344838950, via: 36,
Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Storage","hostId":36,"wait":0},"result":true,"wait":0}}]
}
2014-05-09 14:46:49,852 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-5:null) Processing command:
com.cloud.agent.api.GetStorageStatsCommand
2014-05-09 14:47:32,977 DEBUG [cloud.agent.Agent] (UgentTask-5:null)
Sending ping: Seq 36-1525:  { Cmd , MgmtId: -1, via: 36, Ver: v1, Flags:
11,
[{"com.cloud.agent.api.PingStorageCommand":{"changes":{},"hostType":"Storage","hostId":36,"wait":0}}]
}
2014-05-09 14:47:33,019 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null)
Received response: Seq 36-1525:  { Ans: , MgmtId: 161344838950, via: 36,
Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Storage","hostId":36,"wait":0},"result":true,"wait":0}}]
}



What is funny, the *folder* on Secondary Storage NFS host *was
created* /mnt/b3eaee50-4fbe-32cf-b384-0d7e09c88a2b/snapshots/2/885,
but no files inside...
I have restarted cloudstack-management service, also restarted SSVM, etc,
but no changes...

But making template and registering ISO files works fine, so not sure what
is happening here...

Thanks for any input

CS Management log:

2014-05-09 16:26:08,962 DEBUG [cloud.api.ApiServlet]
(http-8843-exec-1:null) ===START===  89.216.56.189 -- GET
 command=createSnapshot&volumeid=d7b2bb82-6e44-4633-a94b-2ea459509e4b&response=json&sessionkey=gMcdqBnImuXjBngdiwALIn6Q1nA%3D&_=1399645571923
2014-05-09 16:26:09,035 DEBUG [cloud.async.AsyncJobManagerImpl]
(http-8843-exec-1:null) submit async job-2508 = [
c2073617-5513-47d3-8fc5-27fc30cf50ad ], details: AsyncJobVO {id:2508,
userId: 2, accountId: 2, sessionKey: null, instanceType: Snapshot,
instanceId: 569, cmd:
org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd,
cmdOriginator: null, cmdInfo:
{"id":"569","response":"json","sessionkey":"gMcdqBnImuXjBngdiwALIn6Q1nA\u003d","cmdEventType":"SNAPSHOT.CREATE","ctxUserId":"2","httpmethod":"GET","_":"1399645571923","volumeid":"d7b2bb82-6e44-4633-a94b-2ea459509e4b","ctxAccountId":"2","ctxStartEventId":"106897"},
cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0,
processStatus: 0, resultCode: 0, result: null, initMsid: 161344838950,
completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-05-09 16:26:09,037 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-27:job-2508 = [ c2073617-5513-47d3-8fc5-27fc30cf50ad ])
Executing org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd
for job-2508 = [ c2073617-5513-47d3-8fc5-27fc30cf50ad ]
2014-05-09 16:26:09,037 DEBUG [cloud.api.ApiServlet]
(http-8843-exec-1:null) ===END===  89.216.56.189 -- GET
 command=createSnapshot&volumeid=d7b2bb82-6e44-4633-a94b-2ea459509e4b&response=json&sessionkey=gMcdqBnImuXjBngdiwALIn6Q1nA%3D&_=1399645571923
2014-05-09 16:26:09,055 INFO  [user.snapshot.CreateSnapshotCmd]
(Job-Executor-27:job-2508 = [ c2073617-5513-47d3-8fc5-27fc30cf50ad ])
VOLSS: createSnapshotCmd starts:1399645569055
2014-05-09 16:26:09,132 DEBUG [agent.transport.Request]
(Job-Executor-27:job-2508 = [ c2073617-5513-47d3-8fc5-27fc30cf50ad ]) Seq
1-2009800058: Sending  { Cmd , MgmtId: 161344838950, via: 1, Ver: v1,
Flags: 100011,
[{"org.apache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"d7b2bb82-6e44-4633-a94b-2ea459509e4b","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"1b469c9e-5617-445e-983f-0885a744cab7","id":200,"poolType":"Filesystem","host":"10.44.253.10","path":"/var/lib/libvirt/images","port":0}},"name":"ROOT-656","size":10737418240,"path":"92172e53-06c2-468a-8fb1-5bddd60aa876","volumeId":885,"vmName":"i-2-656-VM","accountId":2,"format":"QCOW2","id":885,"hypervisorType":"KVM"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"1b469c9e-5617-445e-983f-0885a744cab7","id":200,"poolType":"Filesystem","host":"10.44.253.10","path":"/var/lib/libvirt/images","port":0}},"vmName":"i-2-656-VM","name":"templateCS1problem_ROOT-656_20140509142608","hypervisorType":"KVM","id":569}},"wait":0}}]
}
2014-05-09 16:26:09,320 DEBUG [agent.transport.Request]
(AgentManager-Handler-7:null) Seq 1-2009800058: Processing:  { Ans: ,
MgmtId: 161344838950, via: 1, Ver: v1, Flags: 10,
[{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/var/lib/libvirt/images/92172e53-06c2-468a-8fb1-5bddd60aa876/bc70ec25-270e-4b22-a186-b33d11de2054","id":0}},"result":true,"wait":0}}]
}
2014-05-09 16:26:09,321 DEBUG [agent.transport.Request]
(Job-Executor-27:job-2508 = [ c2073617-5513-47d3-8fc5-27fc30cf50ad ]) Seq
1-2009800058: Received:  { Ans: , MgmtId: 161344838950, via: 1, Ver: v1,
Flags: 10, { CreateObjectAnswer } }
2014-05-09 16:26:09,386 DEBUG [storage.motion.AncientDataMotionStrategy]
(Job-Executor-27:job-2508 = [ c2073617-5513-47d3-8fc5-27fc30cf50ad ])
copyAsync inspecting src type SNAPSHOT copyAsync inspecting dest type
SNAPSHOT
2014-05-09 16:26:09,414 DEBUG [agent.transport.Request]
(Job-Executor-27:job-2508 = [ c2073617-5513-47d3-8fc5-27fc30cf50ad ]) Seq
1-2009800059: Sending  { Cmd , MgmtId: 161344838950, via: 1, Ver: v1,
Flags: 100111,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/var/lib/libvirt/images/92172e53-06c2-468a-8fb1-5bddd60aa876/bc70ec25-270e-4b22-a186-b33d11de2054","volume":{"uuid":"d7b2bb82-6e44-4633-a94b-2ea459509e4b","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"1b469c9e-5617-445e-983f-0885a744cab7","id":200,"poolType":"Filesystem","host":"10.44.253.10","path":"/var/lib/libvirt/images","port":0}},"name":"ROOT-656","size":10737418240,"path":"92172e53-06c2-468a-8fb1-5bddd60aa876","volumeId":885,"vmName":"i-2-656-VM","accountId":2,"format":"QCOW2","id":885,"hypervisorType":"KVM"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"1b469c9e-5617-445e-983f-0885a744cab7","id":200,"poolType":"Filesystem","host":"10.44.253.10","path":"/var/lib/libvirt/images","port":0}},"vmName":"i-2-656-VM","name":"templateCS1problem_ROOT-656_20140509142608","hypervisorType":"KVM","id":569}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/885","volume":{"uuid":"d7b2bb82-6e44-4633-a94b-2ea459509e4b","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"1b469c9e-5617-445e-983f-0885a744cab7","id":200,"poolType":"Filesystem","host":"10.44.253.10","path":"/var/lib/libvirt/images","port":0}},"name":"ROOT-656","size":10737418240,"path":"92172e53-06c2-468a-8fb1-5bddd60aa876","volumeId":885,"vmName":"i-2-656-VM","accountId":2,"format":"QCOW2","id":885,"hypervisorType":"KVM"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://
10.44.253.13/var/lib/libvirt/SECONDARY","_role":"Image"}},"vmName":"i-2-656-VM","name":"templateCS1problem_ROOT-656_20140509142608","hypervisorType":"KVM","id":569}},"executeInSequence":true,"wait":21600}}]
}
2014-05-09 16:26:09,853 DEBUG [agent.transport.Request]
(AgentManager-Handler-15:null) Seq 1-2009800059: Processing:  { Ans: ,
MgmtId: 161344838950, via: 1, Ver: v1, Flags: 110,
[{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"Failed
to backup bc70ec25-270e-4b22-a186-b33d11de2054 for disk
/var/lib/libvirt/images/92172e53-06c2-468a-8fb1-5bddd60aa876 to
/mnt/b3eaee50-4fbe-32cf-b384-0d7e09c88a2b/snapshots/2/885","wait":0}}] }
2014-05-09 16:26:09,854 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-15:null) Seq 1-2009800059: No more commands found
2014-05-09 16:26:09,854 DEBUG [agent.transport.Request]
(Job-Executor-27:job-2508 = [ c2073617-5513-47d3-8fc5-27fc30cf50ad ]) Seq
1-2009800059: Received:  { Ans: , MgmtId: 161344838950, via: 1, Ver: v1,
Flags: 110, { CopyCmdAnswer } }
2014-05-09 16:26:09,874 DEBUG [storage.snapshot.SnapshotManagerImpl]
(Job-Executor-27:job-2508 = [ c2073617-5513-47d3-8fc5-27fc30cf50ad ])
Failed to create snapshot
com.cloud.utils.exception.CloudRuntimeException: *Failed to backup
bc70ec25-270e-4b22-a186-b33d11de2054 for disk
/var/lib/libvirt/images/92172e53-06c2-468a-8fb1-5bddd60aa876 to
/mnt/b3eaee50-4fbe-32cf-b384-0d7e09c88a2b/snapshots/2/885*
        at
org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:280)
        at
org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:136)
        at
org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:279)
        at
com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1007)
        at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
        at
org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1311)
        at
com.cloud.storage.VolumeManagerImpl.takeSnapshot(VolumeManagerImpl.java:2773)
        at
org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:170)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
        at
com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
        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.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:701)
2014-05-09 16:26:09,901 DEBUG [storage.volume.VolumeServiceImpl]
(Job-Executor-27:job-2508 = [ c2073617-5513-47d3-8fc5-27fc30cf50ad ]) Take
snapshot: 885 failed
com.cloud.utils.exception.CloudRuntimeException: Failed to create snapshot
        at
com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1034)
        at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
        at
org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1311)
        at
com.cloud.storage.VolumeManagerImpl.takeSnapshot(VolumeManagerImpl.java:2773)
        at
org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:170)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
        at
com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
        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.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:701)
Caused by: com.cloud.utils.exception.CloudRuntimeException: Failed to
backup bc70ec25-270e-4b22-a186-b33d11de2054 for disk
/var/lib/libvirt/images/92172e53-06c2-468a-8fb1-5bddd60aa876 to
/mnt/b3eaee50-4fbe-32cf-b384-0d7e09c88a2b/snapshots/2/885
        at
org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:280)
        at
org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:136)
        at
org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:279)
        at
com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1007)
        ... 16 more
2014-05-09 16:26:09,901 DEBUG [user.snapshot.CreateSnapshotCmd]
(Job-Executor-27:job-2508 = [ c2073617-5513-47d3-8fc5-27fc30cf50ad ])
Failed to create snapshot
org.apache.cloudstack.api.ServerApiException
        at
org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:176)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
        at
com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
        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.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:701)
2014-05-09 16:26:09,902 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-27:job-2508 = [ c2073617-5513-47d3-8fc5-27fc30cf50ad ])
Complete async job-2508 = [ c2073617-5513-47d3-8fc5-27fc30cf50ad ],
jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: Failed
to create snapshot due to an internal error creating snapshot for volume 885
-- 

Andrija Panić

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message