-
Type: Bug
-
Status: Closed (View Workflow)
-
Priority: Minor
-
Resolution: Done
-
Affects Version/s: 1.6.0
-
Fix Version/s: 1.6.0
-
Component/s: None
-
Labels:
-
Environment:
3 node cluster, 7 switches, openflow 1.3, 1 multipoint to singlepoint intent.
-
Story Points:3
When taking one the of the links down and bringing it back up to test intent rerouting functionality, after bringing the link back up there was a topology missmatch, followed quickly by the topology failing and links between switches and hosts disappearing.
First in the onos log, the following warnings were seen:
2016-04-25 13:42:03,686 | WARN | ew I/O worker #6 | NiciraSwitchHandshaker | 177 - org.onosproject.onos-of-api - 1.6.0.SNAPSHOT | Received permission error from switch 00:00:00:00:00:00:00:06 while being master. Reasserting master role. 2016-04-25 13:42:03,687 | WARN | ew I/O worker #6 | NiciraSwitchHandshaker | 177 - org.onosproject.onos-of-api - 1.6.0.SNAPSHOT | Received permission error from switch 00:00:00:00:00:00:00:06 while being master. Reasserting master role. 2016-04-25 13:42:03,687 | WARN | ew I/O worker #2 | NiciraSwitchHandshaker | 177 - org.onosproject.onos-of-api - 1.6.0.SNAPSHOT | Received permission error from switch 00:00:00:00:00:00:00:02 while being master. Reasserting master role. 2016-04-25 13:42:03,687 | WARN | ew I/O worker #2 | NiciraSwitchHandshaker | 177 - org.onosproject.onos-of-api - 1.6.0.SNAPSHOT | Received permission error from switch 00:00:00:00:00:00:00:02 while being master. Reasserting master role. 2016-04-25 13:42:03,687 | WARN | ew I/O worker #2 | NiciraSwitchHandshaker | 177 - org.onosproject.onos-of-api - 1.6.0.SNAPSHOT | Received permission error from switch 00:00:00:00:00:00:00:02 while being master. Reasserting master role. 2016-04-25 13:42:03,687 | WARN | ew I/O worker #2 | NiciraSwitchHandshaker | 177 - org.onosproject.onos-of-api - 1.6.0.SNAPSHOT | Received permission error from switch 00:00:00:00:00:00:00:02 while being master. Reasserting master role. 2016-04-25 13:42:03,688 | WARN | ew I/O worker #2 | NiciraSwitchHandshaker | 177 - org.onosproject.onos-of-api - 1.6.0.SNAPSHOT | Received permission error from switch 00:00:00:00:00:00:00:02 while being master. Reasserting master role. 2016-04-25 13:42:03,688 | WARN | ew I/O worker #2 | NiciraSwitchHandshaker | 177 - org.onosproject.onos-of-api - 1.6.0.SNAPSHOT | Received permission error from switch 00:00:00:00:00:00:00:02 while being master. Reasserting master role. 2016-04-25 13:42:03,688 | WARN | ew I/O worker #2 | NiciraSwitchHandshaker | 177 - org.onosproject.onos-of-api - 1.6.0.SNAPSHOT | Received permission error from switch 00:00:00:00:00:00:00:02 while being master. Reasserting master role. 2016-04-25 13:42:03,688 | WARN | ew I/O worker #2 | NiciraSwitchHandshaker | 177 - org.onosproject.onos-of-api - 1.6.0.SNAPSHOT | Received permission error from switch 00:00:00:00:00:00:00:02 while being master. Reasserting master role. 2016-04-25 13:42:03,689 | WARN | f-event-stats-18 | OpenFlowRuleProvider | 182 - org.onosproject.onos-of-provider-flow - 1.6.0.SNAPSHOT | Received error message OFBadRequestErrorMsgVer13(xid=2435, code=EPERM, data=[unparsed: 04 0d 00 79 00 00 09 83 ff ff ff ff ff ff ff fd 00 10 00 00 00 00 00 00 00 00 00 10 00 00 00 01 00 00 00 00 00 00 00 00 01 23 20 00 00 01 de ad be ef ba 11 88 cc 02 07 04 00 00 00 00 00 02 04]) from 00:00:00:00:00:00:00:02 2016-04-25 13:42:03,691 | WARN | f-event-stats-28 | OpenFlowRuleProvider | 182 - org.onosproject.onos-of-provider-flow - 1.6.0.SNAPSHOT | Received error message OFBadRequestErrorMsgVer13(xid=2442, code=EPERM, data=[unparsed: 04 0d 00 79 00 00 09 8a ff ff ff ff ff ff ff fd 00 10 00 00 00 00 00 00 00 00 00 10 00 00 00 04 00 00 00 00 00 00 00 00 ff ff ff ff ff ff de ad be ef ba 11 89 42 02 07 04 00 00 00 00 00 02 04]) from 00:00:00:00:00:00:00:02 2016-04-25 13:42:03,691 | WARN | ew I/O worker #6 | NiciraSwitchHandshaker | 177 - org.onosproject.onos-of-api - 1.6.0.SNAPSHOT | Received permission error from switch 00:00:00:00:00:00:00:06 while being master. Reasserting master role. 2016-04-25 13:42:03,689 | WARN | f-event-stats-22 | OpenFlowRuleProvider | 182 - org.onosproject.onos-of-provider-flow - 1.6.0.SNAPSHOT | Received error message OFBadRequestErrorMsgVer13(xid=2436, code=EPERM, data=[unparsed: 04 0d 00 79 00 00 09 84 ff ff ff ff ff ff ff fd 00 10 00 00 00 00 00 00 00 00 00 10 00 00 00 01 00 00 00 00 00 00 00 00 ff ff ff ff ff ff de ad be ef ba 11 89 42 02 07 04 00 00 00 00 00 02 04]) from 00:00:00:00:00:00:00:02 2016-04-25 13:42:03,691 | WARN | f-event-stats-20 | OpenFlowRuleProvider | 182 - org.onosproject.onos-of-provider-flow - 1.6.0.SNAPSHOT | Received error message OFBadRequestErrorMsgVer13(xid=2440, code=EPERM, data=[unparsed: 04 0d 00 79 00 00 09 88 ff ff ff ff ff ff ff fd 00 10 00 00 00 00 00 00 00 00 00 10 00 00 00 03 00 00 00 00 00 00 00 00 ff ff ff ff ff ff de ad be ef ba 11 89 42 02 07 04 00 00 00 00 00 02 04]) from 00:00:00:00:00:00:00:02 2016-04-25 13:42:03,690 | WARN | f-event-stats-24 | OpenFlowRuleProvider | 182 - org.onosproject.onos-of-provider-flow - 1.6.0.SNAPSHOT | Received error message OFBadRequestErrorMsgVer13(xid=2438, code=EPERM, data=[unparsed: 04 0d 00 79 00 00 09 86 ff ff ff ff ff ff ff fd 00 10 00 00 00 00 00 00 00 00 00 10 00 00 00 02 00 00 00 00 00 00 00 00 ff ff ff ff ff ff de ad be ef ba 11 89 42 02 07 04 00 00 00 00 00 02 04]) from 00:00:00:00:00:00:00:02 2016-04-25 13:42:03,692 | WARN | of-event-stats-3 | OpenFlowRuleProvider | 182 - org.onosproject.onos-of-provider-flow - 1.6.0.SNAPSHOT | Received error message OFBadRequestErrorMsgVer13(xid=2393, code=EPERM, data=[unparsed: 04 0d 00 79 00 00 09 59 ff ff ff ff ff ff ff fd 00 10 00 00 00 00 00 00 00 00 00 10 00 00 00 02 00 00 00 00 00 00 00 00 01 23 20 00 00 01 de ad be ef ba 11 88 cc 02 07 04 00 00 00 00 00 06 04]) from 00:00:00:00:00:00:00:06 2016-04-25 13:42:03,690 | WARN | f-event-stats-17 | OpenFlowRuleProvider | 182 - org.onosproject.onos-of-provider-flow - 1.6.0.SNAPSHOT | Received error message OFBadRequestErrorMsgVer13(xid=2439, code=EPERM, data=[unparsed: 04 0d 00 79 00 00 09 87 ff ff ff ff ff ff ff fd 00 10 00 00 00 00 00 00 00 00 00 10 00 00 00 03 00 00 00 00 00 00 00 00 01 23 20 00 00 01 de ad be ef ba 11 88 cc 02 07 04 00 00 00 00 00 02 04]) from 00:00:00:00:00:00:00:02
Then the following warnings and stack trace were seen:
2016-04-25 13:42:04,383 | WARN | f-event-stats-21 | OpenFlowRuleProvider | 182 - org.onosproject.onos-of-provider-flow - 1.6.0.SNAPSHOT | Received error message OFBadRequestErrorMsgVer13(xid=0, code=EPERM, data=OFFlowDeleteStrictVer13(xid=0, cookie=0x00070000bc47a77c, cookieMask=0x0000000000000000, tableId=0x0, idleTimeout=0, hardTimeout=0, priority=40000, bufferId=4294967295, outPort=any, outGroup=any, flags=[SEND_FLOW_REM], match=OFMatchV3Ver13(eth_type=0x8942), instructions=[])) from 00:00:00:00:00:00:00:05 2016-04-25 13:42:04,383 | WARN | of-event-stats-8 | OpenFlowRuleProvider | 182 - org.onosproject.onos-of-provider-flow - 1.6.0.SNAPSHOT | Received error message OFBadRequestErrorMsgVer13(xid=0, code=EPERM, data=OFFlowDeleteStrictVer13(xid=0, cookie=0x00070000b90d5c0d, cookieMask=0x0000000000000000, tableId=0x0, idleTimeout=0, hardTimeout=0, priority=40000, bufferId=4294967295, outPort=any, outGroup=any, flags=[SEND_FLOW_REM], match=OFMatchV3Ver13(eth_type=0x88cc), instructions=[])) from 00:00:00:00:00:00:00:05 2016-04-25 13:42:04,383 | WARN | of-event-stats-0 | OpenFlowRuleProvider | 182 - org.onosproject.onos-of-provider-flow - 1.6.0.SNAPSHOT | Received error message OFBadRequestErrorMsgVer13(xid=0, code=EPERM, data=OFFlowDeleteStrictVer13(xid=0, cookie=0x00070000964f38f7, cookieMask=0x0000000000000000, tableId=0x0, idleTimeout=0, hardTimeout=0, priority=40000, bufferId=4294967295, outPort=any, outGroup=any, flags=[SEND_FLOW_REM], match=OFMatchV3Ver13(eth_type=0x806), instructions=[])) from 00:00:00:00:00:00:00:05
2016-04-25 13:42:42,250 | ERROR | entLoopGroup-3-2 | NettyMessagingManager | 131 - org.onosproject.onos-core-dist - 1.6.0.SNAPSHOT | Exception inside channel handling pipeline. com.esotericsoftware.kryo.KryoException: java.lang.IndexOutOfBoundsException: Index: 306, Size: 3 Serialization trace: sender (org.onosproject.store.primitives.impl.AntiEntropyAdvertisement) at com.esotericsoftware.kryo.serializers.ObjectField.read(ObjectField.java:144)[57:com.esotericsoftware.kryo:3.0.3] at com.esotericsoftware.kryo.serializers.FieldSerializer.read(FieldSerializer.java:551)[57:com.esotericsoftware.kryo:3.0.3] at com.esotericsoftware.kryo.Kryo.readClassAndObject(Kryo.java:790)[57:com.esotericsoftware.kryo:3.0.3] at org.onlab.util.KryoNamespace.deserialize(KryoNamespace.java:318)[72:org.onosproject.onlab-misc:1.6.0.SNAPSHOT] at org.onosproject.store.serializers.KryoSerializer.decode(KryoSerializer.java:57)[134:org.onosproject.onos-core-serializers:1.6.0.SNAPSHOT] at org.onosproject.store.cluster.messaging.impl.ClusterCommunicationManager$1.apply(ClusterCommunicationManager.java:278)[131:org.onosproject.onos-core-dist:1.6.0.SNAPSHOT] at org.onosproject.store.cluster.messaging.impl.ClusterCommunicationManager$InternalMessageResponder.apply(ClusterCommunicationManager.java:322)[131:org.onosproject.onos-core-dist:1.6.0.SNAPSHOT] at org.onosproject.store.cluster.messaging.impl.ClusterCommunicationManager$InternalMessageResponder.apply(ClusterCommunicationManager.java:306)[131:org.onosproject.onos-core-dist:1.6.0.SNAPSHOT] at org.onosproject.store.cluster.messaging.impl.NettyMessagingManager.lambda$registerHandler$7(NettyMessagingManager.java:300)[131:org.onosproject.onos-core-dist:1.6.0.SNAPSHOT] at org.onosproject.store.cluster.messaging.impl.NettyMessagingManager.dispatchLocally(NettyMessagingManager.java:532)[131:org.onosproject.onos-core-dist:1.6.0.SNAPSHOT] at org.onosproject.store.cluster.messaging.impl.NettyMessagingManager.access$900(NettyMessagingManager.java:93)[131:org.onosproject.onos-core-dist:1.6.0.SNAPSHOT] at org.onosproject.store.cluster.messaging.impl.NettyMessagingManager$InboundMessageDispatcher.channelRead0(NettyMessagingManager.java:488)[131:org.onosproject.onos-core-dist:1.6.0.SNAPSHOT] at org.onosproject.store.cluster.messaging.impl.NettyMessagingManager$InboundMessageDispatcher.channelRead0(NettyMessagingManager.java:482)[131:org.onosproject.onos-core-dist:1.6.0.SNAPSHOT] at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105)[47:io.netty.transport:4.0.33.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:318)[47:io.netty.transport:4.0.33.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:304)[47:io.netty.transport:4.0.33.Final] at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:276)[49:io.netty.codec:4.0.33.Final] at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:263)[49:io.netty.codec:4.0.33.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:318)[47:io.netty.transport:4.0.33.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:304)[47:io.netty.transport:4.0.33.Final] at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:846)[47:io.netty.transport:4.0.33.Final] at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:131)[47:io.netty.transport:4.0.33.Final] at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511)[47:io.netty.transport:4.0.33.Final] at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)[47:io.netty.transport:4.0.33.Final] at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)[47:io.netty.transport:4.0.33.Final] at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)[47:io.netty.transport:4.0.33.Final] at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112)[45:io.netty.common:4.0.33.Final] at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137)[45:io.netty.common:4.0.33.Final] at java.lang.Thread.run(Thread.java:745)[:1.8.0_72] Caused by: java.lang.IndexOutOfBoundsException: Index: 306, Size: 3 at java.util.ArrayList.rangeCheck(ArrayList.java:653)[:1.8.0_72] at java.util.ArrayList.get(ArrayList.java:429)[:1.8.0_72] at com.esotericsoftware.kryo.util.MapReferenceResolver.getReadObject(MapReferenceResolver.java:60)[57:com.esotericsoftware.kryo:3.0.3] at com.esotericsoftware.kryo.Kryo.readReferenceOrNull(Kryo.java:834)[57:com.esotericsoftware.kryo:3.0.3] at com.esotericsoftware.kryo.Kryo.readObjectOrNull(Kryo.java:757)[57:com.esotericsoftware.kryo:3.0.3] at com.esotericsoftware.kryo.serializers.ObjectField.read(ObjectField.java:132)[57:com.esotericsoftware.kryo:3.0.3] ... 28 more