Trigger: Enabling streaming telemetry.
Business Impact: None.
Troubleshooting Steps Taken:
Issue: Higher than expected CPU usage has been observed on Juniper switches after enabling streaming telemetry.
While observing the device's CLI during periods of high CPU usage, the process that appears to be consuming the most resources is mgd and agentd.
mgd
user@switch1> show system processes extensive | except 0.00 last pid: 13491; load averages: 5.39, 5.19, 4.83 up 0+01:07:43 09:05:53 315 threads: 10 running, 282 sleeping, 2 zombie, 21 waiting CPU: 75.0% user, 0.0% nice, 16.0% system, 2.2% interrupt, 6.8% idle Mem: 707M Active, 580M Inact, 237M Wired, 39M Buf, 398M Free PID USERNAME PRI NICE SIZE RES STATE C TIME WCPU COMMAND 13469 root 82 0 312M 47M CPU1 1 0:09 35.99% mgd 13471 root 81 0 312M 47M RUN 0 0:08 31.98% mgd 8739 root -52 r0 958M 190M CPU1 1 12:48 19.97% fxpc{fxpc} 8739 root 20 0 958M 190M select 1 14:04 17.97% fxpc{fxpc} 13488 root 73 0 290M 24M RUN 0 0:01 5.96% mgd 8731 root 23 0 370M 59M select 1 2:05 4.98% chassisd 8749 root 24 0 356M 38M pfesta 1 3:42 3.96% mib2d 8808 root 22 0 55M 26M select 0 3:13 3.96% na-grpcd{na-grpcd} 8808 root 22 0 55M 26M select 1 3:13 3.96% na-grpcd{na-grpcd} 8750 root 26 0 536M 168M kqread 1 1:36 3.96% rpd{rpd} 8666 root 22 0 284M 14M select 1 2:06 2.98% eventd 8801 root 22 0 298M 12M select 1 1:45 1.95% xmlproxyd 8842 root 34 0 292M 51M select 0 1:33 1.95% mgd 8753 root 20 0 362M 27M select 1 0:44 0.98% pfed
Multiple output of "top" can be collected from the Juniper shell to understand the CPU spikes pattern.
% top -SH -d 2 -s2 >> /var/tmp/top-output.log % cat /var/tmp/top-output.log command: top -SH -d 2 -s2 last pid: 75457; load averages: 5.29, 4.90, 4.17 up 63+04:13:33 12:11:43 341 threads: 10 running, 308 sleeping, 2 zombie, 21 waiting CPU 0: -0.2% user, 0.0% nice, 0.0% system, 0.0% interrupt, 0.1% idle CPU 1: -0.2% user, 0.0% nice, 0.0% system, -0.1% interrupt, 0.2% idle Mem: 340M Active, 53M Inact, 30M Laundry, 261M Wired, 50M Buf, 91M Free PID USERNAME PRI NICE SIZE RES STATE C TIME WCPU COMMAND 75287 root 81 0 312M 18M RUN 0 0:07 30.96% mgd 75292 root 80 0 318M 53M RUN 1 0:06 27.98% mgd 8739 root 52 0 958M 175M RUN 0 302.9H 15.97% fxpc{fxpc} 8739 root -52 r0 958M 175M umtxn 0 321.1H 12.99% fxpc{fxpc} 8774 root 22 0 558M 139M select 0 33.7H 7.96% authd{authd} 8731 root 22 0 379M 35M select 0 55.1H 4.98% chassisd 8808 root 23 0 218M 191M CPU0 0 172:26 4.98% na-grpcd{na-grpcd} 8808 root 23 0 218M 191M RUN 0 169:58 3.96% na-grpcd{na-grpcd} 8749 root 22 0 373M 53M pfesta 1 98.3H 2.98% mib2d 8666 root 21 0 284M 4756K select 1 44.7H 2.98% eventd 8801 root 21 0 298M 11M sbwait 1 46.2H 1.95% xmlproxyd 8842 root 30 0 292M 42M select 1 40.5H 0.98% mgd 12 root -72 - 0B 336K WAIT 1 37.4H 0.98% intr{swi1: netisr 0} 12 root -88 - 0B 336K WAIT 1 25.0H 0.98% intr{gic0,s101: bcmrng0} 11 root 155 ki31 0B 32K RUN 0 364.9H 0.00% idle{idle: cpu0} 11 root 155 ki31 0B 32K RUN 1 301.0H 0.00% idle{idle: cpu1} 8750 root 20 0 548M 137M kqread 1 37.8H 0.00% rpd{rpd} 8782 root 20 0 294M 24M select 1 24.0H 0.00% agentd{agentd} last pid: 75457; load averages: 5.29, 4.90, 4.17 up 63+04:13:35 12:11:45 340 threads: 7 running, 311 sleeping, 2 zombie, 20 waiting CPU 0: 67.7% user, 0.0% nice, 16.0% system, 3.1% interrupt, 13.2% idle CPU 1: 81.3% user, 0.0% nice, 12.1% system, 1.9% interrupt, 4.7% idle Mem: 338M Active, 54M Inact, 30M Laundry, 262M Wired, 51M Buf, 91M Free PID USERNAME PRI NICE SIZE RES STATE C TIME WCPU COMMAND 75287 root 83 0 312M 20M CPU1 1 0:09 68.27% mgd 8739 root 77 0 958M 175M RUN 0 302.9H 27.23% fxpc{fxpc} 8739 root -52 r0 958M 175M select 0 321.1H 16.93% fxpc{fxpc} 11 root 155 ki31 0B 32K RUN 0 364.9H 14.12% idle{idle: cpu0} 75292 root 52 0 350M 57M wdrain 1 0:06 9.79% mgd 8808 root 23 0 218M 191M select 1 169:59 9.46% na-grpcd{na-grpcd} 8808 root 23 0 218M 191M select 0 172:26 8.59% na-grpcd{na-grpcd} 8666 root 22 0 284M 4756K select 1 44.7H 7.14% eventd 8731 root 22 0 379M 35M select 0 55.1H 6.91% chassisd 11 root 155 ki31 0B 32K RUN 1 301.0H 5.37% idle{idle: cpu1} 8749 root 22 0 373M 53M pfesta 0 98.3H 4.75% mib2d 8801 root 22 0 298M 11M select 0 46.2H 2.98% xmlproxyd 12 root -72 - 0B 336K CPU1 1 37.4H 2.53% intr{swi1: netisr 0} 8774 root 21 0 558M 139M select 1 33.7H 2.17% authd{authd} 12 root -88 - 0B 336K WAIT 0 25.0H 1.63% intr{gic0,s101: bcmrng0} 8808 root 20 0 218M 191M select 0 0:01 1.03% na-grpcd{na-grpcd} 8795 root 20 0 618M 315M select 1 20:24 0.92% jsd{jsd} 8795 root 20 0 618M 315M select 0 21:02 0.88% jsd{jsd}
We collected grpc-traces and noticed that some clients are frequently reconnecting on the device. Following traces need to be configured,
set system services extension-service traceoptions file grpc-trace set system services extension-service traceoptions file size 20m set system services extension-service traceoptions file files 10 set system services extension-service traceoptions flag all set system services extension-service traceoptions flag libgrpc-debug
Upon further investigation, we noticed that the clients were trying to subscribe to an unsupported sensor /system/alarms. Juniper engineering team confirmed that frequent disconnects can add lot of churn on the CPU and unsupported sensors can cause RPC errors which can lead the clients to disconnect.
Sep 30 09:23:24 hpack_parser.cc:650: Decode: 'grpc-message: Unsupported subscription path, /system/alarms', elem_interned=1 [3], k_interned=1, v_interned=1
It is worth noting that supported sensors for different hardware and software combination keeps evolving. We can get accurate information from Juniper YANG Data Model Explorer.