[BGPCEP-792] Listening peer reconnection Created: 24/Apr/18  Updated: 12/Jul/18  Resolved: 25/Apr/18

Status: Verified
Project: bgpcep
Component/s: BGP
Affects Version/s: Fluorine
Fix Version/s: Fluorine

Type: Bug Priority: Medium
Reporter: Tomas Markovic Assignee: Claudio David Gasparini
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File karaf.log     File play.py     File reconf_ibgp_simple_talking.py     File startplay.sh    

 Description   

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


 Comments   
Comment by Tomas Markovic [ 25/Apr/18 ]

looking good

https://jenkins.opendaylight.org/sandbox/job/tomas-bgpcep-csit-1node-userfeatures-all-fluorine/12/

Generated at Wed Feb 07 19:14:08 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.