Description

High CPU, RPD JTASK_SCHED_SLIP can be observed and convergence takes longer during route churn with enabled protocol "traceoptions flag all"

 

Example: The customer lost traffic for more than 30 minutes after a link flap and ospf/BGP trceoptions flag all is enabled.

Symptoms

High CPU, RPD JTASK_SCHED_SLIP can be observed and convergence takes longer during route churn with enabled protocol "traceoptions flag all"

 

The issue is that RPD is hogging on a high CPU state.

 

user@host> start shell

% top

last pid: 50577; load averages: 2.85, 2.63, 2.59                           up 29+03:50:21 01:10:21

118 processes: 3 running, 114 sleeping, 1 zombie

CPU 0:  0.7% user, 0.0% nice, 0.7% system, 0.0% interrupt, 98.6% idle

CPU 1:  0.0% user, 0.0% nice, 35.9% system, 0.0% interrupt, 64.1% idle

CPU 2:  0.7% user, 0.0% nice, 0.7% system, 0.0% interrupt, 98.6% idle

CPU 3:  0.7% user, 0.0% nice, 54.9% system, 0.0% interrupt, 44.4% idle

CPU 4:  0.0% user, 0.0% nice, 10.8% system, 0.0% interrupt, 89.2% idle

CPU 5:  0.0% user, 0.0% nice, 21.8% system, 0.0% interrupt, 78.2% idle

CPU 6:  0.0% user, 0.0% nice, 19.0% system, 0.0% interrupt, 81.0% idle

CPU 7:  0.0% user, 0.0% nice, 2.1% system, 0.0% interrupt, 97.9% idle

CPU 8:  1.4% user, 0.0% nice, 18.4% system, 0.0% interrupt, 80.1% idle

CPU 9:  7.8% user, 0.0% nice, 29.1% system, 0.0% interrupt, 63.1% idle

CPU 10: 0.0% user, 0.0% nice, 22.5% system, 0.0% interrupt, 77.5% idle

CPU 11: 0.0% user, 0.0% nice, 33.6% system, 0.0% interrupt, 66.4% idle

Mem: 2444M Active, 4560M Inact, 1638M Wired, 599M Buf, 85G Free

Swap: 12G Total, 12G Free

 

 PID USERNAME  THR PRI NICE  SIZE  RES STATE  C  TIME  WCPU COMMAND

24852 root     4 52  0 3798M 2912M nanslp 10 310.3H 104.84% rpd.  >>>>>>

50433 root     1 20  0  19M 8928K CPU1   1  0:00  0.57% top

28482 root     35 20  0  136M  46M nanslp  5 98:20  0.34% na-grpcd

19902 root     1  1  0  487M  23M select  2 46.8H  0.32% eventd

..

..

{master}

user@host> show log messages | match kernel

kernel: hw.chassis.startup_time update to 1726780800.397524

kernel: hw.chassis.startup_time update to 1726780800.397522

kernel: rts_setflags: unsupported rtsock type (40) ignored, pid 43339 (rtsockmon)

kernel: rts_setflags: unsupported rtsock type (40) ignored, pid 43339 (rtsockmon)

kernel: rts_setflags: unsupported rtsock type (43) ignored, pid 43339 (rtsockmon)

 

...

rpd[24852]: RPD_RT_HWM_NOTICE: New FIB highwatermark for routes: 191978 [2024-10-19 00:53:58]

rpd[24852]: RPD_RT_HWM_NOTICE: New RIB highwatermark for unique destinations: 594277 [2024-10-19 00:53:59]

rpd[24852]: RPD_RT_HWM_NOTICE: New FIB highwatermark for routes: 192067 [2024-10-19 00:54:29]

rpd[24852]: RPD_RT_HWM_NOTICE: New RIB highwatermark for unique destinations: 594368 [2024-10-19 00:54:32]

rpd[24852]: JTASK_SCHED_SLIP: 5 sec scheduler slip, user: 0 sec 123338 usec, system: 1 sec, 725425 usec

rpd[24852]: JTASK_SCHED_SLIP: 5 sec scheduler slip, user: 0 sec 107577 usec, system: 1 sec, 922890 usec

 

Solution

These traceoptions app-engine-virtual-machine-management-service Should enabled in case customers are seeing any issue with the host OS (kernel communication). As the router running with Next Generations RE's runs a Virtual Machine Management Daemon (vmmd), which communicates with the host OS.

 Also, it is suggested to disable all the types of trace-options until you are troubleshooting a specific issue, as they are CPU & memory-intensive.

 

What fixes the high-CPU% by RPD:

 

user@host> configure

Entering configuration mode

 

{master}[edit]

user@host# deactivate system processes app-engine-virtual-machine-management-service traceoptions

 

{master}[edit]

user@host# deactivate protocols bgp traceoptions

 

{master}[edit]

user@host#show | compare

[edit system processes app-engine-virtual-machine-management-service]

!   inactive: traceoptions { ... }

[edit protocols bgp]

!   inactive: traceoptions { ... }

 

{master}[edit]

user@host#commit

re1:

configuration check succeeds

re0:

commit complete

re1:

commit complete

 

{master}[edit]

user@host#

 

{master}[edit]

user@host#

 

{master}[edit]

user@host#exit

Exiting configuration mode

 

{master}

user@host> start shell

% top

last pid: 51746; load averages: 0.86, 2.09, 2.39                           up 29+03:52:44 01:12:44

119 processes: 2 running, 116 sleeping, 1 zombie

CPU 0:  0.0% user, 0.0% nice, 0.4% system, 0.4% interrupt, 99.2% idle

CPU 1:  0.0% user, 0.0% nice, 0.0% system, 0.0% interrupt, 100% idle

CPU 2:  1.2% user, 0.0% nice, 0.0% system, 0.0% interrupt, 98.8% idle

CPU 3:  0.4% user, 0.0% nice, 0.0% system, 0.0% interrupt, 99.6% idle

CPU 4:  0.0% user, 0.0% nice, 0.4% system, 0.0% interrupt, 99.6% idle

CPU 5:  0.0% user, 0.0% nice, 0.0% system, 0.0% interrupt, 100% idle

CPU 6:  0.0% user, 0.0% nice, 0.4% system, 0.0% interrupt, 99.6% idle

CPU 7:  0.4% user, 0.0% nice, 0.0% system, 0.0% interrupt, 99.6% idle

CPU 8:  0.0% user, 0.0% nice, 0.0% system, 0.0% interrupt, 100% idle

CPU 9:  0.0% user, 0.0% nice, 0.0% system, 0.0% interrupt, 100% idle

CPU 10: 0.4% user, 0.0% nice, 0.0% system, 0.0% interrupt, 99.6% idle

CPU 11: 2.3% user, 0.0% nice, 0.4% system, 0.0% interrupt, 97.3% idle

Mem: 2532M Active, 4560M Inact, 1598M Wired, 599M Buf, 85G Free

Swap: 12G Total, 12G Free

 

 PID USERNAME  THR PRI NICE  SIZE  RES STATE  C  TIME  WCPU COMMAND

24852 root     4 21  0 3878M 2996M CPU8   8 310.3H  3.73% rpd.  >>> RPD is now stable.

20113 root     1 20  0  756M  11M select  8  7:20  0.21% ifstraced

19974 root     2 20  0  608M  61M select  4 47:32  0.13% chassisd

28493 root     1 20  0  547M  85M select  8 33:58  0.11% mib2d

...

 

Modification History

2024-05-28 : Article Created