Here is problem I just encoutered on 4.3 Master:
1. Created a Shared Advanced network
2. Created an instance
3. Removed the instance
4. After the GUI showed the Instance was removed I tried to delete the network
The network deletion fails, due to VRouter Instance being present:
>> WARN [c.c.n.NetworkManagerImpl] (Job-Executor-2:ctx-820db89a) Unable to
>> complete destroy of the network due to element: VirtualRouter
Really the problem is that VRouter is already deleted on XenServer but looks
like it is still in the MS database! I cleaned up the database and removed the
VRouter instance information from the vm_instance table, and was able to
successfully remove the network.
Is this a known issue?
-Soheil
[root@xenserver1-cloudstack ~]# xe vm-list
uuid ( RO) : 58a9612b-7a73-8a14-4b29-58f043acec7c
name-label ( RW): s-1-VM
power-state ( RO): running
uuid ( RO) : 9e5503d1-16a5-40ab-a0dc-788bad583c0d
name-label ( RW): Control domain on host: xenserver1-cloudstack
power-state ( RO): running
uuid ( RO) : 91950b00-584b-a6b8-e3f9-27a75f071e6d
name-label ( RW): v-2-VM
power-state ( RO): running
The exception is from the call to destroy VM that calls advanceExpunge() and
fails when it finally called the Hypervisor:
s_logger.debug("Cleaning up NICS");
>> List<Command> nicExpungeCommands = hvGuru.finalizeExpungeNics(vm,
>> profile.getNics());
Here is what the database looks like for the instances:
mysql> select * from vm_instance;
+----+--------+--------------------------------------+---------------+-----------+----------------+-------------+---------------------+--------------------+--------+----------------+---------+--------------+----------+---------------------+------------------+------------+---------------+--------------+---------------------+---------------------+---------------------+--------------------+--------------------+------------+-----------+---------------------+--------------------------------------+-----------------+------------------+------+------+-------+-------+-----------+--------------+---------------+----------------------+------------+--------------+-------------------------+--------------------------+------------+
| id | name | uuid | instance_name | state
| vm_template_id | guest_os_id | private_mac_address | private_ip_address |
pod_id | data_center_id | host_id | last_host_id | proxy_id | proxy_assign_time
| vnc_password | ha_enabled | limit_cpu_use | update_count | update_time
| created | removed | type |
vm_type | account_id | domain_id | service_offering_id |
reservation_id | hypervisor_type | disk_offering_id | cpu
| ram | owner | speed | host_name | display_name | desired_state |
dynamically_scalable | display_vm | power_state | power_state_update_time |
power_state_update_count | power_host |
+----+--------+--------------------------------------+---------------+-----------+----------------+-------------+---------------------+--------------------+--------+----------------+---------+--------------+----------+---------------------+------------------+------------+---------------+--------------+---------------------+---------------------+---------------------+--------------------+--------------------+------------+-----------+---------------------+--------------------------------------+-----------------+------------------+------+------+-------+-------+-----------+--------------+---------------+----------------------+------------+--------------+-------------------------+--------------------------+------------+
| 1 | s-1-VM | 4cd7eee7-b420-4fce-8aec-90fae16ff3a0 | s-1-VM | Running
| 1 | 183 | 06:f2:48:00:00:0c | 10.48.15.41 |
1 | 1 | 1 | 1 | NULL | NULL
| 3e0934c4827e7b71 | 0 | 0 | 3 | 2013-09-27
05:27:32 | 2013-09-27 05:24:44 | NULL | SecondaryStorageVm |
SecondaryStorageVm | 1 | 1 | 9 |
002fd3d7-a347-4b21-8ee5-0c4418b8cce6 | XenServer | NULL |
NULL | NULL | NULL | NULL | NULL | NULL | NULL |
0 | 1 | PowerUnknown | NULL |
0 | NULL |
| 2 | v-2-VM | d89219d1-e741-4242-ac20-215dd3d325e3 | v-2-VM | Running
| 1 | 183 | 06:55:34:00:00:05 | 10.48.15.34 |
1 | 1 | 1 | 1 | NULL | NULL
| 735aa2bf84c2b6e | 0 | 0 | 3 | 2013-09-27
05:27:32 | 2013-09-27 05:24:44 | NULL | ConsoleProxy |
ConsoleProxy | 1 | 1 | 11 |
7fce9eb6-37e3-4005-992d-2b5f6697455d | XenServer | NULL |
NULL | NULL | NULL | NULL | NULL | NULL | NULL |
0 | 1 | PowerUnknown | NULL |
0 | NULL |
| 3 | test-1 | 3bc0aac9-d0f6-4857-a1d3-7a22502568e7 | i-2-3-VM |
Expunging | 5 | 12 | NULL | NULL
| 1 | 1 | NULL | 1 | 2 | 2013-09-27
06:19:09 | af66cf89de44164c | 0 | 0 | 7 |
2013-09-27 16:59:31 | 2013-09-27 06:04:34 | 2013-09-27 16:59:31 | User
| User | 2 | 1 | 1 |
ef69ce90-cf48-4d2f-9b78-cfd23e33b1c3 | XenServer | NULL |
NULL | NULL | 2 | 500 | test-1 | test-1 | NULL |
1 | 1 | PowerUnknown | NULL |
0 | NULL |
| 4 | r-4-VM | d6023287-96fe-4600-87a5-2185369f66b1 | r-4-VM |
Expunging | 1 | 183 | 0e:00:a9:fe:01:60 | 169.254.1.96
| 1 | 1 | NULL | 1 | NULL | NULL
| 9260dccbe93d0fbd | 1 | 0 | 11 |
2013-09-27 19:09:20 | 2013-09-27 06:04:34 | NULL | DomainRouter
| DomainRouter | 1 | 1 | 7 |
aa4644df-e84a-4e88-86c3-268620efda67 | XenServer | NULL |
NULL | NULL | NULL | NULL | NULL | NULL | NULL |
0 | 1 | PowerUnknown | NULL |
0 | NULL |
+----+--------+--------------------------------------+---------------+-----------+----------------+-------------+---------------------+--------------------+--------+----------------+---------+--------------+----------+---------------------+------------------+------------+---------------+--------------+---------------------+---------------------+---------------------+--------------------+--------------------+------------+-----------+---------------------+--------------------------------------+-----------------+------------------+------+------+-------+-------+-----------+--------------+---------------+----------------------+------------+--------------+-------------------------+--------------------------+------------+
4 rows in set (0.00 sec)
Here is logs of the VRouter being deleted before the Network Deletion:
2013-09-27 10:00:07,865 DEBUG [c.c.a.t.Request] (Job-Executor-1:ctx-6ec41752)
Seq 1-1875509262: Sending { Cmd , MgmtId: 345051679068, via: 1, Ver: v1,
Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"r-4-VM","wait":0}}]
}
2013-09-27 10:00:07,865 DEBUG [c.c.a.t.Request] (Job-Executor-1:ctx-6ec41752)
Seq 1-1875509262: Executing: { Cmd , MgmtId: 345051679068, via: 1, Ver: v1,
Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"r-4-VM","wait":0}}]
}
2013-09-27 10:00:07,866 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-24:null) Seq 1-1875509262: Executing request
2013-09-27 10:00:07,937 DEBUG [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-24:null) 9. The VM r-4-VM is in Stopping state
2013-09-27 10:00:09,777 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-4:null) SeqA 4-5727: Processing Seq 4-5727: { Cmd ,
MgmtId: -1, via: 4, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2013-09-27 10:00:09,782 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-4:null) SeqA 4-5727: Sending Seq 4-5727: { Ans: ,
MgmtId: 345051679068, via: 4, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2013-09-27 10:00:10,807 DEBUG [c.c.a.ApiServlet]
(195265152@qtp-1059832856-7:null) ===START=== 10.102.29.241 -- GET
command=queryAsyncJobResult&jobId=c452b6ee-1217-44af-8b3e-d080a00ac819&response=json&sessionkey=xpHlrPDHihGwKMQmb5AOvQOGsTY%3D&_=1380301202053
2013-09-27 10:00:10,842 DEBUG [c.c.a.ApiServlet]
(195265152@qtp-1059832856-7:ctx-73ba96af) ===END=== 10.102.29.241 -- GET
command=queryAsyncJobResult&jobId=c452b6ee-1217-44af-8b3e-d080a00ac819&response=json&sessionkey=xpHlrPDHihGwKMQmb5AOvQOGsTY%3D&_=1380301202053
2013-09-27 10:00:13,808 DEBUG [c.c.a.ApiServlet]
(195265152@qtp-1059832856-7:null) ===START=== 10.102.29.241 -- GET
command=queryAsyncJobResult&jobId=c452b6ee-1217-44af-8b3e-d080a00ac819&response=json&sessionkey=xpHlrPDHihGwKMQmb5AOvQOGsTY%3D&_=1380301205054
2013-09-27 10:00:13,827 DEBUG [c.c.a.ApiServlet]
(195265152@qtp-1059832856-7:ctx-ccb65db9) ===END=== 10.102.29.241 -- GET
command=queryAsyncJobResult&jobId=c452b6ee-1217-44af-8b3e-d080a00ac819&response=json&sessionkey=xpHlrPDHihGwKMQmb5AOvQOGsTY%3D&_=1380301205054
2013-09-27 10:00:16,805 DEBUG [c.c.a.ApiServlet]
(195265152@qtp-1059832856-7:null) ===START=== 10.102.29.241 -- GET
command=queryAsyncJobResult&jobId=c452b6ee-1217-44af-8b3e-d080a00ac819&response=json&sessionkey=xpHlrPDHihGwKMQmb5AOvQOGsTY%3D&_=1380301208053
2013-09-27 10:00:16,825 DEBUG [c.c.a.ApiServlet]
(195265152@qtp-1059832856-7:ctx-e1f5b9b2) ===END=== 10.102.29.241 -- GET
command=queryAsyncJobResult&jobId=c452b6ee-1217-44af-8b3e-d080a00ac819&response=json&sessionkey=xpHlrPDHihGwKMQmb5AOvQOGsTY%3D&_=1380301208053
2013-09-27 10:00:17,313 INFO [c.c.h.x.r.XenServer56Resource]
(DirectAgent-24:null) Catch com.xensource.xenapi.Types$InternalError: failed to
destory VLAN eth0 on host cba14b8c-9d89-430a-ba26-f0433aa66b55 due to The
server failed to handle your request, due to an internal error. The given
message may give details useful for debugging the problem.
2013-09-27 10:00:17,314 DEBUG [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-24:null) 10. The VM r-4-VM is in Stopped state
2013-09-27 10:00:17,314 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-24:null) Seq 1-1875509262: Response Received:
2013-09-27 10:00:17,314 DEBUG [c.c.a.t.Request] (DirectAgent-24:null) Seq
1-1875509262: Processing: { Ans: , MgmtId: 345051679068, via: 1, Ver: v1,
Flags: 10,
[{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"details":"Stop
VM r-4-VM Succeed","wait":0}}] }
2013-09-27 10:00:17,314 DEBUG [c.c.a.t.Request] (Job-Executor-1:ctx-6ec41752)
Seq 1-1875509262: Received: { Ans: , MgmtId: 345051679068, via: 1, Ver: v1,
Flags: 10, { StopAnswer } }
2013-09-27 10:00:17,329 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(Job-Executor-1:ctx-6ec41752) Successfully updated user statistics as a part of
domR VM[DomainRouter|r-4-VM] reboot/stop
2013-09-27 10:00:17,336 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-1:ctx-6ec41752) VM[DomainRouter|r-4-VM] is stopped on the host.
Proceeding to release resource held.
2013-09-27 10:00:17,351 DEBUG [c.c.n.g.ControlNetworkGuru]
(Job-Executor-1:ctx-6ec41752) Released nic: NicProfile[11-4-null-null-null
2013-09-27 10:00:17,354 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-1:ctx-6ec41752) Successfully released network resources for the
vm VM[DomainRouter|r-4-VM]
2013-09-27 10:00:17,354 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-1:ctx-6ec41752) Successfully released storage resources for the
vm VM[DomainRouter|r-4-VM]
2013-09-27 10:00:17,359 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-1:ctx-6ec41752) VM state transitted from :Stopping to Stopped
with event: OperationSucceededvm's original host id: 1 new host id: null host
id before state transition: 1
2013-09-27 10:00:17,366 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-1:ctx-6ec41752) Hosts's actual total CPU: 12264 and CPU after
applying overprovisioning: 12264
2013-09-27 10:00:17,366 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-1:ctx-6ec41752) Hosts's actual total RAM: 7555125312 and RAM
after applying overprovisioning: 7555125248
2013-09-27 10:00:17,366 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-1:ctx-6ec41752) release cpu from host: 1, old used:
1500,reserved: 0, actual total: 12264, total with overprovisioning: 12264; new
used: 1000,reserved:500; movedfromreserved: false,moveToReserveredtrue
2013-09-27 10:00:17,366 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-1:ctx-6ec41752) release mem from host: 1, old used:
1476395008,reserved: 0, total: 7555125248; new used:
1342177280,reserved:134217728; movedfromreserved: false,moveToReserveredtrue
2013-09-27 10:00:17,373 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-1:ctx-6ec41752) VM state transitted from :Stopped to Expunging
with event: ExpungeOperationvm's original host id: 1 new host id: null host id
before state transition: null
2013-09-27 10:00:17,379 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-1:ctx-6ec41752) Hosts's actual total CPU: 12264 and CPU after
applying overprovisioning: 12264
2013-09-27 10:00:17,379 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-1:ctx-6ec41752) Hosts's actual total RAM: 7555125312 and RAM
after applying overprovisioning: 7555125248
2013-09-27 10:00:17,379 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-1:ctx-6ec41752) release cpu from host: 1, old used:
1000,reserved: 500, actual total: 12264, total with overprovisioning: 12264;
new used: 1000,reserved:0; movedfromreserved: true,moveToReserveredfalse
2013-09-27 10:00:17,379 DEBUG [c.c.c.CapacityManagerImpl]
(Job-Executor-1:ctx-6ec41752) release mem from host: 1, old used:
1342177280,reserved: 134217728, total: 7555125248; new used:
1342177280,reserved:0; movedfromreserved: true,moveToReserveredfalse
2013-09-27 10:00:17,381 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-1:ctx-6ec41752) Destroying vm VM[DomainRouter|r-4-VM]
2013-09-27 10:00:17,381 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Job-Executor-1:ctx-6ec41752) Cleaning up NICS
2013-09-27 10:00:17,381 DEBUG [c.c.n.NetworkManagerImpl]
(Job-Executor-1:ctx-6ec41752) Cleaning network for vm: 4
2013-09-27 10:00:17,387 DEBUG [c.c.n.NetworkModelImpl]
(Job-Executor-1:ctx-6ec41752) Service SecurityGroup is not supported in the
network id=204
2013-09-27 10:00:17,393 DEBUG [c.c.n.NetworkManagerImpl]
(Job-Executor-1:ctx-6ec41752) Asking VirtualRouter to release
Nic[10-4-null-192.168.10.51]
2013-09-27 10:00:17,394 DEBUG [c.c.n.g.DirectNetworkGuru]
(Job-Executor-1:ctx-6ec41752) Deallocate network: networkId: 204, ip:
192.168.10.51
2013-09-27 10:00:17,397 DEBUG [c.c.n.g.DirectNetworkGuru]
(Job-Executor-1:ctx-6ec41752) Not releasing direct ip 207 yet as its ip is
saved in the placeholder
2013-09-27 10:00:17,397 DEBUG [c.c.n.g.DirectNetworkGuru]
(Job-Executor-1:ctx-6ec41752) remove nic 10 secondary ip
2013-09-27 10:00:17,410 DEBUG [c.c.n.NetworkManagerImpl]
(Job-Executor-1:ctx-6ec41752) Removed nic id=10
2013-09-27 10:00:17,411 DEBUG [c.c.n.NetworkManagerImpl]
(Job-Executor-1:ctx-6ec41752) Revoving nic secondary ip entry ...
2013-09-27 10:00:17,419 WARN [c.c.n.NetworkManagerImpl]
(Job-Executor-1:ctx-6ec41752) Unable to complete destroy of the network due to
element: VirtualRouter
