[j-nsp] MX-480 BGP Open message error with unknown subcode.

Fri Jan 24 07:52:09 EST 2014

This is strange  for directly connected peers on the same physical segment.   Is it possible to share your configuration and IP allocation for the connecting interfaces?

Peer1----- /127--------Peer2
Peer1-------/30-------------Peer2

-----Original Message-----
From: juniper-nsp [mailto:juniper-nsp-bounces at puck.nether.net] On Behalf Of Misak Khachatryan
Sent: Friday, January 24, 2014 7:43 AM
To: juniper-nsp at puck.nether.net >> juniper-nsp
Subject: Re: [j-nsp] MX-480 BGP Open message error with unknown subcode.

This issue resolved by adding multihop stanza to neighbor, which is pretty weird, as peers use directly connected interface IPs ...

Misak Khachatryan wrote:
> Hello,
>
> I have strange problem on my MX-480. From some time router suddenly 
> drops BGP peering with two customers and session doesn't come up from 
> that time. One peer is IPv4, another one IPv6. Not configuration 
> change done. There are lot of other BGP peers working OK on that router.
>
> Here is excerpt from log of one BGP session:
>
>
> Jan 22 12:46:34.412693 bgp_event: peer 2a02:2a50:0:11::2 (External AS
> 47623) old state Idle event Start new state Active Jan 22 
> 12:46:34.412703 task_timer_ucreate: created timer 
> BGP_47623_49800.2a02:2a50:0:11::2_Connect  flags <> Jan 22 
> 12:46:34.412713 task_timer_uset: timer 
> BGP_47623_49800.2a02:2a50:0:11::2_Connect <Touched> set to offset 2:28 
> at 12:49:02 Jan 22 12:47:37.567137 Jan 22 12:47:37.567137 BGP RECV 
> 2a02:2a50:0:11::2+59259 ->
> 2a02:2a50:0:11::1+179
> Jan 22 12:47:37.567190 BGP RECV message type 1 (Open) length 45 Jan 22 
> 12:47:37.567198 BGP RECV version 4 as 47623 holdtime 180 id
> 93.187.163.1 parmlen 16
> Jan 22 12:47:37.567204 BGP RECV Refresh capability, code=2 Jan 22 
> 12:47:37.567210 BGP RECV 4 Byte AS-Path capability (65), as_num
> 47623
> Jan 22 12:47:37.567215 BGP RECV MP capability AFI=2, SAFI=1 Jan 22 
> 12:47:37.567252 task_timer_delete:
> BGP_47623_49800.2a02:2a50:0:11::2_Connect <Touched> Jan 22 
> 12:47:37.567267 task_set_socket: task
> BGP_47623_49800.2a02:2a50:0:11::2 socket 112 Jan 22 12:47:37.567278 
> task_set_option_internal: task
> BGP_47623_49800.2a02:2a50:0:11::2 socket 112 option RecvBuffer(0) 
> value
> 16384
> Jan 22 12:47:37.567287 task_set_option_internal: task
> BGP_47623_49800.2a02:2a50:0:11::2 socket 112 option SendBuffer(1) 
> value
> 16384
> Jan 22 12:47:37.567309 task_set_option_internal: task
> BGP_47623_49800.2a02:2a50:0:11::2+59259 socket 112 option
> PathMTUDiscovery(26) value 0
> Jan 22 12:47:37.567333 task_set_option_internal: task
> BGP_47623_49800.2a02:2a50:0:11::2+59259 socket 112 option DontRoute(5) 
> value 1 Jan 22 12:47:37.567342 task_set_option_internal: task
> BGP_47623_49800.2a02:2a50:0:11::2+59259 socket 112 option
> IifRestrict(36) value 1
> Jan 22 12:47:37.567351 task_set_option_internal: task
> BGP_47623_49800.2a02:2a50:0:11::2+59259 socket 112 option TTL(15) 
> value 1 Jan 22 12:47:37.567362 task_timer_ucreate: created timer 
> BGP_47623_49800.2a02:2a50:0:11::2+59259_Hold  flags <> Jan 22 
> 12:47:37.567373 task_timer_uset: timer 
> BGP_47623_49800.2a02:2a50:0:11::2+59259_Hold <Touched> set to offset
> 1:30 at 12:49:07
> Jan 22 12:47:37.567382 bgp_event: peer 2a02:2a50:0:11::2 (External AS
> 47623) old state Active event Open new state OpenSent Jan 22 
> 12:47:37.567391 advertising graceful restart receiving-speaker-only 
> capability to neighbor 2a02:2a50:0:11::2 (External AS 47623) Jan 22 
> 12:47:37.567401 bgp_4byte_aspath_add_cap():153 AS4-Peer
> 2a02:2a50:0:11::2 (External AS 47623)(SEND): 4 byte AS capability 
> added, AS 49800 Jan 22 12:47:37.567408 bgp_send: sending 59 bytes to 
> 2a02:2a50:0:11::2 (External AS 47623) Jan 22 12:47:37.567414 Jan 22 
> 12:47:37.567414 BGP SEND 2a02:2a50:0:11::1+179 ->
> 2a02:2a50:0:11::2+59259
> Jan 22 12:47:37.567421 BGP SEND message type 1 (Open) length 59 Jan 22 
> 12:47:37.567427 BGP SEND version 4 as 49800 holdtime 90 id
> 46.19.96.5 parmlen 30
> Jan 22 12:47:37.567432 BGP SEND MP capability AFI=2, SAFI=1 Jan 22 
> 12:47:37.567436 BGP SEND Refresh capability, code=128 Jan 22 
> 12:47:37.567440 BGP SEND Refresh capability, code=2 Jan 22 
> 12:47:37.567445 BGP SEND Restart capability, code=64, time=120, flags= 
> Jan 22 12:47:37.567450 BGP SEND 4 Byte AS-Path capability (65), as_num
> 49800
> Jan 22 12:47:37.567490 bgp_process_4byte_aspath_cap():286 AS4-Peer
> 2a02:2a50:0:11::2 (External AS 47623)(RECV): 4 byte AS Cap value 
> stored
> 47623
>
> Jan 22 12:47:37.567499 bgp_event: peer 2a02:2a50:0:11::2 (External AS
> 47623) old state OpenSent event RecvOpen new state OpenConfirm Jan 22 
> 12:47:37.567504 bgp_send: sending 19 bytes to 2a02:2a50:0:11::2 
> (External AS 47623) Jan 22 12:47:37.567517 Jan 22 12:47:37.567517 BGP 
> SEND 2a02:2a50:0:11::1+179 ->
> 2a02:2a50:0:11::2+59259
> Jan 22 12:47:37.567524 BGP SEND message type 4 (KeepAlive) length 19 
> Jan 22 12:47:37.567533 bgp_recv_change: peer 2a02:2a50:0:11::2 
> (External AS 47623) receiver changed to bgp_recv_open Jan 22 
> 12:47:37.567540 task_set_socket: task
> BGP_47623_49800.2a02:2a50:0:11::2+59259 socket 112 Jan 22 
> 12:47:37.568371 task_process_events: recv ready for
> BGP_47623_49800.2a02:2a50:0:11::2+59259
> Jan 22 12:47:37.568378 bgp_recv_open: called for peer 
> 2a02:2a50:0:11::2 (External AS 47623) Jan 22 12:47:37.568387 Jan 22 
> 12:47:37.568387 BGP RECV 2a02:2a50:0:11::2+59259 ->
> 2a02:2a50:0:11::1+179
> Jan 22 12:47:37.568395 BGP RECV message type 4 (KeepAlive) length 19 
> Jan 22 12:47:37.568426 bgp_peer_established:6685: NOTIFICATION sent to
> 2a02:2a50:0:11::2 (External AS 47623): code 2 (Open Message Error),
> Reason: pending close
> Jan 22 12:47:37.568433 bgp_send: sending 21 bytes to 2a02:2a50:0:11::2 
> (External AS 47623) Jan 22 12:47:37.568439 Jan 22 12:47:37.568439 BGP 
> SEND 2a02:2a50:0:11::1+179 ->
> 2a02:2a50:0:11::2+59259
> Jan 22 12:47:37.568446 BGP SEND message type 3 (Notification) length 
> 21 Jan 22 12:47:37.568451 BGP SEND Notification code 2 (Open Message 
> Error) subcode 0 (unspecified error) Jan 22 12:47:37.568461 
> bgp_peer_close: closing peer 2a02:2a50:0:11::2 (External AS 47623), 
> state is 5 (OpenConfirm) Jan 22 12:47:37.568474 bgp_close_socket: peer 
> 2a02:2a50:0:11::2 (External AS 47623) Jan 22 12:47:37.568480 
> task_close: close socket 112 task
> BGP_47623_49800.2a02:2a50:0:11::2+59259
> Jan 22 12:47:37.568486 task_reset_socket: task
> BGP_47623_49800.2a02:2a50:0:11::2+59259 socket 112 Jan 22 
> 12:47:37.568518 task_timer_delete:
> BGP_47623_49800.2a02:2a50:0:11::2_Hold <Touched> Jan 22 
> 12:47:37.568526 bgp_event: peer 2a02:2a50:0:11::2 (External AS
> 47623) old state OpenConfirm event OpenFail new state Idle Jan 22 
> 12:47:37.568718 bgp_event: peer 2a02:2a50:0:11::2 (External AS
> 47623) old state Idle event Start new state Active Jan 22 
> 12:47:37.568733 task_timer_ucreate: created timer 
> BGP_47623_49800.2a02:2a50:0:11::2_Connect  flags <> Jan 22 
> 12:47:37.568743 task_timer_uset: timer 
> BGP_47623_49800.2a02:2a50:0:11::2_Connect <Touched> set to offset 2:28 
> at 12:50:05
>
>
> Any clue? Thanks in advance.
>

--
Best regards,
Misak Khachatryan,
Head of Network Administration
and Monitoring Department,
GNC-Alfa CJSC.
_______________________________________________
juniper-nsp mailing list juniper-nsp at puck.nether.net https://puck.nether.net/mailman/listinfo/juniper-nsp