FOG Server CPU usage 100%

[Tom Elliott]

@fernando-gietz I’m going to guess the tasks table is a bit on the high side maybe?

[Fernando Gietz]

Done.

[root@fog7 conf]# lsof -c http | grep cwd
httpd   13036   root  cwd       DIR              253,0      4096      128 /
httpd   13037 apache  cwd       DIR              253,2       133 23069131 /var/www/html/fog/management
httpd   13038 apache  cwd       DIR              253,0      4096      128 /
httpd   13039 apache  cwd       DIR              253,0      4096      128 /
httpd   13040 apache  cwd       DIR              253,0      4096      128 /
httpd   13041 apache  cwd       DIR              253,0      4096      128 /
httpd   13044 apache  cwd       DIR              253,2      4096  8388946 /var/www/html/fog/status
httpd   13118 apache  cwd       DIR              253,0      4096      128 /
httpd   13144 apache  cwd       DIR              253,0      4096      128 /
httpd   13145 apache  cwd       DIR              253,0      4096      128 /

And now the output of server status

Server Version: Apache/2.4.6 (Red Hat Enterprise Linux) OpenSSL/1.0.2k-fips PHP/5.6.31
Server MPM: prefork
Server Built: Jul 26 2017 04:45:44

Current Time: Tuesday, 14-Nov-2017 19:49:35 CET
Restart Time: Tuesday, 14-Nov-2017 19:44:15 CET
Parent Server Config. Generation: 1
Parent Server MPM Generation: 0
Server uptime: 5 minutes 20 seconds
Server load: 1.01 0.85 0.65
Total accesses: 557 - Total Traffic: 3.4 MB
CPU Usage: u167.78 s11.08 cu0 cs0 - 55.9% CPU load
1.74 requests/sec - 10.8 kB/second - 6.2 kB/request
3 requests currently being processed, 6 idle workers

W____WW__.......................................................
................................................................
................................................................
................................................................

Scoreboard Key:
"_" Waiting for Connection, "S" Starting up, "R" Reading Request,
"W" Sending Reply, "K" Keepalive (read), "D" DNS Lookup,
"C" Closing connection, "L" Logging, "G" Gracefully finishing,
"I" Idle cleanup of worker, "." Open slot with no current process

Srv	PID	Acc	M	CPU 	SS	Req	Conn	Child	Slot	Client	VHost	Request
0-0	13037	0/58/58	W 	5.22	120	0	0.0	0.19	0.19 	158.227.4.135	10.0.15.4:80	GET /fog/management/index.php?node=group&sub=membership&id=334
1-0	13038	0/75/75	_ 	6.88	2	107	0.0	0.27	0.27 	158.227.138.124	10.0.15.4:80	GET /fog/management/index.php?sub=requestClientInfo&configure&n
2-0	13039	0/76/76	_ 	6.59	2	0	0.0	0.23	0.23 	158.227.4.135	10.0.15.4:80	GET /server-status HTTP/1.1
3-0	13040	0/39/39	_ 	4.78	2	232	0.0	0.07	0.07 	158.227.138.124	10.0.15.4:80	GET /fog/management/index.php?sub=requestClientInfo&mac=94:57:A
4-0	13041	0/75/75	_ 	6.74	1	150	0.0	0.23	0.23 	158.227.115.42	10.0.15.4:80	GET /fog/management/index.php?node=task&sub=active&_=1510657597
5-0	13044	0/19/19	W 	131.09	87	0	0.0	1.69	1.69 	158.227.4.135	10.0.15.4:80	POST /fog/status/getservertime.php HTTP/1.1
6-0	13118	0/72/72	W 	7.25	0	0	0.0	0.23	0.23 	158.227.4.135	10.0.15.4:80	GET /server-status HTTP/1.1
7-0	13144	0/72/72	_ 	6.11	1	73	0.0	0.23	0.23 	158.227.138.124	10.0.15.4:80	GET /fog/service/getversion.php?newService&json HTTP/1.1
8-0	13145	0/71/71	_ 	4.20	2	75	0.0	0.24	0.24 	158.227.138.124	10.0.15.4:80	GET /fog/service/getversion.php?clientver&newService&json HTTP/
Srv	Child Server number - generation
PID	OS process ID
Acc	Number of accesses this connection / this child / this slot
M	Mode of operation
CPU	CPU usage, number of seconds
SS	Seconds since beginning of most recent request
Req	Milliseconds required to process most recent request
Conn	Kilobytes transferred this connection
Child	Megabytes transferred this child
Slot	Total megabytes transferred this slot
SSL/TLS Session Cache Status:
cache type: SHMCB, shared memory: 512000 bytes, current entries: 0
subcaches: 32, indexes per subcache: 88
index usage: 0%, cache usage: 0%
total entries stored since starting: 0
total entries replaced since starting: 0
total entries expired since starting: 0
total (pre-expiry) entries scrolled out of the cache: 0
total retrieves since starting: 0 hit, 0 miss
total removes since starting: 0 hit, 0 miss

[Fernando Gietz]

@fernando-gietz

/fog/management/index.php?node=group&sub=membership&id=334

[Wayne Workman]

Actually this line is using a ton of CPU:

131.09	87	0	0.0	1.69	1.69 	158.227.4.135	10.0.15.4:80	POST /fog/status/getservertime.php HTTP/1.1

131 is a LOT.

[Fernando Gietz]

@tom-elliott Tasks table?

[Wayne Workman]

@fernando-gietz You should have a table called tasks in MySQL.

[Sebastian Roth]

@wayne-workman said:

Actually this line is using a ton of CPU:

131.09	87	0	0.0	1.69	1.69 	158.227.4.135	10.0.15.4:80	POST /fog/status/getservertime.php HTTP/1.1

131 is a LOT.

Yeah that looks like there is something strange going on with this script. Though I have no idea what could be causing this. On the other hand the PHP code in that file looks kind of like it might take more time than usual. I guess only @Tom-Elliott can tell us what’s those calls to ignore_user_abort() and set_time_limit() are used for.

[Fernando Gietz]

@Tom-Elliott about the tasks table:

MariaDB [fog]> show table status from fog where Name = 'tasks';
+-------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-----------------+----------+--------------------+---------+
| Name  | Engine | Version | Row_format | Rows | Avg_row_length | Data_length | Max_data_length | Index_length | Data_free | Auto_increment | Create_time         | Update_time         | Check_time          | Collation       | Checksum | Create_options     | Comment |
+-------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-----------------+----------+--------------------+---------+
| tasks | MyISAM |      10 | Dynamic    | 5217 |            125 |      653940 | 281474976710655 |       602112 |         0 |           5225 | 2017-06-14 18:23:02 | 2017-11-15 13:10:31 | 2017-09-07 15:31:22 | utf8_general_ci |     NULL | row_format=DYNAMIC |         |
+-------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+---------------------+---------------------+-----------------+----------+--------------------+---------+

[Wayne Workman]

@fernando-gietz Truncate it.

[Fernando Gietz]

@Wayne-Workman I have truncated the table and nothing.

Srv	PID	Acc	M	CPU 	SS	Req	Conn	Child	Slot	Client	VHost	Request
0-0	4154	0/133/2998	_ 	15.91	0	175	0.0	0.18	3.69 	158.227.129.66	10.0.15.4:80	POST /fog/management/index.php?sub=requestClientInfo&authorize&
1-0	22327	0/633/2833	_ 	101.18	0	88	0.0	0.70	3.34 	158.227.129.66	10.0.15.4:80	GET /fog/service/getversion.php?newService&json HTTP/1.1
2-0	10758	0/3575/3575	_ 	583.44	0	0	0.0	4.46	4.46 	158.227.129.66	10.0.15.4:80	GET /fog/management/other/ssl/srvpublic.crt HTTP/1.1
3-0	11712	0/1096/3380	_ 	174.13	0	210	0.0	1.27	4.11 	158.227.115.42	10.0.15.4:80	GET /fog/management/index.php?node=home&sub=bandwidth&url%5B%5D
4-0	17308	0/3259/3538	W 	531.14	58	0	0.0	3.79	4.26 	158.227.4.135	10.0.15.4:80	POST /fog/status/getservertime.php HTTP/1.1
5-0	22817	0/605/3241	_ 	95.71	1	73	0.0	0.68	5.64 	158.227.138.17	10.0.15.4:80	GET /fog/service/getversion.php?newService&json HTTP/1.1
6-0	13038	0/1037/3469	_ 	166.05	0	74	0.0	1.20	4.01 	158.227.129.66	10.0.15.4:80	GET /fog/service/getversion.php?clientver&newService&json HTTP/
7-0	-	0/0/2866	. 	2.96	167	0	0.0	0.00	3.64 	::1	10.0.15.4:80	OPTIONS * HTTP/1.0
8-0	11826	0/997/3504	W 	165.00	115	0	0.0	1.13	4.20 	158.227.4.135	10.0.15.4:80	GET /fog/management/index.php?node=group&sub=membership&id=334
9-0	3151	0/174/3003	_ 	25.77	0	77	0.0	0.21	3.42 	10.0.15.4	10.0.15.4:80	GET /fog/status/bandwidth.php?dev=ens192 HTTP/1.1
10-0	15893	0/3295/3295	W 	551.38	0	0	0.0	3.74	3.74 	158.227.4.135	10.0.15.4:80	GET /server-status HTTP/1.1```

[Tom Elliott]

@sebastian-roth The idea of those is specific to ajax calls, though I guess the ignore_user_abort could be done with. The set_time_limit basically tells the script that it can run indefinitely. Ignore_user_abort tells the script to keep processing the script even if the client (browser) has requested to abort/stop/cancel the script.

[Fernando Gietz]

To don’t lose the thread.

Hi again!

I follow with this issue Toisolate the problem I have do a fresh install:

Enviroment:
FOG version: 1.5.0
Computer: HP 800 G2 with 8 GB RAM and SSD
OS: Centos 7 64 bits

I have imported 7000 new hosts to the database from webUI, later I have created a new group with one computer. If I try to list the membership of this new group, the browser needs 40 second to show me the computer.

If anybody wants to reply the issu, I can send the hosts import file.

[Joe Schmitt]

@Tom-Elliott sounds like the group membership is doing a lot of unnecessary calculations.

[Tom Elliott]

@joe-schmitt somewhat yes, somewhat no. For membership it should just gather the names, but when the object loads it first has to get the ids so it knows which hostnames it needs to grab. This should happen fairly fast, but processing to display 7k items does take a bit.

[Fernando Gietz]

@tom-elliott I can understand that the proccess takes a bit 10 seconds or 15 seconds, but in my producction environment takes 2 minutes and in the physical server 40 seconds.

Repeat, I can send you the import hosts file to do test and see in-situ the problem.

[Joe Schmitt]

• thread note:

@Fernando-Gietz I have replicated the issue and am looking at it now.

[george1421]

@fernando-gietz If I can break some time free I’d like to look at it from a SQL database point of view. We may be missing an index that is causing such a bad performance.

[Tom Elliott]

Mind installing the working-1.5.1 branch please?

Significantly improved load for membership and taskings.

[Tom Elliott]

For benchmark/testing.

Using Joe’s server as the testbed, it was taking about 42 seconds to load the group membership page and around 30 seconds for the tasking page.

It now takes 3 seconds to load, and 5 (total) to render on membership. Tasking is relatively instant.

[Fernando Gietz]

@tom-elliott Oh la la!! works very verry fine