RP/0/RP0/CPU0:PE1#show bgp trace | utility tail -n 150 Thu Oct 15 13:27:26.275 UTC Oct 15 13:17:23.784 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:2040: bpm build txlist: task 1 [1-last-batch,0-more] , inst-id 0, item-count 2, chkpt-count 2, total-item 42, buff-seq 9 Oct 15 13:17:23.784 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:596: bpm buff pack, bscan 0 inst-id 0, buff-seq 9, item-count 2, msg-size 252 Oct 15 13:17:23.784 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:482: Sending init config done signal to inst_id 0, rc 0, loc 1 Oct 15 13:17:23.784 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:535: bpm chkpt notify: Chkpt status after 1 [1-EDM Gen, 2-Monitor Del], bpm_edm_chkpt_items 0, item_cnt 2 Oct 15 13:17:23.784 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:302: func bpm_edm_generate_notifications, event can't find instinfo, instance_id 1 Oct 15 13:17:23.784 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:302: func bpm_edm_generate_notifications, event can't find instinfo, instance_id 2 Oct 15 13:17:23.784 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:302: func bpm_edm_generate_notifications, event can't find instinfo, instance_id 3 Oct 15 13:17:23.784 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:373: bpm send msg, role 0 (1:S, 0:A)inst-id 0, buff-seq 9, msg-id 5, rc 0 Oct 15 13:17:23.784 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:398: bpm txlist handler end, role 0 (1:S, 0:A)inst-id 0, send_status 1 [1:ok, 2:blocked, 3:failed] elem-count 1, rc 0 Oct 15 13:17:23.784 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:210: bpm txlist show:loc 1 [1:txlist-handler, 2:conn-up 3:timer-cleanup] active-mem 1, suspend-mem 0, end-list 1, remove-mem 0, elements 2 Oct 15 13:17:23.784 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:299: func txlist-no-active-mem, TXLIST cleanup start timer :60 Oct 15 13:17:23.784 default-bgp/spkr-tr2-apic 0/RP0/CPU0 t4624 [AIPC]:1619: func bgp_bpm_ipc_cb: type, event input-wait, p1 3 p2 0 p3 1 Oct 15 13:17:23.784 default-bgp/spkr-tr2-postit 0/RP0/CPU0 t4624 [POSTIT]:5163: skip postit: 'Allowas-in configuration changed - route refresh', nbr: 172.16.5.2, reason: 1 Oct 15 13:17:23.784 default-bgp/spkr-tr2-apic 0/RP0/CPU0 t4624 [AIPC]:1358: bgp ipc rcv, inst-id 0, msg-len 192, buff-seq 8, msg count 1, buff-rel 1, init-config 1 [0-not Done , 1-Done] Oct 15 13:17:23.784 default-bgp/spkr-tr2-apic 0/RP0/CPU0 t4624 [AIPC]:1358: bgp ipc rcv, inst-id 0, msg-len 252, buff-seq 9, msg count 2, buff-rel 1, init-config 1 [0-not Done , 1-Done] Oct 15 13:17:23.784 default-bgp/spkr-tr2-apic 0/RP0/CPU0 t4624 [AIPC]:1619: func bgp_bpm_ipc_cb: type, event input-wait, p1 3 p2 0 p3 0 Oct 15 13:17:23.985 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:2504: func bpm_ipc_cb: type, event send-status, p1 10 p2 0 p3 0 Oct 15 13:17:23.985 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:525: bpm send status, role 0 (1:S, 0:A)inst-id 0, msg-id 4, send-ok 1, rel buff-seq 0 Oct 15 13:17:23.985 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:2504: func bpm_ipc_cb: type, event send-status, p1 10 p2 0 p3 0 Oct 15 13:17:23.985 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:525: bpm send status, role 0 (1:S, 0:A)inst-id 0, msg-id 5, send-ok 1, rel buff-seq 0 Oct 15 13:17:25.862 default-bgp/spkr-tr2-imp 0/RP0/CPU0 t4661 [IMPORT]:6748: Import walk: import ver 30 -> 35: 0 nets processed (0 paths updated) afi 4 forced/ms 0 Oct 15 13:17:25.862 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4645 [LABEL]:4366: Config release label mode for table 0xe0000002 (mode:6, 6, 6) flags:0x201, 0x0 Oct 15 13:17:25.862 default-bgp/spkr-tr2-imp 0/RP0/CPU0 t4661 [IMPORT]:6777: Import walk: import ver 30 -> 35: 5 nets processed (0 paths updated) afi 4 forced/ms 0 Oct 15 13:17:25.862 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4645 [LABEL]:4366: Config release label mode for table 0xe0000003 (mode:6, 6, 6) flags:0x201, 0x0 Oct 15 13:17:25.863 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4651 [RIB]:18929: RIB walk for afi VPNv4 Unicast: target version 30, min_fwdtable_version 30, import_version 35, label_version 30, table_version 35 Oct 15 13:17:25.863 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4645 [LABEL]:9001: label walk afi:VPNv4 Unicast, lbl ver 30 -> 35, be 0, skp 0 upd 5 Oct 15 13:17:25.863 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4645 [LABEL]:9006: label walk afi:VPNv4 Unicast, lbl ver 30 -> 35, be 0, skp 0 upd 1 Oct 15 13:17:25.863 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4651 [RIB]:18929: RIB walk for afi VPNv4 Unicast: target version 35, min_fwdtable_version 30, import_version 35, label_version 35, table_version 35 Oct 15 13:17:25.863 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4651 [RIB]:18965: RIBUPD_START: parentafi=4{rtrstate=6}, walkversion=[30 - 35]: tblver=35, labelver=35 Oct 15 13:17:25.864 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4651 [RIB]:16216: send converge to RIB, afi VPNv4 Unicast, tableid 0xe0000003, converged 1, send_version 2, last_recv_version 2 Oct 15 13:17:25.865 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4651 [RIB]:17459: RIB :time_rib_batch tot_pfx = 5, 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 13:17:25.865 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4651 [RIB]:17487: RIB(CUST-A-HUBOUT:Vv4u): ver 30 -> 35 :pfx inst/upd/skip/rem 0/0/0/5 Oct 15 13:17:25.865 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4651 [RIB]:19031: RIBUPD_END: parentafi=4{rtrstate=6}, walkversion=[30 - 35]: minfwdtblver=35(acked=35) Oct 15 13:17:25.865 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4651 [RIB]:19038: RIBUPD_END2: parentafi=4, prefixstats={install=0, skip=0, mod=0, wdr=5}, updtrigger=1 Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13186: UPDGEN_UPD: table="TBL:default (1/128)", parentafi=4, afi=4, updgrp=0.2, subgrp=0.1 Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13190: UPDGEN_UPD2: table=0x00000000, subgrp=0.1, walktype=1(Quick-withdraw), inputtargetver=35, pureRR=0 Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13193: UPDGEN_UPD3: walkversion=[30 - 35]: resumedver=0, advdisabled=0, completed=1, msgcount=1 Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=5, adv=0, wdn=5, skp=0, sup=0, bestext=0} Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:4101: UPDGEN_FG_APPEND: AFI=4, UG=2, FG=1, walktype=1, targetver=35: msgcount=1 Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:4104: UPDGEN_FG_APPEND2: fg-prefixstats={adv=0, wdn=5, sup=0, skp=0} Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13186: UPDGEN_UPD: table="TBL:CUST-A-HUBIN (1/1)", parentafi=4, afi=0, updgrp=0.2, subgrp=0.1 Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13190: UPDGEN_UPD2: table=0xe0000002, subgrp=0.1, walktype=1(Quick-withdraw), inputtargetver=35, pureRR=0 Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13193: UPDGEN_UPD3: walkversion=[30 - 35]: resumedver=0, advdisabled=0, completed=1, msgcount=0 Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=0, adv=0, wdn=0, skp=0, sup=0, bestext=0} Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 15 13:17:25.873 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4662 [COMMON]:3717: vrf 0x60000002 nbr 0x7e99eaace4c0, set peer ack version to 30, afi 0, loc 4 Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13360: Updgen - Skip EoR for Tbl:(TBL:CUST-A-HUBIN (1/1)) subgrp:(1) UG:(2) end 35 Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13186: UPDGEN_UPD: table="TBL:CUST-A-HUBOUT (1/1)", parentafi=4, afi=0, updgrp=0.1, subgrp=0.1 Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13190: UPDGEN_UPD2: table=0xe0000003, subgrp=0.1, walktype=1(Quick-withdraw), inputtargetver=35, pureRR=0 Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13193: UPDGEN_UPD3: walkversion=[30 - 35]: resumedver=0, advdisabled=0, completed=1, msgcount=0 Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=5, adv=0, wdn=0, skp=5, sup=0, bestext=0} Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 15 13:17:25.873 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4662 [COMMON]:3717: vrf 0x60000003 nbr 0x7e99eaacc980, set peer ack version to 30, afi 0, loc 4 Oct 15 13:17:25.873 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13360: Updgen - Skip EoR for Tbl:(TBL:CUST-A-HUBOUT (1/1)) subgrp:(1) UG:(1) end 35 Oct 15 13:17:25.892 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13186: UPDGEN_UPD: table="TBL:default (1/128)", parentafi=4, afi=4, updgrp=0.2, subgrp=0.1 Oct 15 13:17:25.892 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13190: UPDGEN_UPD2: table=0x00000000, subgrp=0.1, walktype=0(Regular), inputtargetver=35, pureRR=0 Oct 15 13:17:25.892 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13193: UPDGEN_UPD3: walkversion=[30 - 35]: resumedver=0, advdisabled=0, completed=1, msgcount=0 Oct 15 13:17:25.892 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=0, adv=0, wdn=0, skp=0, sup=0, bestext=0} Oct 15 13:17:25.892 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 15 13:17:25.892 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13360: Updgen - Skip EoR for Tbl:(TBL:default (1/128)) subgrp:(1) UG:(2) end 35 Oct 15 13:17:25.894 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13186: UPDGEN_UPD: table="TBL:CUST-A-HUBIN (1/1)", parentafi=4, afi=0, updgrp=0.2, subgrp=0.1 Oct 15 13:17:25.894 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13190: UPDGEN_UPD2: table=0xe0000002, subgrp=0.1, walktype=0(Regular), inputtargetver=35, pureRR=0 Oct 15 13:17:25.894 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13193: UPDGEN_UPD3: walkversion=[30 - 35]: resumedver=0, advdisabled=0, completed=1, msgcount=0 Oct 15 13:17:25.894 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=0, adv=0, wdn=0, skp=0, sup=0, bestext=0} Oct 15 13:17:25.894 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 15 13:17:25.894 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4662 [COMMON]:3717: vrf 0x60000002 nbr 0x7e99eaace4c0, set peer ack version to 35, afi 0, loc 4 Oct 15 13:17:25.894 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13360: Updgen - Skip EoR for Tbl:(TBL:CUST-A-HUBIN (1/1)) subgrp:(1) UG:(2) end 35 Oct 15 13:17:25.894 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13186: UPDGEN_UPD: table="TBL:CUST-A-HUBOUT (1/1)", parentafi=4, afi=0, updgrp=0.1, subgrp=0.1 Oct 15 13:17:25.894 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13190: UPDGEN_UPD2: table=0xe0000003, subgrp=0.1, walktype=0(Regular), inputtargetver=35, pureRR=0 Oct 15 13:17:25.894 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13193: UPDGEN_UPD3: walkversion=[30 - 35]: resumedver=0, advdisabled=0, completed=1, msgcount=0 Oct 15 13:17:25.894 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=0, adv=0, wdn=0, skp=0, sup=0, bestext=0} Oct 15 13:17:25.894 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 15 13:17:25.894 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4662 [COMMON]:3717: vrf 0x60000003 nbr 0x7e99eaacc980, set peer ack version to 35, afi 0, loc 4 Oct 15 13:17:25.894 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13360: Updgen - Skip EoR for Tbl:(TBL:CUST-A-HUBOUT (1/1)) subgrp:(1) UG:(1) end 35 Oct 15 13:18:23.784 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:584: bpm chkpt remove: inst-id 0, buff-seq 8, total count 3, delete count 1, ok 1 Oct 15 13:18:23.784 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:584: bpm chkpt remove: inst-id 0, buff-seq 9, total count 2, delete count 2, ok 1 Oct 15 13:18:23.784 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [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 2, elements 0 Oct 15 13:18:23.784 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:913: func txlist_timer_expiry, event restart, p1 1 p2 60 p3 1 Oct 15 13:18:27.812 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4659 [COMMON]:857: vrf 0x60000000 nbr 0x7e99eaad0000, set peer ack version to 30, afi 4, loc 2 Oct 15 13:18:27.812 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4659 [COMMON]:1000: vrf 0x60000000 nbr 0x7e99eaad0000, set peer ack version to 35, afi 4, loc 3 Oct 15 13:18:27.812 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4659 [COMMON]:857: vrf 0x60000000 nbr 0x7e99eaad1b40, set peer ack version to 30, afi 4, loc 2 Oct 15 13:18:27.812 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4659 [COMMON]:1000: vrf 0x60000000 nbr 0x7e99eaad1b40, set peer ack version to 35, afi 4, loc 3 Oct 15 13:19:23.785 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [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 13:21:30.166 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4645 [LABEL]:3971: Label RPF download LSD | processed: 0 err: 0 Oct 15 13:24:43.495 bgp/bpm-tr2-gen 0/RP0/CPU0 t4533 [GEN]:4298: BPM verify running (sense=1, asn=65001, inst=default) started Oct 15 13:24:43.495 bgp/bpm-tr2-gen 0/RP0/CPU0 t4533 [GEN]:4383: BPM verify running (sense=1, asn=65001, inst=default) ended Oct 15 13:24:43.563 bgp/bpm-tr2-gen 0/RP0/CPU0 t4533 [GEN]:4547: BPM apply running (sense=1, asn=65001, inst=default) started Oct 15 13:24:43.563 bgp/bpm-tr2-gen 0/RP0/CPU0 t4533 [GEN]:4563: BPM doing apply-running for configuration Oct 15 13:24:43.563 bgp/bpm-tr2-gen 0/RP0/CPU0 t4533 [GEN]:4706: BPM apply running (sense=1, asn=65001, inst=default) ended Oct 15 13:24:43.690 bgp/bpm-tr2-gen 0/RP0/CPU0 t4533 [GEN]:17034: BPM Forward-ref ua-exists: ent - , vrf - CUST-A-HUBOUT, inst - default, fr - 0 Oct 15 13:24:45.563 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:340: bpm gen notify: inst-name default, inst-id 0, total publish 45, chkpt count 3 Oct 15 13:24:45.563 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:447: bpm chkpt notify: Chkpt status during 'EDM Gen', ok 1 finished 0 objid-is-null? 1 loc 0 Oct 15 13:24:45.563 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:2040: bpm build txlist: task 1 [1-last-batch,0-more] , inst-id 0, item-count 3, chkpt-count 3, total-item 45, buff-seq 10 Oct 15 13:24:45.563 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:596: bpm buff pack, bscan 0 inst-id 0, buff-seq 10, item-count 3, msg-size 424 Oct 15 13:24:45.563 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:482: Sending init config done signal to inst_id 0, rc 0, loc 1 Oct 15 13:24:45.563 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:535: bpm chkpt notify: Chkpt status after 1 [1-EDM Gen, 2-Monitor Del], bpm_edm_chkpt_items 0, item_cnt 3 Oct 15 13:24:45.563 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:302: func bpm_edm_generate_notifications, event can't find instinfo, instance_id 1 Oct 15 13:24:45.563 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:302: func bpm_edm_generate_notifications, event can't find instinfo, instance_id 2 Oct 15 13:24:45.563 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:302: func bpm_edm_generate_notifications, event can't find instinfo, instance_id 3 Oct 15 13:24:45.563 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:373: bpm send msg, role 0 (1:S, 0:A)inst-id 0, buff-seq 10, msg-id 6, rc 0 Oct 15 13:24:45.563 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:398: bpm txlist handler end, role 0 (1:S, 0:A)inst-id 0, send_status 1 [1:ok, 2:blocked, 3:failed] elem-count 1, rc 0 Oct 15 13:24:45.563 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:210: bpm txlist show:loc 1 [1:txlist-handler, 2:conn-up 3:timer-cleanup] active-mem 1, suspend-mem 0, end-list 1, remove-mem 0, elements 1 Oct 15 13:24:45.563 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:299: func txlist-no-active-mem, TXLIST cleanup start timer :60 Oct 15 13:24:45.563 default-bgp/spkr-tr2-apic 0/RP0/CPU0 t4624 [AIPC]:1619: func bgp_bpm_ipc_cb: type, event input-wait, p1 3 p2 0 p3 1 Oct 15 13:24:45.564 default-bgp/spkr-tr2-postit 0/RP0/CPU0 t4624 [POSTIT]:5163: skip postit: 'Allowas-in configuration changed - route refresh', nbr: 172.16.5.2, reason: 1 Oct 15 13:24:45.564 default-bgp/spkr-tr2-apic 0/RP0/CPU0 t4624 [AIPC]:1358: bgp ipc rcv, inst-id 0, msg-len 424, buff-seq 10, msg count 3, buff-rel 1, init-config 1 [0-not Done , 1-Done] Oct 15 13:24:45.764 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:2504: func bpm_ipc_cb: type, event send-status, p1 10 p2 0 p3 0 Oct 15 13:24:45.764 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:525: bpm send status, role 0 (1:S, 0:A)inst-id 0, msg-id 6, send-ok 1, rel buff-seq 0 Oct 15 13:24:47.663 default-bgp/spkr-tr2-imp 0/RP0/CPU0 t4661 [IMPORT]:6748: Import walk: import ver 35 -> 40: 0 nets processed (0 paths updated) afi 4 forced/ms 0 Oct 15 13:24:47.663 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4645 [LABEL]:4366: Config release label mode for table 0xe0000002 (mode:6, 6, 6) flags:0x201, 0x0 Oct 15 13:24:47.663 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4645 [LABEL]:4366: Config release label mode for table 0xe0000003 (mode:6, 6, 6) flags:0x201, 0x0 Oct 15 13:24:47.663 default-bgp/spkr-tr2-imp 0/RP0/CPU0 t4661 [IMPORT]:6777: Import walk: import ver 35 -> 40: 5 nets processed (0 paths updated) afi 4 forced/ms 0 Oct 15 13:24:47.663 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4651 [RIB]:18929: RIB walk for afi VPNv4 Unicast: target version 35, min_fwdtable_version 35, import_version 40, label_version 35, table_version 40 Oct 15 13:24:47.664 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4645 [LABEL]:9001: label walk afi:VPNv4 Unicast, lbl ver 35 -> 40, be 5, skp 0 upd 0 Oct 15 13:24:47.664 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4645 [LABEL]:9006: label walk afi:VPNv4 Unicast, lbl ver 35 -> 40, be 0, skp 0 upd 1 Oct 15 13:24:47.664 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4651 [RIB]:18929: RIB walk for afi VPNv4 Unicast: target version 40, min_fwdtable_version 35, import_version 40, label_version 40, table_version 40 Oct 15 13:24:47.664 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4651 [RIB]:18965: RIBUPD_START: parentafi=4{rtrstate=6}, walkversion=[35 - 40]: tblver=40, labelver=40 Oct 15 13:24:47.664 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4651 [RIB]:16216: send converge to RIB, afi VPNv4 Unicast, tableid 0xe0000003, converged 1, send_version 2, last_recv_version 2 Oct 15 13:24:47.665 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4651 [RIB]:17459: RIB :time_rib_batch tot_pfx = 5, rib_calls = 1, total_time = 1 ms, rib_api_time = 0 ms, avg_rib_api_time = 0 ms, max_rib_api_time = 0 ms Oct 15 13:24:47.665 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4651 [RIB]:17487: RIB(CUST-A-HUBOUT:Vv4u): ver 35 -> 40 :pfx inst/upd/skip/rem 5/0/0/0 Oct 15 13:24:47.665 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4651 [RIB]:19031: RIBUPD_END: parentafi=4{rtrstate=6}, walkversion=[35 - 40]: minfwdtblver=40(acked=40) Oct 15 13:24:47.665 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4651 [RIB]:19038: RIBUPD_END2: parentafi=4, prefixstats={install=5, skip=0, mod=0, wdr=0}, updtrigger=1 Oct 15 13:24:47.689 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13186: UPDGEN_UPD: table="TBL:default (1/128)", parentafi=4, afi=4, updgrp=0.2, subgrp=0.1 Oct 15 13:24:47.689 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13190: UPDGEN_UPD2: table=0x00000000, subgrp=0.1, walktype=0(Regular), inputtargetver=40, pureRR=0 Oct 15 13:24:47.689 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13193: UPDGEN_UPD3: walkversion=[35 - 40]: resumedver=0, advdisabled=0, completed=1, msgcount=3 Oct 15 13:24:47.689 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=5, adv=5, wdn=0, skp=0, sup=0, bestext=0} Oct 15 13:24:47.689 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 15 13:24:47.689 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:4101: UPDGEN_FG_APPEND: AFI=4, UG=2, FG=1, walktype=0, targetver=40: msgcount=3 Oct 15 13:24:47.689 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:4104: UPDGEN_FG_APPEND2: fg-prefixstats={adv=5, wdn=0, sup=0, skp=0} Oct 15 13:24:47.691 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13186: UPDGEN_UPD: table="TBL:CUST-A-HUBIN (1/1)", parentafi=4, afi=0, updgrp=0.2, subgrp=0.1 Oct 15 13:24:47.691 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13190: UPDGEN_UPD2: table=0xe0000002, subgrp=0.1, walktype=0(Regular), inputtargetver=40, pureRR=0 Oct 15 13:24:47.691 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13193: UPDGEN_UPD3: walkversion=[35 - 40]: resumedver=0, advdisabled=0, completed=1, msgcount=0 Oct 15 13:24:47.691 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=0, adv=0, wdn=0, skp=0, sup=0, bestext=0} Oct 15 13:24:47.691 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 15 13:24:47.691 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4662 [COMMON]:3717: vrf 0x60000002 nbr 0x7e99eaace4c0, set peer ack version to 40, afi 0, loc 4 Oct 15 13:24:47.691 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13360: Updgen - Skip EoR for Tbl:(TBL:CUST-A-HUBIN (1/1)) subgrp:(1) UG:(2) end 40 Oct 15 13:24:47.761 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13186: UPDGEN_UPD: table="TBL:CUST-A-HUBOUT (1/1)", parentafi=4, afi=0, updgrp=0.1, subgrp=0.1 Oct 15 13:24:47.761 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13190: UPDGEN_UPD2: table=0xe0000003, subgrp=0.1, walktype=0(Regular), inputtargetver=40, pureRR=0 Oct 15 13:24:47.761 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13193: UPDGEN_UPD3: walkversion=[35 - 40]: resumedver=0, advdisabled=0, completed=1, msgcount=0 Oct 15 13:24:47.761 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=5, adv=0, wdn=0, skp=5, sup=0, bestext=0} Oct 15 13:24:47.761 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 15 13:24:47.761 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4662 [COMMON]:3717: vrf 0x60000003 nbr 0x7e99eaacc980, set peer ack version to 40, afi 0, loc 4 Oct 15 13:24:47.761 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4662 [UPD]:13360: Updgen - Skip EoR for Tbl:(TBL:CUST-A-HUBOUT (1/1)) subgrp:(1) UG:(1) end 40 Oct 15 13:25:45.564 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:584: bpm chkpt remove: inst-id 0, buff-seq 10, total count 3, delete count 3, ok 1 Oct 15 13:25:45.564 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [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 13:25:45.564 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [AIPC]:913: func txlist_timer_expiry, event restart, p1 1 p2 60 p3 1 Oct 15 13:25:57.823 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4659 [COMMON]:857: vrf 0x60000000 nbr 0x7e99eaad0000, set peer ack version to 40, afi 4, loc 2 Oct 15 13:25:57.823 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4659 [COMMON]:857: vrf 0x60000000 nbr 0x7e99eaad1b40, set peer ack version to 40, afi 4, loc 2 Oct 15 13:26:45.564 bgp/bpm-tr2-apic 0/RP0/CPU0 t4607 [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