BFD and OSPF failure

colossus1611 · ‎03-21-2020

Hi Team,

We have a site that has been consistently showing BFD and OSPF fialures on a WAN link, however the Service Provider are suggesting no fault found at end at all.

Is there anyting else that I could look at on my router to identify the fault root cause? The logs I am seeing are as below:

Mar 21 16:21:51.003 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 21 16:21:51.004 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 21 16:21:52.548 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 21 16:21:53.547 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 21 16:21:59.048 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 21 16:21:59.048 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 21 16:22:01.785 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 21 16:25:32.603 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 21 16:25:32.604 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 21 16:25:32.605 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 21 16:25:33.669 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 21 16:25:34.667 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 21 16:25:37.921 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 21 16:25:37.921 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 21 16:25:41.600 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 21 16:57:47.391 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 21 16:57:47.391 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 21 16:57:47.392 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 21 16:57:47.841 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 21 16:57:49.717 AWST: %LINK-3-UPDOWN: Interface GigabitEthernet0/0/0, changed state to down
Mar 21 16:57:49.731 AWST: %LDP-5-NBRCHG: LDP Neighbor 172.28.0.18:0 (1) is DOWN (Interface not operational)
Mar 21 16:57:50.714 AWST: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet0/0/0, changed state to down
Mar 21 16:57:50.841 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 21 16:57:52.714 AWST: %LINK-3-UPDOWN: Interface GigabitEthernet0/0/0, changed state to up
Mar 21 16:57:53.731 AWST: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet0/0/0, changed state to up
Mar 21 16:57:58.778 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 21 16:57:58.779 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 21 16:58:01.744 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 21 16:58:07.272 AWST: %LDP-5-NBRCHG: LDP Neighbor 172.28.0.18:0 (1) is UP
Mar 21 17:16:13.351 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 21 17:16:13.351 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 21 17:16:13.352 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 21 17:16:13.967 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 21 17:16:14.966 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 21 17:16:16.424 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 21 17:16:16.424 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 21 17:16:18.563 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 21 17:26:15.367 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 21 17:26:15.368 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 21 17:26:15.368 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 21 17:26:16.091 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 21 17:26:17.134 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 21 17:26:21.336 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 21 17:26:21.337 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 21 17:26:24.092 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 21 18:13:34.470 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 21 18:13:34.470 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 21 18:13:34.471 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 21 18:13:38.094 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 21 18:13:38.095 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 21 18:13:41.713 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 21 18:16:10.830 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 21 18:16:10.831 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 21 18:16:10.831 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 21 18:16:11.363 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 21 18:16:12.363 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 21 18:16:19.816 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 21 18:16:19.816 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 21 18:16:23.439 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 21 18:33:25.912 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 21 18:33:25.913 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 21 18:33:25.913 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 21 18:33:26.649 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 21 18:33:27.648 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 21 18:33:32.990 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 21 18:33:32.991 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 21 18:33:35.028 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 21 18:37:37.247 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 21 18:37:37.247 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 21 18:37:37.248 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 21 18:37:40.853 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 21 18:37:40.853 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 21 18:37:43.889 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 21 21:21:14.661 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 21 21:21:14.662 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 21 21:21:14.662 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 21 21:21:15.224 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 21 21:21:16.225 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 21 21:21:18.271 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 21 21:21:18.271 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 21 21:21:20.184 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 21 21:24:40.526 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 21 21:24:40.526 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 21 21:24:40.527 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 21 21:24:41.328 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 21 21:24:42.327 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 21 21:24:48.838 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 21 21:24:48.838 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 21 21:24:50.920 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 22 00:18:17.391 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 22 00:18:17.391 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 22 00:18:17.392 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 22 00:18:18.271 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 22 00:18:19.272 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 22 00:18:24.428 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 22 00:18:24.428 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 22 00:18:27.851 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 22 00:25:50.930 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 22 00:25:50.930 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 22 00:25:50.931 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 22 00:25:51.323 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 22 00:25:52.323 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 22 00:25:59.248 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 22 00:25:59.248 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 22 00:26:01.353 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 22 03:30:24.710 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 22 03:30:24.710 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 22 03:30:24.711 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 22 03:30:24.891 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 22 03:30:25.895 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 22 03:30:28.951 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 22 03:30:28.951 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 22 03:30:31.964 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 22 04:21:49.966 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 22 04:21:49.967 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 22 04:21:49.967 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 22 04:21:50.147 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 22 04:21:51.186 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 22 04:21:59.516 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 22 04:21:59.516 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 22 04:22:02.616 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 22 04:58:48.807 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 22 04:58:48.808 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 22 04:58:48.808 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 22 04:58:49.495 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 22 04:58:50.495 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 22 04:58:53.808 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 22 04:58:53.808 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 22 04:58:57.480 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 22 07:53:47.155 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 22 07:53:47.155 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 22 07:53:47.156 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 22 07:53:53.497 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 22 07:53:53.498 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 22 07:53:56.474 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 22 08:23:17.695 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 22 08:23:17.695 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 22 08:23:17.696 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 22 08:23:18.171 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 22 08:23:19.171 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 22 08:23:27.349 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 22 08:23:27.349 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 22 08:23:29.537 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP
Mar 22 09:30:41.543 AWST: %BFDFSM-6-BFD_SESS_DOWN: BFD-SYSLOG: BFD session ld:4097 handle:1,is going Down Reason: ECHO FAILURE
Mar 22 09:30:41.544 AWST: %BFD-6-BFD_SESS_DESTROYED: BFD-SYSLOG: bfd_session_destroyed, ld:4097 neigh proc:OSPF, handle:1 act
Mar 22 09:30:41.544 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from FULL to DOWN, Neighbor Down: BFD node down
Mar 22 09:30:42.357 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 22 09:30:43.356 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 22 09:30:49.657 AWST: %OSPF-5-ADJCHG: Process 1, Nbr 172.28.0.18 on GigabitEthernet0/0/0 from LOADING to FULL, Loading Done
Mar 22 09:30:49.657 AWST: %BFD-6-BFD_SESS_CREATED: BFD-SYSLOG: bfd_session_created, neigh 10.255.174.113 proc:OSPF, idb:GigabitEthernet0/0/0 handle:1 act
Mar 22 09:30:52.415 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Up -> Down
Mar 22 09:30:53.416 AWST: %TRACK-6-STATE: 1 interface Gi0/0/0 line-protocol Down -> Up
Mar 22 09:30:53.798 AWST: %BFDFSM-6-BFD_SESS_UP: BFD-SYSLOG: BFD session ld:4097 handle:1 is going UP

balaji.bandi · ‎03-21-2020

%LINK-3-UPDOWN: Interface GigabitEthernet0/0/0, changed state to down

Since you mentioned there is no issue with provider, i would first start investing physical patch cable from provider NTU to Gig interface , they are intact, or if possible replace with new one check.

Also like to see the configuration and IPSLA, also stats on the interface see how is your utilisation of the port to gain more information.

BB

***** Rate All Helpful Responses *****

How to Ask The Cisco Community for Help

colossus1611 · ‎03-21-2020

Hello,

Here are the stats on that interface Gig0/0/0, noteworthy that I am seeing a lot of output drops as well as Lost carrier counts. The traffic on the link has been bursty it seems but still below 10Mb limit; the average is also well below the 10Mbps that this service is providing. Have also attached a sanitised version of config for this device.

GigabitEthernet0/0/0 is up, line protocol is up
Hardware is C1111-2x1GE, address is 2cf8.9b63.1300 (bia 2cf8.9b63.1300)
Internet address is 10.255.174.118/29
MTU 1522 bytes, BW 10000 Kbit/sec, DLY 100 usec,
reliability 255/255, txload 1/255, rxload 3/255
Encapsulation ARPA, loopback not set
Keepalive not supported
Full Duplex, 100Mbps, link type is auto, media type is RJ45
output flow-control is off, input flow-control is off
ARP type: ARPA, ARP Timeout 04:00:00
Last input 00:00:00, output 00:00:00, output hang never
Last clearing of "show interface" counters 2d00h
Input queue: 0/375/0/0 (size/max/drops/flushes); Total output drops: 2467
Queueing strategy: Class-based queueing
Output queue: 0/40 (size/max)
30 second input rate 127000 bits/sec, 29 packets/sec
30 second output rate 44000 bits/sec, 32 packets/sec
7492538 packets input, 3580021640 bytes, 0 no buffer
Received 0 broadcasts (0 IP multicasts)
0 runts, 1 giants, 0 throttles
2 input errors, 1 CRC, 0 frame, 0 overrun, 0 ignored
0 watchdog, 110657 multicast, 0 pause input
6881718 packets output, 1629511778 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
0 unknown protocol drops
0 babbles, 0 late collision, 0 deferred
47 lost carrier, 0 no carrier, 0 pause output
0 output buffer failures, 0 output buffers swapped out

There's no IP SLA configuration on the device.

Joseph W. Doherty · ‎03-22-2020

Loss of BFD packets, of course, will cause BFD to drop. Often bandwidth usage is calculated on a much, much larger time scale than it takes to overflow an egress queue and drop some packets. A link flap might be enough to cause BFD to drop too.

I see you're using WRED in class-default. (NB: which show some drops both "random" and tail. The drop count is relatively low, but the point of interest it's happening.) Unless you're a QoS expert, I recommend against using WRED. If supported, I would suggest using fair-queue.

Also BTW, I'm unsure all Cisco platforms include L2 overhead in their shaper bandwidth calculation. Further, w/o knowing what parameters your provider is using to enforce your contracted 10 Mbps rate, you might be bursting above what your provider allows for your 10 Mbps. If so, they (your provider) could be dropping some of your traffic. (How/why did you chose the Bc value you did?)

Giuseppe Larosa · ‎03-21-2020

Hello @colossus1611 ,

in addition to what have been suggested by @balaji.bandi can you provide the output of

show version

show run int gi0/0/0

Because depending on the platform the BFD timers may be too small.

Hope to help

Giuseppe

colossus1611 · ‎03-21-2020

Hi Giuseppe,

Just posted the running config with other stats. Thanks.

Giuseppe Larosa · ‎03-21-2020

Hello @colossus1611 ,

you have a Cisco ISR 1100 router that is a software based IOS XE device.

Your BFD template is fine:

>> bfd-template single-hop BFD_TEMPLATE
interval min-tx 600 min-rx 600 multiplier 3
echo

However, can you explain the QoS configuraton applied outbound to interface gi0/0/0 ?

policy-map L2-TELSTRA-SHAPING
class class-default
shape average 9700000 97000 0
service-policy L1-QUEUING
!

The parent policy-map a shaper is fine as you have a 10 Mbps bidirectional contract with the ISP.

However, the child policy the scheduler should be reviewed in my opinion

I understand your device is acting as a PE node and that you have MPLS labeled packets traveling out ge0/0/0

So you have defined classes that can match on the top MPLS label EXP value:

class-map match-any L1-CS1.AF11.AF12.AF13-EXP1
match dscp cs1 af11 af12 af13
match mpls experimental topmost 1
class-map match-any L1-CS2.AF21.AF22.AF23-EXP2
match dscp cs2 af21 af22 af23
match mpls experimental topmost 2
class-map match-any L1-CS5.EF-EXP5
match dscp cs5 ef
match mpls experimental topmost 5
class-map match-any L1-CS4.AF41.AF42.AF43-EXP4
match dscp cs4 af41 af42 af43
match mpls experimental topmost 4
class-map match-any L1-DSCP7-EXP7
match dscp cs7
match mpls experimental topmost 7
class-map match-any L1-DSCP6-EXP6
match dscp cs6
match mpls experimental topmost 6
class-map match-any L1-CS3.AF31.AF32.AF3-EXP3
match dscp cs3 af31 af32 af33
match mpls experimental topmost 3
!

And this is fine.

the scheduler definition is :

policy-map L1-QUEUING
class L1-DSCP7-EXP7
bandwidth remaining percent 1
class L1-DSCP6-EXP6
bandwidth remaining percent 1
class L1-CS5.EF-EXP5
priority level 1
police rate percent 10
class L1-CS4.AF41.AF42.AF43-EXP4
bandwidth remaining percent 20
class L1-CS3.AF31.AF32.AF3-EXP3
bandwidth remaining percent 15
class L1-CS2.AF21.AF22.AF23-EXP2
bandwidth remaining percent 15
class L1-CS1.AF11.AF12.AF13-EXP1
bandwidth remaining percent 10
class class-default
random-detect

You have bandwidth 10000 under the gi0/0/0 interface this is fine but here in child policy bandwidth should be inherited by parent policy 9700000 bps.

What is missing ?

A class-map for BFD traffic.

BFD packets one hop travel without a label

I would suggest to create a dedicated class for them using an extended ACL to define them and to put that class near the beginning of policy-map definition, order matters.

if your BFD packets travel with IP precedence six you are giving them

>> bandwidth remaining percent 1

if they are travelling with IP Prec 0 they are likely in class default.

About the output drops you have a policer verify if the output drops are the same as the dropped packets by policer using

show policy-map interface gi0/0/0

be prepared for a long output

Hope to help

Giuseppe

colossus1611 · ‎03-22-2020

Hi Giuseppe,

Thanks for looking into the QoS configuration there. So are we saying that the BFD drops are because there is no class-map defining/covering BFD packets? I have an exact same setup for another site, including the QoS class-map and policy-map configuration, and that site is showing no BFD failures at all interstingly. You mentioned about the BFD travelling with IP Precedence 0 or 1, how can I verify that? Also, since there are already Layer 1 link flaps as noted by @balaji.banadi too, are we saying that there are two separate issues here possibly?

Policy-map policer output shows same drops as below:
GigabitEthernet0/0/0

Service-policy output: L2-TELSTRA-SHAPING

Class-map: class-default (match-any)
7179630 packets, 1692690809 bytes
30 second offered rate 50000 bps, drop rate 0000 bps
Match: any
Queueing
queue limit 64 packets
(queue depth/total drops/no-buffer drops) 0/2491/0
(pkts output/bytes output) 6365426/1643345809
shape (average) cir 9700000, bc 97000, be 0
target shape rate 9700000

Service-policy : L1-QUEUING

queue stats for all priority classes:
Queueing
priority level 1
queue limit 512 packets
(queue depth/total drops/no-buffer drops) 0/0/0
(pkts output/bytes output) 1096106/231769812

Class-map: L1-DSCP7-EXP7 (match-any)
0 packets, 0 bytes
30 second offered rate 0000 bps, drop rate 0000 bps
Match: dscp cs7 (56)
Match: mpls experimental topmost 7
Queueing
queue limit 64 packets
(queue depth/total drops/no-buffer drops) 0/0/0
(pkts output/bytes output) 0/0
bandwidth remaining 1%

Class-map: L1-DSCP6-EXP6 (match-any)
1122731 packets, 110695480 bytes
30 second offered rate 4000 bps, drop rate 0000 bps
Match: dscp cs6 (48)
Match: mpls experimental topmost 6
Queueing
queue limit 64 packets
(queue depth/total drops/no-buffer drops) 0/0/0
(pkts output/bytes output) 311019/62764224
bandwidth remaining 1%

Class-map: L1-CS5.EF-EXP5 (match-any)
1096106 packets, 231769812 bytes
30 second offered rate 1000 bps, drop rate 0000 bps
Match: dscp cs5 (40) ef (46)
Match: mpls experimental topmost 5
Priority: Strict, b/w exceed drops: 0

Priority Level: 1
police:
rate 10 %
rate 970000 bps, burst 30312 bytes
conformed 1096106 packets, 231769812 bytes; actions:
transmit
exceeded 0 packets, 0 bytes; actions:
drop
conformed 1000 bps, exceeded 0000 bps

Class-map: L1-CS4.AF41.AF42.AF43-EXP4 (match-any)
520281 packets, 373302109 bytes
30 second offered rate 0000 bps, drop rate 0000 bps
Match: dscp cs4 (32) af41 (34) af42 (36) af43 (38)
Match: mpls experimental topmost 4
Queueing
queue limit 64 packets
(queue depth/total drops/no-buffer drops) 0/0/0
(pkts output/bytes output) 520281/373302109
bandwidth remaining 20%

Class-map: L1-CS3.AF31.AF32.AF3-EXP3 (match-any)
162786 packets, 97850293 bytes
30 second offered rate 4000 bps, drop rate 0000 bps
Match: dscp cs3 (24) af31 (26) af32 (28) af33 (30)
Match: mpls experimental topmost 3
Queueing
queue limit 64 packets
(queue depth/total drops/no-buffer drops) 0/0/0
(pkts output/bytes output) 162786/97850293
bandwidth remaining 15%

Class-map: L1-CS2.AF21.AF22.AF23-EXP2 (match-any)
8348 packets, 1117033 bytes
30 second offered rate 0000 bps, drop rate 0000 bps
Match: dscp cs2 (16) af21 (18) af22 (20) af23 (22)
Match: mpls experimental topmost 2
Queueing
queue limit 64 packets
(queue depth/total drops/no-buffer drops) 0/0/0
(pkts output/bytes output) 8348/1117033
bandwidth remaining 15%

Class-map: L1-CS1.AF11.AF12.AF13-EXP1 (match-any)
309 packets, 31678 bytes
30 second offered rate 0000 bps, drop rate 0000 bps
Match: dscp cs1 (8) af11 (10) af12 (12) af13 (14)
Match: mpls experimental topmost 1
Queueing
queue limit 64 packets
(queue depth/total drops/no-buffer drops) 0/0/0
(pkts output/bytes output) 309/31678
bandwidth remaining 10%

Class-map: class-default (match-any)
4269069 packets, 877924404 bytes
30 second offered rate 40000 bps, drop rate 0000 bps
Match: any

queue limit 64 packets
(queue depth/total drops/no-buffer drops) 0/2491/0
(pkts output/bytes output) 4266577/876510660
Exp-weight-constant: 9 (1/512)
Mean queue depth: 0 packets
class Transmitted Random drop Tail drop Minimum Maximum Mark
pkts/bytes pkts/bytes pkts/bytes thresh thresh prob

0 4266577/876510660 68/38124 411/244004 16 32 1/10
1 0/0 0/0 0/0 18 32 1/10
2 0/0 0/0 0/0 20 32 1/10
3 0/0 0/0 0/0 22 32 1/10
4 0/0 0/0 0/0 24 32 1/10
5 0/0 0/0 0/0 26 32 1/10
6 0/0 0/0 0/0 28 32 1/10
7 0/0 0/0 0/0 30 32 1/10

Thanks.

balaji.bandi · ‎03-22-2020

As of now there may be 2 issues, until we fix one and move to next the solution will not be in place.

Since you confirmed that other side working same config, - for instance you think that is not QoS issue.

I would first investigate physical issue, once that is confirmed all good, if still issue, we can get in to further tweaking config side.

Other note : when did this started this issue, how long it was working (or is this new setup having issue - to asses better).

BB

***** Rate All Helpful Responses *****

How to Ask The Cisco Community for Help

colossus1611 · ‎03-22-2020

Thanks @balaji.banadi. I have organised for a field engineer visit to site to investigate on the physical layer. Hopefully that resolves the issue. I, however, noticed that the link only goes down for one second, every time it happens, and it does not necessarily happen before the BFD failure, it in fact happens after it.

balaji.bandi · ‎03-22-2020

For now i suspect still, there may be small loose contact for now. let us know out come of field engineer visit.

BB

***** Rate All Helpful Responses *****

How to Ask The Cisco Community for Help

Joseph W. Doherty · ‎03-22-2020

". . . put that class near the beginning of policy-map definition, order matters."

BTW, to expand a bit on this, order, does, and doesn't matter. Policy map class order is important for matching, i.e. first class match is what is used for that traffic, but for priority of traffic processing treatment, order doesn't matter.

colossus1611 · ‎03-22-2020

@joseph, we recently migrated the WAN service for this site and the problem has persisted ever since, so some of those settings/configuration has been inherited and I suppose we can tweak it as required to try and resolve this issue.

colossus1611 · ‎03-25-2020

So it hasn't been a cabling issue with the Layer 1 up to NTU being cleared of any physical layer issues. Still pursuing with Service Provider for lost carrier issues and dorp outs, but haven't got anywhere else to go other than that.