Description

KRT queue stuck on router labrouter_re0 was causing transit traffic drop.

Symptoms

Junos Version

Model: mx960

Junos: 19.4R3-S2.2

JUNOS Selective Update J1 [19.4R3-S2-J1]

 

KRT State

root@labrouter_re0show krt state

 

General state:

       Install job is not running

        Number of operations queued: 10025

               Routing table adds: 0

                Interface routes: 259

                High pri multicast  Adds/Changes: 31

                Indirect Next Hop   Adds/Changes: 4      Deletes: 167

               MPLS       Adds: 1      Changes: 0

               High pri   Adds: 0      Changes: 0      Deletes: 1

                Normal pri Indirects: 35

                Normal pri Adds: 3968   Changes: 2622   Deletes: 2937

               GMP GENCFG Objects: 0

               Routing Table deletes: 0

       Number of operations deferred: 0

       Number of operations canceled: 0

        Number of async queue entries: 33629

       Number of async non queue entries: 0

       Time until next queue run: 0

       Routes learned from kernel: 1416943

 

 

 

 

Solution

Based on the analysis of the available logs, we suspect that the communication issues reported between the routing engine may be contributing to the slow state consumption on the backup routing engine. This situation appears to be leading to the KRT queue piling up on RE0, resulting in the queue being stuck. We were successful in recovering the system by disabling GRES/NSR and subsequently replacing the faulty backup RE. 

Nov 21 03:14:08 labrouter_re0 local3.notice: labrouter: kernel: %KERN-5: tcp_timer_keep: Dropping socket connection due to keepalive timer expiration, idle/intvl/cnt: 500/500/3

Nov 21 03:14:08 labrouter_re0 local3.notice: labrouter: kernel: %KERN-5: tcp_timer_keep:Local(0x80000004:15001) Foreign(0x80000005:62863)

Nov 21 03:14:10 labrouter_re0 local3.notice: labrouter: kernel: %KERN-5: tcp_timer_keep: Dropping socket connection due to keepalive timer expiration, idle/intvl/cnt: 500/500/3

Nov 21 03:14:10 labrouter_re0 local3.notice: labrouter: kernel: %KERN-5: tcp_timer_keep:Local(0x80000004:15001) Foreign(0x80000005:63946)

Nov 21 03:14:13 labrouter_re0 local3.notice: labrouter: kernel: %KERN-5: tcp_timer_keep: Dropping socket connection due to keepalive timer expiration, idle/intvl/cnt: 500/500/3

Nov 21 03:14:13 labrouter_re0 local3.notice: labrouter: kernel: %KERN-5: tcp_timer_keep:Local(0x80000004:15001) Foreign(0x80000005:64489)

Nov 21 03:14:13 labrouter_re0 local3.notice: labrouter: kernel: %KERN-5: tcp_timer_keep: Dropping socket connection due to keepalive timer expiration, idle/intvl/cnt: 500/500/3

 

Nov 21 03:14:13 labrouter_re0 local3.notice: labrouter: kernel: %KERN-5: tcp_timer_keep:Local(0x80000004:15001) Foreign(0x80000005:52417)

Nov 21 03:23:55 labrouter_re0 local3.err: labrouter: kernel: %KERN-3: rt_pfe_veto: Too many delayed route/nexthop unrefs. Op 2 err 55, rtsm_id 5:-1, msg type 2, veto simulation: 0

Nov 21 03:23:55 labrouter_re0 local3.err: labrouter: kernel: %KERN-3: rt_pfe_veto: Memory usage of M_RTNEXTHOP type = (0) Max size possible for M_RTNEXTHOP type = (25089099776) Current delayed unref = (60000), Max delayed unref on this platform = (40000) Current delayed weight unref = (60243) Max delayed weight unref on this platform= (400000) curproc = rpd

Nov 21 03:23:55 labrouter_re0 local3.err: labrouter: kernel: %KERN-3: rt_pfe_veto: Possible slowest client is vrrpd. States processed - 2368128716. States to be processed - 33

Nov 21 03:23:55 labrouter_re0 local3.err: labrouter: kernel: %KERN-3: rt_pfe_veto: Possible second slowest client is xdpc7. States processed - 2368128716. States to be processed - 33

Nov 21 03:24:00 labrouter_re0 local3.err: labrouter: kernel: %KERN-3: rt_pfe_veto: Too many delayed route/nexthop unrefs. Op 2 err 55, rtsm_id 5:-1, msg type 2, veto simulation: 0

Nov 21 03:24:00 labrouter_re0 local3.err: labrouter: kernel: %KERN-3: rt_pfe_veto: Memory usage of M_RTNEXTHOP type = (0) Max size possible for M_RTNEXTHOP type = (25089099776) Current delayed unref = (60000), Max delayed unref on this platform = (40000) Current delayed weight unref = (60243) Max delayed weight unref on this platform= (400000) curproc = rpd

Nov 21 03:24:05 labrouter_re0 local3.err: labrouter: kernel: %KERN-3: rt_pfe_veto: Too many delayed route/nexthop unrefs. Op 2 err 55, rtsm_id 5:-1, msg type 2, veto simulation: 0

Nov 21 03:24:05 labrouter_re0 local3.err: labrouter: kernel: %KERN-3: rt_pfe_veto: Memory usage of M_RTNEXTHOP type = (0) Max size possible for M_RTNEXTHOP type = (25089099776) Current delayed unref = (60001), Max delayed unref on this platform = (40000) Current delayed weight unref = (60244) Max delayed weight unref on this platform= (400000) curproc = rpd

...

 

IFSMON Output reports that RE1 is not consuming states completely

CLIENT PROGRESS PERCENTAGE: 

Client Name         Next state          HPNS                states done         states acked        statesdone percent  statesacked

 

xdpc8               0                   0                   1954949             1954947             100.000             100.000             

xdpc7               0                   0                   1954949             1954947             100.000             100.000             

slaveRE1            0                   0                   1954949             4244                100.000             0.217  

 

Modification History

2024-12-09 : Article Created