cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Girish Shilamkar (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (CLOUDSTACK-5342) Add NIC to virtual machine fails in KVM
Date Thu, 12 Dec 2013 03:48:11 GMT

    [ https://issues.apache.org/jira/browse/CLOUDSTACK-5342?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13846043#comment-13846043
] 

Girish Shilamkar commented on CLOUDSTACK-5342:
----------------------------------------------

ceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.user.vm.AddNicToVMCmd,
cmdInfo: {"response":"json","sessionkey":"D+cRXhCkN+eHk9chCpFpEVBD47E\u003d","virtualmachineid":"bcddd332-9c2d-4319-b421-097e72f10167","cmdEventType":"NIC.CREATE","ctxUserId":"2","httpmethod":"GET","_":"1386158703567","ctxAccountId":"2","networkid":"a05731b2-b132-4087-b250-5a159fb811bf","ctxStartEventId":"379"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid:
6851580133501, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-12-04 22:56:10,915 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-b672bd0f ctx-23a1ba4b)
===END===  10.252.192.19 -- GET  command=addNicToVirtualMachine&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&virtualmachineid=bcddd332-9c2d-4319-b421-097e72f10167&networkid=a05731b2-b132-4087-b250-5a159fb811bf&_=1386158703567
2013-12-04 22:56:10,919 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-17:ctx-ebfd064f)
Add job-96 into job monitoring
2013-12-04 22:56:10,919 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-17:ctx-ebfd064f)
Executing AsyncJobVO {id:96, userId: 2, accountId: 2, instanceType: None, instanceId: null,
cmd: org.apache.cloudstack.api.command.user.vm.AddNicToVMCmd, cmdInfo: {"response":"json","sessionkey":"D+cRXhCkN+eHk9chCpFpEVBD47E\u003d","virtualmachineid":"bcddd332-9c2d-4319-b421-097e72f10167","cmdEventType":"NIC.CREATE","ctxUserId":"2","httpmethod":"GET","_":"1386158703567","ctxAccountId":"2","networkid":"a05731b2-b132-4087-b250-5a159fb811bf","ctxStartEventId":"379"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid:
6851580133501, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-12-04 22:56:10,944 DEBUG [c.c.v.VirtualMachineManagerImpl] (Job-Executor-17:ctx-ebfd064f
ctx-23a1ba4b) Adding vm VM[User|testVM1] to network Ntwk[205|Guest|8]; requested nic profile
NicProfile[0-0-null-null-null
2013-12-04 22:56:10,957 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-17:ctx-ebfd064f
ctx-23a1ba4b) Allocating nic for vm VM[User|testVM1] in network Ntwk[205|Guest|8] with requested
profile NicProfile[0-0-null-null-null
2013-12-04 22:56:11,002 DEBUG [c.c.n.NetworkModelImpl] (Job-Executor-17:ctx-ebfd064f ctx-23a1ba4b)
Service SecurityGroup is not supported in the network id=205
2013-12-04 22:56:11,005 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-17:ctx-ebfd064f
ctx-23a1ba4b) Nic is allocated successfully for vm VM[User|testVM1] in network Ntwk[205|Guest|8]
2013-12-04 22:56:11,006 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-17:ctx-ebfd064f
ctx-23a1ba4b) Network id=205 is already implemented
2013-12-04 22:56:11,025 DEBUG [c.c.n.NetworkModelImpl] (Job-Executor-17:ctx-ebfd064f ctx-23a1ba4b)
Service SecurityGroup is not supported in the network id=205
2013-12-04 22:56:11,030 DEBUG [c.c.a.t.Request] (AgentManager-Handler-14:null) Seq 1-493553024:
Processing:  { Ans: , MgmtId: 6851580133501, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.CheckRouterAnswer":{"state":"BACKUP","isBumped":false,"result":true,"details":"Status:
BACKUP&Bumped: NO","wait":0}}] }
2013-12-04 22:56:11,031 DEBUG [c.c.a.t.Request] (RedundantRouterStatusMonitor-2:ctx-147da5be)
Seq 1-493553024: Received:  { Ans: , MgmtId: 6851580133501, via: 1, Ver: v1, Flags: 10, {
CheckRouterAnswer } }
2013-12-04 22:56:11,031 DEBUG [c.c.a.m.AgentManagerImpl] (RedundantRouterStatusMonitor-2:ctx-147da5be)
Details from executing class com.cloud.agent.api.CheckRouterCommand: Status: BACKUP&Bumped:
NO
2013-12-04 22:56:11,050 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-17:ctx-ebfd064f
ctx-23a1ba4b) Changing active number of nics for network id=205 on 1
2013-12-04 22:56:11,063 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-17:ctx-ebfd064f
ctx-23a1ba4b) Asking VirtualRouter to prepare for Nic[42-5-null-10.1.1.137]
2013-12-04 22:56:11,081 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Job-Executor-17:ctx-ebfd064f
ctx-23a1ba4b) Lock is acquired for network id 205 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(null)-Cluster(null)-Host(1)-Storage()]
2013-12-04 22:56:11,085 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Job-Executor-17:ctx-ebfd064f
ctx-23a1ba4b) Lock is released for network id 205 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(null)-Cluster(null)-Host(1)-Storage()]
2013-12-04 22:56:11,098 DEBUG [c.c.n.NetworkModelImpl] (Job-Executor-17:ctx-ebfd064f ctx-23a1ba4b)
Service SecurityGroup is not supported in the network id=205
2013-12-04 22:56:11,119 DEBUG [c.c.n.NetworkModelImpl] (Job-Executor-17:ctx-ebfd064f ctx-23a1ba4b)
Service SecurityGroup is not supported in the network id=205
2013-12-04 22:56:11,128 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Job-Executor-17:ctx-ebfd064f
ctx-23a1ba4b) Applying dhcp entry in network Ntwk[205|Guest|8]
2013-12-04 22:56:11,160 DEBUG [c.c.a.t.Request] (Job-Executor-17:ctx-ebfd064f ctx-23a1ba4b)
Seq 1-493553025: Sending  { Cmd , MgmtId: 6851580133501, via: 1(Rack1Pod1Host31), Ver: v1,
Flags: 100011, [{"com.cloud.agent.api.routing.DhcpEntryCommand":{"vmMac":"02:00:21:b4:00:04","vmIpAddress":"10.1.1.137","vmName":"testVM1","defaultRouter":"10.1.1.1","defaultDns":"10.1.1.1","duid":"00:03:00:01:02:00:21:b4:00:04","isDefault":false,"executeInSequence":false,"accessDetails":{"router.guest.ip":"10.1.1.1","zone.network.type":"Advanced","router.name":"r-8-VM","router.ip":"169.254.0.210"},"wait":0}}]
}
2013-12-04 22:56:11,312 DEBUG [c.c.a.t.Request] (AgentManager-Handler-3:null) Seq 1-493553025:
Processing:  { Ans: , MgmtId: 6851580133501, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}]
}
2013-12-04 22:56:11,313 DEBUG [c.c.a.t.Request] (Job-Executor-17:ctx-ebfd064f ctx-23a1ba4b)
Seq 1-493553025: Received:  { Ans: , MgmtId: 6851580133501, via: 1, Ver: v1, Flags: 10, {
Answer } }
2013-12-04 22:56:11,326 DEBUG [c.c.n.NetworkModelImpl] (Job-Executor-17:ctx-ebfd064f ctx-23a1ba4b)
Service SecurityGroup is not supported in the network id=205
2013-12-04 22:56:11,338 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (Job-Executor-17:ctx-ebfd064f
ctx-23a1ba4b) Applying userdata and password entry in network Ntwk[205|Guest|8]
2013-12-04 22:56:11,361 DEBUG [c.c.a.t.Request] (Job-Executor-17:ctx-ebfd064f ctx-23a1ba4b)
Seq 1-493553026: Sending  { Cmd , MgmtId: 6851580133501, via: 1(Rack1Pod1Host31), Ver: v1,
Flags: 100011, [{"com.cloud.agent.api.routing.VmDataCommand":{"vmIpAddress":"10.1.1.137","vmName":"testVM1","executeInSequence":false,"accessDetails":{"router.guest.ip":"10.1.1.1","zone.network.type":"Advanced","router.ip":"169.254.0.210","router.name":"r-8-VM"},"wait":0}}]
}
2013-12-04 22:56:11,469 DEBUG [c.c.a.t.Request] (AgentManager-Handler-2:null) Seq 1-493553026:
Processing:  { Ans: , MgmtId: 6851580133501, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}]
}
2013-12-04 22:56:11,469 DEBUG [c.c.a.t.Request] (Job-Executor-17:ctx-ebfd064f ctx-23a1ba4b)
Seq 1-493553026: Received:  { Ans: , MgmtId: 6851580133501, via: 1, Ver: v1, Flags: 10, {
Answer } }
2013-12-04 22:56:11,472 DEBUG [c.c.n.NetworkModelImpl] (Job-Executor-17:ctx-ebfd064f ctx-23a1ba4b)
Service SecurityGroup is not supported in the network id=205
2013-12-04 22:56:11,472 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Job-Executor-17:ctx-ebfd064f
ctx-23a1ba4b) Nic is prepared successfully for vm VM[User|testVM1] in network Ntwk[205|Guest|8]
2013-12-04 22:56:11,481 DEBUG [c.c.v.VirtualMachineManagerImpl] (Job-Executor-17:ctx-ebfd064f
ctx-23a1ba4b) Plugging nic for vm VM[User|testVM1] in network Ntwk[205|Guest|8]
2013-12-04 22:56:11,489 DEBUG [c.c.a.t.Request] (Job-Executor-17:ctx-ebfd064f ctx-23a1ba4b)
Seq 1-493553027: Sending  { Cmd , MgmtId: 6851580133501, via: 1(Rack1Pod1Host31), Ver: v1,
Flags: 100111, [{"com.cloud.agent.api.PlugNicCommand":{"nic":{"deviceId":2,"networkRateMbps":200,"defaultNic":false,"uuid":"a831db68-514a-4489-85d6-f550bc09cff3","ip":"10.1.1.137","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:21:b4:00:04","dns1":"10.140.50.6","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://967","isolationUri":"vlan://967","isSecurityGroupEnabled":false},"instanceName":"i-5-5-VM","vmType":"User","wait":0}}]
}
2013-12-04 22:56:11,703 DEBUG [c.c.a.t.Request] (AgentManager-Handler-4:null) Seq 1-493553027:
Processing:  { Ans: , MgmtId: 6851580133501, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.PlugNicAnswer":{"result":true,"details":"success","wait":0}}]
}
2013-12-04 22:56:11,703 DEBUG [c.c.a.m.AgentAttache] (AgentManager-Handler-4:null) Seq 1-493553027:
No more commands found
2013-12-04 22:56:11,703 DEBUG [c.c.a.t.Request] (Job-Executor-17:ctx-ebfd064f ctx-23a1ba4b)
Seq 1-493553027: Received:  { Ans: , MgmtId: 6851580133501, via: 1, Ver: v1, Flags: 110, {
PlugNicAnswer } }
2013-12-04 22:56:11,704 DEBUG [c.c.v.VirtualMachineManagerImpl] (Job-Executor-17:ctx-ebfd064f
ctx-23a1ba4b) Nic is plugged successfully for vm VM[User|testVM1] in network Ntwk[205|Guest|8].
Vm  is a part of network now
2013-12-04 22:56:11,713 DEBUG [c.c.v.UserVmManagerImpl] (Job-Executor-17:ctx-ebfd064f ctx-23a1ba4b)
Successful addition of Ntwk[205|Guest|8] from VM[User|testVM1]
2013-12-04 22:56:11,738 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-17:ctx-ebfd064f
ctx-23a1ba4b) Complete async job-96, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.UserVmResponse/virtualmachine/{"id":"bcddd332-9c2d-4319-b421-097e72f10167","name":"testVM1","displayname":"testVM1","account":"test","domainid":"7f9219f5-e458-4e76-9454-0901f67b165c","domain":"test","created":"2013-12-03T20:50:34+0530","state":"Running","haenable":false,"zoneid":"5d183080-7858-4adf-92ff-ea6933c9be27","zonename":"z","hostid":"4484f869-a428-482e-990a-f3a908dfbb85","hostname":"Rack1Pod1Host31","guestosid":"112","securitygroup":[],"nic":[{"id":"19ea92f9-9b79-4092-8bd8-b51c2ed6c5b6","networkid":"1a4c3dc6-f0e0-40bf-a005-9b9d85b7696d","networkname":"testNet1","netmask":"255.255.255.0","gateway":"10.1.1.1","ipaddress":"10.1.1.123","isolationuri":"vlan://963","broadcasturi":"vlan://963","traffictype":"Guest","type":"Isolated","isdefault":true,"macaddress":"02:00:70:31:00:01"},{"id":"58f02263-c5e8-4aed-bdf3-de862b8f4ffa","networkid":"eb30c55a-0ed2-494f-90a3-8710f7020ffc","networkname":"shared","netmask":"255.255.255.0","gateway":"10.0.1.1","ipaddress":"10.0.1.5","isolationuri":"vlan://971","broadcasturi":"vlan://971","traffictype":"Guest","type":"Shared","isdefault":false,"macaddress":"06:d0:7c:00:00:2a"},{"id":"a831db68-514a-4489-85d6-f550bc09cff3","networkid":"a05731b2-b132-4087-b250-5a159fb811bf","networkname":"testNet2","netmask":"255.255.255.0","gateway":"10.1.1.1","ipaddress":"10.1.1.137","isolationuri":"vlan://967","broadcasturi":"vlan://967","traffictype":"Guest","type":"Isolated","isdefault":false,"macaddress":"02:00:21:b4:00:04"}],"hypervisor":"KVM","publicipid":"24a1e6cf-0e9e-411f-87d2-7ccef2d805fd","publicip":"10.147.47.10","instancename":"i-5-5-VM","tags":[],"affinitygroup":[],"displayvm":true,"isdynamicallyscalable":false}
2013-12-04 22:56:11,749 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-17:ctx-ebfd064f)
Done executing org.apache.cloudstack.api.command.user.vm.AddNicToVMCmd for job-96
2013-12-04 22:56:11,756 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-17:ctx-ebfd064f)
Remove job-96 from job monitoring
2013-12-04 22:56:12,223 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-6:null) SeqA
5-1455: Processing Seq 5-1455:  { Cmd , MgmtId: -1, via: 5, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":3,"_loadInfo":"{\n
 \"connections\": []\n}","wait":0}}] }
2013-12-04 22:56:12,231 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-6:null) SeqA
5-1455: Sending Seq 5-1455:  { Ans: , MgmtId: 6851580133501, via: 5, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2013-12-04 22:56:14,030 DEBUG [c.c.a.ApiServlet] (catalina-exec-22:ctx-552b3750) ===START===
 10.252.192.19 -- GET  command=queryAsyncJobResult&jobId=38b00d5e-8098-4c47-84c6-2e02d2e7f9a6&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&_=1386158706971
2013-12-04 22:56:14,065 DEBUG [c.c.a.ApiServlet] (catalina-exec-22:ctx-552b3750 ctx-ea60769c)
===END===  10.252.192.19 -- GET  command=queryAsyncJobResult&jobId=38b00d5e-8098-4c47-84c6-2e02d2e7f9a6&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&_=1386158706971
2013-12-04 22:56:14,242 DEBUG [c.c.a.ApiServlet] (catalina-exec-23:ctx-222552b8) ===START===
 10.252.192.19 -- GET  command=listVirtualMachines&details=nics&id=bcddd332-9c2d-4319-b421-097e72f10167&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&_=1386158707088
2013-12-04 22:56:14,280 DEBUG [c.c.a.ApiServlet] (catalina-exec-23:ctx-222552b8 ctx-80a4c6ac)
===END===  10.252.192.19 -- GET  command=listVirtualMachines&details=nics&id=bcddd332-9c2d-4319-b421-097e72f10167&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&_=1386158707088
2013-12-04 22:56:15,416 DEBUG [c.c.s.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-46e7aafb)
Zone 1 is ready to launch secondary storage VM
2013-12-04 22:56:15,488 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-e8adcbc5)
Zone 1 is ready to launch console proxy
2013-12-04 22:56:15,864 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-ec5d9af1)
Resetting hosts suitable for reconnect
2013-12-04 22:56:15,867 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-ec5d9af1)
Completed resetting hosts suitable for reconnect
2013-12-04 22:56:15,867 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-ec5d9af1)
Acquiring hosts for clusters already owned by this management server
2013-12-04 22:56:15,868 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-ec5d9af1)
Completed acquiring hosts for clusters already owned by this management server
2013-12-04 22:56:15,868 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-ec5d9af1)
Acquiring hosts for clusters not owned by any management server
2013-12-04 22:56:15,869 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-ec5d9af1)
Completed acquiring hosts for clusters not owned by any management server
2013-12-04 22:56:17,618 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-7:null) Ping
from 1
2013-12-04 22:56:19,577 DEBUG [c.c.a.ApiServlet] (catalina-exec-7:ctx-84495902) ===START===
 10.252.192.19 -- GET  command=listVirtualMachines&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&listAll=true&page=1&pagesize=20&_=1386158712452
2013-12-04 22:56:19,639 DEBUG [c.c.a.ApiServlet] (catalina-exec-7:ctx-84495902 ctx-90cea5c6)
===END===  10.252.192.19 -- GET  command=listVirtualMachines&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&listAll=true&page=1&pagesize=20&_=1386158712452
2013-12-04 22:56:21,807 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-ec4d90cd) StorageCollector
is running...
2013-12-04 22:56:21,870 DEBUG [c.c.a.t.Request] (StatsCollector-2:ctx-ec4d90cd) Seq 6-51249334:
Received:  { Ans: , MgmtId: 6851580133501, via: 6, Ver: v1, Flags: 10, { GetStorageStatsAnswer
} }
2013-12-04 22:56:22,028 DEBUG [c.c.a.t.Request] (StatsCollector-2:ctx-ec4d90cd) Seq 1-493553028:
Received:  { Ans: , MgmtId: 6851580133501, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer
} }
2013-12-04 22:56:22,223 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-9:null) SeqA
5-1456: Processing Seq 5-1456:  { Cmd , MgmtId: -1, via: 5, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":3,"_loadInfo":"{\n
 \"connections\": []\n}","wait":0}}] }
2013-12-04 22:56:22,233 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-9:null) SeqA
5-1456: Sending Seq 5-1456:  { Ans: , MgmtId: 6851580133501, via: 5, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2013-12-04 22:56:23,435 DEBUG [c.c.a.ApiServlet] (catalina-exec-6:ctx-6c5a1b10) ===START===
 10.252.192.19 -- GET  command=listZones&id=5d183080-7858-4adf-92ff-ea6933c9be27&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&_=1386158716319
2013-12-04 22:56:23,455 DEBUG [c.c.a.ApiServlet] (catalina-exec-6:ctx-6c5a1b10 ctx-ac33212f)
===END===  10.252.192.19 -- GET  command=listZones&id=5d183080-7858-4adf-92ff-ea6933c9be27&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&_=1386158716319
2013-12-04 22:56:23,533 DEBUG [c.c.a.ApiServlet] (catalina-exec-20:ctx-75b46641) ===START===
 10.252.192.19 -- GET  command=listVirtualMachines&id=bcddd332-9c2d-4319-b421-097e72f10167&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&_=1386158716465
2013-12-04 22:56:23,572 DEBUG [c.c.a.ApiServlet] (catalina-exec-20:ctx-75b46641 ctx-a0909f12)
===END===  10.252.192.19 -- GET  command=listVirtualMachines&id=bcddd332-9c2d-4319-b421-097e72f10167&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&_=1386158716465
2013-12-04 22:56:23,743 DEBUG [c.c.a.ApiServlet] (catalina-exec-25:ctx-06d86725) ===START===
 10.252.192.19 -- GET  command=listOsTypes&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&_=1386158716584
2013-12-04 22:56:23,784 DEBUG [c.c.a.ApiServlet] (catalina-exec-4:ctx-4d19ee9c) ===START===
 10.252.192.19 -- GET  command=listTags&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&resourceId=bcddd332-9c2d-4319-b421-097e72f10167&resourceType=UserVm&listAll=true&_=1386158716625
2013-12-04 22:56:23,797 DEBUG [c.c.a.ApiServlet] (catalina-exec-4:ctx-4d19ee9c ctx-ff0bed68)
===END===  10.252.192.19 -- GET  command=listTags&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&resourceId=bcddd332-9c2d-4319-b421-097e72f10167&resourceType=UserVm&listAll=true&_=1386158716625
2013-12-04 22:56:24,159 DEBUG [c.c.a.ApiServlet] (catalina-exec-25:ctx-06d86725 ctx-ec136a31)
===END===  10.252.192.19 -- GET  command=listOsTypes&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&_=1386158716584
2013-12-04 22:56:25,674 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-fa8ed547) ===START===
 10.252.192.19 -- GET  command=listVirtualMachines&details=nics&id=bcddd332-9c2d-4319-b421-097e72f10167&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&_=1386158718580
2013-12-04 22:56:25,714 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-fa8ed547 ctx-f055ad3b)
===END===  10.252.192.19 -- GET  command=listVirtualMachines&details=nics&id=bcddd332-9c2d-4319-b421-097e72f10167&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&_=1386158718580
2013-12-04 22:56:32,225 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-12:null) SeqA
5-1457: Processing Seq 5-1457:  { Cmd , MgmtId: -1, via: 5, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":3,"_loadInfo":"{\n
 \"connections\": []\n}","wait":0}}] }
2013-12-04 22:56:32,262 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-12:null) SeqA
5-1457: Sending Seq 5-1457:  { Ans: , MgmtId: 6851580133501, via: 5, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2013-12-04 22:56:32,732 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-10:null) Ping
from 6
2013-12-04 22:56:33,497 DEBUG [c.c.a.ApiServlet] (catalina-exec-5:ctx-29081485) ===START===
 10.252.192.19 -- GET  command=listNetworks&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&zoneid=5d183080-7858-4adf-92ff-ea6933c9be27&account=test&domainid=7f9219f5-e458-4e76-9454-0901f67b165c&_=1386158726427
2013-12-04 22:56:33,514 DEBUG [c.c.u.AccountManagerImpl] (catalina-exec-5:ctx-29081485 ctx-1539c154)
Access granted to Acct[2-admin] to Domain:2/test/ by AffinityGroupAccessChecker
2013-12-04 22:56:33,782 DEBUG [c.c.a.ApiServlet] (catalina-exec-5:ctx-29081485 ctx-1539c154)
===END===  10.252.192.19 -- GET  command=listNetworks&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&zoneid=5d183080-7858-4adf-92ff-ea6933c9be27&account=test&domainid=7f9219f5-e458-4e76-9454-0901f67b165c&_=1386158726427
2013-12-04 22:56:35,116 DEBUG [c.c.a.ApiServlet] (catalina-exec-9:ctx-3fd1ad18) ===START===
 10.252.192.19 -- GET  command=addNicToVirtualMachine&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&virtualmachineid=bcddd332-9c2d-4319-b421-097e72f10167&networkid=a05731b2-b132-4087-b250-5a159fb811bf&_=1386158727976
2013-12-04 22:56:35,142 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-9:ctx-3fd1ad18
ctx-978c03e0) submit async job-97, details: AsyncJobVO {id:97, userId: 2, accountId: 2, instanceType:
None, instanceId: null, cmd: org.apache.cloudstack.api.command.user.vm.AddNicToVMCmd, cmdInfo:
{"response":"json","sessionkey":"D+cRXhCkN+eHk9chCpFpEVBD47E\u003d","virtualmachineid":"bcddd332-9c2d-4319-b421-097e72f10167","cmdEventType":"NIC.CREATE","ctxUserId":"2","httpmethod":"GET","_":"1386158727976","ctxAccountId":"2","networkid":"a05731b2-b132-4087-b250-5a159fb811bf","ctxStartEventId":"380"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid:
6851580133501, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-12-04 22:56:35,143 DEBUG [c.c.a.ApiServlet] (catalina-exec-9:ctx-3fd1ad18 ctx-978c03e0)
===END===  10.252.192.19 -- GET  command=addNicToVirtualMachine&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&virtualmachineid=bcddd332-9c2d-4319-b421-097e72f10167&networkid=a05731b2-b132-4087-b250-5a159fb811bf&_=1386158727976
2013-12-04 22:56:35,145 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-18:ctx-dda264e1)
Add job-97 into job monitoring
2013-12-04 22:56:35,145 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-18:ctx-dda264e1)
Executing AsyncJobVO {id:97, userId: 2, accountId: 2, instanceType: None, instanceId: null,
cmd: org.apache.cloudstack.api.command.user.vm.AddNicToVMCmd, cmdInfo: {"response":"json","sessionkey":"D+cRXhCkN+eHk9chCpFpEVBD47E\u003d","virtualmachineid":"bcddd332-9c2d-4319-b421-097e72f10167","cmdEventType":"NIC.CREATE","ctxUserId":"2","httpmethod":"GET","_":"1386158727976","ctxAccountId":"2","networkid":"a05731b2-b132-4087-b250-5a159fb811bf","ctxStartEventId":"380"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid:
6851580133501, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-12-04 22:56:35,157 ERROR [c.c.a.ApiAsyncJobDispatcher] (Job-Executor-18:ctx-dda264e1)
Unexpected exception while executing org.apache.cloudstack.api.command.user.vm.AddNicToVMCmd
com.cloud.utils.exception.CloudRuntimeException: A NIC already exists for VM:i-5-5-VM in network:
a05731b2-b132-4087-b250-5a159fb811bf
        at com.cloud.vm.UserVmManagerImpl.addNicToVirtualMachine(UserVmManagerImpl.java:994)
        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:616)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy169.addNicToVirtualMachine(Unknown Source)
        at org.apache.cloudstack.api.command.user.vm.AddNicToVMCmd.execute(AddNicToVMCmd.java:110)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
        at com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109)
        at com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
        at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:520)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-12-04 22:56:35,159 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-18:ctx-dda264e1)
Complete async job-97, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"A
NIC already exists for VM:i-5-5-VM in network: a05731b2-b132-4087-b250-5a159fb811bf"}
2013-12-04 22:56:35,180 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-18:ctx-dda264e1)
Done executing org.apache.cloudstack.api.command.user.vm.AddNicToVMCmd for job-97
2013-12-04 22:56:35,185 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-18:ctx-dda264e1)
Remove job-97 from job monitoring
2013-12-04 22:56:38,216 DEBUG [c.c.a.ApiServlet] (catalina-exec-10:ctx-b63ec78f) ===START===
 10.252.192.19 -- GET  command=queryAsyncJobResult&jobId=0274872d-e249-44cd-943a-e5d7bbd5e88e&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&_=1386158731156
2013-12-04 22:56:38,289 DEBUG [c.c.a.ApiServlet] (catalina-exec-10:ctx-b63ec78f ctx-42c9d601)
===END===  10.252.192.19 -- GET  command=queryAsyncJobResult&jobId=0274872d-e249-44cd-943a-e5d7bbd5e88e&response=json&sessionkey=D%2BcRXhCkN%2BeHk9chCpFpEVBD47E%3D&_=1386158731156
2013-12-04 22:56:40,742 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-b031c6a4)
Found 5 routers to update status.
2013-12-04 22:56:40,745 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-b031c6a4)
Found 1 networks to update RvR status.
2013-12-04 22:56:40,766 DEBUG [c.c.a.t.Request] (RedundantRouterStatusMonitor-9:ctx-c1db7120)
Seq 1-493553029: Sending  { Cmd , MgmtId: 6851580133501, via: 1(Rack1Pod1Host31), Ver: v1,
Flags: 100011, [{"com.cloud.agent.api.CheckRouterCommand":{"accessDetails":{"router.ip":"169.254.3.139","router.name":"r-12-VM"},"wait":30}}]
}
2013-12-04 22:56:40,867 DEBUG [c.c.a.t.Request] (AgentManager-Handler-11:null) Seq 1-493553029:
Processing:  { Ans: , MgmtId: 6851580133501, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.CheckRouterAnswer":{"state":"MASTER","isBumped":false,"result":true,"details":"Status:
MASTER&Bumped: NO","wait":0}}] }
2013-12-04 22:56:40,867 DEBUG [c.c.a.t.Request] (RedundantRouterStatusMonitor-9:ctx-c1db7120)
Seq 1-493553029: Received:  { Ans: , MgmtId: 6851580133501, via: 1, Ver: v1, Flags: 10, {
CheckRouterAnswer } }
2013-12-04 22:56:40,867 DEBUG [c.c.a.m.AgentManagerImpl] (RedundantRouterStatusMonitor-9:ctx-c1db7120)
Details from executing class com.cloud.agent.api.CheckRouterCommand: Status: MASTER&Bumped:
NO
2013-12-04 22:56:40,888 DEBUG [c.c.a.t.Request] (RedundantRouterStatusMonitor-9:ctx-c1db7120)
Seq 1-493553030: Sending  { Cmd , MgmtId: 6851580133501, via: 1(Rack1Pod1Host31), Ver: v1,
Flags: 100011, [{"com.cloud.agent.api.CheckRouterCommand":{"accessDetails":{"router.ip":"169.254.1.193","router.name":"r-13-VM"},"wait":30}}]
}
2013-12-04 22:56:41,026 DEBUG [c.c.a.t.Request] (AgentManager-Handler-13:null) Seq 1-493553030:
Processing:  { Ans: , MgmtId: 6851580133501, via: 1

> Add NIC to virtual machine fails in KVM
> ---------------------------------------
>
>                 Key: CLOUDSTACK-5342
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5342
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>          Components: Network Controller
>    Affects Versions: 4.3.0
>         Environment: KVM advanced
>            Reporter: Gaurav Aradhye
>            Assignee: Gaurav Aradhye
>            Priority: Blocker
>             Fix For: 4.3.0
>
>
> Add network to VM test cases fail in KVM with following error.
> Execute cmd: asyncquery failed, due to: {errorcode : 530, errortext : u'Unable to add
NIC to VM[User|VM-e9350ee5-bf2e-418c-91d6-1535dcb4d488]'}
> The same test cases execute successfully on XenServer. As per the feature specification
(see https://cwiki.apache.org/confluence/display/CLOUDSTACK/Add+Remove+Networks+to+VMs), "Add
network to VM" feature should be supported on KVM too.



--
This message was sent by Atlassian JIRA
(v6.1.4#6159)

Mime
View raw message