[NETVIRT-1665] Exception from NAT service on release the ID from IDManager Created: 28/Jan/20  Updated: 04/Feb/20  Resolved: 04/Feb/20

Status: Verified
Project: netvirt
Component/s: natservice
Affects Version/s: None
Fix Version/s: Magnesium

Type: Bug Priority: Medium
Reporter: Karthikeyan Krishnan Assignee: Karthikeyan Krishnan
Resolution: Done Votes: 0
Labels: csit:exception
Remaining Estimate: 0 minutes
Time Spent: 4 hours
Original Estimate: Not Specified


 Description   

The following exception is seen in the CSIT job.

 

9f23e1794ccc with rd 15969f23-bc47-4bfa-b45b-9f23e1794ccc
2020-01-27T11:35:44,897 | INFO | jobcoordinator-main-task-25 | ExternalRoutersListener | 362 - org.opendaylight.netvirt.natservice-impl - 0.10.0.SNAPSHOT | removeTunnelTableEntry : called with DpnId = 211194717753353 and label = 100040
2020-01-27T11:35:44,898 | INFO | jobcoordinator-main-task-25 | IdManager | 254 - org.opendaylight.genius.idmanager-impl - 0.8.0.SNAPSHOT | Specified Id key 15969f23-bc47-4bfa-b45b-9f23e1794ccc.10.10.10.20/32 does not exist in id pool vpnservices
2020-01-27T11:35:44,898 | ERROR | jobcoordinator-main-task-25 | IdManager | 254 - org.opendaylight.genius.idmanager-impl - 0.8.0.SNAPSHOT | RPC releaseId() failed; input = ReleaseIdInput{_idKey=15969f23-bc47-4bfa-b45b-9f23e1794ccc.10.10.10.20/32, _poolName=vpnservices, augmentation=[]}
org.opendaylight.genius.idmanager.IdManagerException: Specified Id key 15969f23-bc47-4bfa-b45b-9f23e1794ccc.10.10.10.20/32 does not exist in id pool vpnservices
at org.opendaylight.genius.idmanager.IdManager.releaseIdFromLocalPool(IdManager.java:593) ~[?:?]
at org.opendaylight.genius.idmanager.IdManager.lambda$releaseId$13(IdManager.java:292) ~[?:?]
at org.opendaylight.serviceutils.tools.rpc.FutureRpcResults.lambda$fromBuilder$0(FutureRpcResults.java:134) ~[?:?]
at org.opendaylight.serviceutils.tools.rpc.FutureRpcResults$FutureRpcResultBuilder.build(FutureRpcResults.java:213) ~[?:?]
at org.opendaylight.genius.idmanager.IdManager.releaseId(IdManager.java:303) ~[?:?]
at org.opendaylight.mdsal.binding.dom.adapter.invoke.RpcMethodInvokerWithInput.invokeOn(RpcMethodInvokerWithInput.java:32) ~[?:?]
at org.opendaylight.mdsal.binding.dom.adapter.invoke.AbstractMappedRpcInvoker.invokeRpc(AbstractMappedRpcInvoker.java:57) ~[?:?]
at org.opendaylight.mdsal.binding.dom.adapter.BindingDOMRpcImplementationAdapter.invoke(BindingDOMRpcImplementationAdapter.java:90) ~[?:?]
at org.opendaylight.mdsal.binding.dom.adapter.BindingDOMRpcImplementationAdapter.invokeRpc(BindingDOMRpcImplementationAdapter.java:72) ~[?:?]
at org.opendaylight.mdsal.dom.broker.DOMRpcRouter$OperationInvocation.invokeGlobalRpc(DOMRpcRouter.java:553) ~[?:?]
at org.opendaylight.mdsal.dom.broker.DOMRpcRouter$OperationInvocation.invoke(DOMRpcRouter.java:498) ~[?:?]
at org.opendaylight.mdsal.dom.broker.DOMRpcRouter$RpcServiceFacade.invokeRpc(DOMRpcRouter.java:434) ~[?:?]
at Proxya371c858_ed6d_47d2_bd80_dc8aa9d14dde.invokeRpc(Unknown Source) ~[?:?]
at org.opendaylight.mdsal.binding.dom.adapter.RpcServiceAdapter$RpcInvocationStrategy.invoke0(RpcServiceAdapter.java:138) ~[?:?]
at org.opendaylight.mdsal.binding.dom.adapter.RpcServiceAdapter$RpcInvocationStrategy.invoke(RpcServiceAdapter.java:124) ~[?:?]
at org.opendaylight.mdsal.binding.dom.adapter.RpcServiceAdapter.invoke(RpcServiceAdapter.java:88) ~[?:?]
at com.sun.proxy.$Proxy88.releaseId(Unknown Source) ~[?:?]
at org.opendaylight.netvirt.vpnmanager.VpnUtil.releaseId(VpnUtil.java:558) ~[?:?]
at org.opendaylight.netvirt.vpnmanager.VpnRpcServiceImpl.removeVpnLabel(VpnRpcServiceImpl.java:114) ~[?:?]
at org.opendaylight.mdsal.binding.dom.adapter.invoke.RpcMethodInvokerWithInput.invokeOn(RpcMethodInvokerWithInput.java:32) ~[?:?]
at org.opendaylight.mdsal.binding.dom.adapter.invoke.AbstractMappedRpcInvoker.invokeRpc(AbstractMappedRpcInvoker.java:57) ~[?:?]
at org.opendaylight.mdsal.binding.dom.adapter.BindingDOMRpcImplementationAdapter.invoke(BindingDOMRpcImplementationAdapter.java:90) ~[?:?]
at org.opendaylight.mdsal.binding.dom.adapter.BindingDOMRpcImplementationAdapter.invokeRpc(BindingDOMRpcImplementationAdapter.java:72) ~[?:?]
at org.opendaylight.mdsal.dom.broker.DOMRpcRouter$OperationInvocation.invokeGlobalRpc(DOMRpcRouter.java:553) ~[?:?]
at org.opendaylight.mdsal.dom.broker.DOMRpcRouter$OperationInvocation.invoke(DOMRpcRouter.java:498) ~[?:?]
at org.opendaylight.mdsal.dom.broker.DOMRpcRouter$RpcServiceFacade.invokeRpc(DOMRpcRouter.java:434) ~[?:?]
at Proxya371c858_ed6d_47d2_bd80_dc8aa9d14dde.invokeRpc(Unknown Source) ~[?:?]
at org.opendaylight.mdsal.binding.dom.adapter.RpcServiceAdapter$RpcInvocationStrategy.invoke0(RpcServiceAdapter.java:138) ~[?:?]
at org.opendaylight.mdsal.binding.dom.adapter.RpcServiceAdapter$RpcInvocationStrategy.invoke(RpcServiceAdapter.java:124) ~[?:?]
at org.opendaylight.mdsal.binding.dom.adapter.RpcServiceAdapter.invoke(RpcServiceAdapter.java:88) ~[?:?]
at com.sun.proxy.$Proxy111.removeVpnLabel(Unknown Source) ~[?:?]
at org.opendaylight.netvirt.natservice.internal.ExternalRoutersListener.lambda$delFibTsAndReverseTraffic$10(ExternalRoutersListener.java:2484) ~[?:?]
at com.google.common.util.concurrent.AbstractTransformFuture$AsyncTransformFuture.doTransform(AbstractTransformFuture.java:213) ~[35:com.google.guava:27.1.0.jre]
at com.google.common.util.concurrent.AbstractTransformFuture$AsyncTransformFuture.doTransform(AbstractTransformFuture.java:202) ~[35:com.google.guava:27.1.0.jre]
at com.google.common.util.concurrent.AbstractTransformFuture.run(AbstractTransformFuture.java:118) ~[35:com.google.guava:27.1.0.jre]
at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30) ~[35:com.google.guava:27.1.0.jre]
at com.google.common.util.concurrent.ImmediateFuture.addListener(ImmediateFuture.java:39) ~[35:com.google.guava:27.1.0.jre]
at com.google.common.util.concurrent.ForwardingFluentFuture.addListener(ForwardingFluentFuture.java:45) ~[35:com.google.guava:27.1.0.jre]
at com.google.common.util.concurrent.AbstractTransformFuture.create(AbstractTransformFuture.java:39) ~[35:com.google.guava:27.1.0.jre]
at com.google.common.util.concurrent.Futures.transformAsync(Futures.java:471) ~[35:com.google.guava:27.1.0.jre]
at org.opendaylight.netvirt.natservice.internal.ExternalRoutersListener.delFibTsAndReverseTraffic(ExternalRoutersListener.java:2479) ~[?:?]
at org.opendaylight.netvirt.natservice.internal.ExternalRoutersListener.clrRtsFromBgpAndDelFibTs(ExternalRoutersListener.java:2301) ~[?:?]
at org.opendaylight.netvirt.natservice.internal.ExternalRoutersListener.clrRtsFromBgpAndDelFibTs(ExternalRoutersListener.java:2292) ~[?:?]
at org.opendaylight.netvirt.natservice.internal.ExternalRoutersListener.handleDisableSnat(ExternalRoutersListener.java:1825) ~[?:?]
at org.opendaylight.netvirt.natservice.internal.ExternalRoutersListener.lambda$remove$7(ExternalRoutersListener.java:1778) ~[?:?]
at org.opendaylight.genius.infra.ManagedTransactionFactoryImpl.lambda$callWithNewTransactionAndSubmit$3(ManagedTransactionFactoryImpl.java:90) ~[?:?]
at org.opendaylight.genius.infra.ManagedTransactionFactoryImpl.applyWithNewTransactionAndSubmit(ManagedTransactionFactoryImpl.java:106) ~[?:?]
at org.opendaylight.genius.infra.ManagedTransactionFactoryImpl.callWithNewTransactionAndSubmit(ManagedTransactionFactoryImpl.java:89) ~[?:?]
at org.opendaylight.genius.infra.ManagedNewTransactionRunnerImpl.callWithNewReadWriteTransactionAndSubmit(ManagedNewTransactionRunnerImpl.java:82) ~[?:?]
at org.opendaylight.netvirt.natservice.internal.ExternalRoutersListener.lambda$remove$8(ExternalRoutersListener.java:1747) ~[?:?]
at org.opendaylight.infrautils.jobcoordinator.internal.JobCoordinatorImpl$MainTask.run(JobCoordinatorImpl.java:432) [278:org.opendaylight.infrautils.jobcoordinator-impl:1.7.0.SNAPSHOT]
at java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1426) [?:?]
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290) [?:?]
at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1020) [?:?]
at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1656) [?:?]
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1594) [?:?]
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177) [?:?]
2020-01-27T11:35:44,907 | ERROR | jobcoordinator-main-task-25 | VpnUtil | 370 - org.opendaylight.netvirt.vpnmanager-impl - 0.10.0.SNAPSHOT | releaseId: RPC Call to release Id for key 15969f23-bc47-4bfa-b45b-9f23e1794ccc.10.10.10.20/32 from pool vpnservices returned with Errors [RpcError [message=Specified Id key 15969f23-bc47-4bfa-b45b-9f23e1794ccc.10.10.10.20/32 does not exist in id pool vpnservices, severity=ERROR, errorType=APPLICATION, tag=operation-failed, applicationTag=null, info=null, cause=org.opendaylight.genius.idmanager.IdManagerException: Specified Id key 15969f23-bc47-4bfa-b45b-9f23e1794ccc.10.10.10.20/32 does not exist in id pool vpnservices]]
2020-01-27T11:35:44,917 | INFO | jobcoordinator-main-task-25 | ExternalRoutersListener | 362 - org.opendaylight.netvirt.natservice-impl - 0.10.0.SNAPSHOT | handleDisableSnat : Exit

 

Log Ref Link:

https://logs.opendaylight.org/releng/vex-yul-odl-jenkins-1/netvirt-csit-1node-0cmb-1ctl-2cmp-openstack-queens-gate-stateful-itm-direct-tunnels-magnesium/81/odl_1/odl1_karaf.log.gz

 



 Comments   
Comment by Karthikeyan Krishnan [ 04/Feb/20 ]

I have not seen the reported ID Manager issue in the below passed log.

https://logs.opendaylight.org/releng/vex-yul-odl-jenkins-1/netvirt-csit-1node-0cmb-1ctl-2cmp-openstack-queens-gate-stateful-magnesium/148/odl_1/odl1_karaf.log.gz

Generated at Wed Feb 07 20:24:39 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.