Hi Andrei,
I tried but it didn't work.
I don't know why the BGP sessions were established after a few days.
Nothing changed on my router or my ISP's router.
However, some routers still faced the same issue.
I set a trace option with a flag all but can not see anything wrong.
I hide the real IP and ASN used on the configuration.
AS65500 and IP 192.168.100.1 are our ISP.
AS64500 and IP 192.168.1.1 are our routers.
Jul 23 13:25:47.253785 task_timer_delete: BGP_65500_64500.192.168.100.1_Down Peer Timer <Processing>
Jul 23 13:26:19.240736 bgp_connect_timeout: BGP_65500_64500.192.168.100.1_Connect
Jul 23 13:26:19.240754 bgp_connect_start: peer 192.168.100.1 (External AS 65500)
Jul 23 13:26:19.240758 bgp_event: peer 192.168.100.1 (External AS 65500) old state Active event ConnectRetry new state Connect
Jul 23 13:26:19.240968 task_get_socket: domain AF_INET type SOCK_STREAM protocol 0 socket 142
Jul 23 13:26:19.240978 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 142 option RecvBuffer(0) value 16384
Jul 23 13:26:19.240983 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 142 option SendBuffer(1) value 16384
Jul 23 13:26:19.240986 task_set_socket: task BGP_65500_64500.192.168.100.1 socket 142
Jul 23 13:26:19.240996 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 142 option NonBlocking(8) value 1
Jul 23 13:26:19.241001 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 142 option ReUsePort(38) value 1
Jul 23 13:26:19.241008 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 142 option PathMTUDiscovery(26) value 0
Jul 23 13:26:19.241013 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 142 option TOS(16) value 192
Jul 23 13:26:19.241018 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 142 option TTL(15) value 255
Jul 23 13:26:19.241022 Eval BFD turn-on, currently off for peer 192.168.100.1 (External AS 65500)(fl:)instance master (kern-id 0)
Jul 23 13:26:19.241029 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 142 option TcpAggressiveTransmission(59) value 0
Jul 23 13:26:19.241035 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 142 option EnableTcpNoDelay(63) value 0
Jul 23 13:26:19.241139 task_timer_reset: reset BGP_65500_64500.192.168.100.1_Connect
Jul 23 13:26:19.241148 task_timer_set_oneshot_latest: timer BGP_65500_64500.192.168.100.1_Connect interval set to 2:28
Jul 23 13:26:19.467654 task_process_events_internal: connect ready for BGP_65500_64500.192.168.100.1
Jul 23 13:26:19.467674 bgp_peer_connected: connection established with 192.168.100.1 (External AS 65500)
Jul 23 13:26:19.467686 task_timer_delete: BGP_65500_64500.192.168.100.1_Connect <Touched>
Jul 23 13:26:19.467690 bgp_recv_setup: peer 192.168.100.1 (External AS 65500) socket 142 set for reading
Jul 23 13:26:19.467693 task_reset_socket: task BGP_65500_64500.192.168.100.1 socket 142
Jul 23 13:26:19.467699 task_set_socket: task BGP_65500_64500.192.168.100.1 socket 142
Jul 23 13:26:19.467711 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 142 option NonBlocking(8) value 1
Jul 23 13:26:19.467718 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 142 option RecvBuffer(0) value 16384
Jul 23 13:26:19.467722 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 142 option SendBuffer(1) value 16384
Jul 23 13:26:19.467727 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 142 option Linger(2) value { 0, 0 }
Jul 23 13:26:19.467734 bgp_event: peer 192.168.100.1 (External AS 65500) old state Connect event Open new state OpenSent
Jul 23 13:26:19.467740 advertising graceful restart receiving-speaker-only capability to neighbor 192.168.100.1 (External AS 65500)
Jul 23 13:26:19.467746 bgp_4byte_aspath_add_cap():179 AS4-Peer 192.168.100.1 (External AS 65500)(SEND): 4 byte AS capability added, AS 64500
Jul 23 13:26:19.467755 advertising LLGR receiving-speaker-only capability to neighbor 192.168.100.1 (External AS 65500)
Jul 23 13:26:19.467761 BGP_65500_64500.192.168.100.1: send proc: sending 63 bytes
Jul 23 13:26:19.467767
Jul 23 13:26:19.467767 BGP SEND 192.168.1.1+50832 -> 192.168.100.1+179
Jul 23 13:26:19.467770 BGP SEND message type 1 (Open) length 63
Jul 23 13:26:19.467773 BGP SEND version 4 as 64500 holdtime 90 id 192.168.1.1 parmlen 34
Jul 23 13:26:19.467775 BGP SEND MP capability AFI=1, SAFI=1
Jul 23 13:26:19.467777 BGP SEND Refresh capability, code=128
Jul 23 13:26:19.467780 BGP SEND Refresh capability, code=2
Jul 23 13:26:19.467783 BGP SEND Restart capability, code=64, time=120, flags=Notification
Jul 23 13:26:19.467785 BGP SEND 4 Byte AS-Path capability (65), as_num 64500
Jul 23 13:26:19.467788 BGP SEND Long-Lived Graceful Restart capability, code=71
Jul 23 13:26:19.467828 BGP_65500_64500.192.168.100.1: send proc: writev 63/63 bytes, rc 1
Jul 23 13:26:19.467833 task_timer_ucreate: created timer BGP_65500_64500.192.168.100.1_Hold flags <>
Jul 23 13:26:19.467893 task_timer_uset: timer BGP_65500_64500.192.168.100.1_Hold <Touched> set to interval 0 offset 1:30 with jitter 0 at 13:27:49.467636
Jul 23 13:26:19.694546 task_process_events_internal: recv ready for BGP_65500_64500.192.168.100.1
Jul 23 13:26:19.694562 bgp_recv_open: called for peer 192.168.100.1 (External AS 65500)
Jul 23 13:26:19.694580 task_process_events_internal: recv ready for BGP_65500_64500.192.168.100.1
Jul 23 13:26:19.694582 bgp_recv_open: called for peer 192.168.100.1 (External AS 65500)
Jul 23 13:26:19.694587
Jul 23 13:26:19.694587 BGP RECV 192.168.100.1+179 -> 192.168.1.1+50832
Jul 23 13:26:19.694590 BGP RECV message type 1 (Open) length 29
Jul 23 13:26:19.694594 BGP RECV version 4 as 65500 holdtime 90 id 192.168.100.1 parmlen 0
Jul 23 13:26:19.694603 bgp_process_4byte_aspath_cap():312 AS4-Peer 192.168.100.1 (External AS 65500)(RECV): 4 byte AS Cap value stored 0
Jul 23 13:26:19.694612 bgp_event: peer 192.168.100.1 (External AS 65500) old state OpenSent event RecvOpen new state OpenConfirm
Jul 23 13:26:19.694618 task_set_socket: task BGP_65500_64500.192.168.100.1 socket 142
Jul 23 13:26:19.694628 task_timer_delete: BGP_65500_64500.192.168.100.1_Hold <Touched>
Jul 23 13:26:19.694649 io-142-1562-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=0
Jul 23 13:26:19.694667 io-142-1562-BGP_65500_64500.192.168.100.1: Success: Initialized queue 0
Jul 23 13:26:19.694671 io-142-1562-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=1
Jul 23 13:26:19.694680 io-142-1562-BGP_65500_64500.192.168.100.1: Success: Initialized queue 1
Jul 23 13:26:19.694685 io-142-1562-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=2
Jul 23 13:26:19.694694 io-142-1562-BGP_65500_64500.192.168.100.1: Success: Initialized queue 2
Jul 23 13:26:19.694701 io-142-1562-BGP_65500_64500.192.168.100.1: Success: Encoded msg op=3
Jul 23 13:26:19.694730 io-142-1562-BGP_65500_64500.192.168.100.1: Success: Created session
Jul 23 13:26:19.694733 bgp_thrio_peer_init: peer 192.168.100.1 (External AS 65500): Initialized I/O session
Jul 23 13:26:19.694742 BGP_65500_64500.192.168.100.1: send proc: send via threaded I/O
Jul 23 13:26:19.694745 sending 19 bytes
Jul 23 13:26:19.694748
Jul 23 13:26:19.694748 BGP SEND 192.168.1.1+50832 -> 192.168.100.1+179
Jul 23 13:26:19.694750 BGP SEND message type 4 (KeepAlive) length 19
Jul 23 13:26:19.694818 bgp_thrio_write_batch:5013: 192.168.100.1 (External AS 65500): Wrote to batch: pdus=1, bytes=19 scheduled flush, res=36
Jul 23 13:26:19.694822 wrote 19 bytes to I/O queue
Jul 23 13:26:19.694824 finished number of messages 1, write qidx 1 rc 1
Jul 23 13:26:19.694955 io-142-1562-BGP_65500_64500.192.168.100.1: Success: Session create done - session enabled
Jul 23 13:26:19.694960 BGP peer 192.168.100.1 (External AS 65500): Threaded I/O session create done - State 2
Jul 23 13:26:19.694970 io-142-1562-BGP_65500_64500.192.168.100.1: Success: posted read request data=0x7fffffffde30, aux=0x0, msg=0xa4a2864, qidx=2
Jul 23 13:26:19.694977 io-142-1562-BGP_65500_64500.192.168.100.1: Processed Session create response, msgid = 43562
Jul 23 13:26:19.695007 io-142-1562-BGP_65500_64500.192.168.100.1: Handling session msg for queue 2, call user to start job and deregister handler
Jul 23 13:26:19.695015 BGP peer 192.168.100.1 (External AS 65500): started read response process job 0x4852c40
Jul 23 13:26:19.695068 io-142-1562-BGP_65500_64500.192.168.100.1: Got inbound PDU, qidx=2, msgid=1, type=1, niov=1, nbytes=0, err=0
Jul 23 13:26:19.695071 bgp_read_resp_process_internal:1382: 192.168.100.1 (External AS 65500): skip empty read resp msg, type=1, id=1
Jul 23 13:26:19.695078 io-142-1562-BGP_65500_64500.192.168.100.1: Got inbound PDU, qidx=2, msgid=1, type=3, niov=1, nbytes=21, err=0
Jul 23 13:26:19.695081 bgp_read_resp_process_internal:1397: 192.168.100.1 (External AS 65500): npdus=1, pdubuf=0xa60a000 iovbase=0xa60a000, iovlen=21
Jul 23 13:26:19.695084
Jul 23 13:26:19.695084 BGP RECV 192.168.100.1+179 -> 192.168.1.1+50832
Jul 23 13:26:19.695086 BGP RECV message type 3 (Notification) length 21
Jul 23 13:26:19.695091 BGP RECV Notification code 6 (Cease) subcode 5 (Connection Rejected)
Jul 23 13:26:19.695135 bgp_handle_notify:4300: NOTIFICATION received from 192.168.100.1 (External AS 65500): code 6 (Cease) subcode 5 (Connection Rejected)
Jul 23 13:26:19.695138 Notify received from 192.168.100.1 (External AS 65500), code 6, subcode 5
Jul 23 13:26:19.695141
Jul 23 13:26:19.695141 BGP RECV 192.168.100.1+179 -> 192.168.1.1+50832
Jul 23 13:26:19.695154 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 15 03 06 05
Jul 23 13:26:19.695158 bgp_peer_close_and_restart: peer 192.168.100.1 (External AS 65500), state is 5 (OpenConfirm) event RecvNotify, flags=0x0
Jul 23 13:26:19.695161 bgp_peer_close_and_restart: closing peer 192.168.100.1 (External AS 65500), state is 5 (OpenConfirm) event RecvNotify
Jul 23 13:26:19.695164 bgp_send_deactivate:2671: 192.168.100.1 (External AS 65500) ,flags=0x0: removed from active list
Jul 23 13:26:19.695174 bgp_event: peer 192.168.100.1 (External AS 65500) old state OpenConfirm event RecvNotify new state Idle
Jul 23 13:26:19.695349 bgp_peer_close_and_restart: 7709: BGP peer 192.168.100.1 (External AS 65500): state Idle task close fd 142
Jul 23 13:26:19.695354 bgp_thrio_peer_delete_internal:2799: BGP peer 192.168.100.1 (External AS 65500) CLOSE:, error 0, delete I/O session
Jul 23 13:26:19.695361 XXio-142-1562-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=0
Jul 23 13:26:19.695365 XXio-142-1562-BGP_65500_64500.192.168.100.1: I/O queue idx 0 stopped
Jul 23 13:26:19.695368 XXio-142-1562-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=1
Jul 23 13:26:19.695371 XXio-142-1562-BGP_65500_64500.192.168.100.1: I/O queue idx 1 stopped
Jul 23 13:26:19.695374 XXio-142-1562-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=2
Jul 23 13:26:19.695377 XXio-142-1562-BGP_65500_64500.192.168.100.1: I/O queue idx 2 stopped
Jul 23 13:26:19.695381 XXio-142-1562-BGP_65500_64500.192.168.100.1: Success: Encoded msg op=4
Jul 23 13:26:19.695402 XXio-142-1562-BGP_65500_64500.192.168.100.1: Success: Started session delete
Jul 23 13:26:19.695568 XXio-142-1562-BGP_65500_64500.192.168.100.1: Processing Session delete response, msgid = 43563
Jul 23 13:26:19.695573 XXio-142-1562-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=0
Jul 23 13:26:19.695576 XXio-142-1562-BGP_65500_64500.192.168.100.1: I/O queue idx 0 stopped
Jul 23 13:26:19.695579 XXio-142-1562-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=1
Jul 23 13:26:19.695586 XXio-142-1562-BGP_65500_64500.192.168.100.1: I/O queue idx 1 stopped
Jul 23 13:26:19.695589 XXio-142-1562-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=2
Jul 23 13:26:19.695594 XXio-142-1562-BGP_65500_64500.192.168.100.1: I/O queue idx 2 stopped
Jul 23 13:26:19.695599 XXio-142-1562-BGP_65500_64500.192.168.100.1: task socket 142 close
Jul 23 13:26:19.695603 task_close: close socket 142 task BGP_65500_64500.192.168.100.1
Jul 23 13:26:19.695606 task_reset_socket: task BGP_65500_64500.192.168.100.1 socket 142
Jul 23 13:26:19.695646 BGP peer 192.168.100.1 (External AS 65500) CLOSE: Threaded I/O session delete done event - do user cleanup
Jul 23 13:26:19.695652 XXio-142-1562-BGP_65500_64500.192.168.100.1: EOF write response messages
Jul 23 13:26:19.695655 XXio-142-1562-BGP_65500_64500.192.168.100.1: EOF write response messages
Jul 23 13:26:19.695659 XXio-142-1562-BGP_65500_64500.192.168.100.1: EOF read messages
Jul 23 13:26:19.695661 BGP peer 192.168.100.1 (External AS 65500) CLOSE: Unlink the I/O session
Jul 23 13:26:19.695668 BGP peer 192.168.100.1 (External AS 65500) CLOSE: Check proceed with close? Rt terminate=Complete, I/O session cleanup=Complete
Jul 23 13:26:19.695674 bgp_peer_post_close: Cleanup complete for peer 192.168.100.1 (last_flap NoEvent, state Idle, flags )
Jul 23 13:26:19.695681 bgp_peer_post_close:7332 BGP Peer 192.168.100.1 (External AS 65500) CLOSE: post close cleanup - NEED restart, (last_flap NoEvent, state Idle, flags )
Jul 23 13:26:19.695687 task_timer_ucreate: created timer BGP_65500_64500.192.168.100.1_Down Peer Timer flags <>
Jul 23 13:26:19.695697 task_timer_uset: timer BGP_65500_64500.192.168.100.1_Down Peer Timer <Touched> set to interval 0 offset 2:00 with jitter 0 at 13:28:19.695563
Jul 23 13:26:19.695700 bgp_event: peer 192.168.100.1 (External AS 65500) old state Idle event Start new state Active
Jul 23 13:26:19.695705 task_timer_ucreate: created timer BGP_65500_64500.192.168.100.1_Connect flags <>
Jul 23 13:26:19.695708 task_timer_uset: timer BGP_65500_64500.192.168.100.1_Connect <Touched> set to interval 0 offset 2:28 with jitter 0 at 13:28:47.695563
Jul 23 13:26:19.695724 XXio-142-1562-BGP_65500_64500.192.168.100.1: Session deleted
Jul 23 13:26:19.694804 task_set_socket: task BGP_65500_64500.192.168.100.1 socket 142 {bgp-io}
Jul 23 13:26:19.694848 task_timer_ucreate: created timer BGP_65500_64500.192.168.100.1_Task parent flags <> {bgp-io}
Jul 23 13:26:19.694852 task_timer_ucreate: created timer BGP_65500_64500.192.168.100.1_Keepalive flags <> {bgp-io}
Jul 23 13:26:19.694856 task_timer_ucreate: created timer BGP_65500_64500.192.168.100.1_Hold flags <> {bgp-io}
Jul 23 13:26:19.694860 task_timer_uset: timer BGP_65500_64500.192.168.100.1_Hold <Touched> set to interval 0 offset 1:30 with jitter 0 at 13:27:49.694762 {bgp-io}
Jul 23 13:26:19.694864 task_timer_reset: reset BGP_65500_64500.192.168.100.1_Hold {bgp-io}
Jul 23 13:26:19.694884 task_timer_reset: reset BGP_65500_64500.192.168.100.1_Keepalive {bgp-io}
Jul 23 13:26:19.694888 task_timer_uset_interval_latest: timer BGP_65500_64500.192.168.100.1_Keepalive interval set to 28.002935 {bgp-io}
Jul 23 13:26:19.694891 task_timer_reset: reset BGP_65500_64500.192.168.100.1_Hold {bgp-io}
Jul 23 13:26:19.694895 task_timer_set_oneshot_latest: timer BGP_65500_64500.192.168.100.1_Hold interval set to 1:30 {bgp-io}
Jul 23 13:26:19.694902 {bgp-io} th-142-1562-BGP_65500_64500.192.168.100.1: SessionFSM: Event 2, State Initial: Enabled @bgp-io
Jul 23 13:26:19.694929 task_process_events_internal: recv ready for BGP_65500_64500.192.168.100.1 {bgp-io}
Jul 23 13:26:19.694935 task_job_create_background: create prio 2 job rd_req_proc for task BGP_65500_64500.192.168.100.1 {bgp-io}
Jul 23 13:26:19.694940 {bgp-io} th-142-1562-BGP_65500_64500.192.168.100.1: Start read processing job, rdfsm state was: WaitSys @bgp-io
Jul 23 13:26:19.694981 background dispatch running job rd_req_proc for task BGP_65500_64500.192.168.100.1 {bgp-io}
Jul 23 13:26:19.694984 bgp_io_read_req_cb:6170: 142-1562-BGP_65500_64500.192.168.100.1: Calling user read cb: req pdu boundary = N, read at pdu boundary = N {bgp-io}
Jul 23 13:26:19.694990 {bgp-io} th-142-1562-BGP_65500_64500.192.168.100.1: Received msg 0xa4a2864 from IO queue 2 @bgp-io
Jul 23 13:26:19.694995 bgp_io_read_single_pdu:5979: 142-1562-BGP_65500_64500.192.168.100.1: Current bytes in stage = 0 {bgp-io}
Jul 23 13:26:19.695002 bgp_io_read_stage_init:5384: 142-1562-BGP_65500_64500.192.168.100.1: Initializing read stage: curr bytes = 0, to read 19 {bgp-io}
Jul 23 13:26:19.695004 bgp_io_read_socket:5284: fd=142, to_read_bytes=19 {bgp-io}
Jul 23 13:26:19.695013 bgp_io_read_socket:5292: task_socket_read - fd=142, len=19, errno=0, se=0, buf=0xa60a000 {bgp-io}
Jul 23 13:26:19.695016 bgp_io_read_send_resp:5647: 142-1562-BGP_65500_64500.192.168.100.1: No full PDU in read stage, nothing to send {bgp-io}
Jul 23 13:26:19.695019 bgp_io_read_post_process:5856: 142-1562-BGP_65500_64500.192.168.100.1: Read blocked, Parsing reached partial PDU {bgp-io}
Jul 23 13:26:19.695021 bgp_io_read_stage_init:5384: 142-1562-BGP_65500_64500.192.168.100.1: Initializing read stage: curr bytes = 19, to read 2 {bgp-io}
Jul 23 13:26:19.695024 bgp_io_read_socket:5284: fd=142, to_read_bytes=2 {bgp-io}
Jul 23 13:26:19.695028 bgp_io_read_socket:5292: task_socket_read - fd=142, len=2, errno=0, se=0, buf=0xa60a013 {bgp-io}
Jul 23 13:26:19.695031 bgp_io_read_post_process:5863: 142-1562-BGP_65500_64500.192.168.100.1: Read, user asked for session disable {bgp-io}
Jul 23 13:26:19.695053 {bgp-io} th-142-1562-BGP_65500_64500.192.168.100.1: Success: posted read: n=1, data=0x7fffff3fc0f0, aux=0x7fffff3fc100 @bgp-io
Jul 23 13:26:19.695057 bgp_io_read_send_resp:5684: 142-1562-BGP_65500_64500.192.168.100.1: Read stage: pdus, 1 pdus, 21 bytes, response send result=0, partial bytes=0 {bgp-io}
Jul 23 13:26:19.695059 bgp_io_read_single_pdu:6007: 142-1562-BGP_65500_64500.192.168.100.1: res=22 {bgp-io}
Jul 23 13:26:19.695063 task_timer_reset: reset BGP_65500_64500.192.168.100.1_Hold {bgp-io}
Jul 23 13:26:19.695066 task_timer_reset: reset BGP_65500_64500.192.168.100.1_Hold {bgp-io}
Jul 23 13:26:19.695069 task_timer_set_oneshot_latest: timer BGP_65500_64500.192.168.100.1_Hold interval set to 1:30 {bgp-io}
Jul 23 13:26:19.695072 bgp_io_read_req_cb:6257: 142-1562-BGP_65500_64500.192.168.100.1: Read some bytes 2, reset the Hold-timer {bgp-io}
Jul 23 13:26:19.695074 bgp_io_read_req_cb:6265: 142-1562-BGP_65500_64500.192.168.100.1: user read cb: req pdu boundary = N, read at pdu boundary = Y, res = 22, recv_bytes=2, inbytes=21, inmsgs=1 {bgp-io}
Jul 23 13:26:19.695079 {bgp-io} th-142-1562-BGP_65500_64500.192.168.100.1: Fail: user asked to disable further reads, wait for user @bgp-io
Jul 23 13:26:19.695083 {bgp-io} th-142-1562-BGP_65500_64500.192.168.100.1: readFSM Disabling immediately: Event 10, State Run @bgp-io
Jul 23 13:26:19.695086 task_job_delete: delete background job rd_req_proc for task BGP_65500_64500.192.168.100.1 {bgp-io}
Jul 23 13:26:19.695091 {bgp-io} th-142-1562-BGP_65500_64500.192.168.100.1: readFSM Disable done: Event 10, State Run @bgp-io
Jul 23 13:26:19.695093 background dispatch completed job rd_req_proc for task BGP_65500_64500.192.168.100.1 {bgp-io}
Jul 23 13:26:19.695447 task_timer_reset: reset BGP_65500_64500.192.168.100.1_Keepalive {bgp-io}
Jul 23 13:26:19.695452 task_timer_reset: reset BGP_65500_64500.192.168.100.1_Hold {bgp-io}
Jul 23 13:26:19.695459 {bgp-io} XXth-142-1562-BGP_65500_64500.192.168.100.1: Disabled status @bgp-io
Jul 23 13:26:19.695465 {bgp-io} XXth-142-1562-BGP_65500_64500.192.168.100.1: writeFSM Event 0, State WaitReq: trigger sessionFSM disable done event @bgp-io
Jul 23 13:26:19.695469 {bgp-io} XXth-142-1562-BGP_65500_64500.192.168.100.1: SessionFSM: Event 3, State Enabled: deleting @bgp-io
Jul 23 13:26:19.695474 {bgp-io} XXth-142-1562-BGP_65500_64500.192.168.100.1: SessionFSM: Event 1, State Deleting: done @bgp-io
Jul 23 13:26:19.695478 {bgp-io} XXth-142-1562-BGP_65500_64500.192.168.100.1: Session delete start final actions, pending req: 0x6e74808(4) @bgp-io
Jul 23 13:26:19.695488 task_timer_delete: BGP_65500_64500.192.168.100.1_Keepalive <Latest Touched> {bgp-io}
Jul 23 13:26:19.695493 task_timer_delete: BGP_65500_64500.192.168.100.1_Hold <Touched> {bgp-io}
Jul 23 13:26:35.466572
Jul 23 13:26:35.466572 BGP RECV 192.168.100.1+53957 -> 192.168.1.1+179
Jul 23 13:26:35.466585 BGP RECV message type 1 (Open) length 63
Jul 23 13:26:35.466589 BGP RECV version 4 as 65500 holdtime 900 id 192.168.100.1 parmlen 34
Jul 23 13:26:35.466591 BGP RECV MP capability AFI=1, SAFI=1
Jul 23 13:26:35.466594 BGP RECV Refresh capability, code=128
Jul 23 13:26:35.466596 BGP RECV Refresh capability, code=2
Jul 23 13:26:35.466606 BGP RECV Restart capability, code=64, time=120, flags=Notification
Jul 23 13:26:35.466608 BGP RECV 4 Byte AS-Path capability (65), as_num 65500
Jul 23 13:26:35.466611 BGP RECV Long-Lived Graceful Restart capability, code=71
Jul 23 13:26:35.466645 task_timer_delete: BGP_65500_64500.192.168.100.1_Connect <Touched>
Jul 23 13:26:35.466650 task_set_socket: task BGP_65500_64500.192.168.100.1 socket 181
Jul 23 13:26:35.466658 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 181 option RecvBuffer(0) value 16384
Jul 23 13:26:35.466663 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 181 option SendBuffer(1) value 16384
Jul 23 13:26:35.466678 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 181 option PathMTUDiscovery(26) value 0
Jul 23 13:26:35.466683 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 181 option TTL(15) value 255
Jul 23 13:26:35.466688 Eval BFD turn-on, currently off for peer 192.168.100.1 (External AS 65500)(fl:)instance master (kern-id 0)
Jul 23 13:26:35.466695 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 181 option TcpAggressiveTransmission(59) value 0
Jul 23 13:26:35.466701 task_set_option_internal: task BGP_65500_64500.192.168.100.1 socket 181 option EnableTcpNoDelay(63) value 0
Jul 23 13:26:35.466705 task_timer_ucreate: created timer BGP_65500_64500.192.168.100.1_Hold flags <>
Jul 23 13:26:35.466715 task_timer_uset: timer BGP_65500_64500.192.168.100.1_Hold <Touched> set to interval 0 offset 1:30 with jitter 0 at 13:28:05.466560
Jul 23 13:26:35.466719 bgp_event: peer 192.168.100.1 (External AS 65500) old state Active event Open new state OpenSent
Jul 23 13:26:35.466724 advertising graceful restart receiving-speaker-only capability to neighbor 192.168.100.1 (External AS 65500)
Jul 23 13:26:35.466727 bgp_4byte_aspath_add_cap():179 AS4-Peer 192.168.100.1 (External AS 65500)(SEND): 4 byte AS capability added, AS 64500
Jul 23 13:26:35.466731 advertising LLGR receiving-speaker-only capability to neighbor 192.168.100.1 (External AS 65500)
Jul 23 13:26:35.466736 BGP_65500_64500.192.168.100.1: send proc: sending 63 bytes
Jul 23 13:26:35.466739
Jul 23 13:26:35.466739 BGP SEND 192.168.1.1+179 -> 192.168.100.1+53957
Jul 23 13:26:35.466742 BGP SEND message type 1 (Open) length 63
Jul 23 13:26:35.466744 BGP SEND version 4 as 64500 holdtime 90 id 192.168.1.1 parmlen 34
Jul 23 13:26:35.466746 BGP SEND MP capability AFI=1, SAFI=1
Jul 23 13:26:35.466748 BGP SEND Refresh capability, code=128
Jul 23 13:26:35.466750 BGP SEND Refresh capability, code=2
Jul 23 13:26:35.466752 BGP SEND Restart capability, code=64, time=120, flags=Notification
Jul 23 13:26:35.466754 BGP SEND 4 Byte AS-Path capability (65), as_num 64500
Jul 23 13:26:35.466756 BGP SEND Long-Lived Graceful Restart capability, code=71
Jul 23 13:26:35.466800 BGP_65500_64500.192.168.100.1: send proc: writev 63/63 bytes, rc 1
Jul 23 13:26:35.466805 bgp_process_4byte_aspath_cap():312 AS4-Peer 192.168.100.1 (External AS 65500)(RECV): 4 byte AS Cap value stored 65500
Jul 23 13:26:35.466813 bgp_event: peer 192.168.100.1 (External AS 65500) old state OpenSent event RecvOpen new state OpenConfirm
Jul 23 13:26:35.466818 task_set_socket: task BGP_65500_64500.192.168.100.1 socket 181
Jul 23 13:26:35.466823 task_timer_delete: BGP_65500_64500.192.168.100.1_Hold <Touched>
Jul 23 13:26:35.466845 io-181-1563-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=0
Jul 23 13:26:35.466857 io-181-1563-BGP_65500_64500.192.168.100.1: Success: Initialized queue 0
Jul 23 13:26:35.466861 io-181-1563-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=1
Jul 23 13:26:35.466870 io-181-1563-BGP_65500_64500.192.168.100.1: Success: Initialized queue 1
Jul 23 13:26:35.466873 io-181-1563-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=2
Jul 23 13:26:35.466882 io-181-1563-BGP_65500_64500.192.168.100.1: Success: Initialized queue 2
Jul 23 13:26:35.466889 io-181-1563-BGP_65500_64500.192.168.100.1: Success: Encoded msg op=3
Jul 23 13:26:35.466917 io-181-1563-BGP_65500_64500.192.168.100.1: Success: Created session
Jul 23 13:26:35.466920 bgp_thrio_peer_init: peer 192.168.100.1 (External AS 65500): Initialized I/O session
Jul 23 13:26:35.466927 BGP_65500_64500.192.168.100.1: send proc: send via threaded I/O
Jul 23 13:26:35.466929 sending 19 bytes
Jul 23 13:26:35.466932
Jul 23 13:26:35.466932 BGP SEND 192.168.1.1+179 -> 192.168.100.1+53957
Jul 23 13:26:35.466934 BGP SEND message type 4 (KeepAlive) length 19
Jul 23 13:26:35.466950 bgp_thrio_write_batch:5013: 192.168.100.1 (External AS 65500): Wrote to batch: pdus=1, bytes=19 scheduled flush, res=36
Jul 23 13:26:35.466953 wrote 19 bytes to I/O queue
Jul 23 13:26:35.466955 finished number of messages 1, write qidx 1 rc 1
Jul 23 13:26:35.467128 io-181-1563-BGP_65500_64500.192.168.100.1: Success: Session create done - session enabled
Jul 23 13:26:35.467133 BGP peer 192.168.100.1 (External AS 65500): Threaded I/O session create done - State 2
Jul 23 13:26:35.467157 io-181-1563-BGP_65500_64500.192.168.100.1: Success: posted read request data=0x7fffffffde30, aux=0x0, msg=0xa4a1964, qidx=2
Jul 23 13:26:35.467162 io-181-1563-BGP_65500_64500.192.168.100.1: Processed Session create response, msgid = 43564
Jul 23 13:26:35.466974 task_set_socket: task BGP_65500_64500.192.168.100.1 socket 181 {bgp-io}
Jul 23 13:26:35.467013 task_timer_ucreate: created timer BGP_65500_64500.192.168.100.1_Task parent flags <> {bgp-io}
Jul 23 13:26:35.467017 task_timer_ucreate: created timer BGP_65500_64500.192.168.100.1_Keepalive flags <> {bgp-io}
Jul 23 13:26:35.467020 task_timer_ucreate: created timer BGP_65500_64500.192.168.100.1_Hold flags <> {bgp-io}
Jul 23 13:26:35.467025 task_timer_uset: timer BGP_65500_64500.192.168.100.1_Hold <Touched> set to interval 0 offset 1:30 with jitter 0 at 13:28:05.466942 {bgp-io}
Jul 23 13:26:35.467029 task_timer_reset: reset BGP_65500_64500.192.168.100.1_Hold {bgp-io}
Jul 23 13:26:35.467056 task_timer_reset: reset BGP_65500_64500.192.168.100.1_Keepalive {bgp-io}
Jul 23 13:26:35.467060 task_timer_uset_interval_latest: timer BGP_65500_64500.192.168.100.1_Keepalive interval set to 26.206045 {bgp-io}
Jul 23 13:26:35.467063 task_timer_reset: reset BGP_65500_64500.192.168.100.1_Hold {bgp-io}
Jul 23 13:26:35.467067 task_timer_set_oneshot_latest: timer BGP_65500_64500.192.168.100.1_Hold interval set to 1:30 {bgp-io}
Jul 23 13:26:35.467074 {bgp-io} th-181-1563-BGP_65500_64500.192.168.100.1: SessionFSM: Event 2, State Initial: Enabled @bgp-io
Jul 23 13:26:35.669751 io-181-1563-BGP_65500_64500.192.168.100.1: Success: posted write n=1, data=0x7fffffffe250, aux=0x7fffffffe240
Jul 23 13:26:35.669759 bgp_thrio_write_batch_user_flush:5086: 181-1563-BGP_65500_64500.192.168.100.1: Queue 1: Flush # 1: pdus=1, total pdus=1 res=0
Jul 23 13:26:35.669932 io-181-1563-BGP_65500_64500.192.168.100.1: Handling session msg for queue 1, call user to start job and deregister handler
Jul 23 13:26:35.669941 BGP peer 192.168.100.1 (External AS 65500): started write response process job 0x5615140
Jul 23 13:26:35.669993 io-181-1563-BGP_65500_64500.192.168.100.1: Got write response, qidx=1, msgid=1, niov=1, nbytes=8, err=0
Jul 23 13:26:35.669999 io-181-1563-BGP_65500_64500.192.168.100.1: EOF write response messages
Jul 23 13:26:35.670005 io-181-1563-BGP_65500_64500.192.168.100.1: Response processing done for queue 1, re-register handler for new msgs
Jul 23 13:26:35.670008 bgp_thrio_write_ready:5133: 192.168.100.1 (External AS 65500): write batch pdus=0
Jul 23 13:26:35.670012 bgp_write_ready:3751: 192.168.100.1 (External AS 65500): Write ready, inserted in act list, write job started
Jul 23 13:26:35.670021 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 16 is 268435455
Jul 23 13:26:35.670024 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 15 is 268435455
Jul 23 13:26:35.670026 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 14 is 268435455
Jul 23 13:26:35.670028 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 13 is 268435455
Jul 23 13:26:35.670030 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 12 is 268435455
Jul 23 13:26:35.670032 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 11 is 268435455
Jul 23 13:26:35.670046 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 10 is 268435455
Jul 23 13:26:35.670048 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 9 is 268435455
Jul 23 13:26:35.670050 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 8 is 268435455
Jul 23 13:26:35.670052 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 7 is 268435455
Jul 23 13:26:35.670054 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 6 is 268435455
Jul 23 13:26:35.670056 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 5 is 268435455
Jul 23 13:26:35.670058 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 4 is 268435455
Jul 23 13:26:35.670060 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 3 is 268435455
Jul 23 13:26:35.670062 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 2 is 268435455
Jul 23 13:26:35.670064 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 1 is 268435455
Jul 23 13:26:35.670066 bgp_write:3386 group=group CLOUDFLARE-RR-1 type External, min ribix for priority 0 is 268435455
Jul 23 13:26:35.670069 bgp_write:3409: 192.168.100.1 (External AS 65500): removed from active list
Jul 23 13:26:35.670072 bgp_rt_send_active:4152: group=group CLOUDFLARE-RR-1 type External, priorities not done=0
Jul 23 13:26:35.670079 task_timer_ucreate: created timer BGP_Group_CLOUDFLARE-RR-1_Route flags <>
Jul 23 13:26:35.670133 task_timer_uset: timer BGP_Group_CLOUDFLARE-RR-1_Route <Touched> set to interval 0 offset 1 with jitter 0 at 13:26:36.670068
Jul 23 13:26:35.670136 bgp_rt_send_active:4303: group CLOUDFLARE-RR-1 type External: END, status=0x0
Jul 23 13:26:35.670139 bgp_write: group group CLOUDFLARE-RR-1 type External: wrote routes, status = 0x0
Jul 23 13:26:35.670141 bgp_write:3696 deleting job for group group CLOUDFLARE-RR-1 type External; setting timer with rto_next_time 33014000
Jul 23 13:26:35.669806 task_job_create_background: create prio 4 job wr_req_proc for task BGP_65500_64500.192.168.100.1 {bgp-io}
Jul 23 13:26:35.669815 {bgp-io} th-181-1563-BGP_65500_64500.192.168.100.1: Start write processing job: wrfsm state was: WaitReq @bgp-io
Jul 23 13:26:35.669823 {bgp-io} th-181-1563-BGP_65500_64500.192.168.100.1: Session queue 1: State Run, Event SESSOPER_EV_REQRDY, trans = yes @bgp-io
Jul 23 13:26:35.669853 background dispatch running job wr_req_proc for task BGP_65500_64500.192.168.100.1 {bgp-io}
Jul 23 13:26:35.669857 bgp_io_write_stage_init:4161: 181-1563-BGP_65500_64500.192.168.100.1: Write stage bytes=0, iovcnt=0, msgs=0, in_msg=0x0 req pdu boundary = N {bgp-io}
Jul 23 13:26:35.669863 bgp_io_write_stage_init:4232: 181-1563-BGP_65500_64500.192.168.100.1: Added msg[1] 0xa4a2864 to write stage bytes=19, iovcnt=1, msgs=1 curridx=1 {bgp-io}
Jul 23 13:26:35.669866 bgp_io_write_stage_init:4253: 181-1563-BGP_65500_64500.192.168.100.1: Initialized write stage bytes=19, iovcnt=1, msgs=1 {bgp-io}
Jul 23 13:26:35.669868 bgp_io_socket_write:4330:181-1563-BGP_65500_64500.192.168.100.1: fd=181, niov=1/1, to_write_bytes=19, to_write_msgs=1, iov_len=19 {bgp-io}
Jul 23 13:26:35.669879 bgp_io_socket_write:4340:181-1563-BGP_65500_64500.192.168.100.1: task_socket_writev - fd=181, len=19, errno=0, se=0 {bgp-io}
Jul 23 13:26:35.669902 bgp_io_write_user_handler_int:4551: 181-1563-BGP_65500_64500.192.168.100.1: Write completed for msgid=1, response sent {bgp-io}
Jul 23 13:26:35.669904 bgp_io_write_user_handler_int:4610: 181-1563-BGP_65500_64500.192.168.100.1: Write done - res=0, full pdu, bytes=19, pdus=1 {bgp-io}
Jul 23 13:26:35.669908 bgp_io_write_stage_init:4161: 181-1563-BGP_65500_64500.192.168.100.1: Write stage bytes=0, iovcnt=0, msgs=0, in_msg=0x0 req pdu boundary = N {bgp-io}
Jul 23 13:26:35.669910 bgp_io_write_stage_init:4253: 181-1563-BGP_65500_64500.192.168.100.1: Initialized write stage bytes=0, iovcnt=0, msgs=0 {bgp-io}
Jul 23 13:26:35.669913 bgp_io_write_user_handler_int:4454: 181-1563-BGP_65500_64500.192.168.100.1: No more write requests {bgp-io}
Jul 23 13:26:35.669915 bgp_io_write_user_handler_int:4610: 181-1563-BGP_65500_64500.192.168.100.1: Write done - res=2, full pdu, bytes=0, pdus=0 {bgp-io}
Jul 23 13:26:35.669920 {bgp-io} th-181-1563-BGP_65500_64500.192.168.100.1: Write requests done: wrote 1 pdus, 19 bytes, @bgp-io
Jul 23 13:26:35.669924 task_job_delete: delete background job wr_req_proc for task BGP_65500_64500.192.168.100.1 {bgp-io}
Jul 23 13:26:35.669927 background dispatch completed job wr_req_proc for task BGP_65500_64500.192.168.100.1 {bgp-io}
Jul 23 13:26:35.751928 io-181-1563-BGP_65500_64500.192.168.100.1: Handling session msg for queue 2, call user to start job and deregister handler
Jul 23 13:26:35.751941 BGP peer 192.168.100.1 (External AS 65500): started read response process job 0x4852f00
Jul 23 13:26:35.751995 io-181-1563-BGP_65500_64500.192.168.100.1: Got inbound PDU, qidx=2, msgid=1, type=1, niov=1, nbytes=0, err=0
Jul 23 13:26:35.751998 bgp_read_resp_process_internal:1382: 192.168.100.1 (External AS 65500): skip empty read resp msg, type=1, id=1
Jul 23 13:26:35.752004 io-181-1563-BGP_65500_64500.192.168.100.1: Got inbound PDU, qidx=2, msgid=1, type=3, niov=1, nbytes=21, err=0
Jul 23 13:26:35.752006 bgp_read_resp_process_internal:1397: 192.168.100.1 (External AS 65500): npdus=1, pdubuf=0xa65c000 iovbase=0xa65c000, iovlen=21
Jul 23 13:26:35.752010
Jul 23 13:26:35.752010 BGP RECV 192.168.100.1+53957 -> 192.168.1.1+179
Jul 23 13:26:35.752013 BGP RECV message type 3 (Notification) length 21
Jul 23 13:26:35.752018 BGP RECV Notification code 2 (Open Message Error) subcode 2 (bad peer AS number)
Jul 23 13:26:35.752077 bgp_handle_notify:4300: NOTIFICATION received from 192.168.100.1 (External AS 65500): code 2 (Open Message Error) subcode 2 (bad peer AS number)
Jul 23 13:26:35.752084 Notify received from 192.168.100.1 (External AS 65500), code 2, subcode 2
Jul 23 13:26:35.752087
Jul 23 13:26:35.752087 BGP RECV 192.168.100.1+53957 -> 192.168.1.1+179
Jul 23 13:26:35.752100 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 15 03 02 02
Jul 23 13:26:35.752106 bgp_peer_close_and_restart: peer 192.168.100.1 (External AS 65500), state is 5 (OpenConfirm) event RecvNotify, flags=0x0
Jul 23 13:26:35.752108 bgp_peer_close_and_restart: closing peer 192.168.100.1 (External AS 65500), state is 5 (OpenConfirm) event RecvNotify
Jul 23 13:26:35.752112 bgp_send_deactivate:2671: 192.168.100.1 (External AS 65500) ,flags=0x0: removed from active list
Jul 23 13:26:35.752122 task_timer_delete: BGP_Group_CLOUDFLARE-RR-1_Route <Touched>
Jul 23 13:26:35.752130 bgp_event: peer 192.168.100.1 (External AS 65500) old state OpenConfirm event RecvNotify new state Idle
Jul 23 13:26:35.752316 bgp_peer_close_and_restart: 7709: BGP peer 192.168.100.1 (External AS 65500): state Idle task close fd 181
Jul 23 13:26:35.752320 bgp_thrio_peer_delete_internal:2799: BGP peer 192.168.100.1 (External AS 65500) CLOSE:, error 0, delete I/O session
Jul 23 13:26:35.752328 XXio-181-1563-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=0
Jul 23 13:26:35.752332 XXio-181-1563-BGP_65500_64500.192.168.100.1: I/O queue idx 0 stopped
Jul 23 13:26:35.752336 XXio-181-1563-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=1
Jul 23 13:26:35.752341 XXio-181-1563-BGP_65500_64500.192.168.100.1: I/O queue idx 1 stopped
Jul 23 13:26:35.752344 XXio-181-1563-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=2
Jul 23 13:26:35.752347 XXio-181-1563-BGP_65500_64500.192.168.100.1: I/O queue idx 2 stopped
Jul 23 13:26:35.752353 XXio-181-1563-BGP_65500_64500.192.168.100.1: Success: Encoded msg op=4
Jul 23 13:26:35.752375 XXio-181-1563-BGP_65500_64500.192.168.100.1: Success: Started session delete
Jul 23 13:26:35.752571 XXio-181-1563-BGP_65500_64500.192.168.100.1: Processing Session delete response, msgid = 43565
Jul 23 13:26:35.752576 XXio-181-1563-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=0
Jul 23 13:26:35.752579 XXio-181-1563-BGP_65500_64500.192.168.100.1: I/O queue idx 0 stopped
Jul 23 13:26:35.752582 XXio-181-1563-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=1
Jul 23 13:26:35.752585 XXio-181-1563-BGP_65500_64500.192.168.100.1: I/O queue idx 1 stopped
Jul 23 13:26:35.752588 XXio-181-1563-BGP_65500_64500.192.168.100.1: Set queue attrs qidx=2
Jul 23 13:26:35.752591 XXio-181-1563-BGP_65500_64500.192.168.100.1: I/O queue idx 2 stopped
Jul 23 13:26:35.752594 XXio-181-1563-BGP_65500_64500.192.168.100.1: task socket 181 close
Jul 23 13:26:35.752623 task_close: close socket 181 task BGP_65500_64500.192.168.100.1
Jul 23 13:26:35.752626 task_reset_socket: task BGP_65500_64500.192.168.100.1 socket 181
Jul 23 13:26:35.752662 BGP peer 192.168.100.1 (External AS 65500) CLOSE: Threaded I/O session delete done event - do user cleanup
Jul 23 13:26:35.752668 XXio-181-1563-BGP_65500_64500.192.168.100.1: EOF write response messages
Jul 23 13:26:35.752672 XXio-181-1563-BGP_65500_64500.192.168.100.1: EOF write response messages
Jul 23 13:26:35.752675 XXio-181-1563-BGP_65500_64500.192.168.100.1: EOF read messages
Jul 23 13:26:35.752678 BGP peer 192.168.100.1 (External AS 65500) CLOSE: Unlink the I/O session
Jul 23 13:26:35.752686 BGP peer 192.168.100.1 (External AS 65500) CLOSE: Check proceed with close? Rt terminate=Complete, I/O session cleanup=Complete
Jul 23 13:26:35.752692 bgp_peer_post_close: Cleanup complete for peer 192.168.100.1 (last_flap NoEvent, state Idle, flags )
Jul 23 13:26:35.752699 bgp_peer_post_close:7332 BGP Peer 192.168.100.1 (External AS 65500) CLOSE: post close cleanup - NEED restart, (last_flap NoEvent, state Idle, flags )
Jul 23 13:26:35.752712 task_timer_uset: timer BGP_65500_64500.192.168.100.1_Down Peer Timer <Touched> set to interval 0 offset 2:00 with jitter 0 at 13:28:35.752550
Jul 23 13:26:35.752715 bgp_event: peer 192.168.100.1 (External AS 65500) old state Idle event Start new state Active
Jul 23 13:26:35.752720 task_timer_ucreate: created timer BGP_65500_64500.192.168.100.1_Connect flags <>
Jul 23 13:26:35.752723 task_timer_uset: timer BGP_65500_64500.192.168.100.1_Connect <Touched> set to interval 0 offset 2:28 with jitter 0 at 13:29:03.752550
Jul 23 13:26:35.752748 XXio-181-1563-BGP_65500_64500.192.168.100.1: Session deleted
Jul 23 13:26:35.751816 task_process_events_internal: recv ready for BGP_65500_64500.192.168.100.1 {bgp-io}
Jul 23 13:26:35.751830 task_job_create_background: create prio 2 job rd_req_proc for task BGP_65500_64500.192.168.100.1 {bgp-io}
Jul 23 13:26:35.751836 {bgp-io} th-181-1563-BGP_65500_64500.192.168.100.1: Start read processing job, rdfsm state was: WaitSys @bgp-io
Jul 23 13:26:35.751844 background dispatch running job rd_req_proc for task BGP_65500_64500.192.168.100.1 {bgp-io}
Jul 23 13:26:35.751848 bgp_io_read_req_cb:6170: 181-1563-BGP_65500_64500.192.168.100.1: Calling user read cb: req pdu boundary = N, read at pdu boundary = N {bgp-io}
Jul 23 13:26:35.751855 {bgp-io} th-181-1563-BGP_65500_64500.192.168.100.1: Received msg 0xa4a1964 from IO queue 2 @bgp-io
Jul 23 13:26:35.751880 bgp_io_read_single_pdu:5979: 181-1563-BGP_65500_64500.192.168.100.1: Current bytes in stage = 0 {bgp-io}
Jul 23 13:26:35.751888 bgp_io_read_stage_init:5384: 181-1563-BGP_65500_64500.192.168.100.1: Initializing read stage: curr bytes = 0, to read 19 {bgp-io}
Jul 23 13:26:35.751891 bgp_io_read_socket:5284: fd=181, to_read_bytes=19 {bgp-io}
Jul 23 13:26:35.751908 bgp_io_read_socket:5292: task_socket_read - fd=181, len=19, errno=0, se=0, buf=0xa65c000 {bgp-io}
Jul 23 13:26:35.751911 bgp_io_read_send_resp:5647: 181-1563-BGP_65500_64500.192.168.100.1: No full PDU in read stage, nothing to send {bgp-io}
Jul 23 13:26:35.751914 bgp_io_read_post_process:5856: 181-1563-BGP_65500_64500.192.168.100.1: Read blocked, Parsing reached partial PDU {bgp-io}
Jul 23 13:26:35.751916 bgp_io_read_stage_init:5384: 181-1563-BGP_65500_64500.192.168.100.1: Initializing read stage: curr bytes = 19, to read 2 {bgp-io}
Jul 23 13:26:35.751918 bgp_io_read_socket:5284: fd=181, to_read_bytes=2 {bgp-io}
Jul 23 13:26:35.751923 bgp_io_read_socket:5292: task_socket_read - fd=181, len=2, errno=0, se=0, buf=0xa65c013 {bgp-io}
Jul 23 13:26:35.751925 bgp_io_read_post_process:5863: 181-1563-BGP_65500_64500.192.168.100.1: Read, user asked for session disable {bgp-io}
Jul 23 13:26:35.751935 {bgp-io} th-181-1563-BGP_65500_64500.192.168.100.1: Success: posted read: n=1, data=0x7fffff3fc0f0, aux=0x7fffff3fc100 @bgp-io
Jul 23 13:26:35.751938 bgp_io_read_send_resp:5684: 181-1563-BGP_65500_64500.192.168.100.1: Read stage: pdus, 1 pdus, 21 bytes, response send result=0, partial bytes=0 {bgp-io}
Jul 23 13:26:35.751941 bgp_io_read_single_pdu:6007: 181-1563-BGP_65500_64500.192.168.100.1: res=22 {bgp-io}
Jul 23 13:26:35.751945 task_timer_reset: reset BGP_65500_64500.192.168.100.1_Hold {bgp-io}
Jul 23 13:26:35.751951 task_timer_reset: reset BGP_65500_64500.192.168.100.1_Hold {bgp-io}
Jul 23 13:26:35.751954 task_timer_set_oneshot_latest: timer BGP_65500_64500.192.168.100.1_Hold interval set to 1:30 {bgp-io}
Jul 23 13:26:35.751957 bgp_io_read_req_cb:6257: 181-1563-BGP_65500_64500.192.168.100.1: Read some bytes 2, reset the Hold-timer {bgp-io}
Jul 23 13:26:35.751959 bgp_io_read_req_cb:6265: 181-1563-BGP_65500_64500.192.168.100.1: user read cb: req pdu boundary = N, read at pdu boundary = Y, res = 22, recv_bytes=2, inbytes=21, inmsgs=1 {bgp-io}
Jul 23 13:26:35.751963 {bgp-io} th-181-1563-BGP_65500_64500.192.168.100.1: Fail: user asked to disable further reads, wait for user @bgp-io
Jul 23 13:26:35.751968 {bgp-io} th-181-1563-BGP_65500_64500.192.168.100.1: readFSM Disabling immediately: Event 10, State Run @bgp-io
Jul 23 13:26:35.751970 task_job_delete: delete background job rd_req_proc for task BGP_65500_64500.192.168.100.1 {bgp-io}
Jul 23 13:26:35.751975 {bgp-io} th-181-1563-BGP_65500_64500.192.168.100.1: readFSM Disable done: Event 10, State Run @bgp-io
Jul 23 13:26:35.751978 background dispatch completed job rd_req_proc for task BGP_65500_64500.192.168.100.1 {bgp-io}
Jul 23 13:26:35.752404 task_timer_reset: reset BGP_65500_64500.192.168.100.1_Keepalive {bgp-io}
Jul 23 13:26:35.752408 task_timer_reset: reset BGP_65500_64500.192.168.100.1_Hold {bgp-io}
Jul 23 13:26:35.752413 {bgp-io} XXth-181-1563-BGP_65500_64500.192.168.100.1: Disabled status @bgp-io
Jul 23 13:26:35.752418 {bgp-io} XXth-181-1563-BGP_65500_64500.192.168.100.1: writeFSM Event 0, State WaitReq: trigger sessionFSM disable done event @bgp-io
Jul 23 13:26:35.752422 {bgp-io} XXth-181-1563-BGP_65500_64500.192.168.100.1: SessionFSM: Event 3, State Enabled: deleting @bgp-io
Jul 23 13:26:35.752426 {bgp-io} XXth-181-1563-BGP_65500_64500.192.168.100.1: SessionFSM: Event 1, State Deleting: done @bgp-io
Jul 23 13:26:35.752431 {bgp-io} XXth-181-1563-BGP_65500_64500.192.168.100.1: Session delete start final actions, pending req: 0x6e74808(4) @bgp-io
Jul 23 13:26:35.752444 task_timer_delete: BGP_65500_64500.192.168.100.1_Keepalive <Latest Touched> {bgp-io}
Jul 23 13:26:35.752448 task_timer_delete: BGP_65500_64500.192.168.100.1_Hold <Touched> {bgp-io}
Jul 23 13:28:35.754638 bgp_down_peer_timeout: BGP_65500_64500.192.168.100.1_Down Peer Timer
Jul 23 13:28:35.754646 bgp_delete_down_peer_timer: peer 192.168.100.1 (External AS 65500), timer 0x23becb140, ignore-down:0, state:3
Jul 23 13:28:35.754651 task_timer_delete: BGP_65500_64500.192.168.100.1_Down Peer Timer <Processing>
Thank you.
------------------------------
KAIWEI TU
------------------------------
Original Message:
Sent: 07-10-2024 04:11
From: Andrei Cebotareanu
Subject: BGP AS23456 questions
Hi,
have you tried to disable 4Byte support with this peer?
https://www.juniper.net/documentation/us/en/software/junos/cli-reference/topics/ref/statement/disable-4byte-as.html
BR
------------------------------
Andrei Cebotareanu
Original Message:
Sent: 07-09-2024 12:06
From: KAIWEI TU
Subject: BGP AS23456 questions
Hi Georgi,
Thank you for the response.
I just noticed that I forgot to mention that the problematic router is running JUNOS 21.4r3 which I think the 4-byte ASN is supported.
The router that can establish BGP peer without a problem also runs the same version of JUNOS.
Nothing related to BGP is different.
The BGP configuration is pretty simple.
Just Like this
edit protocol bgp group ISPset local-address [our router IP]set neighbor [our ISP IP]set peer-as [2-byte AS of ISP]set local-as [2-byte AS of us]
This is not the first time I have encountered this problem.
I also have this problem when peering with the member in IX sometimes.
Best regards,
James
------------------------------
KAIWEI TU
Original Message:
Sent: 07-09-2024 09:50
From: GEORGI SINAPOV
Subject: BGP AS23456 questions
Greetings.
AS23456 is 2-byte AS, which is used as 4-byte AS substitute. The first peer supports 4-byte AS. The second one – doesn't. You need to setup a proper 2-byte AS for the second peering on your side.
Best e-gards,
Georgi Sinapov
Core Network Architect
Original Message:
Sent: 7/9/2024 6:29:00 AM
From: KAIWEI TU
Subject: BGP AS23456 questions
Hi Team,
I met a very strange issue and couldn't find out the root cause.
The BGP session can not be established and my ISP shared this log message with us.
Reserved AS_TRANS(23456) cannot be used as the AS of any BGP Speaker (Used for 4 byte AS extension only)
However, we use 2 bytes AS to peer with our ISP, and our ISP also uses 2 bytes AS
More interesting is we have another router using the same BGP configuration to peer with the same router of our ISP and it's successfully established.
Anywhere I should check further about this issue?
Thank you.
Best regards,
James
------------------------------
KAIWEI TU
------------------------------