Why is the CPU load so much higher?

[sibezwo]

Hi Rern

I noticed that the CPU load is at least five times higher on average and fluctuates a lot. A few updates ago, it was usually below 0.10. Now, after an Up Time of 1d 10h 56m, I see a CPU load of 1.14 0.72 0.59. If I watch for a few minutes, it fluctuates between 0.09 and over 1.00.

Another SD card with the latest image and update, manually configured with the same settings, behaves in the same way.

RPi 3B with SMSL Q5 Pro via USB, playing 24/7 "Smooth Jazz Tampa Bay HD" mp3 256kbps stream via WiFi.

Thomas

[sibezwo]

Even after 30 minutes in idle, the CPU load is 0.55 0.37 0.37. This was not the case with previous updates. I always stopped the player before an update and waited afterwards until the CPU load was low enough to perform a reboot.

[rern]

• Run command top.
• See column %CPU - COMMAND for which processes consume the load.

[fillods]

Starting with release 20210414, I also noticed a high CPU load.

I don't have my system at hand right now for further investigation, what I can say is that the high load was not due to a single process. top was not helpful. The more featureful atop was able to reveal that many scripts like status.sh were called in a loop.

[fillods]

Here is the output of atop while listening to a webradio, without any mpc/web client. The atop averaging is over a 10 second period.
Notice the #exit value, there's 50 proc exiting per second, which is quite high for a regular setup.

PRC | sys    3.67s | user   2.74s  | #proc    104 | #trun      2 | #tslpi    69 |  #tslpu     0 | #zombie    0 | clones  50/s |               | #exit   50/s |
CPU | sys      63% | user     36%  | irq       1% | idle      0% | wait      0% |  guest     0% | ipc     0.30 | cycl  996MHz |  avgf 1.00GHz | avgscal 100% |
CPL | avg1    2.70 | avg5    2.28  | avg15   2.09 |              |              |  csw   3111/s | intr  2301/s |              |               | numcpu     1 |
MEM | tot   485.7M | free  291.6M  | cache 105.8M | dirty   0.0M | buff   16.1M |  slab   30.2M | shrss   0.0M | vmbal   0.0M |  zfarc   0.0M | hptot   0.0M |
SWP | tot     0.0M | free    0.0M  |              |              | swcac   0.0M |               |              |              |  vmcom 201.7M | vmlim 242.9M |
DSK |      mmcblk0 | busy      5%  | read     0/s | write    1/s | KiB/r      0 |  KiB/w     16 | MBr/s    0.0 | MBw/s    0.0 |  avq     0.94 | avio 62.5 ms |
NET | transport    | tcpi    60/s  | tcpo    53/s | udpi     0/s | udpo     0/s |  tcpao    5/s | tcppo    3/s | tcprs    0/s |  tcpie    0/s | udpie    0/s |
NET | network      | ipi     60/s  | ipo     53/s | ipfrw    0/s | deliv   60/s |               |              |              |  icmpi    0/s | icmpo    0/s |
NET | eth0    ---- | pcki    23/s  | pcko    14/s | sp    0 Mbps | si  206 Kbps |  so    9 Kbps | erri     0/s | erro     0/s |  drpi     2/s | drpo     0/s |
NET | lo      ---- | pcki    39/s  | pcko    39/s | sp    0 Mbps | si   31 Kbps |  so   31 Kbps | erri     0/s | erro     0/s |  drpi     0/s | drpo     0/s |

  PID   SYSCPU    USRCPU    RDELAY     VGROW     RGROW     RDDSK     WRDSK    RUID       EUID        ST    EXC     THR    S    CPUNR     CPU    CMD       1/15
 1031    0.25s     0.44s     1.20s        0K        0K      0K/s      0K/s    mpd        mpd         --      -       6    S        0      7%    mpd
24248    0.43s     0.00s     0.27s        0K        0K      0K/s      0K/s    root       root        --      -       1    I        0      4%    kworker/0:1-pm
 2515    0.14s     0.02s     0.21s      404K      404K      0K/s      0K/s    alarm      alarm       --      -       1    R        0      2%    atop
21334    0.10s     0.06s         -        0K        0K         -         -    root       -           NE      0       0    E        -      2%    <status.sh>
21463    0.10s     0.05s         -        0K        0K         -         -    root       -           NE      0       0    E        -      2%    <status.sh>
    1    0.03s     0.11s     0.10s        0K        0K      0K/s      0K/s    root       root        --      -       1    R        0      1%    systemd
21205    0.11s     0.02s         -        0K        0K         -         -    root       -           NE      0       0    E        -      1%    <status.sh>
21592    0.04s     0.06s     0.03s     8348K     3056K      0K/s      0K/s    root       root        N-      -       1    S        0      1%    status.sh
   13    0.10s     0.00s     0.09s        0K        0K      0K/s      0K/s    root       root        --      -       1    I        0      1%    rcu_preempt
21199    0.10s     0.00s         -        0K        0K         -         -    root       -           NE     23       0    E        -      1%    <curl>
21485    0.05s     0.04s         -        0K        0K         -         -    root       -           NE      0       0    E        -      1%    <cmd.sh>
21182    0.07s     0.00s         -        0K        0K         -         -    root       -           NE      0       0    E        -      1%    <curl>
21356    0.03s     0.04s         -        0K        0K         -         -    root       -           NE      0       0    E        -      1%    <cmd.sh>
21614    0.03s     0.04s         -        0K        0K         -         -    root       -           NE      0       0    E        -      1%    <cmd.sh>
21440    0.03s     0.03s         -        0K        0K         -         -    root       -           NE      0       0    E        -      1%    <curl>
21333    0.02s     0.04s         -        0K        0K         -         -    root       -           NE      0       0    E        -      1%    <cmd.sh>
21457    0.02s     0.04s         -        0K        0K         -         -    root       -           NE     23       0    E        -      1%    <curl>
21587    0.02s     0.04s         -        0K        0K         -         -    root       -           NE     23       0    E        -      1%    <curl>
 1043    0.04s     0.01s     0.00s        0K        0K      0K/s      4K/s    root       root        --      -       1    S        0      1%    mpdidle.sh
21330    0.02s     0.03s         -        0K        0K         -         -    root       -           NE      0       0    E        -      1%    <mpc>
21337    0.04s     0.01s         -        0K        0K         -         -    root       -           NE      0       0    E        -      1%    <mpc>
21462    0.01s     0.04s         -        0K        0K         -         -    root       -           NE      0       0    E        -      1%    <cmd.sh>
21581    0.02s     0.03s         -        0K        0K         -         -    root       -           NE      0       0    E        -      1%    <mpc>
21629    0.01s     0.04s         -        0K        0K         -         -    root       -           NE      0       0    E        -      1%    <sed>
21591    0.01s     0.03s     0.00s     8480K     3260K      0K/s      0K/s    root       root        N-      -       1    S        0      0%    cmd.sh
21311    0.01s     0.03s         -        0K        0K         -         -    root       -           NE      0       0    E        -      0%    <curl>
21204    0.04s     0.00s         -        0K        0K         -         -    root       -           NE      0       0    E        -      0%    <cmd.sh>
21328    0.02s     0.02s         -        0K        0K         -         -    root       -           NE     23       0    E        -      0%    <curl>
21385    0.02s     0.02s         -        0K        0K         -         -    root       -           NE      0       0    E        -      0%    <awk>

Here is a typical output of pstree:

systemd─┬─2*[agetty]
        ├─...
        ├─mpd───5*[{mpd}]
        ├─mpdidle.sh─┬─mpc
        │            └─mpdidle.sh───cmd.sh───status.sh───cmd.sh

The load average is around 2.05.
I'm worried this high loadavg is running hot the CPU :(

NB: this is running on BeagleBone Black.