RP/0/RP0/CPU0:R1#show ospf trace spf_ext Tue Sep 15 05:53:11.171 UTC Traces for OSPF 1 (Thu Jan 1 00:00:00) Traces returned/requested/available: 0/256/0 Trace buffer: spf_ext No trace entries are available RP/0/RP0/CPU0:R1#show ospf trace adj_cycle Tue Sep 15 05:53:12.030 UTC Traces for OSPF 1 (Tue Sep 15 05:53:12) Traces returned/requested/available: 26/8192/26 Trace buffer: adj_cycle 1 Sep 15 05:41:18.731 ospf_rcv_dbd: from 3.3.3.3(10.0.13.3) intf Gi0/0/0/1 seq 0x6aebe187 2 Sep 15 05:41:18.731 ospf_send_dbd: to 3.3.3.3(10.0.13.3) intf Gi0/0/0/1 seq 0x336a311f 3 Sep 15 05:41:18.732 ospf_send_dbd: to 3.3.3.3(10.0.13.3) intf Gi0/0/0/1 seq 0x6aebe187 4 Sep 15 05:41:18.738 ospf_rcv_dbd: from 3.3.3.3(10.0.13.3) intf Gi0/0/0/1 seq 0x6aebe188 5 Sep 15 05:41:18.738 ospf_output: LSA pkt, src 10.0.13.1 dest 10.0.13.3 area 0.0.0.0 intf Gi0/0/0/1 6 Sep 15 05:41:18.738 ospf_send_req: LS REQ pkt, nbr 3.3.3.3/10.0.13.3 cnt 1 unsent 0 7 Sep 15 05:41:18.738 ospf_send_dbd: to 3.3.3.3(10.0.13.3) intf Gi0/0/0/1 seq 0x6aebe188 8 Sep 15 05:41:18.745 ospf_do_hello_packets: LSA pkt, src 10.0.13.3 intf Gi0/0/0/1 type 4 paksize 178 9 Sep 15 05:41:18.745 ospf_do_hello_packets: LSA pkt, src 10.0.13.3 intf Gi0/0/0/1 type 3 paksize 126 10 Sep 15 05:41:18.746 ospf_output: LSA pkt, src 10.0.13.1 dest 10.0.13.3 area 0.0.0.0 intf Gi0/0/0/1 11 Sep 15 05:41:18.798 ospf_output: LSA pkt, src 10.0.13.1 dest 224.0.0.5 area 0.0.0.0 intf Gi0/0/0/1 12 Sep 15 05:41:18.822 ospf_do_hello_packets: LSA pkt, src 10.0.13.3 intf Gi0/0/0/1 type 4 paksize 190 13 Sep 15 05:41:20.746 ospf_output: LSA pkt, src 10.0.13.1 dest 224.0.0.5 area 0.0.0.0 intf Gi0/0/0/1 14 Sep 15 05:41:20.752 ospf_do_hello_packets: LSA pkt, src 10.0.13.3 intf Gi0/0/0/1 type 5 paksize 134 15 Sep 15 05:41:22.136 ospf_do_hello_packets: LSA pkt, src 10.0.13.3 intf Gi0/0/0/1 type 4 paksize 178 16 Sep 15 05:41:22.187 ospf_do_hello_packets: LSA pkt, src 10.0.13.3 intf Gi0/0/0/1 type 4 paksize 202 17 Sep 15 05:41:22.220 ospf_do_hello_packets: LSA pkt, src 10.0.13.3 intf Gi0/0/0/1 type 4 paksize 190 18 Sep 15 05:41:24.137 ospf_output: LSA pkt, src 10.0.13.1 dest 224.0.0.5 area 0.0.0.0 intf Gi0/0/0/1 19 Sep 15 05:41:26.749 ospf_do_hello_packets: LSA pkt, src 10.0.13.3 intf Gi0/0/0/1 type 4 paksize 166 20 Sep 15 05:41:26.800 ospf_do_hello_packets: LSA pkt, src 10.0.13.3 intf Gi0/0/0/1 type 4 paksize 202 21 Sep 15 05:41:28.750 ospf_output: LSA pkt, src 10.0.13.1 dest 224.0.0.5 area 0.0.0.0 intf Gi0/0/0/1 22 Sep 15 05:41:31.797 ospf_do_hello_packets: LSA pkt, src 10.0.13.3 intf Gi0/0/0/1 type 4 paksize 178 23 Sep 15 05:41:33.798 ospf_output: LSA pkt, src 10.0.13.1 dest 224.0.0.5 area 0.0.0.0 intf Gi0/0/0/1 24 Sep 15 05:52:03.624 ospf_output: LSA pkt, src 10.0.13.1 dest 224.0.0.5 area 0.0.0.0 intf Gi0/0/0/1 25 Sep 15 05:52:03.720 ospf_output: LSA pkt, src 10.0.13.1 dest 224.0.0.5 area 0.0.0.0 intf Gi0/0/0/1 26 Sep 15 05:52:05.632 ospf_do_hello_packets: LSA pkt, src 10.0.13.3 intf Gi0/0/0/1 type 5 paksize 154 RP/0/RP0/CPU0:R1#show ospf trace events Tue Sep 15 05:53:12.912 UTC Traces for OSPF 1 (Tue Sep 15 05:53:13) Traces returned/requested/available: 99/4096/99 Trace buffer: events 1 Sep 15 05:40:41.233 ospf_nsr_event_manager_create: Created channel, ISSU-role 0, HA-role 0 2 Sep 15 05:40:42.437 ospf_if_issu_map_complete_cb: IM issu if mapping complete cb: mapping_complete 0x1 3 Sep 15 05:40:42.437 ospf_get_instance_by_name: : Name unknown in inst AVL name tree 4 Sep 15 05:40:42.437 ospf_create_instance: : instance alloc ptr 0x5ef4e3acde70 5 Sep 15 05:40:42.437 ospf_create_instance: : AVL instance insert ptr 0x5ef4e3acde70 6 Sep 15 05:40:42.437 ospf_create_instance: lock instance 0x0 ptr 0x5ef4e3acde70 refcount 1 7 Sep 15 05:40:42.634 ospf_ds_init: op_issu_id 0 8 Sep 15 05:40:44.025 ospf_create_area: : area 0.0.0.0 (0x5ef4e3b68570) dummy 1 9 Sep 15 05:40:44.225 ospf_nsr_fsm_dispatch_event: dispatching event 32, state 0 -> 0, rev 0 10 Sep 15 05:40:44.225 ospf_nsr_fsm_dispatch_event: NSR-index 0x0 11 Sep 15 05:40:44.225 ospf_nsr_fsm_dispatch_event: dispatching event 32, state 0 -> 0, rev 0 12 Sep 15 05:40:44.225 ospf_nsr_fsm_dispatch_event: NSR-index 0x1 13 Sep 15 05:40:44.225 ospf_nsr_fsm_dispatch_event: dispatching event 14, state 0 -> 0, rev 0 14 Sep 15 05:40:44.225 ospf_nsr_fsm_dispatch_event: NSR-index 0x0 15 Sep 15 05:40:44.225 ospf_nsr_fsm_dispatch_event: dispatching event 14, state 0 -> 0, rev 0 16 Sep 15 05:40:44.225 ospf_nsr_fsm_dispatch_event: NSR-index 0x1 17 Sep 15 05:40:44.225 ospf_nsr_fsm_dispatch_event: dispatching event 20, state 0 -> 1, rev 0 18 Sep 15 05:40:44.225 ospf_nsr_fsm_dispatch_event: NSR-index 0x1 19 Sep 15 05:40:44.444 ospf_register_end_of_cfg: Attempt to register for end of config notification 20 Sep 15 05:40:44.524 ospf_cfgmgr_end_of_cfg_reg_cb: Received registration callback 21 Sep 15 05:40:44.524 ospf_cfgmgr_end_of_cfg_reg_cb: Registered for end of config 22 Sep 15 05:40:44.525 ospf_register_end_of_cfg: Registration accepted 23 Sep 15 05:40:44.634 ospf_nsr_fsm_dispatch_event: dispatching event 20, state 0 -> 1, rev 0 24 Sep 15 05:40:44.634 ospf_nsr_fsm_dispatch_event: NSR-index 0x0 25 Sep 15 05:40:44.638 ospf_ds_connect_cb: DS Connected 26 Sep 15 05:40:44.638 ospf_publish_ncd_ds_endp: Proc role not yet known 27 Sep 15 05:40:44.638 ospf_register_ncd_ds_service: Proc role not yet known 28 Sep 15 05:40:44.642 ospf_publish_ncd_ds_endp: Proc role not yet known 29 Sep 15 05:40:44.642 ospf_register_ncd_ds_service: Proc role not yet known 30 Sep 15 05:40:44.723 ospf_update_sckt_vrf_opt: vrf opts update OK for vrfid 0x60000000 31 Sep 15 05:40:44.724 ospf_publish_ncd_ds_endp: DS NCD service successfully published, ISSU role 1, HA role 1, 32 Sep 15 05:40:44.724 ospf_nsr_fsm_dispatch_event: dispatching event 31, state 1 -> 1, rev 0 33 Sep 15 05:40:44.724 ospf_nsr_fsm_dispatch_event: NSR-index 0x0 34 Sep 15 05:40:44.724 ospf_nsr_fsm_dispatch_event: dispatching event 2, state 1 -> 1, rev 0 35 Sep 15 05:40:44.724 ospf_nsr_fsm_dispatch_event: NSR-index 0x0 36 Sep 15 05:40:44.724 ospf_nsr_fsm_dispatch_event: dispatching event 31, state 1 -> 1, rev 0 37 Sep 15 05:40:44.724 ospf_nsr_fsm_dispatch_event: NSR-index 0x1 38 Sep 15 05:40:44.724 ospf_register_ncd_ds_service: Successfully registered for NCD DS notification 39 Sep 15 05:40:44.724 ospf_nsr_fsm_dispatch_event: dispatching event 2, state 1 -> 1, rev 0 40 Sep 15 05:40:44.724 ospf_nsr_fsm_dispatch_event: NSR-index 0x1 41 Sep 15 05:40:44.724 ospf_nsr_fsm_dispatch_event: dispatching event 15, state 1 -> 1, rev 0 42 Sep 15 05:40:44.724 ospf_nsr_fsm_dispatch_event: NSR-index 0x0 43 Sep 15 05:40:44.724 ospf_nsr_fsm_dispatch_event: dispatching event 15, state 1 -> 1, rev 0 44 Sep 15 05:40:44.724 ospf_nsr_fsm_dispatch_event: NSR-index 0x1 45 Sep 15 05:40:44.725 ospf_nsr_msg_chan_update: Update channel, ISSU-role 1, HA-role 1 46 Sep 15 05:40:44.833 ospf_bfd_connect: Attempt to connect to BFD server 47 Sep 15 05:40:44.836 ospf_ds_publish_service_cb: DS NCD service publised succesfully 48 Sep 15 05:40:44.838 ospf_rtrid_set_configured: new_rtr_id 1.1.1.1 49 Sep 15 05:40:44.838 ospf_rtrid_set_configured: rtrid config by value, op_conf_rtr_id 1.1.1.1 vrfid 60000000 50 Sep 15 05:40:44.840 ospf_ds_register_cb: DS NCD service registered succesfully, reg-handle 0x1 51 Sep 15 05:40:44.842 ospf_service_redist_delete: Deleting old redist routes, instance 0x60000000 52 Sep 15 05:40:44.842 ospf_soft_reset: start 53 Sep 15 05:40:44.842 ospf_flush_type5: flush external links 54 Sep 15 05:40:44.842 ospf_flush_type11: flush opaque AS links 55 Sep 15 05:40:44.920 ospf_soft_reset_up: inst 0x5ef4e3acde70 vrfid 0x60000000 delete rid tuple, alloc new rid 56 Sep 15 05:40:44.920 ospf_rtrid_allocate: checking for old rtrid 0x60000000 57 Sep 15 05:40:44.920 ospf_rtrid_allocate: checking for rtrid config 58 Sep 15 05:40:44.920 ospf_rtrid_allocate: rtrid for vrf 0x60000000 set by numeric config: 1.1.1.1 59 Sep 15 05:40:44.925 ospf_soft_reset_up: rtrid: new 1.1.1.1 old 0.0.0.0 60 Sep 15 05:40:44.925 ospf_soft_reset_up: rtrid changed, check vlink for reconfig 61 Sep 15 05:40:44.925 ospf_ds_notify_service_cb: Number of EPs 1 62 Sep 15 05:40:44.925 ospf_ds_notify_service_cb: Setting new DS endp rev 1, number of EPs - 1 63 Sep 15 05:40:44.925 ospf_ncd_ds_endp_update: DS NCD endp, HA-role 1, ISSU-role 1 op_ospf_role 6 64 Sep 15 05:40:44.925 ospf_ncd_ds_endp_update: op_issu_id 0 issu_id 0 65 Sep 15 05:40:44.925 ospf_ncd_ds_endp_update: Ignore DS endp on V1A, ha-role 1, issu-role 1 66 Sep 15 05:40:44.925 ospf_ncd_ds_endp_clean_stale: Cleaning stale NCD endpoints 67 Sep 15 05:40:44.925 ospf_ncd_ds_endp_clean_stale: peer handle not set yet 68 Sep 15 05:40:44.925 ospf_ncd_ds_endp_clean_stale: peer handle not set yet 69 Sep 15 05:40:44.930 ospf_apply_area: instance ptr 0x5ef4e3acde70 70 Sep 15 05:40:44.930 ospf_create_area: : area 0.0.0.0 (0x5ef4e3c4a090) dummy 0 71 Sep 15 05:40:44.937 ospf_bfd_bind_callback: Bind to BFD server - success 72 Sep 15 05:40:44.937 ospf_bfd_conn_callback: Connection to BFD established 73 Sep 15 05:40:44.937 ospf_bfd_send_create_batch: Batch size 0 74 Sep 15 05:40:44.937 ospf_bfd_end_of_replay: Sending EoR to BFD 75 Sep 15 05:40:45.021 ospf_activate_area_ptr: inactive area, area 0.0.0.0 (0x5ef4e3c4a090) op_area_count 1 76 Sep 15 05:40:45.021 ospf_activate_area: active area, area 0.0.0.0 77 Sep 15 05:40:45.845 ospf_service_redist_summary: Start redist-scanning 78 Sep 15 05:40:53.622 ospf_schedule_rtr_lsa: scheduling rtr lsa for area 0.0.0.0 79 Sep 15 05:40:53.722 ospf_if_rtr_id_callback: Router-id sent by IPARM: 1.1.1.1 80 Sep 15 05:40:54.725 ospf_cfgmgr_end_of_cfg_cb: Received end of config callback 81 Sep 15 05:40:54.725 ospf_cfgmgr_end_of_cfg_cb: Success 82 Sep 15 05:40:54.725 ospf_nsr_fsm_dispatch_event: dispatching event 30, state 1 -> 1, rev 1 83 Sep 15 05:40:54.725 ospf_nsr_fsm_dispatch_event: NSR-index 0x0 84 Sep 15 05:40:54.725 ospf_nsr_fsm_dispatch_event: dispatching event 2, state 1 -> 1, rev 1 85 Sep 15 05:40:54.725 ospf_nsr_fsm_dispatch_event: NSR-index 0x0 86 Sep 15 05:40:54.725 ospf_nsr_fsm_dispatch_event: dispatching event 30, state 1 -> 1, rev 1 87 Sep 15 05:40:54.725 ospf_nsr_fsm_dispatch_event: NSR-index 0x1 88 Sep 15 05:40:54.725 ospf_nsr_fsm_dispatch_event: dispatching event 2, state 1 -> 1, rev 1 89 Sep 15 05:40:54.725 ospf_nsr_fsm_dispatch_event: NSR-index 0x1 90 Sep 15 05:40:55.845 ospf_service_redist_summary: Start redist-scanning 91 Sep 15 05:40:59.332 ospf_schedule_rtr_lsa: scheduling rtr lsa for area 0.0.0.0 92 Sep 15 05:41:05.845 ospf_service_redist_summary: Start redist-scanning 93 Sep 15 05:41:18.746 ospf_schedule_rtr_lsa: scheduling rtr lsa for area 0.0.0.0 94 Sep 15 05:42:44.724 ospf_nsr_fsm_dispatch_event: dispatching event 22, state 1 -> 1, rev 1 95 Sep 15 05:42:44.724 ospf_nsr_fsm_dispatch_event: NSR-index 0x0 96 Sep 15 05:42:44.724 ospf_nsr_fsm_dispatch_event: dispatching event 22, state 1 -> 1, rev 1 97 Sep 15 05:42:44.724 ospf_nsr_fsm_dispatch_event: NSR-index 0x1 98 Sep 15 05:52:03.620 ospf_schedule_rtr_lsa: scheduling rtr lsa for area 0.0.0.0 99 Sep 15 05:52:04.620 ospf_service_redist_summary: Start redist-scanning RP/0/RP0/CPU0:R1#show ospf trace adj Tue Sep 15 05:53:13.609 UTC Traces for OSPF 1 (Tue Sep 15 05:53:14) Traces returned/requested/available: 50/8192/50 Trace buffer: adj 1 Sep 15 05:40:42.437 ospf_create_instance: Instance 0x0 quiesce_time INIT 2 Sep 15 05:40:44.025 ospf_create_area: Area 0.0.0.0 quiesce_time INIT 3 Sep 15 05:40:44.842 ospf_build_ex_lsa: no rtrid to build external LSA 4 Sep 15 05:40:44.930 ospf_create_area: Area 0.0.0.0 quiesce_time INIT 5 Sep 15 05:40:45.845 ospf_service_redist_summary: end scanning, elapsed time 000000000.000038253 6 Sep 15 05:40:53.624 ospf_build_rtr_lsa: area 0.0.0.0 rtrid 1.1.1.1 seq 0x80000001 vrfid 0x60000000 7 Sep 15 05:40:55.845 ospf_service_redist_summary: scan for redist 8 Sep 15 05:40:55.845 ospf_service_redist_summary: end scanning, elapsed time 000000000.000032007 9 Sep 15 05:40:59.472 ospf_build_rtr_lsa: area 0.0.0.0 rtrid 1.1.1.1 seq 0x80000002 vrfid 0x60000000 10 Sep 15 05:41:05.845 ospf_service_redist_summary: scan for redist 11 Sep 15 05:41:05.845 ospf_service_redist_summary: end scanning, elapsed time 000000000.000035916 12 Sep 15 05:41:12.331 ospf_if_inc_nbr_cnt: Gi0/0/0/1 - count in inst 1 (ex_load 0), on idb 1 13 Sep 15 05:41:12.331 ospf_inc_nbr_form_cnt: Instance 0x60000000 quiesce_time INIT 14 Sep 15 05:41:12.331 ospf_inc_nbr_form_cnt: Area 0.0.0.0 quiesce_time INIT 15 Sep 15 05:41:12.331 ospf_inc_nbr_form_cnt: nbr 3.3.3.3 forming Gi0/0/0/1, area 0.0.0.0 16 Sep 15 05:41:12.331 ospf_inc_nbr_form_cnt: #Nbrs: (ar: 1, inst: 1) forming, 0 full, area 0.0.0.0 17 Sep 15 05:41:12.331 ospf_log_adj_chg: nbr 3.3.3.3/10.0.13.3 changes from 0 to 2 18 Sep 15 05:41:12.331 ospf_log_adj_chg: Flooding stats: LSA-Req sent: 0 pkts 0 LSAs, LSA-Upd Rcv: 0 pkts 0 LSAs 19 Sep 15 05:41:12.331 ospf_log_adj_chg: DBD Rcv: 0 pkts 0 LSAs, area 0.0.0.0, vrfid 0x60000000 20 Sep 15 05:41:18.731 ospf_log_adj_chg: nbr 3.3.3.3/10.0.13.3 changes from 2 to 3 21 Sep 15 05:41:18.731 ospf_log_adj_chg: Flooding stats: LSA-Req sent: 0 pkts 0 LSAs, LSA-Upd Rcv: 0 pkts 0 LSAs 22 Sep 15 05:41:18.731 ospf_log_adj_chg: DBD Rcv: 0 pkts 0 LSAs, area 0.0.0.0, vrfid 0x60000000 23 Sep 15 05:41:18.731 ospf_log_adj_chg: nbr 3.3.3.3/10.0.13.3 changes from 3 to 4 24 Sep 15 05:41:18.731 ospf_log_adj_chg: Flooding stats: LSA-Req sent: 0 pkts 0 LSAs, LSA-Upd Rcv: 0 pkts 0 LSAs 25 Sep 15 05:41:18.731 ospf_log_adj_chg: DBD Rcv: 0 pkts 0 LSAs, area 0.0.0.0, vrfid 0x60000000 26 Sep 15 05:41:18.731 ospf_log_adj_chg: nbr 3.3.3.3/10.0.13.3 changes from 4 to 5 27 Sep 15 05:41:18.731 ospf_log_adj_chg: Flooding stats: LSA-Req sent: 0 pkts 0 LSAs, LSA-Upd Rcv: 0 pkts 0 LSAs 28 Sep 15 05:41:18.731 ospf_log_adj_chg: DBD Rcv: 0 pkts 0 LSAs, area 0.0.0.0, vrfid 0x60000000 29 Sep 15 05:41:18.731 ospf_nbr_inc_ex_load_count: Inst: 1 neighbors in ex_load Gi0/0/0/1, area 0.0.0.0, instance quiesce_time updated 30 Sep 15 05:41:18.731 ospf_nbr_inc_ex_load_count: Area: 1 neighbors in ex_load Gi0/0/0/1, area 0.0.0.0, area quiesce_time updated 31 Sep 15 05:41:18.731 build_dbd_sum: took 0 ms for nbr 3.3.3.3 count 1 vrf 0x60000000 32 Sep 15 05:41:18.738 ospf_log_adj_chg: nbr 3.3.3.3/10.0.13.3 changes from 5 to 6 33 Sep 15 05:41:18.738 ospf_log_adj_chg: Flooding stats: LSA-Req sent: 0 pkts 0 LSAs, LSA-Upd Rcv: 0 pkts 0 LSAs 34 Sep 15 05:41:18.738 ospf_log_adj_chg: DBD Rcv: 2 pkts 1 LSAs, area 0.0.0.0, vrfid 0x60000000 35 Sep 15 05:41:18.745 ospf_log_adj_chg: nbr 3.3.3.3/10.0.13.3 changes from 6 to 7 36 Sep 15 05:41:18.745 ospf_log_adj_chg: Flooding stats: LSA-Req sent: 1 pkts 1 LSAs, LSA-Upd Rcv: 1 pkts 1 LSAs 37 Sep 15 05:41:18.745 ospf_log_adj_chg: DBD Rcv: 2 pkts 1 LSAs, area 0.0.0.0, vrfid 0x60000000 38 Sep 15 05:41:18.746 ospf_if_inc_nbr_full_cnt: Gi0/0/0/1 - full count in inst 1, on idb 1, area fullcnt 1 39 Sep 15 05:41:18.746 ospf_dec_nbr_form_cnt: nbr 3.3.3.3 forming Gi0/0/0/1, area 0.0.0.0 40 Sep 15 05:41:18.746 ospf_dec_nbr_form_cnt: #Nbrs: (ar: 0, inst: 0) forming, 1 full, area 0.0.0.0 41 Sep 15 05:41:18.798 ospf_build_rtr_lsa: area 0.0.0.0 rtrid 1.1.1.1 seq 0x80000003 vrfid 0x60000000 42 Sep 15 05:41:22.220 ospf_rcv_update: Min Arrival time check fail 4.4.4.4 type 1 Adv rtr 4.4.4.4 vrfid 0x60000000 43 Sep 15 05:41:58.739 ospf_nbr_hold_dbd: Timer expired (nbr_hold_dbd): nbr_id 3.3.3.3 44 Sep 15 05:52:03.621 ospf_redist_default_check: route source 0x3 our_hndl 0x4 45 Sep 15 05:52:03.621 ospf_redist_default_check: Redist default check: default_route 0x5ef4e3ad34c0 event 0x1 46 Sep 15 05:52:03.720 ospf_build_rtr_lsa: area 0.0.0.0 rtrid 1.1.1.1 seq 0x80000004 vrfid 0x60000000 47 Sep 15 05:52:04.620 ospf_service_redist_summary: scan for redist 48 Sep 15 05:52:04.620 ospf_redist_default_check: route source 0x3 our_hndl 0x4 49 Sep 15 05:52:04.620 ospf_redist_default_check: Redist default check: default_route 0x5ef4e3ad34c0 event 0x1 50 Sep 15 05:52:04.621 ospf_service_redist_summary: end scanning, elapsed time 000000000.000198309 exit