[OVSDB-316] OVSDB server doesn't close connection after peer is power down Created: 13/Mar/16  Updated: 30/Oct/17  Resolved: 27/May/16

Status: Resolved
Project: ovsdb
Component/s: Library
Affects Version/s: unspecified
Fix Version/s: None

Type: Bug
Reporter: Hsin-Yi Shen Assignee: Vishal Thapar
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Operating System: All
Platform: All


External issue ID: 5506

 Description   

In passive connection scenario, OVSDB connection is not closed on server side when peer is down before it has chance to send TCP FIN packet. We have seen this issue when peer is power off or crashed.



 Comments   
Comment by Sam Hague [ 15/Mar/16 ]

master: https://git.opendaylight.org/gerrit/35436
beryllium: https://git.opendaylight.org/gerrit/36152

The main issue with the bug has been fixed. I think we should close this bug and open another to track the open item for configuration.

Comment by Vishal Thapar [ 26/May/16 ]

Re-opening the bug as fix is not complete.

https://git.opendaylight.org/gerrit/#/c/36152/ added code to detect when a peer goes down without sending a FIN. However, it only did it for switch initiated connection. In case of ODL initiated connection we are unable to detect peer being down and reconciliation is never triggered.

Comment by Vishal Thapar [ 26/May/16 ]

Logs with the fix in place:

2016-05-26 16:29:39,075 | TRACE | entLoopGroup-8-1 | JsonRpcEndpoint | 168 - org.opendaylight.ovsdb.library - 1.2.4.SNAPSHOT | Request : null "update" ["b738c559-fd98-4251-9d6d-04bffd76e9ad",{"Manager":{"f1e4c461-19f3-4755-9cc1-38b5e9b9dcd6":{"new":

{"_version":["uuid","a77a7a32-0a3d-4fb4-84a0-9f1350e24f46"],"connection_mode":["set",[]],"is_connected":true,"other_config":["map",[]],"external_ids":["map",[]],"status":["map",[["bound_port","6640"],["sec_since_connect","5"],["state","ACTIVE"]]],"_uuid":["uuid","f1e4c461-19f3-4755-9cc1-38b5e9b9dcd6"],"target":"ptcp:6640","inactivity_probe":["set",[]],"max_backoff":["set",[]]}

,"old":{"_version":["uuid","23525c95-63de-4bea-a2d4-bafa4853034d"],"status":["map",[["bound_port","6640"],["sec_since_connect","0"],["state","ACTIVE"]]]}}}}]

After this log entry I bring down the interface on OVS.

2016-05-26 16:30:39,087 | DEBUG | entLoopGroup-8-1 | ExceptionHandler | 168 - org.opendaylight.ovsdb.library - 1.2.4.SNAPSHOT | Get idle state event
2016-05-26 16:30:39,087 | DEBUG | entLoopGroup-8-1 | ExceptionHandler | 168 - org.opendaylight.ovsdb.library - 1.2.4.SNAPSHOT | Reader idle state. Send echo message to peer
2016-05-26 16:30:39,087 | TRACE | entLoopGroup-8-1 | JsonRpcEndpoint | 168 - org.opendaylight.ovsdb.library - 1.2.4.SNAPSHOT | getClient Request :

{"id":"46b0eba4-3429-4a85-854f-f4c0136e75da","method":"echo","params":[]}

2016-05-26 16:30:57,991 | INFO | entLoopGroup-8-1 | OvsdbConnectionService | 168 - org.opendaylight.ovsdb.library - 1.2.4.SNAPSHOT | Connection closed ConnectionInfo [Remote-address=192.168.56.111, Remote-port=6640, Local-address192.168.56.1, Local-port=58166, type=ACTIVE]
2016-05-26 16:30:57,992 | INFO | entLoopGroup-8-1 | OvsdbConnectionManager | 174 - org.opendaylight.ovsdb.southbound-impl - 1.2.4.SNAPSHOT | Library disconnected ACTIVE from /192.168.56.111:6640 to /192.168.56.1:58166. Cleaning up the operational data store
2016-05-26 16:30:57,995 | INFO | entLoopGroup-8-1 | OvsdbConnectionManager | 174 - org.opendaylight.ovsdb.southbound-impl - 1.2.4.SNAPSHOT | Disconnected/Failed connection ConnectionInfo{getRemoteIp=IpAddress [_ipv4Address=Ipv4Address [_value=192.168.56.111], _value=[1, 9, 2, ., 1, 6, 8, ., 5, 6, ., 1, 1, 1]], getRemotePort=PortNumber [_value=6640], augmentations={}} was controller initiated, attempting reconnection
2016-05-26 16:30:57,998 | INFO | ult-dispatcher-3 | OvsdbConnectionManager | 174 - org.opendaylight.ovsdb.southbound-impl - 1.2.4.SNAPSHOT | Entity{type='ovsdb', id=/(urn:TBD:params:xml:ns:yang:network-topology?revision=2013-10-21)network-topology/topology/topology[

{(urn:TBD:params:xml:ns:yang:network-topology?revision=2013-10-21)topology-id=ovsdb:1}

]/node/node[

{(urn:TBD:params:xml:ns:yang:network-topology?revision=2013-10-21)node-id=ovsdb://192.168.56.111:6640}

]} has no owner, cleaning up the operational data store
2016-05-26 16:30:57,999 | TRACE | entLoopGroup-8-1 | JsonRpcDecoder | 168 - org.opendaylight.ovsdb.library - 1.2.4.SNAPSHOT | readable bytes 0, records read 8, incomplete record bytes 0
2016-05-26 16:30:58,000 | INFO | sdb-reconciler-1 | ConnectionReconciliationTask | 174 - org.opendaylight.ovsdb.southbound-impl - 1.2.4.SNAPSHOT | Retry(1) connection to Ovsdb Node ConnectionInfo{getRemoteIp=IpAddress [_ipv4Address=Ipv4Address [_value=192.168.56.111], _value=[1, 9, 2, ., 1, 6, 8, ., 5, 6, ., 1, 1, 1]], getRemotePort=PortNumber [_value=6640], augmentations={}}
2016-05-26 16:30:58,001 | INFO | sdb-reconciler-1 | OvsdbConnectionManager | 174 - org.opendaylight.ovsdb.southbound-impl - 1.2.4.SNAPSHOT | Connecting to 192.168.56.111:6640
2016-05-26 16:31:19,025 | WARN | sdb-reconciler-1 | OvsdbConnectionService | 168 - org.opendaylight.ovsdb.library - 1.2.4.SNAPSHOT | bootstrap.connect failed
java.net.ConnectException: Connection timed out: no further information: /192.168.56.111:6640
at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)[:1.8.0_60]
at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)[:1.8.0_60]
at io.netty.channel.socket.nio.NioSocketChannel.doFinishConnect(NioSocketChannel.java:224)[125:io.netty.transport:4.0.33.Final]
at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:289)[125:io.netty.transport:4.0.33.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:528)[125:io.netty.transport:4.0.33.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)[125:io.netty.transport:4.0.33.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)[125:io.netty.transport:4.0.33.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)[125:io.netty.transport:4.0.33.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112)[124:io.netty.common:4.0.33.Final]
at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137)[124:io.netty.common:4.0.33.Final]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_60]
2016-05-26 16:31:19,028 | WARN | sdb-reconciler-1 | OvsdbConnectionManager | 174 - org.opendaylight.ovsdb.southbound-impl - 1.2.4.SNAPSHOT | Failed to connect to OVSDB Node ConnectionInfo{getRemoteIp=IpAddress [_ipv4Address=Ipv4Address [_value=192.168.56.111], _value=[1, 9, 2, ., 1, 6, 8, ., 5, 6, ., 1, 1, 1]], getRemotePort=PortNumber [_value=6640], augmentations={}}
2016-05-26 16:31:19,028 | WARN | sdb-reconciler-1 | ConnectionReconciliationTask | 174 - org.opendaylight.ovsdb.southbound-impl - 1.2.4.SNAPSHOT | Connection retry(1) failed for ConnectionInfo{getRemoteIp=IpAddress [_ipv4Address=Ipv4Address [_value=192.168.56.111], _value=[1, 9, 2, ., 1, 6, 8, ., 5, 6, ., 1, 1, 1]], getRemotePort=PortNumber [_value=6640], augmentations={}}.
2016-05-26 16:31:29,029 | INFO | sdb-reconciler-1 | ConnectionReconciliationTask | 174 - org.opendaylight.ovsdb.southbound-impl - 1.2.4.SNAPSHOT | Retry(2) connection to Ovsdb Node ConnectionInfo{getRemoteIp=IpAddress [_ipv4Address=Ipv4Address [_value=192.168.56.111], _value=[1, 9, 2, ., 1, 6, 8, ., 5, 6, ., 1, 1, 1]], getRemotePort=PortNumber [_value=6640], augmentations={}}

Also, in this case we never hit the readTimeOutException because reconciliation logic has already torn down the connection.

Comment by Vishal Thapar [ 26/May/16 ]

stable/beryllium: https://git.opendaylight.org/gerrit/39477

Comment by Vishal Thapar [ 27/May/16 ]

(In reply to Vishal Thapar from comment #4)
> stable/beryllium: https://git.opendaylight.org/gerrit/39477

Boron: https://git.opendaylight.org/gerrit/#/c/39511/

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