cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
6147
Views
30
Helpful
14
Replies

IS-IS Flapping & BFD logging ASR9k - Nokia

Physical Topology:

Nokia - ASR900 - ASR9k1 - ASR9k2 - ASR9k3

 

Logical Topology:

Nokia - ASR9k3

  • ASR9k1: Pseudowire Stitching to ASR900 & ASR9k2

 

Log:

LC/0/0/CPU0:Sep 27 12:17:53.484 BKK: bfd_agent[125]: %L2-BFD-6-SESSION_STATE_DOWN : BFD session to neighbor 10.x.23.90 on interface Bundle-Ether9.1 has gone down. Reason: Control timer expired

 

How should I do?

 

Thank you very much.

1 Accepted Solution

Accepted Solutions

The problem comes from LACP flap, it fixed by configure on ASR900:


interface Port-channel3
 service instance 1 ethernet
  encapsulation untagged
  l2protocol peer lldp lacp
  xconnect 10.x.40.2 519 encapsulation mpls

And I tried to change ASR900 to ASR9k, it no need additional command.

Thank you very much.

View solution in original post

14 Replies 14

smailmilak
Level 4
Level 4

Hi,

 

This message could mean a lot. Maybe the BFD timers are too aggressive or the link is congested.

 

How often does this happen? 

And btw. check out this link

Search for "control timer"

  • No traffic yet
  • sho log | inc tim
    Spoiler
    Wed Sep 27 15:45:02.359 BKK
    LC/0/0/CPU0:Sep 27 15:39:16.986 BKK: bfd_agent[125]: %L2-BFD-6-SESSION_STATE_DOWN : BFD session to neighbor 10.x.23.90 on interface Bundle-Ether9.1 has gone down. Reason: Control timer expired
    LC/0/0/CPU0:Sep 27 15:42:02.691 BKK: bfd_agent[125]: %L2-BFD-6-SESSION_STATE_DOWN : BFD session to neighbor 10.x.23.90 on interface Bundle-Ether9.1 has gone down. Reason: Control timer expired
    LC/0/0/CPU0:Sep 27 15:44:46.571 BKK: bfd_agent[125]: %L2-BFD-6-SESSION_STATE_DOWN : BFD session to neighbor 10.x.23.90 on interface Bundle-Ether9.1 has gone down. Reason: Control timer expired
  • sho bfd session interface be9.1 detail
    Spoiler
    Wed Sep 27 15:49:25.094 BKK
    I/f: Bundle-Ether9.1, Location: 0/0/CPU0
    Dest: 10.x.23.90
    Src: 10.x.23.89
     State: UP for 0d:0h:0m:6s, number of times UP: 1
     Session type: SW/V4/SH/BL
    Received parameters:
     Version: 1, desired tx interval: 100 ms, required rx interval: 100 ms
     Required echo rx interval: 0 ms, multiplier: 3, diag: None
     My discr: 563, your discr: 66137, state UP, D/F/P/C/A: 0/0/0/1/0
    Transmitted parameters:
     Version: 1, desired tx interval: 100 ms, required rx interval: 100 ms
     Required echo rx interval: 0 ms, multiplier: 3, diag: None
     My discr: 66137, your discr: 563, state UP, D/F/P/C/A: 0/0/0/1/0
    Timer Values:
     Local negotiated async tx interval: 100 ms
     Remote negotiated async tx interval: 100 ms
     Desired echo tx interval: 0 s, local negotiated echo tx interval: 0 ms
     Echo detection time: 0 ms(0 ms*3), async detection time: 300 ms(100 ms*3)
    Label:
     Internal label: 24016/0x5dd0
    Local Stats:
     Intervals between async packets:
       Tx: Number of intervals=100, min=8 ms, max=1999 ms, avg=583 ms
           Last packet transmitted 31 ms ago
       Rx: Number of intervals=100, min=5 ms, max=135 ms, avg=100 ms
           Last packet received 73 ms ago
     Intervals between echo packets:
       Tx: Number of intervals=0, min=0 s, max=0 s, avg=0 s
           Last packet transmitted 0 s ago
       Rx: Number of intervals=0, min=0 s, max=0 s, avg=0 s
           Last packet received 0 s ago
     Latency of echo packets (time between tx and rx):
       Number of packets: 0, min=0 ms, max=0 ms, avg=0 ms
    MP download state: BFD_MP_DOWNLOAD_ACK
    State change time: Sep 27 15:47:29.945
    Session owner information:
                                Desired               Adjusted
      Client               Interval   Multiplier Interval   Multiplier
      -------------------- --------------------- ---------------------
      isis-40              100 ms     3          100 ms     3        

Thank you very much.

What IOS-XR version are you running?

do a show bfd trace reverse and paste it here.

  • sho ver bri
    Spoiler
    Wed Sep 27 16:03:53.904 BKK

    Cisco IOS XR Software, Version 5.3.4[Default]
  • show bfd trace reverse
    Spoiler
    Wed Sep 27 16:05:49.460 BKK
    BFD Filter: Unknown Tracepoint: 0x200000c08
    BFD Filter: Unknown Tracepoint: 0x200000c08
    BFD Filter: Unknown Tracepoint: 0x200000c08
    BFD Filter: Unknown Tracepoint: 0x200000c08
    BFD Filter: Unknown Tracepoint: 0x200000c08
    BFD Filter: Unknown Tracepoint: 0x200000c08
    BFD Filter: Unknown Tracepoint: 0x200000c08
    9503 wrapping entries (33792 possible, 0 filtered, 61415 total)
    Sep 27 16:05:20.982 ip_bfd/err 0/RSP0/CPU0 t1  -Traceback = [ip/bfd/src/bfd_db_server.c:10392]: 0x423f1ef 0x421bab6 0x421b749 0x421bceb 0x4214c54 0xecc36d5
    Sep 27 16:05:11.644 ip_bfd/events 0/RSP0/CPU0 t8  Client API notifying app of SCN for session[intf=Bundle-Ether9.1 (ifh=0x80037e0), Dst=10.x.23.90], state 0 , callback 0x420e916, jid 1011
    Sep 27 16:05:11.644 ip_bfd/events 0/RSP0/CPU0 t1  Client API notifying app of SCN for session[intf=Bundle-Ether9.1 (ifh=0x80037e0), Dst=10.x.23.90], state 0 , callback 0x45384d4, jid 1057
    Sep 27 16:05:11.644 ip_bfd/events 0/RSP0/CPU0 t1  Client API notifying app of SCN for session[intf=Bundle-Ether9.1 (ifh=0x80037e0), Dst=10.x.23.90], state 0 , callback 0x421d660, jid 1055
    Sep 27 16:05:11.644 ip_bfd/events 0/RSP0/CPU0 t11 Reply to client read request, num_elem 1, num_queued 1, rc 0
    Sep 27 16:05:11.644 ip_bfd/events 0/RSP0/CPU0 t11 Reply to client read request, num_elem 1, num_queued 1, rc 0
    Sep 27 16:05:11.644 ip_bfd/events 0/RSP0/CPU0 t11 Reply to client read request, num_elem 1, num_queued 1, rc 0
    Sep 27 16:05:11.644 ip_bfd/events 0/RSP0/CPU0 t10 Notified client with app id 13 of data ready
    Sep 27 16:05:11.644 ip_bfd/events 0/RSP0/CPU0 t10 Enqueue session scn [intf=Bundle-Ether9.1 (ifh=0x80037e0), Dst=10.x.23.90], event:0, state 0, app id 13
    Sep 27 16:05:11.644 ip_bfd/events 0/RSP0/CPU0 t10 Notified client with app id 2 of data ready
    Sep 27 16:05:11.644 ip_bfd/events 0/RSP0/CPU0 t10 Enqueue session scn [intf=Bundle-Ether9.1 (ifh=0x80037e0), Dst=10.x.23.90], event:0, state 0, app id 2
    Sep 27 16:05:11.644 ip_bfd/events 0/RSP0/CPU0 t10 Notified client with app id 5 of data ready
    Sep 27 16:05:11.644 ip_bfd/events 0/RSP0/CPU0 t10 Enqueue session scn [intf=Bundle-Ether9.1 (ifh=0x80037e0), Dst=10.x.23.90], event:0, state 0, app id 5
    Sep 27 16:05:11.644 ip_bfd/events 0/RSP0/CPU0 t14 Processed MIB events (cont'd): inter-thread stats: created 0, avg ms 0, max ms 0, trapped 1, avg ms 0, max ms 0
    Sep 27 16:05:11.644 ip_bfd/events 0/RSP0/CPU0 t14 Punted MIB events: Q size 1, noneed create 0, created 0, trapped 1, create error 0, trap error 0, generic error 0
    Sep 27 16:05:11.644 ip_bfd/events 0/RSP0/CPU0 t1  [intf=Bundle-Ether9.1 (ifh=0x80037e0), Dst=10.x.23.90] RX SCN from agent: session found. SCN type 0x1, nodeid 0x801, old state 1, new state 0, number of clients 1
    Sep 27 16:05:11.644 ip_bfd/events 0/RSP0/CPU0 t1  Rx session scn, num_elem 1, nodeid 2049
    Sep 27 16:05:07.036 ip_bfd/events 0/RSP0/CPU0 t14 Processed MIB events (cont'd): inter-thread stats: created 1, avg ms 3, max ms 3, trapped 0, avg ms 0, max ms 0
    Sep 27 16:05:07.036 ip_bfd/events 0/RSP0/CPU0 t14 Punted MIB events: Q size 1, noneed create 0, created 1, trapped 0, create error 0, trap error 0, generic error 0
    Sep 27 16:05:07.036 ip_bfd/events 0/RSP0/CPU0 t14 [0x80037e0 10.x.23.90] Successfully obtained ifIndex for interface Bundle-Ether9.1 @@@ 1: 0xd0
    Sep 27 16:05:07.036 ip_bfd/events 0/RSP0/CPU0 t14 Punted MIB events: ifindex query for 1 items took 3 ms, result 0x0 (No error)
    Sep 27 16:05:07.034 ip_bfd/events 0/RSP0/CPU0 t1  Session created notif received [0x80037e0, 10.x.23.90]: session->discr 0x1025e, scn->discr 0x1025e
    Sep 27 16:05:07.034 ip_bfd/events 0/RSP0/CPU0 t1  MP Download State Change success [intf=Bundle-Ether9.1 (ifh=0x80037e0), Dst=10.x.23.90, Src:10.x.23.89], parent i/f: Bundle-Ether9.1 (0x80037e0), prev dnld state 0 new dnld state 2 for event 0x0, state 0x0
    Sep 27 16:05:07.034 ip_bfd/events 0/RSP0/CPU0 t1  [intf=Bundle-Ether9.1 (ifh=0x80037e0), Dst=10.x.23.90] RX SCN from agent: session found. SCN type 0x2, nodeid 0x801, old state 3, new state 0, number of clients 1
    Sep 27 16:05:07.034 ip_bfd/events 0/RSP0/CPU0 t1  Rx session scn, num_elem 1, nodeid 2049

Thank you very much.

There are some traceback messages. You should compare the timestamps of control timer expired (show log) and timestamps in show bfd trace reverse. If there is nothing unusual you could try to use higher timer values or check out with Cisco TAC.

  • sho bfd tra rev | inc Tra
    Spoiler
    Wed Sep 27 17:07:46.012 BKK
    BFD Filter: Unknown Tracepoint: 0x200000c08
    BFD Filter: Unknown Tracepoint: 0x200000c08
    BFD Filter: Unknown Tracepoint: 0x200000c08
    BFD Filter: Unknown Tracepoint: 0x200000c08
    BFD Filter: Unknown Tracepoint: 0x200000c08
    BFD Filter: Unknown Tracepoint: 0x200000c08
    BFD Filter: Unknown Tracepoint: 0x200000c08
    Sep 27 17:07:21.259 ip_bfd/err 0/RSP0/CPU0 t1  -Traceback = [ip/bfd/src/bfd_db_server.c:10392]: 0x423f1ef 0x421bab6 0x421b749 0x421bceb 0x4214c54 0xecc36d5
    Sep 27 17:04:51.251 ip_bfd/err 0/RSP0/CPU0 t1  -Traceback = [ip/bfd/src/bfd_db_server.c:10392]: 0x423f1ef 0x421bab6 0x421b749 0x421bceb 0x4214c54 0xecc36d5
  • sho log | inc tim
    Spoiler
    Wed Sep 27 17:11:27.582 BKK
    LC/0/0/CPU0:Sep 27 17:04:21.321 BKK: bfd_agent[125]: %L2-BFD-6-SESSION_STATE_DOWN : BFD session to neighbor 10.206.23.90 on interface Bundle-Ether9.1 has gone down. Reason: Control timer expired
    LC/0/0/CPU0:Sep 27 17:05:46.615 BKK: bfd_agent[125]: %L2-BFD-6-SESSION_STATE_DOWN : BFD session to neighbor 10.206.23.90 on interface Bundle-Ether9.1 has gone down. Reason: Control timer expired
    LC/0/0/CPU0:Sep 27 17:07:11.911 BKK: bfd_agent[125]: %L2-BFD-6-SESSION_STATE_DOWN : BFD session to neighbor 10.206.23.90 on interface Bundle-Ether9.1 has gone down. Reason: Control timer expired

Thank you very much.

This looks like a job for Cisco TAC.
My recommendation is to open a service request.

I tried to change timer from 100x3 to 200x3, the result is same (still flap).

If I configure QoS this l2vpn circuit to EXP5, will it help?

 

Thank you very much.

Hi,

I doubt that it will be of any help. You could try, and use EXP6 because BFD packets are marked with DSCP CS6/EXP6.

You could also check if BFD is droped in LPTS
show lpts pifib hardware police location LOCATION

Check if BFD has dropped packets.

Hi,

 

Are BFD packets marked with DSCP CS6/EXP6 by default?

However, no EXP6 configuration on my PE node.

Spoiler
class-map match-all EXP5
 match mpls experimental topmost 5
 end-class-map
!
policy-map CISCO
 class EXP5
  bandwidth percent 25
 !
 class EXP4
  bandwidth percent 15
 !
 class EXP3
  bandwidth percent 15
 !
 class EXP1
  bandwidth percent 10
 !
 class class-default
 !
 end-policy-map
!

Thank you very much.

Well, you can configure it.

 

Have you checked LPTS?

This policy-map is designed by Cisco which used all my MPLS interfaces, I can't change. I think mask this circuit to EXP5 is easier.

No BFD drop on LPTS:

sho lpt pif har pol loc 0/0/cPU0 | inc BFD

Spoiler
Fri Sep 29 09:27:56.025 BKK
-------------------------------------------------------------
                Node 0/0/CPU0:
-------------------------------------------------------------
 Burst = 100ms for all flow types
-------------------------------------------------------------
FlowType               Policer Type    Cur. Rate  Def. Rate  Accepted             Dropped              TOS Value
---------------------- ------- ------- ---------- ---------- -------------------- -------------------- ----------
BFD-known              150     Static  9600       9600       0                    0                    01234567            
BFD-default            160     Static  45340      9600       0                    0                    01234567            
BFD-MP-known           178     Static  11520      11520      0                    0                    01234567            
BFD-MP-0               179     Static  128        128        0                    0                    01234567            
BFD-BLB-known          183     Static  11520      11520      0                    0                    01234567            
BFD-BLB-0              184     Static  128        128        0                    0                    01234567            
BFD-SP-0               182     Static  512        512        0                    0                    01234567           

Thank you very much.

Today I found the LACP is flap:

Oct  9 14:17:15.991 BKK: %EC-5-MINLINKS_NOTMET: Port-channel Port-channel3 is down bundled ports (0) doesn't meet min-links
Oct  9 14:17:15.992 BKK: GigabitEthernet0/2/0 taken out of port-channel3

Oct  9 14:17:16.009 BKK: GigabitEthernet0/2/0 added as member-1 to port-channel3

 

How should I do?

 

Thank you very much.

The problem comes from LACP flap, it fixed by configure on ASR900:


interface Port-channel3
 service instance 1 ethernet
  encapsulation untagged
  l2protocol peer lldp lacp
  xconnect 10.x.40.2 519 encapsulation mpls

And I tried to change ASR900 to ASR9k, it no need additional command.

Thank you very much.