cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From France <mailingli...@isg.si>
Subject Fwd: ACS 4.1.1 -> 4.3.1 = errorInfo: [XENAPI_PLUGIN_FAILURE, getSnapshotSize, CommandException, 2] && vhd-util: libvhd::vhd_open: failed to open /dev/VG_XenStorage-197c3580-fc82-35e5-356d-1f0909a9cfd9/VHD-3d732e11-8697-4a45-9518-44d4154ee6d6: -2
Date Wed, 08 Oct 2014 10:45:13 GMT
Sending it here. Maybe here someone will respond.

Begin forwarded message:

> From: France <mailinglists@isg.si>
> Subject: ACS 4.1.1 -> 4.3.1 = errorInfo: [XENAPI_PLUGIN_FAILURE, getSnapshotSize,
CommandException, 2] && vhd-util: libvhd::vhd_open: failed to open /dev/VG_XenStorage-197c3580-fc82-35e5-356d-1f0909a9cfd9/VHD-3d732e11-8697-4a45-9518-44d4154ee6d6:
-2 
> Date: 7 Oct 2014 19:04:15 GMT+2
> To: "dev@cloudstack.apache.org" <dev@cloudstack.apache.org>
> Reply-To: dev@cloudstack.apache.org
> 
> Hi guys,
> 
> after upgrading ACS from 4.1.1 to 4.3.1 and upgrading XS 6.0.2 to latest hotfixes and
manually replacing NFSSR.py with one from ACS 4.3.1, amongst other errors, I see this error.
> Snapshot is created successfully. I have created templates from it and used them to create
new VMs, but in the log there is an error. (Also snapshots are not working on volumes which
have had snapshots before the upgrade. But i will deal with that issue later. They might even
be related.)
> 
> What should I check to provide you with more info about the issue, so we can address
it?
> Google search came up empty for this issue. :-( Please help me sort this out.
> To me, it looks like Xen removed /dev/VG_XenStorage-197c3580-fc82-35e5-356d-1f0909a9cfd9/VHD-3d732e11-8697-4a45-9518-44d4154ee6d6
after the copy to secondary storage but before cloudstack ordered the removal.
> Should I open a bug for it?
> 
> 
> This is where i believe the snapshot was ordered:
> /////////////////////////////////////
> 2014-10-07 16:51:16,919 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (http-6443-exec-42:ctx-6a64da65
ctx-e324e472) submit async job-2171, details: AsyncJobVO {id:2171, userId: 28, accountId:
30, instanceType: Snapshot, instanceId: 977, cmd: org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd,
cmdInfo: {"id":"977","response":"json","sessionkey”:"XXXXX","cmdEventType":"SNAPSHOT.CREATE","ctxUserId":"28","httpmethod":"GET","_":"1412693528063","volumeid":"72d5b956-fbaf-44c2-8aeb-df49354ddbb3","quiescevm":"false","ctxAccountId":"30","ctxStartEventId":"60842"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid:
95545481387, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2014-10-07 16:51:16,920 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-84:ctx-649dbc0e)
Add job-2171 into job monitoring
> 2014-10-07 16:51:16,920 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-84:ctx-649dbc0e)
Executing AsyncJobVO {id:2171, userId: 28, accountId: 30, instanceType: Snapshot, instanceId:
977, cmd: org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd, cmdInfo: {"id":"977","response":"json","sessionkey”:"XXXXX","cmdEventType":"SNAPSHOT.CREATE","ctxUserId":"28","httpmethod":"GET","_":"1412693528063","volumeid":"72d5b956-fbaf-44c2-8aeb-df49354ddbb3","quiescevm":"false","ctxAccountId":"30","ctxStartEventId":"60842"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid:
95545481387, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2014-10-07 16:51:16,920 DEBUG [c.c.a.ApiServlet] (http-6443-exec-42:ctx-6a64da65 ctx-e324e472)
===END===  XX.XX.XX.XX -- GET  command=createSnapshot&volumeid=72d5b956-fbaf-44c2-8aeb-df49354ddbb3&quiescevm=false&response=json&sessionkey=XXXXXX%3D&_=1412693528063
> 2014-10-07 16:51:16,928 DEBUG [c.c.u.AccountManagerImpl] (Job-Executor-84:ctx-649dbc0e
ctx-e324e472) Access to Acct[7ff6cd6b-7400-4d44-980b-9dc3115264eb-XXXXXX] granted to Acct[7ff6cd6b-7400-4d44-980b-9dc3115264eb-XXXX]
by DomainChecker
> 2014-10-07 16:51:16,953 INFO  [o.a.c.a.c.u.s.CreateSnapshotCmd] (Job-Executor-84:ctx-649dbc0e
ctx-e324e472) VOLSS: createSnapshotCmd starts:1412693476953
> 2014-10-07 16:51:17,290 DEBUG [c.c.a.t.Request] (Job-Executor-84:ctx-649dbc0e ctx-e324e472)
Seq 2-1824254062: Sending  { Cmd , MgmtId: 95545481387, via: 2(x2.XXX), Ver: v1, Flags: 100011,
[{"org.apache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"72d5b956-fbaf-44c2-8aeb-df49354ddbb3","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"1c8dbf77-2b23-3244-91ee-5037cb2a55a8","id":208,"poolType":"IscsiLUN","host":"s2.v.XXX","path":"/iqn.2010-02.XXX:storage.XXX.s2/1","port":3260,"url":"IscsiLUN://s2.v.XXX//iqn.2010-02.XXX:storage.XXX.s2/1/?ROLE=Primary&STOREUUID=1c8dbf77-2b23-3244-91ee-5037cb2a55a8"}},"name":"ROOT-457","size":21474836480,"path":"5f54e049-7336-46bf-88be-c364624504f9","volumeId":556,"vmName":"i-30-457-VM","accountId":30,"format":"VHD","id":556,"deviceId":0,"hypervisorType":"XenServer"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"1c8dbf77-2b23-3244-91ee-5037cb2a55a8","id":208,"poolType":"IscsiLUN","host":"s2.v.XXX","path":"/iqn.2010-02.XXX:storage.XXX.s2/1","port":3260,"url":"IscsiLUN://s2.v.XXX//iqn.2010-02.XXX:storage.XXX.s2/1/?ROLE=Primary&STOREUUID=1c8dbf77-2b23-3244-91ee-5037cb2a55a8"}},"vmName":"i-30-457-VM","name":"MInecraftDebian_ROOT-457_20141007145115","hypervisorType":"XenServer","id":977,"quiescevm":false,"physicalSize":0}},"wait":0}}]
}
> 2014-10-07 16:51:17,291 DEBUG [c.c.a.t.Request] (Job-Executor-84:ctx-649dbc0e ctx-e324e472)
Seq 2-1824254062: Executing:  { Cmd , MgmtId: 95545481387, via: 2(x2.XXX), Ver: v1, Flags:
100011, [{"org.apache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"72d5b956-fbaf-44c2-8aeb-df49354ddbb3","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"1c8dbf77-2b23-3244-91ee-5037cb2a55a8","id":208,"poolType":"IscsiLUN","host":"s2.v.XXX","path":"/iqn.2010-02.XXX:storage.XXX.s2/1","port":3260,"url":"IscsiLUN://s2.v.XXX//iqn.2010-02.XXX:storage.XXX.s2/1/?ROLE=Primary&STOREUUID=1c8dbf77-2b23-3244-91ee-5037cb2a55a8"}},"name":"ROOT-457","size":21474836480,"path":"5f54e049-7336-46bf-88be-c364624504f9","volumeId":556,"vmName":"i-30-457-VM","accountId":30,"format":"VHD","id":556,"deviceId":0,"hypervisorType":"XenServer"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"1c8dbf77-2b23-3244-91ee-5037cb2a55a8","id":208,"poolType":"IscsiLUN","host":"s2.v.XXX","path":"/iqn.2010-02.XXX:storage.XXX.s2/1","port":3260,"url":"IscsiLUN://s2.v.XXX//iqn.2010-02.XXX:storage.XXX.s2/1/?ROLE=Primary&STOREUUID=1c8dbf77-2b23-3244-91ee-5037cb2a55a8"}},"vmName":"i-30-457-VM","name":"MInecraftDebian_ROOT-457_20141007145115","hypervisorType":"XenServer","id":977,"quiescevm":false,"physicalSize":0}},"wait":0}}]
}
> 2014-10-07 16:51:17,291 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-25:ctx-a5197893)
Seq 2-1824254062: Executing request
> 2014-10-07 16:51:18,352 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-7:null)
Ping from 21
> 2014-10-07 16:51:20,075 DEBUG [c.c.a.ApiServlet] (http-6443-exec-34:ctx-c9163aa8) ===START===
 XX.XX.XX.XX -- GET  command=queryAsyncJobResult&jobId=89c49a6f-9d61-4bd8-a9ee-c41390ea3747&response=json&sessionkey=XXXXX%3D&_=1412693532730
> 2014-10-07 16:51:20,165 DEBUG [c.c.a.ApiServlet] (http-6443-exec-34:ctx-c9163aa8 ctx-25e4cfa1)
===END===  XX.XX.XX.XX -- GET  command=queryAsyncJobResult&jobId=89c49a6f-9d61-4bd8-a9ee-c41390ea3747&response=json&sessionkey=XXXXXX%3D&_=1412693532730
> 2014-10-07 16:51:20,238 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-12:null)
SeqA 27-139339: Processing Seq 27-139339:  { Cmd , MgmtId: -1, via: 27, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":473,"_loadInfo":"{\n 
\"connections\": []\n}","wait":0}}] }
> 2014-10-07 16:51:20,281 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-12:null)
SeqA 27-139339: Sending Seq 27-139339:  { Ans: , MgmtId: 95545481387, via: 27, Ver: v1, Flags:
100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2014-10-07 16:51:21,767 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-25:ctx-a5197893)
Seq 2-1824254062: Response Received: 
> 2014-10-07 16:51:21,767 DEBUG [c.c.a.t.Request] (DirectAgent-25:ctx-a5197893) Seq 2-1824254062:
Processing:  { Ans: , MgmtId: 95545481387, via: 2, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"d38b38f3-ebda-4cf7-9701-4ba22409644c","id":0,"quiescevm":false,"physicalSize":0}},"result":true,"wait":0}}]
}
> 2014-10-07 16:51:21,768 DEBUG [c.c.a.t.Request] (Job-Executor-84:ctx-649dbc0e ctx-e324e472)
Seq 2-1824254062: Received:  { Ans: , MgmtId: 95545481387, via: 2, Ver: v1, Flags: 10, { CreateObjectAnswer
} }
> 2014-10-07 16:51:22,156 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (Job-Executor-84:ctx-649dbc0e
ctx-e324e472) copyAsync inspecting src type SNAPSHOT copyAsync inspecting dest type SNAPSHOT
> 2014-10-07 16:51:22,201 DEBUG [c.c.a.t.Request] (Job-Executor-84:ctx-649dbc0e ctx-e324e472)
Seq 1-949601544: Sending  { Cmd , MgmtId: 95545481387, via: 1(x3.XXX), Ver: v1, Flags: 100011,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"d38b38f3-ebda-4cf7-9701-4ba22409644c","volume":{"uuid":"72d5b956-fbaf-44c2-8aeb-df49354ddbb3","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"1c8dbf77-2b23-3244-91ee-5037cb2a55a8","id":208,"poolType":"IscsiLUN","host":"s2.v.XXX","path":"/iqn.2010-02.XXX:storage.XXX.s2/1","port":3260,"url":"IscsiLUN://s2.v.XXX//iqn.2010-02.XXX:storage.XXX.s2/1/?ROLE=Primary&STOREUUID=1c8dbf77-2b23-3244-91ee-5037cb2a55a8"}},"name":"ROOT-457","size":21474836480,"path":"5f54e049-7336-46bf-88be-c364624504f9","volumeId":556,"vmName":"i-30-457-VM","accountId":30,"format":"VHD","id":556,"deviceId":0,"hypervisorType":"XenServer"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"1c8dbf77-2b23-3244-91ee-5037cb2a55a8","id":208,"poolType":"IscsiLUN","host":"s2.v.XXX","path":"/iqn.2010-02.XXX:storage.XXX.s2/1","port":3260,"url":"IscsiLUN://s2.v.XXX//iqn.2010-02.XXX:storage.XXX.s2/1/?ROLE=Primary&STOREUUID=1c8dbf77-2b23-3244-91ee-5037cb2a55a8"}},"vmName":"i-30-457-VM","name":"MInecraftDebian_ROOT-457_20141007145115","hypervisorType":"XenServer","id":977,"quiescevm":false,"physicalSize":0}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/30/556","volume":{"uuid":"72d5b956-fbaf-44c2-8aeb-df49354ddbb3","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"1c8dbf77-2b23-3244-91ee-5037cb2a55a8","id":208,"poolType":"IscsiLUN","host":"s2.v.XXX","path":"/iqn.2010-02.XXX:storage.XXX.s2/1","port":3260,"url":"IscsiLUN://s2.v.XXX//iqn.2010-02.XXX:storage.XXX.s2/1/?ROLE=Primary&STOREUUID=1c8dbf77-2b23-3244-91ee-5037cb2a55a8"}},"name":"ROOT-457","size":21474836480,"path":"5f54e049-7336-46bf-88be-c364624504f9","volumeId":556,"vmName":"i-30-457-VM","accountId":30,"format":"VHD","id":556,"deviceId":0,"hypervisorType":"XenServer"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://s6.XXX/mnt/rootPool/nfsSecondary","_role":"Image"}},"vmName":"i-30-457-VM","name":"MInecraftDebian_ROOT-457_20141007145115","hypervisorType":"XenServer","id":977,"quiescevm":false,"physicalSize":0}},"executeInSequence":false,"options":{"fullSnapshot":"true"},"wait":21600}}]
}
> 2014-10-07 16:51:22,201 DEBUG [c.c.a.t.Request] (Job-Executor-84:ctx-649dbc0e ctx-e324e472)
Seq 1-949601544: Executing:  { Cmd , MgmtId: 95545481387, via: 1(x3.XXX), Ver: v1, Flags:
100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"d38b38f3-ebda-4cf7-9701-4ba22409644c","volume":{"uuid":"72d5b956-fbaf-44c2-8aeb-df49354ddbb3","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"1c8dbf77-2b23-3244-91ee-5037cb2a55a8","id":208,"poolType":"IscsiLUN","host":"s2.v.XXX","path":"/iqn.2010-02.XXX:storage.XXX.s2/1","port":3260,"url":"IscsiLUN://s2.v.XXX//iqn.2010-02.XXX:storage.XXX.s2/1/?ROLE=Primary&STOREUUID=1c8dbf77-2b23-3244-91ee-5037cb2a55a8"}},"name":"ROOT-457","size":21474836480,"path":"5f54e049-7336-46bf-88be-c364624504f9","volumeId":556,"vmName":"i-30-457-VM","accountId":30,"format":"VHD","id":556,"deviceId":0,"hypervisorType":"XenServer"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"1c8dbf77-2b23-3244-91ee-5037cb2a55a8","id":208,"poolType":"IscsiLUN","host":"s2.v.XXX","path":"/iqn.2010-02.XXX:storage.XXX.s2/1","port":3260,"url":"IscsiLUN://s2.v.XXX//iqn.2010-02.XXX:storage.XXX.s2/1/?ROLE=Primary&STOREUUID=1c8dbf77-2b23-3244-91ee-5037cb2a55a8"}},"vmName":"i-30-457-VM","name":"MInecraftDebian_ROOT-457_20141007145115","hypervisorType":"XenServer","id":977,"quiescevm":false,"physicalSize":0}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/30/556","volume":{"uuid":"72d5b956-fbaf-44c2-8aeb-df49354ddbb3","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"1c8dbf77-2b23-3244-91ee-5037cb2a55a8","id":208,"poolType":"IscsiLUN","host":"s2.v.XXX","path":"/iqn.2010-02.XXX:storage.XXX.s2/1","port":3260,"url":"IscsiLUN://s2.v.XXX//iqn.2010-02.XXX:storage.XXX.s2/1/?ROLE=Primary&STOREUUID=1c8dbf77-2b23-3244-91ee-5037cb2a55a8"}},"name":"ROOT-457","size":21474836480,"path":"5f54e049-7336-46bf-88be-c364624504f9","volumeId":556,"vmName":"i-30-457-VM","accountId":30,"format":"VHD","id":556,"deviceId":0,"hypervisorType":"XenServer"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://s6.XXX/mnt/rootPool/nfsSecondary","_role":"Image"}},"vmName":"i-30-457-VM","name":"MInecraftDebian_ROOT-457_20141007145115","hypervisorType":"XenServer","id":977,"quiescevm":false,"physicalSize":0}},"executeInSequence":false,"options":{"fullSnapshot":"true"},"wait":21600}}]
}
> 2014-10-07 16:51:22,202 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-307:ctx-a2d8b59b)
Seq 1-949601544: Executing request
> 2014-10-07 16:51:23,072 DEBUG [c.c.a.ApiServlet] (http-6443-exec-33:ctx-7d98629a) ===START===
 XX.XX.XX.XX -- GET  command=queryAsyncJobResult&jobId=89c49a6f-9d61-4bd8-a9ee-c41390ea3747&response=json&sessionkey=XXXX%3D&_=1412693535726
> 2014-10-07 16:51:23,091 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-307:ctx-a2d8b59b)
Creating a not shared SR for nfs://s6.XXX/mnt/rootPool/nfsSecondary/snapshots/30/556
> 2014-10-07 16:51:23,254 DEBUG [c.c.a.ApiServlet] (http-6443-exec-33:ctx-7d98629a ctx-b1c48235)
===END===  XX.XX.XX.XX -- GET  command=queryAsyncJobResult&jobId=89c49a6f-9d61-4bd8-a9ee-c41390ea3747&response=json&sessionkey=XXXXXD&_=1412693535726
> 2014-10-07 16:51:23,954 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-307:ctx-a2d8b59b)
Checking 844c542f-2085-350d-8be6-2c2452eb3728 or SR 197c3580-fc82-35e5-356d-1f0909a9cfd9 on
XS[f6d699aa-f58f-449e-9a51-6e965562f178-XX.XX.023]
> 2014-10-07 16:51:23,965 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-307:ctx-a2d8b59b)
Host XX.XX.023 OpaqueRef:72228e56-6e60-e1dc-677d-d1dd171045c7: Created a SR; UUID is 197c3580-fc82-35e5-356d-1f0909a9cfd9
device config is {serverpath=/mnt/rootPool/nfsSecondary/snapshots/30/556, server=s6.XXX}
> /////////////////////////////////////
> 
> At that time x3 hypervisor wrote the following to messages:
> /////////////////////////////////////
> Oct  7 16:51:34 x3 multipathd: dm-24: add map (uevent) 
> Oct  7 16:51:34 x3 multipathd: dm-24: add map (uevent) 
> Oct  7 16:51:34 x3 multipathd: dm-25: add map (uevent) 
> Oct  7 16:51:34 x3 multipathd: dm-25: add map (uevent) 
> Oct  7 16:51:34 x3 multipathd: dm-26: add map (uevent) 
> Oct  7 16:51:34 x3 multipathd: dm-27: add map (uevent) 
> Oct  7 16:51:34 x3 multipathd: dm-27: add map (uevent) 
> Oct  7 16:51:34 x3 tapdisk[1677]: tapdisk-control: init, 10 x 4k buffers 
> Oct  7 16:51:34 x3 tapdisk[1677]: I/O queue driver: lio 
> Oct  7 16:51:34 x3 tapdisk[1677]: tapdisk-log: started, level 0 
> Oct  7 16:51:34 x3 tapdisk[1677]: /dev/VG_XenStorage-3b6e386d-8736-6b6b-7006-f3f4df9bd586/VHD-d38b38f3-ebda-4cf7-9701-4ba22409644c
version: tap 0x00010003, b: 10240, a: 0, f: 0, n: 0 
> Oct  7 16:51:34 x3 tapdisk[1677]: opened image /dev/VG_XenStorage-3b6e386d-8736-6b6b-7006-f3f4df9bd586/VHD-d38b38f3-ebda-4cf7-9701-4ba22409644c
(1 users, state: 0x00000003, type: 4, ro) 
> Oct  7 16:51:34 x3 tapdisk[1677]: /dev/mapper/VG_XenStorage--3b6e386d--8736--6b6b--7006--f3f4df9bd586-VHD--a6e64bdc--9883--476f--87b1--07fc669eade7
version: tap 0x00010003, b: 10240, a: 227, f: 1, n: 0 
> Oct  7 16:51:34 x3 tapdisk[1677]: opened image /dev/mapper/VG_XenStorage--3b6e386d--8736--6b6b--7006--f3f4df9bd586-VHD--a6e64bdc--9883--476f--87b1--07fc669eade7
(1 users, state: 0x00000003, type: 4, ro) 
> Oct  7 16:51:34 x3 tapdisk[1677]: /dev/mapper/VG_XenStorage--3b6e386d--8736--6b6b--7006--f3f4df9bd586-VHD--19ef64e0--398a--43b4--ad52--1d36eedc2b81
version: tap 0x00010003, b: 10240, a: 9422, f: 8614, n: 0 
> Oct  7 16:51:34 x3 tapdisk[1677]: opened image /dev/mapper/VG_XenStorage--3b6e386d--8736--6b6b--7006--f3f4df9bd586-VHD--19ef64e0--398a--43b4--ad52--1d36eedc2b81
(1 users, state: 0x00000003, type: 4, ro) 
> Oct  7 16:51:34 x3 tapdisk[1677]: /dev/mapper/VG_XenStorage--3b6e386d--8736--6b6b--7006--f3f4df9bd586-VHD--dde0bd55--1ae3--44bf--be8d--dac901b49c66
version: tap 0x00010003, b: 10240, a: 770, f: 372, n: 0 
> Oct  7 16:51:34 x3 tapdisk[1677]: opened image /dev/mapper/VG_XenStorage--3b6e386d--8736--6b6b--7006--f3f4df9bd586-VHD--dde0bd55--1ae3--44bf--be8d--dac901b49c66
(1 users, state: 0x00000003, type: 4, ro) 
> Oct  7 16:51:34 x3 tapdisk[1677]: VBD CHAIN: 
> Oct  7 16:51:34 x3 tapdisk[1677]: /dev/VG_XenStorage-3b6e386d-8736-6b6b-7006-f3f4df9bd586/VHD-d38b38f3-ebda-4cf7-9701-4ba22409644c:
type:vhd(4) storage:lvm(3) 
> Oct  7 16:51:34 x3 tapdisk[1677]: /dev/mapper/VG_XenStorage--3b6e386d--8736--6b6b--7006--f3f4df9bd586-VHD--a6e64bdc--9883--476f--87b1--07fc669eade7:
type:vhd(4) storage:lvm(3) 
> Oct  7 16:51:34 x3 tapdisk[1677]: /dev/mapper/VG_XenStorage--3b6e386d--8736--6b6b--7006--f3f4df9bd586-VHD--19ef64e0--398a--43b4--ad52--1d36eedc2b81:
type:vhd(4) storage:lvm(3) 
> Oct  7 16:51:34 x3 tapdisk[1677]: /dev/mapper/VG_XenStorage--3b6e386d--8736--6b6b--7006--f3f4df9bd586-VHD--dde0bd55--1ae3--44bf--be8d--dac901b49c66:
type:vhd(4) storage:lvm(3) 
> Oct  7 16:51:34 x3 tapdisk[1677]: bdev: capacity=41943040 sector_size=512/512 flags=0
> Oct  7 16:51:34 x3 multipathd: tdg: add path (uevent) 
> Oct  7 16:51:34 x3 multipathd: tdg: failed to store path info 
> Oct  7 16:51:34 x3 multipathd: uevent trigger error 
> Oct  7 16:51:34 x3 kernel: block tdg: sector-size: 512/512 capacity: 41943040
> Oct  7 16:51:34 x3 kernel: blkback: event-channel 85
> Oct  7 16:51:34 x3 kernel: blkback: ring-ref 8
> Oct  7 16:51:34 x3 kernel: blkback: protocol 1 (x86_32-abi)
> Oct  7 16:51:34 x3 multipathd: xvda: add path (uevent) 
> Oct  7 16:51:34 x3 multipathd: xvda: failed to store path info 
> Oct  7 16:51:34 x3 multipathd: uevent trigger error 
> Oct  7 16:51:34 x3 kernel: blkfront: xvda: barriers enabled
> Oct  7 16:51:34 x3 kernel:  xvda: xvda1 xvda2 < xvda5 >
> Oct  7 16:51:35 x3 vbd.uevent[add](backend/vbd/0/51712): wrote /xapi/0/hotplug/vbd/51712/hotplug
= 'online'
> Oct  7 16:51:35 x3 vbd.uevent[add](backend/vbd/0/51712): wrote backend/vbd/0/51712/hotplug-status
= 'connected'
> Oct  7 16:51:37 x3 tapdisk[2033]: tapdisk-control: init, 10 x 4k buffers 
> Oct  7 16:51:37 x3 tapdisk[2033]: I/O queue driver: lio 
> Oct  7 16:51:37 x3 tapdisk[2033]: tapdisk-log: started, level 0 
> Oct  7 16:51:37 x3 tapdisk[2033]: /var/run/sr-mount/197c3580-fc82-35e5-356d-1f0909a9cfd9/3d732e11-8697-4a45-9518-44d4154ee6d6.vhd
version: tap 0x00010003, b: 10240, a: 0, f: 0, n: 87 
> Oct  7 16:51:37 x3 tapdisk[2033]: opened image /var/run/sr-mount/197c3580-fc82-35e5-356d-1f0909a9cfd9/3d732e11-8697-4a45-9518-44d4154ee6d6.vhd
(1 users, state: 0x00000001, type: 4, rw) 
> Oct  7 16:51:37 x3 tapdisk[2033]: VBD CHAIN: 
> Oct  7 16:51:37 x3 tapdisk[2033]: /var/run/sr-mount/197c3580-fc82-35e5-356d-1f0909a9cfd9/3d732e11-8697-4a45-9518-44d4154ee6d6.vhd:
type:vhd(4) storage:nfs(1) 
> Oct  7 16:51:37 x3 tapdisk[2033]: bdev: capacity=41943040 sector_size=512/512 flags=0
> Oct  7 16:51:37 x3 multipathd: tdi: add path (uevent) 
> Oct  7 16:51:37 x3 multipathd: tdi: failed to store path info 
> Oct  7 16:51:37 x3 multipathd: uevent trigger error 
> Oct  7 16:51:37 x3 kernel: block tdi: sector-size: 512/512 capacity: 41943040
> Oct  7 16:51:37 x3 multipathd: xvdb: add path (uevent) 
> Oct  7 16:51:37 x3 multipathd: xvdb: failed to store path info 
> Oct  7 16:51:37 x3 multipathd: uevent trigger error 
> Oct  7 16:51:37 x3 kernel: blkback: event-channel 87
> Oct  7 16:51:37 x3 kernel: blkback: ring-ref 69
> Oct  7 16:51:37 x3 kernel: blkback: protocol 1 (x86_32-abi)
> Oct  7 16:51:37 x3 kernel: blkfront: xvdb: barriers enabled
> Oct  7 16:51:37 x3 kernel:  xvdb: unknown partition table
> Oct  7 16:51:37 x3 vbd.uevent[add](backend/vbd/0/51728): wrote /xapi/0/hotplug/vbd/51728/hotplug
= 'online'
> Oct  7 16:51:37 x3 vbd.uevent[add](backend/vbd/0/51728): wrote backend/vbd/0/51728/hotplug-status
= 'connected'
> Oct  7 16:51:38 x3 sparse_dd: [ info|x3.XXX|0||sparse_dd] streaming from raw /dev/xvda
using BAT from /dev/VG_XenStorage-3b6e386d-8736-6b6b-7006-f3f4df9bd586/VHD-d38b38f3-ebda-4cf7-9701-4ba22409644c
(relative to None) to raw file:///dev/xvdb
> /////////////////////////////////////
> 
> This is the actual error, which a believe comes after the copy of the snapshot is made
to secondary storage:
> /////////////////////////////////////
> 2014-10-07 17:58:49,920 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-307:ctx-a2d8b59b)
Task failed! Task record:                 uuid: 1258a9a9-1b7b-027c-5bfd-a210407b8ba5
>           nameLabel: Async.host.call_plugin
>     nameDescription: 
>   allowedOperations: []
>   currentOperations: {}
>             created: Tue Oct 07 17:58:48 CEST 2014
>            finished: Tue Oct 07 17:58:49 CEST 2014
>              status: failure
>          residentOn: com.xensource.xenapi.Host@c612622b
>            progress: 1.0
>                type: <none/>
>              result: 
>           errorInfo: [XENAPI_PLUGIN_FAILURE, getSnapshotSize, CommandException, 2]
>         otherConfig: {}
>           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
>            subtasks: []
> 
> 2014-10-07 17:58:49,929 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-307:ctx-a2d8b59b)
callHostPlugin failed for cmd: getSnapshotSize with args snapshotUuid: 3d732e11-8697-4a45-9518-44d4154ee6d6,
isISCSI: true, primaryStorageSRUuid: 197c3580-fc82-35e5-356d-1f0909a9cfd9,  due to Task failed!
Task record:                 uuid: 1258a9a9-1b7b-027c-5bfd-a210407b8ba5
>           nameLabel: Async.host.call_plugin
>     nameDescription: 
>   allowedOperations: []
>   currentOperations: {}
>             created: Tue Oct 07 17:58:48 CEST 2014
>            finished: Tue Oct 07 17:58:49 CEST 2014
>              status: failure
>          residentOn: com.xensource.xenapi.Host@c612622b
>            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: 1258a9a9-1b7b-027c-5bfd-a210407b8ba5
>           nameLabel: Async.host.call_plugin
>     nameDescription: 
>   allowedOperations: []
>   currentOperations: {}
>             created: Tue Oct 07 17:58:48 CEST 2014
>            finished: Tue Oct 07 17:58:49 CEST 2014
>              status: failure
>          residentOn: com.xensource.xenapi.Host@c612622b
>            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:3764)
> 	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.callHostPluginAsync(CitrixResourceBase.java:3971)
> 	at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.getSnapshotSize(XenServerStorageProcessor.java:1161)
> 	at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.backupSnapshot(XenServerStorageProcessor.java:1348)
> 	at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:90)
> 	at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:50)
> 	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:609)
> 	at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
> 	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$101(ScheduledThreadPoolExecutor.java:165)
> 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
> 	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-10-07 17:58:49,945 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-307:ctx-a2d8b59b)
Host XX.XX.023 OpaqueRef:72228e56-6e60-e1dc-677d-d1dd171045c7: Removing SR
> 2014-10-07 17:58:49,976 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-307:ctx-a2d8b59b)
Host XX.XX.023 OpaqueRef:417a2b3b-8042-359e-6394-180cbf82f600: Unplugging pbd
> 2014-10-07 17:58:50,423 DEBUG [c.c.a.ApiServlet] (http-6443-exec-42:ctx-b31e9f9b) ===START===
 XX.XX.XX.XX -- GET  command=queryAsyncJobResult&jobId=89c49a6f-9d61-4bd8-a9ee-c41390ea3747&response=json&sessionkey=vnXXXXXXX%3D&_=1412697583219
> 2014-10-07 17:58:50,446 DEBUG [c.c.a.ApiServlet] (http-6443-exec-42:ctx-b31e9f9b ctx-b14e1b8b)
===END===  XX.XX.XX.XX -- GET  command=queryAsyncJobResult&jobId=89c49a6f-9d61-4bd8-a9ee-c41390ea3747&response=json&sessionkey=vnXXXXXXX%3D&_=1412697583219
> 2014-10-07 17:58:50,529 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-307:ctx-a2d8b59b)
Host XX.XX.023 OpaqueRef:72228e56-6e60-e1dc-677d-d1dd171045c7: Forgetting
> 2014-10-07 17:58:50,535 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-222d1581)
VmStatsCollector is running...
> 2014-10-07 17:58:50,555 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-418:ctx-665da9a5)
Seq 1-949601730: Executing request
> 2014-10-07 17:58:50,979 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-418:ctx-665da9a5)
Vm cpu utilization 0.98
> 2014-10-07 17:58:50,979 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-418:ctx-665da9a5)
Vm cpu utilization 7.2124999999999995
> 2014-10-07 17:58:50,979 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-418:ctx-665da9a5)
Vm cpu utilization 1.3299999999999998
> 2014-10-07 17:58:50,979 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-418:ctx-665da9a5)
Vm cpu utilization 0.27
> 2014-10-07 17:58:51,013 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-418:ctx-665da9a5)
Error while collecting disk stats from : 
> 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:209)
> 	at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
> 	at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
> 	at com.xensource.xenapi.VBDMetrics.getIoReadKbs(VBDMetrics.java:210)
> 	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.getVmStats(CitrixResourceBase.java:2863)
> 	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:2763)
> 	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:493)
> 	at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
> 	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$101(ScheduledThreadPoolExecutor.java:165)
> 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
> 	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-10-07 17:58:51,036 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-418:ctx-665da9a5)
Seq 1-949601730: Response Received: 
> 2014-10-07 17:58:51,036 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-222d1581) Seq 1-949601730:
Received:  { Ans: , MgmtId: 95545481387, via: 1, Ver: v1, Flags: 10, { GetVmStatsAnswer }
}
> 2014-10-07 17:58:51,061 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-165:ctx-3c5b0bdc)
Seq 2-1824254287: Executing request
> 2014-10-07 17:58:51,627 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-165:ctx-3c5b0bdc)
Vm cpu utilization 0.53
> 2014-10-07 17:58:51,627 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-165:ctx-3c5b0bdc)
Vm cpu utilization 37.46
> 2014-10-07 17:58:51,627 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-165:ctx-3c5b0bdc)
Vm cpu utilization 0.62
> 2014-10-07 17:58:51,627 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-165:ctx-3c5b0bdc)
Vm cpu utilization 3.375
> 2014-10-07 17:58:51,627 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-165:ctx-3c5b0bdc)
Vm cpu utilization 0.54
> 2014-10-07 17:58:51,627 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-165:ctx-3c5b0bdc)
Vm cpu utilization 60.28
> 2014-10-07 17:58:51,627 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-165:ctx-3c5b0bdc)
Vm cpu utilization 0.63
> 2014-10-07 17:58:51,660 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-165:ctx-3c5b0bdc)
Error while collecting disk stats from : 
> 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:209)
> 	at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
> 	at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
> 	at com.xensource.xenapi.VBDMetrics.getIoReadKbs(VBDMetrics.java:210)
> 	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.getVmStats(CitrixResourceBase.java:2863)
> 	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:2763)
> 	at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:493)
> 	at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
> 	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$101(ScheduledThreadPoolExecutor.java:165)
> 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
> 	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-10-07 17:58:51,683 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-165:ctx-3c5b0bdc)
Seq 2-1824254287: Response Received: 
> 2014-10-07 17:58:51,683 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-222d1581) Seq 2-1824254287:
Received:  { Ans: , MgmtId: 95545481387, via: 2, Ver: v1, Flags: 10, { GetVmStatsAnswer }
}
> 2014-10-07 17:58:51,708 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-16:ctx-3d6b458a)
Seq 3-1392049173: Executing request
> 2014-10-07 17:58:51,733 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-307:ctx-a2d8b59b)
Successfully destroyed snapshot on volume: 5f54e049-7336-46bf-88be-c364624504f9 execept this
current snapshot d38b38f3-ebda-4cf7-9701-4ba22409644c
> 2014-10-07 17:58:51,734 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-307:ctx-a2d8b59b)
Seq 1-949601544: Response Received: 
> 2014-10-07 17:58:51,734 DEBUG [c.c.a.t.Request] (DirectAgent-307:ctx-a2d8b59b) Seq 1-949601544:
Processing:  { Ans: , MgmtId: 95545481387, via: 1, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/30/556/3d732e11-8697-4a45-9518-44d4154ee6d6","id":0,"quiescevm":false,"physicalSize":0}},"result":true,"wait":0}}]
}
> 2014-10-07 17:58:51,734 DEBUG [c.c.a.t.Request] (Job-Executor-84:ctx-649dbc0e ctx-e324e472)
Seq 1-949601544: Received:  { Ans: , MgmtId: 95545481387, via: 1, Ver: v1, Flags: 10, { CopyCmdAnswer
} }
> 2014-10-07 17:58:51,784 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-84:ctx-649dbc0e
ctx-e324e472) Complete async job-2171, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.SnapshotResponse/snapshot/{"id":"a5df5f35-c5f6-4644-a569-9bd4a26e500d","account":"martinG","domainid":"1268ca9a-7ec5-4154-9839-9b90699dfa4b","domain":"ROOT","snapshottype":"MANUAL","volumeid":"72d5b956-fbaf-44c2-8aeb-df49354ddbb3","volumename":"ROOT-457","volumetype":"ROOT","created":"2014-10-07T16:51:15+0200","name":"MInecraftDebian_ROOT-457_20141007145115","intervaltype":"MANUAL","state":"Allocated","tags":[],"revertable":false}
> /////////////////////////////////////
> 
> At that time the x3 hypervisor wrote this to messages:
> /////////////////////////////////////
> Oct  7 17:58:42 x3 multipathd: xvdb: remove path (uevent) 
> Oct  7 17:58:42 x3 multipathd: xvdb: spurious uevent, path not in pathvec 
> Oct  7 17:58:42 x3 multipathd: uevent trigger error 
> Oct  7 17:58:42 x3 vbd.uevent[remove](backend/vbd/0/51728): removed /xapi/0/hotplug/vbd/51728/hotplug
> Oct  7 17:58:42 x3 vbd.uevent[remove](backend/vbd/0/51728): removed backend/vbd/0/51728/hotplug-status
> Oct  7 17:58:43 x3 multipathd: tdi: remove path (uevent) 
> Oct  7 17:58:43 x3 multipathd: tdi: spurious uevent, path not in pathvec 
> Oct  7 17:58:43 x3 multipathd: uevent trigger error 
> Oct  7 17:58:43 x3 tapdisk[2033]: gaps written/skipped: 0/0 
> Oct  7 17:58:43 x3 tapdisk[2033]: /var/run/sr-mount/197c3580-fc82-35e5-356d-1f0909a9cfd9/3d732e11-8697-4a45-9518-44d4154ee6d6.vhd:
b: 10240, a: 9510, f: 9510, n: 39029120 
> Oct  7 17:58:43 x3 tapdisk[2033]: closed image /var/run/sr-mount/197c3580-fc82-35e5-356d-1f0909a9cfd9/3d732e11-8697-4a45-9518-44d4154ee6d6.vhd
(0 users, state: 0x00000000, type: 4) 
> Oct  7 17:58:43 x3 tapdisk[2033]: tapdisk-log: closing after 0 errors 
> Oct  7 17:58:43 x3 tapdisk[2033]: tapdisk-syslog: 11 messages, 893 bytes, xmits: 12,
failed: 0, dropped: 0
> Oct  7 17:58:43 x3 tapdisk[2033]: tapdisk-control: draining 1 connections 
> Oct  7 17:58:43 x3 tapdisk[2033]: tapdisk-control: done 
> Oct  7 17:58:44 x3 ovs-vswitchd: 46807|timeval|WARN|9 ms poll interval (0 ms user, 0
ms system) is over 14 times the weighted mean interval 1 ms (54312674 samples)
> Oct  7 17:58:44 x3 ovs-vswitchd: 46808|coverage|INFO|Skipping details of duplicate event
coverage for hash=735285a1 in epoch 54312674
> Oct  7 17:58:44 x3 multipathd: xvda: remove path (uevent) 
> Oct  7 17:58:44 x3 multipathd: xvda: spurious uevent, path not in pathvec 
> Oct  7 17:58:44 x3 multipathd: uevent trigger error 
> Oct  7 17:58:44 x3 vbd.uevent[remove](backend/vbd/0/51712): removed /xapi/0/hotplug/vbd/51712/hotplug
> Oct  7 17:58:44 x3 vbd.uevent[remove](backend/vbd/0/51712): removed backend/vbd/0/51712/hotplug-status
> Oct  7 17:58:45 x3 multipathd: tdg: remove path (uevent) 
> Oct  7 17:58:45 x3 multipathd: tdg: spurious uevent, path not in pathvec 
> Oct  7 17:58:45 x3 tapdisk[1677]: gaps written/skipped: 0/0 
> Oct  7 17:58:45 x3 multipathd: uevent trigger error 
> Oct  7 17:58:45 x3 tapdisk[1677]: /dev/VG_XenStorage-3b6e386d-8736-6b6b-7006-f3f4df9bd586/VHD-d38b38f3-ebda-4cf7-9701-4ba22409644c:
b: 10240, a: 0, f: 0, n: 0 
> Oct  7 17:58:45 x3 tapdisk[1677]: closed image /dev/VG_XenStorage-3b6e386d-8736-6b6b-7006-f3f4df9bd586/VHD-d38b38f3-ebda-4cf7-9701-4ba22409644c
(0 users, state: 0x00000002, type: 4) 
> Oct  7 17:58:45 x3 tapdisk[1677]: gaps written/skipped: 0/0 
> Oct  7 17:58:45 x3 tapdisk[1677]: /dev/mapper/VG_XenStorage--3b6e386d--8736--6b6b--7006--f3f4df9bd586-VHD--a6e64bdc--9883--476f--87b1--07fc669eade7:
b: 10240, a: 227, f: 1, n: 0 
> Oct  7 17:58:45 x3 tapdisk[1677]: closed image /dev/mapper/VG_XenStorage--3b6e386d--8736--6b6b--7006--f3f4df9bd586-VHD--a6e64bdc--9883--476f--87b1--07fc669eade7
(0 users, state: 0x00000002, type: 4) 
> Oct  7 17:58:45 x3 tapdisk[1677]: gaps written/skipped: 0/0 
> Oct  7 17:58:45 x3 tapdisk[1677]: /dev/mapper/VG_XenStorage--3b6e386d--8736--6b6b--7006--f3f4df9bd586-VHD--19ef64e0--398a--43b4--ad52--1d36eedc2b81:
b: 10240, a: 9422, f: 8614, n: 0 
> Oct  7 17:58:45 x3 tapdisk[1677]: closed image /dev/mapper/VG_XenStorage--3b6e386d--8736--6b6b--7006--f3f4df9bd586-VHD--19ef64e0--398a--43b4--ad52--1d36eedc2b81
(0 users, state: 0x00000002, type: 4) 
> Oct  7 17:58:45 x3 tapdisk[1677]: gaps written/skipped: 0/0 
> Oct  7 17:58:45 x3 tapdisk[1677]: /dev/mapper/VG_XenStorage--3b6e386d--8736--6b6b--7006--f3f4df9bd586-VHD--dde0bd55--1ae3--44bf--be8d--dac901b49c66:
b: 10240, a: 770, f: 372, n: 0 
> Oct  7 17:58:45 x3 tapdisk[1677]: closed image /dev/mapper/VG_XenStorage--3b6e386d--8736--6b6b--7006--f3f4df9bd586-VHD--dde0bd55--1ae3--44bf--be8d--dac901b49c66
(0 users, state: 0x00000002, type: 4) 
> Oct  7 17:58:45 x3 tapdisk[1677]: tapdisk-log: closing after 0 errors 
> Oct  7 17:58:46 x3 tapdisk[1677]: tapdisk-syslog: 14 messages, 1425 bytes, xmits: 15,
failed: 0, dropped: 0
> Oct  7 17:58:45 x3 tapdisk[1677]: tapdisk-control: draining 1 connections 
> Oct  7 17:58:45 x3 tapdisk[1677]: tapdisk-control: done 
> Oct  7 17:58:46 x3 multipathd: dm-24: remove map (uevent) 
> Oct  7 17:58:46 x3 multipathd: dm-24: devmap not registered, can't remove 
> Oct  7 17:58:46 x3 multipathd: dm-24: remove map (uevent) 
> Oct  7 17:58:46 x3 multipathd: dm-24: devmap not registered, can't remove 
> Oct  7 17:58:46 x3 multipathd: dm-27: remove map (uevent) 
> Oct  7 17:58:46 x3 multipathd: dm-27: devmap not registered, can't remove 
> Oct  7 17:58:46 x3 multipathd: dm-27: remove map (uevent) 
> Oct  7 17:58:46 x3 multipathd: dm-27: devmap not registered, can't remove 
> Oct  7 17:58:46 x3 multipathd: dm-25: remove map (uevent) 
> Oct  7 17:58:46 x3 multipathd: dm-25: devmap not registered, can't remove 
> Oct  7 17:58:47 x3 multipathd: dm-25: remove map (uevent) 
> Oct  7 17:58:47 x3 multipathd: dm-25: devmap not registered, can't remove 
> Oct  7 17:58:47 x3 multipathd: dm-26: remove map (uevent) 
> Oct  7 17:58:47 x3 multipathd: dm-26: devmap not registered, can't remove 
> Oct  7 17:58:47 x3 multipathd: dm-26: remove map (uevent) 
> Oct  7 17:58:47 x3 multipathd: dm-26: devmap not registered, can't remove 
> Oct  7 17:58:49 x3 vhd-util: libvhd::vhd_open: failed to open /dev/VG_XenStorage-197c3580-fc82-35e5-356d-1f0909a9cfd9/VHD-3d732e11-8697-4a45-9518-44d4154ee6d6:
-2 
> /////////////////////////////////////
> 
> vhd-utils on x3:
> 
> [root@x3 log]# find / -name vhd-util
> /usr/sbin/vhd-util
> /opt/xensource/bin/vhd-util
> /opt/cloud/bin/vhd-util
> find: /proc/7815/net: Invalid argument
> [root@x3 log]# md5sum /usr/sbin/vhd-util
> c849eae34a76f18163ffeea7ae1008fe  /usr/sbin/vhd-util
> [root@x3 log]# md5sum /opt/xensource/bin/vhd-util
> 2f3b434842d25d9672cc0a75d103ae90  /opt/xensource/bin/vhd-util
> [root@x3 log]# md5sum /opt/cloud/bin/vhd-util
> 2f3b434842d25d9672cc0a75d103ae90  /opt/cloud/bin/vhd-util
> 
> Also in XenCenter I can still see MInecraftDebian_ROOT-457_20141007145115.
> 
> Thank you for your time.
> Regads,
> F.
> 


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