[BGPCEP-211] "Transaction factory was closed" after BGP connection closed Created: 22/Apr/15  Updated: 03/Mar/19  Resolved: 08/Sep/15

Status: Resolved
Project: bgpcep
Component/s: BGP
Affects Version/s: Bugzilla Migration
Fix Version/s: Bugzilla Migration

Type: Bug
Reporter: Jozef Behran Assignee: Dana Kutenicsova
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Operating System: All
Platform: All


Attachments: Text File Logs.txt     File tools.tar.xz    
External issue ID: 3043

 Description   

Tested on Lithium, build http://nexus.opendaylight.org/content/repositories/opendaylight.snapshot/org/opendaylight/integration/distribution-karaf/0.3.0-SNAPSHOT/distribution-karaf-0.3.0-20150421.015145-1180.tar.gz

Steps to reproduce:

1. Prepare ODL: Change featuresBoot to contain only "odl-restconf" and "odl-bgpcep-bgp-all".
2. Place the file 41-bgp-example.xml from the attached archive into etc/opendaylight/karaf subdirectory of the ODL installation.
3. Boot ODL.
4. Wait for the empty topology to appear:
curl -u 'admin:admin' 127.0.0.2:8181/restconf/operational/network-topology:network-topology/topology/example-ipv4-topology >curl-000.out
(you should get a "curl-000.out" file that is around 100 bytes long)
5. Start the "play.py" tool from the archive:
python play.py --gencount=2
6. After the tool responds with "Sending completed", verify that the routes are in topology:
curl -u 'admin:admin' 127.0.0.2:8181/restconf/operational/network-topology:network-topology/topology/example-ipv4-topology >curl-001.out
(the file curl-001.out shall now be around 240 bytes long)
7. Go to the terminal window with the "play.py" tool and hit Ctrl-C to terminate it.
8. Verify that the topology is now empty:
curl -u 'admin:admin' 127.0.0.2:8181/restconf/operational/network-topology:network-topology/topology/example-ipv4-topology >curl-003.out
(you should get a "curl-003.out" file that is the same as "curl-000.out")
9. Start the "play.py" tool again:
python play.py --gencount=2
10. Look at the topology again:
curl -u 'admin:admin' 127.0.0.2:8181/restconf/operational/network-topology:network-topology/topology/example-ipv4-topology >curl-004.out
11. The "curl-004.out" produced with step 10 shall be the same as "curl-001.out" produced in step 6 but it is the same as "curl-000.out" and "curl-003.out" (i.e. empty) instead.
12. Looking into logs you will now see this exception (note the "Transaction factory was closed" message below):

2015-04-22 11:15:38,025 | WARN | oupCloseable-3-2 | DefaultChannelPipeline | 154 - io.netty.common - 4.0.26.Final | An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception.
io.netty.channel.ChannelPipelineException: org.opendaylight.protocol.bgp.rib.impl.BGPSessionImpl.handlerAdded() has thrown an exception; removed.
at io.netty.channel.DefaultChannelPipeline.callHandlerAdded0(DefaultChannelPipeline.java:501)[153:io.netty.transport:4.0.26.Final]
at io.netty.channel.DefaultChannelPipeline.callHandlerAdded(DefaultChannelPipeline.java:482)[153:io.netty.transport:4.0.26.Final]
at io.netty.channel.DefaultChannelPipeline.replace0(DefaultChannelPipeline.java:455)[153:io.netty.transport:4.0.26.Final]
at io.netty.channel.DefaultChannelPipeline.replace(DefaultChannelPipeline.java:405)[153:io.netty.transport:4.0.26.Final]
at io.netty.channel.DefaultChannelPipeline.replace(DefaultChannelPipeline.java:372)[153:io.netty.transport:4.0.26.Final]
at org.opendaylight.protocol.framework.AbstractSessionNegotiator.negotiationSuccessful(AbstractSessionNegotiator.java:46)[156:org.opendaylight.controller.protocol-framework:0.6.0.SNAPSHOT]
at org.opendaylight.protocol.bgp.rib.impl.AbstractBGPSessionNegotiator.handleMessage(AbstractBGPSessionNegotiator.java:147)[236:org.opendaylight.bgpcep.bgp-rib-impl:0.4.0.SNAPSHOT]
at org.opendaylight.protocol.bgp.rib.impl.AbstractBGPSessionNegotiator.handleMessage(AbstractBGPSessionNegotiator.java:42)[236:org.opendaylight.bgpcep.bgp-rib-impl:0.4.0.SNAPSHOT]
at org.opendaylight.protocol.framework.AbstractSessionNegotiator.channelRead(AbstractSessionNegotiator.java:93)[156:org.opendaylight.controller.protocol-framework:0.6.0.SNAPSHOT]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339)[153:io.netty.transport:4.0.26.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324)[153:io.netty.transport:4.0.26.Final]
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:242)[179:io.netty.codec:4.0.26.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339)[153:io.netty.transport:4.0.26.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324)[153:io.netty.transport:4.0.26.Final]
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:242)[179:io.netty.codec:4.0.26.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:339)[153:io.netty.transport:4.0.26.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:324)[153:io.netty.transport:4.0.26.Final]
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:847)[153:io.netty.transport:4.0.26.Final]
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:131)[153:io.netty.transport:4.0.26.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511)[153:io.netty.transport:4.0.26.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)[153:io.netty.transport:4.0.26.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)[153:io.netty.transport:4.0.26.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)[153:io.netty.transport:4.0.26.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:111)[154:io.netty.common:4.0.26.Final]
at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137)[154:io.netty.common:4.0.26.Final]
at java.lang.Thread.run(Thread.java:745)[:1.7.0_65]
Caused by: java.lang.IllegalStateException: Transaction factory was closed. No further operations allowed.
at com.google.common.base.Preconditions.checkState(Preconditions.java:173)[37:com.google.guava:18.0.0]
at org.opendaylight.controller.md.sal.dom.broker.impl.AbstractDOMForwardedTransactionFactory.checkNotClosed(AbstractDOMForwardedTransactionFactory.java:233)[192:org.opendaylight.controller.sal-broker-impl:1.2.0.SNAPSHOT]
at org.opendaylight.controller.md.sal.dom.broker.impl.AbstractDOMForwardedTransactionFactory.newWriteOnlyTransaction(AbstractDOMForwardedTransactionFactory.java:149)[192:org.opendaylight.controller.sal-broker-impl:1.2.0.SNAPSHOT]
at org.opendaylight.protocol.bgp.rib.impl.AdjRibInWriter.transform(AdjRibInWriter.java:127)[236:org.opendaylight.bgpcep.bgp-rib-impl:0.4.0.SNAPSHOT]
at org.opendaylight.protocol.bgp.rib.impl.BGPPeer.onSessionUp(BGPPeer.java:187)[236:org.opendaylight.bgpcep.bgp-rib-impl:0.4.0.SNAPSHOT]
at org.opendaylight.protocol.bgp.rib.impl.BGPPeer.onSessionUp(BGPPeer.java:65)[236:org.opendaylight.bgpcep.bgp-rib-impl:0.4.0.SNAPSHOT]
at org.opendaylight.protocol.bgp.rib.impl.BGPSessionImpl.sessionUp(BGPSessionImpl.java:368)[236:org.opendaylight.bgpcep.bgp-rib-impl:0.4.0.SNAPSHOT]
at org.opendaylight.protocol.framework.AbstractProtocolSession.handlerAdded(AbstractProtocolSession.java:58)[156:org.opendaylight.controller.protocol-framework:0.6.0.SNAPSHOT]
at io.netty.channel.DefaultChannelPipeline.callHandlerAdded0(DefaultChannelPipeline.java:488)[153:io.netty.transport:4.0.26.Final]
... 25 more



 Comments   
Comment by Jozef Behran [ 22/Apr/15 ]

Attachment tools.tar.xz has been added with description: Archive with tools necessary to replicate the problem

Comment by Jozef Behran [ 22/Apr/15 ]

Further experiments revealed

Comment by Jozef Behran [ 22/Apr/15 ]

Further experiments revealed additional behaviors of the bug:

1. It does not matter whether the CEASE/CLIENT DECONFIGURED/whatever NOTIFICATION message was received or not, as soon as the connection is closed, the BGP is dead.
2. If multiple clients connect, they will be able to push their updates without problems. But if ANY ONE of them disconnects, the BGP dies and no more updates will be received. If any of the additional clients which managed to get their updates through disconnects, its updates will be deleted correctly.
3. If a peer connection is closed due to missing KEEPALIVE, the BGP dies as well.

It seems to me that no matter how the connection dies, once a connection dies, the BGP dies with it.

Comment by Claudio David Gasparini [ 13/May/15 ]

Attachment Logs.txt has been added with description: Logs with log DEBUG level

Comment by Claudio David Gasparini [ 13/May/15 ]

Attached logs after reproduce the issue.
If Karaf is started on debug, it wont work even first steps.

Comment by Dana Kutenicsova [ 13/May/15 ]

https://git.opendaylight.org/gerrit/#/c/20249/
https://git.opendaylight.org/gerrit/20250

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