[OPNFLWPLUG-68] pingall on Mininet with 15 nodes cause the controller to fail with many exceptions Created: 09/Feb/14  Updated: 27/Sep/21  Resolved: 25/Mar/14

Status: Resolved
Project: OpenFlowPlugin
Component/s: General
Affects Version/s: None
Fix Version/s: None

Type: Bug
Reporter: Jan Medved Assignee: Luis Gomez
Resolution: Duplicate Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Operating System: Mac OS
Platform: Macintosh

Issue Links:
Duplicate
duplicates CONTROLLER-232 Packet loss on first time ping test Resolved
External issue ID: 409

 Description   

When attaching a mininet with 15 nodes and trying to do a pingall on the mininet, all pings fail, and the following exceptions are observed at the controller:

2014-02-09 15:42:50.817 PST [md-sal-binding-commit-76] ERROR o.o.c.m.s.c.i.service.TwoPhaseCommit - Transaction: BA-153773 Finish Commit failed
java.lang.IllegalArgumentException: Session for the cookie is invalid. Reason: the switch has been recently diconnected OR inventory provides outdated information.
at org.opendaylight.openflowplugin.openflow.md.core.session.MessageDispatchServiceImpl.getConnectionAdapter(MessageDispatchServiceImpl.java:92) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.session.MessageDispatchServiceImpl.flowMod(MessageDispatchServiceImpl.java:124) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.sal.ModelDrivenSwitchImpl.removeFlow(ModelDrivenSwitchImpl.java:403) ~[na:na]
at org.opendaylight.yang.gen.v1.urn.opendaylight.flow.service.rev130819.SalFlowService$$Broker$Router.removeFlow(SalFlowService$$Broker$Router.java) ~[na:na]
at org.opendaylight.yang.gen.v1.urn.opendaylight.flow.service.rev130819.SalFlowService$$Broker$DirectProxy.removeFlow(SalFlowService$$Broker$DirectProxy.java) ~[na:na]
at org.opendaylight.controller.frm.flow.FlowTransaction.remove(FlowTransaction.java:65) ~[na:na]
at org.opendaylight.controller.frm.AbstractTransaction.callRpcs(AbstractTransaction.java:79) ~[na:na]
at org.opendaylight.controller.frm.AbstractTransaction.finish(AbstractTransaction.java:35) ~[na:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.call(TwoPhaseCommit.java:101) [bundlefile:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.call(TwoPhaseCommit.java:38) [bundlefile:na]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) [na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_51]
at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]
2014-02-09 15:42:50.827 PST [Thread-937] ERROR o.o.c.s.c.FlowProgrammerAdapter - Execution exception occured during processing flow
java.lang.IllegalArgumentException: Session for the cookie is invalid. Reason: the switch has been recently diconnected OR inventory provides outdated information.
at org.opendaylight.openflowplugin.openflow.md.core.session.MessageDispatchServiceImpl.getConnectionAdapter(MessageDispatchServiceImpl.java:92) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.session.MessageDispatchServiceImpl.flowMod(MessageDispatchServiceImpl.java:124) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.sal.ModelDrivenSwitchImpl.addFlow(ModelDrivenSwitchImpl.java:248) ~[na:na]
at org.opendaylight.yang.gen.v1.urn.opendaylight.flow.service.rev130819.SalFlowService$$Broker$Router.addFlow(SalFlowService$$Broker$Router.java) ~[na:na]
at org.opendaylight.yang.gen.v1.urn.opendaylight.flow.service.rev130819.SalFlowService$$Broker$DirectProxy.addFlow(SalFlowService$$Broker$DirectProxy.java) ~[na:na]
at org.opendaylight.controller.frm.flow.FlowTransaction.add(FlowTransaction.java:121) ~[na:na]
at org.opendaylight.controller.frm.AbstractTransaction.rollbackRpcs(AbstractTransaction.java:119) ~[na:na]
at org.opendaylight.controller.frm.AbstractTransaction.rollback(AbstractTransaction.java:45) ~[na:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.rollback(TwoPhaseCommit.java:154) ~[na:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.call(TwoPhaseCommit.java:111) ~[na:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.call(TwoPhaseCommit.java:38) ~[na:na]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) ~[na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) ~[na:1.7.0_51]
at java.lang.Thread.run(Thread.java:744) ~[na:1.7.0_51]
2014-02-09 15:42:50.837 PST [md-sal-binding-commit-75] ERROR o.o.c.m.s.c.i.service.TwoPhaseCommit - Transaction: BA-153798 Finish Commit failed
java.lang.IllegalArgumentException: Session for the cookie is invalid. Reason: the switch has been recently diconnected OR inventory provides outdated information.
at org.opendaylight.openflowplugin.openflow.md.core.session.MessageDispatchServiceImpl.getConnectionAdapter(MessageDispatchServiceImpl.java:92) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.session.MessageDispatchServiceImpl.flowMod(MessageDispatchServiceImpl.java:124) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.sal.ModelDrivenSwitchImpl.addFlow(ModelDrivenSwitchImpl.java:248) ~[na:na]
at org.opendaylight.yang.gen.v1.urn.opendaylight.flow.service.rev130819.SalFlowService$$Broker$Router.addFlow(SalFlowService$$Broker$Router.java) ~[na:na]
at org.opendaylight.yang.gen.v1.urn.opendaylight.flow.service.rev130819.SalFlowService$$Broker$DirectProxy.addFlow(SalFlowService$$Broker$DirectProxy.java) ~[na:na]
at org.opendaylight.controller.frm.flow.FlowTransaction.add(FlowTransaction.java:121) ~[na:na]
at org.opendaylight.controller.frm.AbstractTransaction.callRpcs(AbstractTransaction.java:63) ~[na:na]
at org.opendaylight.controller.frm.AbstractTransaction.finish(AbstractTransaction.java:35) ~[na:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.call(TwoPhaseCommit.java:101) [bundlefile:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.call(TwoPhaseCommit.java:38) [bundlefile:na]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) [na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_51]
at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]
2014-02-09 15:42:50.851 PST [Thread-937] ERROR o.o.c.s.c.FlowProgrammerAdapter - Execution exception occured during processing flow
java.lang.IllegalArgumentException: Session for the cookie is invalid. Reason: the switch has been recently diconnected OR inventory provides outdated information.
at org.opendaylight.openflowplugin.openflow.md.core.session.MessageDispatchServiceImpl.getConnectionAdapter(MessageDispatchServiceImpl.java:92) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.session.MessageDispatchServiceImpl.flowMod(MessageDispatchServiceImpl.java:124) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.sal.ModelDrivenSwitchImpl.removeFlow(ModelDrivenSwitchImpl.java:403) ~[na:na]
at org.opendaylight.yang.gen.v1.urn.opendaylight.flow.service.rev130819.SalFlowService$$Broker$Router.removeFlow(SalFlowService$$Broker$Router.java) ~[na:na]
at org.opendaylight.yang.gen.v1.urn.opendaylight.flow.service.rev130819.SalFlowService$$Broker$DirectProxy.removeFlow(SalFlowService$$Broker$DirectProxy.java) ~[na:na]
at org.opendaylight.controller.frm.flow.FlowTransaction.remove(FlowTransaction.java:65) ~[na:na]
at org.opendaylight.controller.frm.AbstractTransaction.rollbackRpcs(AbstractTransaction.java:103) ~[na:na]
at org.opendaylight.controller.frm.AbstractTransaction.rollback(AbstractTransaction.java:45) ~[na:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.rollback(TwoPhaseCommit.java:154) ~[na:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.call(TwoPhaseCommit.java:111) ~[na:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.call(TwoPhaseCommit.java:38) ~[na:na]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) ~[na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) ~[na:1.7.0_51]
at java.lang.Thread.run(Thread.java:744) ~[na:1.7.0_51]
2014-02-09 15:42:50.851 PST [Thread-937] ERROR o.o.c.s.s.i.SimpleForwardingImpl - Failed to install policy: 10.0.0.1/32 (Internal Error)
2014-02-09 15:42:50.878 PST [md-sal-binding-commit-53] ERROR o.o.c.m.s.c.i.service.TwoPhaseCommit - Transaction: BA-153834 Finish Commit failed
java.lang.IllegalArgumentException: Session for the cookie is invalid. Reason: the switch has been recently diconnected OR inventory provides outdated information.
at org.opendaylight.openflowplugin.openflow.md.core.session.MessageDispatchServiceImpl.getConnectionAdapter(MessageDispatchServiceImpl.java:92) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.session.MessageDispatchServiceImpl.flowMod(MessageDispatchServiceImpl.java:124) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.sal.ModelDrivenSwitchImpl.removeFlow(ModelDrivenSwitchImpl.java:403) ~[na:na]
at org.opendaylight.yang.gen.v1.urn.opendaylight.flow.service.rev130819.SalFlowService$$Broker$Router.removeFlow(SalFlowService$$Broker$Router.java) ~[na:na]
at org.opendaylight.yang.gen.v1.urn.opendaylight.flow.service.rev130819.SalFlowService$$Broker$DirectProxy.removeFlow(SalFlowService$$Broker$DirectProxy.java) ~[na:na]
at org.opendaylight.controller.frm.flow.FlowTransaction.remove(FlowTransaction.java:65) ~[na:na]
at org.opendaylight.controller.frm.AbstractTransaction.callRpcs(AbstractTransaction.java:79) ~[na:na]
at org.opendaylight.controller.frm.AbstractTransaction.finish(AbstractTransaction.java:35) ~[na:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.call(TwoPhaseCommit.java:101) [bundlefile:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.call(TwoPhaseCommit.java:38) [bundlefile:na]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) [na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_51]
at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]
2014-02-09 15:42:50.890 PST [Thread-942] ERROR o.o.c.s.c.FlowProgrammerAdapter - Execution exception occured during processing flow
java.lang.IllegalArgumentException: Session for the cookie is invalid. Reason: the switch has been recently diconnected OR inventory provides outdated information.
at org.opendaylight.openflowplugin.openflow.md.core.session.MessageDispatchServiceImpl.getConnectionAdapter(MessageDispatchServiceImpl.java:92) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.session.MessageDispatchServiceImpl.flowMod(MessageDispatchServiceImpl.java:124) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.sal.ModelDrivenSwitchImpl.addFlow(ModelDrivenSwitchImpl.java:248) ~[na:na]
at org.opendaylight.yang.gen.v1.urn.opendaylight.flow.service.rev130819.SalFlowService$$Broker$Router.addFlow(SalFlowService$$Broker$Router.java) ~[na:na]
at org.opendaylight.yang.gen.v1.urn.opendaylight.flow.service.rev130819.SalFlowService$$Broker$DirectProxy.addFlow(SalFlowService$$Broker$DirectProxy.java) ~[na:na]
at org.opendaylight.controller.frm.flow.FlowTransaction.add(FlowTransaction.java:121) ~[na:na]
at org.opendaylight.controller.frm.AbstractTransaction.rollbackRpcs(AbstractTransaction.java:119) ~[na:na]
at org.opendaylight.controller.frm.AbstractTransaction.rollback(AbstractTransaction.java:45) ~[na:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.rollback(TwoPhaseCommit.java:154) ~[na:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.call(TwoPhaseCommit.java:111) ~[na:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.call(TwoPhaseCommit.java:38) ~[na:na]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) ~[na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) ~[na:1.7.0_51]
at java.lang.Thread.run(Thread.java:744) ~[na:1.7.0_51]
2014-02-09 15:42:50.905 PST [md-sal-binding-commit-75] ERROR o.o.c.m.s.c.i.service.TwoPhaseCommit - Transaction: BA-153860 Finish Commit failed
java.lang.IllegalArgumentException: Session for the cookie is invalid. Reason: the switch has been recently diconnected OR inventory provides outdated information.
at org.opendaylight.openflowplugin.openflow.md.core.session.MessageDispatchServiceImpl.getConnectionAdapter(MessageDispatchServiceImpl.java:92) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.session.MessageDispatchServiceImpl.flowMod(MessageDispatchServiceImpl.java:124) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.sal.ModelDrivenSwitchImpl.addFlow(ModelDrivenSwitchImpl.java:248) ~[na:na]
at org.opendaylight.yang.gen.v1.urn.opendaylight.flow.service.rev130819.SalFlowService$$Broker$Router.addFlow(SalFlowService$$Broker$Router.java) ~[na:na]
at org.opendaylight.yang.gen.v1.urn.opendaylight.flow.service.rev130819.SalFlowService$$Broker$DirectProxy.addFlow(SalFlowService$$Broker$DirectProxy.java) ~[na:na]
at org.opendaylight.controller.frm.flow.FlowTransaction.add(FlowTransaction.java:121) ~[na:na]
at org.opendaylight.controller.frm.AbstractTransaction.callRpcs(AbstractTransaction.java:63) ~[na:na]
at org.opendaylight.controller.frm.AbstractTransaction.finish(AbstractTransaction.java:35) ~[na:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.call(TwoPhaseCommit.java:101) [bundlefile:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.call(TwoPhaseCommit.java:38) [bundlefile:na]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) [na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_51]
at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]
2014-02-09 15:42:50.917 PST [Thread-942] ERROR o.o.c.s.c.FlowProgrammerAdapter - Execution exception occured during processing flow
java.lang.IllegalArgumentException: Session for the cookie is invalid. Reason: the switch has been recently diconnected OR inventory provides outdated information.
at org.opendaylight.openflowplugin.openflow.md.core.session.MessageDispatchServiceImpl.getConnectionAdapter(MessageDispatchServiceImpl.java:92) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.session.MessageDispatchServiceImpl.flowMod(MessageDispatchServiceImpl.java:124) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.sal.ModelDrivenSwitchImpl.removeFlow(ModelDrivenSwitchImpl.java:403) ~[na:na]
at org.opendaylight.yang.gen.v1.urn.opendaylight.flow.service.rev130819.SalFlowService$$Broker$Router.removeFlow(SalFlowService$$Broker$Router.java) ~[na:na]
at org.opendaylight.yang.gen.v1.urn.opendaylight.flow.service.rev130819.SalFlowService$$Broker$DirectProxy.removeFlow(SalFlowService$$Broker$DirectProxy.java) ~[na:na]
at org.opendaylight.controller.frm.flow.FlowTransaction.remove(FlowTransaction.java:65) ~[na:na]
at org.opendaylight.controller.frm.AbstractTransaction.rollbackRpcs(AbstractTransaction.java:103) ~[na:na]
at org.opendaylight.controller.frm.AbstractTransaction.rollback(AbstractTransaction.java:45) ~[na:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.rollback(TwoPhaseCommit.java:154) ~[na:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.call(TwoPhaseCommit.java:111) ~[na:na]
at org.opendaylight.controller.md.sal.common.impl.service.TwoPhaseCommit.call(TwoPhaseCommit.java:38) ~[na:na]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) ~[na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) ~[na:1.7.0_51]
at java.lang.Thread.run(Thread.java:744) ~[na:1.7.0_51]
2014-02-09 15:42:50.917 PST [Thread-942] ERROR o.o.c.s.s.i.SimpleForwardingImpl - Failed to install policy: 10.0.0.1/32 (Internal Error)
2014-02-09 15:42:51.028 PST [Thread-4628] ERROR o.o.c.h.internal.HostTracker - Exception on new host notification
java.lang.IllegalArgumentException: adflow is unknown
at org.opendaylight.controller.sal.compatibility.FlowProgrammerAdapter.internalRemoveFlowAsync(FlowProgrammerAdapter.java:301) ~[na:na]
at org.opendaylight.controller.sal.compatibility.FlowProgrammerAdapter.removeFlow(FlowProgrammerAdapter.java:136) ~[na:na]
at org.opendaylight.controller.sal.implementation.internal.FlowProgrammerService.removeFlow(FlowProgrammerService.java:197) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.removeEntryInternal(ForwardingRulesManager.java:705) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.removeEntry(ForwardingRulesManager.java:648) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.uninstallFlowEntry(ForwardingRulesManager.java:981) ~[na:na]
at org.opendaylight.controller.samples.simpleforwarding.internal.SimpleForwardingImpl.uninstallPerHostRules(SimpleForwardingImpl.java:686) ~[na:na]
at org.opendaylight.controller.samples.simpleforwarding.internal.SimpleForwardingImpl.notifyHTClientHostRemoved(SimpleForwardingImpl.java:838) ~[na:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.notifyHostLearnedOrRemoved(HostTracker.java:574) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.replaceHost(HostTracker.java:486) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.access$200(HostTracker.java:103) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker$NotifyHostThread.run(HostTracker.java:528) [bundlefile:na]
2014-02-09 15:42:51.117 PST [Thread-14] ERROR o.o.o.o.m.core.ErrorHandlerQueueImpl - IN THREAD: pool-109-thread-1; session:null -> rpcError:null;
java.lang.Exception: rpcError:null;
at org.opendaylight.openflowplugin.openflow.md.core.RpcUtil.smokeRpc(RpcUtil.java:34) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.HandshakeManagerImpl.sendHelloMessage(HandshakeManagerImpl.java:277) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.HandshakeManagerImpl.handleLowerVersionProposal(HandshakeManagerImpl.java:152) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.HandshakeManagerImpl.handleStepByStepVersionNegotiation(HandshakeManagerImpl.java:138) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.HandshakeManagerImpl.shake(HandshakeManagerImpl.java:103) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.HandshakeStepWrapper.run(HandshakeStepWrapper.java:47) ~[na:na]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) ~[na:1.7.0_51]
at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]
2014-02-09 15:42:51.122 PST [Thread-14] ERROR o.o.o.o.m.core.ErrorHandlerQueueImpl - IN THREAD: pool-110-thread-1; session:null -> rpcError:null;
java.lang.Exception: rpcError:null;
at org.opendaylight.openflowplugin.openflow.md.core.RpcUtil.smokeRpc(RpcUtil.java:34) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.HandshakeManagerImpl.sendHelloMessage(HandshakeManagerImpl.java:277) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.HandshakeManagerImpl.handleStepByStepVersionNegotiation(HandshakeManagerImpl.java:124) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.HandshakeManagerImpl.shake(HandshakeManagerImpl.java:103) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.HandshakeStepWrapper.run(HandshakeStepWrapper.java:47) ~[na:na]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_51]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) ~[na:1.7.0_51]
at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]
2014-02-09 15:42:51.262 PST [Thread-3923] ERROR o.o.c.h.internal.HostTracker - Exception on new host notification
java.lang.IllegalArgumentException: adflow is unknown
at org.opendaylight.controller.sal.compatibility.FlowProgrammerAdapter.internalRemoveFlowAsync(FlowProgrammerAdapter.java:301) ~[na:na]
at org.opendaylight.controller.sal.compatibility.FlowProgrammerAdapter.removeFlow(FlowProgrammerAdapter.java:136) ~[na:na]
at org.opendaylight.controller.sal.implementation.internal.FlowProgrammerService.removeFlow(FlowProgrammerService.java:197) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.removeEntryInternal(ForwardingRulesManager.java:705) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.removeEntry(ForwardingRulesManager.java:648) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.uninstallFlowEntry(ForwardingRulesManager.java:981) ~[na:na]
at org.opendaylight.controller.samples.simpleforwarding.internal.SimpleForwardingImpl.uninstallPerHostRules(SimpleForwardingImpl.java:686) ~[na:na]
at org.opendaylight.controller.samples.simpleforwarding.internal.SimpleForwardingImpl.notifyHTClientHostRemoved(SimpleForwardingImpl.java:838) ~[na:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.notifyHostLearnedOrRemoved(HostTracker.java:574) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.replaceHost(HostTracker.java:486) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.access$200(HostTracker.java:103) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker$NotifyHostThread.run(HostTracker.java:528) [bundlefile:na]
2014-02-09 15:42:51.307 PST [Thread-3645] ERROR o.o.c.h.internal.HostTracker - Exception on new host notification
java.lang.IllegalArgumentException: adflow is unknown
at org.opendaylight.controller.sal.compatibility.FlowProgrammerAdapter.internalRemoveFlowAsync(FlowProgrammerAdapter.java:301) ~[na:na]
at org.opendaylight.controller.sal.compatibility.FlowProgrammerAdapter.removeFlow(FlowProgrammerAdapter.java:136) ~[na:na]
at org.opendaylight.controller.sal.implementation.internal.FlowProgrammerService.removeFlow(FlowProgrammerService.java:197) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.removeEntryInternal(ForwardingRulesManager.java:705) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.removeEntry(ForwardingRulesManager.java:648) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.uninstallFlowEntry(ForwardingRulesManager.java:981) ~[na:na]
at org.opendaylight.controller.samples.simpleforwarding.internal.SimpleForwardingImpl.uninstallPerHostRules(SimpleForwardingImpl.java:686) ~[na:na]
at org.opendaylight.controller.samples.simpleforwarding.internal.SimpleForwardingImpl.notifyHTClientHostRemoved(SimpleForwardingImpl.java:838) ~[na:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.notifyHostLearnedOrRemoved(HostTracker.java:574) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.replaceHost(HostTracker.java:486) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.access$200(HostTracker.java:103) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker$NotifyHostThread.run(HostTracker.java:528) [bundlefile:na]
2014-02-09 15:42:51.795 PST [Thread-3153] ERROR o.o.c.h.internal.HostTracker - Exception on new host notification
java.lang.IllegalArgumentException: adflow is unknown
at org.opendaylight.controller.sal.compatibility.FlowProgrammerAdapter.internalRemoveFlowAsync(FlowProgrammerAdapter.java:301) ~[na:na]
at org.opendaylight.controller.sal.compatibility.FlowProgrammerAdapter.removeFlow(FlowProgrammerAdapter.java:136) ~[na:na]
at org.opendaylight.controller.sal.implementation.internal.FlowProgrammerService.removeFlow(FlowProgrammerService.java:197) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.removeEntryInternal(ForwardingRulesManager.java:705) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.removeEntry(ForwardingRulesManager.java:648) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.uninstallFlowEntry(ForwardingRulesManager.java:981) ~[na:na]
at org.opendaylight.controller.samples.simpleforwarding.internal.SimpleForwardingImpl.uninstallPerHostRules(SimpleForwardingImpl.java:686) ~[na:na]
at org.opendaylight.controller.samples.simpleforwarding.internal.SimpleForwardingImpl.notifyHTClientHostRemoved(SimpleForwardingImpl.java:838) ~[na:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.notifyHostLearnedOrRemoved(HostTracker.java:574) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.replaceHost(HostTracker.java:486) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.access$200(HostTracker.java:103) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker$NotifyHostThread.run(HostTracker.java:528) [bundlefile:na]
2014-02-09 15:42:51.891 PST [Thread-2612] ERROR o.o.c.h.internal.HostTracker - Exception on new host notification
java.lang.IllegalArgumentException: adflow is unknown
at org.opendaylight.controller.sal.compatibility.FlowProgrammerAdapter.internalRemoveFlowAsync(FlowProgrammerAdapter.java:301) ~[na:na]
at org.opendaylight.controller.sal.compatibility.FlowProgrammerAdapter.removeFlow(FlowProgrammerAdapter.java:136) ~[na:na]
at org.opendaylight.controller.sal.implementation.internal.FlowProgrammerService.removeFlow(FlowProgrammerService.java:197) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.removeEntryInternal(ForwardingRulesManager.java:705) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.removeEntry(ForwardingRulesManager.java:648) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.uninstallFlowEntry(ForwardingRulesManager.java:981) ~[na:na]
at org.opendaylight.controller.samples.simpleforwarding.internal.SimpleForwardingImpl.uninstallPerHostRules(SimpleForwardingImpl.java:686) ~[na:na]
at org.opendaylight.controller.samples.simpleforwarding.internal.SimpleForwardingImpl.notifyHTClientHostRemoved(SimpleForwardingImpl.java:838) ~[na:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.notifyHostLearnedOrRemoved(HostTracker.java:574) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.replaceHost(HostTracker.java:486) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.access$200(HostTracker.java:103) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker$NotifyHostThread.run(HostTracker.java:528) [bundlefile:na]
2014-02-09 15:42:51.904 PST [Thread-2606] ERROR o.o.c.h.internal.HostTracker - Exception on new host notification

2014-02-09 15:42:53.114 PST [Thread-2262] ERROR o.o.c.h.internal.HostTracker - Exception on new host notification
java.lang.IllegalArgumentException: adflow is unknown
at org.opendaylight.controller.sal.compatibility.FlowProgrammerAdapter.internalRemoveFlowAsync(FlowProgrammerAdapter.java:301) ~[na:na]
at org.opendaylight.controller.sal.compatibility.FlowProgrammerAdapter.removeFlow(FlowProgrammerAdapter.java:136) ~[na:na]
at org.opendaylight.controller.sal.implementation.internal.FlowProgrammerService.removeFlow(FlowProgrammerService.java:197) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.removeEntryInternal(ForwardingRulesManager.java:705) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.removeEntry(ForwardingRulesManager.java:648) ~[na:na]
at org.opendaylight.controller.forwardingrulesmanager.internal.ForwardingRulesManager.uninstallFlowEntry(ForwardingRulesManager.java:981) ~[na:na]
at org.opendaylight.controller.samples.simpleforwarding.internal.SimpleForwardingImpl.uninstallPerHostRules(SimpleForwardingImpl.java:686) ~[na:na]
at org.opendaylight.controller.samples.simpleforwarding.internal.SimpleForwardingImpl.notifyHTClientHostRemoved(SimpleForwardingImpl.java:838) ~[na:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.notifyHostLearnedOrRemoved(HostTracker.java:574) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.replaceHost(HostTracker.java:486) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker.access$200(HostTracker.java:103) [bundlefile:na]
at org.opendaylight.controller.hosttracker.internal.HostTracker$NotifyHostThread.run(HostTracker.java:528) [bundlefile:na]

Note that this behavior is not observed on a mininet with 7 nodes - 15 nodes and up are required to to observe this problem.

 Comments   
Comment by Ed Warnicke [ 10/Feb/14 ]

Additional data. This bug is believed to be rooted in a race condition in the adapters. The InventoryAndReadAdapter is receiving a NodeConnectorUpdated notification, and then checking for the presence of the referenced NodeConnector in the data store to determine whether or not the operation to be represented to the AD-SAL is an ADD or CHANGED. Unfortunately, the FlowCapableInventoryManager is receiving the same notification, and if it completes its write to the data store first, then that check will indicate CHANGED when it should indicated ADD.

The correct solution to this is to use DataChangeListeners, which allow you to distinguish creation from update.

One warning with DataChangeListeners as its it counter intuitive... and add is listed in both the created and updated set of modifications. See the FRM or TopologyAdapter for examples of how to sort this out.

Comment by Moiz Raja [ 10/Feb/14 ]

Ed,

While using a DataChangeListener may be a solution wouldn't it be better if the NodeUpdated/NodeConnectorUpdated event was enhanced to specify whether this is an addition or update of the node/nodeconnector? Otherwise it seems like the notification is not that useful because I am forced now to use a DataChange instead of it.

Also using a DataChange seems like a hack to me anyway because it exposes the underlying details of the implementation (of the notifier) and that is not good either.

Comment by Abhijit Kumbhare [ 17/Mar/14 ]

Luis,

Can you check if this issue still exists?

Abhijit

Comment by Madhusudhan Ananderi [ 18/Mar/14 ]

Tested on two things:

1. using OF10 mininet:
It is working, but during the first round usually not all pings succeed. The second round is then always 100% success.

I believe that as soon as the topology is explored, the controller must be able to manage all ping packets to be delivered.

2. using OF13 mininet:
It is working, but during the first round usually not all pings succeed. The second round is then always 100% success.

I believe that as soon as the topology is explored, the controller must be able to manage all ping packets to be delivered.

Comment by Abhijit Kumbhare [ 20/Mar/14 ]

We should look into the first ping failing. However the reported issue seems to be fixed.

Comment by Luis Gomez [ 25/Mar/14 ]

I created CONTROLLER-232 to collect this issue.

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