Description

In scenarios where the rpd process on a router exhibits high CPU utilization (100%) for extended periods, it is essential to perform systematic data collection and analysis to determine the root cause. This knowledge base article outlines the steps for data collection and provides guidance on analyzing the collected data.

Symptoms

In the command output below, you can observe that the rpd process is running at 100% CPU utilization. This situation involves the rpd process spiking to high usage unexpectedly and maintaining that elevated level for an extended period.

 

root-r1> show system processes extensive no-forwarding

last pid: 70055; load averages: 2.96, 2.81, 2.88 up 5+19:13:21  18:22:17

391 processes: 11 running, 351 sleeping, 1 zombie, 28 waiting

Mem: 1746M Active, 4439M Inact, 1294M Wired, 440M Buf, 24G Free

Swap: 8192M Total, 8192M Free

 PID USERNAME   PRI NICE  SIZE  RES STATE  C  TIME  WCPU COMMAND

 8820 root     101  0 3459M 2494M CPU0  0 98.1H 100.00% rpd{rpd}

69929 root      81  0  757M 59012K CPU1  1  0:04 33.79% mgd

69738 root      27  0 86692K 44404K select 1  0:00 26.17% cli

69724 root      47  0  757M 59636K RUN   2  0:06 24.27% mgd

69984 root      79  0  757M 58416K RUN   3  0:03 23.29% mgd

  11 root     155 ki31   0K  64K RUN   3 50.4H 18.16% idle{idle: cpu3}

  11 root     155 ki31   0K  64K RUN   2 50.2H 16.80% idle{idle: cpu2}

69734 root      52  0 14896K 2424K wait  2  0:00 16.70% sh

  11 root     155 ki31   0K  64K RUN   1 49.9H 16.46% idle{idle: cpu1}

 

Solution

Data Collection Steps

Step 1: Graph Collection

Please provide the following graphs for analysis:

  • RPD CPU graph for the last 24 hours.
  • RE CPU graph for the last 24 hours.
  • FPC CPU graph for the last 24 hours.

These graphs should include a 5-minute interval for the specified duration, focusing on the time frame of the high CPU impact.

 

Step 2: Accounting Information

Perform the following steps during the period of high RPD CPU utilization:

Enable Accounting and Collect RPD Stats:

RE0> set task accounting on

RE0> set cli timestamps

 

Collect Data for 10 Minutes:

Execute the following commands at 30-second intervals, collecting data five times:

RE0> show task accounting detail | no-more

RE0> show task jobs

RE0> show task io

RE0> show krt queue

RE0> show krt state

RE0> show system process extensive | no-more

 

Disable Accounting:

RE0> set task accounting off

 

Step 3: Task Snapshots

During the period of high RPD CPU, collect the following data five times:

show task memory

show system process extensive | no-more

show system process extensive | match rpd

show rsvp statistics | no-more

show krt indirect-next-hop | no-more

show route summary

show pfe route summary

show bgp summary

show bgp neighbor

show log messages | no-more

show chassis routing-engine | no-more

show krt state

show krt acknowledgement

show krt queue

show task jobs # collect 10 snapshots back to back every 2-3 seconds apart

show task io

show task timers details

show krt queue | no-more # collect 10 back to back snapshots

show krt acknowledgement # collect 4-5 snapshots a couple of mins apart.

show krt indirect-next-hop | no-more

 

 

Step 4: Ifsmon Monitor Output

Run these commands three times at an interval of 10 seconds:

> start shell user root

ifsmon -c

ifsmon -g

ifsmon -P

 

 

Step 5: RTSOCKMON Monitor Output

Obtain rtsockmon output from the RE shell:

 

> start shell user root

% rtsockmon -nrt >> rtsockmon-jtac # run this command for 15 minutes

 

 

 

Analysis

  • Identify when the high RPD utilization started.
  • Check RSI and Varlogs for any relevant logs around the identified time.
  • Examine if there are routes stuck in the KRT queue.
  • Validate task jobs and task accounting to pinpoint where RPD is busy.
  • Check for background jobs and their activities.

 

eg,

 

Background jobs:

Pri Task Job Name             Runs Misses  Wait Flags

 0 bgpio-0/mgmt_resp_proc          0   0   0

 1 MGMT.local/UI Print mode Producer   3005   0   0

 3 RT/Flash update             0   0   0 <SubJob>

 4 RT/rt_static_ifachange_bg       212  253   0

 5 RT/Flash update             6   4   0 <SubJob>

 5 BGP_RT_Background/BGP Peer reconfi   125   0   0

 6 RT/Flash update INET          98  2299   0 <SubJob>

 6 RT/Flash update             98  2298   0 <SubJob>

 6 RT/Flash update INET6          98  2297   0 <SubJob>

 7 BMPp.127.0.0.1+51132/write_job      0 14588   0

 

Task accounting is enabled.

Task            Started  User Time System Time Longest Run

Scheduler         10327050   54.5103   19.6623   1.54186

LMP Client         190862   0.32514   0.07877   0.00783

           Misc    13   0.00011      0   0.00001

         Changes  190849   0.32502   0.07877   0.00783

 

IF             191661   0.83868   0.11842   0.00783

           Misc    13   0.02583   0.00003   0.00229

         Changes  191512   0.81136   0.11839   0.00783

           Jobs   136   0.00148   0.00000   0.00011

 

ISO             101213   0.19171   0.07853   0.00783

           Misc    26   0.00104   0.00000   0.00012

         Changes  101187   0.19066   0.07852   0.00783

 

INET6            101213   0.19406   0.06286   0.00783

           Misc    26   0.00007      0   0.00000

         Changes  101187   0.19399   0.06286   0.00783

 

INET            101291   0.50136   0.06296   0.01512

           Misc    26   0.21328   0.00002   0.01512

         Changes  101265   0.28808   0.06294   0.00783

 

Memory             110   0.14025   0.00004   0.03294

          Timers   110   0.14025   0.00004   0.03294

 

ML_SP.0.0.0.0+8503       26   0.00006      0   0.00000

           Misc    26   0.00006      0   0.00000

 

RPD_TELEMETRY          26   0.00006      0   0.00000

           Misc    26   0.00006      0   0.00000

 

TCNH_TASK           208   0.00038      0   0.00000

         Changes   208   0.00038      0   0.00000

 

RPD Unix Domain Server./v    13   0.00002      0   0.00000

           Misc    13   0.00002      0   0.00000

 

RPD Server.0.0.0.0+666   101200   0.23191   0.04727   0.00783

           Misc    13   0.00002      0   0.00000

         Changes  101187   0.23188   0.04727   0.00783

 

hakr              18   0.00009      0   0.00001

          Timers    18   0.00009      0   0.00001

 

Aggregate            26   0.05757   0.00007   0.00248

           Misc    26   0.05757   0.00007   0.00248

 

RT             418404   17:22.7   0.46367   0.10966

           Misc    26   0.38568   0.00002   0.01799

         Changes  190927   0.78610   0.10283   0.00783

           Jobs  227451   17:21.5   0.36081   0.10966

 

Rt Remote Flash         13   0.00003      0   0.00000

           Misc    13   0.00003      0   0.00000

 

rdc_mtask            26   0.00008      0   0.00000

           Misc    26   0.00008      0   0.00000

 

rds_mtask            26   0.00006      0   0.00000

           Misc    26   0.00006      0   0.00000

 

ids_mtask            26   0.00006      0   0.00000

           Misc    26   0.00006      0   0.00000

 

DYN_TUNNEL           42   0.01518   0.00002   0.00115

           Misc    26   0.01438   0.00002   0.00115

           Jobs    16   0.00080      0   0.00010

 

ICMP              26   0.00009      0   0.00000

           Misc    26   0.00009      0   0.00000

 

Router-Advertisement    189029   0.34546   0.12575   0.00783

           Misc    26   0.00007      0   0.00000

         Changes  188990   0.34534   0.12575   0.00783

           Jobs    13   0.00003      0   0.00000

 

ICMPv6             26   0.00006      0   0.00000

           Misc    26   0.00006      0   0.00000

 

BGP MultiPath          27   0.00011      0   0.00000

           Misc    13   0.00003      0   0.00000

           Jobs    14   0.00007      0   0.00000

 

krtio              52   0.00025      0   0.00001

           Misc    13   0.00003      0   0.00000

          Timers    39   0.00021      0   0.00001

 

mvpn global task        269   0.00068      0   0.00000

           Misc    13   0.00003      0   0.00000

         Changes   256   0.00065      0   0.00000

 

l2vpn global task        48   0.00011   0.00000   0.00000

           Misc    13   0.00002      0   0.00000

         Changes    35   0.00008   0.00000   0.00000

 

BGP_RT_Background      15505   26:48.7   0.40745   0.38660

           Misc    13   4.83874      0   0.38660

           Jobs  15181   26:43.9   0.40745   0.14313

          Timers   311   0.00338   0.00000   0.00010

 

bgpio-0           769296   3.29039   0.92266   0.00784

           Misc    13   0.00003      0   0.00000

           Jobs  769243   3.28992   0.92266   0.00784

          Timers    40   0.00043   0.00000   0.00002

 

bgp-thrio          158526   1:30.49   0.22420   0.14279

           Jobs  157061   1:30.40   0.19321   0.14279

          Timers   1465   0.08234   0.03098   0.00781

 

BGP_Listen.0.0.0.0+179   104445   1.14196   0.02399   0.04066

           Misc    13   0.50646      0   0.04066

         Changes  101239   0.20290   0.02374   0.00783

           Jobs   3193   0.43260   0.00024   0.01639

 

MC             190888   0.36102   0.06319   0.00783

           Misc    13   0.00005      0   0.00000

         Changes  190875   0.36097   0.06319   0.00783

 

MPLS MPLS OAM rcv task     496   0.00224   0.00000   0.00001

          Timers   496   0.00224   0.00000   0.00001

 

MPLS_PM Proto I/O./var/ru   372   0.00372   0.01551   0.00779

           I/O   248   0.00165   0.00000   0.00002

          Timers   124   0.00207   0.01551   0.00779

 

Routing interface service  189007   0.41250   0.05545   0.00783

         Changes  188990   0.38003   0.05544   0.00783

           Jobs    17   0.03247   0.00001   0.00195

 

Condition manager      87803   0.12773   0.07071   0.00783

         Changes  87803   0.12773   0.07071   0.00783

 

MPLSOAMD I/O./var/run/mpl   395   0.00501   0.00783   0.00782

           I/O   260   0.00242      0   0.00002

           Jobs    13   0.00067   0.00782   0.00782

          Timers   122   0.00191   0.00000   0.00003

 

rt-export            26   0.31785   0.00001   0.02032

           Misc    26   0.31785   0.00001   0.02032

 

BFD I/O./var/run/bfdd_con   379   0.02010   0.00002   0.00194

           I/O   248   0.00220   0.00000   0.00002

           Jobs    13   0.01610   0.00001   0.00194

          Timers   118   0.00179   0.00000   0.00005

 

Common L2 VC        189159   0.36087   0.17281   0.00783

           Misc    26   0.00010      0   0.00000

         Changes  189133   0.36077   0.17281   0.00783

 

RT PPM Proto I/O./var/run   1001   0.13782   0.07816   0.00784

           I/O   248   0.00226   0.00000   0.00004

           Jobs   637   0.13348   0.07815   0.00784

          Timers   116   0.00207   0.00000   0.00003

 

BMPp.127.0.0.1+51132     25371   1.76915   0.47730   0.00784

           I/O    50   0.00129      0   0.00005

           Jobs  24974   1.76432   0.47730   0.00784

          Timers   347   0.00353   0.00000   0.00002

 

BGP_64938_10124.169.254.9    67   0.01720   0.00771   0.00769

           I/O    33   0.00711   0.00770   0.00769

          Timers    34   0.01009   0.00001   0.00036

 

Further Actions

If the above logs do not reveal the issue, collect two RPD cores. If RPD remains high for over 20 minutes, collect the first core at the start of the high utilization and the second one after 10 minutes or more, depending on the duration of high CPU utilization.

Modification History

2024-07-16 : Article Created