Sorry, you've already sent all the info needed. Doesn't look like you have any non-expunged vm, so seems to be a bug in vm expunge when nic count wasn't reduced in op_networks table. Please file it.
Here is a workaround: * save the db dump just to be on the safe side * update op_networks with the statement: Update op_networks set nics_count=0 where id=236 * next account clenaup thread should be able to remove the network id=236. -Alena. On 7/24/12 12:57 PM, "Alena Prokharchyk" <[email protected]> wrote: >Diego, can you also provide output on mysql statements I've mentioned in >my prev email? > >-Alena. > >On 7/24/12 12:12 PM, "Diego Spinola Castro" <[email protected]> >wrote: > >>OK: >> >>https://dl.dropbox.com/u/19653845/management-server.log.2012-07-19.gz >> >> >>2012/7/24 Alena Prokharchyk <[email protected]> >> >>> Please Zip it, place it on some publicly available web host and send >>>the >>> link. >>> >>> Thank you, >>> Alena. >>> >>> On 7/24/12 11:59 AM, "Diego Spinola Castro" <[email protected]> >>> wrote: >>> >>> >What about management log. its 10mb , how do i send to you? >>> > >>> >mysql> select * from op_networks; >>> >+-----+-----------------+------------+----+--------------+ >>> >| id | mac_address_seq | nics_count | gc | check_for_gc | >>> >+-----+-----------------+------------+----+--------------+ >>> >| 200 | 2069 | 0 | 0 | 0 | >>> >| 201 | 1 | 0 | 0 | 0 | >>> >| 202 | 1062 | 0 | 0 | 0 | >>> >| 203 | 1 | 0 | 0 | 0 | >>> >| 204 | 224 | 5 | 1 | 1 | >>> >| 205 | 13 | 0 | 1 | 0 | >>> >| 206 | 8 | 3 | 1 | 1 | >>> >| 207 | 12 | 0 | 1 | 0 | >>> >| 208 | 7 | 2 | 1 | 1 | >>> >| 209 | 10 | 0 | 1 | 0 | >>> >| 210 | 5 | 0 | 1 | 0 | >>> >| 211 | 10 | 1 | 1 | 1 | >>> >| 212 | 14 | 0 | 1 | 0 | >>> >| 213 | 8 | 6 | 1 | 1 | >>> >| 214 | 5 | 0 | 1 | 0 | >>> >| 215 | 4 | 0 | 1 | 0 | >>> >| 216 | 3 | 0 | 1 | 0 | >>> >| 217 | 3 | 0 | 1 | 0 | >>> >| 218 | 4 | 3 | 1 | 1 | >>> >| 219 | 3 | 0 | 1 | 0 | >>> >| 220 | 10 | 5 | 1 | 1 | >>> >| 221 | 6 | 6 | 1 | 1 | >>> >| 222 | 16 | 5 | 1 | 1 | >>> >| 223 | 14 | 1 | 1 | 1 | >>> >| 224 | 30 | 1 | 1 | 1 | >>> >| 225 | 3 | 0 | 1 | 0 | >>> >| 226 | 8 | 11 | 1 | 1 | >>> >| 227 | 3 | 0 | 1 | 0 | >>> >| 228 | 3 | 2 | 1 | 1 | >>> >| 229 | 4 | 3 | 1 | 1 | >>> >| 230 | 3 | 0 | 1 | 0 | >>> >| 231 | 6 | 7 | 1 | 1 | >>> >| 232 | 26 | 24 | 1 | 1 | >>> >| 233 | 4 | 2 | 1 | 1 | >>> >| 234 | 7 | 9 | 1 | 1 | >>> >| 235 | 3 | 0 | 1 | 0 | >>> >| 236 | 3 | 2 | 1 | 1 | >>> >| 237 | 4 | 0 | 1 | 0 | >>> >| 238 | 9 | 7 | 1 | 1 | >>> >| 240 | 4 | 3 | 1 | 1 | >>> >| 241 | 5 | 3 | 1 | 1 | >>> >| 242 | 3 | 3 | 1 | 1 | >>> >| 243 | 30 | 4 | 1 | 1 | >>> >| 244 | 3 | 0 | 1 | 0 | >>> >| 245 | 4 | 3 | 1 | 1 | >>> >| 246 | 4 | 3 | 1 | 1 | >>> >| 247 | 4 | 3 | 1 | 1 | >>> >| 248 | 3 | 2 | 1 | 1 | >>> >| 249 | 3 | 2 | 1 | 1 | >>> >| 250 | 3 | 3 | 1 | 1 | >>> >| 251 | 7 | 0 | 1 | 0 | >>> >| 252 | 4 | 6 | 1 | 1 | >>> >| 253 | 3 | 2 | 1 | 1 | >>> >| 254 | 13 | 6 | 1 | 1 | >>> >| 255 | 7 | 3 | 1 | 1 | >>> >| 256 | 3 | 1 | 1 | 1 | >>> >| 257 | 6 | 4 | 1 | 1 | >>> >| 258 | 1 | 6 | 1 | 1 | >>> >| 259 | 4 | 3 | 1 | 1 | >>> >| 260 | 5 | 2 | 1 | 1 | >>> >| 261 | 3 | 3 | 1 | 1 | >>> >| 262 | 5 | 0 | 1 | 0 | >>> >| 263 | 5 | 1 | 1 | 1 | >>> >| 264 | 3 | 0 | 1 | 0 | >>> >| 265 | 3 | 1 | 1 | 1 | >>> >| 266 | 4 | 1 | 1 | 1 | >>> >| 267 | 3 | 1 | 1 | 1 | >>> >| 268 | 6 | 2 | 1 | 1 | >>> >| 269 | 3 | 1 | 1 | 1 | >>> >| 270 | 4 | 0 | 1 | 0 | >>> >| 271 | 3 | 1 | 1 | 1 | >>> >| 272 | 3 | 1 | 1 | 1 | >>> >| 273 | 3 | 1 | 1 | 1 | >>> >| 274 | 10 | 2 | 1 | 1 | >>> >| 275 | 3 | 1 | 1 | 1 | >>> >+-----+-----------------+------------+----+--------------+ >>> > >>> >mysql> select * from op_networks where id=236; >>> >+-----+-----------------+------------+----+--------------+ >>> >| id | mac_address_seq | nics_count | gc | check_for_gc | >>> >+-----+-----------------+------------+----+--------------+ >>> >| 236 | 3 | 2 | 1 | 1 | >>> >+-----+-----------------+------------+----+--------------+ >>> > >>> >mysql> select * from vm_instance where id in (select instance_id from >>>nics >>> >where removed is null and network_id=236)\G >>> >*************************** 1. row *************************** >>> > id: 348 >>> > name: r-348-VM >>> > instance_name: r-348-VM >>> > state: Stopped >>> > vm_template_id: 8 >>> > guest_os_id: 15 >>> >private_mac_address: 02:00:13:63:03:ed >>> > private_ip_address: 10.16.140.70 >>> > private_netmask: NULL >>> > pod_id: 1 >>> > data_center_id: 1 >>> > host_id: NULL >>> > last_host_id: 2 >>> > proxy_id: 305 >>> > proxy_assign_time: 2012-03-17 04:43:35 >>> > vnc_password: d3cc123795551907 >>> > ha_enabled: 1 >>> > limit_cpu_use: 1 >>> > update_count: 202 >>> > update_time: 2012-07-17 15:54:54 >>> > created: 2012-02-16 16:37:19 >>> > removed: NULL >>> > type: DomainRouter >>> > vm_type: DomainRouter >>> > account_id: 43 >>> > domain_id: 1 >>> >service_offering_id: 7 >>> > reservation_id: 147062dc-3596-4799-a84e-667784810067 >>> > hypervisor_type: VMware >>> >1 row in set (0.00 sec) >>> > >>> > >>> >2012/7/24 Alena Prokharchyk <[email protected]> >>> > >>> >> Error message: >>> >> >>> >> "Unable to remove the network id=236 as it has active Nics". >>> >> >>> >> >>> >> Indicates that the User vm(s) (not router) fail to expunge during >>>the >>> >> account deletion, therefore the corresponding network failed to be >>> >> removed. The account will be marked with Removed=someDate + >>> >> cleanup_needed=1, and the recurring thread (runs every >>> >> account.clenaup.interval defined in global config) will try to >>>cleanup >>> >>the >>> >> account again and again, until it succeeds. >>> >> >>> >> >>> >> >>> >> To find out if this is the root cause, following is needed: >>> >> >>> >> * management server log >>> >> * content of the op_networks table, the active nic info is stored >>>there. >>> >> Nics should be counted for non-expunged user vms only (select * from >>> >> op_networks where id=236) >>> >> * information about the user vms belonging to network id=236 (select >>>* >>> >> from vm_instance where id in (select instance_id from nics where >>>removed >>> >> is null and network_id=236)) >>> >> >>> >> -Alena. >>> >> >>> >> On 7/24/12 11:15 AM, "Edison Su" <[email protected]> wrote: >>> >> >>> >> >Sounds like a bug, the VR is not got destroyed during >>>deleteAccount. >>> >> >Could you help to fire a bug, and attach the whole mgt server log? >>> >> > >>> >> >> -----Original Message----- >>> >> >> From: Diego Spinola Castro [mailto:[email protected]] >>> >> >> Sent: Tuesday, July 24, 2012 10:03 AM >>> >> >> To: [email protected] >>> >> >> Subject: Orphaned VRouters >>> >> >> >>> >> >> Hi, i found some orphan vrouters and don't know why they still >>> >>running >>> >> >> even >>> >> >> there's no account anymore (i deleted account). >>> >> >> >>> >> >> Bellow management.log >>> >> >> >>> >> >> >>> >> >> 2012-07-19 12:39:06,437 DEBUG [cloud.async.AsyncJobManagerImpl] >>> >> >> (http-12449-14:null) submit async job-6598, details: AsyncJobVO >>> >> >> {id:6598, >>> >> >> userId: 32, accountId: 2, sessionKey: null, instanceType: None, >>> >> >> instanceId: >>> >> >> null, cmd: com.cloud.api.commands.DeleteAccountCmd, >>>cmdOriginator: >>> >>null, >>> >> >> cmdInfo: >>> >> >> >>> >>>>>{"id":"43","response":"json","sessionkey":"7uBHMfOyDdSLdtSjPB9K0FcVloQ >>>>>\ >>> >> >> >>> >>>>>u003d","ctxUserId":"32","_":"1342707903173","ctxAccountId":"2","ctxSta >>>>>r >>> >> >> tEventId":"35670"}, >>> >> >> cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, >>> >> >> processStatus: 0, resultCode: 0, result: null, initMsid: >>> >>144350996536, >>> >> >> completeMsid: null, lastUpdated: null, lastPolled: null, created: >>> >>null} >>> >> >> 2012-07-19 12:39:06,438 DEBUG [cloud.async.AsyncJobManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Executing >>> >> >> com.cloud.api.commands.DeleteAccountCmd for job-6598 >>> >> >> 2012-07-19 12:39:06,443 DEBUG [cloud.user.AccountManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Access to Acct[43-300012_CUBOCC] >>>granted >>> >>to >>> >> >> Acct[2-admin] by DomainChecker >>> >> >> 2012-07-19 12:39:06,460 DEBUG [cloud.user.AccountManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Remove account 43 >>> >> >> 2012-07-19 12:39:06,514 DEBUG [agent.transport.Request] >>> >> >> (Job-Executor-25:job-6598) Seq 20-573703176: Sending { Cmd , >>>MgmtId: >>> >> >> 144350996536, via: 20, Ver: v1, Flags: 100011, >>> >> >> >>> >>>>>[{"DeleteSnapshotsDirCommand":{"primaryStoragePoolNameLabel":"016b139d >>>>>- >>> >> >> a43e-32de-a330-e57a91388695","secondaryStoragePoolURL":"nfs:// >>> >> >> >>> >>>>>10.16.140.11/export","dcId":1,"accountId":43,"volumeId":467,"volumePat >>>>>h >>> >> >> ":"2c880c4443a44672971b964d0cfe725c","wait":0}}] >>> >> >> } >>> >> >> 2012-07-19 12:39:09,334 DEBUG [agent.transport.Request] >>> >> >> (Job-Executor-25:job-6598) Seq 20-573703176: Received: { Ans: , >>> >>MgmtId: >>> >> >> 144350996536, via: 20, Ver: v1, Flags: 10, { Answer } } >>> >> >> 2012-07-19 12:39:09,343 DEBUG >>>[cloud.vm.VirtualMachineManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Cleanup succeeded. Details null >>> >> >> 2012-07-19 12:39:09,343 DEBUG >>>[storage.snapshot.SnapshotManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Deleted snapshotsDir for volume: 467 >>>under >>> >> >> account: 43 >>> >> >> 2012-07-19 12:39:09,345 DEBUG [cloud.user.AccountManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Successfully deleted snapshots >>>directories >>> >> >> for >>> >> >> all volumes under account 43 across all zones >>> >> >> 2012-07-19 12:39:09,348 DEBUG [cloud.user.AccountManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Destroying # of vms (accountId=43): 1 >>> >> >> 2012-07-19 12:39:09,348 DEBUG >>>[cloud.vm.VirtualMachineManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Stopped called on VM[User|i-43-347-VM] >>>but >>> >> >> the >>> >> >> state is Destroyed >>> >> >> 2012-07-19 12:39:09,355 DEBUG >>>[cloud.capacity.CapacityManagerImpl] >>> >> >> (Job-Executor-25:job-6598) VM state transitted from :Destroyed to >>> >> >> Expunging >>> >> >> with event: ExpungeOperationvm's original host id: 4 new host id: >>> >>null >>> >> >> host >>> >> >> id before state transition: null >>> >> >> 2012-07-19 12:39:09,355 DEBUG >>>[cloud.vm.VirtualMachineManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Destroying vm VM[User|i-43-347-VM] >>> >> >> 2012-07-19 12:39:09,355 DEBUG [cloud.network.NetworkManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Cleaning network for vm: 347 >>> >> >> 2012-07-19 12:39:09,369 DEBUG [cloud.storage.StorageManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Cleaning storage for vm: 347 >>> >> >> 2012-07-19 12:39:09,401 DEBUG [cloud.storage.StorageManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Detaching Vol[467|vm=347|DATADISK] >>> >> >> 2012-07-19 12:39:09,402 DEBUG [cloud.storage.StorageManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Detaching Vol[488|vm=347|DATADISK] >>> >> >> 2012-07-19 12:39:09,404 DEBUG [cloud.storage.StorageManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Expunging Vol[392|vm=347|ROOT] >>> >> >> 2012-07-19 12:39:09,407 DEBUG [agent.transport.Request] >>> >> >> (Job-Executor-25:job-6598) Seq 3-115876736: Sending { Cmd , >>>MgmtId: >>> >> >> 144350996536, via: 3, Ver: v1, Flags: 100111, >>> >> >> [{"storage.DestroyCommand":{"vmName":"i-43-347- >>> >> >> VM","volume":{"id":392,"name":"ROOT- >>> >> >> 347","mountPoint":"/TELIUMSPO/SATA_R5_VOL3","path":"ROOT- >>> >> >> >>> >>>>>347","size":53687091200,"type":"ROOT","storagePoolType":"VMFS","storag >>>>>e >>> >> >> PoolUuid":"30b0d978-3291-3ce3-a06f- >>> >> >> eea3ac2f4f51","deviceId":0},"wait":0}}] >>> >> >> } >>> >> >> 2012-07-19 12:39:09,407 DEBUG [agent.transport.Request] >>> >> >> (Job-Executor-25:job-6598) Seq 3-115876736: Executing: { Cmd , >>> >>MgmtId: >>> >> >> 144350996536, via: 3, Ver: v1, Flags: 100111, >>> >> >> [{"storage.DestroyCommand":{"vmName":"i-43-347- >>> >> >> VM","volume":{"id":392,"name":"ROOT- >>> >> >> 347","mountPoint":"/TELIUMSPO/SATA_R5_VOL3","path":"ROOT- >>> >> >> >>> >>>>>347","size":53687091200,"type":"ROOT","storagePoolType":"VMFS","storag >>>>>e >>> >> >> PoolUuid":"30b0d978-3291-3ce3-a06f- >>> >> >> eea3ac2f4f51","deviceId":0},"wait":0}}] >>> >> >> } >>> >> >> 2012-07-19 12:39:27,879 DEBUG [agent.transport.Request] >>> >> >> (Job-Executor-25:job-6598) Seq 3-115876736: Received: { Ans: , >>> >>MgmtId: >>> >> >> 144350996536, via: 3, Ver: v1, Flags: 110, { Answer } } >>> >> >> 2012-07-19 12:39:27,879 DEBUG >>>[cloud.vm.VirtualMachineManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Cleanup succeeded. Details Success >>> >> >> 2012-07-19 12:39:27,890 DEBUG [cloud.storage.StorageManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Volume successfully expunged from 206 >>> >> >> 2012-07-19 12:39:27,890 DEBUG >>>[cloud.vm.VirtualMachineManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Expunged VM[User|i-43-347-VM] >>> >> >> 2012-07-19 12:39:27,890 DEBUG [cloud.vm.UserVmManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Starting cleaning up vm >>> >>VM[User|i-43-347-VM] >>> >> >> resources... >>> >> >> 2012-07-19 12:39:27,947 DEBUG >>>[network.firewall.FirewallManagerImpl] >>> >> >> (Job-Executor-25:job-6598) No firewall rules are found for vm >>>id=347 >>> >> >> 2012-07-19 12:39:27,947 DEBUG [cloud.vm.UserVmManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Firewall rules are removed >>>successfully >>> >>as a >>> >> >> part of vm id=347 expunge >>> >> >> 2012-07-19 12:39:27,995 DEBUG [network.rules.RulesManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Applying port forwarding rules for ip >>> >> >> address >>> >> >> id=58 as a part of vm expunge >>> >> >> 2012-07-19 12:39:28,001 DEBUG [cloud.network.NetworkManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Network Rules for network 236 were >>>not >>> >> >> handled >>> >> >> by ExternalFirewall >>> >> >> 2012-07-19 12:39:28,001 DEBUG [cloud.network.NetworkManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Network Rules for network 236 were >>>not >>> >> >> handled >>> >> >> by ExternalLoadBalancer >>> >> >> 2012-07-19 12:39:28,003 DEBUG >>> >> >> [network.router.VirtualNetworkApplianceManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Router r-348-VM is in Stopped, so not >>> >> >> sending >>> >> >> apply firewall rules commands to the backend >>> >> >> 2012-07-19 12:39:28,003 DEBUG [cloud.network.NetworkManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Network Rules for network 236 were >>> >>handled >>> >> >> by >>> >> >> DomainRouter >>> >> >> 2012-07-19 12:39:28,003 DEBUG [cloud.network.NetworkManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Network Rules for network 236 were >>>not >>> >> >> handled >>> >> >> by Dhcp >>> >> >> 2012-07-19 12:39:28,003 DEBUG [cloud.network.NetworkManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Network Rules for network 236 were >>> >>handled >>> >> >> by >>> >> >> Ovs >>> >> >> 2012-07-19 12:39:28,003 DEBUG [cloud.network.NetworkManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Network Rules for network 236 were >>> >>handled >>> >> >> by >>> >> >> ExternalDhcp >>> >> >> 2012-07-19 12:39:28,003 DEBUG [cloud.network.NetworkManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Network Rules for network 236 were >>> >>handled >>> >> >> by >>> >> >> BareMetal >>> >> >> 2012-07-19 12:39:28,003 DEBUG >>> >> >> [network.element.ElasticLoadBalancerElement] >>> >> >> (Job-Executor-25:job-6598) Not handling network with guest Type >>> >> >> Virtual >>> >> >> and traffic type Guest >>> >> >> 2012-07-19 12:39:28,003 DEBUG [cloud.network.NetworkManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Network Rules for network 236 were >>>not >>> >> >> handled >>> >> >> by ElasticLoadBalancer >>> >> >> 2012-07-19 12:39:28,034 DEBUG [cloud.vm.UserVmManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Port forwarding rules are removed >>> >> >> successfully >>> >> >> as a part of vm id=347 expunge >>> >> >> 2012-07-19 12:39:28,045 DEBUG [cloud.vm.UserVmManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Removed vm id=347 from all load >>>balancers >>> >>as >>> >> >> a >>> >> >> part of expunge process >>> >> >> 2012-07-19 12:39:28,046 DEBUG [cloud.vm.UserVmManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Successfully cleaned up vm >>> >>VM[User|i-43-347- >>> >> >> VM] >>> >> >> resources as a part of expunge process >>> >> >> 2012-07-19 12:39:28,108 INFO [cloud.user.AccountManagerImpl] >>> >> >> (Job-Executor-25:job-6598) deleteAccount: Deleted 1 network >>>groups >>> >>for >>> >> >> account 43 >>> >> >> 2012-07-19 12:39:28,108 DEBUG [cloud.user.AccountManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Deleting networks for account 43 >>> >> >> 2012-07-19 12:39:28,111 DEBUG [cloud.network.NetworkManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Unable to remove the network id=236 as >>>it >>> >> >> has >>> >> >> active Nics. >>> >> >> 2012-07-19 12:39:28,111 WARN [cloud.user.AccountManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Unable to destroy network >>> >>Ntwk[236|Guest|6] >>> >> >> as a >>> >> >> part of account id=43 cleanup. >>> >> >> 2012-07-19 12:39:28,114 INFO [cloud.user.AccountManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Cleanup for account 43 is needed. >>> >> >> 2012-07-19 12:39:28,126 DEBUG [cloud.async.AsyncJobManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Complete async job-6598, jobStatus: 1, >>> >> >> resultCode: 0, result: >>> >>com.cloud.api.response.SuccessResponse@49ce1227 >>> >> >> 2012-07-19 12:39:28,129 DEBUG [cloud.async.AsyncJobManagerImpl] >>> >> >> (Job-Executor-25:job-6598) Done executing >>> >> >> com.cloud.api.commands.DeleteAccountCmd for job-6598 >>> >> >> 2012-07-19 12:39:36,657 DEBUG [cloud.async.AsyncJobManagerImpl] >>> >> >> (http-12449-14:null) Async job-6598 completed >>> >> >> >>> >> >> >>> >> >> PS: all vms, snapshots and volumes was vanished after account >>> >>deleted. >>> >> >> just >>> >> >> vrouter wasn't. >>> >> > >>> >> >>> >> >>> >> >>> > >>> >>> >>> >> > > >
