RP/0/RP0/CPU0:PE2#show bgp trace | utility tail -n 150 Thu Oct 15 12:56:40.089 UTC Oct 15 12:48:50.256 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4697 [EV]:1067: IDB: msg opcode type: create, ifhhandle: 0x8, state: unknown Oct 15 12:48:50.257 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4697 [EV]:1027: IDB: rx-ed IMC bulk notif, 1 events Oct 15 12:48:50.257 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4697 [EV]:1040: IDB: msg opcode type: state value, ifhhandle: 0x8, state: up Oct 15 12:48:50.257 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4697 [EV]:1027: IDB: rx-ed IMC bulk notif, 1 events Oct 15 12:48:51.254 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:7958: trying to find update group for nbr 0x75b1a53614c0, afi All Oct 15 12:48:51.254 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:6921: created update group for table TBL:CUST-A (1/1), index 0.2, nbr 172.16.2.2, flags 0x4000 Oct 15 12:48:51.254 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:6967: Delete update group for table TBL:CUST-A (1/1), index 0.1 Oct 15 12:48:51.255 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:1476: Filter-group op (Alloc) Tbl/Nbr(TBL:CUST-A (1/1)) fgrp idx 0.1 subgrp idx 0.1 updgrp 0.0 rtset 2 Oct 15 12:48:51.255 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:2792: Filter-group op (Filter-group Add Nbr new) Tbl/Nbr(Afi:IPv4 Unicast:Vrf:CUST-A:Nbr:172.16.2.2) fgrp idx 0.1 subgrp idx 0.1 updgrp 0.2 rtset 0 Oct 15 12:48:51.255 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:2818: created filtergrp 1 for vrf 0x60000002 nbr 172.16.2.2, afi 0, subgrp version 0, refresh 0 Oct 15 12:48:51.255 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:4592: Created subgrp:1(0x75b15800e790) refr:0 for nbr 172.16.2.2 (vrf CUST-A), afi 0 version 0 Oct 15 12:48:51.255 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:7104: added vrf 0x60000002 nbr 172.16.2.2 to update group 0.2, afi IPv4 Unicast, flags 0x4800 Oct 15 12:48:52.769 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4692 [EV]:2016: Inside bgp_process_nbrwait_timer, nbrwait timer fired, evt-in-nbrwait 1 Oct 15 12:48:52.771 default-bgp/spkr-tr2-ha 0/RP0/CPU0 t4692 [HA]:2024: called sysmgr_proc_available with success, loc 3 Oct 15 12:48:52.771 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4692 [EV]:2030: Notified SysMgr of availability (Nbrs up) Oct 15 12:48:58.692 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4697 [EV]:2266: GW Cache: lsd conn event: 1 Oct 15 12:48:58.692 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4679 [EV]:11913: bgp label handle lsd event: UP Oct 15 12:48:58.693 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4679 [EV]:11983: bgp label start rsrc-complete notif timer - reason 1 value 1500 sec Oct 15 12:48:58.693 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4679 [EV]:11294: bgp label start reclaim walk Oct 15 12:49:26.578 bgp/bpm-tr2-apic 0/RP0/CPU0 t4639 [AIPC]:584: bpm chkpt remove: inst-id 0, buff-seq 5, total count 23, delete count 23, ok 1 Oct 15 12:49:26.578 bgp/bpm-tr2-apic 0/RP0/CPU0 t4639 [AIPC]:210: bpm txlist show:loc 3 [1:txlist-handler, 2:conn-up 3:timer-cleanup] active-mem 1, suspend-mem 0, end-list 1, remove-mem 1, elements 0 Oct 15 12:49:26.578 bgp/bpm-tr2-apic 0/RP0/CPU0 t4639 [AIPC]:913: func txlist_timer_expiry, event restart, p1 1 p2 60 p3 1 Oct 15 12:49:42.571 default-bgp/spkr-tr2-nbr 0/RP0/CPU0 t4691 [NBR]:1431: TBL:default (1/128), EOR rx-ed from vrf 0x60000000 nbr '1.1.1.1', afi:4, accepted prefix count:0, explicit:0 Oct 15 12:49:49.301 default-bgp/spkr-tr2-nbr 0/RP0/CPU0 t4691 [NBR]:1431: TBL:CUST-A (1/1), EOR rx-ed from vrf 0x60000002 nbr '172.16.2.2', afi:0, accepted prefix count:0, explicit:0 Oct 15 12:49:49.503 default-bgp/spkr-tr2-nbr 0/RP0/CPU0 t4693 [NBR]:1431: TBL:CUST-A (1/1), EOR rx-ed from vrf 0x60000002 nbr '172.16.2.2', afi:0, accepted prefix count:1, explicit:1 Oct 15 12:50:03.861 default-bgp/spkr-tr2-nh 0/RP0/CPU0 t4697 [NH]:6167: nexthop notif: VRF 0x60000000, 4.4.4.4/32 is now not connected, non-local, reachable, with metric 3, admin distance 110 andifhandle 0x00000010 nh_id 0x0, af_user_bits 0x0, change:1 Oct 15 12:50:05.073 default-bgp/spkr-tr2-gen 0/RP0/CPU0 t4648 [GEN]:634: vrf 0x60000000 nbr 4.4.4.4, old state 1, new state 3, fd type 2, fd 0 Oct 15 12:50:05.137 default-bgp/spkr-tr2-gen 0/RP0/CPU0 t4648 [IO]:11323: Nbr '4.4.4.4': Loc 3: Determined lport/fport 40201/179 Oct 15 12:50:05.137 default-bgp/spkr-tr2-nbr 0/RP0/CPU0 t4648 [NBR]:11331: send open nbr: 4.4.4.4, loc 1 Oct 15 12:50:05.137 default-bgp/spkr-tr2-gen 0/RP0/CPU0 t4648 [GEN]:2651: OPEN 'to' '4.4.4.4' vrf_id 0x60000000 has EXTENDED NEXTHOP ENCODING cap for afi/safi/nexthop_afi: 1/128/2 Oct 15 12:50:05.137 default-bgp/spkr-tr2-gen 0/RP0/CPU0 t4648 [GEN]:634: vrf 0x60000000 nbr 4.4.4.4, old state 3, new state 4, fd type 1, fd 1000305 Oct 15 12:50:07.151 default-bgp/spkr-tr2-gen 0/RP0/CPU0 t4691 [GEN]:1449: OPEN 'from' '4.4.4.4' vrf_id 0x60000000 has EXTENDED NEXTHOP ENCODING cap for afi/safi/nexthop_afi: 1/1/2 Oct 15 12:50:07.151 default-bgp/spkr-tr2-gen 0/RP0/CPU0 t4691 [GEN]:1449: OPEN 'from' '4.4.4.4' vrf_id 0x60000000 has EXTENDED NEXTHOP ENCODING cap for afi/safi/nexthop_afi: 1/2/2 Oct 15 12:50:07.151 default-bgp/spkr-tr2-gen 0/RP0/CPU0 t4691 [GEN]:1449: OPEN 'from' '4.4.4.4' vrf_id 0x60000000 has EXTENDED NEXTHOP ENCODING cap for afi/safi/nexthop_afi: 1/128/2 Oct 15 12:50:07.151 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4691 [UPD]:2111: updgrp change scheduled (0:no/1:yes):1, after open processing, nbr 4.4.4.4, flags 0x8310000 Oct 15 12:50:07.151 default-bgp/spkr-tr2-gen 0/RP0/CPU0 t4691 [GEN]:634: vrf 0x60000000 nbr 4.4.4.4, old state 4, new state 5, fd type 1, fd 1000305 Oct 15 12:50:07.151 default-bgp/spkr-tr2-nbr 0/RP0/CPU0 t4691 [NBR]:2714: send keepalive nbr: 4.4.4.4, loc 1 Oct 15 12:50:07.160 default-bgp/spkr-tr2-gen 0/RP0/CPU0 t4691 [GEN]:634: vrf 0x60000000 nbr 4.4.4.4, old state 5, new state 6, fd type 1, fd 1000305 Oct 15 12:50:07.160 default-bgp/spkr-tr2-gen 0/RP0/CPU0 t4691 [GEN]:646: vrf 0x60000000 nbr '4.4.4.4' established, ptr 0x75b1a5363000 Oct 15 12:50:07.160 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4691 [EV]:2499: Inside scan_adjust_estab_outstanding for vrf 0x60000000 nbr 4.4.4.4, nbr-down 0, state 2, evt-in-nbrwait 0 Oct 15 12:50:09.151 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:7958: trying to find update group for nbr 0x75b1a5363000, afi All Oct 15 12:50:09.151 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:6967: Delete update group for table TBL:default (1/128), index 0.1 Oct 15 12:50:09.151 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:2701: Filter-group op (Filter-group Add Nbr exst) Tbl/Nbr(Afi:VPNv4 Unicast:Vrf:default:Nbr:4.4.4.4) fgrp idx 0.1 subgrp idx 0.1 updgrp 0.2 rtset 0 Oct 15 12:50:09.151 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:7104: added vrf 0x60000000 nbr 4.4.4.4 to update group 0.2, afi VPNv4 Unicast, flags 0x104983 Oct 15 12:50:14.997 default-bgp/spkr-tr2-table 0/RP0/CPU0 t4693 [TABLE]:2883: state change rdinfo: 0x75b1879dee88, old flags:0x2, new flags:0x2 rd_state:1 Oct 15 12:50:14.998 default-bgp/spkr-tr2-table 0/RP0/CPU0 t4693 [TABLE]:2883: state change rdinfo: 0x75b1879dee00, old flags:0x2, new flags:0x2 rd_state:1 Oct 15 12:50:14.998 default-bgp/spkr-tr2-nbr 0/RP0/CPU0 t4693 [NBR]:1431: TBL:default (1/128), EOR rx-ed from vrf 0x60000000 nbr '1.1.1.1', afi:4, accepted prefix count:2, explicit:1 Oct 15 12:50:26.579 bgp/bpm-tr2-apic 0/RP0/CPU0 t4639 [AIPC]:210: bpm txlist show:loc 3 [1:txlist-handler, 2:conn-up 3:timer-cleanup] active-mem 1, suspend-mem 0, end-list 1, remove-mem 0, elements 0 Oct 15 12:50:29.870 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4698 [EV]:3683: Update delay timer expired for afi 4 Oct 15 12:50:29.870 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4698 [EV]:3700: Trigger exit RO mode for afi VPNv4 Unicast, loc 4 Oct 15 12:50:29.870 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4698 [SYNC]:1792: NSR event: 'End of read-only' on active Oct 15 12:50:29.870 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4696 [SYNC]:6368: active NSR state transition for 'Standby Sync-group', event 'End of read-only', 'None' -> 'Active Ready', mask 0x2 Oct 15 12:50:29.870 default-bgp/spkr-tr2-sr 0/RP0/CPU0 t4697 [SR]:724: SR-policy XTC send EoD notif to XTC Oct 15 12:50:29.870 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4698 [LABEL]:12425: 0 RPC set entries found (error: iter 0, data 0) in chkpt database for table id 0x1e88 afi: 4 success: 1 Oct 15 12:50:29.870 default-bgp/spkr-tr2-l2vpn 0/RP0/CPU0 t4701 [L2VPN]:8653: EVPN GW Track:Recv Msg NH:,Track:0 Ifh:0x0 Conv:1 Oct 15 12:50:29.870 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4698 [LABEL]:12425: 0 RPC set entries found (error: iter 0, data 0) in chkpt database for table id 0x18a8 afi: 4 success: 1 Oct 15 12:50:29.870 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4698 [EV]:1282: Entering 'Bestpath Calculation' mode for AF 'VPNv4 Unicast' Oct 15 12:50:29.871 default-bgp/spkr-tr2-mvpn 0/RP0/CPU0 t4698 [MVPN]:4609: Update PIM RD msg 3 : afi 0, vrf CUST-A, rd 2ASN:65001:1, ret 0 Oct 15 12:50:29.871 default-bgp/spkr-tr2-mvpn 0/RP0/CPU0 t4698 [MVPN]:4966: Download vrf rd:vrf CUST-A, afi 4, rd 2ASN:65001:1 Oct 15 12:50:29.871 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4682 [EV]:19520: Entering 'Import' mode for AF 'VPNv4 Unicast' Oct 15 12:50:29.871 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4694 [EV]:7147: Import mode handler for af 'VPNv4 Unicast', loc 0, tablever 8 import ver 0 Oct 15 12:50:29.871 default-bgp/spkr-tr2-imp 0/RP0/CPU0 t4694 [IMPORT]:6748: Import walk: import ver 0 -> 8: 0 nets processed (0 paths updated) afi 4 forced/ms 1 Oct 15 12:50:29.872 default-bgp/spkr-tr2-mvpn 0/RP0/CPU0 t4698 [MVPN]:4078: BGP end readonly: force vpn table refresh, vpn afi 4, rc 0 Oct 15 12:50:29.872 default-bgp/spkr-tr2-imp 0/RP0/CPU0 t4694 [IMPORT]:6777: Import walk: import ver 0 -> 8: 6 nets processed (2 paths updated) afi 4 forced/ms 1 Oct 15 12:50:29.872 default-bgp/spkr-tr2-mvpn 0/RP0/CPU0 t4698 [MVPN]:1556: BGP end readonly: Scan force vpn refresh, vpn afi 4, rc 0 Oct 15 12:50:29.872 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4694 [EV]:7165: Import mode handler for af 'VPNv4 Unicast', loc 1, tablever 12 import ver 8 Oct 15 12:50:29.872 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4694 [EV]:7099: Try to enter 'Label Allocation' mode for AF 'VPNv4 Unicast', thread 4 Oct 15 12:50:29.872 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4694 [EV]:9672: Entering 'Label Allocation' mode for AF 'VPNv4 Unicast' Oct 15 12:50:29.872 default-bgp/spkr-tr2-imp 0/RP0/CPU0 t4694 [IMPORT]:6748: Import walk: import ver 8 -> 12: 0 nets processed (0 paths updated) afi 4 forced/ms 0 Oct 15 12:50:29.872 default-bgp/spkr-tr2-imp 0/RP0/CPU0 t4694 [IMPORT]:6777: Import walk: import ver 8 -> 12: 4 nets processed (0 paths updated) afi 4 forced/ms 0 Oct 15 12:50:29.872 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4679 [LABEL]:4366: Config release label mode for table 0xe0000002 (mode:6, 6, 6) flags:0x1, 0x0 Oct 15 12:50:29.873 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4679 [LABEL]:6244: Label RW request for table-id 0xe0000002 mode:0 Oct 15 12:50:29.874 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4679 [LABEL]:2178: Label change on table 0xe0000002 (old label:0, new label:24006) Oct 15 12:50:29.874 default-bgp/spkr-tr2-l2vpn 0/RP0/CPU0 t4679 [L2VPN]:5109: EVPN - L3 Label trigger: afi 0, encap 1 Oct 15 12:50:29.874 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4679 [LABEL]:2237: Allocated label 24006 VRF:(VRF 'TBL:CUST-A (1/1)') tbl_id:0xe0000002 flags1:0x201 flags2:0x0 mode:0 Oct 15 12:50:29.875 default-bgp/spkr-tr2-l2vpn 0/RP0/CPU0 t4701 [L2VPN]:5159: EVPN - Receive EVPN L3 Label Update: afi: 0 table_ctx: 0x75b1a4a7bcc8 VRF: CUST-A Oct 15 12:50:29.875 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4679 [EV]:963: Sent rsrc-complete notif to LSD Oct 15 12:50:29.875 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4679 [EV]:969: bgp label stop rsrc-complete notif timer - reason 1 Oct 15 12:50:29.876 default-bgp/spkr-tr2-sr 0/RP0/CPU0 t4697 [SR]:913: SR-policy XTC got EoD notif from XTC: 1 Oct 15 12:50:29.876 default-bgp/spkr-tr2-sr 0/RP0/CPU0 t4697 [SR]:1713: SR-policy XTC stale NH tunnels sweeped, trigger nh walk 0 Oct 15 12:50:29.876 default-bgp/spkr-tr2-sr 0/RP0/CPU0 t4697 [SR]:1494: SR-policy null bgp_ctx - afi 23, op table_walk Oct 15 12:50:29.876 default-bgp/spkr-tr2-sr 0/RP0/CPU0 t4697 [SR]:1620: SR-policy table walk, afi 23, OP - sweep-stale done, updated 0 nets, 0 locally sourced paths Oct 15 12:50:29.876 default-bgp/spkr-tr2-sr 0/RP0/CPU0 t4697 [SR]:1494: SR-policy null bgp_ctx - afi 24, op table_walk Oct 15 12:50:29.876 default-bgp/spkr-tr2-sr 0/RP0/CPU0 t4697 [SR]:1633: SR-policy table walk, afi 24, OP - sweep-stale done, updated 0 nets, 0 locally sourced paths Oct 15 12:50:29.876 default-bgp/spkr-tr2-srv6 0/RP0/CPU0 t4679 [SRV6]:1859: SRv6: bgp_srv6_sid_resource_notf_timer loc: 6 resource complete notif sent, caller loc 2 Oct 15 12:50:29.876 default-bgp/spkr-tr2-srv6 0/RP0/CPU0 t4679 [SRV6]:1865: SRv6: bgp_srv6_sid_resource_notf_timer loc: 7 resource complete notif sent, caller loc 2 Oct 15 12:50:29.876 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4679 [LABEL]:9001: label walk afi:VPNv4 Unicast, lbl ver 0 -> 12, be 2, skp 0 upd 0 Oct 15 12:50:29.876 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4679 [LABEL]:9006: label walk afi:VPNv4 Unicast, lbl ver 0 -> 12, be 0, skp 0 upd 1 Oct 15 12:50:29.876 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4679 [EV]:9643: Try to enter 'RIB Update' mode for AF 'VPNv4 Unicast', thread 8 Oct 15 12:50:29.876 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4679 [EV]:19718: Entering 'RIB Update' mode for AF 'VPNv4 Unicast' Oct 15 12:50:29.876 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4682 [RIB]:18929: RIB walk for afi VPNv4 Unicast: target version 12, min_fwdtable_version 1, import_version 12, label_version 12, table_version 12 Oct 15 12:50:29.877 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4682 [RIB]:18965: RIBUPD_START: parentafi=4{rtrstate=5}, walkversion=[1 - 12]: tblver=12, labelver=12 Oct 15 12:50:29.877 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4682 [RIB]:16216: send converge to RIB, afi VPNv4 Unicast, tableid 0xe0000002, converged 1, send_version 3, last_recv_version 3 Oct 15 12:50:29.878 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4682 [RIB]:16250: RIB converge flags (VRF 'CUST-A') , 0x5, 1, afi 0 tr_upd_gen:0 Oct 15 12:50:29.879 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4682 [RIB]:17459: RIB :time_rib_batch tot_pfx = 4, rib_calls = 1, total_time = 1 ms, rib_api_time = 1 ms, avg_rib_api_time = 1 ms, max_rib_api_time = 1 ms Oct 15 12:50:29.879 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4682 [RIB]:17487: RIB(CUST-A:Vv4u): ver 1 -> 12 :pfx inst/upd/skip/rem 3/0/0/1 Oct 15 12:50:29.879 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4682 [RIB]:19031: RIBUPD_END: parentafi=4{rtrstate=5}, walkversion=[1 - 12]: minfwdtblver=12(acked=12) Oct 15 12:50:29.879 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4682 [RIB]:19038: RIBUPD_END2: parentafi=4, prefixstats={install=3, skip=0, mod=0, wdr=1}, updtrigger=1 Oct 15 12:50:29.879 default-bgp/spkr-tr2-ev 0/RP0/CPU0 t4682 [EV]:19593: Entering 'Normal' mode for AF 'VPNv4 Unicast' Oct 15 12:50:29.879 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4682 [SYNC]:19622: entering READ-WRITE mode, set initsync version for bgp_ctx 'VPNv4 Unicast' to 12 Oct 15 12:50:29.882 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4697 [RIB]:6257: RIB converge flags (VRF 'CUST-A') , 0x7, 0, afi 0 tr_upd_gen:1 Oct 15 12:50:29.882 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4697 [RIB]:6263: RIB converge flags (VRF 'CUST-A') , 0x3, 0, afi 0 tr_upd_gen:1 Oct 15 12:50:29.882 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4697 [RIB]:6296: ACK from RIB: tbl_id 0xe0000002, converged 1, ver 3, pending nhscan 0 Oct 15 12:50:29.882 default-bgp/spkr-tr2-table 0/RP0/CPU0 t4697 [TABLE]:6322: table 'TBL:CUST-A (1/1)' propogate rd version, bgp tbl ver 13 Oct 15 12:50:29.882 default-bgp/spkr-tr2-imp 0/RP0/CPU0 t4694 [IMPORT]:6748: Import walk: import ver 12 -> 13: 0 nets processed (0 paths updated) afi 4 forced/ms 0 Oct 15 12:50:29.882 default-bgp/spkr-tr2-imp 0/RP0/CPU0 t4694 [IMPORT]:6777: Import walk: import ver 12 -> 13: 0 nets processed (0 paths updated) afi 4 forced/ms 0 Oct 15 12:50:29.882 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4679 [LABEL]:4366: Config release label mode for table 0xe0000002 (mode:6, 6, 6) flags:0x201, 0x0 Oct 15 12:50:29.882 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4679 [LABEL]:9001: label walk afi:VPNv4 Unicast, lbl ver 12 -> 13, be 0, skp 0 upd 0 Oct 15 12:50:29.882 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4679 [LABEL]:9006: label walk afi:VPNv4 Unicast, lbl ver 12 -> 13, be 0, skp 0 upd 1 Oct 15 12:50:29.887 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4682 [RIB]:18929: RIB walk for afi VPNv4 Unicast: target version 13, min_fwdtable_version 12, import_version 13, label_version 13, table_version 13 Oct 15 12:50:29.887 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4682 [RIB]:18965: RIBUPD_START: parentafi=4{rtrstate=6}, walkversion=[12 - 13]: tblver=13, labelver=13 Oct 15 12:50:29.887 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4682 [RIB]:16216: send converge to RIB, afi VPNv4 Unicast, tableid 0xe0000002, converged 1, send_version 3, last_recv_version 3 Oct 15 12:50:29.887 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4682 [RIB]:19031: RIBUPD_END: parentafi=4{rtrstate=6}, walkversion=[12 - 13]: minfwdtblver=13(acked=13) Oct 15 12:50:29.887 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4682 [RIB]:19038: RIBUPD_END2: parentafi=4, prefixstats={install=0, skip=0, mod=0, wdr=0}, updtrigger=1 Oct 15 12:50:29.912 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:13186: UPDGEN_UPD: table="TBL:default (1/128)", parentafi=4, afi=4, updgrp=0.2, subgrp=0.1 Oct 15 12:50:29.912 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:13190: UPDGEN_UPD2: table=0x00000000, subgrp=0.1, walktype=0(Regular), inputtargetver=13, pureRR=0 Oct 15 12:50:29.912 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:13193: UPDGEN_UPD3: walkversion=[0 - 13]: resumedver=0, advdisabled=0, completed=1, msgcount=2 Oct 15 12:50:29.912 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=6, adv=2, wdn=0, skp=4, sup=0, bestext=0} Oct 15 12:50:29.912 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 15 12:50:29.912 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:4101: UPDGEN_FG_APPEND: AFI=4, UG=2, FG=1, walktype=0, targetver=13: msgcount=2 Oct 15 12:50:29.912 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:4104: UPDGEN_FG_APPEND2: fg-prefixstats={adv=2, wdn=0, sup=0, skp=4} Oct 15 12:50:29.912 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:4101: UPDGEN_FG_APPEND: AFI=4, UG=2, FG=1, walktype=0, targetver=13: msgcount=1 Oct 15 12:50:29.912 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:4104: UPDGEN_FG_APPEND2: fg-prefixstats={adv=2, wdn=0, sup=0, skp=4} Oct 15 12:50:29.912 default-bgp/spkr-tr2-nbr 0/RP0/CPU0 t4695 [NBR]:12181: table 'TBL:default (1/128)' EoR sent to sub-grp 0.1 upd-grp 2 Oct 15 12:50:29.913 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:13186: UPDGEN_UPD: table="TBL:CUST-A (1/1)", parentafi=4, afi=0, updgrp=0.2, subgrp=0.1 Oct 15 12:50:29.913 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:13190: UPDGEN_UPD2: table=0xe0000002, subgrp=0.1, walktype=0(Regular), inputtargetver=13, pureRR=0 Oct 15 12:50:29.913 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:13193: UPDGEN_UPD3: walkversion=[0 - 13]: resumedver=0, advdisabled=0, completed=1, msgcount=3 Oct 15 12:50:29.913 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=4, adv=3, wdn=0, skp=1, sup=0, bestext=0} Oct 15 12:50:29.913 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 15 12:50:29.913 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:4101: UPDGEN_FG_APPEND: AFI=0, UG=2, FG=1, walktype=0, targetver=13: msgcount=3 Oct 15 12:50:29.913 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:4104: UPDGEN_FG_APPEND2: fg-prefixstats={adv=3, wdn=0, sup=0, skp=1} Oct 15 12:50:29.913 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:4101: UPDGEN_FG_APPEND: AFI=0, UG=2, FG=1, walktype=0, targetver=13: msgcount=1 Oct 15 12:50:29.913 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4695 [UPD]:4104: UPDGEN_FG_APPEND2: fg-prefixstats={adv=3, wdn=0, sup=0, skp=1} Oct 15 12:50:29.913 default-bgp/spkr-tr2-nbr 0/RP0/CPU0 t4695 [NBR]:12181: table 'TBL:CUST-A (1/1)' EoR sent to sub-grp 0.1 upd-grp 2 Oct 15 12:50:57.681 default-bgp/spkr-tr2-nbr 0/RP0/CPU0 t4693 [NBR]:1431: TBL:default (1/128), EOR rx-ed from vrf 0x60000000 nbr '4.4.4.4', afi:4, accepted prefix count:0, explicit:1 Oct 15 12:50:57.891 default-bgp/spkr-tr2-nbr 0/RP0/CPU0 t4691 [NBR]:1431: TBL:default (1/128), EOR rx-ed from vrf 0x60000000 nbr '4.4.4.4', afi:4, accepted prefix count:0, explicit:0 Oct 15 12:51:42.688 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4692 [COMMON]:857: vrf 0x60000000 nbr 0x75b1a5364b40, set peer ack version to 13, afi 4, loc 2 Oct 15 12:51:42.688 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4692 [COMMON]:857: vrf 0x60000002 nbr 0x75b1a53614c0, set peer ack version to 13, afi 0, loc 2 Oct 15 12:51:42.688 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4692 [COMMON]:857: vrf 0x60000000 nbr 0x75b1a5363000, set peer ack version to 13, afi 4, loc 2 Oct 15 12:52:32.872 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4698 [SYNC]:2280: reached initsync version 12 for afi VPNv4 Unicast, min_nbr_ack version 13, scanner_runs 3 Oct 15 12:52:32.872 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4698 [SYNC]:1792: NSR event: 'End of Convergence' on active Oct 15 12:52:32.872 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4698 [SYNC]:1792: NSR event: 'End of Convergence' on active Oct 15 12:52:32.872 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4696 [SYNC]:6368: active NSR state transition for 'Standby Sync-group', event 'End of Convergence', 'Active Ready' -> 'Active Ready', mask 0x12 Oct 15 12:52:32.872 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4696 [SYNC]:6368: active NSR state transition for 'ISSU Sync-group', event 'End of Convergence', 'None' -> 'None', mask 0x10 Oct 15 12:52:32.872 default-bgp/spkr-tr2-issu 0/RP0/CPU0 t4696 [ISSU]:541: ISM: ISSU Not enabled Oct 15 12:52:32.872 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4696 [SYNC]:6460: send active up msg to 'ISSU Sync-group' 'Unknown', after NSR restart or tcp restart Oct 15 12:52:32.872 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4696 [SYNC]:5241: scoped sync: trigger forced cleanup, batch state 0, count 0 Oct 15 12:52:32.872 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4648 [SYNC]:4950: scoped sync: forced cleanup, batch state 0 Oct 15 12:52:32.872 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4648 [SYNC]:4952: scoped sync: batch state change from 0 to 0 Oct 15 12:52:32.873 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4696 [SYNC]:8714: scoped sync: skip sending table update done, global NSR not ready