System Delay - httpd-prefork

[IanGP]

Hi All,

VERSION: 2.14-697a
BUILD: 190121-2019
Version: 2.14b0.5
SVN Version: 3061
DB Schema Version: 1562
DB Schema Update Date: 2019-01-22 05:44:08
Asterisk 13.21.1-vici

We are having issues where agents report slow systems and ultimately System Delay.
When this happens top shows quite a number of instances of httpd-prefork.
Any ideas as to why this might be happening?

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2105 mysql 20 0 13.174g 2.662g 216088 S 114.62 4.237 206:44.86 mysqld
2456 root 19 -1 9369676 100188 28880 S 29.900 0.152 109:52.46 asterisk
2643 root 20 0 66568 20200 6496 S 2.990 0.031 13:04.47 AST_update_AMI2
10792 root 20 0 54700 14252 6260 S 0.997 0.022 0:00.11 AST_vm_update.p
2646 root 20 0 46024 11860 6016 S 0.664 0.018 7:38.59 AST_manager_sen
7388 wwwrun 20 0 312628 24548 15948 S 0.664 0.037 0:00.55 httpd-prefork
9122 wwwrun 20 0 312340 24444 15984 S 0.664 0.037 0:00.34 httpd-prefork
28421 root 20 0 90876 56828 6236 S 0.664 0.086 2:33.01 AST_VDadapt.pl
29497 wwwrun 20 0 313008 26380 17276 S 0.664 0.040 0:02.48 httpd-prefork
841 wwwrun 20 0 312964 26516 17468 S 0.332 0.040 0:01.56 httpd-prefork
1249 wwwrun 20 0 312724 24940 16188 S 0.332 0.038 0:01.34 httpd-prefork
1253 wwwrun 20 0 312680 24292 15548 S 0.332 0.037 0:01.46 httpd-prefork
1442 root 20 0 22300 2932 2468 S 0.332 0.004 0:22.11 irqd
1443 wwwrun 20 0 312484 24828 16348 S 0.332 0.038 0:01.38 httpd-prefork
1528 wwwrun 20 0 312740 25968 17248 S 0.332 0.039 0:01.36 httpd-prefork
1851 wwwrun 20 0 312668 24824 16188 S 0.332 0.038 0:01.68 httpd-prefork
1854 wwwrun 20 0 312704 25040 16380 S 0.332 0.038 0:01.36 httpd-prefork
2372 root 31 11 536456 461380 16688 S 0.332 0.701 2:45.25 syncthing
2468 wwwrun 20 0 312656 24744 16124 S 0.332 0.038 0:01.36 httpd-prefork
2652 root 20 0 55756 21508 5992 S 0.332 0.033 2:39.24 AST_VDauto_dial
3023 wwwrun 20 0 312672 25160 16504 S 0.332 0.038 0:01.12 httpd-prefork
3547 wwwrun 20 0 312832 25192 16380 S 0.332 0.038 0:01.46 httpd-prefork
3665 wwwrun 20 0 312860 25088 16188 S 0.332 0.038 0:01.05 httpd-prefork
3874 wwwrun 20 0 312972 25560 16444 S 0.332 0.039 0:01.28 httpd-prefork
3875 wwwrun 20 0 312812 25668 16892 S 0.332 0.039 0:00.81 httpd-prefork
4777 wwwrun 20 0 312444 24200 15676 S 0.332 0.037 0:00.80 httpd-prefork
5570 wwwrun 20 0 312552 24584 16032 S 0.332 0.037 0:00.82 httpd-prefork
5714 wwwrun 20 0 312876 24608 15740 S 0.332 0.037 0:00.68 httpd-prefork
5913 wwwrun 20 0 312484 23504 15008 S 0.332 0.036 0:00.79 httpd-prefork
5972 wwwrun 20 0 312404 24456 15932 S 0.332 0.037 0:00.64 httpd-prefork
6167 wwwrun 20 0 312596 24032 15420 S 0.332 0.036 0:00.73 httpd-prefork
6174 wwwrun 20 0 312888 26200 17340 S 0.332 0.040 0:00.70 httpd-prefork
6657 wwwrun 20 0 312440 22388 14012 S 0.332 0.034 0:00.56 httpd-prefork
7003 wwwrun 20 0 312416 22224 13820 S 0.332 0.034 0:00.39 httpd-prefork
7192 wwwrun 20 0 312668 24888 16252 S 0.332 0.038 0:00.47 httpd-prefork
7195 wwwrun 20 0 312432 22796 14332 S 0.332 0.035 0:00.44 httpd-prefork
7408 wwwrun 20 0 312636 24804 16188 S 0.332 0.038 0:00.61 httpd-prefork
7409 wwwrun 20 0 312328 22036 13728 S 0.332 0.033 0:00.47 httpd-prefork
7530 wwwrun 20 0 313080 25612 16700 S 0.332 0.039 0:00.48 httpd-prefork
8095 wwwrun 20 0 312616 24208 15612 S 0.332 0.037 0:00.43 httpd-prefork
8513 wwwrun 20 0 312672 24752 16124 S 0.332 0.038 0:00.35 httpd-prefork
8802 wwwrun 20 0 312680 24884 16252 S 0.332 0.038 0:00.30 httpd-prefork
8832 wwwrun 20 0 312516 24224 15728 S 0.332 0.037 0:00.28 httpd-prefork
8834 wwwrun 20 0 312420 24452 15932 S 0.332 0.037 0:00.30 httpd-prefork
9668 wwwrun 20 0 312420 23572 15244 S 0.332 0.036 0:00.23 httpd-prefork
9976 wwwrun 20 0 312632 23872 15292 S 0.332 0.036 0:00.16 httpd-prefork
10004 wwwrun 20 0 312028 20108 12124 S 0.332 0.031 0:00.04 httpd-prefork
10395 wwwrun 20 0 312244 21564 13360 S 0.332 0.033 0:00.03 httpd-prefork

Thanks
IanGP

[carpenox]

the preforks are normal, they arent killing your ram and cpu, its the mysql, perhaps think about separating the database to another server or upgrading your ram

[mflorell]

Those are almost always caused by database load issues. Start by trimming the unnecessary leads from your vicidial_list table and shortening the timeframe for archiving of your log tables.

[IanGP]

Thanks All.

I'll make some changes, and post solution when I have one.

[williamconley]

If it is mysql, this may show the offending query. Once you have the query ... you can begin the hunt for the offending script(s) and/or data in need of indexing or record reduction.

Code: Select all

VARDB_pass=`awk '/VARDB_pass/{print $NF}' /etc/astguiclient.conf`; VARDB_server=`awk '/VARDB_server/{print $NF}' /etc/astguiclient.conf`;
mysql asterisk -h $VARDB_server -ucron -p$VARDB_pass -e "select * from information_schema.processlist where command not in ('Sleep') and (info not like '%processlist%' or info is null)  and state <> 'Waiting for table level lock'"

[IanGP]

Thanks All.

The culprit was a poorly composed SQL query, on our 3rd party reporting app.
Killed that particular query, all OK.

Regards
GP

[mflorell]

That is a common issue, thanks for the followup post!

[carpenox]

hey william, thx for the commands to use to search for "offending queries", so any that show as a result are offenders? like i have 5:

Code: Select all

Database changed
MariaDB [asterisk]> select * from information_schema.processlist where command not in ('Sleep') and (info not like '%processlist%' or info is null)  and state <> 'Waiting for table level lock'
    -> ;
+----+-------------+------+------+---------+------+--------------------------+------+---------+-------+-----------+----------+-------------+---------------+----------+-------------+------+
| ID | USER        | HOST | DB   | COMMAND | TIME | STATE                    | INFO | TIME_MS | STAGE | MAX_STAGE | PROGRESS | MEMORY_USED | EXAMINED_ROWS | QUERY_ID | INFO_BINARY | TID  |
+----+-------------+------+------+---------+------+--------------------------+------+---------+-------+-----------+----------+-------------+---------------+----------+-------------+------+
|  5 | system user |      | NULL | Daemon  |    0 | InnoDB shutdown handler  | NULL |   0.000 |     0 |         0 |    0.000 |       24336 |             0 |        0 | NULL        | 3407 |
|  4 | system user |      | NULL | Daemon  |    0 | InnoDB purge worker      | NULL |   0.000 |     0 |         0 |    0.000 |       24336 |             0 |        0 | NULL        | 3401 |
|  3 | system user |      | NULL | Daemon  |    0 | InnoDB purge worker      | NULL |   0.000 |     0 |         0 |    0.000 |       24336 |             0 |        0 | NULL        | 3400 |
|  2 | system user |      | NULL | Daemon  |    0 | InnoDB purge worker      | NULL |   0.000 |     0 |         0 |    0.000 |       24336 |             0 |        0 | NULL        | 3402 |
|  1 | system user |      | NULL | Daemon  |    0 | InnoDB purge coordinator | NULL |   0.000 |     0 |         0 |    0.000 |       24336 |             0 |        0 | NULL        | 3399 |
+----+-------------+------+------+---------+------+--------------------------+------+---------+-------+-----------+----------+-------------+---------------+----------+-------------+------+
5 rows in set (0.07 sec)


should i hunt all those down? thx

-Nox

[williamconley]

Any mysql query that takes more than one second to complete is questionable. But if none take more than a second, your problem likely lies elsewhere.

PS: Turn off InnoDB. Disable it. Seriously.