High System Load, how to identify and resolve

no-clu · 20. Juli 2020

I've installed "Armbian buster with Linux 5.4.49-rockchip64" on my nanopim4v2, straight to SDCard. I ran apt update and upgrade. Then used the install script for ARM devices and everything went fine.

I've been able to login to the webUI fine. I created 1 user. Then I created 2 shares. One temporary test share for SMB. One for Docker and any containers. I set the path for Docker. Then installed Docker and Portainer all using the WebUI. All working great.

Now to problem. I simply leave the system on (doing nothing) over night and next morning a see the 'heartbeat' light flashing away. I wondered why so SSH in and ah... high system load, but low CPU. I don't know how to tackle this but I've tried to include some info below. Let me know what else you might need in order to suggest something. Thanks, any help appreciated.

BTW this is a totally clean install. I've wiped the SDCard, followed ARM install guide and the result is the same, it's fine initially but after some times (hours) the system load ramps up and up.

Code

root@nanopim4v2:~# uptime
 18:56:38 up 2 days, 12:03,  1 user,  load average: 689.18, 685.17, 674.69

Code

root@nanopim4v2:~# ps -e v
  PID TTY      STAT   TIME  MAJFL   TRS   DRS   RSS %MEM COMMAND
    1 ?        Ss     1:24     86  1149 165654 10136  0.2 /sbin/init
    2 ?        S      0:00      0     0     0     0  0.0 [kthreadd]
    3 ?        I<     0:00      0     0     0     0  0.0 [rcu_gp]
    4 ?        I<     0:00      0     0     0     0  0.0 [rcu_par_gp]
    8 ?        I<     0:00      0     0     0     0  0.0 [mm_percpu_wq]
    9 ?        S      0:01      0     0     0     0  0.0 [ksoftirqd/0]

Code

root@nanopim4v2:~# top
top - 18:57:09 up 2 days, 12:04,  1 user,  load average: 689.19, 685.55, 675.15
Tasks: 2949 total,   1 running, 2947 sleeping,   0 stopped,   1 zombie
%Cpu(s):  0.3 us,  0.9 sy,  0.0 ni, 98.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
MiB Mem :   3866.8 total,    157.8 free,   1101.3 used,   2607.7 buff/cache
MiB Swap:      0.0 total,      0.0 free,      0.0 used.   2612.5 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
29799 root      20   0   12204   6276   2528 R   6.4   0.2   0:00.91 top
28361 root      20   0       0      0      0 I   0.3   0.0   0:00.20 kworker/4:2-events
    1 root      20   0  166804  10136   6968 S   0.0   0.3   1:29.27 systemd
    2 root      20   0       0      0      0 S   0.0   0.0   0:00.40 kthreadd
    3 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 rcu_gp
    4 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 rcu_par_gp
    8 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 mm_percpu_wq
    9 root      20   0       0      0      0 S   0.0   0.0   0:01.12 ksoftirqd/0
   10 root      20   0       0      0      0 I   0.0   0.0   0:49.46 rcu_preempt
   11 root      rt   0       0      0      0 S   0.0   0.0   0:00.62 migration/0

...truncated...

Alles anzeigen

no-clu · 20. Juli 2020

Hm... syslog has lots of nginx entries stopping and restarting?? And I cannot connect via WebGUI any more, just SSH. Reboot fixes until it all happens again.

Code

Jul 20 19:39:07 localhost monit[1584]: '\nanopim4v2' loadavg (5min) of 726.6 matches resource limit [loadavg (5min) > 6.0]
Jul 20 19:39:07 localhost monit[1584]: '\nanopim4v2' loadavg (1min) of 730.5 matches resource limit [loadavg (1min) > 12.0]
Jul 20 19:39:07 localhost monit[1584]: 'nginx' failed protocol test [HTTP] at [127.0.0.1]:80 [TCP/IP] -- HTTP error: Server returned status 502
Jul 20 19:39:07 localhost monit[1584]: 'nginx' trying to restart
Jul 20 19:39:07 localhost monit[1584]: 'nginx' stop: '/bin/systemctl stop nginx'
Jul 20 19:39:07 localhost systemd[1]: Stopping A high performance web server and a reverse proxy server...
Jul 20 19:39:07 localhost systemd[1]: nginx.service: Succeeded.
Jul 20 19:39:07 localhost systemd[1]: Stopped A high performance web server and a reverse proxy server.
Jul 20 19:39:07 localhost monit[1584]: 'nginx' start: '/bin/systemctl start nginx'
Jul 20 19:39:07 localhost systemd[1]: Starting A high performance web server and a reverse proxy server...
Jul 20 19:39:07 localhost systemd[1]: Started A high performance web server and a reverse proxy server.
Jul 20 19:39:38 localhost monit[1584]: '\nanopim4v2' loadavg (5min) of 727.2 matches resource limit [loadavg (5min) > 6.0]
Jul 20 19:39:38 localhost monit[1584]: '\nanopim4v2' loadavg (1min) of 731.2 matches resource limit [loadavg (1min) > 12.0]
Jul 20 19:39:38 localhost monit[1584]: 'nginx' failed protocol test [HTTP] at [127.0.0.1]:80 [TCP/IP] -- HTTP error: Server returned status 502
Jul 20 19:39:38 localhost monit[1584]: 'nginx' trying to restart
Jul 20 19:39:38 localhost monit[1584]: 'nginx' stop: '/bin/systemctl stop nginx'
Jul 20 19:39:38 localhost systemd[1]: Stopping A high performance web server and a reverse proxy server...
Jul 20 19:39:38 localhost systemd[1]: nginx.service: Succeeded.
Jul 20 19:39:38 localhost systemd[1]: Stopped A high performance web server and a reverse proxy server.
Jul 20 19:39:38 localhost monit[1584]: 'nginx' start: '/bin/systemctl start nginx'
Jul 20 19:39:38 localhost systemd[1]: Starting A high performance web server and a reverse proxy server...
Jul 20 19:39:38 localhost systemd[1]: Started A high performance web server and a reverse proxy server.
Jul 20 19:40:09 localhost monit[1584]: '\nanopim4v2' loadavg (5min) of 727.7 matches resource limit [loadavg (5min) > 6.0]
Jul 20 19:40:09 localhost monit[1584]: '\nanopim4v2' loadavg (1min) of 731.7 matches resource limit [loadavg (1min) > 12.0]
Jul 20 19:40:09 localhost monit[1584]: 'nginx' failed protocol test [HTTP] at [127.0.0.1]:80 [TCP/IP] -- HTTP error: Server returned status 502
Jul 20 19:40:09 localhost monit[1584]: 'nginx' trying to restart
Jul 20 19:40:09 localhost monit[1584]: 'nginx' stop: '/bin/systemctl stop nginx'
Jul 20 19:40:09 localhost systemd[1]: Stopping A high performance web server and a reverse proxy server...
Jul 20 19:40:09 localhost systemd[1]: nginx.service: Succeeded.
Jul 20 19:40:09 localhost systemd[1]: Stopped A high performance web server and a reverse proxy server.
Jul 20 19:40:09 localhost monit[1584]: 'nginx' start: '/bin/systemctl start nginx'
Jul 20 19:40:09 localhost systemd[1]: Starting A high performance web server and a reverse proxy server...
Jul 20 19:40:09 localhost systemd[1]: Started A high performance web server and a reverse proxy server.

Alles anzeigen

davidh2k · 21. Juli 2020

Take a deeper look at this thread: 502 Bad Gateway nginx

Greetings

David

no-clu · 21. Juli 2020

Zitat von davidh2k

Take a deeper look at this thread: 502 Bad Gateway nginx

Greetings
David

Appreciate the feedback, thanks. I've now read through the suggested thread. I don't see how it directly applies tbh? I've tried some of the commands to see if packages were missing but seems fine. If I reboot everything is working fine, I can access the WebUI, change settings etc... But after what appears to be a random undefined time period the system starts getting the high system loads.

Currently, after last reboot it's still running smoothly.

Code

root@npim4v2:~# uptime
 14:56:25 up 18:48,  1 user,  load average: 0.00, 0.06, 0.07

I expect however that within the next 12 hours he system load will start to increase and then just runaway. Just need to know where I should look to to try and find out the cause. Then obviously try to resolve.

davidh2k · 22. Juli 2020

Zitat von no-clu

. I don't see how it directly applies tbh?

It looked to be similiar to your logs, thus I suggested the look at it.

Zitat von no-clu

But after what appears to be a random undefined time period the system starts getting the high system loads.

Do you by any chance see what is using the ressources in top or htop?

Greetings

David

no-clu · 22. Juli 2020

Zitat von davidh2k

It looked to be similiar to your logs, thus I suggested the look at it.

Sorry, I totally appreciated the direction. While the error in syslog was the same, I was able to access the WebUI etc.. just with a reboot until the next runaway system load increase. The problems, to me, seem unconnected with different symptoms. Although certainly it was worth me looking into, which I did. What I should have said was, my conclusion after reading that thread was that I didn't think it applied to this problem.

Zitat von davidh2k

Do you by any chance see what is using the ressources in top or htop?

When I had the high system load you can see the output of top in my first post above. I don't see anything.

Load averages were all in the 600's (nearly 700's) and the CPU usage was mostly ideal. Biggest use was from top. Although interestingly my system is currently running okay and top only takes 1% of CPU compared to the 6% seen when load was abnormal.

I could not run htop while system load was abnormal, SSH just sat with a blinking cursor until I hit Ctl+C. htop runs okay when the system is behaving.

no-clu · 23. Juli 2020

Okay... this morning I'm seeing the high load again here are is the output from uptime, top and syslog. I cannot run htop.

2 days of running fine, similar timeframe to last one.

Bash

root@npim4v2:~# uptime
 07:00:47 up 2 days, 10:53,  1 user,  load average: 52.26, 48.29, 38.36

and 15 mins later load averages increasing...

Bash

root@npim4v2:~# uptime
 07:17:57 up 2 days, 11:10,  1 user,  load average: 70.37, 66.41, 55.81

Cannot see anything hogging with top.

Bash

root@npim4v2:~# top
top - 07:01:24 up 2 days, 10:53,  1 user,  load average: 52.96, 48.97, 39.01
Tasks: 410 total,   1 running, 408 sleeping,   0 stopped,   1 zombie
%Cpu(s):  0.2 us,  0.2 sy,  0.0 ni, 99.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
MiB Mem :   3866.8 total,   2609.2 free,    376.3 used,    881.2 buff/cache
MiB Swap:      0.0 total,      0.0 free,      0.0 used.   3338.5 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
 9998 root      20   0    9200   3468   2640 R   2.3   0.1   0:00.38 top
    1 root      20   0  166928  10272   7004 S   0.3   0.3   0:53.88 systemd
  497 root      20   0    7784   4504   1420 S   0.3   0.1   0:04.46 haveged
    2 root      20   0       0      0      0 S   0.0   0.0   0:00.36 kthreadd
    3 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 rcu_gp
    4 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 rcu_par_gp
    8 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 mm_percpu_wq
    9 root      20   0       0      0      0 S   0.0   0.0   0:01.30 ksoftirqd/0
   10 root      20   0       0      0      0 I   0.0   0.0   0:49.22 rcu_preempt
   11 root      rt   0       0      0      0 S   0.0   0.0   0:00.69 migration/0
   12 root      20   0       0      0      0 S   0.0   0.0   0:00.00 cpuhp/0
   13 root      20   0       0      0      0 S   0.0   0.0   0:00.00 cpuhp/1
   14 root      rt   0       0      0      0 S   0.0   0.0   0:00.78 migration/1
   15 root      20   0       0      0      0 S   0.0   0.0   0:01.54 ksoftirqd/1
   18 root      20   0       0      0      0 S   0.0   0.0   0:00.00 cpuhp/2
   19 root      rt   0       0      0      0 S   0.0   0.0   0:00.75 migration/2
   20 root      20   0       0      0      0 S   0.0   0.0   0:02.96 ksoftirqd/2
   23 root      20   0       0      0      0 S   0.0   0.0   0:00.00 cpuhp/3
   24 root      rt   0       0      0      0 S   0.0   0.0   0:00.70 migration/3
   25 root      20   0       0      0      0 S   0.0   0.0   0:01.50 ksoftirqd/3
   28 root      20   0       0      0      0 S   0.0   0.0   0:00.00 cpuhp/4
   29 root      rt   0       0      0      0 S   0.0   0.0   0:00.03 migration/4
   30 root      20   0       0      0      0 S   0.0   0.0   0:01.17 ksoftirqd/4

Alles anzeigen

In the last few minutes of the log below something starts to go wrong, but i don't know what. About 05:49 things seem to start going pear shaped followed shortly by the nginx issues.

--syslog is attached--

syslog.txt

davidh2k · 23. Juli 2020

According to some similiar questions on serverfault.com a user suggested that the load average does not need to be linked to explicit load of the CPU but requests to get a CPU timeslot. Even File System waits seem to be able to cause such issues. To be honest, until now I did not know that either of such things can cause a high load average. Yours also seems extremely high.

Greetings
David

no-clu · 23. Juli 2020

Zitat von davidh2k

According to some similiar questions on serverfault.com a user suggested that the load average does not need to be linked to explicit load of the CPU but requests to get a CPU timeslot. Even File System waits seem to be able to cause such issues. To be honest, until now I did not know that either of such things can cause a high load average. Yours also seems extremely high.

Greetings
David

Thanks davidh2k an interesting read and led me to a few useful places. I'd seen that post but dismissed it due to the OS. But on second look there were some linked posts which were very useful. Thanks

My action plan is as follows.

1. Wipe SDCard and reinstall armbian buster for nanopom4v2, leave this running a few days to see if load stays normal or problem persists.

2. If step 1. passes. Install OMV using script for ARM installs.

3. If/When system loads increase use some commands from these sources to try and gain further insight to cause

--a. serverfault.com

--b. brendangregg.com

I'll post back after step 3. Although I'm happy to read any other thoughts in the meantime. Thanks.

Agricola · 28. Juli 2020

I was having the runaway heartbeat some time ago with a version-one M4 and finally figured I had scheduled a remote Rsync to my backup server which coincided with Plex running it’s scheduled maintenance. I moved the schedule a couple hours later and the problem went away.

no-clu · 4. August 2020

Zitat von Agricola

I was having the runaway heartbeat some time ago with a version-one M4 and finally figured I had scheduled a remote Rsync to my backup server which coincided with Plex running it’s scheduled maintenance. I moved the schedule a couple hours later and the problem went away.

I missed this reply. Thanks. This was on a fresh install, all I'd done was, install Docker and Portainer (source on dedicated spinning disk HDD) and created a shared folder on a second spinning HDD and setup SMB share for same folder.

I've had armbian running for over 1 week with no problems. I even filled the SDCard 100% to see if it causes an problems. All runnign smoothly regarding system loads. Stage two is install OMV using install script for ARM devices, leave as is, i.e. totally fresh, excpet change admin password and wait for the system loads to go crazy, then investigate further as not an armbian issue.

Thanks, will update again as I discover and require assistance

Here is the output from Login, Uptime and df

Bash

Welcome to Armbian buster with Linux 5.4.49-rockchip64

System load:   0.00 0.00 0.00   Up time:       11 days 23:59
Memory usage:  4 % of 3866MB    IP:            192.168.50.11
CPU temp:      31°C
Usage of /:    100% of 3.5G

Last login: Sat Jul 25 20:29:16 2020 from

root@nanopim4v2:~# uptime
 21:25:32 up 11 days, 23:59,  1 user,  load average: 0.00, 0.00, 0.00
root@nanopim4v2:~# df
Filesystem     1K-blocks    Used Available Use% Mounted on
udev             1907492       0   1907492   0% /dev
tmpfs             395960   35156    360804   9% /run
/dev/mmcblk1p1   3570624 3553332         0 100% /
tmpfs            1979788       0   1979788   0% /dev/shm
tmpfs               5120       4      5116   1% /run/lock
tmpfs            1979788       0   1979788   0% /sys/fs/cgroup
/dev/zram2       1032088    2588    960688   1% /tmp
/dev/zram0         49584     560     45440   2% /var/log
tmpfs             395956       0    395956   0% /run/user/0

Alles anzeigen

High System Load, how to identify and resolve

Jetzt mitmachen!

Tags