Re: [Ryu-devel] BGP session cannot established in Ryu

Tue, 10 Oct 2017 01:41:56 -0700 

Hi Fujimoto,
I do not start controllers exactly at the same time. This happens even when I start the other controller very late. 





From your log, I saw c1 sent a connection request to c2 and 
established the connection.

After that, c1 receives a connection request from c2.
I think this request was sent before the connection is established, right?

If we run the controller at the same time or really close in time to 
each other, the answer is yes. But this happened also when I run the 
second controller after a while.

If so, sending NOTIFICATION is valid operation.

It is specified to send the NOTIFICATION when it receives a connection 
request while the connection is established.

Actually, I tried to print the peering status and as you said the 
peering was established. Therefore, your claim is right.

API method operator.show called with args: {'params': ['neighbor', 
'summary', '20.0.2.1'], 'format': 'json'}

And this message indicates the valid BGP connection is still established.

So, BGP connection is not crashed. It just rejects the connection 
request after connection establishment.


According to peer status the BGP connection is not crashed.

One more report, in some experiments I found an error which states that 
*"Negotiated hold time 40 expired"*. What can cause this error? because 
in this circumstance the peering is crashed.

Thanks,
Habib



Thanks,
Fujimoto


On 2017年10月05日 22:27, Habib Mostafaei wrote:


Hi Fujimoto,

I used a dedicated machine for each node in the network with this 
topology:


     ____20.0.3.0/24_____ ____20.0.4.0/24____
    |                                     |              | |
c1----20.0.0.0/24----sw1----20.0.1.0/24----sw2----20.0.2.0/24----C2

  * Each controller is connected to the switch via two links, one is
    dedicated as the control channel for the switch and the other one
    to steer BGP traffic.
  * Each link belongs to a different subnet.

Enclosed you can find the BGP configuration file for each controller.

*Here is the log of Ryu with --verbose option:*
lzma module is not available
Registered VCS backend: git
Registered VCS backend: hg
Registered VCS backend: svn
Registered VCS backend: bzr
loading app mainBGP.py
Create CustomEvent called
loading app ryu.controller.ofp_handler
instantiating app ryu.controller.ofp_handler of OFPHandler
instantiating app mainBGP.py of mainBGP
Loading config file conf/bgp_conf_c1.py...

conf/bgp_conf_c1.py:1: RuntimeWarning: Parent module 
'bgpspeaker.application' not found while handling absolute import

  import os

conf/bgp_conf_c1.py:3: RuntimeWarning: Parent module 
'bgpspeaker.application' not found while handling absolute import

  from ryu.services.protocols.bgp.bgpspeaker import RF_VPN_V4
BRICK mainBGP
  CONSUMES EventOFPSwitchFeatures
  CONSUMES EventOFPPacketIn
BRICK ofp_event
  PROVIDES EventOFPSwitchFeatures TO {'mainBGP': set(['config'])}
  PROVIDES EventOFPPacketIn TO {'mainBGP': set(['main'])}
  CONSUMES EventOFPPortStatus
  CONSUMES EventOFPSwitchFeatures
  CONSUMES EventOFPPortDescStatsReply
  CONSUMES EventOFPErrorMsg
  CONSUMES EventOFPHello
  CONSUMES EventOFPEchoRequest
  CONSUMES EventOFPEchoReply

connected socket:<eventlet.greenio.base.GreenSocket object at 
0x7f2b6983ce90> address:('20.0.3.2', 57318)
hello ev <ryu.controller.ofp_event.EventOFPHello object at 
0x7f2b69852190>

move onto config mode
EVENT ofp_event->mainBGP EventOFPSwitchFeatures

switch features ev 
version=0x4,msg_type=0x6,msg_len=0x20,xid=0x9cc5d46b,OFPSwitchFeatures(auxiliary_id=0,capabilities=79,datapath_id=29143675633473,n_buffers=256,n_tables=254)

Starting BGPSpeaker...

API method core.start called with args: {'router_id': '20.0.0.1', 
'label_range': (100, 100000), 'waiter': <ryu.lib.hub.Event object at 
0x7f2b69852550>, 'bgp_server_port': 179, 'local_as': 1, 
'allow_local_as_in_count': 0, 'refresh_stalepath_time': 0, 
'cluster_id': None, 'refresh_max_eor_time': 0}

move onto main mode
Create CustomEvent called
Starting new processing run...
Processing RT NLRI destination...
Processing destination...
Adding neighbors...

Adding neighbor settings: {'remote_as': 2, 'enable_ipv6': True, 
'enable_ipv4': True, 'enable_vpnv6': True, 'enable_vpnv4': True, 
'address': '20.0.2.1'}
API method neighbor.create called with args: {'connect_mode': 'both', 
'cap_mbgp_evpn': False, 'remote_as': 2, 'cap_mbgp_vpnv6': True, 
'cap_four_octet_as_number': True, 'cap_mbgp_ipv6': True, 
'is_next_hop_self': False, 'cap_mbgp_ipv4': True, 'cap_mbgp_ipv4fs': 
False, 'is_route_reflector_client': False, 'is_route_server_client': 
False, 'cap_enhanced_refresh': False, 'peer_next_hop': None, 
'password': None, 'ip_address': '20.0.2.1', 'cap_mbgp_vpnv4fs': 
False, 'cap_mbgp_vpnv4': True}

Create CustomEvent called
Create CustomEvent called
Adding routes...
Adding route settings: {'prefix': '30.0.0.1/24'}
API method network.add called with args: {'prefix': '30.0.0.1/24'}

SIGNAL: ('core', 'dest', 'changed') emitted with data: 
Destination(table: Ipv4Table(scope_id: None, rf: 
RouteFamily(afi=1,safi=1)), nlri: 
IPAddrPrefix(addr='30.0.0.1',length=24), paths: 0, withdraws: 0, new 
paths: 1)

Started peer Peer(ip: 20.0.2.1, asn: 2)
start connect loop. (mode: both)
Starting new processing run...
Processing RT NLRI destination...
Processing destination...

Processing destination: Destination(table: Ipv4Table(scope_id: None, 
rf: RouteFamily(afi=1,safi=1)), nlri: 
IPAddrPrefix(addr='30.0.0.1',length=24), paths: 0, withdraws: 0, new 
paths: 1)

Removing 0 withdrawals

New best path selected for destination Destination(table: 
Ipv4Table(scope_id: None, rf: RouteFamily(afi=1,safi=1)), nlri: 
IPAddrPrefix(addr='30.0.0.1',length=24), paths: 1, withdraws: 0, new 
paths: 0)

Peer Peer(ip: 20.0.2.1, asn: 2) asked to communicate path

Skipping sending path as peer is not in ESTABLISHED state 
Path(source: None, nlri: IPAddrPrefix(addr='30.0.0.1',length=24), 
source ver#: 1, path attrs.: OrderedDict([(1, 
BGPPathAttributeOrigin(flags=0,length=None,type=1,value=0)), (2, 
BGPPathAttributeAsPath(flags=0,length=None,type=2,value=[[]]))]), 
nexthop: 0.0.0.0, is_withdraw: False)
SIGNAL: ('core', 'best', 'changed') emitted with data: {'path': 
Path(None, IPAddrPrefix(addr='30.0.0.1',length=24), 1, 
OrderedDict([(1, 
BGPPathAttributeOrigin(flags=0,length=None,type=1,value=0)), (2, 
BGPPathAttributeAsPath(flags=0,length=None,type=2,value=[[]]))]), 
0.0.0.0, False), 'is_withdraw': False}

EVENT ofp_event->mainBGP EventOFPPacketIn
Peer 20.0.2.1 BGP FSM went from Idle to Connect
Peer(ip: 20.0.2.1, asn: 2) trying to connect to ('20.0.2.1', 179)
Connect TCP called for 20.0.2.1:179
EVENT ofp_event->mainBGP EventOFPPacketIn
Peer 20.0.2.1 BGP FSM went from Connect to OpenSent

Sent msg to ('20.0.2.1', '179') >> 
BGPOpen(bgp_identifier='20.0.0.1',hold_time=40,len=73,my_as=1,opt_param=[BGPOptParamCapabilityMultiprotocol(afi=1,cap_code=1,cap_length=4,length=6,reserved=0,safi=1,type=2), 
BGPOptParamCapabilityMultiprotocol(afi=2,cap_code=1,cap_length=4,length=6,reserved=0,safi=1,type=2), 
BGPOptParamCapabilityMultiprotocol(afi=1,cap_code=1,cap_length=4,length=6,reserved=0,safi=128,type=2), 
BGPOptParamCapabilityMultiprotocol(afi=2,cap_code=1,cap_length=4,length=6,reserved=0,safi=128,type=2), 
BGPOptParamCapabilityRouteRefresh(cap_code=2,cap_length=0,length=2,type=2), 
BGPOptParamCapabilityFourOctetAsNumber(as_number=1,cap_code=65,cap_length=4,length=6,type=2)],opt_param_len=44,type=1,version=4)

Connection to peer: 20.0.2.1 established

Received msg from ('20.0.2.1', '179') << 
BGPOpen(bgp_identifier='20.0.2.1',hold_time=40,len=73,my_as=2,opt_param=[BGPOptParamCapabilityMultiprotocol(afi=1,cap_code=1,cap_length=4,length=6,reserved=0,safi=1,type=2), 
BGPOptParamCapabilityMultiprotocol(afi=2,cap_code=1,cap_length=4,length=6,reserved=0,safi=1,type=2), 
BGPOptParamCapabilityMultiprotocol(afi=1,cap_code=1,cap_length=4,length=6,reserved=0,safi=128,type=2), 
BGPOptParamCapabilityMultiprotocol(afi=2,cap_code=1,cap_length=4,length=6,reserved=0,safi=128,type=2), 
BGPOptParamCapabilityRouteRefresh(cap_code=2,cap_length=0,length=2,type=2), 
BGPOptParamCapabilityFourOctetAsNumber(as_number=2,cap_code=65,cap_length=4,length=6,type=2)],opt_param_len=44,type=1,version=4)

Peer 20.0.2.1 BGP FSM went from OpenSent to OpenConfirm

Trying to bind protocol 
<ryu.services.protocols.bgp.speaker.BgpProtocol object at 
0x7f2b69852410> to peer Peer(ip: 20.0.2.1, asn: 2)

Connect retry event for Peer(ip: 20.0.2.1, asn: 2) is cleared
Started keep-alive and expire timer for negotiated holdtime 40
Sent msg to ('20.0.2.1', '179') >> BGPKeepAlive(len=19,type=4)
Received msg from ('20.0.2.1', '179') << BGPKeepAlive(len=19,type=4)

SIGNAL: ('core', 'adj', 'up') emitted with data: {'peer': 
<ryu.services.protocols.bgp.peer.Peer object at 0x7f2b697a5fd0>}

Peer 20.0.2.1 BGP FSM went from OpenConfirm to Established
Communicating current best path for all afi/safi except 1/132
Peer Peer(ip: 20.0.2.1, asn: 2) asked to communicate path

SIGNAL: ('core', 'adj', 'rib', 'out', 'changed') emitted with data: 
{'peer': <ryu.services.protocols.bgp.peer.Peer object at 
0x7f2b697a5fd0>, 'sent_route': 
<ryu.services.protocols.bgp.model.SentRoute object at 0x7f2b697c4f10>}
Sent msg to ('20.0.2.1', '179') >> 
BGPUpdate(len=47,nlri=[IPAddrPrefix(addr='30.0.0.0',length=24)],path_attributes=[BGPPathAttributeNextHop(flags=64,length=4,type=3,value='20.0.0.1'), 
BGPPathAttributeOrigin(flags=64,length=1,type=1,value=0), 
BGPPathAttributeAsPath(flags=64,length=6,type=2,value=[[1]])],total_path_attribute_len=20,type=2,withdrawn_routes=[],withdrawn_routes_len=0)
Received msg from ('20.0.2.1', '179') << 
BGPUpdate(len=47,nlri=[BGPNLRI(addr='20.0.1.0',length=24)],path_attributes=[BGPPathAttributeNextHop(flags=64,length=4,type=3,value='20.0.2.1'), 
BGPPathAttributeOrigin(flags=64,length=1,type=1,value=0), 
BGPPathAttributeAsPath(flags=64,length=6,type=2,value=[[2]])],total_path_attribute_len=20,type=2,withdrawn_routes=[],withdrawn_routes_len=0)

NLRI: BGPNLRI(addr='20.0.1.0',length=24)

Extracted paths from Update msg.: Path(source: Peer(ip: 20.0.2.1, 
asn: 2), nlri: BGPNLRI(addr='20.0.1.0',length=24), source ver#: 1, 
path attrs.: {1: 
BGPPathAttributeOrigin(flags=64,length=1,type=1,value=0), 2: 
BGPPathAttributeAsPath(flags=64,length=6,type=2,value=[[2]]), 3: 
BGPPathAttributeNextHop(flags=64,length=4,type=3,value='20.0.2.1')}, 
nexthop: 20.0.2.1, is_withdraw: False)
SIGNAL: ('core', 'adj', 'rib', 'in', 'changed') emitted with data: 
{'peer': <ryu.services.protocols.bgp.peer.Peer object at 
0x7f2b697a5fd0>, 'received_route': 
<ryu.services.protocols.bgp.model.ReceivedRoute object at 
0x7f2b697745d0>}
SIGNAL: ('core', 'dest', 'changed') emitted with data: 
Destination(table: Ipv4Table(scope_id: None, rf: 
RouteFamily(afi=1,safi=1)), nlri: BGPNLRI(addr='20.0.1.0',length=24), 
paths: 0, withdraws: 0, new paths: 1)

Starting new processing run...
Processing RT NLRI destination...
Processing destination...

Processing destination: Destination(table: Ipv4Table(scope_id: None, 
rf: RouteFamily(afi=1,safi=1)), nlri: 
BGPNLRI(addr='20.0.1.0',length=24), paths: 0, withdraws: 0, new paths: 1)

Removing 0 withdrawals

New best path selected for destination Destination(table: 
Ipv4Table(scope_id: None, rf: RouteFamily(afi=1,safi=1)), nlri: 
BGPNLRI(addr='20.0.1.0',length=24), paths: 1, withdraws: 0, new paths: 0)

Peer Peer(ip: 20.0.2.1, asn: 2) asked to communicate path
Skipping sending path as AS_PATH has peer AS 2

SIGNAL: ('core', 'best', 'changed') emitted with data: {'path': 
Path(Peer(ip: 20.0.2.1, asn: 2), BGPNLRI(addr='20.0.1.0',length=24), 
1, {1: BGPPathAttributeOrigin(flags=64,length=1,type=1,value=0), 2: 
BGPPathAttributeAsPath(flags=64,length=6,type=2,value=[[2]]), 3: 
BGPPathAttributeNextHop(flags=64,length=4,type=3,value='20.0.2.1')}, 
20.0.2.1, False), 'is_withdraw': False}

Connect request received from client for port 20.0.2.1:58592

Closing connection to 20.0.2.1:58592 as we have connection in state 
other than IDLE or ACTIVE, i.e. connection resolution
SIGNAL: ('error', 'bgp', None) emitted with data: {'peer': None, 
'subcode': 7, 'code': 6, 'reason': 'Cease: Connection Collision 
Resolution'}
Sent notification to ('20.0.0.1', '179') >> 
BGPNotification(data='',error_code=6,error_subcode=7,len=21,type=3)

EVENT ofp_event->mainBGP EventOFPPacketIn
EVENT ofp_event->mainBGP EventOFPPacketIn
EVENT ofp_event->mainBGP EventOFPPacketIn
EVENT ofp_event->mainBGP EventOFPPacketIn
EVENT ofp_event->mainBGP EventOFPPacketIn
EVENT ofp_event->mainBGP EventOFPPacketIn

API method operator.show called with args: {'params': ['neighbor', 
'summary', '20.0.2.1'], 'format': 'json'}
API method operator.show called with args: {'params': ['neighbor', 
'summary', '20.0.2.1'], 'format': 'json'}
API method operator.show called with args: {'params': ['neighbor', 
'summary', '20.0.2.1'], 'format': 'json'}
API method operator.show called with args: {'params': ['neighbor', 
'summary', '20.0.2.1'], 'format': 'json'}
API method operator.show called with args: {'params': ['neighbor', 
'summary', '20.0.2.1'], 'format': 'json'}
API method operator.show called with args: {'params': ['neighbor', 
'summary', '20.0.2.1'], 'format': 'json'}

Keyboard Interrupt received. Closing RYU application manager...


Best regards,

Habib


On 10/5/2017 4:03 AM, Fujimoto Satoshi wrote:

Hi, Habib

Umm, I couldn't reproduce the issue you see...

More informations will be needed.
Could you give some informations like the followings?

* Your detailed network topology

   (including whether your controllers and switches are in the same 
host or not)

* Log message of Ryu with '--verbose' option
* Your bgp-app-config-files

Thanks,
Fujimoto


On 2017年10月04日 18:23, Habib Mostafaei wrote:


Hi Fujimot,


I checked the source and destinations on Open Message and they were 
different. I put the full interaction between controllers before 
crashing the peering here.



09:12:59.513039 IP 20.0.2.1.45766 > 20.0.0.1.179: Flags [S], seq 
3337738282, win 29200, options [mss 1460,sackOK,TS val 3323265941 
ecr 0,nop,wscale 7], length 0
09:13:00.530207 IP 20.0.2.1.45766 > 20.0.0.1.179: Flags [S], seq 
3337738282, win 29200, options [mss 1460,sackOK,TS val 3323266196 
ecr 0,nop,wscale 7], length 0
09:13:02.546189 IP 20.0.2.1.45766 > 20.0.0.1.179: Flags [S], seq 
3337738282, win 29200, options [mss 1460,sackOK,TS val 3323266700 
ecr 0,nop,wscale 7], length 0

09:13:04.530089 ARP, Request who-has 20.0.2.3 tell 20.0.2.1, length 28
09:13:04.551988 ARP, Reply 20.0.2.3 is-at 02:42:ac:14:00:02, length 46

09:13:05.810546 IP 20.0.0.1.48904 > 20.0.2.1.179: Flags [S], seq 
2385777952, win 29200, options [mss 1460,sackOK,TS val 2983019486 
ecr 0,nop,wscale 7], length 0
09:13:05.810650 IP 20.0.2.1.179 > 20.0.0.1.48904: Flags [S.], seq 
2978601207, ack 2385777953, win 28960, options [mss 1460,sackOK,TS 
val 3323267516 ecr 2983019486,nop,wscale 7], length 0
09:13:05.811551 IP 20.0.0.1.48904 > 20.0.2.1.179: Flags [.], ack 1, 
win 229, options [nop,nop,TS val 2983019486 ecr 3323267516], length 0
09:13:05.819879 IP 20.0.2.1.179 > 20.0.0.1.48904: Flags [P.], seq 
1:74, ack 1, win 227, options [nop,nop,TS val 3323267518 ecr 
2983019486], length 73: BGP
09:13:05.820030 IP 20.0.0.1.48904 > 20.0.2.1.179: Flags [.], ack 
74, win 229, options [nop,nop,TS val 2983019488 ecr 3323267518], 
length 0
09:13:05.821175 IP 20.0.0.1.48904 > 20.0.2.1.179: Flags [P.], seq 
1:74, ack 74, win 229, options [nop,nop,TS val 2983019488 ecr 
3323267518], length 73: BGP
09:13:05.824110 IP 20.0.2.1.179 > 20.0.0.1.48904: Flags [.], ack 
74, win 227, options [nop,nop,TS val 3323267519 ecr 2983019488], 
length 0
09:13:05.832021 IP 20.0.0.1.48904 > 20.0.2.1.179: Flags [P.], seq 
74:93, ack 74, win 229, options [nop,nop,TS val 2983019491 ecr 
3323267519], length 19: BGP
09:13:05.832056 IP 20.0.2.1.179 > 20.0.0.1.48904: Flags [.], ack 
93, win 227, options [nop,nop,TS val 3323267521 ecr 2983019491], 
length 0
09:13:05.839841 IP 20.0.2.1.179 > 20.0.0.1.48904: Flags [P.], seq 
74:93, ack 93, win 227, options [nop,nop,TS val 3323267523 ecr 
2983019491], length 19: BGP
09:13:05.845671 IP 20.0.0.1.48904 > 20.0.2.1.179: Flags [P.], seq 
93:140, ack 93, win 229, options [nop,nop,TS val 2983019494 ecr 
3323267523], length 47: BGP
09:13:05.859928 IP 20.0.2.1.179 > 20.0.0.1.48904: Flags [P.], seq 
93:140, ack 140, win 227, options [nop,nop,TS val 3323267528 ecr 
2983019494], length 47: BGP
09:13:05.901944 IP 20.0.0.1.48904 > 20.0.2.1.179: Flags [.], ack 
140, win 229, options [nop,nop,TS val 2983019509 ecr 3323267528], 
length 0
*09:13:06.578254 IP 20.0.2.1.45766 > 20.0.0.1.179: Flags [S], seq 
3337738282, win 29200, options [mss 1460,sackOK,TS val 3323267708 
ecr 0,nop,wscale 7], length 0**
**09:13:06.579726 IP 20.0.0.1.179 > 20.0.2.1.45766: Flags [S.], seq 
2970304277, ack 3337738283, win 28960, options [mss 1460,sackOK,TS 
val 2983019678 ecr 3323267708,nop,wscale 7], length 0*



The last two interactions show the crash between controllers and in 
controller CLI I have:



Sent notification to ('20.0.2.1', '45766') >> 
BGPNotification(data='',error_code=6,error_subcode=7,len=21,type=3)


while on the other controller I have this error as below;


Sent notification to ('20.0.0.1', '179') >> 
BGPNotification(data='',error_code=6,error_subcode=7,len=21,type=3)


These two interactions align with my settings.

Best regards,

Habib


On 10/4/2017 2:17 AM, Fujimoto Satoshi wrote:

same source and destination address



------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org!http://sdm.link/slashdot


_______________________________________________
Ryu-devel mailing list
Ryu-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/ryu-devel



--
Office DIA-214
Department of Engineering
Roma Tre University
Via della Vasca Navale, 79
00146, Rome, Italy
Phone: +39-06-57333215
Fax: +39-06-57333612


------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org!http://sdm.link/slashdot


_______________________________________________
Ryu-devel mailing list
Ryu-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/ryu-devel



--
Office DIA-214
Department of Engineering
Roma Tre University
Via della Vasca Navale, 79
00146, Rome, Italy
Phone: +39-06-57333215
Fax: +39-06-57333612


------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
Ryu-devel mailing list
Ryu-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/ryu-devel






















					Reply via email to