V
V
Vitaly R2018-01-23 13:05:42
PHP
Vitaly R, 2018-01-23 13:05:42

Why does php-fpm spawn processes and load the system?

There is a zabbix server version 3.0. Always worked properly. Recently began to slow down terribly. Studies have shown that php-fpm processes multiply and terribly load the system. And so far, it has not been possible to trace any regularity.

php-fpm log
[23-Jan-2018 14:55:17.187223] DEBUG: pid 8266, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool www] currently 20 active children, 0 spare children, 20 running children. Spawning rate 1
[23-Jan-2018 14:55:18.188435] DEBUG: pid 8266, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool www] currently 20 active children, 0 spare children, 20 running children. Spawning rate 1
[23-Jan-2018 14:55:19.189574] DEBUG: pid 8266, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool www] currently 20 active children, 0 spare children, 20 running children. Spawning rate 1
[23-Jan-2018 14:55:19.304932] WARNING: pid 8266, fpm_request_check_timed_out(), line 271: [pool www] child 9011, script '/usr/share/zabbix/map.php' (request: "GET /map.php") executing too slow (13.250784 sec), logging
[23-Jan-2018 14:55:19.305105] WARNING: pid 8266, fpm_request_check_timed_out(), line 271: [pool www] child 8353, script '/usr/share/zabbix/map.php' (request: "GET /map.php") executing too slow (12.110724 sec), logging
[23-Jan-2018 14:55:19.305144] DEBUG: pid 8266, fpm_got_signal(), line 76: received SIGCHLD
[23-Jan-2018 14:55:19.305169] NOTICE: pid 8266, fpm_children_bury(), line 227: child 8353 stopped for tracing
[23-Jan-2018 14:55:19.305175] NOTICE: pid 8266, fpm_php_trace(), line 144: about to trace 8353
[23-Jan-2018 14:55:19.305548] NOTICE: pid 8266, fpm_php_trace(), line 172: finished trace of 8353
[23-Jan-2018 14:55:19.305563] NOTICE: pid 8266, fpm_children_bury(), line 227: child 9011 stopped for tracing
[23-Jan-2018 14:55:19.305568] NOTICE: pid 8266, fpm_php_trace(), line 144: about to trace 9011
[23-Jan-2018 14:55:19.305729] NOTICE: pid 8266, fpm_php_trace(), line 172: finished trace of 9011
[23-Jan-2018 14:55:19.305742] DEBUG: pid 8266, fpm_got_signal(), line 76: received SIGCHLD
[23-Jan-2018 14:55:19.305748] DEBUG: pid 8266, fpm_event_loop(), line 419: event module triggered 1 events
[23-Jan-2018 14:55:20.190686] DEBUG: pid 8266, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool www] currently 20 active children, 0 spare children, 20 running children. Spawning rate 1
[23-Jan-2018 14:55:32.640866] WARNING: pid 8266, fpm_request_check_timed_out(), line 271: [pool www] child 9040, script '/usr/share/zabbix/map.php' (request: "GET /map.php") executing too slow (13.057358 sec), logging
[23-Jan-2018 14:55:32.641051] DEBUG: pid 8266, fpm_got_signal(), line 76: received SIGCHLD
[23-Jan-2018 14:55:32.641077] NOTICE: pid 8266, fpm_children_bury(), line 227: child 9040 stopped for tracing
[23-Jan-2018 14:55:32.641085] NOTICE: pid 8266, fpm_php_trace(), line 144: about to trace 9040
[23-Jan-2018 14:55:32.641415] NOTICE: pid 8266, fpm_php_trace(), line 172: finished trace of 9040
[23-Jan-2018 14:55:32.641428] DEBUG: pid 8266, fpm_event_loop(), line 419: event module triggered 1 events
[23-Jan-2018 14:55:33.205565] DEBUG: pid 8266, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool www] currently 20 active children, 0 spare children, 20 running children. Spawning rate 1
[23-Jan-2018 14:55:39.211917] DEBUG: pid 8266, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool www] currently 20 active children, 0 spare children, 20 running children. Spawning rate 1
[23-Jan-2018 14:55:39.308203] WARNING: pid 8266, fpm_request_check_timed_out(), line 271: [pool www] child 8969, script '/usr/share/zabbix/map.php' (request: "GET /map.php") executing too slow (10.989382 sec), logging
[23-Jan-2018 14:55:39.308357] DEBUG: pid 8266, fpm_got_signal(), line 76: received SIGCHLD
[23-Jan-2018 14:55:39.308381] NOTICE: pid 8266, fpm_children_bury(), line 227: child 8969 stopped for tracing
[23-Jan-2018 14:55:39.308388] NOTICE: pid 8266, fpm_php_trace(), line 144: about to trace 8969
[23-Jan-2018 14:55:39.308678] NOTICE: pid 8266, fpm_php_trace(), line 172: finished trace of 8969
[23-Jan-2018 14:55:39.308691] DEBUG: pid 8266, fpm_event_loop(), line 419: event module triggered 1 events
[23-Jan-2018 14:55:40.213576] DEBUG: pid 8266, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool www] currently 20 active children, 0 spare children, 20 running children. Spawning rate 1

php-fpm-slow log

[23-Jan-2018 14:57:09.329814] [pool www] pid 9040
script_filename = /usr/share/zabbix/map.php
[0x00007fe2fed799e0] get() /usr/share/zabbix/include/classes/api/services/CMap.php:256
[0x00007ffe350accc0] get() unknown:0
[0x00007fe2fed78f48] call_user_func_array() /usr/share/zabbix/include/classes/api/clients/CLocalApiClient.php:123
[0x00007fe2fed78d20] callMethod() /usr/share/zabbix/include/classes/api/wrappers/CFrontendApiWrapper.php:97
[0x00007fe2fed78c18] callClientMethod() /usr/share/zabbix/include/classes/api/wrappers/CApiWrapper.php:94
[0x00007fe2fed787e0] callMethod() /usr/share/zabbix/include/classes/api/wrappers/CFrontendApiWrapper.php:63
[0x00007fe2fed786b8] callMethod() /usr/share/zabbix/include/classes/api/wrappers/CApiWrapper.php:82
[0x00007ffe350acfc0] __call() unknown:0
[0x00007fe2fed77520] get() /usr/share/zabbix/include/maps.inc.php:366
[0x00007fe2fed75490] add_elementNames() /usr/share/zabbix/map.php:105
[23-Jan-2018 14:57:19.325910] [pool www] pid 8996
script_filename = /usr/share/zabbix/map.php
[0x00007fe2fed799a0] get() /usr/share/zabbix/include/classes/api/services/CMap.php:261
[0x00007ffe350accc0] get() unknown:0
[0x00007fe2fed78f08] call_user_func_array() /usr/share/zabbix/include/classes/api/clients/CLocalApiClient.php:123
[0x00007fe2fed78ce0] callMethod() /usr/share/zabbix/include/classes/api/wrappers/CFrontendApiWrapper.php:97
[0x00007fe2fed78bd8] callClientMethod() /usr/share/zabbix/include/classes/api/wrappers/CApiWrapper.php:94
[0x00007fe2fed787a0] callMethod() /usr/share/zabbix/include/classes/api/wrappers/CFrontendApiWrapper.php:63
[0x00007fe2fed78678] callMethod() /usr/share/zabbix/include/classes/api/wrappers/CApiWrapper.php:82
[0x00007ffe350acfc0] __call() unknown:0
[0x00007fe2fed774e0] get() /usr/share/zabbix/include/maps.inc.php:366

Actually it is logical to assume that the problem is in the php script map. But how to fix it? and what exactly is this problem? It happens that the Zabix web interface works perfectly for half a day, opening anything, including all cards, in milliseconds, and then *oops starts abruptly. Everything slows down and opens for 10 seconds. And I can’t trace in any way, after what and whose actions this happens.
Unfortunately, I was not engaged in script programming and I absolutely cannot understand what needs to be corrected in the script. And to be honest, for some reason I’m sure that it’s not about him, because for periods the web works perfectly (it can’t be that the script worked 100 times normally, and then it began to work out abruptly, and then it’s normal again).
Tell me where to drop? Where to look?

Answer the question

In order to leave comments, you need to log in

2 answer(s)
P
Puma Thailand, 2018-01-23
@opium

well, you can upgrade to the latest version, everything has become completely different there,
well, look at the logs of slow queries in the muscle

F
Fortop, 2018-01-24
@Fortop

it cannot be that the script worked 100 times normally, and then it began to work out abruptly, and then it was normal again

Maybe.
But information is not enough.
PHP versions are not specified.
Iron - not specified.
Whether other applications work on this server - not specified
This is what you need to know first of all to make at least an initial diagnosis in the form of "in which direction to dig."

Didn't find what you were looking for?

Ask your question

Ask a Question

731 491 924 answers to any question