Excessive CPU usage on CCGX

[mansr]

Report of increased CPU usage in 2.30:

With all public versions of v2.30 my CCGX sees massive overloads, with an average of around 5.3 during daytime. This leads to display (and mqtt) values being outdated by more than 30 minutes, loss of (zigbee) connection to meter and eventually a reboot. Last working for me was 2.20\~67 (also with the 4.x kernel already). My system consists of two serial MPPTs, a Multi, a modbus coupled PVAC, and a zigbee/RS485 connected meter. Below are two top snapshots when running v2.30\~27 and v2.20\~67 respectively.

v2.30\~27:

Mem: 224436K used, 15708K free, 1336K shrd, 0K buff, 45200K cached
CPU:  69% usr  28% sys   0% nic   0% idle   0% io   0% irq   2% sirq
Load average: 5.27 5.53 5.43 6/217 8605
  PID  PPID USER     STAT   VSZ %VSZ %CPU COMMAND
  746   731 root     S <  71212  30%  26% /opt/victronenergy/gui/gui -nomouse -d
  788   772 root     R    35360  15%  12% {dbus_systemcalc} /usr/bin/python -u /
  798   781 root     R    37384  16%  12% {dbus_mqtt.py} /usr/bin/python -u /opt
  475   473 messageb S     4120   2%   8% dbus-daemon --system --nofork
  817   797 root     S    44220  18%   8% {vrmlogger.py} /usr/bin/python -u /opt
 1211  1149 root     S     3452   1%   4% /opt/victronenergy/mk2-dbus/mk2-dbus -
  827   813 root     S     9336   4%   3% {dbus-modbustcp} /opt/victronenergy/db
  766   748 mosquitt S     6232   3%   3% /usr/sbin/mosquitto -c /etc/mosquitto/
 1261  1254 root     S     3000   1%   3% {vedirect-dbus} /opt/victronenergy/ved
 1257  1251 root     S     3000   1%   3% {vedirect-dbus} /opt/victronenergy/ved
 8582  1866 root     R     2476   1%   2% top
 3172     2 root     IW       0   0%   2% [kworker/u2:4-ev]
  288     2 root     IW       0   0%   2% [kworker/u2:2-ev]
 1303  1301 root     S     8264   3%   1% {dbus-cgwacs} /opt/victronenergy/dbus-
  809   790 root     S     8256   3%   1% {hub4control} /opt/victronenergy/hub4c
 1229  1173 root     S     1724   1%   1% multilog t s25000 n4 /var/log/vedirect
  779   759 root     S     3060   1%   1% {serial-starter.} /bin/bash /opt/victr
 6650     2 root     IW       0   0%   1% [kworker/u2:3-ev]
  829   818 root     S    15880   7%   0% {dbus-fronius} /opt/victronenergy/dbus
 1834   762 root     S     4684   2%   0% sshd: root@pts/0
  823   802 root     S     3060   1%   0% {navico-announce} /bin/sh /opt/victron
 1068  1031 root     S     1724   1%   0% multilog t s25000 n4 /var/log/vedirect
    7     2 root     SW       0   0%   0% [ksoftirqd/0]
  771   752 root     S    30880  13%   0% {mqtt-rpc.py} /usr/bin/python -u /opt/
  815   794 root     S    15080   6%   0% {dbus-qwacs} /opt/victronenergy/dbus-q
  478     1 root     S     7576   3%   0% /usr/sbin/haveged -w 1024 -v 1
 1495  1443 root     S     4768   2%   0% ssh -o ExitOnForwardFailure=yes -o Con
  502     1 avahi    S     3668   2%   0% avahi-daemon: running [d8509119f2e3270
  560     1 avahi-au S     2044   1%   0% avahi-autoipd: [ll-eth0] bound 169.254
  424     1 root     S     1784   1%   0% /usr/sbin/watchdog -c /etc/watchdog.co
  727   718 root     S     1740   1%   0% svscan /service
 8550     2 root     IW       0   0%   0% [kworker/0:0-eve]
  755   741 root     S    23900  10%   0% {localsettings.p} /usr/bin/python -u /
  524     1 nobody   S    20144   8%   0% /usr/sbin/hiawatha
  514     1 root     S    17660   7%   0% php-fpm: master process (/etc/php-fpm.
  515   514 www-data S    17660   7%   0% php-fpm: pool www
  516   514 www-data S    17660   7%   0% php-fpm: pool www
  792   774 root     S    15464   6%   0% {dbus_vebus_to_p} /usr/bin/python -u /
  831   821 simple-u S    10480   4%   0% /bin/simple-upnpd --xml /etc/simple-up
   84     1 root     S    10380   4%   0% /sbin/udevd -d
  559     1 root     S     9308   4%   0% /usr/sbin/wpa_supplicant -u -O /var/ru
  762   744 root     S     4684   2%   0% /usr/sbin/sshd -D -e -f /etc/ssh/sshd_
  521   519 root     S     4640   2%   0% connmand --nodnsproxy --nodaemon
  754   739 root     S     3672   2%   0% {websockify} /opt/victronenergy/websoc
  503   502 avahi    S     3540   1%   0% avahi-daemon: chroot helper
 1866  1834 root     S     3184   1%   0% -sh
 1443   764 root     S     3060   1%   0% {setup-tunnel.sh} /bin/bash /opt/victr

v2.20~67:

Mem: 163340K used, 84040K free, 884K shrd, 0K buff, 42844K cached
CPU:  62% usr  20% sys   0% nic  15% idle   0% io   0% irq   1% sirq
Load average: 2.36 2.94 1.97 1/200 2682
  PID  PPID USER     STAT   VSZ %VSZ %CPU COMMAND
  760   741 root     S    30936  12%  15% {dbus_mqtt.py} /usr/bin/python -u /opt
  710   694 root     S <  59256  24%  11% /opt/victronenergy/gui/gui -nomouse -d
  750   732 root     S    17932   7%  11% {dbus_systemcalc} /usr/bin/python -u /
  777   758 root     S    30196  12%  10% {vrmlogger.py} /usr/bin/python -u /opt
  461   459 messageb R     4344   2%  10% dbus-daemon --system --nofork
  780   765 root     S     9360   4%   4% {dbus-modbustcp} /opt/victronenergy/db
  730   709 mosquitt S     6260   3%   3% /usr/sbin/mosquitto -c /etc/mosquitto/
 1156  1148 root     S     2980   1%   3% {vedirect-dbus} /opt/victronenergy/ved
 1102  1079 root     S     2924   1%   2% /opt/victronenergy/vecan-mk2/mk2-dbus
 1159  1152 root     S     2976   1%   2% {vedirect-dbus} /opt/victronenergy/ved
 1117  1053 root     S     1724   1%   2% multilog t s99999 n8 /log/vedirect.tty
 1299     2 root     IW       0   0%   1% [kworker/u2:3]
 1182  1168 root     S     8276   3%   1% {dbus-cgwacs} /opt/victronenergy/dbus-
  773   752 root     S     8264   3%   1% {hub4control} /opt/victronenergy/hub4c
 1018   946 root     S     1724   1%   1% multilog t s99999 n8 /log/vedirect.tty
   34     2 root     IW       0   0%   1% [kworker/u2:1]
 1996  1377 root     R     2712   1%   1% top
   64     2 root     SW       0   0%   1% [ubifs_bgt0_2]
  782   767 root     S    15860   6%   0% {dbus-fronius} /opt/victronenergy/dbus
  740   721 root     S     3292   1%   0% {serial-starter.} /bin/bash /opt/victr
  734   714 root     S    27692  11%   0% {mqtt-rpc.py} /usr/bin/python -u /opt/
  795   783 simple-u S    10256   4%   0% /bin/simple-upnpd --xml /etc/simple-up
 1321   722 root     S     4920   2%   0% sshd: root@pts/0
 1309   717 root     S     4092   2%   0% {websockify} /opt/victronenergy/websoc
  418     1 root     S     1784   1%   0% /usr/sbin/watchdog -c /etc/watchdog.co
    7     2 root     SW       0   0%   0% [ksoftirqd/0]
   41     2 root     SW       0   0%   0% [ubi_bgt0d]
  720   704 root     S    24132  10%   0% {localsettings.p} /usr/bin/python -u /
  490     1 nobody   S    19020   8%   0% /usr/sbin/hiawatha
  480     1 root     S    17904   7%   0% php-fpm: master process (/etc/php-fpm.
  481   480 www-data S    17904   7%   0% php-fpm: pool www
  482   480 www-data S    17904   7%   0% php-fpm: pool www
  754   735 root     S    15692   6%   0% {dbus_vebus_to_p} /usr/bin/python -u /
  774   756 root     S    15100   6%   0% {dbus-qwacs} /opt/victronenergy/dbus-q
   74     1 root     S    10600   4%   0% /sbin/udevd -d
  537     1 root     S     9308   4%   0% /usr/sbin/wpa_supplicant -u -O /var/ru
  722   706 root     S     4920   2%   0% /usr/sbin/sshd -D -e -f /etc/ssh/sshd_
 1341  1315 root     S     4796   2%   0% ssh -o ExitOnForwardFailure=yes -o Con
  487   485 root     S     4636   2%   0% connmand --nodnsproxy --nodaemon
  717   702 root     S     3824   2%   0% {websockify} /opt/victronenergy/websoc
 1315   724 root     S     3292   1%   0% {setup-tunnel.sh} /bin/bash /opt/victr
 1377  1321 root     S     3292   1%   0% -sh
 1079   947 root     S     3292   1%   0% {start-mk2-dbus.} /bin/sh /opt/victron
 1148  1052 root     S     3292   1%   0% {start-vedirect.} /bin/bash /opt/victr
 1152   945 root     S     3292   1%   0% {start-vedirect.} /bin/bash /opt/victr
 1168  1134 root     S     3292   1%   0% {start-cgwacs.sh} /bin/bash /opt/victr
  783   771 root     S     3292   1%   0% {start-simple-up} /bin/sh /bin/start-s

The main difference here seems to be the GUI, going from 11% CPU to 26%.

[mansr]

This appears to be caused by the new kernel config having HZ=1000. Lowering HZ to 100 makes the problem go away.

[mpvader]

for the 1000Hz issue; what I understand is the following:

• Jeroen set HZ to 1000 [1] during 4.x ccgx kernel testing to fix a wifi issue [2].
• at that setting, cpu usage is increased [3]
• setting it to 100 could be a fix
• any changes to it might affect canbus rx performance: so this needs testing. The requirement is that at 100% busload @ 250kpbs, its performs no worse wrt packetloss than the old kernel.

1. https://github.com/victronenergy/linux/commit/c919f4d772e77fb5d52360fd5ced6e44e2588bf4
2. https://github.com/victronenergy/venus/issues/331
3. https://github.com/victronenergy/venus/issues/425

Mans, will do any other work related to this, which would be testing the wifi and also testing the canbus at full load. Anything else needed?

And is setting to 100 and then testing it indeed the way to go? What are the other machines at?

I don’t know anything about all this. Just want to make sure its properly solved and preferably with as little time from Jeroen as possible

[mpvader]

Mans wrote:

the other machines use dynticks/nohz they are also much faster

Jeroen wrote:

the other machines are not so relevant, since this patch tries to workaround a bug somewhere else in the ccgx.. I am not aware other kernels have this issue. (it might be fixed by the mutex issue as well ...) test it with cansequence.c the CAN-bus is the most time critical function I am aware we have... And it is designed around the assumption that there are no messages dropped

[jhofstee]

For Groningen Hub1 this seems to help, lets wait for https://groups.google.com/d/msg/victron-dev-venus/RluRx3xcl5Q/XMmxAFzJAQAJ or otherwise close the issue. No hung processes spotted yet.

[mansr]

User reports:

I updated to 2.30~35 two days ago and have had no reboot since. I can also confirm that the average load is back to normal levels on my system.

[mpvader]

Indeed; closing!