sympa-community / sympa

Sympa, Mailing List Management Software
https://www.sympa.community/sympa
GNU General Public License v2.0
243 stars 96 forks source link

High CPU on MySQL #1589

Closed abdoulosseni closed 1 year ago

abdoulosseni commented 1 year ago

Hello,

We are having a CPU load issue on our server when SYMPA is updating the lists (we have over 900 lists).

Version

Sympa 6.2.70

Installation method

We installed sympa via apt (deb packages)

Expected behavior

No abnormal increase in cpu

Actual behavior

High (100% or more) cpu usage by MySQL.

We put Sympa in debug mode (log_level3) and we see the following logs in a loop:

Feb 6 12:19:32 2e251945e40a task_manager[17]: debug3 Sympa::Database::do_prepared_query() Will perform query "SELECT COUNT() FROM subscriber_table WHERE user_subscriber = ? AND list_subscriber = ? AND robot_subscriber = ? AND inclusion_subscriber IS NOT NULL AND ? <= inclusion_subscriber AND inclusion_ext_subscriber IS NOT NULL AND ? <= inclusion_ext_subscriber" Feb 6 12:19:32 2e251945e40a task_manager[17]: debug3 Sympa::Database::do_prepared_query() Will perform query "UPDATE subscriber_table SET inclusion_subscriber = ?, inclusion_ext_subscriber = ? WHERE user_subscriber = ? AND list_subscriber = ? AND robot_subscriber = ? AND inclusion_subscriber IS NOT NULL AND ? <= inclusion_subscriber" Feb 6 12:19:32 2e251945e40a task_manager[17]: debug3 Sympa::Database::do_prepared_query() Will perform query "UPDATE subscriber_table SET inclusion_subscriber = ?, inclusion_ext_subscriber = ?, inclusion_label_subscriber = ? WHERE user_subscriber = ? AND list_subscriber = ? AND robot_subscriber = ?" Feb 6 12:19:32 2e251945e40a task_manager[17]: debug3 Sympa::Database::do_prepared_query() Will perform query "SELECT COUNT() FROM subscriber_table WHERE user_subscriber = ? AND list_subscriber = ? AND robot_subscriber = ? AND inclusion_subscriber IS NOT NULL AND ? <= inclusion_subscriber AND inclusion_ext_subscriber IS NOT NULL AND ? <= inclusion_ext_subscriber" Feb 6 12:19:32 2e251945e40a task_manager[17]: debug3 Sympa::Database::do_prepared_query() Will perform query "UPDATE subscriber_table SET inclusion_subscriber = ?, inclusion_ext_subscriber = ? WHERE user_subscriber = ? AND list_subscriber = ? AND robot_subscriber = ? AND inclusion_subscriber IS NOT NULL AND ? <= inclusion_subscriber" Feb 6 12:19:32 2e251945e40a task_manager[17]: debug3 Sympa::Database::do_prepared_query() Will perform query "UPDATE subscriber_table SET inclusion_subscriber = ?, inclusion_ext_subscriber = ?, inclusion_label_subscriber = ? WHERE user_subscriber = ? AND list_subscriber = ? AND robot_subscriber = ?" Feb 6 12:19:32 2e251945e40a task_manager[17]: debug3 Sympa::Database::do_prepared_query() Will perform query "SELECT COUNT(*) FROM subscriber_table WHERE user_subscriber = ? AND list_subscriber = ? AND robot_subscriber = ? AND inclusion_subscriber IS NOT NULL AND ? <= inclusion_subscriber AND inclusion_ext_subscriber IS NOT NULL AND ? <= inclusion_ext_subscriber" Feb 6 12:19:32 2e251945e40a task_manager[17]: debug3 Sympa::Database::do_prepared_query() Will perform query "UPDATE subscriber_table SET inclusion_subscriber = ?, inclusion_ext_subscriber = ? WHERE user_subscriber = ? AND list_subscriber = ? AND robot_subscriber = ? AND inclusion_subscriber IS NOT NULL AND ? <= inclusion_subscriber" Feb 6 12:19:32 2e251945e40a task_manager[17]: debug3 Sympa::Database::do_prepared_query() Will perform query "UPDATE subscriber_table SET inclusion_subscriber = ?, inclusion_ext_subscriber = ?, inclusion_label_subscriber = ? WHERE user_subscriber = ? AND list_subscriber = ? AND robot_subscriber = ?"

Regards Abdoul OSSENI

ikedas commented 1 year ago

High (100% or more) cpu usage by MySQL.

This is not enough to determine if CPU usage is really high, much less if queries above are causing the problem. Could you please provide some more information?

abdoulosseni commented 1 year ago

Please find bellow the number of SQL requests made by sympa during the synchronisation of our lists: egrep -i 'UPDATE subscriber_table' /var/log/sympa/sympa.log | cut -d':' -f1,2 | uniq -c 5970 Feb 7 15:16 16863 Feb 7 15:17 18113 Feb 7 15:18 18064 Feb 7 15:19 17842 Feb 7 15:20 17326 Feb 7 15:21 16599 Feb 7 15:22 18091 Feb 7 15:23 18000 Feb 7 15:24 18079 Feb 7 15:25 17392 Feb 7 15:26 17688 Feb 7 15:27 17374 Feb 7 15:28 17980 Feb 7 15:29 13016 Feb 7 15:30

The SQL requests are: Feb 7 15:31:55 72a1b4749564 task_manager[27]: debug3 Sympa::Database::do_prepared_query() Will perform query "UPDATE subscriber_table SET inclusion_subscriber = ?, inclusion_ext_subscriber = ?, inclusion_label_subscriber = ? WHERE user_subscriber = ? AND list_subscriber = ? AND robot_subscriber = ?" Feb 7 15:31:55 72a1b4749564 task_manager[27]: debug3 Sympa::Database::do_prepared_query() Will perform query "SELECT COUNT(*) FROM subscriber_table WHERE user_subscriber = ? AND list_subscriber = ? AND robot_subscriber = ? AND inclusion_subscriber IS NOT NULL AND ? <= inclusion_subscriber AND inclusion_ext_subscriber IS NOT NULL AND ? <= inclusion_ext_subscriber"

Top command result:

top - 15:33:19 up 6 days, 2:55, 8 users, load average: 3,68, 3,82, 3,47 Tâches: 258 total, 3 en cours, 255 en veille, 0 arrêté, 0 zombie %Cpu(s): 18,4 ut, 20,3 sy, 0,0 ni, 53,4 id, 2,7 wa, 0,0 hi, 5,2 si, 0,0 st MiB Mem : 15973,8 total, 3170,7 libr, 2224,7 util, 10578,4 tamp/cache MiB Éch : 7629,0 total, 7627,5 libr, 1,5 util. 12679,7 dispo Mem

PID UTIL.     PR  NI    VIRT    RES    SHR S  %CPU  %MEM    TEMPS+ COM.                                                                                            

1696627 systemd+ 20 0 4034784 654248 156944 S 85,5 4,0 159:37.53 mariadbd
1696226 root 20 0 463300 11720 9460 S 26,1 0,1 5:40.40 syslog-ng
1710815 systemd+ 20 0 242492 204912 13732 S 21,8 1,3 5:28.72 task_manager.pl

When task_manager.pl finish to process, the CPU charge of MySql decrease.

ikedas commented 1 year ago

Please find bellow the number of SQL requests made by sympa during the synchronisation of our lists:

(snip)

Top command result:

top - 15:33:19 up 6 days, 2:55, 8 users, load average: 3,68, 3,82, 3,47 Tâches: 258 total, 3 en cours, 255 en veille, 0 arrêté, 0 zombie %Cpu(s): 18,4 ut, 20,3 sy, 0,0 ni, 53,4 id, 2,7 wa, 0,0 hi, 5,2 si, 0,0 st MiB Mem : 15973,8 total, 3170,7 libr, 2224,7 util, 10578,4 tamp/cache MiB Éch : 7629,0 total, 7627,5 libr, 1,5 util. 12679,7 dispo Mem

PID UTIL.     PR  NI    VIRT    RES    SHR S  %CPU  %MEM    TEMPS+ COM.                                                                                            

1696627 systemd+ 20 0 4034784 654248 156944 S 85,5 4,0 159:37.53 mariadbd 1696226 root 20 0 463300 11720 9460 S 26,1 0,1 5:40.40 syslog-ng 1710815 systemd+ 20 0 242492 204912 13732 S 21,8 1,3 5:28.72 task_manager.pl

"High (100% or more) cpu usage" is not observed.

To begin with, in a multi-core environment, it is common that the total CPU usage exceeds 100% and the load averages are proportional to the number of cores.

When task_manager.pl finish to process, the CPU charge of MySql decrease.

I believe that this is simply because task_manager.pl was busy with the sync_include task and is not an anomaly.

fredbcode commented 1 year ago

I believe that this is simply because task_manager.pl was busy with the sync_include task and is not an anomaly

It's permanently, one core and sometimes more than one is used

With exactly the same lists + version 6.0.1 (on old hardware), the cpu usage is very low (mysql usage is reduced by 10 at least)

If possible we will try to compile 6.0.1 and just switch 6.2.7 to see

ikedas commented 1 year ago

I believe that this is simply because task_manager.pl was busy with the sync_include task and is not an anomaly

It's permanently, one core and sometimes more than one is used

MySQL is the multi-thread application. It's natural that it occasionally uses more than one cores.

With exactly the same lists + version 6.0.1 (on old hardware), the cpu usage is very low (mysql usage is reduced by 10 at least)

If possible we will try to compile 6.0.1 and just switch 6.2.7 to see

The sync_include task of 6.1.x or earlier was sometimes broken and caused problems such as sudden increases in memory consumption (Rather, 6.0.x is no longer practically maintained). 6.2.x improved these problems by relying on the capabilities of the SQL servers. So while Sympa itself consumes less resources, the SQL server consumes more resources.

To begin with, if the utilization of the majority of cores in your environment was at 100% and would not go down, it is anomaly. However, in general, it is normal that the utilization of every core is below 100% at almost all times.

stale[bot] commented 1 year ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.