RP/0/RP0/CPU0:PE3#show bgp trace | utility tail -n 150 Mon Oct 12 00:33:12.045 UTC Oct 12 00:22:45.633 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13186: UPDGEN_UPD: table="TBL:default (1/128)", parentafi=4, afi=4, updgrp=0.2, subgrp=0.1 Oct 12 00:22:45.633 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13190: UPDGEN_UPD2: table=0x00000000, subgrp=0.1, walktype=0(Regular), inputtargetver=13, pureRR=0 Oct 12 00:22:45.633 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13193: UPDGEN_UPD3: walkversion=[0 - 13]: resumedver=0, advdisabled=0, completed=1, msgcount=2 Oct 12 00:22:45.633 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=4, adv=2, wdn=0, skp=2, sup=0, bestext=0} Oct 12 00:22:45.633 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 12 00:22:45.633 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4101: UPDGEN_FG_APPEND: AFI=4, UG=2, FG=1, walktype=0, targetver=13: msgcount=2 Oct 12 00:22:45.633 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4104: UPDGEN_FG_APPEND2: fg-prefixstats={adv=2, wdn=0, sup=0, skp=2} Oct 12 00:22:45.633 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4101: UPDGEN_FG_APPEND: AFI=4, UG=2, FG=1, walktype=0, targetver=13: msgcount=1 Oct 12 00:22:45.633 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4104: UPDGEN_FG_APPEND2: fg-prefixstats={adv=2, wdn=0, sup=0, skp=2} Oct 12 00:22:45.633 default-bgp/spkr-tr2-nbr 0/RP0/CPU0 t4685 [NBR]:12181: table 'TBL:default (1/128)' EoR sent to sub-grp 0.1 upd-grp 2 Oct 12 00:22:45.636 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13186: UPDGEN_UPD: table="TBL:CUST-A (1/1)", parentafi=4, afi=0, updgrp=0.2, subgrp=0.1 Oct 12 00:22:45.636 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13190: UPDGEN_UPD2: table=0xe0000002, subgrp=0.1, walktype=0(Regular), inputtargetver=13, pureRR=0 Oct 12 00:22:45.636 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13193: UPDGEN_UPD3: walkversion=[0 - 13]: resumedver=0, advdisabled=0, completed=1, msgcount=2 Oct 12 00:22:45.636 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=4, adv=2, wdn=0, skp=2, sup=0, bestext=0} Oct 12 00:22:45.636 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 12 00:22:45.636 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4101: UPDGEN_FG_APPEND: AFI=0, UG=2, FG=1, walktype=0, targetver=13: msgcount=2 Oct 12 00:22:45.636 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4104: UPDGEN_FG_APPEND2: fg-prefixstats={adv=2, wdn=0, sup=0, skp=2} Oct 12 00:22:45.636 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4101: UPDGEN_FG_APPEND: AFI=0, UG=2, FG=1, walktype=0, targetver=13: msgcount=1 Oct 12 00:22:45.636 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4104: UPDGEN_FG_APPEND2: fg-prefixstats={adv=2, wdn=0, sup=0, skp=2} Oct 12 00:22:45.636 default-bgp/spkr-tr2-nbr 0/RP0/CPU0 t4685 [NBR]:12181: table 'TBL:CUST-A (1/1)' EoR sent to sub-grp 0.1 upd-grp 2 Oct 12 00:22:45.651 default-bgp/spkr-tr2-nbr 0/RP0/CPU0 t4683 [NBR]:1431: TBL:default (1/128), EOR rx-ed from vrf 0x60000000 nbr '2.2.2.2', afi:4, accepted prefix count:2, explicit:1 Oct 12 00:22:45.651 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4672 [LABEL]:4366: Config release label mode for table 0xe0000002 (mode:6, 6, 6) flags:0x201, 0x0 Oct 12 00:22:45.651 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4672 [LABEL]:9001: label walk afi:VPNv4 Unicast, lbl ver 13 -> 15, be 0, skp 0 upd 0 Oct 12 00:22:45.651 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4672 [LABEL]:9006: label walk afi:VPNv4 Unicast, lbl ver 13 -> 15, be 0, skp 0 upd 1 Oct 12 00:22:45.651 default-bgp/spkr-tr2-imp 0/RP0/CPU0 t4684 [IMPORT]:6748: Import walk: import ver 13 -> 15: 0 nets processed (0 paths updated) afi 4 forced/ms 0 Oct 12 00:22:45.651 default-bgp/spkr-tr2-imp 0/RP0/CPU0 t4684 [IMPORT]:6777: Import walk: import ver 13 -> 15: 2 nets processed (0 paths updated) afi 4 forced/ms 0 Oct 12 00:22:45.651 default-bgp/spkr-tr2-imp 0/RP0/CPU0 t4684 [IMPORT]:6748: Import walk: import ver 15 -> 17: 0 nets processed (0 paths updated) afi 4 forced/ms 0 Oct 12 00:22:45.651 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4672 [LABEL]:4366: Config release label mode for table 0xe0000002 (mode:6, 6, 6) flags:0x201, 0x0 Oct 12 00:22:45.651 default-bgp/spkr-tr2-imp 0/RP0/CPU0 t4684 [IMPORT]:6777: Import walk: import ver 15 -> 17: 2 nets processed (0 paths updated) afi 4 forced/ms 0 Oct 12 00:22:45.651 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4672 [LABEL]:9001: label walk afi:VPNv4 Unicast, lbl ver 15 -> 17, be 0, skp 0 upd 0 Oct 12 00:22:45.651 default-bgp/spkr-tr2-label 0/RP0/CPU0 t4672 [LABEL]:9006: label walk afi:VPNv4 Unicast, lbl ver 15 -> 17, be 0, skp 0 upd 1 Oct 12 00:22:45.651 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4675 [RIB]:18929: RIB walk for afi VPNv4 Unicast: target version 17, min_fwdtable_version 13, import_version 17, label_version 17, table_version 17 Oct 12 00:22:45.651 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4675 [RIB]:18965: RIBUPD_START: parentafi=4{rtrstate=6}, walkversion=[13 - 17]: tblver=17, labelver=17 Oct 12 00:22:45.652 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4675 [RIB]:16216: send converge to RIB, afi VPNv4 Unicast, tableid 0xe0000002, converged 1, send_version 3, last_recv_version 3 Oct 12 00:22:45.652 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4675 [RIB]:17459: RIB :time_rib_batch tot_pfx = 2, rib_calls = 1, total_time = 0 ms, rib_api_time = 0 ms, avg_rib_api_time = 0 ms, max_rib_api_time = 0 ms Oct 12 00:22:45.652 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4675 [RIB]:17487: RIB(CUST-A:Vv4u): ver 13 -> 17 :pfx inst/upd/skip/rem 2/0/0/0 Oct 12 00:22:45.652 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4675 [RIB]:19031: RIBUPD_END: parentafi=4{rtrstate=6}, walkversion=[13 - 17]: minfwdtblver=17(acked=17) Oct 12 00:22:45.652 default-bgp/spkr-tr2-rib 0/RP0/CPU0 t4675 [RIB]:19038: RIBUPD_END2: parentafi=4, prefixstats={install=2, skip=0, mod=0, wdr=0}, updtrigger=1 Oct 12 00:22:45.677 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13186: UPDGEN_UPD: table="TBL:default (1/128)", parentafi=4, afi=4, updgrp=0.2, subgrp=0.1 Oct 12 00:22:45.677 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13190: UPDGEN_UPD2: table=0x00000000, subgrp=0.1, walktype=0(Regular), inputtargetver=17, pureRR=0 Oct 12 00:22:45.677 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13193: UPDGEN_UPD3: walkversion=[13 - 17]: resumedver=0, advdisabled=0, completed=1, msgcount=0 Oct 12 00:22:45.677 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=2, adv=0, wdn=0, skp=2, sup=0, bestext=0} Oct 12 00:22:45.677 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 12 00:22:45.677 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13360: Updgen - Skip EoR for Tbl:(TBL:default (1/128)) subgrp:(1) UG:(2) end 17 Oct 12 00:22:45.680 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13186: UPDGEN_UPD: table="TBL:CUST-A (1/1)", parentafi=4, afi=0, updgrp=0.2, subgrp=0.1 Oct 12 00:22:45.680 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13190: UPDGEN_UPD2: table=0xe0000002, subgrp=0.1, walktype=0(Regular), inputtargetver=17, pureRR=0 Oct 12 00:22:45.680 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13193: UPDGEN_UPD3: walkversion=[13 - 17]: resumedver=0, advdisabled=0, completed=1, msgcount=1 Oct 12 00:22:45.680 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=2, adv=1, wdn=0, skp=1, sup=0, bestext=0} Oct 12 00:22:45.680 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 12 00:22:45.680 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4101: UPDGEN_FG_APPEND: AFI=0, UG=2, FG=1, walktype=0, targetver=17: msgcount=1 Oct 12 00:22:45.680 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4104: UPDGEN_FG_APPEND2: fg-prefixstats={adv=1, wdn=0, sup=0, skp=1} Oct 12 00:22:45.680 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4101: UPDGEN_FG_APPEND: AFI=0, UG=2, FG=1, walktype=0, targetver=17: msgcount=1 Oct 12 00:22:45.680 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4104: UPDGEN_FG_APPEND2: fg-prefixstats={adv=1, wdn=0, sup=0, skp=1} Oct 12 00:23:25.405 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [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 12 00:23:56.702 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4682 [COMMON]:857: vrf 0x60000002 nbr 0x725f1d6de4c0, set peer ack version to 13, afi 0, loc 2 Oct 12 00:23:56.702 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4682 [COMMON]:857: vrf 0x60000002 nbr 0x725f1d6de4c0, set peer ack version to 17, afi 0, loc 2 Oct 12 00:23:56.702 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4682 [COMMON]:857: vrf 0x60000000 nbr 0x725f1d6e1b40, set peer ack version to 13, afi 4, loc 2 Oct 12 00:23:56.702 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4682 [COMMON]:1000: vrf 0x60000000 nbr 0x725f1d6e1b40, set peer ack version to 17, afi 4, loc 3 Oct 12 00:23:56.702 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4682 [COMMON]:857: vrf 0x60000000 nbr 0x725f1d6e0000, set peer ack version to 13, afi 4, loc 2 Oct 12 00:23:56.702 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4682 [COMMON]:1000: vrf 0x60000000 nbr 0x725f1d6e0000, set peer ack version to 17, afi 4, loc 3 Oct 12 00:24:48.580 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4688 [SYNC]:2280: reached initsync version 12 for afi VPNv4 Unicast, min_nbr_ack version 17, scanner_runs 3 Oct 12 00:24:48.580 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4688 [SYNC]:1792: NSR event: 'End of Convergence' on active Oct 12 00:24:48.580 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4688 [SYNC]:1792: NSR event: 'End of Convergence' on active Oct 12 00:24:48.580 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4686 [SYNC]:6368: active NSR state transition for 'Standby Sync-group', event 'End of Convergence', 'Active Ready' -> 'Active Ready', mask 0x12 Oct 12 00:24:48.580 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4686 [SYNC]:6368: active NSR state transition for 'ISSU Sync-group', event 'End of Convergence', 'None' -> 'None', mask 0x10 Oct 12 00:24:48.580 default-bgp/spkr-tr2-issu 0/RP0/CPU0 t4686 [ISSU]:541: ISM: ISSU Not enabled Oct 12 00:24:48.580 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4686 [SYNC]:6460: send active up msg to 'ISSU Sync-group' 'Unknown', after NSR restart or tcp restart Oct 12 00:24:48.580 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4686 [SYNC]:5241: scoped sync: trigger forced cleanup, batch state 0, count 0 Oct 12 00:24:48.581 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4616 [SYNC]:4950: scoped sync: forced cleanup, batch state 0 Oct 12 00:24:48.581 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4616 [SYNC]:4952: scoped sync: batch state change from 0 to 0 Oct 12 00:24:48.581 default-bgp/spkr-tr2-sync 0/RP0/CPU0 t4686 [SYNC]:8714: scoped sync: skip sending table update done, global NSR not ready Oct 12 00:29:15.714 bgp/bpm-tr2-gen 0/RP0/CPU0 t4543 [GEN]:4298: BPM verify running (sense=1, asn=65001, inst=default) started Oct 12 00:29:15.714 bgp/bpm-tr2-gen 0/RP0/CPU0 t4543 [GEN]:4383: BPM verify running (sense=1, asn=65001, inst=default) ended Oct 12 00:29:15.723 bgp/bpm-tr2-gen 0/RP0/CPU0 t4543 [GEN]:4547: BPM apply running (sense=1, asn=65001, inst=default) started Oct 12 00:29:15.723 bgp/bpm-tr2-gen 0/RP0/CPU0 t4543 [GEN]:4563: BPM doing apply-running for configuration Oct 12 00:29:15.723 bgp/bpm-tr2-gen 0/RP0/CPU0 t4543 [GEN]:4706: BPM apply running (sense=1, asn=65001, inst=default) ended Oct 12 00:29:15.827 bgp/bpm-tr2-gen 0/RP0/CPU0 t4543 [GEN]:17034: BPM Forward-ref ua-exists: ent - , vrf - CUST-A, inst - default, fr - 0 Oct 12 00:29:17.724 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [AIPC]:340: bpm gen notify: inst-name default, inst-id 0, total publish 26, chkpt count 3 Oct 12 00:29:17.724 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [AIPC]:447: bpm chkpt notify: Chkpt status during 'EDM Gen', ok 1 finished 0 objid-is-null? 1 loc 0 Oct 12 00:29:17.724 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [AIPC]:2040: bpm build txlist: task 1 [1-last-batch,0-more] , inst-id 0, item-count 3, chkpt-count 3, total-item 26, buff-seq 6 Oct 12 00:29:17.724 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [AIPC]:596: bpm buff pack, bscan 0 inst-id 0, buff-seq 6, item-count 3, msg-size 412 Oct 12 00:29:17.724 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [AIPC]:482: Sending init config done signal to inst_id 0, rc 0, loc 1 Oct 12 00:29:17.724 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [AIPC]:535: bpm chkpt notify: Chkpt status after 1 [1-EDM Gen, 2-Monitor Del], bpm_edm_chkpt_items 0, item_cnt 3 Oct 12 00:29:17.724 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [AIPC]:302: func bpm_edm_generate_notifications, event can't find instinfo, instance_id 1 Oct 12 00:29:17.724 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [AIPC]:302: func bpm_edm_generate_notifications, event can't find instinfo, instance_id 2 Oct 12 00:29:17.724 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [AIPC]:302: func bpm_edm_generate_notifications, event can't find instinfo, instance_id 3 Oct 12 00:29:17.724 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [AIPC]:373: bpm send msg, role 0 (1:S, 0:A)inst-id 0, buff-seq 6, msg-id 2, rc 0 Oct 12 00:29:17.724 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [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 12 00:29:17.724 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [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 12 00:29:17.724 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [AIPC]:299: func txlist-no-active-mem, TXLIST cleanup start timer :60 Oct 12 00:29:17.724 default-bgp/spkr-tr2-apic 0/RP0/CPU0 t4629 [AIPC]:1619: func bgp_bpm_ipc_cb: type, event input-wait, p1 3 p2 0 p3 1 Oct 12 00:29:17.725 default-bgp/spkr-tr2-apic 0/RP0/CPU0 t4629 [AIPC]:1358: bgp ipc rcv, inst-id 0, msg-len 412, buff-seq 6, msg count 3, buff-rel 1, init-config 1 [0-not Done , 1-Done] Oct 12 00:29:17.725 default-bgp/spkr-tr2-postit 0/RP0/CPU0 t4685 [POSTIT]:5163: skip postit: 'As-override config change', nbr: 172.16.3.2, reason: 1 Oct 12 00:29:17.925 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [AIPC]:2504: func bpm_ipc_cb: type, event send-status, p1 10 p2 0 p3 0 Oct 12 00:29:17.925 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [AIPC]:525: bpm send status, role 0 (1:S, 0:A)inst-id 0, msg-id 2, send-ok 1, rel buff-seq 0 Oct 12 00:29:19.725 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:7958: trying to find update group for nbr 0x725f1d6de4c0, afi IPv4 Unicast Oct 12 00:29:19.725 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:6921: created update group for table TBL:CUST-A (1/1), index 0.1, nbr 172.16.3.2, flags 0x64000 Oct 12 00:29:19.725 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:2102: Filter-group op (Filter-group Rm Nbr) Tbl/Nbr(Afi:IPv4 Unicast:Nbr:172.16.3.2) fgrp idx 0.1 subgrp idx 0.1 updgrp 0.2 rtset 0 Oct 12 00:29:19.725 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:1566: Filter-group op (Delete) Tbl/Nbr(TBL:CUST-A (1/1)) fgrp idx 0.1 subgrp idx 0.1 updgrp 0.0 rtset 2 Oct 12 00:29:19.725 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:6967: Delete update group for table TBL:CUST-A (1/1), index 0.2 Oct 12 00:29:19.725 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:2244: Filter-group op (Filter-group Compute Nbr RT) Tbl/Nbr(172.16.3.2) fgrp idx 0.1 subgrp idx 0.1 updgrp 0.1 rtset 0 Oct 12 00:29:19.725 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:1476: Filter-group op (Alloc) Tbl/Nbr(TBL:CUST-A (1/1)) fgrp idx 0.2 subgrp idx 0.2 updgrp 0.0 rtset 1 Oct 12 00:29:19.725 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:2792: Filter-group op (Filter-group Add Nbr new) Tbl/Nbr(Afi:IPv4 Unicast:Vrf:CUST-A:Nbr:172.16.3.2) fgrp idx 0.2 subgrp idx 0.2 updgrp 0.1 rtset 0 Oct 12 00:29:19.725 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:2818: created filtergrp 2 for vrf 0x60000002 nbr 172.16.3.2, afi 0, subgrp version 0, refresh 0 Oct 12 00:29:19.726 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4592: Created subgrp:2(0x725ec400e910) refr:0 for nbr 172.16.3.2 (vrf CUST-A), afi 0 version 0 Oct 12 00:29:19.726 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:7104: added vrf 0x60000002 nbr 172.16.3.2 to update group 0.1, afi IPv4 Unicast, flags 0x64000 Oct 12 00:29:19.726 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:3184: TBL:CUST-A (1/1) free subgrp SG:1 subgrp:0x725ec400b6b0 Oct 12 00:29:19.726 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:1381: Update gen Start bit operation Filtergrp delete-timer fgrp idx/size 1 Oct 12 00:29:19.726 default-bgp/spkr-tr2-postit 0/RP0/CPU0 t4688 [POSTIT]:5163: skip postit: 'None', nbr: 172.16.3.2, reason: 1 Oct 12 00:29:19.726 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4688 [UPD]:957: Updgen - Resending table to neighbor 172.16.3.2, afi IPv4 Unicastrt-size 0, parallel refresh 0, route-refresh 0 Oct 12 00:29:19.756 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13186: UPDGEN_UPD: table="TBL:CUST-A (1/1)", parentafi=4, afi=0, updgrp=0.1, subgrp=0.2 Oct 12 00:29:19.756 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13190: UPDGEN_UPD2: table=0xe0000002, subgrp=0.2, walktype=0(Regular), inputtargetver=17, pureRR=0 Oct 12 00:29:19.756 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13193: UPDGEN_UPD3: walkversion=[0 - 17]: resumedver=0, advdisabled=0, completed=1, msgcount=3 Oct 12 00:29:19.756 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=6, adv=5, wdn=0, skp=1, sup=0, bestext=0} Oct 12 00:29:19.756 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 12 00:29:19.756 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4101: UPDGEN_FG_APPEND: AFI=0, UG=1, FG=2, walktype=0, targetver=17: msgcount=3 Oct 12 00:29:19.756 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4104: UPDGEN_FG_APPEND2: fg-prefixstats={adv=5, wdn=0, sup=0, skp=1} Oct 12 00:29:21.640 default-bgp/spkr-tr2-postit 0/RP0/CPU0 t4629 [POSTIT]:5163: skip postit: 'Outbound user soft clear', nbr: 172.16.3.2, reason: 1 Oct 12 00:29:21.640 default-bgp/spkr-tr2-postit 0/RP0/CPU0 t4688 [POSTIT]:5163: skip postit: 'None', nbr: 172.16.3.2, reason: 1 Oct 12 00:29:21.640 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4688 [UPD]:957: Updgen - Resending table to neighbor 172.16.3.2, afi IPv4 Unicastrt-size 0, parallel refresh 0, route-refresh 0 Oct 12 00:29:23.351 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4688 [COMMON]:2504: nbr soft-reconfig 'ptr: 0x725f1d6de4c0',afi: 0 af_flag: 0x091100a4 af3_flag: 0x00080000 loc: 1 Oct 12 00:29:23.351 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4688 [COMMON]:2571: soft-reconfig delayed bestpath: elapsed time(ms) 0, total run 0 , afi IPv4 Unicast, count 1 Oct 12 00:29:23.640 default-bgp/spkr-tr2-postit 0/RP0/CPU0 t4688 [POSTIT]:7502: skip pending postit: nbr: 172.16.3.2, afi: 0, global nsr not ready Oct 12 00:29:23.640 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4688 [UPD]:2102: Filter-group op (Filter-group Rm Nbr) Tbl/Nbr(Afi:IPv4 Unicast:Nbr:172.16.3.2) fgrp idx 0.2 subgrp idx 0.2 updgrp 0.1 rtset 0 Oct 12 00:29:23.640 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4688 [UPD]:1566: Filter-group op (Delete) Tbl/Nbr(TBL:CUST-A (1/1)) fgrp idx 0.2 subgrp idx 0.2 updgrp 0.0 rtset 2 Oct 12 00:29:23.640 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4688 [COMMON]:6095: nbr_ptr 0x725f1d6de4c0 resend updates, afi IPv4 Unicast, versions: 0, 0 fl:0x4 Oct 12 00:29:23.640 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4688 [UPD]:2244: Filter-group op (Filter-group Compute Nbr RT) Tbl/Nbr(172.16.3.2) fgrp idx 0.2 subgrp idx 0.2 updgrp 0.1 rtset 0 Oct 12 00:29:23.640 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4688 [UPD]:1476: Filter-group op (Alloc) Tbl/Nbr(TBL:CUST-A (1/1)) fgrp idx 0.3 subgrp idx 0.1 updgrp 0.0 rtset 1 Oct 12 00:29:23.640 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4688 [UPD]:2792: Filter-group op (Filter-group Add Nbr new) Tbl/Nbr(Afi:IPv4 Unicast:Vrf:CUST-A:Nbr:172.16.3.2) fgrp idx 0.3 subgrp idx 0.1 updgrp 0.1 rtset 0 Oct 12 00:29:23.640 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4688 [UPD]:2818: created filtergrp 3 for vrf 0x60000002 nbr 172.16.3.2, afi 0, subgrp version 0, refresh 0 Oct 12 00:29:23.640 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4688 [UPD]:3392: TBL:CUST-A (1/1) delete subgrp UG/SG:1/2 subgrp:0x725ec400e910 caller 0x5f3014a56e0f Oct 12 00:29:23.641 default-bgp/spkr-tr2-nbr 0/RP0/CPU0 t4685 [NBR]:5297: bgp_default_originate table:0x725f1cdf8cc8 nbr:0x725f1d6de4c0 afi:IPv4 Unicast def_vpn_ctx:REFRESH action:DONOTHING bgp_default_orig_ctx:REFRESH bgp_default_orig_state:Zero old_bgp_default_orig_state:Zero msg-created:False loc:00066700 Oct 12 00:29:23.641 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:1381: Update gen Start bit operation Filtergrp delete-timer fgrp idx/size 2 Oct 12 00:29:23.672 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13186: UPDGEN_UPD: table="TBL:CUST-A (1/1)", parentafi=4, afi=0, updgrp=0.1, subgrp=0.1 Oct 12 00:29:23.672 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13190: UPDGEN_UPD2: table=0xe0000002, subgrp=0.1, walktype=0(Regular), inputtargetver=17, pureRR=0 Oct 12 00:29:23.672 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13193: UPDGEN_UPD3: walkversion=[0 - 17]: resumedver=0, advdisabled=0, completed=1, msgcount=3 Oct 12 00:29:23.672 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13195: UPDGEN_UPD4: prefixstats={total=6, adv=5, wdn=0, skp=1, sup=0, bestext=0} Oct 12 00:29:23.672 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:13197: UPDGEN_UPD5: prefixstats={fg_wdn=0, fg_skp=0} Oct 12 00:29:23.672 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4101: UPDGEN_FG_APPEND: AFI=0, UG=1, FG=3, walktype=0, targetver=17: msgcount=3 Oct 12 00:29:23.672 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:4104: UPDGEN_FG_APPEND2: fg-prefixstats={adv=5, wdn=0, sup=0, skp=1} Oct 12 00:29:23.672 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4682 [COMMON]:857: vrf 0x60000002 nbr 0x725f1d6de4c0, set peer ack version to 17, afi 0, loc 2 Oct 12 00:30:17.724 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [AIPC]:584: bpm chkpt remove: inst-id 0, buff-seq 6, total count 3, delete count 3, ok 1 Oct 12 00:30:17.724 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [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 12 00:30:17.724 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [AIPC]:913: func txlist_timer_expiry, event restart, p1 1 p2 60 p3 1 Oct 12 00:30:19.726 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:1062: Update gen release-index bit operation TBL:CUST-A (1/1) fgrp idx/size 0 Oct 12 00:30:19.726 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:1079: Update gen release-index for bit operation TBL:CUST-A (1/1) fgrp idx/size 2 Oct 12 00:30:19.726 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:1079: Update gen release-index for bit operation TBL:CUST-A (1/1) fgrp idx/size 1 Oct 12 00:30:23.641 default-bgp/spkr-tr2-upd 0/RP0/CPU0 t4685 [UPD]:3184: TBL:CUST-A (1/1) free subgrp SG:2 subgrp:0x725ec400e910 Oct 12 00:30:26.711 default-bgp/spkr-tr2-common 0/RP0/CPU0 t4682 [COMMON]:857: vrf 0x60000002 nbr 0x725f1d6de4c0, set peer ack version to 17, afi 0, loc 2 Oct 12 00:31:17.725 bgp/bpm-tr2-apic 0/RP0/CPU0 t4602 [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