cloudstack-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Jayapal Reddy Uradi <jayapalreddy.ur...@citrix.com>
Subject Re: can't create new instance on cloudstack 4.1.1+xenserver 6.1
Date Fri, 20 Sep 2013 14:21:46 GMT
Hi,

>From the logs it seems you xenserver doesn't have vhd-util binary.
.CitrixResourthe vhdceBase.copy_vhd_from_secondarystorage
Please check your host logs in /var/log/SMlog

in xenserver vhd-util path is /opt/xensource/bin/vhd-util

Thanks,
Jayapal

On 20-Sep-2013, at 7:39 PM, William Jiang <William.Jiang@manwin.com>
 wrote:

> Hi all,
> I need emergency help for my cloudstack(cloudstack 4.1.1 + xenserver 6.1), it was working well but now can't create new instance any  more.
> 
> The management-server.log as following:
> 
> 2013-09-20 09:37:58,271 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-200:null) Ping from 1
> 2013-09-20 09:37:58,681 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684278126
> 2013-09-20 09:37:58,694 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684278126
> 2013-09-20 09:37:58,936 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-15:null) Ping from 2
> 2013-09-20 09:38:01,197 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-146:null) Ping from 3
> 2013-09-20 09:38:01,683 DEBUG [cloud.api.ApiServlet] (catalina-exec-3:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684281127
> 2013-09-20 09:38:01,695 DEBUG [cloud.api.ApiServlet] (catalina-exec-3:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684281127
> 2013-09-20 09:38:04,501 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-487:null) Seq 4-1494220805: Executing request
> 2013-09-20 09:38:04,685 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684284129
> 2013-09-20 09:38:04,697 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684284129
> 2013-09-20 09:38:05,336 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-487:null) Seq 4-1494220805: Response Received:
> 2013-09-20 09:38:05,336 DEBUG [agent.transport.Request] (DirectAgent-487:null) Seq 4-1494220805: Processing:  { Ans: , MgmtId: 110492071566, via: 4, Ver: v1, Flags: 10, [{"ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}] }
> 2013-09-20 09:38:06,501 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-455:null) Seq 4-1494223565: Response Received:
> 2013-09-20 09:38:06,501 DEBUG [agent.transport.Request] (DirectAgent-455:null) Seq 4-1494223565: Processing:  { Ans: , MgmtId: 110492071566, via: 4, Ver: v1, Flags: 110, [{"Answer":{"result":true,"wait":0}},{"Answer":{"result":true,"wait":0}}] }
> 2013-09-20 09:38:06,501 DEBUG [agent.manager.AgentAttache] (DirectAgent-455:null) Seq 4-1494223565: No more commands found
> 2013-09-20 09:38:06,501 DEBUG [agent.transport.Request] (Job-Executor-10:job-1696) Seq 4-1494223565: Received:  { Ans: , MgmtId: 110492071566, via: 4, Ver: v1, Flags: 110, { Answer, Answer } }
> 2013-09-20 09:38:06,501 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-10:job-1696) Asking Ovs to prepare for Nic[347-278-6fb43b9f-cb8e-49d5-886f-724281b1b75a-10.3.34.62]
> 2013-09-20 09:38:06,501 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-10:job-1696) Asking SecurityGroupProvider to prepare for Nic[347-278-6fb43b9f-cb8e-49d5-886f-724281b1b75a-10.3.34.62]
> 2013-09-20 09:38:06,504 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-10:job-1696) Asking VpcVirtualRouter to prepare for Nic[347-278-6fb43b9f-cb8e-49d5-886f-724281b1b75a-10.3.34.62]
> 2013-09-20 09:38:06,504 WARN  [network.element.VpcVirtualRouterElement] (Job-Executor-10:job-1696) Network Ntwk[204|Guest|5] is not associated with any VPC
> 2013-09-20 09:38:06,509 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-10:job-1696) Checking if we need to prepare 1 volumes for VM[User|test-ub12-sep20]
> 2013-09-20 09:38:06,511 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-10:job-1696) Creating volume: Vol[339|vm=278|ROOT]
> 2013-09-20 09:38:06,511 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-10:job-1696) Trying to create in Pool[202|IscsiLUN]
> 2013-09-20 09:38:06,522 DEBUG [cloud.template.TemplateManagerImpl] (Job-Executor-10:job-1696) Downloading 313 via 112
> 2013-09-20 09:38:06,525 DEBUG [agent.transport.Request] (Job-Executor-10:job-1696) Seq 112-365365005: Sending  { Cmd , MgmtId: 110492071566, via: 112, Ver: v1, Flags: 100111, [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/2865ed4f-e8da-31f2-9353-c0abd93d8aba","poolUuid":"2865ed4f-e8da-31f2-9353-c0abd93d8aba","poolId":202,"primaryPool":{"id":202,"uuid":"2865ed4f-e8da-31f2-9353-c0abd93d8aba","host":"10.3.34.5","path":"/iqn.2001-05.com.equallogic:0-1cb196-305b0190a-84600000019511bd-cloudstackprimary/0","port":3260,"type":"IscsiLUN"},"secondaryStorageUrl":"nfs://mgt-cld.na.manwin.local/home/secondary","primaryStorageUrl":"nfs://10.3.34.5/iqn.2001-05.com.equallogic:0-1cb196-305b0190a-84600000019511bd-cloudstackprimary/0","url":"nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/4/313//e754f71a-4b34-47e0-b69d-b349a6c356d1.vhd","format":"VHD","accountId":4,"name":"e754f71a-4b34-47e0-b69d-b349a6c356d1","wait":10800}}] }
> 2013-09-20 09:38:06,525 DEBUG [agent.transport.Request] (Job-Executor-10:job-1696) Seq 112-365365005: Executing:  { Cmd , MgmtId: 110492071566, via: 112, Ver: v1, Flags: 100111, [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/2865ed4f-e8da-31f2-9353-c0abd93d8aba","poolUuid":"2865ed4f-e8da-31f2-9353-c0abd93d8aba","poolId":202,"primaryPool":{"id":202,"uuid":"2865ed4f-e8da-31f2-9353-c0abd93d8aba","host":"10.3.34.5","path":"/iqn.2001-05.com.equallogic:0-1cb196-305b0190a-84600000019511bd-cloudstackprimary/0","port":3260,"type":"IscsiLUN"},"secondaryStorageUrl":"nfs://mgt-cld.na.manwin.local/home/secondary","primaryStorageUrl":"nfs://10.3.34.5/iqn.2001-05.com.equallogic:0-1cb196-305b0190a-84600000019511bd-cloudstackprimary/0","url":"nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/4/313//e754f71a-4b34-47e0-b69d-b349a6c356d1.vhd","format":"VHD","accountId":4,"name":"e754f71a-4b34-47e0-b69d-b349a6c356d1","wait":10800}}] }
> 2013-09-20 09:38:06,525 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-145:null) Seq 112-365365005: Executing request
> 2013-09-20 09:38:07,686 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684287130
> 2013-09-20 09:38:07,699 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684287130
> 2013-09-20 09:38:10,689 DEBUG [cloud.api.ApiServlet] (catalina-exec-16:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684290133
> 2013-09-20 09:38:10,701 DEBUG [cloud.api.ApiServlet] (catalina-exec-16:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684290133
> 2013-09-20 09:38:13,692 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684293135
> 2013-09-20 09:38:13,709 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684293135
> 2013-09-20 09:38:13,762 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
> 2013-09-20 09:38:14,015 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
> 2013-09-20 09:38:14,227 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status.
> 2013-09-20 09:38:14,228 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> 2013-09-20 09:38:14,289 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status.
> 2013-09-20 09:38:14,290 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> 2013-09-20 09:38:16,693 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684296136
> 2013-09-20 09:38:16,711 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684296136
> 2013-09-20 09:38:19,695 DEBUG [cloud.api.ApiServlet] (catalina-exec-14:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684299139
> 2013-09-20 09:38:19,710 DEBUG [cloud.api.ApiServlet] (catalina-exec-14:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684299139
> 2013-09-20 09:38:22,101 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-284:null) Seq 1-1182466053: Executing request
> 2013-09-20 09:38:22,278 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-487:null) Seq 113-1310720005: Executing request
> 2013-09-20 09:38:22,414 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-284:null) Seq 1-1182466053: Response Received:
> 2013-09-20 09:38:22,414 DEBUG [agent.transport.Request] (DirectAgent-284:null) Seq 1-1182466053: Processing:  { Ans: , MgmtId: 110492071566, via: 1, Ver: v1, Flags: 10, [{"Answer":{"result":true,"wait":0}}] }
> 2013-09-20 09:38:22,628 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-487:null) Seq 113-1310720005: Response Received:
> 2013-09-20 09:38:22,628 DEBUG [agent.transport.Request] (DirectAgent-487:null) Seq 113-1310720005: Processing:  { Ans: , MgmtId: 110492071566, via: 113, Ver: v1, Flags: 10, [{"Answer":{"result":true,"wait":0}}] }
> 2013-09-20 09:38:22,697 DEBUG [cloud.api.ApiServlet] (catalina-exec-12:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684302141
> 2013-09-20 09:38:22,712 DEBUG [cloud.api.ApiServlet] (catalina-exec-12:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684302141
> 2013-09-20 09:38:23,166 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-86:null) Seq 112-365363205: Executing request
> 2013-09-20 09:38:23,489 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-487:null) Seq 2-1298137093: Executing request
> 2013-09-20 09:38:23,752 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-487:null) Seq 2-1298137093: Response Received:
> 2013-09-20 09:38:23,753 DEBUG [agent.transport.Request] (DirectAgent-487:null) Seq 2-1298137093: Processing:  { Ans: , MgmtId: 110492071566, via: 2, Ver: v1, Flags: 10, [{"Answer":{"result":true,"wait":0}}] }
> 2013-09-20 09:38:23,804 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-86:null) Seq 112-365363205: Response Received:
> 2013-09-20 09:38:23,805 DEBUG [agent.transport.Request] (DirectAgent-86:null) Seq 112-365363205: Processing:  { Ans: , MgmtId: 110492071566, via: 112, Ver: v1, Flags: 10, [{"Answer":{"result":true,"wait":0}}] }
> 2013-09-20 09:38:23,871 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) StorageCollector is running...
> 2013-09-20 09:38:24,155 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 110-165151534: Received:  { Ans: , MgmtId: 110492071566, via: 110, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2013-09-20 09:38:24,164 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-146:null) Seq 1-1182468804: Executing request
> 2013-09-20 09:38:25,699 DEBUG [cloud.api.ApiServlet] (catalina-exec-4:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684305143
> 2013-09-20 09:38:25,717 DEBUG [cloud.api.ApiServlet] (catalina-exec-4:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684305143
> 2013-09-20 09:38:26,059 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-322:null) Seq 3-766967813: Executing request
> 2013-09-20 09:38:26,294 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-322:null) Seq 3-766967813: Response Received:
> 2013-09-20 09:38:26,294 DEBUG [agent.transport.Request] (DirectAgent-322:null) Seq 3-766967813: Processing:  { Ans: , MgmtId: 110492071566, via: 3, Ver: v1, Flags: 10, [{"Answer":{"result":true,"wait":0}}] }
> 2013-09-20 09:38:27,999 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-146:null) GetStorageStats Exception:SR_BACKEND_FAILURE_46The VDI is not available [opterr=Error scanning VDI 50a8e81f-a556-41dd-b882-6a35693844c5]host:21870d6d-c300-4f6d-80c2-b4bedc7f1f25storageid: 2865ed4f-e8da-31f2-9353-c0abd93d8aba
> 2013-09-20 09:38:27,999 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-146:null) Seq 1-1182468804: Response Received:
> 2013-09-20 09:38:27,999 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 1-1182468804: Received:  { Ans: , MgmtId: 110492071566, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2013-09-20 09:38:28,004 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-365:null) Seq 2-1298139823: Executing request
> 2013-09-20 09:38:28,702 DEBUG [cloud.api.ApiServlet] (catalina-exec-9:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684308145
> 2013-09-20 09:38:28,729 DEBUG [cloud.api.ApiServlet] (catalina-exec-9:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684308145
> 2013-09-20 09:38:29,659 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-365:null) Seq 2-1298139823: Response Received:
> 2013-09-20 09:38:29,660 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 2-1298139823: Received:  { Ans: , MgmtId: 110492071566, via: 2, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2013-09-20 09:38:29,665 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-447:null) Seq 1-1182468805: Executing request
> 2013-09-20 09:38:29,703 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) HostStatsCollector is running...
> 2013-09-20 09:38:29,710 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-434:null) Seq 1-1182468806: Executing request
> 2013-09-20 09:38:30,463 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-434:null) Seq 1-1182468806: Response Received:
> 2013-09-20 09:38:30,464 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 1-1182468806: Received:  { Ans: , MgmtId: 110492071566, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2013-09-20 09:38:30,468 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-165:null) Seq 2-1298139824: Executing request
> 2013-09-20 09:38:31,038 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) VmStatsCollector is running...
> 2013-09-20 09:38:31,074 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-256:null) Seq 1-1182468807: Executing request
> 2013-09-20 09:38:31,160 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-165:null) Seq 2-1298139824: Response Received:
> 2013-09-20 09:38:31,160 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 2-1298139824: Received:  { Ans: , MgmtId: 110492071566, via: 2, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2013-09-20 09:38:31,167 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-94:null) Seq 3-766970552: Executing request
> 2013-09-20 09:38:31,348 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-256:null) Found 2 VMs with name: i-4-50-VM
> 2013-09-20 09:38:31,371 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-447:null) Seq 1-1182468805: Response Received:
> 2013-09-20 09:38:31,371 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 1-1182468805: Received:  { Ans: , MgmtId: 110492071566, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2013-09-20 09:38:31,376 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-64:null) Seq 3-766970553: Executing request
> 2013-09-20 09:38:31,704 DEBUG [cloud.api.ApiServlet] (catalina-exec-15:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684311147
> 2013-09-20 09:38:31,721 DEBUG [cloud.api.ApiServlet] (catalina-exec-15:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684311147
> 2013-09-20 09:38:32,067 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-94:null) Seq 3-766970552: Response Received:
> 2013-09-20 09:38:32,067 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 3-766970552: Received:  { Ans: , MgmtId: 110492071566, via: 3, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2013-09-20 09:38:32,072 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-1:null) Seq 4-1494223566: Executing request
> 2013-09-20 09:38:32,329 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-1:null) Seq 4-1494223566: Response Received:
> 2013-09-20 09:38:32,330 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 4-1494223566: Received:  { Ans: , MgmtId: 110492071566, via: 4, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2013-09-20 09:38:32,335 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-455:null) Seq 112-365365006: Executing request
> 2013-09-20 09:38:32,396 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-256:null) Vm cpu utilization 5.5
> 2013-09-20 09:38:32,396 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-256:null) Vm cpu utilization 0.0
> 2013-09-20 09:38:32,396 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-256:null) Vm cpu utilization 0.315
> 2013-09-20 09:38:32,396 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-256:null) Vm cpu utilization 0.1575
> 2013-09-20 09:38:32,396 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-256:null) Vm cpu utilization 0.6975
> 2013-09-20 09:38:32,396 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-256:null) Vm cpu utilization 0.08062500000000002
> 2013-09-20 09:38:32,397 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-256:null) Vm cpu utilization 0.27999999999999997
> 2013-09-20 09:38:32,397 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-256:null) Vm cpu utilization 0.45249999999999996
> 2013-09-20 09:38:32,397 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-256:null) Vm cpu utilization 0.20625000000000002
> 2013-09-20 09:38:32,397 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-256:null) Vm cpu utilization 1.4949999999999999
> 2013-09-20 09:38:32,397 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-256:null) Vm cpu utilization 0.73
> 2013-09-20 09:38:32,397 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-256:null) Vm cpu utilization 7.857500000000001
> 2013-09-20 09:38:32,397 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-256:null) Vm cpu utilization 0.7925
> 2013-09-20 09:38:32,397 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-256:null) Seq 1-1182468807: Response Received:
> 2013-09-20 09:38:32,397 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-1182468807: Received:  { Ans: , MgmtId: 110492071566, via: 1, Ver: v1, Flags: 10, { GetVmStatsAnswer } }
> 2013-09-20 09:38:32,424 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-258:null) Seq 2-1298139825: Executing request
> 2013-09-20 09:38:33,167 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-64:null) Seq 3-766970553: Response Received:
> 2013-09-20 09:38:33,167 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 3-766970553: Received:  { Ans: , MgmtId: 110492071566, via: 3, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2013-09-20 09:38:33,172 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-1:null) Seq 4-1494223567: Executing request
> 2013-09-20 09:38:33,219 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-258:null) Vm cpu utilization 0.5
> 2013-09-20 09:38:33,219 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-258:null) Vm cpu utilization 1.1199999999999999
> 2013-09-20 09:38:33,219 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-258:null) Vm cpu utilization 2.4
> 2013-09-20 09:38:33,219 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-258:null) Vm cpu utilization 0.30874999999999997
> 2013-09-20 09:38:33,219 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-258:null) Seq 2-1298139825: Response Received:
> 2013-09-20 09:38:33,219 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 2-1298139825: Received:  { Ans: , MgmtId: 110492071566, via: 2, Ver: v1, Flags: 10, { GetVmStatsAnswer } }
> 2013-09-20 09:38:33,250 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-163:null) Seq 3-766970554: Executing request
> 2013-09-20 09:38:33,378 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-455:null) Seq 112-365365006: Response Received:
> 2013-09-20 09:38:33,379 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 112-365365006: Received:  { Ans: , MgmtId: 110492071566, via: 112, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2013-09-20 09:38:33,383 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-344:null) Seq 113-1310721837: Executing request
> 2013-09-20 09:38:34,083 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-344:null) Seq 113-1310721837: Response Received:
> 2013-09-20 09:38:34,083 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 113-1310721837: Received:  { Ans: , MgmtId: 110492071566, via: 113, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2013-09-20 09:38:34,215 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-1:null) Seq 4-1494223567: Response Received:
> 2013-09-20 09:38:34,215 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 4-1494223567: Received:  { Ans: , MgmtId: 110492071566, via: 4, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2013-09-20 09:38:34,220 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-343:null) Seq 112-365365007: Executing request
> 2013-09-20 09:38:34,296 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-163:null) Vm cpu utilization 1.1900000000000002
> 2013-09-20 09:38:34,296 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-163:null) Vm cpu utilization 1.2025
> 2013-09-20 09:38:34,296 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-163:null) Vm cpu utilization 8.6675
> 2013-09-20 09:38:34,296 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-163:null) Vm cpu utilization 0.6725
> 2013-09-20 09:38:34,296 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-163:null) Vm cpu utilization 0.345
> 2013-09-20 09:38:34,296 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-163:null) Vm cpu utilization 1.2574999999999998
> 2013-09-20 09:38:34,296 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-163:null) Vm cpu utilization 0.14250000000000002
> 2013-09-20 09:38:34,296 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-163:null) Vm cpu utilization 0.27
> 2013-09-20 09:38:34,296 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-163:null) Vm cpu utilization 0.295
> 2013-09-20 09:38:34,296 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-163:null) Vm cpu utilization 3.8149999999999995
> 2013-09-20 09:38:34,296 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-163:null) Vm cpu utilization 0.12875
> 2013-09-20 09:38:34,296 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-163:null) Vm cpu utilization 3.8024999999999998
> 2013-09-20 09:38:34,296 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-163:null) Vm cpu utilization 0.215
> 2013-09-20 09:38:34,296 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-163:null) Vm cpu utilization 0.505
> 2013-09-20 09:38:34,296 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-163:null) Seq 3-766970554: Response Received:
> 2013-09-20 09:38:34,296 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 3-766970554: Received:  { Ans: , MgmtId: 110492071566, via: 3, Ver: v1, Flags: 10, { GetVmStatsAnswer } }
> 2013-09-20 09:38:34,331 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-379:null) Seq 4-1494223568: Executing request
> 2013-09-20 09:38:34,486 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-379:null) Found 2 VMs with name: i-5-119-VM
> 2013-09-20 09:38:34,508 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-379:null) Found 2 VMs with name: i-4-136-VM
> 2013-09-20 09:38:34,706 DEBUG [cloud.api.ApiServlet] (catalina-exec-13:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684314149
> 2013-09-20 09:38:34,721 DEBUG [cloud.api.ApiServlet] (catalina-exec-13:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684314149
> 2013-09-20 09:38:34,945 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-379:null) Vm cpu utilization 1.0999999999999999
> 2013-09-20 09:38:34,945 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-379:null) Vm cpu utilization 4.079999999999999
> 2013-09-20 09:38:34,945 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-379:null) Vm cpu utilization 3.6387499999999995
> 2013-09-20 09:38:34,945 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-379:null) Vm cpu utilization 1.145
> 2013-09-20 09:38:34,945 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-379:null) Vm cpu utilization 0.32125000000000004
> 2013-09-20 09:38:34,945 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-379:null) Vm cpu utilization 0.1925
> 2013-09-20 09:38:34,945 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-379:null) Vm cpu utilization 0.21000000000000002
> 2013-09-20 09:38:34,945 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-379:null) Vm cpu utilization 0.265
> 2013-09-20 09:38:34,945 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-379:null) Vm cpu utilization 3.3449999999999993
> 2013-09-20 09:38:34,945 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-379:null) Vm cpu utilization 12.955
> 2013-09-20 09:38:34,945 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-379:null) Vm cpu utilization 0.0
> 2013-09-20 09:38:34,945 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-379:null) Vm cpu utilization 1.354375
> 2013-09-20 09:38:34,945 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-379:null) Vm cpu utilization 0.675
> 2013-09-20 09:38:34,945 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-379:null) Vm cpu utilization 58.537499999999994
> 2013-09-20 09:38:34,945 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-379:null) Seq 4-1494223568: Response Received:
> 2013-09-20 09:38:34,946 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 4-1494223568: Received:  { Ans: , MgmtId: 110492071566, via: 4, Ver: v1, Flags: 10, { GetVmStatsAnswer } }
> 2013-09-20 09:38:35,946 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-343:null) Seq 112-365365007: Response Received:
> 2013-09-20 09:38:35,947 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 112-365365007: Received:  { Ans: , MgmtId: 110492071566, via: 112, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2013-09-20 09:38:35,950 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-277:null) Seq 113-1310721838: Executing request
> 2013-09-20 09:38:37,532 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-277:null) Seq 113-1310721838: Response Received:
> 2013-09-20 09:38:37,532 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 113-1310721838: Received:  { Ans: , MgmtId: 110492071566, via: 113, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2013-09-20 09:38:37,708 DEBUG [cloud.api.ApiServlet] (catalina-exec-21:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684317151
> 2013-09-20 09:38:37,720 DEBUG [cloud.api.ApiServlet] (catalina-exec-21:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684317151
> 2013-09-20 09:38:40,710 DEBUG [cloud.api.ApiServlet] (catalina-exec-23:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684320153
> 2013-09-20 09:38:40,722 DEBUG [cloud.api.ApiServlet] (catalina-exec-23:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684320153
> 2013-09-20 09:38:42,070 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-145:null) failed to scan sr 3bcca549-8365-35ce-8a87-17ac8768adc6
> 2013-09-20 09:38:42,070 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-145:null) Catch Exception com.cloud.utils.exception.CloudRuntimeException on host:1864865d-9b62-4a6b-b647-4881867dc729 for template: nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/4/313//e754f71a-4b34-47e0-b69d-b349a6c356d1.vhd due to com.cloud.utils.exception.CloudRuntimeException: failed to scan sr 3bcca549-8365-35ce-8a87-17ac8768adc6
> com.cloud.utils.exception.CloudRuntimeException: failed to scan sr 3bcca549-8365-35ce-8a87-17ac8768adc6
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.copy_vhd_from_secondarystorage(CitrixResourceBase.java:2707)
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:2729)
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:501)
>        at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
>        at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
>        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:1110)
>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>        at java.lang.Thread.run(Thread.java:679)
> 2013-09-20 09:38:42,070 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-145:null) Seq 112-365365005: Response Received:
> 2013-09-20 09:38:42,071 DEBUG [agent.transport.Request] (DirectAgent-145:null) Seq 112-365365005: Processing:  { Ans: , MgmtId: 110492071566, via: 112, Ver: v1, Flags: 110, [{"storage.PrimaryStorageDownloadAnswer":{"templateSize":0,"result":false,"details":"Catch Exception com.cloud.utils.exception.CloudRuntimeException on host:1864865d-9b62-4a6b-b647-4881867dc729 for template: nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/4/313//e754f71a-4b34-47e0-b69d-b349a6c356d1.vhd due to com.cloud.utils.exception.CloudRuntimeException: failed to scan sr 3bcca549-8365-35ce-8a87-17ac8768adc6","wait":0}}] }
> 2013-09-20 09:38:42,071 DEBUG [agent.transport.Request] (Job-Executor-10:job-1696) Seq 112-365365005: Received:  { Ans: , MgmtId: 110492071566, via: 112, Ver: v1, Flags: 110, { PrimaryStorageDownloadAnswer } }
> 2013-09-20 09:38:42,071 DEBUG [agent.manager.AgentAttache] (DirectAgent-145:null) Seq 112-365365005: No more commands found
> 2013-09-20 09:38:42,071 DEBUG [agent.manager.AgentManagerImpl] (Job-Executor-10:job-1696) Details from executing class com.cloud.agent.api.storage.PrimaryStorageDownloadCommand: Catch Exception com.cloud.utils.exception.CloudRuntimeException on host:1864865d-9b62-4a6b-b647-4881867dc729 for template: nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/4/313//e754f71a-4b34-47e0-b69d-b349a6c356d1.vhd due to com.cloud.utils.exception.CloudRuntimeException: failed to scan sr 3bcca549-8365-35ce-8a87-17ac8768adc6
> 2013-09-20 09:38:42,071 DEBUG [cloud.template.TemplateManagerImpl] (Job-Executor-10:job-1696) Template 313 download to pool 202 failed due to Catch Exception com.cloud.utils.exception.CloudRuntimeException on host:1864865d-9b62-4a6b-b647-4881867dc729 for template: nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/4/313//e754f71a-4b34-47e0-b69d-b349a6c356d1.vhd due to com.cloud.utils.exception.CloudRuntimeException: failed to scan sr 3bcca549-8365-35ce-8a87-17ac8768adc6
> 2013-09-20 09:38:42,071 DEBUG [cloud.template.TemplateManagerImpl] (Job-Executor-10:job-1696) Downloading 313 via 3
> 2013-09-20 09:38:42,074 DEBUG [agent.transport.Request] (Job-Executor-10:job-1696) Seq 3-766970555: Sending  { Cmd , MgmtId: 110492071566, via: 3, Ver: v1, Flags: 100111, [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/2865ed4f-e8da-31f2-9353-c0abd93d8aba","poolUuid":"2865ed4f-e8da-31f2-9353-c0abd93d8aba","poolId":202,"primaryPool":{"id":202,"uuid":"2865ed4f-e8da-31f2-9353-c0abd93d8aba","host":"10.3.34.5","path":"/iqn.2001-05.com.equallogic:0-1cb196-305b0190a-84600000019511bd-cloudstackprimary/0","port":3260,"type":"IscsiLUN"},"secondaryStorageUrl":"nfs://mgt-cld.na.manwin.local/home/secondary","primaryStorageUrl":"nfs://10.3.34.5/iqn.2001-05.com.equallogic:0-1cb196-305b0190a-84600000019511bd-cloudstackprimary/0","url":"nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/4/313//e754f71a-4b34-47e0-b69d-b349a6c356d1.vhd","format":"VHD","accountId":4,"name":"e754f71a-4b34-47e0-b69d-b349a6c356d1","wait":10800}}] }
> 2013-09-20 09:38:42,074 DEBUG [agent.transport.Request] (Job-Executor-10:job-1696) Seq 3-766970555: Executing:  { Cmd , MgmtId: 110492071566, via: 3, Ver: v1, Flags: 100111, [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/2865ed4f-e8da-31f2-9353-c0abd93d8aba","poolUuid":"2865ed4f-e8da-31f2-9353-c0abd93d8aba","poolId":202,"primaryPool":{"id":202,"uuid":"2865ed4f-e8da-31f2-9353-c0abd93d8aba","host":"10.3.34.5","path":"/iqn.2001-05.com.equallogic:0-1cb196-305b0190a-84600000019511bd-cloudstackprimary/0","port":3260,"type":"IscsiLUN"},"secondaryStorageUrl":"nfs://mgt-cld.na.manwin.local/home/secondary","primaryStorageUrl":"nfs://10.3.34.5/iqn.2001-05.com.equallogic:0-1cb196-305b0190a-84600000019511bd-cloudstackprimary/0","url":"nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/4/313//e754f71a-4b34-47e0-b69d-b349a6c356d1.vhd","format":"VHD","accountId":4,"name":"e754f71a-4b34-47e0-b69d-b349a6c356d1","wait":10800}}] }
> 2013-09-20 09:38:42,075 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-67:null) Seq 3-766970555: Executing request
> 2013-09-20 09:38:43,711 DEBUG [cloud.api.ApiServlet] (catalina-exec-19:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684323155
> 2013-09-20 09:38:43,724 DEBUG [cloud.api.ApiServlet] (catalina-exec-19:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684323155
> 2013-09-20 09:38:43,761 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
> 2013-09-20 09:38:44,008 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
> 2013-09-20 09:38:44,227 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status.
> 2013-09-20 09:38:44,228 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> 2013-09-20 09:38:44,288 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status.
> 2013-09-20 09:38:44,289 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> 2013-09-20 09:38:46,511 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-6:null) Ping from 111
> 2013-09-20 09:38:46,549 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-7:null) Ping from 110
> 2013-09-20 09:38:46,715 DEBUG [cloud.api.ApiServlet] (catalina-exec-17:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684326158
> 2013-09-20 09:38:46,727 DEBUG [cloud.api.ApiServlet] (catalina-exec-17:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684326158
> 2013-09-20 09:38:49,716 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684329159
> 2013-09-20 09:38:49,732 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684329159
> 2013-09-20 09:38:52,719 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684332162
> 2013-09-20 09:38:52,735 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684332162
> 2013-09-20 09:38:55,720 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684335163
> 2013-09-20 09:38:55,736 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684335163
> 2013-09-20 09:38:56,906 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-113:null) Ping from 4
> 2013-09-20 09:38:58,049 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-263:null) Ping from 113
> 2013-09-20 09:38:58,096 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-343:null) Ping from 112
> 2013-09-20 09:38:58,308 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-255:null) Ping from 1
> 2013-09-20 09:38:58,723 DEBUG [cloud.api.ApiServlet] (catalina-exec-20:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684338165
> 2013-09-20 09:38:58,742 DEBUG [cloud.api.ApiServlet] (catalina-exec-20:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684338165
> 2013-09-20 09:38:58,871 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-181:null) Ping from 2
> 2013-09-20 09:39:01,725 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684341167
> 2013-09-20 09:39:01,740 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684341167
> 2013-09-20 09:39:01,975 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-113:null) Ping from 3
> 2013-09-20 09:39:04,501 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-44:null) Seq 4-1494220805: Executing request
> 2013-09-20 09:39:04,727 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684344169
> 2013-09-20 09:39:04,742 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684344169
> 2013-09-20 09:39:05,716 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-44:null) Seq 4-1494220805: Response Received:
> 2013-09-20 09:39:05,716 DEBUG [agent.transport.Request] (DirectAgent-44:null) Seq 4-1494220805: Processing:  { Ans: , MgmtId: 110492071566, via: 4, Ver: v1, Flags: 10, [{"ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}] }
> 2013-09-20 09:39:07,729 DEBUG [cloud.api.ApiServlet] (catalina-exec-11:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684347172
> 2013-09-20 09:39:07,746 DEBUG [cloud.api.ApiServlet] (catalina-exec-11:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684347172
> 2013-09-20 09:39:10,730 DEBUG [cloud.api.ApiServlet] (catalina-exec-18:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684350173
> 2013-09-20 09:39:10,742 DEBUG [cloud.api.ApiServlet] (catalina-exec-18:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684350173
> 2013-09-20 09:39:13,733 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684353176
> 2013-09-20 09:39:13,748 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684353176
> 2013-09-20 09:39:13,761 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
> 2013-09-20 09:39:14,008 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
> 2013-09-20 09:39:14,227 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status.
> 2013-09-20 09:39:14,228 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> 2013-09-20 09:39:14,288 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status.
> 2013-09-20 09:39:14,289 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> 2013-09-20 09:39:15,007 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-67:null) Task failed! Task record:                 uuid: 2f8817d3-b620-4619-bf77-f44caf095cc0
>           nameLabel: Async.host.call_plugin
>     nameDescription:
>   allowedOperations: []
>   currentOperations: {}
>             created: Fri Sep 20 09:39:13 EDT 2013
>            finished: Fri Sep 20 09:39:13 EDT 2013
>              status: failure
>          residentOn: com.xensource.xenapi.Host@b6084a46
>            progress: 1.0
>                type: <none/>
>              result:
>           errorInfo: [XENAPI_PLUGIN_FAILURE, signal: SIGKILL, ]
>         otherConfig: {}
>           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
>            subtasks: []
> 
> 2013-09-20 09:39:15,119 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-67:null) callHostPlugin failed for cmd: kill_copy_process with args namelabel: e754f71a-4b34-47e0-b69d-b349a6c356d1.vhd,  due to Task failed! Task record:                 uuid: 2f8817d3-b620-4619-bf77-f44caf095cc0
>           nameLabel: Async.host.call_plugin
>     nameDescription:
>   allowedOperations: []
>   currentOperations: {}
>             created: Fri Sep 20 09:39:13 EDT 2013
>            finished: Fri Sep 20 09:39:13 EDT 2013
>              status: failure
>          residentOn: com.xensource.xenapi.Host@b6084a46
>            progress: 1.0
>                type: <none/>
>              result:
>           errorInfo: [XENAPI_PLUGIN_FAILURE, signal: SIGKILL, ]
>         otherConfig: {}
>           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
>            subtasks: []
> 
> Task failed! Task record:                 uuid: 2f8817d3-b620-4619-bf77-f44caf095cc0
>           nameLabel: Async.host.call_plugin
>     nameDescription:
>   allowedOperations: []
>   currentOperations: {}
>             created: Fri Sep 20 09:39:13 EDT 2013
>            finished: Fri Sep 20 09:39:13 EDT 2013
>              status: failure
>          residentOn: com.xensource.xenapi.Host@b6084a46
>            progress: 1.0
>                type: <none/>
>              result:
>           errorInfo: [XENAPI_PLUGIN_FAILURE, signal: SIGKILL, ]
>         otherConfig: {}
>           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
>            subtasks: []
> 
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3177)
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.callHostPluginAsync(CitrixResourceBase.java:3490)
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.killCopyProcess(CitrixResourceBase.java:2657)
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.copy_vhd_from_secondarystorage(CitrixResourceBase.java:2703)
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:2729)
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:501)
>        at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
>        at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
>        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:1110)
>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>        at java.lang.Thread.run(Thread.java:679)
> 2013-09-20 09:39:15,126 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-67:null) kill_copy_process failed
> 2013-09-20 09:39:15,127 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-67:null) failed to scan sr 3bcca549-8365-35ce-8a87-17ac8768adc6
> 2013-09-20 09:39:15,127 WARN  [xen.resource.CitrixResourceBase] (DirectAgent-67:null) Catch Exception com.cloud.utils.exception.CloudRuntimeException on host:a956ec58-a7bd-43e5-8a68-18182a3d3ade for template: nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/4/313//e754f71a-4b34-47e0-b69d-b349a6c356d1.vhd due to com.cloud.utils.exception.CloudRuntimeException: failed to scan sr 3bcca549-8365-35ce-8a87-17ac8768adc6
> com.cloud.utils.exception.CloudRuntimeException: failed to scan sr 3bcca549-8365-35ce-8a87-17ac8768adc6
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.copy_vhd_from_secondarystorage(CitrixResourceBase.java:2707)
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:2729)
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:501)
>        at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
>        at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
>        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:1110)
>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>        at java.lang.Thread.run(Thread.java:679)
> 2013-09-20 09:39:15,127 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-67:null) Seq 3-766970555: Response Received:
> 2013-09-20 09:39:15,127 DEBUG [agent.transport.Request] (DirectAgent-67:null) Seq 3-766970555: Processing:  { Ans: , MgmtId: 110492071566, via: 3, Ver: v1, Flags: 110, [{"storage.PrimaryStorageDownloadAnswer":{"templateSize":0,"result":false,"details":"Catch Exception com.cloud.utils.exception.CloudRuntimeException on host:a956ec58-a7bd-43e5-8a68-18182a3d3ade for template: nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/4/313//e754f71a-4b34-47e0-b69d-b349a6c356d1.vhd due to com.cloud.utils.exception.CloudRuntimeException: failed to scan sr 3bcca549-8365-35ce-8a87-17ac8768adc6","wait":0}}] }
> 2013-09-20 09:39:15,127 DEBUG [agent.transport.Request] (Job-Executor-10:job-1696) Seq 3-766970555: Received:  { Ans: , MgmtId: 110492071566, via: 3, Ver: v1, Flags: 110, { PrimaryStorageDownloadAnswer } }
> 2013-09-20 09:39:15,127 DEBUG [agent.manager.AgentAttache] (DirectAgent-67:null) Seq 3-766970555: No more commands found
> 2013-09-20 09:39:15,127 DEBUG [agent.manager.AgentManagerImpl] (Job-Executor-10:job-1696) Details from executing class com.cloud.agent.api.storage.PrimaryStorageDownloadCommand: Catch Exception com.cloud.utils.exception.CloudRuntimeException on host:a956ec58-a7bd-43e5-8a68-18182a3d3ade for template: nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/4/313//e754f71a-4b34-47e0-b69d-b349a6c356d1.vhd due to com.cloud.utils.exception.CloudRuntimeException: failed to scan sr 3bcca549-8365-35ce-8a87-17ac8768adc6
> 2013-09-20 09:39:15,127 DEBUG [cloud.template.TemplateManagerImpl] (Job-Executor-10:job-1696) Template 313 download to pool 202 failed due to Catch Exception com.cloud.utils.exception.CloudRuntimeException on host:a956ec58-a7bd-43e5-8a68-18182a3d3ade for template: nfs://mgt-cld.na.manwin.local/home/secondary/template/tmpl/4/313//e754f71a-4b34-47e0-b69d-b349a6c356d1.vhd due to com.cloud.utils.exception.CloudRuntimeException: failed to scan sr 3bcca549-8365-35ce-8a87-17ac8768adc6
> 2013-09-20 09:39:15,128 DEBUG [cloud.template.TemplateManagerImpl] (Job-Executor-10:job-1696) Template 313 is not found on and can not be downloaded to pool 202
> 2013-09-20 09:39:15,128 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-10:job-1696) Cannot use this pool Pool[202|IscsiLUN] because we can't propagate template Tmpl[313-VHD-e754f71a-4b34-47e0-b69d-b349a6c356d1
> 2013-09-20 09:39:15,130 INFO  [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-10:job-1696) Unable to contact resource.
> com.cloud.exception.StorageUnavailableException: Resource [StoragePool:202] is unreachable: Unable to create Vol[339|vm=278|ROOT]
>        at com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3488)
>        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:748)
>        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:471)
>        at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:212)
>        at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
>        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3871)
>        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3464)
>        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3450)
>        at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
>        at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:379)
>        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:162)
>        at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:437)
>        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:1110)
>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>        at java.lang.Thread.run(Thread.java:679)
> 2013-09-20 09:39:15,134 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-10:job-1696) Cleaning up resources for the vm VM[User|test-ub12-sep20] in Starting state
> 2013-09-20 09:39:15,135 DEBUG [agent.transport.Request] (Job-Executor-10:job-1696) Seq 2-1298139826: Sending  { Cmd , MgmtId: 110492071566, via: 2, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"i-7-278-VM","wait":0}}] }
> 2013-09-20 09:39:15,135 DEBUG [agent.transport.Request] (Job-Executor-10:job-1696) Seq 2-1298139826: Executing:  { Cmd , MgmtId: 110492071566, via: 2, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"i-7-278-VM","wait":0}}] }
> 2013-09-20 09:39:15,135 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-371:null) Seq 2-1298139826: Executing request
> 2013-09-20 09:39:15,371 INFO  [xen.resource.CitrixResourceBase] (DirectAgent-371:null) VM does not exist on XenServer197f085d-4716-47f7-b2ec-1de2b9fe6025
> 2013-09-20 09:39:15,372 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-371:null) Seq 2-1298139826: Response Received:
> 2013-09-20 09:39:15,372 DEBUG [agent.transport.Request] (DirectAgent-371:null) Seq 2-1298139826: Processing:  { Ans: , MgmtId: 110492071566, via: 2, Ver: v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"details":"VM does not exist","wait":0}}] }
> 2013-09-20 09:39:15,372 DEBUG [agent.transport.Request] (Job-Executor-10:job-1696) Seq 2-1298139826: Received:  { Ans: , MgmtId: 110492071566, via: 2, Ver: v1, Flags: 110, { StopAnswer } }
> 2013-09-20 09:39:15,372 DEBUG [agent.manager.AgentAttache] (DirectAgent-371:null) Seq 2-1298139826: No more commands found
> 2013-09-20 09:39:15,378 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-10:job-1696) Changing active number of nics for network id=204 on -1
> 2013-09-20 09:39:15,379 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-10:job-1696) Asking NiciraNvp to release Nic[347-278-6fb43b9f-cb8e-49d5-886f-724281b1b75a-10.3.34.62]
> 2013-09-20 09:39:15,379 DEBUG [network.element.NiciraNvpElement] (Job-Executor-10:job-1696) Checking if NiciraNvpElement can handle service Connectivity on network guestNetworkForBasicZone
> 2013-09-20 09:39:15,379 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-10:job-1696) Asking JuniperSRX to release Nic[347-278-6fb43b9f-cb8e-49d5-886f-724281b1b75a-10.3.34.62]
> 2013-09-20 09:39:15,379 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-10:job-1696) Asking Netscaler to release Nic[347-278-6fb43b9f-cb8e-49d5-886f-724281b1b75a-10.3.34.62]
> 2013-09-20 09:39:15,379 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-10:job-1696) Asking F5BigIP to release Nic[347-278-6fb43b9f-cb8e-49d5-886f-724281b1b75a-10.3.34.62]
> 2013-09-20 09:39:15,379 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-10:job-1696) Asking CiscoNexus1000vVSM to release Nic[347-278-6fb43b9f-cb8e-49d5-886f-724281b1b75a-10.3.34.62]
> 2013-09-20 09:39:15,380 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-10:job-1696) Asking BigSwitchVnsElement to release Nic[347-278-6fb43b9f-cb8e-49d5-886f-724281b1b75a-10.3.34.62]
> 2013-09-20 09:39:15,380 DEBUG [network.element.BigSwitchVnsElement] (Job-Executor-10:job-1696) Checking if BigSwitchVnsElement can handle service Connectivity on network guestNetworkForBasicZone
> 2013-09-20 09:39:15,380 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-10:job-1696) Asking VirtualRouter to release Nic[347-278-6fb43b9f-cb8e-49d5-886f-724281b1b75a-10.3.34.62]
> 2013-09-20 09:39:15,380 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-10:job-1696) Asking Ovs to release Nic[347-278-6fb43b9f-cb8e-49d5-886f-724281b1b75a-10.3.34.62]
> 2013-09-20 09:39:15,380 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-10:job-1696) Asking SecurityGroupProvider to release Nic[347-278-6fb43b9f-cb8e-49d5-886f-724281b1b75a-10.3.34.62]
> 2013-09-20 09:39:15,380 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-10:job-1696) Asking VpcVirtualRouter to release Nic[347-278-6fb43b9f-cb8e-49d5-886f-724281b1b75a-10.3.34.62]
> 2013-09-20 09:39:15,380 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-10:job-1696) Successfully released network resources for the vm VM[User|test-ub12-sep20]
> 2013-09-20 09:39:15,380 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-10:job-1696) Successfully cleanued up resources for the vm VM[User|test-ub12-sep20] in Starting state
> 2013-09-20 09:39:15,381 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-10:job-1696) DeploymentPlanner allocation algorithm: random
> 2013-09-20 09:39:15,381 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-10:job-1696) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu: 1000, requested ram: 1073741824
> 2013-09-20 09:39:15,381 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-10:job-1696) Is ROOT volume READY (pool already allocated)?: No
> 2013-09-20 09:39:15,381 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-10:job-1696) DeploymentPlan has host_id specified, choosing this host and making no checks on this host: 2
> 2013-09-20 09:39:15,382 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-10:job-1696) Looking for suitable pools for this host under zone: 1, pod: 1, cluster: 1
> 2013-09-20 09:39:15,383 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-10:job-1696) Checking suitable pools for volume (Id, Type): (339,ROOT)
> 2013-09-20 09:39:15,383 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-10:job-1696) We need to allocate new storagepool for this volume
> 2013-09-20 09:39:15,384 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-10:job-1696) Calling StoragePoolAllocators to find suitable pools
> 2013-09-20 09:39:15,384 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-10:job-1696) Looking for pools in dc: 1  pod:1  cluster:1
> 2013-09-20 09:39:15,385 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-10:job-1696) FirstFitStoragePoolAllocator has 7 pools to check for allocation
> 2013-09-20 09:39:15,385 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Checking if storage pool is suitable, name: xen5-cld.na.manwin.local Local Storage ,poolId: 209
> 2013-09-20 09:39:15,385 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Is localStorageAllocationNeeded? false
> 2013-09-20 09:39:15,385 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Is storage pool shared? false
> 2013-09-20 09:39:15,385 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) StoragePool is not of correct type, skipping this pool
> 2013-09-20 09:39:15,385 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Checking if storage pool is suitable, name: xen4-cld.na.manwin.local Local Storage ,poolId: 206
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Is localStorageAllocationNeeded? false
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Is storage pool shared? false
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) StoragePool is not of correct type, skipping this pool
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Checking if storage pool is suitable, name: xen2-cld.na.manwin.local Local Storage ,poolId: 207
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Is localStorageAllocationNeeded? false
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Is storage pool shared? false
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) StoragePool is not of correct type, skipping this pool
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Checking if storage pool is suitable, name: xen1-cld.na.manwin.local Local Storage ,poolId: 204
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Is localStorageAllocationNeeded? false
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Is storage pool shared? false
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) StoragePool is not of correct type, skipping this pool
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Checking if storage pool is suitable, name: xen6-cld.na.manwin.local Local Storage ,poolId: 210
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Is localStorageAllocationNeeded? false
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Is storage pool shared? false
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) StoragePool is not of correct type, skipping this pool
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Checking if storage pool is suitable, name: xen3-cld.na.manwin.local Local Storage ,poolId: 208
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Is localStorageAllocationNeeded? false
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Is storage pool shared? false
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) StoragePool is not of correct type, skipping this pool
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) Checking if storage pool is suitable, name: CloudStackPrimary ,poolId: 202
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-10:job-1696) StoragePool is in avoid set, skipping this pool
> 2013-09-20 09:39:15,386 DEBUG [storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-10:job-1696) FirstFitStoragePoolAllocator returning 0 suitable storage pools
> 2013-09-20 09:39:15,386 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-10:job-1696) No suitable pools found for volume: Vol[339|vm=278|ROOT] under cluster: 1
> 2013-09-20 09:39:15,386 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-10:job-1696) No suitable pools found
> 2013-09-20 09:39:15,386 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-10:job-1696) Cannnot deploy to specified host, returning.
> 2013-09-20 09:39:15,390 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-10:job-1696) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 2
> 2013-09-20 09:39:15,392 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-10:job-1696) Hosts's actual total CPU: 64000 and CPU after applying overprovisioning: 64000
> 2013-09-20 09:39:15,393 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-10:job-1696) release cpu from host: 2, old used: 23000,reserved: 0, actual total: 64000, total with overprovisioning: 64000; new used: 22000,reserved:0; movedfromreserved: false,moveToReserveredfalse
> 2013-09-20 09:39:15,393 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-10:job-1696) release mem from host: 2, old used: 14063501312,reserved: 0, total: 269593309440; new used: 12989759488,reserved:0; movedfromreserved: false,moveToReserveredfalse
> 2013-09-20 09:39:15,395 DEBUG [cloud.vm.UserVmManagerImpl] (Job-Executor-10:job-1696) Destroying vm VM[User|test-ub12-sep20] as it failed to create on Host with Id:null
> 2013-09-20 09:39:15,399 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-10:job-1696) VM state transitted from :Stopped to Error with event: OperationFailedToErrorvm's original host id: null new host id: null host id before state transition: null
> 2013-09-20 09:39:15,419 INFO  [user.vm.DeployVMCmd] (Job-Executor-10:job-1696) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|test-ub12-sep20]Scope=interface com.cloud.dc.DataCenter; id=1
> 2013-09-20 09:39:15,419 INFO  [user.vm.DeployVMCmd] (Job-Executor-10:job-1696) Unable to create a deployment for VM[User|test-ub12-sep20]
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|test-ub12-sep20]Scope=interface com.cloud.dc.DataCenter; id=1
>        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:728)
>        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:471)
>        at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:212)
>        at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
>        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3871)
>        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3464)
>        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3450)
>        at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
>        at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:379)
>        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:162)
>        at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:437)
>        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:1110)
>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>        at java.lang.Thread.run(Thread.java:679)
> 2013-09-20 09:39:15,419 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-10:job-1696) Complete async job-1696, jobStatus: 2, resultCode: 530, result: Error Code: 533 Error text: Unable to create a deployment for VM[User|test-ub12-sep20]
> 2013-09-20 09:39:16,736 DEBUG [cloud.api.ApiServlet] (catalina-exec-3:null) ===START===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684356178
> 2013-09-20 09:39:16,744 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-3:null) Async job-1696 completed
> 2013-09-20 09:39:16,747 DEBUG [cloud.api.ApiServlet] (catalina-exec-3:null) ===END===  10.3.12.134 -- GET  command=queryAsyncJobResult&jobId=ab142696-45ff-47df-988b-8f15601d96ff&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684356178
> 2013-09-20 09:39:16,759 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===START===  10.3.12.134 -- GET  command=listVirtualMachines&id=9ece5f74-1780-4112-b5ec-8d92ad8af021&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684356200
> 2013-09-20 09:39:16,774 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===END===  10.3.12.134 -- GET  command=listVirtualMachines&id=9ece5f74-1780-4112-b5ec-8d92ad8af021&response=json&sessionkey=Np8chP0grRArLFjBWpyrjex0MJ4%3D&projectid=84f07373-28ef-42ff-972a-1c984865ea7e&_=1379684356200
> 
> Any comments or suggests will be greatly appreciated.
> 
> Thanks,
> William
> This e-mail may be privileged and/or confidential, and the sender does not waive any related rights and obligations. Any distribution, use or copying of this e-mail or the information it contains by other than an intended recipient is unauthorized. If you received this e-mail in error, please advise me (by return e-mail or otherwise) immediately. Ce courrier électronique est confidentiel et protégé. L'expéditeur ne renonce pas aux droits et obligations qui s'y rapportent. Toute diffusion, utilisation ou copie de ce message ou des renseignements qu'il contient par une personne autre que le (les) destinataire(s) désigné(s) est interdite. Si vous recevez ce courrier électronique par erreur, veuillez m'en aviser immédiatement, par retour de courrier électronique ou par un autre moyen.


Mime
View raw message