cloudstack-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From 穆凯辉 <k...@landhightech.com>
Subject 答复: hyperv ssvm start failed
Date Wed, 26 Nov 2014 03:53:34 GMT
Hi,
	We have used the newest system vm template for hyperv
(cloudstack.apt-get.eu/systemvm/4.4/systemvm64template-4.4.1-hyperv.vhd).
But the Virtual Router is in the Status of "Starting" for a long time.
The log in Cloudstack Management is as follows:
2014-11-26 11:38:12,016 INFO  [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-102:ctx-2f394c5c) Could] not connect to 192.168.1.214 due to
java.net.NoRouteToHostException: No route to host
2014-11-26 11:38:12,689 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-8:null) SeqA 3-820: Processing Seq 3-820:  { Cmd ,
MgmtId: -1, via: 3, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_load
Info":"{\n  \"connections\": []\n}","wait":0}}] }
2014-11-26 11:38:12,693 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-8:null) SeqA 3-820: Sending Seq 3-820:  { Ans: ,
MgmtId: 52237247174, via: 3, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.
AgentControlAnswer":{"result":true,"wait":0}}] }
2014-11-26 11:38:13,016 INFO  [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-102:ctx-2f394c5c) Trying to connect to 192.168.1.214
2014-11-26 11:38:13,412 INFO  [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-50:ctx-0e4289a9) Trying to connect to 192.168.1.212
2014-11-26 11:38:13,413 INFO  [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-50:ctx-0e4289a9) Could] not connect to 192.168.1.212 due to
java.net.ConnectException: Connection refused
2014-11-26 11:38:15,017 INFO  [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-102:ctx-2f394c5c) Could] not connect to 192.168.1.214 due to
java.net.NoRouteToHostException: No route to host
2014-11-26 11:38:16,017 INFO  [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-102:ctx-2f394c5c) Trying to connect to 192.168.1.214


But I ping the public and management network ip of this virtual Router
successfully:
 [root@cloudstack-management4 ~]# ping 12.1.1.102
PING 12.1.1.102 (12.1.1.102) 56(84) bytes of data.
64 bytes from 12.1.1.102: icmp_seq=1 ttl=64 time=71.9 ms
64 bytes from 12.1.1.102: icmp_seq=2 ttl=64 time=0.585 ms
64 bytes from 12.1.1.102: icmp_seq=3 ttl=64 time=0.597 ms
^C
--- 12.1.1.102 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2216ms
rtt min/avg/max/mdev = 0.585/24.383/71.969/33.648 ms
[root@cloudstack-management4 ~]# ping 192.168.1.212
PING 192.168.1.212 (192.168.1.212) 56(84) bytes of data.
64 bytes from 192.168.1.212: icmp_seq=1 ttl=128 time=0.609 ms
64 bytes from 192.168.1.212: icmp_seq=2 ttl=128 time=0.643 ms
64 bytes from 192.168.1.212: icmp_seq=3 ttl=128 time=0.622 ms
^C
--- 192.168.1.212 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2229ms
rtt min/avg/max/mdev = 0.609/0.624/0.643/0.032 ms



khmu
-----邮件原件-----
发件人: Anshul Gangwar [mailto:anshul.gangwar@citrix.com] 
发送时间: 2014年11月24日 13:08
收件人: dev@cloudstack.apache.org
主题: RE: hyperv ssvm start failed

You have to upgrade your system vm template.

If you want to move ahead with current setup and play around then you can
disable router version check by setting 
Configuration router.version.check to false.

You can find latest templates at http://cloudstack.apt-get.eu/systemvm/4.4/.

For upgrade instructions look at mix of these documents
http://cloudstack-release-notes.readthedocs.org/en/latest/upgrade/upgrade-4.
3.html
http://quia.cf/orange/pooxy4/nph-poxy.pl/ar/20/http/cloudstack-release-notes
.readthedocs.org/en/latest/upgrade/upgrade-4.4.html
http://support.citrix.com/article/CTX200024



-----Original Message-----
From: 穆凯辉 [mailto:khmu@landhightech.com] 
Sent: Saturday, November 22, 2014 10:43 AM
To: dev@cloudstack.apache.org
Subject: 答复: hyperv ssvm start failed

Hi,
	We have changed to advanced network to configure cloudstack 4.4.1 +
hyperv. 
	Now, the ssvm and cpvm have started successfully. The states shown
in Dashboard are all OK!
	But when we create an instance using win8 ISO, the log in cloudstack
said: Unable to find work for VM: VM[DomainRouter|r-4-VM] and state:
Starting. But in the Hyperv host, this vm is started.
In Infrastructure, this virtual routers is in starting status. The details
information about r-4-vm is as follows:
Name	r-4-VM
ID	3b40b1bb-f05b-4d0b-a0e0-48ebc146ea03
State	Starting
Version	UNKNOWN
Requires Upgrade	Yes
Network ID	a9a5f27a-4993-4472-bccc-46a0a79b6f05
Public IP Address	10.3.101.12
Guest IP Address	10.1.1.1
Link Local IP Address	
Host	192.168.1.78
Compute offering	System Offering For Software Router
Network Domain	cloud.priv
Domain	ROOT
Account	admin
Created	21 Nov 2014 19:42:35
Redundant Router	No
Redundant state	
VPC ID


The Nics information is as follows:
NIC 1
Type	Isolated
Traffic Type	Guest
Network Name	test
Netmask	255.255.255.0
IP Address	10.1.1.1
ID	dbc2c510-4c22-4f89-a4a3-7be972845012
Network ID	a9a5f27a-4993-4472-bccc-46a0a79b6f05
Isolation URI	
Broadcast URI	

NIC 2
Type	
Traffic Type	Control
Network Name	
Netmask	
IP Address	
ID	f75198a0-93b8-4b6b-81f2-f4bcbfb3bcf0
Network ID	5b5bf9af-0e24-46ff-83cc-dec0bc224085
Isolation URI	
Broadcast URI	

NIC 3 (Default)
Type	
Traffic Type	Public
Network Name	
Netmask	255.255.0.0
IP Address	10.3.101.12
ID	01ded894-91c5-430a-8bd0-6318e5a4fff0
Network ID	b8b10cde-6728-4ac6-bf6a-066a0d4ac541
Isolation URI	vlan://26
Broadcast URI	vlan://26

The logs in Hyperv server are as follows:
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:36:06","2014/11/23 4:36:06",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41315","(0)","0","Informati
on","2014-11-22 12:36:06,857 [11] DEBUG
HypervResource.HypervResourceController
[acd479e8-0af5-47d9-a62c-7d0355f56341] -
com.cloud.agent.api.GetStorageStatsCommand set used bytes for
\\192.168.1.79\WINPrimary to 42745344000
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:36:06","2014/11/23 4:36:06",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41314","(0)","0","Informati
on","2014-11-22 12:36:06,764 [11] INFO
HypervResource.HypervResourceController
[acd479e8-0af5-47d9-a62c-7d0355f56341] -
com.cloud.agent.api.GetStorageStatsCommand{
  ""id"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
  ""localPath"": ""/WINPrimary?user=cloudstackadmin&domain=cloud"",
  ""pooltype"": ""SMB"",
  ""contextMap"": {},
  ""wait"": 0
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:36:06","2014/11/23 4:36:06",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41313","(0)","0","Informati
on","2014-11-22 12:35:51,279 [11] INFO
HypervResource.HypervResourceController
[73e94316-3648-4670-9bcb-ff75c95906dd] - {
  ""com.cloud.agent.api.CheckHealthAnswer"": {
    ""result"": true,
    ""details"": ""resource is alive"",
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:35:51","2014/11/23 4:35:51",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41312","(0)","0","Informati
on","2014-11-22 12:35:51,279 [11] INFO
HypervResource.HypervResourceController
[73e94316-3648-4670-9bcb-ff75c95906dd] -
com.cloud.agent.api.CheckHealthCommand{
  ""contextMap"": {},
  ""wait"": 50
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:35:51","2014/11/23 4:35:51",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41311","(0)","0","Informati
on","2014-11-22 12:35:40,243 [11] INFO
HypervResource.HypervResourceController
[a7952b4a-0659-40ad-af46-3a7ab5e56a8d] - {
  ""com.cloud.agent.api.GetHostStatsAnswer"": {
    ""result"": true,
    ""hostStats"": {
      ""hostId"": 1,
      ""entityType"": ""host"",
      ""cpuUtilization"": 1.0,
      ""networkReadKBs"": 1215479482.0,
      ""networkWriteKBs"": 19449823345.0,
      ""totalMemoryKBs"": 134138344.0,
      ""freeMemoryKBs"": 125803152.0
    },
    ""details"": null,
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:35:40","2014/11/23 4:35:40",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41310","(0)","0","Informati
on","2014-11-22 12:35:39,868 [11] INFO
HypervResource.HypervResourceController
[a7952b4a-0659-40ad-af46-3a7ab5e56a8d] -
com.cloud.agent.api.GetHostStatsCommand{
  ""hostGuid"": ""3be2f4fe-f3c7-33c1-8127-696c45258534-HypervResource"",
  ""hostName"": ""192.168.1.78"",
  ""hostId"": 1,
  ""contextMap"": {},
  ""wait"": 0
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:35:39","2014/11/23 4:35:39",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41309","(0)","0","Informati
on","2014-11-22 12:35:06,120 [11] INFO
HypervResource.HypervResourceController
[3de03305-d8f2-405a-b464-6368023a5463] - {
  ""com.cloud.agent.api.GetStorageStatsAnswer"": {
    ""result"": true,
    ""details"": null,
    ""capacity"": 149954752512,
    ""used"": 42745344000,
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:35:06","2014/11/23 4:35:06",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41308","(0)","0","Informati
on","2014-11-22 12:35:06,120 [11] DEBUG
HypervResource.HypervResourceController
[3de03305-d8f2-405a-b464-6368023a5463] -
com.cloud.agent.api.GetStorageStatsCommand set used bytes for
\\192.168.1.79\WINPrimary to 42745344000
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:35:06","2014/11/23 4:35:06",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41307","(0)","0","Informati
on","2014-11-22 12:35:06,026 [11] INFO
HypervResource.HypervResourceController
[3de03305-d8f2-405a-b464-6368023a5463] -
com.cloud.agent.api.GetStorageStatsCommand{
  ""id"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
  ""localPath"": ""/WINPrimary?user=cloudstackadmin&domain=cloud"",
  ""pooltype"": ""SMB"",
  ""contextMap"": {},
  ""wait"": 0
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:35:06","2014/11/23 4:35:06",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41306","(0)","0","Informati
on","2014-11-22 12:34:51,269 [11] INFO
HypervResource.HypervResourceController
[48d02c33-b8eb-4f8b-962b-c8e39d65f9f8] - {
  ""com.cloud.agent.api.CheckHealthAnswer"": {
    ""result"": true,
    ""details"": ""resource is alive"",
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:34:51","2014/11/23 4:34:51",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41305","(0)","0","Informati
on","2014-11-22 12:34:51,269 [11] INFO
HypervResource.HypervResourceController
[48d02c33-b8eb-4f8b-962b-c8e39d65f9f8] -
com.cloud.agent.api.CheckHealthCommand{
  ""contextMap"": {},
  ""wait"": 50
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:34:51","2014/11/23 4:34:51",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41304","(0)","0","Informati
on","2014-11-22 12:34:39,764 [11] INFO
HypervResource.HypervResourceController
[b5f5ee69-f4a2-42dd-a214-b10175640d72] - {
  ""com.cloud.agent.api.GetHostStatsAnswer"": {
    ""result"": true,
    ""hostStats"": {
      ""hostId"": 1,
      ""entityType"": ""host"",
      ""cpuUtilization"": 1.0,
      ""networkReadKBs"": 1214833283.0,
      ""networkWriteKBs"": 19433893723.0,
      ""totalMemoryKBs"": 134138344.0,
      ""freeMemoryKBs"": 125803168.0
    },
    ""details"": null,
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:34:39","2014/11/23 4:34:39",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41303","(0)","0","Informati
on","2014-11-22 12:34:39,389 [11] INFO
HypervResource.HypervResourceController
[b5f5ee69-f4a2-42dd-a214-b10175640d72] -
com.cloud.agent.api.GetHostStatsCommand{
  ""hostGuid"": ""3be2f4fe-f3c7-33c1-8127-696c45258534-HypervResource"",
  ""hostName"": ""192.168.1.78"",
  ""hostId"": 1,
  ""contextMap"": {},
  ""wait"": 0
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:34:39","2014/11/23 4:34:39",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41302","(0)","0","Informati
on","2014-11-22 12:34:05,561 [11] INFO
HypervResource.HypervResourceController
[9aebebaf-6499-443d-8a50-6b04f9ef1b28] - {
  ""com.cloud.agent.api.GetStorageStatsAnswer"": {
    ""result"": true,
    ""details"": null,
    ""capacity"": 149954752512,
    ""used"": 42745344000,
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:34:05","2014/11/23 4:34:05",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41301","(0)","0","Informati
on","2014-11-22 12:34:05,561 [11] DEBUG
HypervResource.HypervResourceController
[9aebebaf-6499-443d-8a50-6b04f9ef1b28] -
com.cloud.agent.api.GetStorageStatsCommand set used bytes for
\\192.168.1.79\WINPrimary to 42745344000
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:34:05","2014/11/23 4:34:05",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41300","(0)","0","Informati
on","2014-11-22 12:34:05,467 [11] INFO
HypervResource.HypervResourceController
[9aebebaf-6499-443d-8a50-6b04f9ef1b28] -
com.cloud.agent.api.GetStorageStatsCommand{
  ""id"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
  ""localPath"": ""/WINPrimary?user=cloudstackadmin&domain=cloud"",
  ""pooltype"": ""SMB"",
  ""contextMap"": {},
  ""wait"": 0
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:34:05","2014/11/23 4:34:05",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41299","(0)","0","Informati
on","2014-11-22 12:33:51,261 [11] INFO
HypervResource.HypervResourceController
[2da51245-0957-4174-9efa-4d7e84c65e10] - {
  ""com.cloud.agent.api.CheckHealthAnswer"": {
    ""result"": true,
    ""details"": ""resource is alive"",
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:33:51","2014/11/23 4:33:51",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41298","(0)","0","Informati
on","2014-11-22 12:33:51,261 [11] INFO
HypervResource.HypervResourceController
[2da51245-0957-4174-9efa-4d7e84c65e10] -
com.cloud.agent.api.CheckHealthCommand{
  ""contextMap"": {},
  ""wait"": 50
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:33:51","2014/11/23 4:33:51",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41297","(0)","0","Informati
on","2014-11-22 12:33:39,287 [11] INFO
HypervResource.HypervResourceController
[8ae4f05c-a81b-4226-86ce-336441f93f06] - {
  ""com.cloud.agent.api.GetHostStatsAnswer"": {
    ""result"": true,
    ""hostStats"": {
      ""hostId"": 1,
      ""entityType"": ""host"",
      ""cpuUtilization"": 1.0,
      ""networkReadKBs"": 1214213222.0,
      ""networkWriteKBs"": 19418247822.0,
      ""totalMemoryKBs"": 134138344.0,
      ""freeMemoryKBs"": 125803160.0
    },
    ""details"": null,
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:33:39","2014/11/23 4:33:39",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41296","(0)","0","Informati
on","2014-11-22 12:33:38,912 [11] INFO
HypervResource.HypervResourceController
[8ae4f05c-a81b-4226-86ce-336441f93f06] -
com.cloud.agent.api.GetHostStatsCommand{
  ""hostGuid"": ""3be2f4fe-f3c7-33c1-8127-696c45258534-HypervResource"",
  ""hostName"": ""192.168.1.78"",
  ""hostId"": 1,
  ""contextMap"": {},
  ""wait"": 0
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:33:38","2014/11/23 4:33:38",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41295","(0)","0","Informati
on","2014-11-22 12:33:04,706 [11] INFO
HypervResource.HypervResourceController
[c5fccab0-50bf-4653-bace-24d82817bc32] - {
  ""com.cloud.agent.api.GetStorageStatsAnswer"": {
    ""result"": true,
    ""details"": null,
    ""capacity"": 149954752512,
    ""used"": 42745344000,
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:33:04","2014/11/23 4:33:04",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41294","(0)","0","Informati
on","2014-11-22 12:33:04,706 [11] DEBUG
HypervResource.HypervResourceController
[c5fccab0-50bf-4653-bace-24d82817bc32] -
com.cloud.agent.api.GetStorageStatsCommand set used bytes for
\\192.168.1.79\WINPrimary to 42745344000
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:33:04","2014/11/23 4:33:04",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41293","(0)","0","Informati
on","2014-11-22 12:33:04,628 [11] INFO
HypervResource.HypervResourceController
[c5fccab0-50bf-4653-bace-24d82817bc32] -
com.cloud.agent.api.GetStorageStatsCommand{
  ""id"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
  ""localPath"": ""/WINPrimary?user=cloudstackadmin&domain=cloud"",
  ""pooltype"": ""SMB"",
  ""contextMap"": {},
  ""wait"": 0
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:33:04","2014/11/23 4:33:04",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41292","(0)","0","Informati
on","2014-11-22 12:32:51,250 [11] INFO
HypervResource.HypervResourceController
[94497c61-024f-46a7-b421-fdd87f3d7cd3] - {
  ""com.cloud.agent.api.CheckHealthAnswer"": {
    ""result"": true,
    ""details"": ""resource is alive"",
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:32:51","2014/11/23 4:32:51",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41291","(0)","0","Informati
on","2014-11-22 12:32:51,250 [11] INFO
HypervResource.HypervResourceController
[94497c61-024f-46a7-b421-fdd87f3d7cd3] -
com.cloud.agent.api.CheckHealthCommand{
  ""contextMap"": {},
  ""wait"": 50
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:32:51","2014/11/23 4:32:51",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41290","(0)","0","Informati
on","2014-11-22 12:32:38,812 [11] INFO
HypervResource.HypervResourceController
[652e4ec7-a6ad-413b-8eeb-b71a71701c36] - {
  ""com.cloud.agent.api.GetHostStatsAnswer"": {
    ""result"": true,
    ""hostStats"": {
      ""hostId"": 1,
      ""entityType"": ""host"",
      ""cpuUtilization"": 1.0,
      ""networkReadKBs"": 1213585829.0,
      ""networkWriteKBs"": 19402599386.0,
      ""totalMemoryKBs"": 134138344.0,
      ""freeMemoryKBs"": 125802784.0
    },
    ""details"": null,
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:32:38","2014/11/23 4:32:38",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41289","(0)","0","Informati
on","2014-11-22 12:32:38,437 [11] INFO
HypervResource.HypervResourceController
[652e4ec7-a6ad-413b-8eeb-b71a71701c36] -
com.cloud.agent.api.GetHostStatsCommand{
  ""hostGuid"": ""3be2f4fe-f3c7-33c1-8127-696c45258534-HypervResource"",
  ""hostName"": ""192.168.1.78"",
  ""hostId"": 1,
  ""contextMap"": {},
  ""wait"": 0
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:32:38","2014/11/23 4:32:38",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41288","(0)","0","Informati
on","2014-11-22 12:32:04,231 [11] INFO
HypervResource.HypervResourceController
[3cfd5276-ff2c-4768-80f0-332086eff37a] - {
  ""com.cloud.agent.api.GetStorageStatsAnswer"": {
    ""result"": true,
    ""details"": null,
    ""capacity"": 149954752512,
    ""used"": 42745344000,
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:32:04","2014/11/23 4:32:04",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41287","(0)","0","Informati
on","2014-11-22 12:32:04,231 [11] DEBUG
HypervResource.HypervResourceController
[3cfd5276-ff2c-4768-80f0-332086eff37a] -
com.cloud.agent.api.GetStorageStatsCommand set used bytes for
\\192.168.1.79\WINPrimary to 42745344000
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:32:04","2014/11/23 4:32:04",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41286","(0)","0","Informati
on","2014-11-22 12:32:04,137 [11] INFO
HypervResource.HypervResourceController
[3cfd5276-ff2c-4768-80f0-332086eff37a] -
com.cloud.agent.api.GetStorageStatsCommand{
  ""id"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
  ""localPath"": ""/WINPrimary?user=cloudstackadmin&domain=cloud"",
  ""pooltype"": ""SMB"",
  ""contextMap"": {},
  ""wait"": 0
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:32:04","2014/11/23 4:32:04",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41285","(0)","0","Informati
on","2014-11-22 12:31:51,243 [11] INFO
HypervResource.HypervResourceController
[a7c9bee2-057b-403a-a4bf-4a88b26ee765] - {
  ""com.cloud.agent.api.CheckHealthAnswer"": {
    ""result"": true,
    ""details"": ""resource is alive"",
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:31:51","2014/11/23 4:31:51",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41284","(0)","0","Informati
on","2014-11-22 12:31:51,243 [11] INFO
HypervResource.HypervResourceController
[a7c9bee2-057b-403a-a4bf-4a88b26ee765] -
com.cloud.agent.api.CheckHealthCommand{
  ""contextMap"": {},
  ""wait"": 50
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:31:51","2014/11/23 4:31:51",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41283","(0)","0","Informati
on","2014-11-22 12:31:38,345 [11] INFO
HypervResource.HypervResourceController
[b9b8a2ce-d52a-4e89-ad19-45547083789d] - {
  ""com.cloud.agent.api.GetHostStatsAnswer"": {
    ""result"": true,
    ""hostStats"": {
      ""hostId"": 1,
      ""entityType"": ""host"",
      ""cpuUtilization"": 1.0,
      ""networkReadKBs"": 1212942602.0,
      ""networkWriteKBs"": 19386718504.0,
      ""totalMemoryKBs"": 134138344.0,
      ""freeMemoryKBs"": 125801972.0
    },
    ""details"": null,
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:31:38","2014/11/23 4:31:38",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41282","(0)","0","Informati
on","2014-11-22 12:31:37,970 [11] INFO
HypervResource.HypervResourceController
[b9b8a2ce-d52a-4e89-ad19-45547083789d] -
com.cloud.agent.api.GetHostStatsCommand{
  ""hostGuid"": ""3be2f4fe-f3c7-33c1-8127-696c45258534-HypervResource"",
  ""hostName"": ""192.168.1.78"",
  ""hostId"": 1,
  ""contextMap"": {},
  ""wait"": 0
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:31:37","2014/11/23 4:31:37",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41281","(0)","0","Informati
on","2014-11-22 12:31:03,610 [11] INFO
HypervResource.HypervResourceController
[c4c194b0-5530-4f1c-ab1d-2319ead46c45] - {
  ""com.cloud.agent.api.GetStorageStatsAnswer"": {
    ""result"": true,
    ""details"": null,
    ""capacity"": 149954752512,
    ""used"": 42745339904,
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:31:03","2014/11/23 4:31:03",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41280","(0)","0","Informati
on","2014-11-22 12:31:03,610 [11] DEBUG
HypervResource.HypervResourceController
[c4c194b0-5530-4f1c-ab1d-2319ead46c45] -
com.cloud.agent.api.GetStorageStatsCommand set used bytes for
\\192.168.1.79\WINPrimary to 42745339904
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:31:03","2014/11/23 4:31:03",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41279","(0)","0","Informati
on","2014-11-22 12:31:03,532 [11] INFO
HypervResource.HypervResourceController
[c4c194b0-5530-4f1c-ab1d-2319ead46c45] -
com.cloud.agent.api.GetStorageStatsCommand{
  ""id"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
  ""localPath"": ""/WINPrimary?user=cloudstackadmin&domain=cloud"",
  ""pooltype"": ""SMB"",
  ""contextMap"": {},
  ""wait"": 0
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:31:03","2014/11/23 4:31:03",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41278","(0)","0","Informati
on","2014-11-22 12:30:51,239 [11] INFO
HypervResource.HypervResourceController
[0f67523d-1f6b-423d-9cf3-ac71ef518b3e] - {
  ""com.cloud.agent.api.CheckHealthAnswer"": {
    ""result"": true,
    ""details"": ""resource is alive"",
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:30:51","2014/11/23 4:30:51",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41277","(0)","0","Informati
on","2014-11-22 12:30:51,239 [11] INFO
HypervResource.HypervResourceController
[0f67523d-1f6b-423d-9cf3-ac71ef518b3e] -
com.cloud.agent.api.CheckHealthCommand{
  ""contextMap"": {},
  ""wait"": 50
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:30:51","2014/11/23 4:30:51",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41276","(0)","0","Informati
on","2014-11-22 12:30:37,874 [11] INFO
HypervResource.HypervResourceController
[a24e7d27-f2ff-4f5f-a6bd-71bacaedc029] - {
  ""com.cloud.agent.api.GetHostStatsAnswer"": {
    ""result"": true,
    ""hostStats"": {
      ""hostId"": 1,
      ""entityType"": ""host"",
      ""cpuUtilization"": 1.0,
      ""networkReadKBs"": 1212316530.0,
      ""networkWriteKBs"": 19371081793.0,
      ""totalMemoryKBs"": 134138344.0,
      ""freeMemoryKBs"": 125801752.0
    },
    ""details"": null,
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:30:37","2014/11/23 4:30:37",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41275","(0)","0","Informati
on","2014-11-22 12:30:37,499 [11] INFO
HypervResource.HypervResourceController
[a24e7d27-f2ff-4f5f-a6bd-71bacaedc029] -
com.cloud.agent.api.GetHostStatsCommand{
  ""hostGuid"": ""3be2f4fe-f3c7-33c1-8127-696c45258534-HypervResource"",
  ""hostName"": ""192.168.1.78"",
  ""hostId"": 1,
  ""contextMap"": {},
  ""wait"": 0
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:30:37","2014/11/23 4:30:37",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41274","(0)","0","Informati
on","2014-11-22 12:30:02,968 [11] INFO
HypervResource.HypervResourceController
[bfd060ef-5b32-4349-917a-93890358cd99] - {
  ""com.cloud.agent.api.GetStorageStatsAnswer"": {
    ""result"": true,
    ""details"": null,
    ""capacity"": 149954752512,
    ""used"": 42745335808,
    ""contextMap"": {}
  }
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:30:02","2014/11/23 4:30:02",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41273","(0)","0","Informati
on","2014-11-22 12:30:02,968 [11] DEBUG
HypervResource.HypervResourceController
[bfd060ef-5b32-4349-917a-93890358cd99] -
com.cloud.agent.api.GetStorageStatsCommand set used bytes for
\\192.168.1.79\WINPrimary to 42745335808
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:30:02","2014/11/23 4:30:02",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41272","(0)","0","Informati
on","2014-11-22 12:30:02,890 [11] INFO
HypervResource.HypervResourceController
[bfd060ef-5b32-4349-917a-93890358cd99] -
com.cloud.agent.api.GetStorageStatsCommand{
  ""id"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
  ""localPath"": ""/WINPrimary?user=cloudstackadmin&domain=cloud"",
  ""pooltype"": ""SMB"",
  ""contextMap"": {},
  ""wait"": 0
}
","CloudStack Hyper-V Agent","System.String[]","0","2014/11/23
4:30:02","2014/11/23 4:30:02",,,
"0","hyperv-server1.cloud.priv","System.Byte[]","41196","(0)","0","Informati
on","2014-11-22 12:19:57,102 [11] INFO
HypervResource.HypervResourceController
[77e9a30b-938e-4ae6-aafd-95e2dfe7f1e5] - {
  ""com.cloud.agent.api.GetStorageStatsAnswer"": {
    ""result"": true,
    ""details"": null,
    ""capacity"": 149954752512,
    ""used"": 42745331712,
    ""contextMap"": {}
  }
}

The logs in Cloudstack management are as follows:
2014-11-22 12:26:23,376 DEBUG [c.c.a.ApiServlet]
(catalina-exec-5:ctx-e09ae67d) ===START===  192.168.255.102 -- GET
command=deployVirtualMachine&response=json&sessionkey=VSlFCdNLXjxVW%2BYdDS5r
5q7NMhY%3D&zoneid=5755b5f8-d914-4ced-8e8b-06be8beda4bb&templateid=46bc4921-3
b95-4688-85f1-7b8ab879a781&hypervisor=Hyperv&serviceofferingid=45952a89-e640
-47d3-ac08-5ee0153cf816&diskofferingid=a1cd5943-2436-4057-a88e-1fed271e22e5&
iptonetworklist%5B0%5D.networkid=a9a5f27a-4993-4472-bccc-46a0a79b6f05&displa
yname=win7test1&name=win7test1&_=1416630399370
2014-11-22 12:26:23,493 DEBUG [c.c.n.NetworkModelImpl]
(catalina-exec-5:ctx-e09ae67d ctx-b8614512) Service SecurityGroup is not
supported in the network id=204
2014-11-22 12:26:23,509 DEBUG [c.c.v.UserVmManagerImpl]
(catalina-exec-5:ctx-e09ae67d ctx-b8614512) Allocating in the DB for vm
2014-11-22 12:26:23,525 DEBUG [c.c.v.VirtualMachineManagerImpl]
(catalina-exec-5:ctx-e09ae67d ctx-b8614512) Allocating entries for VM:
VM[User|i-2-12-VM]
2014-11-22 12:26:23,526 DEBUG [c.c.v.VirtualMachineManagerImpl]
(catalina-exec-5:ctx-e09ae67d ctx-b8614512) Allocating nics for
VM[User|i-2-12-VM]
2014-11-22 12:26:23,527 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(catalina-exec-5:ctx-e09ae67d ctx-b8614512) Allocating nic for vm
VM[User|i-2-12-VM] in network
Ntwk[a9a5f27a-4993-4472-bccc-46a0a79b6f05|Guest|8] with requested profile
NicProfile[0-0-null-null-null
2014-11-22 12:26:23,544 DEBUG [c.c.n.NetworkModelImpl]
(catalina-exec-5:ctx-e09ae67d ctx-b8614512) Service SecurityGroup is not
supported in the network id=204
2014-11-22 12:26:23,546 DEBUG [c.c.v.VirtualMachineManagerImpl]
(catalina-exec-5:ctx-e09ae67d ctx-b8614512) Allocating disks for
VM[User|i-2-12-VM]
2014-11-22 12:26:23,562 DEBUG [c.c.v.VirtualMachineManagerImpl]
(catalina-exec-5:ctx-e09ae67d ctx-b8614512) Allocation completed for VM:
VM[User|i-2-12-VM]
2014-11-22 12:26:23,562 DEBUG [c.c.v.UserVmManagerImpl]
(catalina-exec-5:ctx-e09ae67d ctx-b8614512) Successfully allocated DB entry
for VM[User|i-2-12-VM]
2014-11-22 12:26:23,590 DEBUG [c.c.n.NetworkModelImpl]
(catalina-exec-5:ctx-e09ae67d ctx-b8614512) Service SecurityGroup is not
supported in the network id=204
2014-11-22 12:26:23,595 DEBUG [c.c.n.NetworkModelImpl]
(catalina-exec-5:ctx-e09ae67d ctx-b8614512) Service SecurityGroup is not
supported in the network id=204
2014-11-22 12:26:23,611 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(catalina-exec-5:ctx-e09ae67d ctx-b8614512) submit async job-122, details:
AsyncJobVO {id:122, userId: 2, accountId: 2, instanceType: VirtualMachine,
instanceId: 12, cmd:
org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin, cmdInfo:
{"sessionkey":"VSlFCdNLXjxVW+YdDS5r5q7NMhY\u003d","serviceofferingid":"45952
a89-e640-47d3-ac08-5ee0153cf816","cmdEventType":"VM.CREATE","ctxUserId":"2",
"zoneid":"5755b5f8-d914-4ced-8e8b-06be8beda4bb","httpmethod":"GET","template
id":"46bc4921-3b95-4688-85f1-7b8ab879a781","id":"12","response":"json","ctxD
etails":"{\"com.cloud.template.VirtualMachineTemplate\":\"46bc4921-3b95-4688
-85f1-7b8ab879a781\",\"com.cloud.vm.VirtualMachine\":\"a3a0f55a-5385-4b40-bf
4d-0819211ff3e7\",\"com.cloud.offering.DiskOffering\":\"a1cd5943-2436-4057-a
88e-1fed271e22e5\",\"com.cloud.dc.DataCenter\":\"5755b5f8-d914-4ced-8e8b-06b
e8beda4bb\",\"com.cloud.offering.ServiceOffering\":\"45952a89-e640-47d3-ac08
-5ee0153cf816\"}","hypervisor":"Hyperv","iptonetworklist[0].networkid":"a9a5
f27a-4993-4472-bccc-46a0a79b6f05","name":"win7test1","_":"1416630399370","uu
id":"a3a0f55a-5385-4b40-bf4d-0819211ff3e7","ctxAccountId":"2","diskofferingi
d":"a1cd5943-2436-4057-a88e-1fed271e22e5","ctxStartEventId":"240","displayna
me":"win7test1"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0,
resultCode: 0, result: null, initMsid: 52237247174, completeMsid: null,
lastUpdated: null, lastPolled: null, created: null}
2014-11-22 12:26:23,613 DEBUG [c.c.a.ApiServlet]
(catalina-exec-5:ctx-e09ae67d ctx-b8614512) ===END===  192.168.255.102 --
GET
command=deployVirtualMachine&response=json&sessionkey=VSlFCdNLXjxVW%2BYdDS5r
5q7NMhY%3D&zoneid=5755b5f8-d914-4ced-8e8b-06be8beda4bb&templateid=46bc4921-3
b95-4688-85f1-7b8ab879a781&hypervisor=Hyperv&serviceofferingid=45952a89-e640
-47d3-ac08-5ee0153cf816&diskofferingid=a1cd5943-2436-4057-a88e-1fed271e22e5&
iptonetworklist%5B0%5D.networkid=a9a5f27a-4993-4472-bccc-46a0a79b6f05&displa
yname=win7test1&name=win7test1&_=1416630399370
2014-11-22 12:26:23,616 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-9:ctx-4ac29706 job-122) Add job-122 into job monitoring
2014-11-22 12:26:23,616 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122) Executing AsyncJobVO {id:122,
userId: 2, accountId: 2, instanceType: VirtualMachine, instanceId: 12, cmd:
org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin, cmdInfo:
{"sessionkey":"VSlFCdNLXjxVW+YdDS5r5q7NMhY\u003d","serviceofferingid":"45952
a89-e640-47d3-ac08-5ee0153cf816","cmdEventType":"VM.CREATE","ctxUserId":"2",
"zoneid":"5755b5f8-d914-4ced-8e8b-06be8beda4bb","httpmethod":"GET","template
id":"46bc4921-3b95-4688-85f1-7b8ab879a781","id":"12","response":"json","ctxD
etails":"{\"com.cloud.template.VirtualMachineTemplate\":\"46bc4921-3b95-4688
-85f1-7b8ab879a781\",\"com.cloud.vm.VirtualMachine\":\"a3a0f55a-5385-4b40-bf
4d-0819211ff3e7\",\"com.cloud.offering.DiskOffering\":\"a1cd5943-2436-4057-a
88e-1fed271e22e5\",\"com.cloud.dc.DataCenter\":\"5755b5f8-d914-4ced-8e8b-06b
e8beda4bb\",\"com.cloud.offering.ServiceOffering\":\"45952a89-e640-47d3-ac08
-5ee0153cf816\"}","hypervisor":"Hyperv","iptonetworklist[0].networkid":"a9a5
f27a-4993-4472-bccc-46a0a79b6f05","name":"win7test1","_":"1416630399370","uu
id":"a3a0f55a-5385-4b40-bf4d-0819211ff3e7","ctxAccountId":"2","diskofferingi
d":"a1cd5943-2436-4057-a88e-1fed271e22e5","ctxStartEventId":"240","displayna
me":"win7test1"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0,
resultCode: 0, result: null, initMsid: 52237247174, completeMsid: null,
lastUpdated: null, lastPolled: null, created: null}
2014-11-22 12:26:23,656 DEBUG [c.c.n.NetworkModelImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Service SecurityGroup
is not supported in the network id=204
2014-11-22 12:26:23,661 DEBUG [c.c.n.NetworkModelImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Service SecurityGroup
is not supported in the network id=204
2014-11-22 12:26:23,681 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Deploy avoids pods:
[], clusters: [], hosts: []
2014-11-22 12:26:23,682 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) DeploymentPlanner
allocation algorithm: com.cloud.deploy.FirstFitPlanner@2019fb2
2014-11-22 12:26:23,682 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Trying to allocate a
host and storage pools from dc:1, pod:null,cluster:null, requested cpu:
1000, requested ram: 1073741824
2014-11-22 12:26:23,682 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Is ROOT volume READY
(pool already allocated)?: No
2014-11-22 12:26:23,683 DEBUG [c.c.d.FirstFitPlanner]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Searching all
possible resources under this Zone: 1
2014-11-22 12:26:23,684 DEBUG [c.c.d.FirstFitPlanner]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Listing clusters in
order of aggregate capacity, that have (atleast one host with) enough CPU
and RAM capacity under this Zone: 1
2014-11-22 12:26:23,689 DEBUG [c.c.d.FirstFitPlanner]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Removing from the
clusterId list these clusters from avoid set: []
2014-11-22 12:26:23,697 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Checking resources in
Cluster: 1 under Pod: 1
2014-11-22 12:26:23,698 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f
FirstFitRoutingAllocator) Looking for hosts in dc: 1  pod:1  cluster:1
2014-11-22 12:26:23,703 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f
FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for
allocation: [Host[-1-Routing]]
2014-11-22 12:26:23,708 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f
FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization:
[Host[-1-Routing]]
2014-11-22 12:26:23,708 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f
FirstFitRoutingAllocator) Looking for speed=1000Mhz, Ram=1024
2014-11-22 12:26:23,717 DEBUG [c.c.c.CapacityManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f
FirstFitRoutingAllocator) Host: 1 has cpu capability (cpu:16, speed:2000) to
support requested CPU: 1 and requested speed: 1000
2014-11-22 12:26:23,717 DEBUG [c.c.c.CapacityManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f
FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for
requested CPU: 1000 and requested RAM: 1073741824 ,
cpuOverprovisioningFactor: 1.0
2014-11-22 12:26:23,720 DEBUG [c.c.c.CapacityManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f
FirstFitRoutingAllocator) Hosts's actual total CPU: 32000 and CPU after
applying overprovisioning: 32000
2014-11-22 12:26:23,720 DEBUG [c.c.c.CapacityManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f
FirstFitRoutingAllocator) Free CPU: 27500 , Requested CPU: 1000
2014-11-22 12:26:23,720 DEBUG [c.c.c.CapacityManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f
FirstFitRoutingAllocator) Free RAM: 132794261504 , Requested RAM: 1073741824
2014-11-22 12:26:23,720 DEBUG [c.c.c.CapacityManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f
FirstFitRoutingAllocator) Host has enough CPU and RAM available
2014-11-22 12:26:23,720 DEBUG [c.c.c.CapacityManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f
FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 4500,
reserved: 0, actual total: 32000, total with overprovisioning: 32000;
requested cpu:1000,alloc_from_last_host?:false ,considerReservedCapacity?:
true
2014-11-22 12:26:23,721 DEBUG [c.c.c.CapacityManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f
FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used:
4563402752, reserved: 0, total: 137357664256; requested mem:
1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-11-22 12:26:23,721 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f
FirstFitRoutingAllocator) Found a suitable host, adding to list: 1
2014-11-22 12:26:23,721 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f
FirstFitRoutingAllocator) Host Allocator returning 1 suitable hosts
2014-11-22 12:26:23,723 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Checking suitable
pools for volume (Id, Type): (12,ROOT)
2014-11-22 12:26:23,723 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) We need to allocate
new storagepool for this volume
2014-11-22 12:26:23,724 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Calling
StoragePoolAllocators to find suitable pools
2014-11-22 12:26:23,725 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f)
LocalStoragePoolAllocator trying to find storage pool to fit the vm
2014-11-22 12:26:23,725 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f)
ClusterScopeStoragePoolAllocator looking for storage pool
2014-11-22 12:26:23,725 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Looking for pools in
dc: 1  pod:1  cluster:1
2014-11-22 12:26:23,727 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Found pools matching
tags: [Pool[1|SMB]]
2014-11-22 12:26:23,729 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Removing pool
Pool[1|SMB] from avoid set, must have been inserted when searching for
another disk's tag
2014-11-22 12:26:23,730 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Checking if storage
pool is suitable, name: null ,poolId: 1
2014-11-22 12:26:23,735 DEBUG [c.c.s.StorageManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Checking pool 1 for
storage, totalSize: 149954752512, usedBytes: 42745335808, usedPct:
0.28505489217208596, disable threshold: 0.85
2014-11-22 12:26:23,738 DEBUG [c.c.s.StorageManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Found storage pool
WINPrimary of type SMB
2014-11-22 12:26:23,738 DEBUG [c.c.s.StorageManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Total capacity of the
pool WINPrimary id: 1 is 149954752512
2014-11-22 12:26:23,739 DEBUG [c.c.s.StorageManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Checking pool: 1 for
volume allocation [Vol[12|vm=12|ROOT]], maxSize : 149954752512,
totalAllocatedSize : 2248710144, askingSize : 21474836480, allocated disable
threshold: 0.85
2014-11-22 12:26:23,740 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f)
ClusterScopeStoragePoolAllocator returning 1 suitable storage pools
2014-11-22 12:26:23,740 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Trying to find a
potenial host and associated storage pools from the suitable host/pool lists
for this VM
2014-11-22 12:26:23,740 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Checking if host: 1
can access any suitable storage pool for volume: ROOT
2014-11-22 12:26:23,741 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Host: 1 can access
pool: 1
2014-11-22 12:26:23,742 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Found a potential
host id: 1 name: 192.168.1.78 and associated storage pools for this VM
2014-11-22 12:26:23,744 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Returning Deployment
Destination:
Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id)
)] :
Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(12|ROOT-->Pool(1))]
2014-11-22 12:26:23,773 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Sync job-123
execution on object VmWorkJobQueue.12
2014-11-22 12:26:23,780 WARN  [c.c.u.d.Merovingian2]
(API-Job-Executor-9:ctx-4ac29706 job-122 ctx-5efec04f) Was unable to find
lock for the key vm_instance12 and thread id 1165599449
2014-11-22 12:26:23,887 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-1590e472) Execute sync-queue item:
SyncQueueItemVO {id:31, queueId: 31, contentType: AsyncJob, contentId: 123,
lastProcessMsid: null, lastprocessNumber: null, lastProcessTime: null,
created: Sat Nov 22 12:26:23 CST 2014}
2014-11-22 12:26:23,888 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-1590e472) Schedule queued job-123
2014-11-22 12:26:23,897 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123) Add job-123 into job
monitoring
2014-11-22 12:26:23,897 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123) Executing AsyncJobVO
{id:123, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd:
com.cloud.vm.VmWorkStart, cmdInfo:
rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9p
ZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAlj
bHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQA
EkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-
AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01h
cDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAE
SgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAAC
AAAAAAAAAAIAAAAAAAAADHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAXBzcgAO
amF2YS5sYW5nLkxvbmc7i-SQzI8j3wIAAUoABXZhbHVleHIAEGphdmEubGFuZy5OdW1iZXKGrJUd
C5TgiwIAAHhwAAAAAAAAAAFxAH4ACnBwcHEAfgAKcHNyABFqYXZhLnV0aWwuSGFzaE1hcAUH2sHD
FmDRAwACRgAKbG9hZEZhY3RvckkACXRocmVzaG9sZHhwP0AAAAAAAAx3CAAAABAAAAABdAAKVm1Q
YXNzd29yZHQAHHJPMEFCWFFBRG5OaGRtVmtYM0JoYzNOM2IzSmt4cA, cmdVersion: 0,
status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null,
initMsid: 52237247174, completeMsid: null, lastUpdated: null, lastPolled:
null, created: Sat Nov 22 12:26:23 CST 2014}
2014-11-22 12:26:23,899 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123) Run VM work job:
com.cloud.vm.VmWorkStart for VM 12, job origin: 122
2014-11-22 12:26:23,901 DEBUG [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Execute VM
work job:
com.cloud.vm.VmWorkStart{"dcId":1,"podId":1,"clusterId":1,"hostId":1,"rawPar
ams":{"VmPassword":"rO0ABXQADnNhdmVkX3Bhc3N3b3Jk"},"userId":2,"accountId":2,
"vmId":12,"handlerName":"VirtualMachineManagerImpl"}
2014-11-22 12:26:23,911 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) VM state
transitted from :Stopped to Starting with event: StartRequestedvm's original
host id: null new host id: null host id before state transition: null
2014-11-22 12:26:23,912 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd)
Successfully transitioned to start state for VM[User|i-2-12-VM] reservation
id = f7cb9fa5-1f68-455e-a40a-186d1938f364
2014-11-22 12:26:23,915 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Trying to
deploy VM, vm has dcId: 1 and podId: null
2014-11-22 12:26:23,916 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd)
advanceStart: DeploymentPlan is provided, using dcId:1, podId: 1, clusterId:
1, hostId: 1, poolId: null
2014-11-22 12:26:23,916 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Deploy
avoids pods: null, clusters: null, hosts: null
2014-11-22 12:26:23,929 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Deploy
avoids pods: [], clusters: [], hosts: []
2014-11-22 12:26:23,930 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd)
DeploymentPlanner allocation algorithm:
com.cloud.deploy.FirstFitPlanner@2019fb2
2014-11-22 12:26:23,930 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Trying to
allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu:
1000, requested ram: 1073741824
2014-11-22 12:26:23,930 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Is ROOT
volume READY (pool already allocated)?: No
2014-11-22 12:26:23,930 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd)
DeploymentPlan has host_id specified, choosing this host and making no
checks on this host: 1
2014-11-22 12:26:23,932 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Looking for
suitable pools for this host under zone: 1, pod: 1, cluster: 1
2014-11-22 12:26:23,935 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Checking
suitable pools for volume (Id, Type): (12,ROOT)
2014-11-22 12:26:23,935 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) We need to
allocate new storagepool for this volume
2014-11-22 12:26:23,937 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Calling
StoragePoolAllocators to find suitable pools
2014-11-22 12:26:23,937 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd)
LocalStoragePoolAllocator trying to find storage pool to fit the vm
2014-11-22 12:26:23,937 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd)
ClusterScopeStoragePoolAllocator looking for storage pool
2014-11-22 12:26:23,937 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Looking for
pools in dc: 1  pod:1  cluster:1
2014-11-22 12:26:23,939 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Found pools
matching tags: [Pool[1|SMB]]
2014-11-22 12:26:23,941 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Removing
pool Pool[1|SMB] from avoid set, must have been inserted when searching for
another disk's tag
2014-11-22 12:26:23,942 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Checking if
storage pool is suitable, name: null ,poolId: 1
2014-11-22 12:26:23,947 DEBUG [c.c.s.StorageManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Checking
pool 1 for storage, totalSize: 149954752512, usedBytes: 42745335808,
usedPct: 0.28505489217208596, disable threshold: 0.85
2014-11-22 12:26:23,950 DEBUG [c.c.s.StorageManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Found
storage pool WINPrimary of type SMB
2014-11-22 12:26:23,950 DEBUG [c.c.s.StorageManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Total
capacity of the pool WINPrimary id: 1 is 149954752512
2014-11-22 12:26:23,951 DEBUG [c.c.s.StorageManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Checking
pool: 1 for volume allocation [Vol[12|vm=12|ROOT]], maxSize : 149954752512,
totalAllocatedSize : 2248710144, askingSize : 21474836480, allocated disable
threshold: 0.85
2014-11-22 12:26:23,951 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd)
ClusterScopeStoragePoolAllocator returning 1 suitable storage pools
2014-11-22 12:26:23,951 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Trying to
find a potenial host and associated storage pools from the suitable
host/pool lists for this VM
2014-11-22 12:26:23,951 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Checking if
host: 1 can access any suitable storage pool for volume: ROOT
2014-11-22 12:26:23,952 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Host: 1 can
access pool: 1
2014-11-22 12:26:23,953 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Found a
potential host id: 1 name: 192.168.1.78 and associated storage pools for
this VM
2014-11-22 12:26:23,953 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Returning
Deployment Destination:
Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id)
)] :
Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(12|ROOT-->Pool(1))]
2014-11-22 12:26:23,954 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Deployment
found  - P0=VM[User|i-2-12-VM],
P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(
Id))] :
Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(12|ROOT-->Pool(1))]
2014-11-22 12:26:23,964 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) VM state
transitted from :Starting to Starting with event: OperationRetryvm's
original host id: null new host id: 1 host id before state transition: null
2014-11-22 12:26:23,976 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Hosts's
actual total CPU: 32000 and CPU after applying overprovisioning: 32000
2014-11-22 12:26:23,976 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) We are
allocating VM, increasing the used capacity of this host:1
2014-11-22 12:26:23,977 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Current
Used CPU: 4500 , Free CPU:27500 ,Requested CPU: 1000
2014-11-22 12:26:23,977 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Current
Used RAM: 4563402752 , Free RAM:132794261504 ,Requested RAM: 1073741824
2014-11-22 12:26:23,977 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) CPU STATS
after allocation: for host: 1, old used: 4500, old reserved: 0, actual
total: 32000, total with overprovisioning: 32000; new used:5500, reserved:0;
requested cpu:1000,alloc_from_last:false
2014-11-22 12:26:23,977 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) RAM STATS
after allocation: for host: 1, old used: 4563402752, old reserved: 0, total:
137357664256; new used: 5637144576, reserved: 0; requested mem:
1073741824,alloc_from_last:false
2014-11-22 12:26:23,980 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) VM is being
created in podId: 1
2014-11-22 12:26:23,983 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Network
id=204 is already implemented
2014-11-22 12:26:23,997 DEBUG [c.c.n.NetworkModelImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Service
SecurityGroup is not supported in the network id=204
2014-11-22 12:26:24,003 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Changing
active number of nics for network id=204 on 1
2014-11-22 12:26:24,011 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Asking
VirtualRouter to prepare for
Nic[21-12-f7cb9fa5-1f68-455e-a40a-186d1938f364-10.1.1.26]
2014-11-22 12:26:24,023 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Lock is
acquired for network id 204 as a part of router startup in
Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id)
)] :
Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(12|ROOT-->Pool(1))]
2014-11-22 12:26:24,027 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Lock is
released for network id 204 as a part of router startup in
Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id)
)] :
Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(12|ROOT-->Pool(1))]
2014-11-22 12:26:24,029 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Starting
router VM[DomainRouter|r-4-VM]
2014-11-22 12:26:24,042 DEBUG [c.c.u.d.T.Transaction]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Rolling
back the transaction: Time = 2 Name =  Work-Job-Executor-12; called by
-TransactionLegacy.rollback:900-TransactionLegacy.removeUpTo:843-Transaction
Legacy.close:667-Transaction.execute:41-VirtualMachineManagerImpl.changeToSt
artState:672-VirtualMachineManagerImpl.orchestrateStart:824-VirtualMachineMa
nagerImpl.advanceStart:778-VirtualNetworkApplianceManagerImpl.start:2948-Vir
tualNetworkApplianceManagerImpl.startVirtualRouter:2035-VirtualNetworkApplia
nceManagerImpl.startRouters:2139-VirtualNetworkApplianceManagerImpl.deployVi
rtualRouterInGuestNetwork:2117-NativeMethodAccessorImpl.invoke0:-2
2014-11-22 12:26:24,044 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Unable to
transition into Starting state due to Unable to transition to a new state
from Starting via StartRequested
2014-11-22 12:26:24,046 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Determining
why we're unable to update the state to Starting for
VM[DomainRouter|r-4-VM].  Retry=4
2014-11-22 12:26:24,047 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Unable to
find work for VM: VM[DomainRouter|r-4-VM] and state: Starting
2014-11-22 12:26:24,050 DEBUG [c.c.u.d.T.Transaction]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Rolling
back the transaction: Time = 1 Name =  Work-Job-Executor-12; called by
-TransactionLegacy.rollback:900-TransactionLegacy.removeUpTo:843-Transaction
Legacy.close:667-Transaction.execute:41-VirtualMachineManagerImpl.changeToSt
artState:672-VirtualMachineManagerImpl.orchestrateStart:824-VirtualMachineMa
nagerImpl.advanceStart:778-VirtualNetworkApplianceManagerImpl.start:2948-Vir
tualNetworkApplianceManagerImpl.startVirtualRouter:2035-VirtualNetworkApplia
nceManagerImpl.startRouters:2139-VirtualNetworkApplianceManagerImpl.deployVi
rtualRouterInGuestNetwork:2117-NativeMethodAccessorImpl.invoke0:-2
2014-11-22 12:26:24,051 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Unable to
transition into Starting state due to Unable to transition to a new state
from Starting via StartRequested
2014-11-22 12:26:24,054 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Determining
why we're unable to update the state to Starting for
VM[DomainRouter|r-4-VM].  Retry=3
2014-11-22 12:26:24,055 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Unable to
find work for VM: VM[DomainRouter|r-4-VM] and state: Starting
2014-11-22 12:26:24,057 DEBUG [c.c.u.d.T.Transaction]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Rolling
back the transaction: Time = 2 Name =  Work-Job-Executor-12; called by
-TransactionLegacy.rollback:900-TransactionLegacy.removeUpTo:843-Transaction
Legacy.close:667-Transaction.execute:41-VirtualMachineManagerImpl.changeToSt
artState:672-VirtualMachineManagerImpl.orchestrateStart:824-VirtualMachineMa
nagerImpl.advanceStart:778-VirtualNetworkApplianceManagerImpl.start:2948-Vir
tualNetworkApplianceManagerImpl.startVirtualRouter:2035-VirtualNetworkApplia
nceManagerImpl.startRouters:2139-VirtualNetworkApplianceManagerImpl.deployVi
rtualRouterInGuestNetwork:2117-NativeMethodAccessorImpl.invoke0:-2
2014-11-22 12:26:24,059 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Unable to
transition into Starting state due to Unable to transition to a new state
from Starting via StartRequested
2014-11-22 12:26:24,061 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Determining
why we're unable to update the state to Starting for
VM[DomainRouter|r-4-VM].  Retry=2
2014-11-22 12:26:24,063 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Unable to
find work for VM: VM[DomainRouter|r-4-VM] and state: Starting
2014-11-22 12:26:24,065 DEBUG [c.c.u.d.T.Transaction]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Rolling
back the transaction: Time = 2 Name =  Work-Job-Executor-12; called by
-TransactionLegacy.rollback:900-TransactionLegacy.removeUpTo:843-Transaction
Legacy.close:667-Transaction.execute:41-VirtualMachineManagerImpl.changeToSt
artState:672-VirtualMachineManagerImpl.orchestrateStart:824-VirtualMachineMa
nagerImpl.advanceStart:778-VirtualNetworkApplianceManagerImpl.start:2948-Vir
tualNetworkApplianceManagerImpl.startVirtualRouter:2035-VirtualNetworkApplia
nceManagerImpl.startRouters:2139-VirtualNetworkApplianceManagerImpl.deployVi
rtualRouterInGuestNetwork:2117-NativeMethodAccessorImpl.invoke0:-2
2014-11-22 12:26:24,067 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Unable to
transition into Starting state due to Unable to transition to a new state
from Starting via StartRequested
2014-11-22 12:26:24,069 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Determining
why we're unable to update the state to Starting for
VM[DomainRouter|r-4-VM].  Retry=1
2014-11-22 12:26:24,071 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Unable to
find work for VM: VM[DomainRouter|r-4-VM] and state: Starting
2014-11-22 12:26:24,073 DEBUG [c.c.u.d.T.Transaction]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Rolling
back the transaction: Time = 2 Name =  Work-Job-Executor-12; called by
-TransactionLegacy.rollback:900-TransactionLegacy.removeUpTo:843-Transaction
Legacy.close:667-Transaction.execute:41-VirtualMachineManagerImpl.changeToSt
artState:672-VirtualMachineManagerImpl.orchestrateStart:824-VirtualMachineMa
nagerImpl.advanceStart:778-VirtualNetworkApplianceManagerImpl.start:2948-Vir
tualNetworkApplianceManagerImpl.startVirtualRouter:2035-VirtualNetworkApplia
nceManagerImpl.startRouters:2139-VirtualNetworkApplianceManagerImpl.deployVi
rtualRouterInGuestNetwork:2117-NativeMethodAccessorImpl.invoke0:-2
2014-11-22 12:26:24,074 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Unable to
transition into Starting state due to Unable to transition to a new state
from Starting via StartRequested
2014-11-22 12:26:24,077 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Determining
why we're unable to update the state to Starting for
VM[DomainRouter|r-4-VM].  Retry=0
2014-11-22 12:26:24,078 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Unable to
find work for VM: VM[DomainRouter|r-4-VM] and state: Starting
2014-11-22 12:26:24,082 ERROR [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-12:ctx-5751770c job-122/job-123 ctx-3a1113bd) Failed to
start instance VM[User|i-2-12-VM]
com.cloud.exception.ConcurrentOperationException: Unable to change the state
of VM[DomainRouter|r-4-VM]
	at
com.cloud.vm.VirtualMachineManagerImpl.changeToStartState(VirtualMachineMana
gerImpl.java:731)
	at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManage
rImpl.java:824)
	at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImp
l.java:778)
	at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.start(VirtualNet
workApplianceManagerImpl.java:2948)
	at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startVirtualRout
er(VirtualNetworkApplianceManagerImpl.java:2035)
	at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.startRouters(Vir
tualNetworkApplianceManagerImpl.java:2139)
	at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRou
terInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:2117)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
)
	at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopU
tils.java:317)
	at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint
(ReflectiveMethodInvocation.java:183)
	at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Reflect
iveMethodInvocation.java:150)
	at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(Expos
eInvocationInterceptor.java:91)
	at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Reflect
iveMethodInvocation.java:172)
	at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopPro
xy.java:204)
	at com.sun.proxy.$Proxy189.deployVirtualRouterInGuestNetwork(Unknown
Source)
	at
com.cloud.network.element.VirtualRouterElement.prepare(VirtualRouterElement.
java:227)
	at
org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepareElemen
t(NetworkOrchestrator.java:1209)
	at
org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepareNic(Ne
tworkOrchestrator.java:1343)
	at
org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepare(Netwo
rkOrchestrator.java:1279)
	at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManage
rImpl.java:986)
	at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManage
rImpl.java:5195)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
)
	at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.jav
a:107)
	at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManager
Impl.java:5340)
	at
com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
	at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext
(AsyncJobManagerImpl.java:503)
	at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedCo
ntextRunnable.java:49)
	at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(Defa
ultManagedContext.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(ManagedCont
extRunnable.java:46)
	at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJob
ManagerImpl.java:460)
	at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:11
45)
	at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:6
15)
	at java.lang.Thread.run(Thread.java:745)

-----邮件原件-----
发件人: Anshul Gangwar [mailto:anshul.gangwar@citrix.com] 
发送时间: 2014年11月20日 20:04
收件人: dev@cloudstack.apache.org
主题: RE: hyperv ssvm start failed

I don't have any such document. 

Documentation to create setup with Advanced networking without  security
groups should work fine.
________________________________________
From: 穆凯辉 [khmu@landhightech.com]
Sent: Thursday, November 20, 2014 5:02 PM
To: dev@cloudstack.apache.org
Subject: 答复: hyperv ssvm start failed

Oh,We use the basic networking. Then, Do you have detailed configuration
about cloudstack 4.* + hyperv 2012?

The configuration in the main site of cloudstack does not give detailed
information about this.



Khmu
-----邮件原件-----
发件人: Anshul Gangwar [mailto:anshul.gangwar@citrix.com]
发送时间: 2014年11月20日 18:36
收件人: dev@cloudstack.apache.org
主题: RE: hyperv ssvm start failed

what type of networking are you using?

Hyper-V is supported only in Advanced Networking.

It doesn't support security groups.
________________________________________
From: 穆凯辉 [khmu@landhightech.com]
Sent: Thursday, November 20, 2014 3:38 PM
To: dev@cloudstack.apache.org
Subject: 答复: hyperv ssvm start failed

#TYPE System.Diagnostics.EventLogEntry#application/CloudStack Hyper-V
Agent/0
EventID,"MachineName","Data","Index","Category","CategoryNumber","EntryType"
,"Message","Source","ReplacementStrings","InstanceId","TimeGenerated","TimeW
ritten","UserName","Site","Container"
0,"hyperv-server1.cloud.priv","System.Byte[]","22841","(0)","0","Information
","2014-11-20 16:24:35,601 [10] INFO
HypervResource.HypervResourceController
[897ebcfe-8897-4c02-b6c7-be7d08f5729c] - {
  ""com.cloud.agent.api.GetStorageStatsAnswer"": {
    ""result"": true,
    ""details"": null,
    ""capacity"": 149954752512,
    ""used"": 23543066624,
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:24:35","2014/11/21 8:24:35",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22840","(0)","0","Information
","2014-11-20 16:24:35,601 [10] DEBUG
HypervResource.HypervResourceController
[897ebcfe-8897-4c02-b6c7-be7d08f5729c] -
com.cloud.agent.api.GetStorageStatsCommand set used bytes for
\\192.168.1.79\WINPrimary to 23543066624
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:24:35","2014/11/21 8:24:35",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22839","(0)","0","Information
","2014-11-20 16:24:35,601 [10] INFO
HypervResource.HypervResourceController
[897ebcfe-8897-4c02-b6c7-be7d08f5729c] -
com.cloud.agent.api.GetStorageStatsCommand{
  ""id"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
  ""localPath"": ""/WINPrimary?user=cloudstackadmin&domain=cloud"",
  ""pooltype"": ""SMB"",
  ""contextMap"": {},
  ""wait"": 0
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:24:35","2014/11/21 8:24:35",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22838","(0)","0","Information
","2014-11-20 16:24:15,506 [10] INFO
HypervResource.HypervResourceController
[4ff92984-9601-4cf4-89d4-f44e7c8dac39] - {
  ""com.cloud.agent.api.GetHostStatsAnswer"": {
    ""result"": true,
    ""hostStats"": {
      ""hostId"": 1,
      ""entityType"": ""host"",
      ""cpuUtilization"": 1.0,
      ""networkReadKBs"": 546709530.0,
      ""networkWriteKBs"": 4708971054.0,
      ""totalMemoryKBs"": 134138344.0,
      ""freeMemoryKBs"": 127542216.0
    },
    ""details"": null,
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:24:15","2014/11/21 8:24:15",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22837","(0)","0","Information
","2014-11-20 16:24:15,131 [10] INFO
HypervResource.HypervResourceController
[4ff92984-9601-4cf4-89d4-f44e7c8dac39] -
com.cloud.agent.api.GetHostStatsCommand{
  ""hostGuid"": ""3be2f4fe-f3c7-33c1-8127-696c45258534-HypervResource"",
  ""hostName"": ""192.168.1.78"",
  ""hostId"": 1,
  ""contextMap"": {},
  ""wait"": 0
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:24:15","2014/11/21 8:24:15",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22836","(0)","0","Information
","2014-11-20 16:24:13,162 [10] INFO
HypervResource.HypervResourceController
[b3bc116e-fb2c-4713-8589-8864dca4c0e0] - {
  ""com.cloud.agent.api.CheckHealthAnswer"": {
    ""result"": true,
    ""details"": ""resource is alive"",
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:24:13","2014/11/21 8:24:13",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22835","(0)","0","Information
","2014-11-20 16:24:13,162 [10] INFO
HypervResource.HypervResourceController
[b3bc116e-fb2c-4713-8589-8864dca4c0e0] -
com.cloud.agent.api.CheckHealthCommand{
  ""contextMap"": {},
  ""wait"": 50
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:24:13","2014/11/21 8:24:13",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22834","(0)","0","Information
","2014-11-20 16:23:35,510 [9] INFO  HypervResource.HypervResourceController
[4e4832aa-e742-40f2-9e62-7a69ae213c2f] - {
  ""com.cloud.agent.api.GetStorageStatsAnswer"": {
    ""result"": true,
    ""details"": null,
    ""capacity"": 149954752512,
    ""used"": 23543066624,
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:23:35","2014/11/21 8:23:35",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22833","(0)","0","Information
","2014-11-20 16:23:35,510 [9] DEBUG HypervResource.HypervResourceController
[4e4832aa-e742-40f2-9e62-7a69ae213c2f] -
com.cloud.agent.api.GetStorageStatsCommand set used bytes for
\\192.168.1.79\WINPrimary to 23543066624
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:23:35","2014/11/21 8:23:35",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22832","(0)","0","Information
","2014-11-20 16:23:35,510 [9] INFO  HypervResource.HypervResourceController
[4e4832aa-e742-40f2-9e62-7a69ae213c2f] -
com.cloud.agent.api.GetStorageStatsCommand{
  ""id"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
  ""localPath"": ""/WINPrimary?user=cloudstackadmin&domain=cloud"",
  ""pooltype"": ""SMB"",
  ""contextMap"": {},
  ""wait"": 0
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:23:35","2014/11/21 8:23:35",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22831","(0)","0","Information
","2014-11-20 16:23:15,040 [9] INFO  HypervResource.HypervResourceController
[2b81b673-a6bb-41ab-9a58-c70c0248fd63] - {
  ""com.cloud.agent.api.GetHostStatsAnswer"": {
    ""result"": true,
    ""hostStats"": {
      ""hostId"": 1,
      ""entityType"": ""host"",
      ""cpuUtilization"": 1.0,
      ""networkReadKBs"": 546646948.0,
      ""networkWriteKBs"": 4708882218.0,
      ""totalMemoryKBs"": 134138344.0,
      ""freeMemoryKBs"": 127540684.0
    },
    ""details"": null,
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:23:15","2014/11/21 8:23:15",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22830","(0)","0","Information
","2014-11-20 16:23:14,665 [9] INFO  HypervResource.HypervResourceController
[2b81b673-a6bb-41ab-9a58-c70c0248fd63] -
com.cloud.agent.api.GetHostStatsCommand{
  ""hostGuid"": ""3be2f4fe-f3c7-33c1-8127-696c45258534-HypervResource"",
  ""hostName"": ""192.168.1.78"",
  ""hostId"": 1,
  ""contextMap"": {},
  ""wait"": 0
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:23:14","2014/11/21 8:23:14",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22829","(0)","0","Information
","2014-11-20 16:23:13,154 [9] INFO  HypervResource.HypervResourceController
[6be4714c-956e-4092-9de3-8f856f5e9237] - {
  ""com.cloud.agent.api.CheckHealthAnswer"": {
    ""result"": true,
    ""details"": ""resource is alive"",
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:23:13","2014/11/21 8:23:13",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22828","(0)","0","Information
","2014-11-20 16:23:13,154 [9] INFO  HypervResource.HypervResourceController
[6be4714c-956e-4092-9de3-8f856f5e9237] -
com.cloud.agent.api.CheckHealthCommand{
  ""contextMap"": {},
  ""wait"": 50
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:23:13","2014/11/21 8:23:13",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22827","(0)","0","Information
","2014-11-20 16:22:35,427 [14] INFO
HypervResource.HypervResourceController
[db581f11-aa2c-4a8c-855d-e6c315c5828e] - {
  ""com.cloud.agent.api.GetStorageStatsAnswer"": {
    ""result"": true,
    ""details"": null,
    ""capacity"": 149954752512,
    ""used"": 23543066624,
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:22:35","2014/11/21 8:22:35",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22826","(0)","0","Information
","2014-11-20 16:22:35,427 [14] DEBUG
HypervResource.HypervResourceController
[db581f11-aa2c-4a8c-855d-e6c315c5828e] -
com.cloud.agent.api.GetStorageStatsCommand set used bytes for
\\192.168.1.79\WINPrimary to 23543066624
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:22:35","2014/11/21 8:22:35",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22825","(0)","0","Information
","2014-11-20 16:22:35,427 [14] INFO
HypervResource.HypervResourceController
[db581f11-aa2c-4a8c-855d-e6c315c5828e] -
com.cloud.agent.api.GetStorageStatsCommand{
  ""id"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
  ""localPath"": ""/WINPrimary?user=cloudstackadmin&domain=cloud"",
  ""pooltype"": ""SMB"",
  ""contextMap"": {},
  ""wait"": 0
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:22:35","2014/11/21 8:22:35",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22824","(0)","0","Information
","2014-11-20 16:22:14,569 [14] INFO
HypervResource.HypervResourceController
[666c6340-208b-4e35-b52e-53e957b0f821] - {
  ""com.cloud.agent.api.GetHostStatsAnswer"": {
    ""result"": true,
    ""hostStats"": {
      ""hostId"": 1,
      ""entityType"": ""host"",
      ""cpuUtilization"": 1.0,
      ""networkReadKBs"": 546590243.0,
      ""networkWriteKBs"": 4708794174.0,
      ""totalMemoryKBs"": 134138344.0,
      ""freeMemoryKBs"": 127537836.0
    },
    ""details"": null,
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:22:14","2014/11/21 8:22:14",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22823","(0)","0","Information
","2014-11-20 16:22:14,194 [14] INFO
HypervResource.HypervResourceController
[666c6340-208b-4e35-b52e-53e957b0f821] -
com.cloud.agent.api.GetHostStatsCommand{
  ""hostGuid"": ""3be2f4fe-f3c7-33c1-8127-696c45258534-HypervResource"",
  ""hostName"": ""192.168.1.78"",
  ""hostId"": 1,
  ""contextMap"": {},
  ""wait"": 0
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:22:14","2014/11/21 8:22:14",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22822","(0)","0","Information
","2014-11-20 16:22:13,147 [14] INFO
HypervResource.HypervResourceController
[92857b5f-1a5f-4d2e-b261-d8222eb89788] - {
  ""com.cloud.agent.api.CheckHealthAnswer"": {
    ""result"": true,
    ""details"": ""resource is alive"",
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:22:13","2014/11/21 8:22:13",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22821","(0)","0","Information
","2014-11-20 16:22:13,147 [14] INFO
HypervResource.HypervResourceController
[92857b5f-1a5f-4d2e-b261-d8222eb89788] -
com.cloud.agent.api.CheckHealthCommand{
  ""contextMap"": {},
  ""wait"": 50
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:22:13","2014/11/21 8:22:13",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22820","(0)","0","Information
","2014-11-20 16:21:35,206 [19] INFO
HypervResource.HypervResourceController
[fa0a907c-2433-40c2-b45f-7431e68b10dc] - {
  ""com.cloud.agent.api.GetStorageStatsAnswer"": {
    ""result"": true,
    ""details"": null,
    ""capacity"": 149954752512,
    ""used"": 23543062528,
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:21:35","2014/11/21 8:21:35",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22819","(0)","0","Information
","2014-11-20 16:21:35,206 [19] DEBUG
HypervResource.HypervResourceController
[fa0a907c-2433-40c2-b45f-7431e68b10dc] -
com.cloud.agent.api.GetStorageStatsCommand set used bytes for
\\192.168.1.79\WINPrimary to 23543062528
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:21:35","2014/11/21 8:21:35",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22818","(0)","0","Information
","2014-11-20 16:21:35,206 [19] INFO
HypervResource.HypervResourceController
[fa0a907c-2433-40c2-b45f-7431e68b10dc] -
com.cloud.agent.api.GetStorageStatsCommand{
  ""id"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
  ""localPath"": ""/WINPrimary?user=cloudstackadmin&domain=cloud"",
  ""pooltype"": ""SMB"",
  ""contextMap"": {},
  ""wait"": 0
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:21:35","2014/11/21 8:21:35",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22817","(0)","0","Information
","2014-11-20 16:21:14,110 [19] INFO
HypervResource.HypervResourceController
[c02f6f45-3077-4fb8-a7f9-fe84a7cdde5f] - {
  ""com.cloud.agent.api.GetHostStatsAnswer"": {
    ""result"": true,
    ""hostStats"": {
      ""hostId"": 1,
      ""entityType"": ""host"",
      ""cpuUtilization"": 1.0,
      ""networkReadKBs"": 546525912.0,
      ""networkWriteKBs"": 4708704488.0,
      ""totalMemoryKBs"": 134138344.0,
      ""freeMemoryKBs"": 127536132.0
    },
    ""details"": null,
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:21:14","2014/11/21 8:21:14",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22816","(0)","0","Information
","2014-11-20 16:21:13,735 [19] INFO
HypervResource.HypervResourceController
[c02f6f45-3077-4fb8-a7f9-fe84a7cdde5f] -
com.cloud.agent.api.GetHostStatsCommand{
  ""hostGuid"": ""3be2f4fe-f3c7-33c1-8127-696c45258534-HypervResource"",
  ""hostName"": ""192.168.1.78"",
  ""hostId"": 1,
  ""contextMap"": {},
  ""wait"": 0
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:21:13","2014/11/21 8:21:13",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22815","(0)","0","Information
","2014-11-20 16:21:13,126 [19] INFO
HypervResource.HypervResourceController
[72657d54-9a7e-4600-aba3-26610949b4bc] - {
  ""com.cloud.agent.api.CheckHealthAnswer"": {
    ""result"": true,
    ""details"": ""resource is alive"",
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:21:13","2014/11/21 8:21:13",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22814","(0)","0","Information
","2014-11-20 16:21:13,126 [19] INFO
HypervResource.HypervResourceController
[72657d54-9a7e-4600-aba3-26610949b4bc] -
com.cloud.agent.api.CheckHealthCommand{
  ""contextMap"": {},
  ""wait"": 50
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:21:13","2014/11/21 8:21:13",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22813","(0)","0","Information
","2014-11-20 16:20:35,113 [19] INFO
HypervResource.HypervResourceController
[bd6aa050-d744-4c97-a5fd-0e7344059f3d] - {
  ""com.cloud.agent.api.GetStorageStatsAnswer"": {
    ""result"": true,
    ""details"": null,
    ""capacity"": 149954752512,
    ""used"": 23543062528,
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:35","2014/11/21 8:20:35",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22812","(0)","0","Information
","2014-11-20 16:20:35,113 [19] DEBUG
HypervResource.HypervResourceController
[bd6aa050-d744-4c97-a5fd-0e7344059f3d] -
com.cloud.agent.api.GetStorageStatsCommand set used bytes for
\\192.168.1.79\WINPrimary to 23543062528
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:35","2014/11/21 8:20:35",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22811","(0)","0","Information
","2014-11-20 16:20:35,113 [19] INFO
HypervResource.HypervResourceController
[bd6aa050-d744-4c97-a5fd-0e7344059f3d] -
com.cloud.agent.api.GetStorageStatsCommand{
  ""id"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
  ""localPath"": ""/WINPrimary?user=cloudstackadmin&domain=cloud"",
  ""pooltype"": ""SMB"",
  ""contextMap"": {},
  ""wait"": 0
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:35","2014/11/21 8:20:35",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22810","(0)","0","Information
","2014-11-20 16:20:26,487 [19] INFO
HypervResource.HypervResourceController
[cef21616-6d6a-42cd-b6b5-bf57930fa3d0] - {
  ""com.cloud.agent.api.Answer"": {
    ""result"": true,
    ""details"": null,
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:26","2014/11/21 8:20:26",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22809","(0)","0","Information
","2014-11-20 16:20:26,362 [19] INFO
HypervResource.HypervResourceController
[cef21616-6d6a-42cd-b6b5-bf57930fa3d0] -
com.cloud.agent.api.storage.DestroyCommand{
  ""data"": {
    ""org.apache.cloudstack.storage.to.VolumeObjectTO"": {
      ""uuid"": ""0d03ce12-d587-400c-ab0e-207d5a7b0e24"",
      ""volumeType"": ""ROOT"",
      ""dataStore"": {
        ""org.apache.cloudstack.storage.to.PrimaryDataStoreTO"": {
          ""uuid"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
          ""id"": 1,
          ""poolType"": ""SMB"",
          ""host"": ""192.168.1.79"",
          ""path"": ""/WINPrimary?user=cloudstackadmin&domain=cloud"",
          ""port"": 445,
          ""url"":
""SMB://192.168.1.79/WINPrimary?user=cloudstackadmin&domain=cloud/?ROLE=Prim
ary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6daaaea9""
        }
      },
      ""name"": ""ROOT-88"",
      ""size"": 0,
      ""path"": ""0d03ce12-d587-400c-ab0e-207d5a7b0e24"",
      ""volumeId"": 88,
      ""vmName"": ""s-88-VM"",
      ""accountId"": 1,
      ""format"": ""VHD"",
      ""id"": 88,
      ""deviceId"": 0,
      ""hypervisorType"": ""Hyperv""
    }
  },
  ""contextMap"": {},
  ""wait"": 0
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:26","2014/11/21 8:20:26",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22808","(0)","0","Information
","2014-11-20 16:20:24,300 [19] INFO
HypervResource.HypervResourceController
[90ad899c-b6f6-46b3-b765-a4471c002038] - {
  ""com.cloud.agent.api.StopAnswer"": {
    ""result"": true,
    ""details"": null,
    ""vm"": null,
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:24","2014/11/21 8:20:24",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22807","(0)","0","Information
","2014-11-20 16:20:24,284 [19] DEBUG HypervResource.WmiCallsV2
[90ad899c-b6f6-46b3-b765-a4471c002038] - WMI job succeeded: Destroying
Virtual Machine, Elapsed=00:00:00.0371560
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:24","2014/11/21 8:20:24",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22806","(0)","0","Information
","2014-11-20 16:20:24,159 [15] INFO
HypervResource.HypervResourceController
[6dee4b13-c80c-493e-aba8-528cac178229] - {
  ""com.cloud.agent.api.StopAnswer"": {
    ""result"": true,
    ""details"": null,
    ""vm"": null,
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:24","2014/11/21 8:20:24",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22805","(0)","0","Information
","2014-11-20 16:20:24,143 [15] DEBUG HypervResource.WmiCallsV2
[6dee4b13-c80c-493e-aba8-528cac178229] - WMI job succeeded: Destroying
Virtual Machine, Elapsed=00:00:00.0388900
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:24","2014/11/21 8:20:24",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22804","(0)","0","Information
","2014-11-20 16:20:23,268 [19] INFO  HypervResource.WmiCallsV2
[90ad899c-b6f6-46b3-b765-a4471c002038] - In progress... 0% completed.
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22803","(0)","0","Information
","2014-11-20 16:20:23,221 [19] DEBUG HypervResource.WmiCallsV2
[90ad899c-b6f6-46b3-b765-a4471c002038] - Delete VM s-88-VM (GUID
DDAF7798-A64A-447E-AE63-6E8194C65BCD)
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22802","(0)","0","Information
","2014-11-20 16:20:23,190 [19] DEBUG HypervResource.WmiCallsV2
[90ad899c-b6f6-46b3-b765-a4471c002038] - Remove associated switch ports for
VM s-88-VM (GUID DDAF7798-A64A-447E-AE63-6E8194C65BCD)
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22801","(0)","0","Information
","2014-11-20 16:20:23,190 [19] INFO  HypervResource.WmiCallsV2
[90ad899c-b6f6-46b3-b765-a4471c002038] - Successfully changed vm state of
s-88-VM (GUID DDAF7798-A64A-447E-AE63-6E8194C65BCD to requested state 3
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22800","(0)","0","Information
","2014-11-20 16:20:23,175 [19] INFO  HypervResource.WmiCallsV2
[90ad899c-b6f6-46b3-b765-a4471c002038] - RequestStateChange returned 32775,
which means vm in wrong state for requested state change.  Treating as if
requested state was reached
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22799","(0)","0","Information
","2014-11-20 16:20:23,175 [19] INFO  HypervResource.WmiCallsV2
[90ad899c-b6f6-46b3-b765-a4471c002038] - Changing state of s-88-VM (GUID
DDAF7798-A64A-447E-AE63-6E8194C65BCD) to Disabled
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22798","(0)","0","Information
","2014-11-20 16:20:23,175 [19] DEBUG HypervResource.WmiCallsV2
[90ad899c-b6f6-46b3-b765-a4471c002038] - Remove VM s-88-VM (GUID
DDAF7798-A64A-447E-AE63-6E8194C65BCD)
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22797","(0)","0","Information
","2014-11-20 16:20:23,159 [19] INFO  HypervResource.WmiCallsV2
[90ad899c-b6f6-46b3-b765-a4471c002038] - Shutting down of system failed; may
be shutdown integration services are missing
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22796","(0)","0","Information
","2014-11-20 16:20:23,128 [15] INFO  HypervResource.WmiCallsV2
[6dee4b13-c80c-493e-aba8-528cac178229] - In progress... 0% completed.
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22795","(0)","0","Information
","2014-11-20 16:20:23,128 [19] DEBUG HypervResource.WmiCallsV2
[90ad899c-b6f6-46b3-b765-a4471c002038] - Got request to destroy vm s-88-VM
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22794","(0)","0","Information
","2014-11-20 16:20:23,128 [19] INFO
HypervResource.HypervResourceController
[90ad899c-b6f6-46b3-b765-a4471c002038] - com.cloud.agent.api.StopCommand{
  ""isProxy"": false,
  ""executeInSequence"": false,
  ""checkBeforeCleanup"": false,
  ""vmName"": ""s-88-VM"",
  ""contextMap"": {},
  ""wait"": 0
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22793","(0)","0","Information
","2014-11-20 16:20:23,096 [15] DEBUG HypervResource.WmiCallsV2
[6dee4b13-c80c-493e-aba8-528cac178229] - Delete VM v-7-VM (GUID
8B66F183-0829-4FE5-98AC-FC8594186F4A)
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22792","(0)","0","Information
","2014-11-20 16:20:23,065 [15] DEBUG HypervResource.WmiCallsV2
[6dee4b13-c80c-493e-aba8-528cac178229] - Remove associated switch ports for
VM v-7-VM (GUID 8B66F183-0829-4FE5-98AC-FC8594186F4A)
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22791","(0)","0","Information
","2014-11-20 16:20:23,065 [15] INFO  HypervResource.WmiCallsV2
[6dee4b13-c80c-493e-aba8-528cac178229] - Successfully changed vm state of
v-7-VM (GUID 8B66F183-0829-4FE5-98AC-FC8594186F4A to requested state 3
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22790","(0)","0","Information
","2014-11-20 16:20:23,065 [15] INFO  HypervResource.WmiCallsV2
[6dee4b13-c80c-493e-aba8-528cac178229] - RequestStateChange returned 32775,
which means vm in wrong state for requested state change.  Treating as if
requested state was reached
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22789","(0)","0","Information
","2014-11-20 16:20:23,050 [15] INFO  HypervResource.WmiCallsV2
[6dee4b13-c80c-493e-aba8-528cac178229] - Changing state of v-7-VM (GUID
8B66F183-0829-4FE5-98AC-FC8594186F4A) to Disabled
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22788","(0)","0","Information
","2014-11-20 16:20:23,050 [15] DEBUG HypervResource.WmiCallsV2
[6dee4b13-c80c-493e-aba8-528cac178229] - Remove VM v-7-VM (GUID
8B66F183-0829-4FE5-98AC-FC8594186F4A)
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22787","(0)","0","Information
","2014-11-20 16:20:23,034 [19] INFO
HypervResource.HypervResourceController
[e7e264e5-a34a-489f-a606-5e0932e4dab6] - {
  ""com.cloud.agent.api.StartAnswer"": {
    ""result"": false,
    ""details"": ""com.cloud.agent.api.StartCommand fail on exceptionObject
reference not set to an instance of an object."",
    ""vm"": {
      ""id"": 88,
      ""name"": ""s-88-VM"",
      ""type"": ""SecondaryStorageVm"",
      ""cpus"": 1,
      ""minSpeed"": 500,
      ""maxSpeed"": 500,
      ""minRam"": 536870912,
      ""maxRam"": 536870912,
      ""arch"": ""x86_64"",
      ""os"": ""Debian GNU/Linux 5.0 (64-bit)"",
      ""bootArgs"": "" template=domP type=secstorage host=192.168.1.130
port=8250 name=s-88-VM zone=1 pod=1 guid=s-88-VM resource=com.cloud.storage.
resource.PremiumSecondaryStorageResource instance=SecStorage sslcopy=false
role=templateProcessor mtu=1500 eth2ip=192.168.1.246 eth2mask=255.255.255.0
gateway=192.168.1.254 eth0ip=169.254.3.96 eth0mask=255.255.0.0
eth1ip=192.168.1.221 eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24
localgw=192.168.1.254 private.network.device=eth1 eth3ip=192.168.1.215
eth3mask=255.255.255.0 storageip=192.168.1.215 storagenetmask=255.255.255.0
storagegateway=192.168.1.254 internaldns1=192.168.1.129 internaldns2=8.8.8.8
dns1=192.168.1.129 dns2=8.8.8.8"",
      ""rebootOnCrash"": false,
      ""enableHA"": false,
      ""limitCpuUse"": false,
      ""enableDynamicallyScaleVm"": false,
      ""vncPassword"": ""95952c26a8b2bfaf"",
      ""params"": {},
      ""uuid"": ""4400c445-b362-4114-9959-410297eb4830"",
      ""disks"": [
        {
          ""data"": {
            ""org.apache.cloudstack.storage.to.VolumeObjectTO"": {
              ""uuid"": ""0d03ce12-d587-400c-ab0e-207d5a7b0e24"",
              ""volumeType"": ""ROOT"",
              ""dataStore"": {
                ""org.apache.cloudstack.storage.to.PrimaryDataStoreTO"": {
                  ""uuid"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
                  ""id"": 1,
                  ""poolType"": ""SMB"",
                  ""host"": ""192.168.1.79"",
                  ""path"":
""/WINPrimary?user=cloudstackadmin&domain=cloud"",
                  ""port"": 445,
                  ""url"":
""SMB://192.168.1.79/WINPrimary?user=cloudstackadmin&domain=cloud/?ROLE=Prim
ary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6daaaea9""
                }
              },
              ""name"": ""ROOT-88"",
              ""size"": 0,
              ""path"": ""0d03ce12-d587-400c-ab0e-207d5a7b0e24"",
              ""volumeId"": 88,
              ""vmName"": ""s-88-VM"",
              ""accountId"": 1,
              ""format"": ""VHD"",
              ""id"": 88,
              ""deviceId"": 0,
              ""hypervisorType"": ""Hyperv""
            }
          },
          ""diskSeq"": 0,
          ""path"": ""0d03ce12-d587-400c-ab0e-207d5a7b0e24"",
          ""type"": ""ROOT"",
          ""_details"": {
            ""managed"": ""false"",
            ""storagePort"": ""445"",
            ""storageHost"": ""192.168.1.79"",
            ""volumeSize"": ""0""
          }
        }
      ],
      ""nics"": [
        {
          ""deviceId"": 2,
          ""networkRateMbps"": -1,
          ""defaultNic"": true,
          ""uuid"": ""88b614de-d611-4e46-94e5-54762d10f1c7"",
          ""ip"": ""192.168.1.246"",
          ""netmask"": ""255.255.255.0"",
          ""gateway"": ""192.168.1.254"",
          ""mac"": ""06:b6:60:00:00:25"",
          ""dns1"": ""192.168.1.129"",
          ""dns2"": ""8.8.8.8"",
          ""broadcastType"": ""Native"",
          ""type"": ""Guest"",
          ""broadcastUri"": ""vlan://untagged"",
          ""isSecurityGroupEnabled"": true,
          ""name"": ""VirtualSwitch""
        },
        {
          ""deviceId"": 0,
          ""networkRateMbps"": -1,
          ""defaultNic"": false,
          ""uuid"": ""fe7ff75d-67d7-4728-afc9-6cc6d4f8760b"",
          ""ip"": ""169.254.3.96"",
          ""netmask"": ""255.255.0.0"",
          ""gateway"": ""169.254.0.1"",
          ""mac"": ""0e:00:a9:fe:03:60"",
          ""broadcastType"": ""LinkLocal"",
          ""type"": ""Control"",
          ""isSecurityGroupEnabled"": false
        },
        {
          ""deviceId"": 1,
          ""networkRateMbps"": -1,
          ""defaultNic"": false,
          ""uuid"": ""246aa3bd-83d6-44ea-98ce-d0ff65b29249"",
          ""ip"": ""192.168.1.221"",
          ""netmask"": ""255.255.255.0"",
          ""gateway"": ""192.168.1.254"",
          ""mac"": ""06:bd:26:00:00:0c"",
          ""broadcastType"": ""Native"",
          ""type"": ""Management"",
          ""isSecurityGroupEnabled"": false,
          ""name"": ""VirtualSwitch""
        },
        {
          ""deviceId"": 3,
          ""networkRateMbps"": -1,
          ""defaultNic"": false,
          ""uuid"": ""bb6dd0ef-ef4c-47a6-a553-3f4463909e73"",
          ""ip"": ""192.168.1.215"",
          ""netmask"": ""255.255.255.0"",
          ""gateway"": ""192.168.1.254"",
          ""mac"": ""06:07:30:00:00:06"",
          ""broadcastType"": ""Native"",
          ""type"": ""Storage"",
          ""isSecurityGroupEnabled"": false,
          ""name"": ""VirtualSwitch""
        }
      ]
    },
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22786","(0)","0","Error","201
4-11-20 16:20:23,034 [19] ERROR HypervResource.HypervResourceController
[e7e264e5-a34a-489f-a606-5e0932e4dab6] - com.cloud.agent.api.StartCommand
fail on exceptionObject reference not set to an instance of an object.
System.NullReferenceException: Object reference not set to an instance of an
object.
   at HypervResource.WmiCallsV2.DeployVirtualMachine(Object jsonObj, String
systemVmIso)
   at HypervResource.HypervResourceController.StartCommand(Object cmd)
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22785","(0)","0","Information
","2014-11-20 16:20:23,034 [19] INFO  HypervResource.WmiCallsV2
[e7e264e5-a34a-489f-a606-5e0932e4dab6] - Created disk
\\HYPERV-SERVER1\root\virtualization\v2:Msvm_StorageAllocationSettingData.In
stanceID=""Microsoft:DDAF7798-A64A-447E-AE63-6E8194C65BCD\\83F8638B-8DCA-415
2-9EDA-2CA8B33039B4\\0\\0\\L"" for VM s-88-VM (GUID
DDAF7798-A64A-447E-AE63-6E8194C65BCD), image
\\192.168.1.79\WINPrimary\0d03ce12-d587-400c-ab0e-207d5a7b0e24.vhd
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22784","(0)","0","Information
","2014-11-20 16:20:23,034 [15] INFO  HypervResource.WmiCallsV2
[6dee4b13-c80c-493e-aba8-528cac178229] - Shutting down of system failed; may
be shutdown integration services are missing
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:23","2014/11/21 8:20:23",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22783","(0)","0","Information
","2014-11-20 16:20:22,659 [15] DEBUG HypervResource.WmiCallsV2
[6dee4b13-c80c-493e-aba8-528cac178229] - Got request to destroy vm v-7-VM
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:22","2014/11/21 8:20:22",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22782","(0)","0","Information
","2014-11-20 16:20:22,659 [15] INFO
HypervResource.HypervResourceController
[6dee4b13-c80c-493e-aba8-528cac178229] - com.cloud.agent.api.StopCommand{
  ""isProxy"": false,
  ""executeInSequence"": false,
  ""checkBeforeCleanup"": false,
  ""vmName"": ""v-7-VM"",
  ""contextMap"": {},
  ""wait"": 0
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:22","2014/11/21 8:20:22",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22781","(0)","0","Information
","2014-11-20 16:20:22,565 [15] INFO
HypervResource.HypervResourceController
[6f5dbb94-77cf-46a9-855f-66ef11a9f0b9] - {
  ""com.cloud.agent.api.StartAnswer"": {
    ""result"": false,
    ""details"": ""com.cloud.agent.api.StartCommand fail on exceptionObject
reference not set to an instance of an object."",
    ""vm"": {
      ""id"": 7,
      ""name"": ""v-7-VM"",
      ""type"": ""ConsoleProxy"",
      ""cpus"": 1,
      ""minSpeed"": 500,
      ""maxSpeed"": 500,
      ""minRam"": 1073741824,
      ""maxRam"": 1073741824,
      ""arch"": ""x86_64"",
      ""os"": ""Debian GNU/Linux 5.0 (64-bit)"",
      ""bootArgs"": "" template=domP type=consoleproxy host=192.168.1.130
port=8250 name=v-7-VM zone=1 pod=1 guid=Proxy.7 proxy_vm=7
disable_rp_filter=true eth2ip=192.168.1.248 eth2mask=255.255.255.0
gateway=192.168.1.254 eth0ip=169.254.0.93 eth0mask=255.255.0.0
eth1ip=192.168.1.216 eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24
localgw=192.168.1.254 internaldns1=192.168.1.129 internaldns2=8.8.8.8
dns1=192.168.1.129 dns2=8.8.8.8"",
      ""rebootOnCrash"": false,
      ""enableHA"": false,
      ""limitCpuUse"": false,
      ""enableDynamicallyScaleVm"": false,
      ""vncPassword"": ""31dd1c6ec4245b64"",
      ""params"": {},
      ""uuid"": ""4924936e-c6ca-4ebf-aea4-517b3ca44127"",
      ""disks"": [
        {
          ""data"": {
            ""org.apache.cloudstack.storage.to.VolumeObjectTO"": {
              ""uuid"": ""07e1889d-dc71-44e6-832a-12d1701fdf19"",
              ""volumeType"": ""ROOT"",
              ""dataStore"": {
                ""org.apache.cloudstack.storage.to.PrimaryDataStoreTO"": {
                  ""uuid"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
                  ""id"": 1,
                  ""poolType"": ""SMB"",
                  ""host"": ""192.168.1.79"",
                  ""path"":
""/WINPrimary?user=cloudstackadmin&domain=cloud"",
                  ""port"": 445,
                  ""url"":
""SMB://192.168.1.79/WINPrimary?user=cloudstackadmin&domain=cloud/?ROLE=Prim
ary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6daaaea9""
                }
              },
              ""name"": ""ROOT-7"",
              ""size"": 0,
              ""path"": ""07e1889d-dc71-44e6-832a-12d1701fdf19"",
              ""volumeId"": 7,
              ""vmName"": ""v-7-VM"",
              ""accountId"": 1,
              ""format"": ""VHD"",
              ""id"": 7,
              ""deviceId"": 0,
              ""hypervisorType"": ""Hyperv""
            }
          },
          ""diskSeq"": 0,
          ""path"": ""07e1889d-dc71-44e6-832a-12d1701fdf19"",
          ""type"": ""ROOT"",
          ""_details"": {
            ""managed"": ""false"",
            ""storagePort"": ""445"",
            ""storageHost"": ""192.168.1.79"",
            ""volumeSize"": ""0""
          }
        }
      ],
      ""nics"": [
        {
          ""deviceId"": 2,
          ""networkRateMbps"": -1,
          ""defaultNic"": true,
          ""uuid"": ""88b614de-d611-4e46-94e5-54762d10f1c7"",
          ""ip"": ""192.168.1.248"",
          ""netmask"": ""255.255.255.0"",
          ""gateway"": ""192.168.1.254"",
          ""mac"": ""06:74:b4:00:00:27"",
          ""dns1"": ""192.168.1.129"",
          ""dns2"": ""8.8.8.8"",
          ""broadcastType"": ""Native"",
          ""type"": ""Guest"",
          ""broadcastUri"": ""vlan://untagged"",
          ""isSecurityGroupEnabled"": true,
          ""name"": ""VirtualSwitch""
        },
        {
          ""deviceId"": 0,
          ""networkRateMbps"": -1,
          ""defaultNic"": false,
          ""uuid"": ""fe7ff75d-67d7-4728-afc9-6cc6d4f8760b"",
          ""ip"": ""169.254.0.93"",
          ""netmask"": ""255.255.0.0"",
          ""gateway"": ""169.254.0.1"",
          ""mac"": ""0e:00:a9:fe:00:5d"",
          ""broadcastType"": ""LinkLocal"",
          ""type"": ""Control"",
          ""isSecurityGroupEnabled"": false
        },
        {
          ""deviceId"": 1,
          ""networkRateMbps"": -1,
          ""defaultNic"": false,
          ""uuid"": ""246aa3bd-83d6-44ea-98ce-d0ff65b29249"",
          ""ip"": ""192.168.1.216"",
          ""netmask"": ""255.255.255.0"",
          ""gateway"": ""192.168.1.254"",
          ""mac"": ""06:19:ec:00:00:07"",
          ""broadcastType"": ""Native"",
          ""type"": ""Management"",
          ""isSecurityGroupEnabled"": false,
          ""name"": ""VirtualSwitch""
        }
      ]
    },
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:22","2014/11/21 8:20:22",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22780","(0)","0","Error","201
4-11-20 16:20:22,565 [15] ERROR HypervResource.HypervResourceController
[6f5dbb94-77cf-46a9-855f-66ef11a9f0b9] - com.cloud.agent.api.StartCommand
fail on exceptionObject reference not set to an instance of an object.
System.NullReferenceException: Object reference not set to an instance of an
object.
   at HypervResource.WmiCallsV2.DeployVirtualMachine(Object jsonObj, String
systemVmIso)
   at HypervResource.HypervResourceController.StartCommand(Object cmd)
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:22","2014/11/21 8:20:22",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22779","(0)","0","Information
","2014-11-20 16:20:22,565 [15] INFO  HypervResource.WmiCallsV2
[6f5dbb94-77cf-46a9-855f-66ef11a9f0b9] - Created disk
\\HYPERV-SERVER1\root\virtualization\v2:Msvm_StorageAllocationSettingData.In
stanceID=""Microsoft:8B66F183-0829-4FE5-98AC-FC8594186F4A\\83F8638B-8DCA-415
2-9EDA-2CA8B33039B4\\0\\0\\L"" for VM v-7-VM (GUID
8B66F183-0829-4FE5-98AC-FC8594186F4A), image
\\192.168.1.79\WINPrimary\07e1889d-dc71-44e6-832a-12d1701fdf19.vhd
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:22","2014/11/21 8:20:22",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22778","(0)","0","Information
","2014-11-20 16:20:22,190 [19] DEBUG HypervResource.WmiCallsV2
[e7e264e5-a34a-489f-a606-5e0932e4dab6] - New disk drive type
Microsoft:Hyper-V:Synthetic Disk Drive WMI path is
\\HYPERV-SERVER1\root\virtualization\v2:Msvm_ResourceAllocationSettingData.I
nstanceID=""Microsoft:DDAF7798-A64A-447E-AE63-6E8194C65BCD\\83F8638B-8DCA-41
52-9EDA-2CA8B33039B4\\0\\0\\D""s
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:22","2014/11/21 8:20:22",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22777","(0)","0","Information
","2014-11-20 16:20:22,081 [19] DEBUG HypervResource.WmiCallsV2
[e7e264e5-a34a-489f-a606-5e0932e4dab6] - Creating disk drive type
Microsoft:Hyper-V:Synthetic Disk Drive, parent IDE controller is
\\HYPERV-SERVER1\root\virtualization\v2:Msvm_ResourceAllocationSettingData.I
nstanceID=""Microsoft:DDAF7798-A64A-447E-AE63-6E8194C65BCD\\83F8638B-8DCA-41
52-9EDA-2CA8B33039B4\\0"" and address on controller is 0
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:22","2014/11/21 8:20:22",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22776","(0)","0","Information
","2014-11-20 16:20:22,065 [15] DEBUG HypervResource.WmiCallsV2
[6f5dbb94-77cf-46a9-855f-66ef11a9f0b9] - New disk drive type
Microsoft:Hyper-V:Synthetic Disk Drive WMI path is
\\HYPERV-SERVER1\root\virtualization\v2:Msvm_ResourceAllocationSettingData.I
nstanceID=""Microsoft:8B66F183-0829-4FE5-98AC-FC8594186F4A\\83F8638B-8DCA-41
52-9EDA-2CA8B33039B4\\0\\0\\D""s
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:22","2014/11/21 8:20:22",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22775","(0)","0","Information
","2014-11-20 16:20:21,987 [15] DEBUG HypervResource.WmiCallsV2
[6f5dbb94-77cf-46a9-855f-66ef11a9f0b9] - Creating disk drive type
Microsoft:Hyper-V:Synthetic Disk Drive, parent IDE controller is
\\HYPERV-SERVER1\root\virtualization\v2:Msvm_ResourceAllocationSettingData.I
nstanceID=""Microsoft:8B66F183-0829-4FE5-98AC-FC8594186F4A\\83F8638B-8DCA-41
52-9EDA-2CA8B33039B4\\0"" and address on controller is 0
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:21","2014/11/21 8:20:21",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22774","(0)","0","Information
","2014-11-20 16:20:21,706 [19] DEBUG HypervResource.WmiCallsV2
[e7e264e5-a34a-489f-a606-5e0932e4dab6] - Creating DISK for VM s-88-VM (GUID
DDAF7798-A64A-447E-AE63-6E8194C65BCD) by attaching
\\192.168.1.79\WINPrimary\0d03ce12-d587-400c-ab0e-207d5a7b0e24.vhd
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:21","2014/11/21 8:20:21",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22773","(0)","0","Information
","2014-11-20 16:20:21,690 [19] DEBUG HypervResource.WmiCallsV2
[e7e264e5-a34a-489f-a606-5e0932e4dab6] - Create disk type
Microsoft:Hyper-V:Synthetic Disk Drive (Named: ROOT-88), on vm s-88-VM ,
inserting
disk\\192.168.1.79\WINPrimary\0d03ce12-d587-400c-ab0e-207d5a7b0e24.vhd
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:21","2014/11/21 8:20:21",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22772","(0)","0","Information
","2014-11-20 16:20:21,690 [19] DEBUG HypervResource.WmiCallsV2
[e7e264e5-a34a-489f-a606-5e0932e4dab6] - Going to create s-88-VM with
attached voluem ROOT-88 at
\\192.168.1.79\WINPrimary\0d03ce12-d587-400c-ab0e-207d5a7b0e24.vhd
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:21","2014/11/21 8:20:21",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22771","(0)","0","Information
","2014-11-20 16:20:21,690 [19] DEBUG HypervResource.WmiCallsV2
[e7e264e5-a34a-489f-a606-5e0932e4dab6] - New controller type
Microsoft:Hyper-V:Synthetic SCSI Controller WMI path is
\\HYPERV-SERVER1\root\virtualization\v2:Msvm_ResourceAllocationSettingData.I
nstanceID=""Microsoft:DDAF7798-A64A-447E-AE63-6E8194C65BCD\\84A8DE65-1D19-4D
C9-B003-AFDFB6B04FFE\\0""s
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:21","2014/11/21 8:20:21",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22770","(0)","0","Information
","2014-11-20 16:20:21,628 [15] DEBUG HypervResource.WmiCallsV2
[6f5dbb94-77cf-46a9-855f-66ef11a9f0b9] - Creating DISK for VM v-7-VM (GUID
8B66F183-0829-4FE5-98AC-FC8594186F4A) by attaching
\\192.168.1.79\WINPrimary\07e1889d-dc71-44e6-832a-12d1701fdf19.vhd
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:21","2014/11/21 8:20:21",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22769","(0)","0","Information
","2014-11-20 16:20:21,628 [15] DEBUG HypervResource.WmiCallsV2
[6f5dbb94-77cf-46a9-855f-66ef11a9f0b9] - Create disk type
Microsoft:Hyper-V:Synthetic Disk Drive (Named: ROOT-7), on vm v-7-VM ,
inserting
disk\\192.168.1.79\WINPrimary\07e1889d-dc71-44e6-832a-12d1701fdf19.vhd
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:21","2014/11/21 8:20:21",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22768","(0)","0","Information
","2014-11-20 16:20:21,628 [15] DEBUG HypervResource.WmiCallsV2
[6f5dbb94-77cf-46a9-855f-66ef11a9f0b9] - Going to create v-7-VM with
attached voluem ROOT-7 at
\\192.168.1.79\WINPrimary\07e1889d-dc71-44e6-832a-12d1701fdf19.vhd
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:21","2014/11/21 8:20:21",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22767","(0)","0","Information
","2014-11-20 16:20:21,628 [15] DEBUG HypervResource.WmiCallsV2
[6f5dbb94-77cf-46a9-855f-66ef11a9f0b9] - New controller type
Microsoft:Hyper-V:Synthetic SCSI Controller WMI path is
\\HYPERV-SERVER1\root\virtualization\v2:Msvm_ResourceAllocationSettingData.I
nstanceID=""Microsoft:8B66F183-0829-4FE5-98AC-FC8594186F4A\\0563D614-A062-4C
B6-9907-F8846D4C25A9\\0""s
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:21","2014/11/21 8:20:21",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22766","(0)","0","Information
","2014-11-20 16:20:21,502 [19] DEBUG HypervResource.WmiCallsV2
[e7e264e5-a34a-489f-a606-5e0932e4dab6] - Resources for vm s-88-VM: 512 MB
memory, 1 vcpus
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:21","2014/11/21 8:20:21",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22765","(0)","0","Information
","2014-11-20 16:20:21,502 [19] INFO  HypervResource.WmiCallsV2
[e7e264e5-a34a-489f-a606-5e0932e4dab6] - VM with display name s-88-VM has
GUID DDAF7798-A64A-447E-AE63-6E8194C65BCD

,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:21","2014/11/21 8:20:21",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22764","(0)","0","Information
","2014-11-20 16:20:21,439 [15] DEBUG HypervResource.WmiCallsV2
[6f5dbb94-77cf-46a9-855f-66ef11a9f0b9] - Resources for vm v-7-VM: 1024 MB
memory, 1 vcpus
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:21","2014/11/21 8:20:21",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22763","(0)","0","Information
","2014-11-20 16:20:21,439 [15] INFO  HypervResource.WmiCallsV2
[6f5dbb94-77cf-46a9-855f-66ef11a9f0b9] - VM with display name v-7-VM has
GUID 8B66F183-0829-4FE5-98AC-FC8594186F4A
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:21","2014/11/21 8:20:21",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22762","(0)","0","Information
","2014-11-20 16:20:20,888 [19] DEBUG HypervResource.WmiCallsV2
[e7e264e5-a34a-489f-a606-5e0932e4dab6] - Created VM s-88-VM
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:20","2014/11/21 8:20:20",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22761","(0)","0","Information
","2014-11-20 16:20:20,873 [15] DEBUG HypervResource.WmiCallsV2
[6f5dbb94-77cf-46a9-855f-66ef11a9f0b9] - Created VM v-7-VM
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:20","2014/11/21 8:20:20",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22760","(0)","0","Information
","2014-11-20 16:20:20,732 [19] DEBUG HypervResource.WmiCallsV2
[e7e264e5-a34a-489f-a606-5e0932e4dab6] - Going ahead with create VM s-88-VM,
1 vcpus, 512MB RAM
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:20","2014/11/21 8:20:20",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22759","(0)","0","Information
","2014-11-20 16:20:20,717 [15] DEBUG HypervResource.WmiCallsV2
[6f5dbb94-77cf-46a9-855f-66ef11a9f0b9] - Going ahead with create VM v-7-VM,
1 vcpus, 1024MB RAM
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:20","2014/11/21 8:20:20",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22758","(0)","0","Information
","2014-11-20 16:20:20,717 [19] INFO
HypervResource.HypervResourceController
[e7e264e5-a34a-489f-a606-5e0932e4dab6] - com.cloud.agent.api.StartCommand{
  ""vm"": {
    ""id"": 88,
    ""name"": ""s-88-VM"",
    ""type"": ""SecondaryStorageVm"",
    ""cpus"": 1,
    ""minSpeed"": 500,
    ""maxSpeed"": 500,
    ""minRam"": 536870912,
    ""maxRam"": 536870912,
    ""arch"": ""x86_64"",
    ""os"": ""Debian GNU/Linux 5.0 (64-bit)"",
    ""bootArgs"": "" template=domP type=secstorage host=192.168.1.130
port=8250 name=s-88-VM zone=1 pod=1 guid=s-88-VM resource=com.cloud.storage.
resource.PremiumSecondaryStorageResource instance=SecStorage sslcopy=false
role=templateProcessor mtu=1500 eth2ip=192.168.1.246 eth2mask=255.255.255.0
gateway=192.168.1.254 eth0ip=169.254.3.96 eth0mask=255.255.0.0
eth1ip=192.168.1.221 eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24
localgw=192.168.1.254 private.network.device=eth1 eth3ip=192.168.1.215
eth3mask=255.255.255.0 storageip=192.168.1.215 storagenetmask=255.255.255.0
storagegateway=192.168.1.254 internaldns1=192.168.1.129 internaldns2=8.8.8.8
dns1=192.168.1.129 dns2=8.8.8.8"",
    ""rebootOnCrash"": false,
    ""enableHA"": false,
    ""limitCpuUse"": false,
    ""enableDynamicallyScaleVm"": false,
    ""vncPassword"": ""95952c26a8b2bfaf"",
    ""params"": {},
    ""uuid"": ""4400c445-b362-4114-9959-410297eb4830"",
    ""disks"": [
      {
        ""data"": {
          ""org.apache.cloudstack.storage.to.VolumeObjectTO"": {
            ""uuid"": ""0d03ce12-d587-400c-ab0e-207d5a7b0e24"",
            ""volumeType"": ""ROOT"",
            ""dataStore"": {
              ""org.apache.cloudstack.storage.to.PrimaryDataStoreTO"": {
                ""uuid"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
                ""id"": 1,
                ""poolType"": ""SMB"",
                ""host"": ""192.168.1.79"",
                ""path"": ""/WINPrimary?user=cloudstackadmin&domain=cloud"",
                ""port"": 445,
                ""url"":
""SMB://192.168.1.79/WINPrimary?user=cloudstackadmin&domain=cloud/?ROLE=Prim
ary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6daaaea9""
              }
            },
            ""name"": ""ROOT-88"",
            ""size"": 0,
            ""path"": ""0d03ce12-d587-400c-ab0e-207d5a7b0e24"",
            ""volumeId"": 88,
            ""vmName"": ""s-88-VM"",
            ""accountId"": 1,
            ""format"": ""VHD"",
            ""id"": 88,
            ""deviceId"": 0,
            ""hypervisorType"": ""Hyperv""
          }
        },
        ""diskSeq"": 0,
        ""path"": ""0d03ce12-d587-400c-ab0e-207d5a7b0e24"",
        ""type"": ""ROOT"",
        ""_details"": {
          ""managed"": ""false"",
          ""storagePort"": ""445"",
          ""storageHost"": ""192.168.1.79"",
          ""volumeSize"": ""0""
        }
      }
    ],
    ""nics"": [
      {
        ""deviceId"": 2,
        ""networkRateMbps"": -1,
        ""defaultNic"": true,
        ""uuid"": ""88b614de-d611-4e46-94e5-54762d10f1c7"",
        ""ip"": ""192.168.1.246"",
        ""netmask"": ""255.255.255.0"",
        ""gateway"": ""192.168.1.254"",
        ""mac"": ""06:b6:60:00:00:25"",
        ""dns1"": ""192.168.1.129"",
        ""dns2"": ""8.8.8.8"",
        ""broadcastType"": ""Native"",
        ""type"": ""Guest"",
        ""broadcastUri"": ""vlan://untagged"",
        ""isSecurityGroupEnabled"": true,
        ""name"": ""VirtualSwitch""
      },
      {
        ""deviceId"": 0,
        ""networkRateMbps"": -1,
        ""defaultNic"": false,
        ""uuid"": ""fe7ff75d-67d7-4728-afc9-6cc6d4f8760b"",
        ""ip"": ""169.254.3.96"",
        ""netmask"": ""255.255.0.0"",
        ""gateway"": ""169.254.0.1"",
        ""mac"": ""0e:00:a9:fe:03:60"",
        ""broadcastType"": ""LinkLocal"",
        ""type"": ""Control"",
        ""isSecurityGroupEnabled"": false
      },
      {
        ""deviceId"": 1,
        ""networkRateMbps"": -1,
        ""defaultNic"": false,
        ""uuid"": ""246aa3bd-83d6-44ea-98ce-d0ff65b29249"",
        ""ip"": ""192.168.1.221"",
        ""netmask"": ""255.255.255.0"",
        ""gateway"": ""192.168.1.254"",
        ""mac"": ""06:bd:26:00:00:0c"",
        ""broadcastType"": ""Native"",
        ""type"": ""Management"",
        ""isSecurityGroupEnabled"": false,
        ""name"": ""VirtualSwitch""
      },
      {
        ""deviceId"": 3,
        ""networkRateMbps"": -1,
        ""defaultNic"": false,
        ""uuid"": ""bb6dd0ef-ef4c-47a6-a553-3f4463909e73"",
        ""ip"": ""192.168.1.215"",
        ""netmask"": ""255.255.255.0"",
        ""gateway"": ""192.168.1.254"",
        ""mac"": ""06:07:30:00:00:06"",
        ""broadcastType"": ""Native"",
        ""type"": ""Storage"",
        ""isSecurityGroupEnabled"": false,
        ""name"": ""VirtualSwitch""
      }
    ]
  },
  ""hostIp"": ""192.168.1.78"",
  ""executeInSequence"": false,
  ""secondaryStorage"":
""cifs://192.168.1.79/SWINSecondary?user=cloudstackadmin&domain=cloud"",
  ""contextMap"": {},
  ""wait"": 0
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:20","2014/11/21 8:20:20",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22757","(0)","0","Information
","2014-11-20 16:20:20,701 [15] INFO
HypervResource.HypervResourceController
[6f5dbb94-77cf-46a9-855f-66ef11a9f0b9] - com.cloud.agent.api.StartCommand{
  ""vm"": {
    ""id"": 7,
    ""name"": ""v-7-VM"",
    ""type"": ""ConsoleProxy"",
    ""cpus"": 1,
    ""minSpeed"": 500,
    ""maxSpeed"": 500,
    ""minRam"": 1073741824,
    ""maxRam"": 1073741824,
    ""arch"": ""x86_64"",
    ""os"": ""Debian GNU/Linux 5.0 (64-bit)"",
    ""bootArgs"": "" template=domP type=consoleproxy host=192.168.1.130
port=8250 name=v-7-VM zone=1 pod=1 guid=Proxy.7 proxy_vm=7
disable_rp_filter=true eth2ip=192.168.1.248 eth2mask=255.255.255.0
gateway=192.168.1.254 eth0ip=169.254.0.93 eth0mask=255.255.0.0
eth1ip=192.168.1.216 eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24
localgw=192.168.1.254 internaldns1=192.168.1.129 internaldns2=8.8.8.8
dns1=192.168.1.129 dns2=8.8.8.8"",
    ""rebootOnCrash"": false,
    ""enableHA"": false,
    ""limitCpuUse"": false,
    ""enableDynamicallyScaleVm"": false,
    ""vncPassword"": ""31dd1c6ec4245b64"",
    ""params"": {},
    ""uuid"": ""4924936e-c6ca-4ebf-aea4-517b3ca44127"",
    ""disks"": [
      {
        ""data"": {
          ""org.apache.cloudstack.storage.to.VolumeObjectTO"": {
            ""uuid"": ""07e1889d-dc71-44e6-832a-12d1701fdf19"",
            ""volumeType"": ""ROOT"",
            ""dataStore"": {
              ""org.apache.cloudstack.storage.to.PrimaryDataStoreTO"": {
                ""uuid"": ""b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"",
                ""id"": 1,
                ""poolType"": ""SMB"",
                ""host"": ""192.168.1.79"",
                ""path"": ""/WINPrimary?user=cloudstackadmin&domain=cloud"",
                ""port"": 445,
                ""url"":
""SMB://192.168.1.79/WINPrimary?user=cloudstackadmin&domain=cloud/?ROLE=Prim
ary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6daaaea9""
              }
            },
            ""name"": ""ROOT-7"",
            ""size"": 0,
            ""path"": ""07e1889d-dc71-44e6-832a-12d1701fdf19"",
            ""volumeId"": 7,
            ""vmName"": ""v-7-VM"",
            ""accountId"": 1,
            ""format"": ""VHD"",
            ""id"": 7,
            ""deviceId"": 0,
            ""hypervisorType"": ""Hyperv""
          }
        },
        ""diskSeq"": 0,
        ""path"": ""07e1889d-dc71-44e6-832a-12d1701fdf19"",
        ""type"": ""ROOT"",
        ""_details"": {
          ""managed"": ""false"",
          ""storagePort"": ""445"",
          ""storageHost"": ""192.168.1.79"",
          ""volumeSize"": ""0""
        }
      }
    ],
    ""nics"": [
      {
        ""deviceId"": 2,
        ""networkRateMbps"": -1,
        ""defaultNic"": true,
        ""uuid"": ""88b614de-d611-4e46-94e5-54762d10f1c7"",
        ""ip"": ""192.168.1.248"",
        ""netmask"": ""255.255.255.0"",
        ""gateway"": ""192.168.1.254"",
        ""mac"": ""06:74:b4:00:00:27"",
        ""dns1"": ""192.168.1.129"",
        ""dns2"": ""8.8.8.8"",
        ""broadcastType"": ""Native"",
        ""type"": ""Guest"",
        ""broadcastUri"": ""vlan://untagged"",
        ""isSecurityGroupEnabled"": true,
        ""name"": ""VirtualSwitch""
      },
      {
        ""deviceId"": 0,
        ""networkRateMbps"": -1,
        ""defaultNic"": false,
        ""uuid"": ""fe7ff75d-67d7-4728-afc9-6cc6d4f8760b"",
        ""ip"": ""169.254.0.93"",
        ""netmask"": ""255.255.0.0"",
        ""gateway"": ""169.254.0.1"",
        ""mac"": ""0e:00:a9:fe:00:5d"",
        ""broadcastType"": ""LinkLocal"",
        ""type"": ""Control"",
        ""isSecurityGroupEnabled"": false
      },
      {
        ""deviceId"": 1,
        ""networkRateMbps"": -1,
        ""defaultNic"": false,
        ""uuid"": ""246aa3bd-83d6-44ea-98ce-d0ff65b29249"",
        ""ip"": ""192.168.1.216"",
        ""netmask"": ""255.255.255.0"",
        ""gateway"": ""192.168.1.254"",
        ""mac"": ""06:19:ec:00:00:07"",
        ""broadcastType"": ""Native"",
        ""type"": ""Management"",
        ""isSecurityGroupEnabled"": false,
        ""name"": ""VirtualSwitch""
      }
    ]
  },
  ""hostIp"": ""192.168.1.78"",
  ""executeInSequence"": false,
  ""secondaryStorage"":
""cifs://192.168.1.79/SWINSecondary?user=cloudstackadmin&domain=cloud"",
  ""contextMap"": {},
  ""wait"": 0
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:20","2014/11/21 8:20:20",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22756","(0)","0","Information
","2014-11-20 16:20:13,638 [15] INFO
HypervResource.HypervResourceController
[70fbbdb5-6c81-4249-9df8-24ed0557d243] - {
  ""com.cloud.agent.api.GetHostStatsAnswer"": {
    ""result"": true,
    ""hostStats"": {
      ""hostId"": 1,
      ""entityType"": ""host"",
      ""cpuUtilization"": 6.0,
      ""networkReadKBs"": 545945126.0,
      ""networkWriteKBs"": 4701571287.0,
      ""totalMemoryKBs"": 134138344.0,
      ""freeMemoryKBs"": 127536248.0
    },
    ""details"": null,
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:13","2014/11/21 8:20:13",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22755","(0)","0","Information
","2014-11-20 16:20:13,247 [15] INFO
HypervResource.HypervResourceController
[70fbbdb5-6c81-4249-9df8-24ed0557d243] -
com.cloud.agent.api.GetHostStatsCommand{
  ""hostGuid"": ""3be2f4fe-f3c7-33c1-8127-696c45258534-HypervResource"",
  ""hostName"": ""192.168.1.78"",
  ""hostId"": 1,
  ""contextMap"": {},
  ""wait"": 0
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:13","2014/11/21 8:20:13",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22754","(0)","0","Information
","2014-11-20 16:20:13,107 [15] INFO
HypervResource.HypervResourceController
[5db730b5-82d9-441e-bd9a-1985b2d56ef3] - {
  ""com.cloud.agent.api.CheckHealthAnswer"": {
    ""result"": true,
    ""details"": ""resource is alive"",
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:13","2014/11/21 8:20:13",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22753","(0)","0","Information
","2014-11-20 16:20:13,107 [15] INFO
HypervResource.HypervResourceController
[5db730b5-82d9-441e-bd9a-1985b2d56ef3] -
com.cloud.agent.api.CheckHealthCommand{
  ""contextMap"": {},
  ""wait"": 50
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:13","2014/11/21 8:20:13",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22752","(0)","0","Information
","2014-11-20 16:20:02,019 [15] INFO
HypervResource.HypervResourceController
[d9761e71-b309-4355-a805-e774b17f78ba] - {
  ""com.cloud.agent.api.StopAnswer"": {
    ""result"": true,
    ""details"": null,
    ""vm"": null,
    ""contextMap"": {}
  }
}
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:02","2014/11/21 8:20:02",,,
0,"hyperv-server1.cloud.priv","System.Byte[]","22751","(0)","0","Information
","2014-11-20 16:20:02,004 [15] DEBUG HypervResource.WmiCallsV2
[d9761e71-b309-4355-a805-e774b17f78ba] - WMI job succeeded: Destroying
Virtual Machine, Elapsed=00:00:00.0400530
,CloudStack Hyper-V Agent","System.String[]","0","2014/11/21
8:20:02","2014/11/21 8:20:02",,,

Khmu

-----邮件原件-----
发件人: Anshul Gangwar [mailto:anshul.gangwar@citrix.com]
发送时间: 2014年11月20日 17:15
收件人: dev@cloudstack.apache.org
主题: RE: hyperv ssvm start failed

Also attach the Hyper-V Agent logs. You can export logs to a file and paste
here.

Log around the error  are also important.
________________________________________
From: 穆凯辉 [khmu@landhightech.com]
Sent: Thursday, November 20, 2014 2:23 PM
To: dev@cloudstack.apache.org
Subject: 答复: hyperv ssvm start failed

The cloudstack log is as follows:


2014-11-20 14:53:10,758 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-3:ctx-c859f450) POST request to
https://secure-web.cisco.com/1oflyd9LmCGMGuT8CDjlfCeNVsFVZvVl2IfjYTxFJtSjyFD
Nf1PvTn8W09yp5CAaG3ZYxhDIAWPOzwbyZYssgKBlz_x3-IX8tcGlrCq0M-kliVTicpGlybr92nG
Bqyi_UiS5cuiJd6qhHRewHJ_Rb-QYrV4jBwqUIjyPF_qJfzi4/https%3A%2F%2F192.168.1.78
%3A8250%2Fapi%2FHypervResource%2Forg.apache.cloudstack.storage.c
ommand.CopyCommand with contents
{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"origUrl":"ht
tp://cloudstack.apt-get.eu/systemvm/4.4/systemvm64template-4.4.0-6-hyperv.vh
d.bz2","uuid":"12778b5a-7080-11e4-a46b-000c299522c6","id":9,"format":"VHD","
accountId":1,"checksum":"1c0bdb131e3b7ee753d014961fdd6eb0","hvm":false,"disp
layText":"SystemVM Template
(HyperV)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataSto
reTO":{"uuid":"b48e8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"poolType":"SMB"
,"host":"192.168.1.79","path":"/WINPrimary?user=cloudstackadmin&domain=cloud
","port":445,"url":"SMB://192.168.1.79/WINPrimary?user=cloudstackadmin&domai
n=cloud/?ROLE=Primary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"}},"nam
e":"routing-9","hypervisorType":"Hyperv"}},"destTO":{"org.apache.cloudstack.
storage.to.VolumeObjectTO":{"uuid":"bab80dd6-16da-4713-979d-c69b91d7eea6","v
olumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryData
StoreTO":{"uuid":"b48e8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"poolType":"S
MB","host":"192.168.1.79","path":"/WINPrimary?user=cloudstackadmin&domain=cl
oud","port":445,"url":"SMB://192.168.1.79/WINPrimary?user=cloudstackadmin&do
main=cloud/?ROLE=Primary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"}},"
name":"ROOT-2","size":0,"volumeId":2,"vmName":"v-2-VM","accountId":1,"format
":"VHDX","id":2,"deviceId":0,"hypervisorType":"Hyperv"}},"executeInSequence"
:false,"options":{},"contextMap":{},"wait":0}
2014-11-20 14:53:10,772 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-3:ctx-c859f450) Sending cmd to
https://secure-web.cisco.com/1oflyd9LmCGMGuT8CDjlfCeNVsFVZvVl2IfjYTxFJtSjyFD
Nf1PvTn8W09yp5CAaG3ZYxhDIAWPOzwbyZYssgKBlz_x3-IX8tcGlrCq0M-kliVTicpGlybr92nG
Bqyi_UiS5cuiJd6qhHRewHJ_Rb-QYrV4jBwqUIjyPF_qJfzi4/https%3A%2F%2F192.168.1.78
%3A8250%2Fapi%2FHypervResource%2Forg.apache.cloudstack.storage.c
ommand.CopyCommand cmd
data:{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"origUrl
":"http://cloudstack.apt-get.eu/systemvm/4.4/systemvm64template-4.4.0-6-hype
rv.vhd.bz2","uuid":"12778b5a-7080-11e4-a46b-000c299522c6","id":9,"format":"V
HD","accountId":1,"checksum":"1c0bdb131e3b7ee753d014961fdd6eb0","hvm":false,
"displayText":"SystemVM Template
(HyperV)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataSto
reTO":{"uuid":"b48e8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"poolType":"SMB"
,"host":"192.168.1.79","path":"/WINPrimary?user=cloudstackadmin&domain=cloud
","port":445,"url":"SMB://192.168.1.79/WINPrimary?user=cloudstackadmin&domai
n=cloud/?ROLE=Primary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"}},"nam
e":"routing-9","hypervisorType":"Hyperv"}},"destTO":{"org.apache.cloudstack.
storage.to.VolumeObjectTO":{"uuid":"bab80dd6-16da-4713-979d-c69b91d7eea6","v
olumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryData
StoreTO":{"uuid":"b48e8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"poolType":"S
MB","host":"192.168.1.79","path":"/WINPrimary?user=cloudstackadmin&domain=cl
oud","port":445,"url":"SMB://192.168.1.79/WINPrimary?user=cloudstackadmin&do
main=cloud/?ROLE=Primary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"}},"
name":"ROOT-2","size":0,"volumeId":2,"vmName":"v-2-VM","accountId":1,"format
":"VHDX","id":2,"deviceId":0,"hypervisorType":"Hyperv"}},"executeInSequence"
:false,"options":{},"contextMap":{},"wait":0}
2014-11-20 14:53:20,838 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-5:ctx-0427c434) POST response is
[{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":true,"deta
ils":null,"newData":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"dat
aStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b48e
8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"poolType":"SMB","host":"192.168.1.
79","path":"/WINPrimary?user=cloudstackadmin&domain=cloud","port":445,"url":
"SMB://192.168.1.79/WINPrimary?user=cloudstackadmin&domain=cloud/?ROLE=Prima
ry&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"}},"format":"VHD","name":"
ROOT-1","path":"f09879e9-fe76-4c2c-b051-164867c4099a","uuid":"f09879e9-fe76-
4c2c-b051-164867c4099a","size":0,"primaryDataStore":{"host":"192.168.1.79","
uri":"cifs://192.168.1.79/WINPrimary?user=cloudstackadmin&domain=cloud","_ro
le":null,"Path":"\\192.168.1.79/WINPrimary","UncPath":"\\192.168.1.79/WINPri
mary","User":"cloudstackadmin",,"Domain":"cloud","isLocal":false},"nfsDataSt
ore":null,"FullFileName":"\\192.168.1.79\WINPrimary\f09879e9-fe76-4c2c-b051-
164867c4099a.vhd"}},"contextMap":{}}}]
2014-11-20 14:53:20,842 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-3:ctx-c859f450) POST response is
[{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":true,"deta
ils":null,"newData":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"dat
aStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b48e
8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"poolType":"SMB","host":"192.168.1.
79","path":"/WINPrimary?user=cloudstackadmin&domain=cloud","port":445,"url":
"SMB://192.168.1.79/WINPrimary?user=cloudstackadmin&domain=cloud/?ROLE=Prima
ry&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"}},"format":"VHD","name":"
ROOT-2","path":"bab80dd6-16da-4713-979d-c69b91d7eea6","uuid":"bab80dd6-16da-
4713-979d-c69b91d7eea6","size":0,"primaryDataStore":{"host":"192.168.1.79","
uri":"cifs://192.168.1.79/WINPrimary?user=cloudstackadmin&domain=cloud","_ro
le":null,"Path":"\\192.168.1.79/WINPrimary","UncPath":"\\192.168.1.79/WINPri
mary","User":"cloudstackadmin",,"Domain":"cloud","isLocal":false},"nfsDataSt
ore":null,"FullFileName":"\\192.168.1.79\WINPrimary\bab80dd6-16da-4713-979d-
c69b91d7eea6.vhd"}},"contextMap":{}}}]
2014-11-20 14:53:20,861 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-5:ctx-0427c434) executeRequest received response
[Lcom.cloud.agent.api.Answer;@6addf124
2014-11-20 14:53:20,861 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-5:ctx-0427c434) Seq 1-425590164786511882: Response Received:
2014-11-20 14:53:20,863 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-3:ctx-c859f450) executeRequest received response
[Lcom.cloud.agent.api.Answer;@65a165fd
2014-11-20 14:53:20,863 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-3:ctx-c859f450) Seq 1-425590164786511883: Response Received:
2014-11-20 14:53:20,871 DEBUG [c.c.a.t.Request] (DirectAgent-5:ctx-0427c434)
Seq 1-425590164786511882: Processing:  { Ans: , MgmtId: 52237247174, via: 1,
Ver: v1, Flags: 10,
[{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apa
che.cloudstack.storage.to.VolumeObjectTO":{"uuid":"f09879e9-fe76-4c2c-b051-1
64867c4099a","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStore
TO":{"uuid":"b48e8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"poolType":"SMB","
host":"192.168.1.79","path":"/WINPrimary?user=cloudstackadmin&domain=cloud",
"port":445,"url":"SMB://192.168.1.79/WINPrimary?user=cloudstackadmin&domain=
cloud/?ROLE=Primary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"}},"name"
:"ROOT-1","size":0,"path":"f09879e9-fe76-4c2c-b051-164867c4099a","accountId"
:0,"format":"VHD","id":0}},"result":true,"wait":0}}] }
2014-11-20 14:53:20,871 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Seq
1-425590164786511882: Received:  { Ans: , MgmtId: 52237247174, via: 1, Ver:
v1, Flags: 10, { CopyCmdAnswer } }
2014-11-20 14:53:20,880 DEBUG [c.c.a.t.Request] (DirectAgent-3:ctx-c859f450)
Seq 1-425590164786511883: Processing:  { Ans: , MgmtId: 52237247174, via: 1,
Ver: v1, Flags: 10,
[{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apa
che.cloudstack.storage.to.VolumeObjectTO":{"uuid":"bab80dd6-16da-4713-979d-c
69b91d7eea6","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStore
TO":{"uuid":"b48e8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"poolType":"SMB","
host":"192.168.1.79","path":"/WINPrimary?user=cloudstackadmin&domain=cloud",
"port":445,"url":"SMB://192.168.1.79/WINPrimary?user=cloudstackadmin&domain=
cloud/?ROLE=Primary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"}},"name"
:"ROOT-2","size":0,"path":"bab80dd6-16da-4713-979d-c69b91d7eea6","accountId"
:0,"format":"VHD","id":0}},"result":true,"wait":0}}] }
2014-11-20 14:53:20,881 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-2:ctx-c1208fbd job-2/job-10 ctx-5358fd84) Seq
1-425590164786511883: Received:  { Ans: , MgmtId: 52237247174, via: 1, Ver:
v1, Flags: 10, { CopyCmdAnswer } }
2014-11-20 14:53:20,901 INFO  [o.a.c.s.v.VolumeServiceImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) releasing lock
for VMTemplateStoragePool 1
2014-11-20 14:53:20,906 INFO  [o.a.c.s.v.VolumeServiceImpl]
(Work-Job-Executor-2:ctx-c1208fbd job-2/job-10 ctx-5358fd84) releasing lock
for VMTemplateStoragePool 1
2014-11-20 14:53:20,906 WARN  [c.c.u.d.Merovingian2]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Was unable to
find lock for the key template_spool_ref1 and thread id 6728486
2014-11-20 14:53:21,054 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) VmWare
hypervisor configured, telling the ssvm to load the
PremiumSecondaryStorageResource
2014-11-20 14:53:21,072 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Boot Args for
VM[SecondaryStorageVm|s-1-VM]:  template=domP type=secstorage
host=192.168.1.130 port=8250 name=s-1-VM zone=1 pod=1 guid=s-1-VM
resource=com.cloud.storage.resource.PremiumSecondaryStorageResource
instance=SecStorage sslcopy=false role=templateProcessor mtu=1500
eth2ip=192.168.1.236 eth2mask=255.255.255.0 gateway=192.168.1.254
eth0ip=169.254.2.19 eth0mask=255.255.0.0 eth1ip=192.168.1.214
eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24 localgw=192.168.1.254
private.network.device=eth1 eth3ip=192.168.1.216 eth3mask=255.255.255.0
storageip=192.168.1.216 storagenetmask=255.255.255.0 storagegateway=192.168.
1.254 internaldns1=192.168.1.129 internaldns2=8.8.8.8 dns1=192.168.1.129
dns2=8.8.8.8
2014-11-20 14:53:21,078 DEBUG [c.c.c.ConsoleProxyManagerImpl]
(Work-Job-Executor-2:ctx-c1208fbd job-2/job-10 ctx-5358fd84) Boot Args for
VM[ConsoleProxy|v-2-VM]:  template=domP type=consoleproxy host=192.168.1.130
port=8250 name=v-2-VM zone=1 pod=1 guid=Proxy.2 proxy_vm=2
disable_rp_filter=true eth2ip=192.168.1.237 eth2mask=255.255.255.0
gateway=192.168.1.254 eth0ip=169.254.1.185 eth0mask=255.255.0.0
eth1ip=192.168.1.217 eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24
localgw=192.168.1.254 internaldns1=192.168.1.129 internaldns2=8.8.8.8
dns1=192.168.1.129 dns2=8.8.8.8
2014-11-20 14:53:21,183 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-2:ctx-c1208fbd job-2/job-10 ctx-5358fd84) Seq
1-425590164786511884: Sending  { Cmd , MgmtId: 52237247174, via:
1(192.168.1.78), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StartCommand":{"vm":{"id":2,"name":"v-2-VM","type":"C
onsoleProxy","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":1073741824,"max
Ram":1073741824,"arch":"x86_64","os":"Debian GNU/Linux 5.0
(64-bit)","bootArgs":" template=domP type=consoleproxy host=192.168.1.130
port=8250 name=v-2-VM zone=1 pod=1 guid=Proxy.2 proxy_vm=2
disable_rp_filter=true eth2ip=192.168.1.237 eth2mask=255.255.255.0
gateway=192.168.1.254 eth0ip=169.254.1.185 eth0mask=255.255.0.0
eth1ip=192.168.1.217 eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24
localgw=192.168.1.254 internaldns1=192.168.1.129 internaldns2=8.8.8.8
dns1=192.168.1.129
dns2=8.8.8.8","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"en
ableDynamicallyScaleVm":false,"vncPassword":"65ddb27a77d86ad2","params":{},"
uuid":"d9fe04b4-2192-43ac-84a6-913916cc27e4","disks":[{"data":{"org.apache.c
loudstack.storage.to.VolumeObjectTO":{"uuid":"bab80dd6-16da-4713-979d-c69b91
d7eea6","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.P
rimaryDataStoreTO":{"uuid":"b48e8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"po
olType":"SMB","host":"192.168.1.79","path":"/WINPrimary?user=cloudstackadmin
&domain=cloud","port":445,"url":"SMB://192.168.1.79/WINPrimary?user=cloudsta
ckadmin&domain=cloud/?ROLE=Primary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6da
aaea9"}},"name":"ROOT-2","size":0,"path":"bab80dd6-16da-4713-979d-c69b91d7ee
a6","volumeId":2,"vmName":"v-2-VM","accountId":1,"format":"VHD","id":2,"devi
ceId":0,"hypervisorType":"Hyperv"}},"diskSeq":0,"path":"bab80dd6-16da-4713-9
79d-c69b91d7eea6","type":"ROOT","_details":{"managed":"false","storagePort":
"445","storageHost":"192.168.1.79","volumeSize":"0"}}],"nics":[{"deviceId":2
,"networkRateMbps":-1,"defaultNic":true,"uuid":"88b614de-d611-4e46-94e5-5476
2d10f1c7","ip":"192.168.1.237","netmask":"255.255.255.0","gateway":"192.168.
1.254","mac":"06:d4:8e:00:00:1c","dns1":"192.168.1.129","dns2":"8.8.8.8","br
oadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSec
urityGroupEnabled":true,"name":"VirtualSwitch"},{"deviceId":0,"networkRateMb
ps":-1,"defaultNic":false,"uuid":"fe7ff75d-67d7-4728-afc9-6cc6d4f8760b","ip"
:"169.254.1.185","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:0
0:a9:fe:01:b9","broadcastType":"LinkLocal","type":"Control","isSecurityGroup
Enabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid"
:"246aa3bd-83d6-44ea-98ce-d0ff65b29249","ip":"192.168.1.217","netmask":"255.
255.255.0","gateway":"192.168.1.254","mac":"06:75:be:00:00:08","broadcastTyp
e":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"Virtu
alSwitch"}]},"hostIp":"192.168.1.78","executeInSequence":false,"wait":0}},{"
com.cloud.agent.api.check.CheckSshCommand":{"ip":"192.168.1.217","port":3922
,"interval":6,"retries":100,"name":"v-2-VM","wait":0}}] }
2014-11-20 14:53:21,199 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-2:ctx-c1208fbd job-2/job-10 ctx-5358fd84) Seq
1-425590164786511884: Executing:  { Cmd , MgmtId: 52237247174, via:
1(192.168.1.78), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StartCommand":{"vm":{"id":2,"name":"v-2-VM","type":"C
onsoleProxy","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":1073741824,"max
Ram":1073741824,"arch":"x86_64","os":"Debian GNU/Linux 5.0
(64-bit)","bootArgs":" template=domP type=consoleproxy host=192.168.1.130
port=8250 name=v-2-VM zone=1 pod=1 guid=Proxy.2 proxy_vm=2
disable_rp_filter=true eth2ip=192.168.1.237 eth2mask=255.255.255.0
gateway=192.168.1.254 eth0ip=169.254.1.185 eth0mask=255.255.0.0
eth1ip=192.168.1.217 eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24
localgw=192.168.1.254 internaldns1=192.168.1.129 internaldns2=8.8.8.8
dns1=192.168.1.129
dns2=8.8.8.8","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"en
ableDynamicallyScaleVm":false,"vncPassword":"65ddb27a77d86ad2","params":{},"
uuid":"d9fe04b4-2192-43ac-84a6-913916cc27e4","disks":[{"data":{"org.apache.c
loudstack.storage.to.VolumeObjectTO":{"uuid":"bab80dd6-16da-4713-979d-c69b91
d7eea6","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.P
rimaryDataStoreTO":{"uuid":"b48e8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"po
olType":"SMB","host":"192.168.1.79","path":"/WINPrimary?user=cloudstackadmin
&domain=cloud","port":445,"url":"SMB://192.168.1.79/WINPrimary?user=cloudsta
ckadmin&domain=cloud/?ROLE=Primary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6da
aaea9"}},"name":"ROOT-2","size":0,"path":"bab80dd6-16da-4713-979d-c69b91d7ee
a6","volumeId":2,"vmName":"v-2-VM","accountId":1,"format":"VHD","id":2,"devi
ceId":0,"hypervisorType":"Hyperv"}},"diskSeq":0,"path":"bab80dd6-16da-4713-9
79d-c69b91d7eea6","type":"ROOT","_details":{"managed":"false","storagePort":
"445","storageHost":"192.168.1.79","volumeSize":"0"}}],"nics":[{"deviceId":2
,"networkRateMbps":-1,"defaultNic":true,"uuid":"88b614de-d611-4e46-94e5-5476
2d10f1c7","ip":"192.168.1.237","netmask":"255.255.255.0","gateway":"192.168.
1.254","mac":"06:d4:8e:00:00:1c","dns1":"192.168.1.129","dns2":"8.8.8.8","br
oadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSec
urityGroupEnabled":true,"name":"VirtualSwitch"},{"deviceId":0,"networkRateMb
ps":-1,"defaultNic":false,"uuid":"fe7ff75d-67d7-4728-afc9-6cc6d4f8760b","ip"
:"169.254.1.185","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:0
0:a9:fe:01:b9","broadcastType":"LinkLocal","type":"Control","isSecurityGroup
Enabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid"
:"246aa3bd-83d6-44ea-98ce-d0ff65b29249","ip":"192.168.1.217","netmask":"255.
255.255.0","gateway":"192.168.1.254","mac":"06:75:be:00:00:08","broadcastTyp
e":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"Virtu
alSwitch"}]},"hostIp":"192.168.1.78","executeInSequence":false,"wait":0}},{"
com.cloud.agent.api.check.CheckSshCommand":{"ip":"192.168.1.217","port":3922
,"interval":6,"retries":100,"name":"v-2-VM","wait":0}}] }
2014-11-20 14:53:21,200 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-6:ctx-89f721b0) Seq 1-425590164786511884: Executing request
2014-11-20 14:53:21,224 DEBUG [c.c.h.h.m.HypervManagerImpl]
(DirectAgent-6:ctx-89f721b0) Executing: sudo mount -t cifs
//192.168.1.79/SWINSecondary /var/cloudstack/mnt/VM/52237247174.293b50a1 -o
uid=cloud,gid=cloud -o user=cloudstackadmin,password=dell_456,domain=cloud
2014-11-20 14:53:21,234 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Seq
1-425590164786511885: Sending  { Cmd , MgmtId: 52237247174, via:
1(192.168.1.78), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StartCommand":{"vm":{"id":1,"name":"s-1-VM","type":"S
econdaryStorageVm","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912
,"maxRam":536870912,"arch":"x86_64","os":"Debian GNU/Linux 5.0
(64-bit)","bootArgs":" template=domP type=secstorage host=192.168.1.130
port=8250 name=s-1-VM zone=1 pod=1 guid=s-1-VM
resource=com.cloud.storage.resource.PremiumSecondaryStorageResource
instance=SecStorage sslcopy=false role=templateProcessor mtu=1500
eth2ip=192.168.1.236 eth2mask=255.255.255.0 gateway=192.168.1.254
eth0ip=169.254.2.19 eth0mask=255.255.0.0 eth1ip=192.168.1.214
eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24 localgw=192.168.1.254
private.network.device=eth1 eth3ip=192.168.1.216 eth3mask=255.255.255.0
storageip=192.168.1.216 storagenetmask=255.255.255.0 storagegateway=192.168.
1.254 internaldns1=192.168.1.129 internaldns2=8.8.8.8 dns1=192.168.1.129
dns2=8.8.8.8","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"en
ableDynamicallyScaleVm":false,"vncPassword":"6cb55063a5328305","params":{},"
uuid":"3c294f1b-c110-4a3f-a23f-73f8fd54bbe8","disks":[{"data":{"org.apache.c
loudstack.storage.to.VolumeObjectTO":{"uuid":"f09879e9-fe76-4c2c-b051-164867
c4099a","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.P
rimaryDataStoreTO":{"uuid":"b48e8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"po
olType":"SMB","host":"192.168.1.79","path":"/WINPrimary?user=cloudstackadmin
&domain=cloud","port":445,"url":"SMB://192.168.1.79/WINPrimary?user=cloudsta
ckadmin&domain=cloud/?ROLE=Primary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6da
aaea9"}},"name":"ROOT-1","size":0,"path":"f09879e9-fe76-4c2c-b051-164867c409
9a","volumeId":1,"vmName":"s-1-VM","accountId":1,"format":"VHD","id":1,"devi
ceId":0,"hypervisorType":"Hyperv"}},"diskSeq":0,"path":"f09879e9-fe76-4c2c-b
051-164867c4099a","type":"ROOT","_details":{"managed":"false","storagePort":
"445","storageHost":"192.168.1.79","volumeSize":"0"}}],"nics":[{"deviceId":2
,"networkRateMbps":-1,"defaultNic":true,"uuid":"88b614de-d611-4e46-94e5-5476
2d10f1c7","ip":"192.168.1.236","netmask":"255.255.255.0","gateway":"192.168.
1.254","mac":"06:06:40:00:00:1b","dns1":"192.168.1.129","dns2":"8.8.8.8","br
oadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSec
urityGroupEnabled":true,"name":"VirtualSwitch"},{"deviceId":0,"networkRateMb
ps":-1,"defaultNic":false,"uuid":"fe7ff75d-67d7-4728-afc9-6cc6d4f8760b","ip"
:"169.254.2.19","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00
:a9:fe:02:13","broadcastType":"LinkLocal","type":"Control","isSecurityGroupE
nabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":
"246aa3bd-83d6-44ea-98ce-d0ff65b29249","ip":"192.168.1.214","netmask":"255.2
55.255.0","gateway":"192.168.1.254","mac":"06:31:c2:00:00:05","broadcastType
":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"Virtua
lSwitch"},{"deviceId":3,"networkRateMbps":-1,"defaultNic":false,"uuid":"bb6d
d0ef-ef4c-47a6-a553-3f4463909e73","ip":"192.168.1.216","netmask":"255.255.25
5.0","gateway":"192.168.1.254","mac":"06:22:28:00:00:07","broadcastType":"Na
tive","type":"Storage","isSecurityGroupEnabled":false,"name":"VirtualSwitch"
}]},"hostIp":"192.168.1.78","executeInSequence":false,"wait":0}},{"com.cloud
.agent.api.check.CheckSshCommand":{"ip":"192.168.1.214","port":3922,"interva
l":6,"retries":100,"name":"s-1-VM","wait":0}}] }
2014-11-20 14:53:21,244 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Seq
1-425590164786511885: Executing:  { Cmd , MgmtId: 52237247174, via:
1(192.168.1.78), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StartCommand":{"vm":{"id":1,"name":"s-1-VM","type":"S
econdaryStorageVm","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912
,"maxRam":536870912,"arch":"x86_64","os":"Debian GNU/Linux 5.0
(64-bit)","bootArgs":" template=domP type=secstorage host=192.168.1.130
port=8250 name=s-1-VM zone=1 pod=1 guid=s-1-VM
resource=com.cloud.storage.resource.PremiumSecondaryStorageResource
instance=SecStorage sslcopy=false role=templateProcessor mtu=1500
eth2ip=192.168.1.236 eth2mask=255.255.255.0 gateway=192.168.1.254
eth0ip=169.254.2.19 eth0mask=255.255.0.0 eth1ip=192.168.1.214
eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24 localgw=192.168.1.254
private.network.device=eth1 eth3ip=192.168.1.216 eth3mask=255.255.255.0
storageip=192.168.1.216 storagenetmask=255.255.255.0 storagegateway=192.168.
1.254 internaldns1=192.168.1.129 internaldns2=8.8.8.8 dns1=192.168.1.129
dns2=8.8.8.8","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"en
ableDynamicallyScaleVm":false,"vncPassword":"6cb55063a5328305","params":{},"
uuid":"3c294f1b-c110-4a3f-a23f-73f8fd54bbe8","disks":[{"data":{"org.apache.c
loudstack.storage.to.VolumeObjectTO":{"uuid":"f09879e9-fe76-4c2c-b051-164867
c4099a","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.P
rimaryDataStoreTO":{"uuid":"b48e8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"po
olType":"SMB","host":"192.168.1.79","path":"/WINPrimary?user=cloudstackadmin
&domain=cloud","port":445,"url":"SMB://192.168.1.79/WINPrimary?user=cloudsta
ckadmin&domain=cloud/?ROLE=Primary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6da
aaea9"}},"name":"ROOT-1","size":0,"path":"f09879e9-fe76-4c2c-b051-164867c409
9a","volumeId":1,"vmName":"s-1-VM","accountId":1,"format":"VHD","id":1,"devi
ceId":0,"hypervisorType":"Hyperv"}},"diskSeq":0,"path":"f09879e9-fe76-4c2c-b
051-164867c4099a","type":"ROOT","_details":{"managed":"false","storagePort":
"445","storageHost":"192.168.1.79","volumeSize":"0"}}],"nics":[{"deviceId":2
,"networkRateMbps":-1,"defaultNic":true,"uuid":"88b614de-d611-4e46-94e5-5476
2d10f1c7","ip":"192.168.1.236","netmask":"255.255.255.0","gateway":"192.168.
1.254","mac":"06:06:40:00:00:1b","dns1":"192.168.1.129","dns2":"8.8.8.8","br
oadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSec
urityGroupEnabled":true,"name":"VirtualSwitch"},{"deviceId":0,"networkRateMb
ps":-1,"defaultNic":false,"uuid":"fe7ff75d-67d7-4728-afc9-6cc6d4f8760b","ip"
:"169.254.2.19","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00
:a9:fe:02:13","broadcastType":"LinkLocal","type":"Control","isSecurityGroupE
nabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":
"246aa3bd-83d6-44ea-98ce-d0ff65b29249","ip":"192.168.1.214","netmask":"255.2
55.255.0","gateway":"192.168.1.254","mac":"06:31:c2:00:00:05","broadcastType
":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"Virtua
lSwitch"},{"deviceId":3,"networkRateMbps":-1,"defaultNic":false,"uuid":"bb6d
d0ef-ef4c-47a6-a553-3f4463909e73","ip":"192.168.1.216","netmask":"255.255.25
5.0","gateway":"192.168.1.254","mac":"06:22:28:00:00:07","broadcastType":"Na
tive","type":"Storage","isSecurityGroupEnabled":false,"name":"VirtualSwitch"
}]},"hostIp":"192.168.1.78","executeInSequence":false,"wait":0}},{"com.cloud
.agent.api.check.CheckSshCommand":{"ip":"192.168.1.214","port":3922,"interva
l":6,"retries":100,"name":"s-1-VM","wait":0}}] }
2014-11-20 14:53:21,245 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-7:ctx-5843c848) Seq 1-425590164786511885: Executing request
2014-11-20 14:53:21,853 DEBUG [c.c.h.h.m.HypervManagerImpl]
(DirectAgent-6:ctx-89f721b0) Execution is successful.
2014-11-20 14:53:21,856 DEBUG [c.c.h.h.m.HypervManagerImpl]
(DirectAgent-6:ctx-89f721b0) Executing: sudo chmod -R 777
/var/cloudstack/mnt/VM/52237247174.293b50a1
2014-11-20 14:53:21,881 DEBUG [c.c.h.h.m.HypervManagerImpl]
(DirectAgent-6:ctx-89f721b0) Exit value is 1
2014-11-20 14:53:21,882 DEBUG [c.c.h.h.m.HypervManagerImpl]
(DirectAgent-6:ctx-89f721b0) chmod: changing permissions of
`/var/cloudstack/mnt/VM/52237247174.293b50a1': Permission denied
2014-11-20 14:53:21,882 WARN  [c.c.h.h.m.HypervManagerImpl]
(DirectAgent-6:ctx-89f721b0) Unable to set permissions for
/var/cloudstack/mnt/VM/52237247174.293b50a1 due to chmod: changing
permissions of `/var/cloudstack/mnt/VM/52237247174.293b50a1': Permission
denied
2014-11-20 14:53:21,888 INFO  [c.c.h.h.m.HypervManagerImpl]
(DirectAgent-6:ctx-89f721b0) Copy System VM patch ISO file to secondary
storage. source ISO: /usr/share/cloudstack-common/vms/systemvm.iso,
destination:
/var/cloudstack/mnt/VM/52237247174.293b50a1/systemvm/systemvm-4.4.1-SNAPSHOT
.iso
2014-11-20 14:53:22,831 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-6:ctx-89f721b0) POST request to
https://secure-web.cisco.com/1_aiPLx8kQ15GuqcApBScbs7V3axbFVx14CfGuGNFRNYBz_
xWF_Fr7y6KCb8d-j1HS4xyzgAw7AMRIAiAZyhdMs_hlNSWYn3CSS5ccpVdUILZ9JyIDS_H09jTtC
eHlttAFP9pbp37YqZzf-UBy7oUgARpGXDtw2ZMxroSyC4lyQg/https%3A%2F%2F192.168.1.78
%3A8250%2Fapi%2FHypervResource%2Fcom.cloud.agent.api.StartComman
d with contents
{"vm":{"id":2,"name":"v-2-VM","type":"ConsoleProxy","cpus":1,"minSpeed":500,
"maxSpeed":500,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":
"Debian GNU/Linux 5.0 (64-bit)","bootArgs":" template=domP type=consoleproxy
host=192.168.1.130 port=8250 name=v-2-VM zone=1 pod=1 guid=Proxy.2
proxy_vm=2 disable_rp_filter=true eth2ip=192.168.1.237 eth2mask=255.255.255.
0 gateway=192.168.1.254 eth0ip=169.254.1.185 eth0mask=255.255.0.0
eth1ip=192.168.1.217 eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24
localgw=192.168.1.254 internaldns1=192.168.1.129 internaldns2=8.8.8.8
dns1=192.168.1.129
dns2=8.8.8.8","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"en
ableDynamicallyScaleVm":false,"vncPassword":"65ddb27a77d86ad2","params":{},"
uuid":"d9fe04b4-2192-43ac-84a6-913916cc27e4","disks":[{"data":{"org.apache.c
loudstack.storage.to.VolumeObjectTO":{"uuid":"bab80dd6-16da-4713-979d-c69b91
d7eea6","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.P
rimaryDataStoreTO":{"uuid":"b48e8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"po
olType":"SMB","host":"192.168.1.79","path":"/WINPrimary?user=cloudstackadmin
&domain=cloud","port":445,"url":"SMB://192.168.1.79/WINPrimary?user=cloudsta
ckadmin&domain=cloud/?ROLE=Primary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6da
aaea9"}},"name":"ROOT-2","size":0,"path":"bab80dd6-16da-4713-979d-c69b91d7ee
a6","volumeId":2,"vmName":"v-2-VM","accountId":1,"format":"VHD","id":2,"devi
ceId":0,"hypervisorType":"Hyperv"}},"diskSeq":0,"path":"bab80dd6-16da-4713-9
79d-c69b91d7eea6","type":"ROOT","_details":{"managed":"false","storagePort":
"445","storageHost":"192.168.1.79","volumeSize":"0"}}],"nics":[{"deviceId":2
,"networkRateMbps":-1,"defaultNic":true,"uuid":"88b614de-d611-4e46-94e5-5476
2d10f1c7","ip":"192.168.1.237","netmask":"255.255.255.0","gateway":"192.168.
1.254","mac":"06:d4:8e:00:00:1c","dns1":"192.168.1.129","dns2":"8.8.8.8","br
oadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSec
urityGroupEnabled":true,"name":"VirtualSwitch"},{"deviceId":0,"networkRateMb
ps":-1,"defaultNic":false,"uuid":"fe7ff75d-67d7-4728-afc9-6cc6d4f8760b","ip"
:"169.254.1.185","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:0
0:a9:fe:01:b9","broadcastType":"LinkLocal","type":"Control","isSecurityGroup
Enabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid"
:"246aa3bd-83d6-44ea-98ce-d0ff65b29249","ip":"192.168.1.217","netmask":"255.
255.255.0","gateway":"192.168.1.254","mac":"06:75:be:00:00:08","broadcastTyp
e":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"Virtu
alSwitch"}]},"hostIp":"192.168.1.78","executeInSequence":false,"secondarySto
rage":"cifs://192.168.1.79/SWINSecondary?user=cloudstackadmin&domain=cloud",
"contextMap":{},"wait":0}
2014-11-20 14:53:22,833 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-7:ctx-5843c848) POST request to
https://secure-web.cisco.com/1_aiPLx8kQ15GuqcApBScbs7V3axbFVx14CfGuGNFRNYBz_
xWF_Fr7y6KCb8d-j1HS4xyzgAw7AMRIAiAZyhdMs_hlNSWYn3CSS5ccpVdUILZ9JyIDS_H09jTtC
eHlttAFP9pbp37YqZzf-UBy7oUgARpGXDtw2ZMxroSyC4lyQg/https%3A%2F%2F192.168.1.78
%3A8250%2Fapi%2FHypervResource%2Fcom.cloud.agent.api.StartComman
d with contents
{"vm":{"id":1,"name":"s-1-VM","type":"SecondaryStorageVm","cpus":1,"minSpeed
":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_64","
os":"Debian GNU/Linux 5.0 (64-bit)","bootArgs":" template=domP
type=secstorage host=192.168.1.130 port=8250 name=s-1-VM zone=1 pod=1
guid=s-1-VM
resource=com.cloud.storage.resource.PremiumSecondaryStorageResource
instance=SecStorage sslcopy=false role=templateProcessor mtu=1500
eth2ip=192.168.1.236 eth2mask=255.255.255.0 gateway=192.168.1.254
eth0ip=169.254.2.19 eth0mask=255.255.0.0 eth1ip=192.168.1.214
eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24 localgw=192.168.1.254
private.network.device=eth1 eth3ip=192.168.1.216 eth3mask=255.255.255.0
storageip=192.168.1.216 storagenetmask=255.255.255.0 storagegateway=192.168.
1.254 internaldns1=192.168.1.129 internaldns2=8.8.8.8 dns1=192.168.1.129
dns2=8.8.8.8","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"en
ableDynamicallyScaleVm":false,"vncPassword":"6cb55063a5328305","params":{},"
uuid":"3c294f1b-c110-4a3f-a23f-73f8fd54bbe8","disks":[{"data":{"org.apache.c
loudstack.storage.to.VolumeObjectTO":{"uuid":"f09879e9-fe76-4c2c-b051-164867
c4099a","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.P
rimaryDataStoreTO":{"uuid":"b48e8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"po
olType":"SMB","host":"192.168.1.79","path":"/WINPrimary?user=cloudstackadmin
&domain=cloud","port":445,"url":"SMB://192.168.1.79/WINPrimary?user=cloudsta
ckadmin&domain=cloud/?ROLE=Primary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6da
aaea9"}},"name":"ROOT-1","size":0,"path":"f09879e9-fe76-4c2c-b051-164867c409
9a","volumeId":1,"vmName":"s-1-VM","accountId":1,"format":"VHD","id":1,"devi
ceId":0,"hypervisorType":"Hyperv"}},"diskSeq":0,"path":"f09879e9-fe76-4c2c-b
051-164867c4099a","type":"ROOT","_details":{"managed":"false","storagePort":
"445","storageHost":"192.168.1.79","volumeSize":"0"}}],"nics":[{"deviceId":2
,"networkRateMbps":-1,"defaultNic":true,"uuid":"88b614de-d611-4e46-94e5-5476
2d10f1c7","ip":"192.168.1.236","netmask":"255.255.255.0","gateway":"192.168.
1.254","mac":"06:06:40:00:00:1b","dns1":"192.168.1.129","dns2":"8.8.8.8","br
oadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSec
urityGroupEnabled":true,"name":"VirtualSwitch"},{"deviceId":0,"networkRateMb
ps":-1,"defaultNic":false,"uuid":"fe7ff75d-67d7-4728-afc9-6cc6d4f8760b","ip"
:"169.254.2.19","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00
:a9:fe:02:13","broadcastType":"LinkLocal","type":"Control","isSecurityGroupE
nabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":
"246aa3bd-83d6-44ea-98ce-d0ff65b29249","ip":"192.168.1.214","netmask":"255.2
55.255.0","gateway":"192.168.1.254","mac":"06:31:c2:00:00:05","broadcastType
":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"Virtua
lSwitch"},{"deviceId":3,"networkRateMbps":-1,"defaultNic":false,"uuid":"bb6d
d0ef-ef4c-47a6-a553-3f4463909e73","ip":"192.168.1.216","netmask":"255.255.25
5.0","gateway":"192.168.1.254","mac":"06:22:28:00:00:07","broadcastType":"Na
tive","type":"Storage","isSecurityGroupEnabled":false,"name":"VirtualSwitch"
}]},"hostIp":"192.168.1.78","executeInSequence":false,"secondaryStorage":"ci
fs://192.168.1.79/SWINSecondary?user=cloudstackadmin&domain=cloud","contextM
ap":{},"wait":0}
2014-11-20 14:53:22,860 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-6:ctx-89f721b0) Sending cmd to
https://secure-web.cisco.com/1_aiPLx8kQ15GuqcApBScbs7V3axbFVx14CfGuGNFRNYBz_
xWF_Fr7y6KCb8d-j1HS4xyzgAw7AMRIAiAZyhdMs_hlNSWYn3CSS5ccpVdUILZ9JyIDS_H09jTtC
eHlttAFP9pbp37YqZzf-UBy7oUgARpGXDtw2ZMxroSyC4lyQg/https%3A%2F%2F192.168.1.78
%3A8250%2Fapi%2FHypervResource%2Fcom.cloud.agent.api.StartComman
d cmd
data:{"vm":{"id":2,"name":"v-2-VM","type":"ConsoleProxy","cpus":1,"minSpeed"
:500,"maxSpeed":500,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64",
"os":"Debian GNU/Linux 5.0 (64-bit)","bootArgs":" template=domP
type=consoleproxy host=192.168.1.130 port=8250 name=v-2-VM zone=1 pod=1
guid=Proxy.2 proxy_vm=2 disable_rp_filter=true eth2ip=192.168.1.237
eth2mask=255.255.255.0 gateway=192.168.1.254 eth0ip=169.254.1.185
eth0mask=255.255.0.0 eth1ip=192.168.1.217 eth1mask=255.255.255.0
mgmtcidr=192.168.1.0/24 localgw=192.168.1.254 internaldns1=192.168.1.129
internaldns2=8.8.8.8 dns1=192.168.1.129 dns2=8.8.8.8","rebootOnCrash":false,
"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPa
ssword":"65ddb27a77d86ad2","params":{},"uuid":"d9fe04b4-2192-43ac-84a6-91391
6cc27e4","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO"
:{"uuid":"bab80dd6-16da-4713-979d-c69b91d7eea6","volumeType":"ROOT","dataSto
re":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b48e8cd6
-8ec5-3c34-8a43-020c6daaaea9","id":1,"poolType":"SMB","host":"192.168.1.79",
"path":"/WINPrimary?user=cloudstackadmin&domain=cloud","port":445,"url":"SMB
://192.168.1.79/WINPrimary?user=cloudstackadmin&domain=cloud/?ROLE=Primary&S
TOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"}},"name":"ROOT-2","size":0,"p
ath":"bab80dd6-16da-4713-979d-c69b91d7eea6","volumeId":2,"vmName":"v-2-VM","
accountId":1,"format":"VHD","id":2,"deviceId":0,"hypervisorType":"Hyperv"}},
"diskSeq":0,"path":"bab80dd6-16da-4713-979d-c69b91d7eea6","type":"ROOT","_de
tails":{"managed":"false","storagePort":"445","storageHost":"192.168.1.79","
volumeSize":"0"}}],"nics":[{"deviceId":2,"networkRateMbps":-1,"defaultNic":t
rue,"uuid":"88b614de-d611-4e46-94e5-54762d10f1c7","ip":"192.168.1.237","netm
ask":"255.255.255.0","gateway":"192.168.1.254","mac":"06:d4:8e:00:00:1c","dn
s1":"192.168.1.129","dns2":"8.8.8.8","broadcastType":"Native","type":"Guest"
,"broadcastUri":"vlan://untagged","isSecurityGroupEnabled":true,"name":"Virt
ualSwitch"},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"fe
7ff75d-67d7-4728-afc9-6cc6d4f8760b","ip":"169.254.1.185","netmask":"255.255.
0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:01:b9","broadcastType":"Link
Local","type":"Control","isSecurityGroupEnabled":false},{"deviceId":1,"netwo
rkRateMbps":-1,"defaultNic":false,"uuid":"246aa3bd-83d6-44ea-98ce-d0ff65b292
49","ip":"192.168.1.217","netmask":"255.255.255.0","gateway":"192.168.1.254"
,"mac":"06:75:be:00:00:08","broadcastType":"Native","type":"Management","isS
ecurityGroupEnabled":false,"name":"VirtualSwitch"}]},"hostIp":"192.168.1.78"
,"executeInSequence":false,"secondaryStorage":"cifs://192.168.1.79/SWINSecon
dary?user=cloudstackadmin&domain=cloud","contextMap":{},"wait":0}
2014-11-20 14:53:22,867 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-7:ctx-5843c848) Sending cmd to
https://secure-web.cisco.com/1_aiPLx8kQ15GuqcApBScbs7V3axbFVx14CfGuGNFRNYBz_
xWF_Fr7y6KCb8d-j1HS4xyzgAw7AMRIAiAZyhdMs_hlNSWYn3CSS5ccpVdUILZ9JyIDS_H09jTtC
eHlttAFP9pbp37YqZzf-UBy7oUgARpGXDtw2ZMxroSyC4lyQg/https%3A%2F%2F192.168.1.78
%3A8250%2Fapi%2FHypervResource%2Fcom.cloud.agent.api.StartComman
d cmd
data:{"vm":{"id":1,"name":"s-1-VM","type":"SecondaryStorageVm","cpus":1,"min
Speed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_
64","os":"Debian GNU/Linux 5.0 (64-bit)","bootArgs":" template=domP
type=secstorage host=192.168.1.130 port=8250 name=s-1-VM zone=1 pod=1
guid=s-1-VM
resource=com.cloud.storage.resource.PremiumSecondaryStorageResource
instance=SecStorage sslcopy=false role=templateProcessor mtu=1500
eth2ip=192.168.1.236 eth2mask=255.255.255.0 gateway=192.168.1.254
eth0ip=169.254.2.19 eth0mask=255.255.0.0 eth1ip=192.168.1.214
eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24 localgw=192.168.1.254
private.network.device=eth1 eth3ip=192.168.1.216 eth3mask=255.255.255.0
storageip=192.168.1.216 storagenetmask=255.255.255.0 storagegateway=192.168.
1.254 internaldns1=192.168.1.129 internaldns2=8.8.8.8 dns1=192.168.1.129
dns2=8.8.8.8","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"en
ableDynamicallyScaleVm":false,"vncPassword":"6cb55063a5328305","params":{},"
uuid":"3c294f1b-c110-4a3f-a23f-73f8fd54bbe8","disks":[{"data":{"org.apache.c
loudstack.storage.to.VolumeObjectTO":{"uuid":"f09879e9-fe76-4c2c-b051-164867
c4099a","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.P
rimaryDataStoreTO":{"uuid":"b48e8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"po
olType":"SMB","host":"192.168.1.79","path":"/WINPrimary?user=cloudstackadmin
&domain=cloud","port":445,"url":"SMB://192.168.1.79/WINPrimary?user=cloudsta
ckadmin&domain=cloud/?ROLE=Primary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6da
aaea9"}},"name":"ROOT-1","size":0,"path":"f09879e9-fe76-4c2c-b051-164867c409
9a","volumeId":1,"vmName":"s-1-VM","accountId":1,"format":"VHD","id":1,"devi
ceId":0,"hypervisorType":"Hyperv"}},"diskSeq":0,"path":"f09879e9-fe76-4c2c-b
051-164867c4099a","type":"ROOT","_details":{"managed":"false","storagePort":
"445","storageHost":"192.168.1.79","volumeSize":"0"}}],"nics":[{"deviceId":2
,"networkRateMbps":-1,"defaultNic":true,"uuid":"88b614de-d611-4e46-94e5-5476
2d10f1c7","ip":"192.168.1.236","netmask":"255.255.255.0","gateway":"192.168.
1.254","mac":"06:06:40:00:00:1b","dns1":"192.168.1.129","dns2":"8.8.8.8","br
oadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSec
urityGroupEnabled":true,"name":"VirtualSwitch"},{"deviceId":0,"networkRateMb
ps":-1,"defaultNic":false,"uuid":"fe7ff75d-67d7-4728-afc9-6cc6d4f8760b","ip"
:"169.254.2.19","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00
:a9:fe:02:13","broadcastType":"LinkLocal","type":"Control","isSecurityGroupE
nabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":
"246aa3bd-83d6-44ea-98ce-d0ff65b29249","ip":"192.168.1.214","netmask":"255.2
55.255.0","gateway":"192.168.1.254","mac":"06:31:c2:00:00:05","broadcastType
":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"Virtua
lSwitch"},{"deviceId":3,"networkRateMbps":-1,"defaultNic":false,"uuid":"bb6d
d0ef-ef4c-47a6-a553-3f4463909e73","ip":"192.168.1.216","netmask":"255.255.25
5.0","gateway":"192.168.1.254","mac":"06:22:28:00:00:07","broadcastType":"Na
tive","type":"Storage","isSecurityGroupEnabled":false,"name":"VirtualSwitch"
}]},"hostIp":"192.168.1.78","executeInSequence":false,"secondaryStorage":"ci
fs://192.168.1.79/SWINSecondary?user=cloudstackadmin&domain=cloud","contextM
ap":{},"wait":0}
2014-11-20 14:53:22,914 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(HostReservationReleaseChecker:ctx-69f3909c) Checking if any host
reservation can be released ...
2014-11-20 14:53:22,927 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(HostReservationReleaseChecker:ctx-69f3909c) Cannot release reservation,
Found 2 VMs Running on host 1
2014-11-20 14:53:22,927 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(HostReservationReleaseChecker:ctx-69f3909c) Done running
HostReservationReleaseChecker ...
2014-11-20 14:53:23,022 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:ctx-25dcf22e) Found 0 routers to update status.
2014-11-20 14:53:23,024 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:ctx-25dcf22e) Found 0 networks to update RvR status.
2014-11-20 14:53:23,063 DEBUG [c.c.a.AlertManagerImpl]
(CapacityChecker:ctx-7f67c97e) Running Capacity Checker ...
2014-11-20 14:53:23,063 DEBUG [c.c.a.AlertManagerImpl]
(CapacityChecker:ctx-7f67c97e) recalculating system capacity
2014-11-20 14:53:23,063 DEBUG [c.c.a.AlertManagerImpl]
(CapacityChecker:ctx-7f67c97e) Executing cpu/ram capacity update
2014-11-20 14:53:23,073 DEBUG [c.c.c.CapacityManagerImpl]
(CapacityChecker:ctx-7f67c97e) Found 2 VMs on host 1
2014-11-20 14:53:23,077 DEBUG [c.c.c.CapacityManagerImpl]
(CapacityChecker:ctx-7f67c97e) Found 0 VM, not running on host 1
2014-11-20 14:53:23,080 DEBUG [c.c.c.CapacityManagerImpl]
(CapacityChecker:ctx-7f67c97e) No need to calibrate cpu capacity, host:1
usedCpu: 1000 reservedCpu: 0
2014-11-20 14:53:23,080 DEBUG [c.c.c.CapacityManagerImpl]
(CapacityChecker:ctx-7f67c97e) No need to calibrate memory capacity, host:1
usedMem: 1610612736 reservedMem: 0
2014-11-20 14:53:23,084 DEBUG [c.c.a.AlertManagerImpl]
(CapacityChecker:ctx-7f67c97e) Done executing cpu/ram capacity update
2014-11-20 14:53:23,084 DEBUG [c.c.a.AlertManagerImpl]
(CapacityChecker:ctx-7f67c97e) Executing storage capacity update
2014-11-20 14:53:23,093 DEBUG [c.c.s.StorageManagerImpl]
(CapacityChecker:ctx-7f67c97e) Found storage pool WINPrimary of type SMB
2014-11-20 14:53:23,093 DEBUG [c.c.s.StorageManagerImpl]
(CapacityChecker:ctx-7f67c97e) Total over provisioned capacity of the pool
WINPrimary id: 1 is 149954752512
2014-11-20 14:53:23,093 DEBUG [c.c.s.StorageManagerImpl]
(CapacityChecker:ctx-7f67c97e) Successfully set Capacity - 149954752512 for
capacity type - 3 , DataCenterId - 1, HostOrPoolId - 1, PodId 1
2014-11-20 14:53:23,093 DEBUG [c.c.a.AlertManagerImpl]
(CapacityChecker:ctx-7f67c97e) Done executing storage capacity update
2014-11-20 14:53:23,093 DEBUG [c.c.a.AlertManagerImpl]
(CapacityChecker:ctx-7f67c97e) Executing capacity updates for public ip and
Vlans
2014-11-20 14:53:23,107 DEBUG [c.c.a.AlertManagerImpl]
(CapacityChecker:ctx-7f67c97e) Done capacity updates for public ip and Vlans
2014-11-20 14:53:23,107 DEBUG [c.c.a.AlertManagerImpl]
(CapacityChecker:ctx-7f67c97e) Executing capacity updates for private ip
2014-11-20 14:53:23,121 DEBUG [c.c.a.AlertManagerImpl]
(CapacityChecker:ctx-7f67c97e) Done executing capacity updates for private
ip
2014-11-20 14:53:23,121 DEBUG [c.c.a.AlertManagerImpl]
(CapacityChecker:ctx-7f67c97e) Done recalculating system capacity
2014-11-20 14:53:23,151 DEBUG [c.c.a.AlertManagerImpl]
(CapacityChecker:ctx-7f67c97e) Done running Capacity Checker ...
2014-11-20 14:53:25,145 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-7:ctx-5843c848) POST response is
[{"com.cloud.agent.api.StartAnswer":{"result":false,"details":"com.cloud.age
nt.api.StartCommand fail on exceptionObject reference not set to an instance
of an
object.","vm":{"id":1,"name":"s-1-VM","type":"SecondaryStorageVm","cpus":1,"
minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x
86_64","os":"Debian GNU/Linux 5.0 (64-bit)","bootArgs":" template=domP
type=secstorage host=192.168.1.130 port=8250 name=s-1-VM zone=1 pod=1
guid=s-1-VM
resource=com.cloud.storage.resource.PremiumSecondaryStorageResource
instance=SecStorage sslcopy=false role=templateProcessor mtu=1500
eth2ip=192.168.1.236 eth2mask=255.255.255.0 gateway=192.168.1.254
eth0ip=169.254.2.19 eth0mask=255.255.0.0 eth1ip=192.168.1.214
eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24 localgw=192.168.1.254
private.network.device=eth1 eth3ip=192.168.1.216 eth3mask=255.255.255.0
storageip=192.168.1.216 storagenetmask=255.255.255.0 storagegateway=192.168.
1.254 internaldns1=192.168.1.129 internaldns2=8.8.8.8 dns1=192.168.1.129
dns2=8.8.8.8","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"en
ableDynamicallyScaleVm":false,"vncPassword":"6cb55063a5328305","params":{},"
uuid":"3c294f1b-c110-4a3f-a23f-73f8fd54bbe8","disks":[{"data":{"org.apache.c
loudstack.storage.to.VolumeObjectTO":{"uuid":"f09879e9-fe76-4c2c-b051-164867
c4099a","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.P
rimaryDataStoreTO":{"uuid":"b48e8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"po
olType":"SMB","host":"192.168.1.79","path":"/WINPrimary?user=cloudstackadmin
&domain=cloud","port":445,"url":"SMB://192.168.1.79/WINPrimary?user=cloudsta
ckadmin&domain=cloud/?ROLE=Primary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6da
aaea9"}},"name":"ROOT-1","size":0,"path":"f09879e9-fe76-4c2c-b051-164867c409
9a","volumeId":1,"vmName":"s-1-VM","accountId":1,"format":"VHD","id":1,"devi
ceId":0,"hypervisorType":"Hyperv"}},"diskSeq":0,"path":"f09879e9-fe76-4c2c-b
051-164867c4099a","type":"ROOT","_details":{"managed":"false","storagePort":
"445","storageHost":"192.168.1.79","volumeSize":"0"}}],"nics":[{"deviceId":2
,"networkRateMbps":-1,"defaultNic":true,"uuid":"88b614de-d611-4e46-94e5-5476
2d10f1c7","ip":"192.168.1.236","netmask":"255.255.255.0","gateway":"192.168.
1.254","mac":"06:06:40:00:00:1b","dns1":"192.168.1.129","dns2":"8.8.8.8","br
oadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSec
urityGroupEnabled":true,"name":"VirtualSwitch"},{"deviceId":0,"networkRateMb
ps":-1,"defaultNic":false,"uuid":"fe7ff75d-67d7-4728-afc9-6cc6d4f8760b","ip"
:"169.254.2.19","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00
:a9:fe:02:13","broadcastType":"LinkLocal","type":"Control","isSecurityGroupE
nabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":
"246aa3bd-83d6-44ea-98ce-d0ff65b29249","ip":"192.168.1.214","netmask":"255.2
55.255.0","gateway":"192.168.1.254","mac":"06:31:c2:00:00:05","broadcastType
":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"Virtua
lSwitch"},{"deviceId":3,"networkRateMbps":-1,"defaultNic":false,"uuid":"bb6d
d0ef-ef4c-47a6-a553-3f4463909e73","ip":"192.168.1.216","netmask":"255.255.25
5.0","gateway":"192.168.1.254","mac":"06:22:28:00:00:07","broadcastType":"Na
tive","type":"Storage","isSecurityGroupEnabled":false,"name":"VirtualSwitch"
}]},"contextMap":{}}}]
2014-11-20 14:53:25,165 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-7:ctx-5843c848) executeRequest received response
[Lcom.cloud.agent.api.Answer;@449814d7
2014-11-20 14:53:25,165 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-7:ctx-5843c848) Seq 1-425590164786511885: Cancelling because
one of the answers is false and it is stop on error.
2014-11-20 14:53:25,165 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-7:ctx-5843c848) Seq 1-425590164786511885: Response Received:
2014-11-20 14:53:25,187 DEBUG [c.c.a.t.Request] (DirectAgent-7:ctx-5843c848)
Seq 1-425590164786511885: Processing:  { Ans: , MgmtId: 52237247174, via: 1,
Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StartAnswer":{"vm":{"id":1,"name":"s-1-VM","type":"Se
condaryStorageVm","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,
"maxRam":536870912,"arch":"x86_64","os":"Debian GNU/Linux 5.0
(64-bit)","bootArgs":" template=domP type=secstorage host=192.168.1.130
port=8250 name=s-1-VM zone=1 pod=1 guid=s-1-VM
resource=com.cloud.storage.resource.PremiumSecondaryStorageResource
instance=SecStorage sslcopy=false role=templateProcessor mtu=1500
eth2ip=192.168.1.236 eth2mask=255.255.255.0 gateway=192.168.1.254
eth0ip=169.254.2.19 eth0mask=255.255.0.0 eth1ip=192.168.1.214
eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24 localgw=192.168.1.254
private.network.device=eth1 eth3ip=192.168.1.216 eth3mask=255.255.255.0
storageip=192.168.1.216 storagenetmask=255.255.255.0 storagegateway=192.168.
1.254 internaldns1=192.168.1.129 internaldns2=8.8.8.8 dns1=192.168.1.129
dns2=8.8.8.8","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"en
ableDynamicallyScaleVm":false,"vncPassword":"6cb55063a5328305","params":{},"
uuid":"3c294f1b-c110-4a3f-a23f-73f8fd54bbe8","disks":[{"data":{"org.apache.c
loudstack.storage.to.VolumeObjectTO":{"uuid":"f09879e9-fe76-4c2c-b051-164867
c4099a","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.P
rimaryDataStoreTO":{"uuid":"b48e8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"po
olType":"SMB","host":"192.168.1.79","path":"/WINPrimary?user=cloudstackadmin
&domain=cloud","port":445,"url":"SMB://192.168.1.79/WINPrimary?user=cloudsta
ckadmin&domain=cloud/?ROLE=Primary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6da
aaea9"}},"name":"ROOT-1","size":0,"path":"f09879e9-fe76-4c2c-b051-164867c409
9a","volumeId":1,"vmName":"s-1-VM","accountId":1,"format":"VHD","id":1,"devi
ceId":0,"hypervisorType":"Hyperv"}},"diskSeq":0,"path":"f09879e9-fe76-4c2c-b
051-164867c4099a","type":"ROOT","_details":{"managed":"false","storagePort":
"445","storageHost":"192.168.1.79","volumeSize":"0"}}],"nics":[{"deviceId":2
,"networkRateMbps":-1,"defaultNic":true,"uuid":"88b614de-d611-4e46-94e5-5476
2d10f1c7","ip":"192.168.1.236","netmask":"255.255.255.0","gateway":"192.168.
1.254","mac":"06:06:40:00:00:1b","dns1":"192.168.1.129","dns2":"8.8.8.8","br
oadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSec
urityGroupEnabled":true,"name":"VirtualSwitch"},{"deviceId":0,"networkRateMb
ps":-1,"defaultNic":false,"uuid":"fe7ff75d-67d7-4728-afc9-6cc6d4f8760b","ip"
:"169.254.2.19","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00
:a9:fe:02:13","broadcastType":"LinkLocal","type":"Control","isSecurityGroupE
nabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":
"246aa3bd-83d6-44ea-98ce-d0ff65b29249","ip":"192.168.1.214","netmask":"255.2
55.255.0","gateway":"192.168.1.254","mac":"06:31:c2:00:00:05","broadcastType
":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"Virtua
lSwitch"},{"deviceId":3,"networkRateMbps":-1,"defaultNic":false,"uuid":"bb6d
d0ef-ef4c-47a6-a553-3f4463909e73","ip":"192.168.1.216","netmask":"255.255.25
5.0","gateway":"192.168.1.254","mac":"06:22:28:00:00:07","broadcastType":"Na
tive","type":"Storage","isSecurityGroupEnabled":false,"name":"VirtualSwitch"
}]},"result":false,"details":"com.cloud.agent.api.StartCommand fail on
exceptionObject reference not set to an instance of an object.","wait":0}}]
}
2014-11-20 14:53:25,187 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Seq
1-425590164786511885: Received:  { Ans: , MgmtId: 52237247174, via: 1, Ver:
v1, Flags: 10, { StartAnswer } }
2014-11-20 14:53:25,191 INFO  [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Unable to start
VM on Host[-1-Routing] due to com.cloud.agent.api.StartCommand fail on
exceptionObject reference not set to an instance of an object.
2014-11-20 14:53:25,194 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Cleaning up
resources for the vm VM[SecondaryStorageVm|s-1-VM] in Starting state
2014-11-20 14:53:25,201 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Seq
1-425590164786511886: Sending  { Cmd , MgmtId: 52237247174, via:
1(192.168.1.78), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":fal
se,"checkBeforeCleanup":false,"vmName":"s-1-VM","wait":0}}] }
2014-11-20 14:53:25,201 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Seq
1-425590164786511886: Executing:  { Cmd , MgmtId: 52237247174, via:
1(192.168.1.78), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":fal
se,"checkBeforeCleanup":false,"vmName":"s-1-VM","wait":0}}] }
2014-11-20 14:53:25,203 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-8:ctx-a8bd9166) Seq 1-425590164786511886: Executing request
2014-11-20 14:53:25,203 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-8:ctx-a8bd9166) POST request to
https://secure-web.cisco.com/155ZBHWq48mGeBZTplmrjfJREiGpoXjhhdP81Z9n36dsv1_
aRE4XKYNtxXza0DiD886-Lq2sd0iY3kAaYr3tvKrkYAxAsCkp7FdzU80jVOyd-73HBd6z4H23YZP
60SfkuVwxM1NnR-k26eM0Csw7tvJT1P9lAizUBZ8FbdQWH4yA/https%3A%2F%2F192.168.1.78
%3A8250%2Fapi%2FHypervResource%2Fcom.cloud.agent.api.StopCommand
with contents
{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmNam
e":"s-1-VM","contextMap":{},"wait":0}
2014-11-20 14:53:25,219 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-8:ctx-a8bd9166) Sending cmd to
https://secure-web.cisco.com/155ZBHWq48mGeBZTplmrjfJREiGpoXjhhdP81Z9n36dsv1_
aRE4XKYNtxXza0DiD886-Lq2sd0iY3kAaYr3tvKrkYAxAsCkp7FdzU80jVOyd-73HBd6z4H23YZP
60SfkuVwxM1NnR-k26eM0Csw7tvJT1P9lAizUBZ8FbdQWH4yA/https%3A%2F%2F192.168.1.78
%3A8250%2Fapi%2FHypervResource%2Fcom.cloud.agent.api.StopCommand
cmd
data:{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"
vmName":"s-1-VM","contextMap":{},"wait":0}
2014-11-20 14:53:25,600 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-6:ctx-89f721b0) POST response is
[{"com.cloud.agent.api.StartAnswer":{"result":false,"details":"com.cloud.age
nt.api.StartCommand fail on exceptionObject reference not set to an instance
of an
object.","vm":{"id":2,"name":"v-2-VM","type":"ConsoleProxy","cpus":1,"minSpe
ed":500,"maxSpeed":500,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_6
4","os":"Debian GNU/Linux 5.0 (64-bit)","bootArgs":" template=domP
type=consoleproxy host=192.168.1.130 port=8250 name=v-2-VM zone=1 pod=1
guid=Proxy.2 proxy_vm=2 disable_rp_filter=true eth2ip=192.168.1.237
eth2mask=255.255.255.0 gateway=192.168.1.254 eth0ip=169.254.1.185
eth0mask=255.255.0.0 eth1ip=192.168.1.217 eth1mask=255.255.255.0
mgmtcidr=192.168.1.0/24 localgw=192.168.1.254 internaldns1=192.168.1.129
internaldns2=8.8.8.8 dns1=192.168.1.129 dns2=8.8.8.8","rebootOnCrash":false,
"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPa
ssword":"65ddb27a77d86ad2","params":{},"uuid":"d9fe04b4-2192-43ac-84a6-91391
6cc27e4","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO"
:{"uuid":"bab80dd6-16da-4713-979d-c69b91d7eea6","volumeType":"ROOT","dataSto
re":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b48e8cd6
-8ec5-3c34-8a43-020c6daaaea9","id":1,"poolType":"SMB","host":"192.168.1.79",
"path":"/WINPrimary?user=cloudstackadmin&domain=cloud","port":445,"url":"SMB
://192.168.1.79/WINPrimary?user=cloudstackadmin&domain=cloud/?ROLE=Primary&S
TOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6daaaea9"}},"name":"ROOT-2","size":0,"p
ath":"bab80dd6-16da-4713-979d-c69b91d7eea6","volumeId":2,"vmName":"v-2-VM","
accountId":1,"format":"VHD","id":2,"deviceId":0,"hypervisorType":"Hyperv"}},
"diskSeq":0,"path":"bab80dd6-16da-4713-979d-c69b91d7eea6","type":"ROOT","_de
tails":{"managed":"false","storagePort":"445","storageHost":"192.168.1.79","
volumeSize":"0"}}],"nics":[{"deviceId":2,"networkRateMbps":-1,"defaultNic":t
rue,"uuid":"88b614de-d611-4e46-94e5-54762d10f1c7","ip":"192.168.1.237","netm
ask":"255.255.255.0","gateway":"192.168.1.254","mac":"06:d4:8e:00:00:1c","dn
s1":"192.168.1.129","dns2":"8.8.8.8","broadcastType":"Native","type":"Guest"
,"broadcastUri":"vlan://untagged","isSecurityGroupEnabled":true,"name":"Virt
ualSwitch"},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"fe
7ff75d-67d7-4728-afc9-6cc6d4f8760b","ip":"169.254.1.185","netmask":"255.255.
0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:01:b9","broadcastType":"Link
Local","type":"Control","isSecurityGroupEnabled":false},{"deviceId":1,"netwo
rkRateMbps":-1,"defaultNic":false,"uuid":"246aa3bd-83d6-44ea-98ce-d0ff65b292
49","ip":"192.168.1.217","netmask":"255.255.255.0","gateway":"192.168.1.254"
,"mac":"06:75:be:00:00:08","broadcastType":"Native","type":"Management","isS
ecurityGroupEnabled":false,"name":"VirtualSwitch"}]},"contextMap":{}}}]
2014-11-20 14:53:25,606 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-6:ctx-89f721b0) executeRequest received response
[Lcom.cloud.agent.api.Answer;@6f800ac8
2014-11-20 14:53:25,606 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-6:ctx-89f721b0) Seq 1-425590164786511884: Cancelling because
one of the answers is false and it is stop on error.
2014-11-20 14:53:25,606 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-6:ctx-89f721b0) Seq 1-425590164786511884: Response Received:
2014-11-20 14:53:25,614 DEBUG [c.c.a.t.Request] (DirectAgent-6:ctx-89f721b0)
Seq 1-425590164786511884: Processing:  { Ans: , MgmtId: 52237247174, via: 1,
Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StartAnswer":{"vm":{"id":2,"name":"v-2-VM","type":"Co
nsoleProxy","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":1073741824,"maxR
am":1073741824,"arch":"x86_64","os":"Debian GNU/Linux 5.0
(64-bit)","bootArgs":" template=domP type=consoleproxy host=192.168.1.130
port=8250 name=v-2-VM zone=1 pod=1 guid=Proxy.2 proxy_vm=2
disable_rp_filter=true eth2ip=192.168.1.237 eth2mask=255.255.255.0
gateway=192.168.1.254 eth0ip=169.254.1.185 eth0mask=255.255.0.0
eth1ip=192.168.1.217 eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24
localgw=192.168.1.254 internaldns1=192.168.1.129 internaldns2=8.8.8.8
dns1=192.168.1.129
dns2=8.8.8.8","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"en
ableDynamicallyScaleVm":false,"vncPassword":"65ddb27a77d86ad2","params":{},"
uuid":"d9fe04b4-2192-43ac-84a6-913916cc27e4","disks":[{"data":{"org.apache.c
loudstack.storage.to.VolumeObjectTO":{"uuid":"bab80dd6-16da-4713-979d-c69b91
d7eea6","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.P
rimaryDataStoreTO":{"uuid":"b48e8cd6-8ec5-3c34-8a43-020c6daaaea9","id":1,"po
olType":"SMB","host":"192.168.1.79","path":"/WINPrimary?user=cloudstackadmin
&domain=cloud","port":445,"url":"SMB://192.168.1.79/WINPrimary?user=cloudsta
ckadmin&domain=cloud/?ROLE=Primary&STOREUUID=b48e8cd6-8ec5-3c34-8a43-020c6da
aaea9"}},"name":"ROOT-2","size":0,"path":"bab80dd6-16da-4713-979d-c69b91d7ee
a6","volumeId":2,"vmName":"v-2-VM","accountId":1,"format":"VHD","id":2,"devi
ceId":0,"hypervisorType":"Hyperv"}},"diskSeq":0,"path":"bab80dd6-16da-4713-9
79d-c69b91d7eea6","type":"ROOT","_details":{"managed":"false","storagePort":
"445","storageHost":"192.168.1.79","volumeSize":"0"}}],"nics":[{"deviceId":2
,"networkRateMbps":-1,"defaultNic":true,"uuid":"88b614de-d611-4e46-94e5-5476
2d10f1c7","ip":"192.168.1.237","netmask":"255.255.255.0","gateway":"192.168.
1.254","mac":"06:d4:8e:00:00:1c","dns1":"192.168.1.129","dns2":"8.8.8.8","br
oadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isSec
urityGroupEnabled":true,"name":"VirtualSwitch"},{"deviceId":0,"networkRateMb
ps":-1,"defaultNic":false,"uuid":"fe7ff75d-67d7-4728-afc9-6cc6d4f8760b","ip"
:"169.254.1.185","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:0
0:a9:fe:01:b9","broadcastType":"LinkLocal","type":"Control","isSecurityGroup
Enabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid"
:"246aa3bd-83d6-44ea-98ce-d0ff65b29249","ip":"192.168.1.217","netmask":"255.
255.255.0","gateway":"192.168.1.254","mac":"06:75:be:00:00:08","broadcastTyp
e":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"Virtu
alSwitch"}]},"result":false,"details":"com.cloud.agent.api.StartCommand fail
on exceptionObject reference not set to an instance of an
object.","wait":0}}] }
2014-11-20 14:53:25,614 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-2:ctx-c1208fbd job-2/job-10 ctx-5358fd84) Seq
1-425590164786511884: Received:  { Ans: , MgmtId: 52237247174, via: 1, Ver:
v1, Flags: 10, { StartAnswer } }
2014-11-20 14:53:25,622 INFO  [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-2:ctx-c1208fbd job-2/job-10 ctx-5358fd84) Unable to start
VM on Host[-1-Routing] due to com.cloud.agent.api.StartCommand fail on
exceptionObject reference not set to an instance of an object.
2014-11-20 14:53:25,625 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-2:ctx-c1208fbd job-2/job-10 ctx-5358fd84) Cleaning up
resources for the vm VM[ConsoleProxy|v-2-VM] in Starting state
2014-11-20 14:53:25,631 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-2:ctx-c1208fbd job-2/job-10 ctx-5358fd84) Seq
1-425590164786511887: Sending  { Cmd , MgmtId: 52237247174, via:
1(192.168.1.78), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":fal
se,"checkBeforeCleanup":false,"vmName":"v-2-VM","wait":0}}] }
2014-11-20 14:53:25,632 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-2:ctx-c1208fbd job-2/job-10 ctx-5358fd84) Seq
1-425590164786511887: Executing:  { Cmd , MgmtId: 52237247174, via:
1(192.168.1.78), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":fal
se,"checkBeforeCleanup":false,"vmName":"v-2-VM","wait":0}}] }
2014-11-20 14:53:25,632 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-1:ctx-704d22cf) Seq 1-425590164786511887: Executing request
2014-11-20 14:53:25,633 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-1:ctx-704d22cf) POST request to
https://secure-web.cisco.com/155ZBHWq48mGeBZTplmrjfJREiGpoXjhhdP81Z9n36dsv1_
aRE4XKYNtxXza0DiD886-Lq2sd0iY3kAaYr3tvKrkYAxAsCkp7FdzU80jVOyd-73HBd6z4H23YZP
60SfkuVwxM1NnR-k26eM0Csw7tvJT1P9lAizUBZ8FbdQWH4yA/https%3A%2F%2F192.168.1.78
%3A8250%2Fapi%2FHypervResource%2Fcom.cloud.agent.api.StopCommand
with contents
{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmNam
e":"v-2-VM","contextMap":{},"wait":0}
2014-11-20 14:53:25,642 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-1:ctx-704d22cf) Sending cmd to
https://secure-web.cisco.com/155ZBHWq48mGeBZTplmrjfJREiGpoXjhhdP81Z9n36dsv1_
aRE4XKYNtxXza0DiD886-Lq2sd0iY3kAaYr3tvKrkYAxAsCkp7FdzU80jVOyd-73HBd6z4H23YZP
60SfkuVwxM1NnR-k26eM0Csw7tvJT1P9lAizUBZ8FbdQWH4yA/https%3A%2F%2F192.168.1.78
%3A8250%2Fapi%2FHypervResource%2Fcom.cloud.agent.api.StopCommand
cmd
data:{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"
vmName":"v-2-VM","contextMap":{},"wait":0}
2014-11-20 14:53:26,717 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-8:ctx-a8bd9166) POST response is
[{"com.cloud.agent.api.StopAnswer":{"result":true,"details":null,"vm":null,"
contextMap":{}}}]
2014-11-20 14:53:26,718 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-8:ctx-a8bd9166) executeRequest received response
[Lcom.cloud.agent.api.Answer;@682fcaba
2014-11-20 14:53:26,719 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-8:ctx-a8bd9166) Seq 1-425590164786511886: Response Received:
2014-11-20 14:53:26,719 DEBUG [c.c.a.t.Request] (DirectAgent-8:ctx-a8bd9166)
Seq 1-425590164786511886: Processing:  { Ans: , MgmtId: 52237247174, via: 1,
Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2014-11-20 14:53:26,719 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Seq
1-425590164786511886: Received:  { Ans: , MgmtId: 52237247174, via: 1, Ver:
v1, Flags: 10, { StopAnswer } }
2014-11-20 14:53:26,753 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Asking
SecurityGroupProvider to release
NicProfile[1-1-f3a53a4e-da5d-4c91-a95d-8cac27008d16-192.168.1.236-vlan://unt
agged
2014-11-20 14:53:26,757 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Asking
VirtualRouter to release
NicProfile[1-1-f3a53a4e-da5d-4c91-a95d-8cac27008d16-192.168.1.236-vlan://unt
agged
2014-11-20 14:53:26,762 DEBUG [c.c.n.g.ControlNetworkGuru]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Released nic:
NicProfile[2-1-null-null-null
2014-11-20 14:53:26,773 DEBUG [c.c.d.d.DataCenterIpAddressDaoImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Releasing ip
address for reservationId=f3a53a4e-da5d-4c91-a95d-8cac27008d16, instance=3
2014-11-20 14:53:26,774 DEBUG [c.c.n.g.PodBasedNetworkGuru]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Released nic:
NicProfile[3-1-null-null-null
2014-11-20 14:53:26,786 DEBUG [c.c.d.d.DataCenterIpAddressDaoImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Releasing ip
address for reservationId=f3a53a4e-da5d-4c91-a95d-8cac27008d16, instance=5
2014-11-20 14:53:26,786 DEBUG [c.c.n.g.PodBasedNetworkGuru]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Released nic:
NicProfile[5-1-null-null-null
2014-11-20 14:53:26,790 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Successfully
released network resources for the vm VM[SecondaryStorageVm|s-1-VM]
2014-11-20 14:53:26,790 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Successfully
cleanued up resources for the vm VM[SecondaryStorageVm|s-1-VM] in Starting
state
2014-11-20 14:53:26,795 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Root volume is
ready, need to place VM in volume's cluster
2014-11-20 14:53:26,795 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927)
Vol[1|vm=1|ROOT] is READY, changing deployment plan to use this pool's dcId:
1 , podId: 1 , and clusterId: 1
2014-11-20 14:53:26,798 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Deploy avoids
pods: null, clusters: null, hosts: [1]
2014-11-20 14:53:26,799 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927)
DeploymentPlanner allocation algorithm:
com.cloud.deploy.FirstFitPlanner@6ba6ccb5
2014-11-20 14:53:26,799 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Trying to
allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu:
500, requested ram: 536870912
2014-11-20 14:53:26,799 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Is ROOT volume
READY (pool already allocated)?: Yes
2014-11-20 14:53:26,800 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Searching
resources only under specified Cluster: 1
2014-11-20 14:53:26,808 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Checking
resources in Cluster: 1 under Pod: 1
2014-11-20 14:53:26,808 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927
FirstFitRoutingAllocator) Looking for hosts in dc: 1  pod:1  cluster:1
2014-11-20 14:53:26,813 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927
FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for
allocation: [Host[-1-Routing]]
2014-11-20 14:53:26,820 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927
FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization:
[Host[-1-Routing]]
2014-11-20 14:53:26,820 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927
FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512
2014-11-20 14:53:26,820 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927
FirstFitRoutingAllocator) Host name: 192.168.1.78, hostId: 1 is in avoid
set, skipping this and trying other available hosts
2014-11-20 14:53:26,820 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927
FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
2014-11-20 14:53:26,820 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) No suitable
hosts found
2014-11-20 14:53:26,820 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) No suitable
hosts found under this Cluster: 1
2014-11-20 14:53:26,823 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Could not find
suitable Deployment Destination for this VM under any clusters, returning.
2014-11-20 14:53:26,823 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Searching
resources only under specified Cluster: 1
2014-11-20 14:53:26,824 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) The specified
cluster is in avoid set, returning.
2014-11-20 14:53:26,827 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Deploy avoids
pods: null, clusters: [1], hosts: [1]
2014-11-20 14:53:26,828 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927)
DeploymentPlanner allocation algorithm:
com.cloud.deploy.FirstFitPlanner@6ba6ccb5
2014-11-20 14:53:26,828 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Trying to
allocate a host and storage pools from dc:1, pod:null,cluster:null,
requested cpu: 500, requested ram: 536870912
2014-11-20 14:53:26,828 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Is ROOT volume
READY (pool already allocated)?: No
2014-11-20 14:53:26,829 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Searching all
possible resources under this Zone: 1
2014-11-20 14:53:26,830 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Listing
clusters in order of aggregate capacity, that have (atleast one host with)
enough CPU and RAM capacity under this Zone: 1
2014-11-20 14:53:26,835 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Removing from
the clusterId list these clusters from avoid set: [1]
2014-11-20 14:53:26,836 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) No clusters
found after removing disabled clusters and clusters in avoid list,
returning.
2014-11-20 14:53:26,856 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) VM state
transitted from :Starting to Stopped with event: OperationFailedvm's
original host id: null new host id: null host id before state transition: 1
2014-11-20 14:53:26,868 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Hosts's actual
total CPU: 32000 and CPU after applying overprovisioning: 32000
2014-11-20 14:53:26,868 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Hosts's actual
total RAM: 137357664256 and RAM after applying overprovisioning:
137357664256
2014-11-20 14:53:26,868 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) release cpu
from host: 1, old used: 1000,reserved: 0, actual total: 32000, total with
overprovisioning: 32000; new used: 500,reserved:0; movedfromreserved: false,
moveToReserveredfalse
2014-11-20 14:53:26,868 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) release mem
from host: 1, old used: 1610612736,reserved: 0, total: 137357664256; new
used: 1073741824,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-11-20 14:53:26,872 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-1:ctx-704d22cf) POST response is
[{"com.cloud.agent.api.StopAnswer":{"result":true,"details":null,"vm":null,"
contextMap":{}}}]
2014-11-20 14:53:26,873 DEBUG [c.c.h.h.r.HypervDirectConnectResource]
(DirectAgent-1:ctx-704d22cf) executeRequest received response
[Lcom.cloud.agent.api.Answer;@48486fc3
2014-11-20 14:53:26,874 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-1:ctx-704d22cf) Seq 1-425590164786511887: Response Received:
2014-11-20 14:53:26,874 DEBUG [c.c.a.t.Request] (DirectAgent-1:ctx-704d22cf)
Seq 1-425590164786511887: Processing:  { Ans: , MgmtId: 52237247174, via: 1,
Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2014-11-20 14:53:26,875 ERROR [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Invocation
exception, caused by:
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[SecondaryStorageVm|s-1-VM]Scope=interface
com.cloud.dc.DataCenter; id=1
2014-11-20 14:53:26,875 INFO  [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11 ctx-ebe86927) Rethrow
exception com.cloud.exception.InsufficientServerCapacityException: Unable to
create a deployment for VM[SecondaryStorageVm|s-1-VM]Scope=interface
com.cloud.dc.DataCenter; id=1
2014-11-20 14:53:26,876 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11) Done with run of VM work
job: com.cloud.vm.VmWorkStart for VM 1, job origin: 1
2014-11-20 14:53:26,876 ERROR [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-1:ctx-62db4a9e job-1/job-11) Unable to complete
AsyncJobVO {id:11, userId: 1, accountId: 1, instanceType: null, instanceId:
null, cmd: com.cloud.vm.VmWorkStart, cmdInfo:
rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9p
ZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAlj
bHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQA
EkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-
AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01h
cDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAE
SgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAAB
AAAAAAAAAAEAAAAAAAAAAXQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBw
cHBwcHA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode:
0, result: null, initMsid: 52237247174, completeMsid: null, lastUpdated:
null, lastPolled: null, created: Thu Nov 20 14:53:03 CST 2014}, job origin:1
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[SecondaryStorageVm|s-1-VM]Scope=interface
com.cloud.dc.DataCenter; id=1
        at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManage
rImpl.java:947)
        at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManage
rImpl.java:5195)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
)
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
.java:43)
        at java.lang.reflect.Method.invoke(Method.java:606)
        at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.jav
a:107)
        at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManager
Impl.java:5340)
        at
com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
        at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext
(AsyncJobManagerImpl.java:503)
        at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedCo
ntextRunnable.java:49)
        at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(Defa
ultManagedContext.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(ManagedCont
extRunnable.java:46)
        at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJob
ManagerImpl.java:460)
        at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
        at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:11
45)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:6
15)


and The logs in the Hyperv server is as follows:

Error HypervResource.HypervResourceController -
com.cloud.agent.api.StartCommand fail in exceptionObject reference not set
to an instance of an object.
System.NullReferenceException: Object reference not set to an instance of an
object.
At HypervResource.WmiCallsV2.DeployVirtualMachine(object JsonObj, String
systemVmIso)
At HypervResource.HypervResourceController.StartCommand(Object cmd)

khmu

-----邮件原件-----
发件人: 穆凯辉 [mailto:khmu@landhightech.com]
发送时间: 2014年11月20日 16:06
收件人: dev@cloudstack.apache.org
主题: 答复: hyperv ssvm start failed

Hi,

We still can not run cloudstack 4.4.1 + hyperv successfully. The Hyperv ssvm
still can not start successfully.

We run cloudstack 4.4.1 in centos 6.5, not added into ad. A 2012 R2 Hyperv
server is used to create hyperv vm with two Ethernet, one for cloudstack
management, and an external switch created on the other enternet. This
hyperv server have been added to AD. A windows server 2012 is created for
the Primary and Secondary storage use SMB protocol, which also has been
added into ad.

When we start the whole zone. The ssvm can not start successfully. The log
of cloudstack is attached in this mail as named "error.log" and The error
log in Hyperv Server is only one as shown in "hyperv-server.png".

Should the cloudstack manage server be added into AD?

Your response is very important for us. Thank you very much.

khmu
-----邮件原件-----
发件人: 穆凯辉 [mailto:khmu@landhightech.com]
发送时间: 2014年11月14日 15:42
收件人: dev@cloudstack.apache.org
主题: 答复: hyperv ssvm start failed

Sorry, we encountered some problem to install the windows server 2012 dc R2.
So we now try to install Hyperv server 2012 r2.
Can windows server 2012 dc be also used for hyperv host with cloudstack 4.4?
We will inform you as soon as possible if there is some progress.

------------------------------------------------
-----邮件原件-----
发件人: Rajesh Battala [mailto:rajesh.battala@citrix.com]
发送时间: 2014年11月14日 15:24
收件人: dev@cloudstack.apache.org
主题: RE: hyperv ssvm start failed

Is it working now?

-----Original Message-----
From: 穆凯辉 [mailto:khmu@landhightech.com]
Sent: Thursday, November 13, 2014 11:52 AM
To: dev@cloudstack.apache.org
Subject: 答复: hyperv ssvm start failed

Ok. We will change to windows server 2012 hyperv host with English locale
set. Thank you very much.

----------------------------------------------------------------------------
-------------------------------
穆凯辉
苏州蓝海彤翔系统科技有限公司
Suzhou Land High System Tech CO.,Ltd
地址:苏州高新区科灵路78号7号楼2层
手机:13771859356
邮编:215163
----------------------------------------------------------------------------
-------------------------------


-----邮件原件-----
发件人: Anshul Gangwar [mailto:anshul.gangwar@citrix.com]
发送时间: 2014年11月13日 14:00
收件人: dev@cloudstack.apache.org
主题: RE: hyperv ssvm start failed

Probably you are facing issue
https://issues.apache.org/jira/browse/CLOUDSTACK-7277.

-----Original Message-----
From: Anshul Gangwar [mailto:anshul.gangwar@citrix.com]
Sent: Thursday, November 13, 2014 10:52 AM
To: dev@cloudstack.apache.org
Subject: RE: hyperv ssvm start failed

You got me wrong. I have not suggested to change permissions. I have
suggested to change the locale to US English(instead of Chinese/Japanese) of
account with which the Hyper-V Agent service is running.

I suspect that your windows server account is running in different locale
other than English.


-----Original Message-----
From: 穆凯辉 [mailto:khmu@landhightech.com]
Sent: Thursday, November 13, 2014 6:10 AM
To: dev@cloudstack.apache.org
Subject: 答复: hyperv ssvm start failed

Thanks.

We try to run Hyper-v agent by local administrator. But the agent crashed.
So we change to use domain administrator to run this agent.

We will try to create a new user to run this agent.

Thank you very much.



----------------------------------------------------------------------------
-------------------------------

-----邮件原件-----
发件人: Anshul Gangwar [mailto:anshul.gangwar@citrix.com]
发送时间: 2014年11月12日 19:39
收件人: dev@cloudstack.apache.org
主题: RE: hyperv ssvm start failed

You have to run Hyper-V Agent service with the account which has it locale
set to US English.



-----Original Message-----
From: 穆凯辉 [mailto:khmu@landhightech.com]
Sent: Wednesday, November 12, 2014 4:56 PM
To: dev@cloudstack.apache.org
Subject: hyperv ssvm start failed

Hi all,



         We use cloudstack 4.4.0 to manage a windows server 2012 dc hyper-v
host. Both of the primary and secondary storage are setup on this windows
hyper-v host using SMB protocol. The Virtual Switch in Hyperv is named
“VirtualNetork”.



when we start the zone, the ssvm is created in hyper-v, but it can not
start, and is destroy immediately. The error event in windows is as follows:




2014-11-12 18:55:03,150 [12] INFO  HypervResource.HypervResourceController
[55c7a1ce-0320-4976-9915-ae6fb44682ba] - {

  "com.cloud.agent.api.StartAnswer": {

    "result": false,

    "details": "com.cloud.agent.api.StartCommand fail on exception未将对象引
用设置到对象的实例。",

    "vm": {

      "id": 1,

      "name": "v-1-VM",

      "type": "ConsoleProxy",

      "cpus": 1,

      "minSpeed": 500,

      "maxSpeed": 500,

      "minRam": 1073741824,

      "maxRam": 1073741824,

      "arch": "x86_64",

      "os": "Debian GNU/Linux 5.0 (64-bit)",

      "bootArgs": " template=domP type=consoleproxy host=192.168.1.137
port=8250 name=v-1-VM zone=1 pod=1 guid=Proxy.1 proxy_vm=1
disable_rp_filter=true eth2ip=192.168.1.33 eth2mask=255.255.255.0
gateway=192.168.1.254 eth0ip=169.254.0.70 eth0mask=255.255.0.0
eth1ip=192.168.1.224 eth1mask=255.255.255.0 mgmtcidr=192.168.1.0/24
localgw=192.168.1.254 internaldns1=192.168.1.92 internaldns2=8.8.8.8
dns1=192.168.1.92 dns2=8.8.8.8",

      "rebootOnCrash": false,

      "enableHA": false,

      "limitCpuUse": false,

      "enableDynamicallyScaleVm": false,

      "vncPassword": "861c2ac4e36ed3c3",

      "params": {},

      "uuid": "0c1a15f6-5cc6-4c10-8cf7-46fac26ee215",

      "disks": [

        {

          "data": {

            "org.apache.cloudstack.storage.to.VolumeObjectTO": {

              "uuid": "8b299dfc-2453-4e6a-bd02-b6dcc12fb32a",

              "volumeType": "ROOT",

              "dataStore": {

                "org.apache.cloudstack.storage.to.PrimaryDataStoreTO": {

                  "uuid": "2c739a85-40bf-365f-b448-152f6e10cad0",

                  "id": 2,

                  "poolType": "SMB",

                  "host": "192.168.1.80",

                  "path": "/Primary?user=administrator&domain=vsdevel",

                  "port": 445,

                  "url":
"SMB://192.168.1.80/Primary?user=administrator&domain=vsdevel/?ROLE=Primary&
STOREUUID=2c739a85-40bf-365f-b448-152f6e10cad0"

                }

              },

              "name": "ROOT-1",

              "size": 0,

              "path": "8b299dfc-2453-4e6a-bd02-b6dcc12fb32a",

              "volumeId": 1,

              "vmName": "v-1-VM",

              "accountId": 1,

              "format": "VHD",

              "id": 1,

              "deviceId": 0,

              "hypervisorType": "Hyperv"

            }

          },

          "diskSeq": 0,

          "path": "8b299dfc-2453-4e6a-bd02-b6dcc12fb32a",

          "type": "ROOT",

          "_details": {

            "managed": "false",

            "storagePort": "445",

            "storageHost": "192.168.1.80",

            "volumeSize": "0"

          }

        }

      ],

      "nics": [

        {

          "deviceId": 2,

          "networkRateMbps": -1,

          "defaultNic": true,

          "uuid": "e48caaf7-b544-443c-94ee-40055fcf90cc",

          "ip": "192.168.1.33",

          "netmask": "255.255.255.0",

          "gateway": "192.168.1.254",

          "mac": "06:4b:cc:00:00:87",

          "dns1": "192.168.1.92",

          "dns2": "8.8.8.8",

          "broadcastType": "Native",

          "type": "Guest",

          "broadcastUri": "vlan://untagged",

          "isSecurityGroupEnabled": true,

          "name": "VirtualNetwork"

        },

        {

          "deviceId": 0,

          "networkRateMbps": -1,

          "defaultNic": false,

          "uuid": "13bb00ec-b354-4fbf-b3f6-fb0dc29715b4",

          "ip": "169.254.0.70",

          "netmask": "255.255.0.0",

          "gateway": "169.254.0.1",

          "mac": "0e:00:a9:fe:00:46",

          "broadcastType": "LinkLocal",

          "type": "Control",

          "isSecurityGroupEnabled": false

        },

        {

          "deviceId": 1,

          "networkRateMbps": -1,

          "defaultNic": false,

          "uuid": "a6d63c0f-72b9-439e-91ce-d158cb37a482",

          "ip": "192.168.1.224",

          "netmask": "255.255.255.0",

          "gateway": "192.168.1.254",

          "mac": "06:e7:80:00:00:5f",

          "broadcastType": "Native",

          "type": "Management",

          "isSecurityGroupEnabled": false,

          "name": "VirtualNetwork"

        }

      ]

    },

    "contextMap": {}

  }

}







We have worked on this problem 3 days, and setup the new zone again and
again. But we still can not solve this problem.The Agentshell.exe is build
in our development environment.

Can anyone encounter this problem. Please help us. Thank you very much.





Khmu










Mime
View raw message