Ahoj,

tohle vypadá, že PHP se z nějakého důvodu nestihne provést za 5 sekund a FPM ho zabije.

Šel bych po zatížení procesoru (CPU usage), vytížení disku (I/O load), nikoliv UNIX load) a zjistil, kde to drhne. 
Jestli drhne databáze, disky, PHP, či něco jiného. A až budeš mít odhad, kde to drhne, tak tam se zaměříš.

--Věroš 

2015-12-02 9:56 GMT+01:00 Branislav Viest <info@branoviest.com>:
tohle je vytezek z php-fpm logu

[02-Dec-2015 09:54:39.867720] WARNING: pid 5043, fpm_request_check_timed_out(), line 269: [pool web1] child 24945, script 'xxxwww//index.php' (request: "GET /index.php") executing too slow (5.799737 sec), logging # to je jasny
[02-Dec-2015 09:54:39.867981] DEBUG: pid 5043, fpm_got_signal(), line 76: received SIGCHLD
[02-Dec-2015 09:54:39.868499] NOTICE: pid 5043, fpm_children_bury(), line 227: child 24945 stopped for tracing
[02-Dec-2015 09:54:39.868508] NOTICE: pid 5043, fpm_php_trace(), line 144: about to trace 24945
[02-Dec-2015 09:54:39.868731] NOTICE: pid 5043, fpm_php_trace(), line 172: finished trace of 24945
[02-Dec-2015 09:54:39.869145] NOTICE: pid 5043, fpm_children_bury(), line 227: child 28359 stopped for tracing
[02-Dec-2015 09:54:39.869161] NOTICE: pid 5043, fpm_php_trace(), line 144: about to trace 28359
[02-Dec-2015 09:54:39.869415] NOTICE: pid 5043, fpm_php_trace(), line 172: finished trace of 28359
[02-Dec-2015 09:54:39.869893] NOTICE: pid 5043, fpm_children_bury(), line 227: child 33445 stopped for tracing
[02-Dec-2015 09:54:39.869904] NOTICE: pid 5043, fpm_php_trace(), line 144: about to trace 33445
[02-Dec-2015 09:54:39.870101] NOTICE: pid 5043, fpm_php_trace(), line 172: finished trace of 33445
[02-Dec-2015 09:54:39.870602] NOTICE: pid 5043, fpm_children_bury(), line 227: child 36581 stopped for tracing
[02-Dec-2015 09:54:39.870615] NOTICE: pid 5043, fpm_php_trace(), line 144: about to trace 36581
[02-Dec-2015 09:54:39.870884] NOTICE: pid 5043, fpm_php_trace(), line 172: finished trace of 36581
[02-Dec-2015 09:54:39.871187] NOTICE: pid 5043, fpm_children_bury(), line 227: child 37001 stopped for tracing
[02-Dec-2015 09:54:39.871195] NOTICE: pid 5043, fpm_php_trace(), line 144: about to trace 37001
[02-Dec-2015 09:54:39.871460] NOTICE: pid 5043, fpm_php_trace(), line 172: finished trace of 37001
[02-Dec-2015 09:54:39.872162] DEBUG: pid 5043, fpm_got_signal(), line 76: received SIGCHLD
[02-Dec-2015 09:54:39.872582] DEBUG: pid 5043, fpm_got_signal(), line 76: received SIGCHLD
[02-Dec-2015 09:54:39.872950] DEBUG: pid 5043, fpm_got_signal(), line 76: received SIGCHLD
[02-Dec-2015 09:54:39.873295] DEBUG: pid 5043, fpm_got_signal(), line 76: received SIGCHLD
[02-Dec-2015 09:54:39.873616] DEBUG: pid 5043, fpm_event_loop(), line 424: event module triggered 1 events

S pozdravem
Branislav Viest



Od: "Věroslav Kaplan" <veros.kaplan@gmail.com>
Komu: "vpsFree.cz Community list" <community-list@lists.vpsfree.cz>
Odoslané: streda, 2. december 2015 9:48:22
Predmet: {Disarmed} [vpsFree.cz: community-list] {Disarmed} Re: php pro nginx high load

Ahoj,

Tohle vypadá, že PHP-FPM z nějakého důvodu zavře to fcgi spojení. Dokážeš vytáhnout nějaké podezřelé logy z toho PHP-FPM a zkusit uhodnout, proč to dělá ?

--Věroš Kaplan
Školíme Ansible: http://ansible.cz/

2015-12-02 8:25 GMT+01:00 Branislav Viest <info@branoviest.com>:
Ahoj,

mám tady jeden server kde je cca 35k lidí za vteřinu. Běží tu nginx + php fpm a mysql db. V nginxu jsem rozjel microcache, což hodně ulevilo zátěži serveru. Nicméně, mám problém s PHPkem. FPM běží přes TCP (zkoušel jsem i unix socket nicméně bylo to pomalější a docházelo ke stejnému problému). Dle error logu dochází k těmto chybám:

2015/12/01 23:26:56 [error] 27043#0: *122476 recv() failed (104: Connection reset by peer) while reading response header from upstream, client: 188.114.98.51, server: xxx request: "GET /xxx/xxxx/xxx HTTP/1.1", upstream: "fastcgi://MailScanner has detected a possible fraud attempt from "127.0.0.1:9000" claiming to be MailScanner warning: numerical links are often malicious: 127.0.0.1:9000", host: "xxxx", referrer: "MailScanner has detected a possible fraud attempt from "xxxxx" claiming to be http://xxxxx"
2015/12/01 23:26:56 [error] 27032#0: *124368 recv() failed (104: Connection reset by peer) while reading response header from upstream, client: 188.114.99.50, server: xxxxxx, request: "GET /xxxxx/xxxxx HTTP/1.1", upstream: "fastcgi://MailScanner has detected a possible fraud attempt from "127.0.0.1:9000" claiming to be MailScanner warning: numerical links are often malicious: 127.0.0.1:9000", host: "xxxxx", referrer: "xxxxx"

a sype to tam docela drsně. Jak vypnu kešování v nginxu load vyskočí, třeba i na 500, těch chyb PHPka je méně ale jsou tam pořád. 

Konfigurace FPM pro pool toho webu je:

[web1]

listen = MailScanner has detected a possible fraud attempt from "127.0.0.1:9000" claiming to be MailScanner warning: numerical links are often malicious: 127.0.0.1:9000
listen.allowed_clients = 127.0.0.1
listen.owner = web1
listen.group = client0
listen.mode = 0660
listen.backlog = 65536

user = web1
group = client0

request_slowlog_timeout = 5s
slowlog = /var/log/php-fpm/slowlog-web1.log

pm = dynamic
pm.max_children = 7000
pm.start_servers = 4000
pm.min_spare_servers = 2000
pm.max_spare_servers = 4000
pm.max_requests = 100

request_terminate_timeout = 60s
rlimit_files = 500000
rlimit_core = unlimited
catch_workers_output = yes

pm.status_path = /php-status

chdir = /

+ openbasedir, sessions save path. atp.

S těma hodnotama jsem se zkoušel různě hrát, nicméně to k vyřešení tohoto problému nepomohlo. Zkoušel jsem upravit i nějaké parametry jádra (local port range, tcp ack timeouty atp.) ale výsledek stejný. Dělá to i u unix socketu, což je mi právě zvláštní. Nginx konfigurace je:
user www-data;
worker_processes 80;
pid /run/nginx.pid;
# set open fd limit to 50000
worker_rlimit_nofile 100000;

events {
worker_connections 1024;
multi_accept on;
use epoll;
}

ve vhostu nic zvlastniho, jenom pro php:

fastcgi_split_path_info ^(.+\.php)(/.+)$;
fastcgi_param SCRIPT_FILENAME $document_root/$fastcgi_script_name;
include /etc/nginx/fastcgi_params;
fastcgi_pass MailScanner has detected a possible fraud attempt from "127.0.0.1:9000" claiming to be MailScanner warning: numerical links are often malicious: 127.0.0.1:9000;
fastcgi_index index.php;
fastcgi_intercept_errors on;
fastcgi_read_timeout 4m;

Dnes bude k tomuto server nový, pro rozdělení zátěže, ale jako fakt nevím jestli to má smysl ve stejné konfiguraci, kvůli těm php chybám. Nenapadá Vás kluci, co s tím? Nebo případně návrh řešení, kterým bych nahradil tohle, při dvou serverech ? Přemýšlím nad MySQL M - M replikací, v DNS round robin a GlusterFS pro data. Ale to phpko mi nedá spát. A dnes večer to už další nápor asi nedá.

Díky za rady a konzultace.

S pozdravem
Branislav Viest

_______________________________________________
Community-list mailing list
Community-list@lists.vpsfree.cz
http://lists.vpsfree.cz/listinfo/community-list




--
--V.Kaplan

_______________________________________________
Community-list mailing list
Community-list@lists.vpsfree.cz
http://lists.vpsfree.cz/listinfo/community-list

_______________________________________________
Community-list mailing list
Community-list@lists.vpsfree.cz
http://lists.vpsfree.cz/listinfo/community-list




--
--V.Kaplan