Medium Overview: We configure odl with one neighbor ( internal, passive-mode:false ), first time I try to start peer with play.py, everything works as expected. But if I stop it, and start again, I see errors same as on jenkins tests.
This is probably happening whenever we reconnect peer to the same neighbor configuration, no matter if it's talking or not.
Steps to reproduce
- configure neighbor
./reconf_ibgp_simple_talking.py
- start listening peer with play.py
./startplay.sh
- then we can check fullrib, it should be working at this point.
- we restart the play.py, and errors should occur.
adding also logs from local test, and here are logs from releng test.
https://logs.opendaylight.org/releng/vex-yul-odl-jenkins-1/bgpcep-csit-1node-userfeatures-all-fluorine/58/odl1_karaf.log.gz
here is sandbox with just one test suite for simpler logs.
https://jenkins.opendaylight.org/sandbox/job/tomas-bgpcep-csit-1node-userfeatures-all-fluorine/10/
ERROR itself, but there is also warning before it which first sign of something going wrong.
2018-04-24T10:28:58,197 | ERROR | epollEventLoopGroup-5-5 | BGPDocumentedException | 220 - org.opendaylight.bgpcep.bgp-parser-api - 0.10.0.SNAPSHOT | Error = CEASE org.opendaylight.protocol.bgp.parser.BGPDocumentedException: null at org.opendaylight.protocol.bgp.rib.impl.BGPSessionImpl.handleException(BGPSessionImpl.java:486) [226:org.opendaylight.bgpcep.bgp-rib-impl:0.10.0.SNAPSHOT] at org.opendaylight.protocol.bgp.rib.impl.BGPSessionImpl.sessionUp(BGPSessionImpl.java:420) [226:org.opendaylight.bgpcep.bgp-rib-impl:0.10.0.SNAPSHOT] at org.opendaylight.protocol.bgp.rib.impl.BGPSessionImpl.handlerAdded(BGPSessionImpl.java:467) [226:org.opendaylight.bgpcep.bgp-rib-impl:0.10.0.SNAPSHOT] at io.netty.channel.DefaultChannelPipeline.callHandlerAdded0(DefaultChannelPipeline.java:617) [104:io.netty.transport:4.1.22.Final] at io.netty.channel.DefaultChannelPipeline.replace(DefaultChannelPipeline.java:577) [104:io.netty.transport:4.1.22.Final] at io.netty.channel.DefaultChannelPipeline.replace(DefaultChannelPipeline.java:514) [104:io.netty.transport:4.1.22.Final] at org.opendaylight.protocol.bgp.rib.impl.AbstractBGPSessionNegotiator.negotiationSuccessful(AbstractBGPSessionNegotiator.java:250) [226:org.opendaylight.bgpcep.bgp-rib-impl:0.10.0.SNAPSHOT] at org.opendaylight.protocol.bgp.rib.impl.AbstractBGPSessionNegotiator.handleMessage(AbstractBGPSessionNegotiator.java:163) [226:org.opendaylight.bgpcep.bgp-rib-impl:0.10.0.SNAPSHOT] at org.opendaylight.protocol.bgp.rib.impl.AbstractBGPSessionNegotiator.channelRead(AbstractBGPSessionNegotiator.java:286) [226:org.opendaylight.bgpcep.bgp-rib-impl:0.10.0.SNAPSHOT] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [104:io.netty.transport:4.1.22.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [104:io.netty.transport:4.1.22.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [104:io.netty.transport:4.1.22.Final] at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310) [99:io.netty.codec:4.1.22.Final] at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:284) [99:io.netty.codec:4.1.22.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [104:io.netty.transport:4.1.22.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [104:io.netty.transport:4.1.22.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [104:io.netty.transport:4.1.22.Final] at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310) [99:io.netty.codec:4.1.22.Final] at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:284) [99:io.netty.codec:4.1.22.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [104:io.netty.transport:4.1.22.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [104:io.netty.transport:4.1.22.Final] at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [104:io.netty.transport:4.1.22.Final] at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1414) [104:io.netty.transport:4.1.22.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [104:io.netty.transport:4.1.22.Final] at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [104:io.netty.transport:4.1.22.Final] at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:945) [104:io.netty.transport:4.1.22.Final] at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:806) [105:io.netty.transport-native-epoll:4.1.22.Final] at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:404) [105:io.netty.transport-native-epoll:4.1.22.Final] at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:304) [105:io.netty.transport-native-epoll:4.1.22.Final] at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:886) [101:io.netty.common:4.1.22.Final] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [101:io.netty.common:4.1.22.Final] at java.lang.Thread.run(Thread.java:748) [?:?] 2018-04-24T10:28:58,199 | INFO | epollEventLoopGroup-5-5 | BGPSessionImpl | 226 - org.opendaylight.bgpcep.bgp-rib-impl - 0.10.0.SNAPSHOT | Closing session: BGPSessionImpl{channel=[id: 0x398b23f0, L:/127.0.0.1:59978 - R:127.0.0.2/127.0.0.2:17900], state=UP} 2018-04-24T10:28:58,199 | INFO | epollEventLoopGroup-5-5 | BGPPeer | 226 - org.opendaylight.bgpcep.bgp-rib-impl - 0.10.0.SNAPSHOT | Session with peer 127.0.0.2 terminated: BGPTerminationReason{error=CEASE} 2018-04-24T10:28:58,200 | INFO | epollEventLoopGroup-5-5 | BGPPeer | 226 - org.opendaylight.bgpcep.bgp-rib-impl - 0.10.0.SNAPSHOT | Closing session with peer 2018-04-24T10:28:58,210 | INFO | epollEventLoopGroup-5-5 | AbstractPeer | 226 - org.opendaylight.bgpcep.bgp-rib-impl - 0.10.0.SNAPSHOT | AdjRibInWriter closed per Peer /(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2018-03-29)bgp-rib/rib/rib[{(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2018-03-29)id=example-bgp-rib}]/peer/peer[{(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2018-03-29)peer-id=bgp://127.0.0.2}] removed
