Hi

I’ve tested  again after adapting the following patch code .
But, this issue has not resolved now .
-> I’m not sure why RPC has disconnected between Ryu-cli and 
NetworkController(net_ctrl) ,after receiving reset_neighbor .

diff --git a/ryu/services/protocols/bgp/speaker.py 
b/ryu/services/protocols/bgp/speaker.py
index 2c823f5..cfa8be7 100644
--- a/ryu/services/protocols/bgp/speaker.py
+++ b/ryu/services/protocols/bgp/speaker.py
@@ -371,8 +371,8 @@ class BgpProtocol(Protocol, Activity):
         reason = notification.reason
         self._send_with_lock(notification)
         self._signal_bus.bgp_error(self._peer, code, subcode, reason)
-        if len(self._localname()):
-            LOG.error('Sent notification to %r >> %s' % (self._localname(),
+        if len(self._localname):
+            LOG.error('Sent notification to %r >> %s' % (self._localname,
                                                          notification))
         self._socket.close()


I hope this report is useful for resolving the issue .
Best regards.

Toshiki Tsuboi


—---- test result as following ---------

(1) starting My sampleApp ( changes log level from info to debug )

$ sudo ./start_RyuBGPSpeaker.sh 

…(snip)

DEBUG 2014-07-27 17:04:10,345 speaker 447 Received msg from ('192.168.100.100', 
'179') << 
BGPKeepAlive(len=19,marker='\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff',type=4)
DEBUG 2014-07-27 17:04:10,346 speaker 447 Received msg from ('192.168.100.100', 
'179') << 
BGPKeepAlive(len=19,marker='\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff',type=4)
DEBUG 2014-07-27 17:04:19,174 base 345 Connect request received from client for 
port 127.0.0.1:42502
CRITICAL 2014-07-27 17:04:19,185 net_ctrl 121 RPC Session to ('127.0.0.1', 
42502) started
DEBUG 2014-07-27 17:04:19,185 net_ctrl 199 NetworkController processing 
outgoing request list.
DEBUG 2014-07-27 17:04:19,186 net_ctrl 166 NetworkController started processing 
incoming messages
DEBUG 2014-07-27 17:04:19,186 net_ctrl 373 Request from NetworkController<<: 
core.reset_neighbor [{'ip_address': '192.168.100.100'}]
INFO 2014-07-27 17:04:19,187 base 207 API method core.reset_neighbor called 
with args: {'ip_address': '192.168.100.100'}
DEBUG 2014-07-27 17:04:19,187 peer 415 Peer Peer(ip: 192.168.100.100, asn: 
64511) configuration update event, enabled: False.
DEBUG 2014-07-27 17:04:19,188 base 11 SIGNAL: ('error', 'bgp', 
<ryu.services.protocols.bgp.peer.Peer object at 0x7fc120a6c750>) emited with 
data: {'peer': <ryu.services.protocols.bgp.peer.Peer object at 0x7fc120a6c750>, 
'subcode': 2, 'code': 6, 'reason': 'Cease: Administrative Shutdown'} 
ERROR 2014-07-27 17:04:19,188 speaker 376 Sent notification to 
('192.168.100.102', '59501') >> 
BGPNotification(data='',error_code=6,error_subcode=2,len=21,marker='\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff',type=3)
DEBUG 2014-07-27 17:04:19,189 base 305 Stopping activity BgpProtocol True, 
('192.168.100.100', '179'), ('192.168.100.102', '59501').
DEBUG 2014-07-27 17:04:19,189 base 291 BgpProtocol True, ('192.168.100.100', 
'179'), ('192.168.100.102', '59501'): Stopping timer Holdtime Timer
DEBUG 2014-07-27 17:04:19,189 base 291 BgpProtocol True, ('192.168.100.100', 
'179'), ('192.168.100.102', '59501'): Stopping timer Keepalive Timer
DEBUG 2014-07-27 17:04:19,190 base 285 BgpProtocol True, ('192.168.100.100', 
'179'), ('192.168.100.102', '59501'): Closing socket passive_conn - 
<eventlet.greenio.GreenSocket object at 0x7fc120a8a550>
DEBUG 2014-07-27 17:04:19,190 base 317 Stopping activity BgpProtocol True, 
('192.168.100.100', '179'), ('192.168.100.102', '59501') finished.
DEBUG 2014-07-27 17:04:19,191 peer 439 Disabling connect-retry as neighbor was 
disabled (True)
DEBUG 2014-07-27 17:04:19,774 base 345 Connect request received from client for 
port 127.0.0.1:42503
DEBUG 2014-07-27 17:04:19,775 base 305 Stopping activity UnknownActivity: 
1406448259.17.
DEBUG 2014-07-27 17:04:19,776 base 276 UnknownActivity: 1406448259.17: Stopping 
child thread net_ctrl._process_outgoing
DEBUG 2014-07-27 17:04:19,776 base 276 UnknownActivity: 1406448259.17: Stopping 
child thread net_ctrl._process_incoming
DEBUG 2014-07-27 17:04:19,776 base 317 Stopping activity UnknownActivity: 
1406448259.17 finished.
CRITICAL 2014-07-27 17:04:19,777 net_ctrl 109 RPC Session to ('127.0.0.1', 
42502) stopped
CRITICAL 2014-07-27 17:04:19,777 net_ctrl 121 RPC Session to ('127.0.0.1', 
42503) started
DEBUG 2014-07-27 17:04:19,778 net_ctrl 199 NetworkController processing 
outgoing request list.
DEBUG 2014-07-27 17:04:19,779 net_ctrl 166 NetworkController started processing 
incoming messages
DEBUG 2014-07-27 17:04:19,779 net_ctrl 373 Request from NetworkController<<: 
core.reset_neighbor [{'ip_address': '192.168.100.100'}]
INFO 2014-07-27 17:04:19,780 base 207 API method core.reset_neighbor called 
with args: {'ip_address': '192.168.100.100'}
ERROR 2014-07-27 17:04:19,783 base 222 Traceback (most recent call last):
  File 
"/usr/local/lib/python2.7/dist-packages/ryu/services/protocols/bgp/api/base.py",
 line 220, in call
    return call(**kwargs)
  File 
"/usr/local/lib/python2.7/dist-packages/ryu/services/protocols/bgp/api/core.py",
 line 79, in reset_neighor
    ' reset.' % ip_address)
RuntimeConfigError: 200.1 - Neighbor 192.168.100.100 is not enabled, hence 
cannot reset.

ERROR 2014-07-27 17:04:19,790 hub 60 hub: uncaught exception: Traceback (most 
recent call last):
  File "/usr/local/lib/python2.7/dist-packages/ryu/lib/hub.py", line 52, in 
_launch
    func(*args, **kwargs)
  File 
"/usr/local/lib/python2.7/dist-packages/ryu/services/protocols/bgp/net_ctrl.py",
 line 171, in _process_incoming_msgs
    msg_buff = self._recv()
  File 
"/usr/local/lib/python2.7/dist-packages/ryu/services/protocols/bgp/net_ctrl.py",
 line 222, in _recv
    return self._sock_wrap(self._socket.recv)(RPC_SOCK_BUFF_SIZE)
  File 
"/usr/local/lib/python2.7/dist-packages/ryu/services/protocols/bgp/net_ctrl.py",
 line 230, in wrapper
    ret = func(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/eventlet/greenio.py", line 264, 
in recv
    timeout_exc=socket.timeout("timed out"))
  File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/__init__.py", line 
151, in trampoline
    listener = hub.add(hub.READ, fileno, current.switch)
  File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/epolls.py", line 
48, in add
    listener = BaseHub.add(self, evtype, fileno, cb)
  File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/hub.py", line 126, 
in add
    evtype, fileno, evtype))
RuntimeError: Second simultaneous read on fileno 11 detected.  Unless you 
really know what you're doing, make sure that only one greenthread can read any 
particular socket.  Consider using a pools.Pool. If you do know what you're 
doing and want to disable this error, call 
eventlet.debug.hub_prevent_multiple_readers(False)

DEBUG 2014-07-27 17:05:05,569 base 345 Connect request received from client for 
port 192.168.100.100:31791
DEBUG 2014-07-27 17:05:05,570 core 435 Closed connection to 
192.168.100.100:31791 as it is not a recognized peer.
DEBUG 2014-07-27 17:05:05,570 base 11 SIGNAL: ('error', 'bgp', None) emited 
with data: {'peer': None, 'subcode': 5, 'code': 6, 'reason': 'Cease: Connection 
Rejected'} 
ERROR 2014-07-27 17:05:05,570 speaker 376 Sent notification to 
('192.168.100.102', '179') >> 
BGPNotification(data='',error_code=6,error_subcode=5,len=21,marker='\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff',type=3)
DEBUG 2014-07-27 17:05:45,523 base 345 Connect request received from client for 
port 192.168.100.100:16040
DEBUG 2014-07-27 17:05:45,524 core 435 Closed connection to 
192.168.100.100:16040 as it is not a recognized peer.
DEBUG 2014-07-27 17:05:45,524 base 11 SIGNAL: ('error', 'bgp', None) emited 
with data: {'peer': None, 'subcode': 5, 'code': 6, 'reason': 'Cease: Connection 
Rejected'} 
ERROR 2014-07-27 17:05:45,524 speaker 376 Sent notification to 
('192.168.100.102', '179') >> 
BGPNotification(data='',error_code=6,error_subcode=5,len=21,marker='\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff',type=3)
DEBUG 2014-07-27 17:06:21,000 base 345 Connect request received from client for 
port 192.168.100.100:33990
DEBUG 2014-07-27 17:06:21,001 core 435 Closed connection to 
192.168.100.100:33990 as it is not a recognized peer.
DEBUG 2014-07-27 17:06:21,001 base 11 SIGNAL: ('error', 'bgp', None) emited 
with data: {'peer': None, 'subcode': 5, 'code': 6, 'reason': 'Cease: Connection 
Rejected'} 
ERROR 2014-07-27 17:06:21,001 speaker 376 Sent notification to 
('192.168.100.102', '179') >> 
BGPNotification(data='',error_code=6,error_subcode=5,len=21,marker='\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff',type=3)
DEBUG 2014-07-27 17:07:06,263 base 345 Connect request received from client for 
port 192.168.100.100:11862
DEBUG 2014-07-27 17:07:06,263 core 435 Closed connection to 
192.168.100.100:11862 as it is not a recognized peer.
DEBUG 2014-07-27 17:07:06,264 base 11 SIGNAL: ('error', 'bgp', None) emited 
with data: {'peer': None, 'subcode': 5, 'code': 6, 'reason': 'Cease: Connection 
Rejected'} 
ERROR 2014-07-27 17:07:06,264 speaker 376 Sent notification to 
('192.168.100.102', '179') >> 
BGPNotification(data='',error_code=6,error_subcode=5,len=21,marker='\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff\xff',type=3)


(2) neighbor reset through RPC in Ryu-cli

$ ./rpc_cli.py --peers=bgps=localhost:50002
(Cmd) request bgps core.reset_neighbor [{'ip_address': '192.168.100.100'}]
disconnected.  trying to connect...
connected.  retrying the request...
RPC ERROR 200.1 - Neighbor 192.168.100.100 is not enabled, hence cannot reset.
(Cmd) 




2014/07/27 10:10、Toshiki Tsuboi <t.tsubo2...@gmail.com> のメール:

> Hi Fujita-san
> 
> I have tested reset_neighbor after adapting patch code .
> It looks to me the previous issue has resolved . 
>  -> BGP peering down properly , because Ryu-BGP sends Notification 
> Message”administrative shutdown”  ,
> 
> But, after that, BGP peering has kept ‘Down ‘,
>  -> Please check the attach “wireshark_keep_peer_down"
> 
> Best regards
> Toshiki Tsuboi
> 
> 
> —---- test result as following ---------
> 
> (1) starting My sampleApp
> 
> $ sudo ./start_RyuBGPSpeaker.sh 
> INFO 2014-07-20 20:31:29,814 base 207 API method core.start called with args: 
> {'router_id': '10.10.0.2', 'label_range': (100, 100000), 'waiter': 
> <ryu.lib.hub.Event object at 0x7fe42269ca90>, 'local_as': 64512, 
> 'bgp_server_port': 179, 'refresh_max_eor_time': 0, 'refresh_stalepath_time': 
> 0}
> INFO 2014-07-20 20:31:29,868 base 207 API method neighbor.create called with 
> args: {'remote_as': 64511, 'ip_address': '192.168.100.100'}
> INFO 2014-07-20 20:31:29,869 base 207 API method network.add called with 
> args: {'prefix': '10.20.0.0/24'}
> INFO 2014-07-20 20:31:29,870 base 207 API method network.add called with 
> args: {'prefix': '10.30.0.0/24'}
> INFO 2014-07-20 20:31:29,871 base 207 API method network.add called with 
> args: {'prefix': '10.40.0.0/16'}
> INFO 2014-07-20 20:31:29,872 base 207 API method network.add called with 
> args: {'prefix': '10.50.0.0/16'}
> CRITICAL 2014-07-20 20:31:30,891 peer 1763 Connection to peer: 
> 192.168.100.100 established
> CRITICAL 2014-07-20 20:32:07,426 net_ctrl 121 RPC Session to ('127.0.0.1', 
> 41478) started
> INFO 2014-07-20 20:32:07,427 base 207 API method comm_conf.get called with 
> args: {}
> INFO 2014-07-20 20:32:28,828 base 207 API method core.reset_neighbor called 
> with args: {'ip_address': '192.168.100.100'}
> ERROR 2014-07-20 20:32:28,829 base 225 Traceback (most recent call last):
>   File 
> "/usr/local/lib/python2.7/dist-packages/ryu/services/protocols/bgp/api/base.py",
>  line 220, in call
>     return call(**kwargs)
>   File 
> "/usr/local/lib/python2.7/dist-packages/ryu/services/protocols/bgp/api/core.py",
>  line 71, in reset_neighor
>     neigh_conf.enabled = False
>   File 
> "/usr/local/lib/python2.7/dist-packages/ryu/services/protocols/bgp/rtconf/neighbors.py",
>  line 351, in enabled
>     enable)
>   File 
> "/usr/local/lib/python2.7/dist-packages/ryu/services/protocols/bgp/rtconf/base.py",
>  line 252, in _notify_listeners
>     callback(ConfEvent(self, evt, value))
>   File 
> "/usr/local/lib/python2.7/dist-packages/ryu/services/protocols/bgp/peer.py", 
> line 433, in on_update_enabled
>     BGP_ERROR_SUB_ADMINISTRATIVE_SHUTDOWN
>   File 
> "/usr/local/lib/python2.7/dist-packages/ryu/services/protocols/bgp/speaker.py",
>  line 374, in send_notification
>     if len(self._localname()):
> TypeError: 'tuple' object is not callable
> 
> CRITICAL 2014-07-20 20:32:28,942 peer 1777 Connection to peer 192.168.100.100 
> lost, reason: Peer closed connection Resetting retry connect loop: False
> INFO 2014-07-20 20:32:28,944 speaker 600 Peer closed connection
> INFO 2014-07-20 20:32:57,340 base 207 API method comm_conf.get called with 
> args: {}
> ERROR 2014-07-20 20:33:16,802 hub 60 hub: uncaught exception: Traceback (most 
> recent call last):
>   File "/usr/local/lib/python2.7/dist-packages/ryu/lib/hub.py", line 52, in 
> _launch
>     func(*args, **kwargs)
>   File 
> "/usr/local/lib/python2.7/dist-packages/ryu/services/protocols/bgp/core.py", 
> line 439, in start_protocol
>     bgp_proto.send_notification(code, subcode)
>   File 
> "/usr/local/lib/python2.7/dist-packages/ryu/services/protocols/bgp/speaker.py",
>  line 374, in send_notification
>     if len(self._localname()):
> TypeError: 'tuple' object is not callable
> 
> (snip)
> 
> 
> (2) neighbor reset through RPC in Ryu-cli
> 
> (Cmd) request bgps comm_conf.get [{}]
> RESULT {'router_id': '10.10.0.2', 'label_range': [100, 100000], 'local_as': 
> 64512, 'bgp_conn_retry_time': 30, 'bgp_server_port': 179, 'tcp_conn_timeout': 
> 30, 'refresh_max_eor_time': 0, 'refresh_stalepath_time': 0, 
> 'maximum_paths_external_rtfilter_all': True}
> (Cmd) 
> (Cmd) request bgps core.reset_neighbor [{'ip_address': '192.168.100.100'}]
> RPC ERROR 500.1 - 'tuple' object is not callable
> (Cmd) NOTIFICATION from bgps ['neighbor.state', {'state': 'Idle', 
> 'ip_address': '192.168.100.100'}]
> 
> (Cmd) request bgps comm_conf.get [{}]
> NOTIFICATION from bgps ['neighbor.down', {'ip_address': '192.168.100.100'}]
> RESULT {'router_id': '10.10.0.2', 'label_range': [100, 100000], 'local_as': 
> 64512, 'bgp_conn_retry_time': 30, 'bgp_server_port': 179, 'tcp_conn_timeout': 
> 30, 'refresh_max_eor_time': 0, 'refresh_stalepath_time': 0, 
> 'maximum_paths_external_rtfilter_all': True}
> (Cmd) 
> (Cmd) request bgps comm_conf.get [{}]
> RESULT {'router_id': '10.10.0.2', 'label_range': [100, 100000], 'local_as': 
> 64512, 'bgp_conn_retry_time': 30, 'bgp_server_port': 179, 'tcp_conn_timeout': 
> 30, 'refresh_max_eor_time': 0, 'refresh_stalepath_time': 0, 
> 'maximum_paths_external_rtfilter_all': True}
> 
> 
> 
> 
> <wireshark_keep_peer_down.png>
> 
> 
> 
> 
> 
> 2014/07/27 8:35、FUJITA Tomonori <fujita.tomon...@lab.ntt.co.jp> のメール:
> 
>> Hi,
>> 
>> On Sun, 27 Jul 2014 08:00:18 +0900
>> Toshiki Tsuboi <t.tsubo2...@gmail.com> wrote:
>> 
>>> I have just found the bug for Ryu-bgp .
>>> Please let me share  a bug report  as follows
>> 
>> Thanks for that!
>> 
>>> (1) starting My sampleApp
>>> -> neighbor create succeed
>>> 
>>>    $ sudo ./start_RyuBGPSpeaker.sh 
>>>    INFO 2014-07-20 19:07:29,012 base 207 API method core.start called with 
>>> args: {'router_id': '10.10.0.2', 'label_range': (100, 100000), 'waiter': 
>>> <ryu.lib.hub.Event object at     
>>>    0x7f8b8d8dba90>, 'local_as': 64512, 'bgp_server_port': 179, 
>>> 'refresh_max_eor_time': 0, 'refresh_stalepath_time': 0}
>>>    INFO 2014-07-20 19:07:29,059 base 207 API method neighbor.create called 
>>> with args: {'remote_as': 64511, 'ip_address': '192.168.100.100'}
>>>    INFO 2014-07-20 19:07:29,060 base 207 API method network.add called with 
>>> args: {'prefix': '10.20.0.0/24'}
>>>    INFO 2014-07-20 19:07:29,061 base 207 API method network.add called with 
>>> args: {'prefix': '10.30.0.0/24'}
>>>    INFO 2014-07-20 19:07:29,062 base 207 API method network.add called with 
>>> args: {'prefix': '10.40.0.0/16'}
>>>    INFO 2014-07-20 19:07:29,063 base 207 API method network.add called with 
>>> args: {'prefix': '10.50.0.0/16'}
>>>    CRITICAL 2014-07-20 19:07:30,096 peer 1759 Connection to peer: 
>>> 192.168.100.100 established
>>> 
>>> (2) neighbor reset through RPC in Ryu-cli
>>>  -> RPC ERROR has occurred 
>>> 
>>>    $ ./rpc_cli.py --peers=bgps=localhost:50002
>>>    (Cmd) request bgps core.reset_neighbor [{'ip_address': 
>>> '192.168.100.100'}]
>>>    RPC ERROR 500.1 - global name 'BGP_ERROR_CEASE' is not defined 
>> 
>> How about the following (sorry, not tested)?
>> 
>> diff --git a/ryu/services/protocols/bgp/peer.py 
>> b/ryu/services/protocols/bgp/peer.py
>> index 4b3675a..03533d7 100644
>> --- a/ryu/services/protocols/bgp/peer.py
>> +++ b/ryu/services/protocols/bgp/peer.py
>> @@ -57,6 +57,10 @@ from ryu.lib.packet.bgp import BGP_MSG_UPDATE
>> from ryu.lib.packet.bgp import BGP_MSG_KEEPALIVE
>> from ryu.lib.packet.bgp import BGP_MSG_ROUTE_REFRESH
>> 
>> +from ryu.lib.packet.bgp import BGP_ERROR_CEASE
>> +from ryu.lib.packet.bgp import BGP_ERROR_SUB_ADMINISTRATIVE_SHUTDOWN
>> +from ryu.lib.packet.bgp import BGP_ERROR_SUB_CONNECTION_COLLISION_RESOLUTION
>> +
>> from ryu.lib.packet.bgp import BGPPathAttributeNextHop
>> from ryu.lib.packet.bgp import BGPPathAttributeAsPath
>> from ryu.lib.packet.bgp import BGPPathAttributeLocalPref
> 

------------------------------------------------------------------------------
Want fast and easy access to all the code in your enterprise? Index and
search up to 200,000 lines of code with a free copy of Black Duck
Code Sight - the same software that powers the world's largest code
search on Ohloh, the Black Duck Open Hub! Try it now.
http://p.sf.net/sfu/bds
_______________________________________________
Ryu-devel mailing list
Ryu-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/ryu-devel

Reply via email to