Please help me tweak my config for php5-fpm and nginx.
The problem is my php5-fpm log keeps reporting slow scripts and killing a child thread.
Dedicated server, quad xeon, 32Gb Ram. 1 php application / site running.
Php application: Nutshell, search engine, results fire off curl requests. Page load time is typically 2 - 3 seconds per search.
Here is what i think is happening:
I'm getting 750 concurrent php users performing searches. I can only set pm.max_children = 400
due to RAM limits. I assume 50Mb per user (child thread) so that = 20GB. I'm assuming each user = 1 child thread. So, pm.max_children
is not enough to cover the 750 active php users who are making searches that take 3 seconds.
So i think i'm seeing users queuing because i see 3 seconds turn into 4 - 7 seconds. As users queue i think the script is getting slow trigger the error log message and php5-fpm pm kills the child?
That is what i think is happening. I have provided my error log output, nginx, php5-fpm config below.
I would really appreciate any advice on if i can tweak my config and if indeed pm.max_children
should be at least equal to you max concurrent users, keeping in mind that my php searches are open for around 3 seconds. Do i need a lot more memory or perhaps additional servers?
This is my memory, but i only restarted nginx about 30 mins ago
:/var/log# free -m
total used free shared buffers cached
Mem: 32151 26175 5975 0 186 13334
-/+ buffers/cache: 12654 19496
Swap: 32739 5 32734
php5-fpm: www.conf: process manager is set to static
I'm using static because i thought all children would be available instantly instead of spawn time and i'm only running 1 application on the box.
;pm = dynamic
pm = static
;pm.max_children = 10
pm.max_children = 400
;pm.start_servers = 4
pm.start_servers = 150
;pm.min_spare_servers = 2
pm.min_spare_servers = 32
;pm.max_spare_servers = 6
pm.max_spare_servers = 64
;pm.max_requests = 500
pm.max_requests = 10000
Errors in php5-fpm logs
I should clarify, the behaviour i see under high load, 750 users at once is that search results cached and not cached start to take longer. i.e. > 1 second for cached and between 4 and 7 seconds for non cached. So as users queue and wait i think search times increase and it spirals to the point where the scripts run slow under the load. Trigger a notice and the child gets killed.
e.g. this was just after restart
[04-Jun-2013 20:11:07] NOTICE: Finishing ...
[04-Jun-2013 20:11:11] NOTICE: exiting, bye-bye!
[04-Jun-2013 20:11:12] NOTICE: fpm is running, pid 17899
[04-Jun-2013 20:11:12] NOTICE: ready to handle connections
[04-Jun-2013 20:27:28] WARNING: [pool www] child 18200, script '/home/site/public_html/index.php' (request: "POST /index.php") executing too slow (10.827363 sec), logging
[04-Jun-2013 20:27:28] WARNING: [pool www] child 18138, script '/home/site/public_html/index.php' (request: "POST /index.php") executing too slow (10.827034 sec), logging
[04-Jun-2013 20:27:28] NOTICE: child 18138 stopped for tracing
[04-Jun-2013 20:27:28] NOTICE: about to trace 18138
[04-Jun-2013 20:27:28] NOTICE: finished trace of 18138
[04-Jun-2013 20:27:28] NOTICE: child 18200 stopped for tracing
[04-Jun-2013 20:27:28] NOTICE: about to trace 18200
[04-Jun-2013 20:27:28] NOTICE: finished trace of 18200
[04-Jun-2013 20:52:52] WARNING: [pool www] child 17948, script '/home/site/public_html/index.php' (request: "GET /index.php") executing too slow (11.724081 sec), logging
[04-Jun-2013 20:52:52] NOTICE: child 17948 stopped for tracing
[04-Jun-2013 20:52:52] NOTICE: about to trace 17948
[04-Jun-2013 20:52:52] ERROR: failed to ptrace(PEEKDATA) pid 17948: Input/output error (5)
[04-Jun-2013 20:52:52] NOTICE: finished trace of 17948
[04-Jun-2013 20:58:22] WARNING: [pool www] child 18287, script '/home/site/public_html/index.php' (request: "POST /index.php") executing too slow (10.701504 sec), logging
[04-Jun-2013 20:58:22] NOTICE: child 18287 stopped for tracing
[04-Jun-2013 20:58:22] NOTICE: about to trace 18287
[04-Jun-2013 20:58:22] NOTICE: finished trace of 18287
[04-Jun-2013 21:19:22] WARNING: [pool www] child 18224, script '/home/site/public_html/index.php' (request: "GET /index.php") executing too slow (10.005466 sec), logging
[04-Jun-2013 21:19:22] WARNING: [pool www] child 18197, script '/home/site/public_html/index.php' (request: "GET /index.php") executing too slow (12.141221 sec), logging
[04-Jun-2013 21:19:22] WARNING: [pool www] child 17946, script '/home/site/public_html/index.php' (request: "GET /index.php") executing too slow (11.107080 sec), logging
[04-Jun-2013 21:19:22] NOTICE: child 17946 stopped for tracing
[04-Jun-2013 21:19:22] NOTICE: about to trace 17946
[04-Jun-2013 21:19:22] NOTICE: finished trace of 17946
[04-Jun-2013 21:19:22] NOTICE: child 18197 stopped for tracing
[04-Jun-2013 21:19:22] NOTICE: about to trace 18197
[04-Jun-2013 21:19:22] NOTICE: finished trace of 18197
[04-Jun-2013 21:19:22] NOTICE: child 18224 stopped for tracing
[04-Jun-2013 21:19:22] NOTICE: about to trace 18224
[04-Jun-2013 21:19:22] NOTICE: finished trace of 18224
[04-Jun-2013 21:19:26] WARNING: [pool www] child 18197, script '/home/site/public_html/index.php' (request: "GET /index.php") execution timed out (15.475021 sec), terminating
[04-Jun-2013 21:19:26] WARNING: [pool www] child 18055, script '/home/site/public_html/index.php' (request: "GET /index.php") executing too slow (12.927407 sec), logging
[04-Jun-2013 21:19:26] NOTICE: child 18055 stopped for tracing
[04-Jun-2013 21:19:26] NOTICE: about to trace 18055
[04-Jun-2013 21:19:26] NOTICE: finished trace of 18055
[04-Jun-2013 21:19:26] WARNING: [pool www] child 18197 exited on signal 15 (SIGTERM) after 4094.193190 seconds from start
[04-Jun-2013 21:19:26] NOTICE: [pool www] child 5137 started
[04-Jun-2013 21:24:49] WARNING: [pool www] child 17918, script '/home/site/public_html/index.php' (request: "GET /index.php") executing too slow (11.367854 sec), logging
[04-Jun-2013 21:24:49] NOTICE: child 17918 stopped for tracing
[04-Jun-2013 21:24:49] NOTICE: about to trace 17918
[04-Jun-2013 21:24:49] NOTICE: finished trace of 17918
[04-Jun-2013 21:24:53] WARNING: [pool www] child 18226, script '/home/site/public_html/index.php' (request: "GET /index.php") executing too slow (10.763667 sec), logging
[04-Jun-2013 21:24:53] WARNING: [pool www] child 18206, script '/home/site/public_html/index.php' (request: "GET /index.php") executing too slow (12.060464 sec), logging
[04-Jun-2013 21:24:53] WARNING: [pool www] child 18073, script '/home/site/public_html/index.php' (request: "GET /index.php") executing too slow (11.846097 sec), logging
[04-Jun-2013 21:24:53] NOTICE: child 18073 stopped for tracing
[04-Jun-2013 21:24:53] NOTICE: about to trace 18073
[04-Jun-2013 21:24:53] NOTICE: finished trace of 18073
[04-Jun-2013 21:24:53] NOTICE: child 18206 stopped for tracing
[04-Jun-2013 21:24:53] NOTICE: about to trace 18206
[04-Jun-2013 21:24:53] NOTICE: finished trace of 18206
[04-Jun-2013 21:24:53] NOTICE: child 18226 stopped for tracing
[04-Jun-2013 21:24:53] NOTICE: about to trace 18226
[04-Jun-2013 21:24:53] NOTICE: finished trace of 18226
[04-Jun-2013 21:24:56] WARNING: [pool www] child 5137, script '/home/site/public_html/index.php' (request: "GET /index.php") executing too slow (12.055624 sec), logging
[04-Jun-2013 21:24:56] WARNING: [pool www] child 18206, script '/home/site/public_html/index.php' (request: "GET /index.php") execution timed out (15.395149 sec), terminating
[04-Jun-2013 21:24:56] WARNING: [pool www] child 17996, script '/home/site/public_html/index.php' (request: "GET /index.php") executing too slow (12.145728 sec), logging
[04-Jun-2013 21:24:56] WARNING: [pool www] child 17918, script '/home/site/public_html/index.php' (request: "GET /index.php") execution timed out (18.036700 sec), terminating
[04-Jun-2013 21:24:56] NOTICE: child 17996 stopped for tracing
[04-Jun-2013 21:24:56] NOTICE: about to trace 17996
[04-Jun-2013 21:24:56] NOTICE: finished trace of 17996
[04-Jun-2013 21:24:56] NOTICE: child 5137 stopped for tracing
[04-Jun-2013 21:24:56] NOTICE: about to trace 5137
[04-Jun-2013 21:24:56] NOTICE: finished trace of 5137
[04-Jun-2013 21:24:56] WARNING: [pool www] child 17918 exited on signal 15 (SIGTERM) after 4424.343036 seconds from start
[04-Jun-2013 21:24:56] NOTICE: [pool www] child 6706 started
[04-Jun-2013 21:24:56] WARNING: [pool www] child 18206 exited on signal 15 (SIGTERM) after 4424.264130 seconds from start
[04-Jun-2013 21:24:56] NOTICE: [pool www] child 6707 started
[04-Jun-2013 21:24:59] WARNING: [pool www] child 17996, script '/home/site/public_html/index.php' (request: "GET /index.php") execution timed out (15.479201 sec), terminating
[04-Jun-2013 21:24:59] WARNING: [pool www] child 17996 exited on signal 15 (SIGTERM) after 4427.655572 seconds from start
[04-Jun-2013 21:24:59] NOTICE: [pool www] child 6708 started
Here is my nginx config
user www-data;
worker_processes 4;
pid /var/run/nginx.pid;
worker_rlimit_nofile 20000;
events {
#worker_connections 768;
#worker_connections 19000;
#multi_accept on;
use epoll;
#worker_connections 10240;
worker_connections 4096;
}
http {
##
# Basic Settings
##
sendfile on;
tcp_nopush on;
tcp_nodelay on;
#keepalive_timeout 65;
#keepalive_timeout 5;
#added
client_body_timeout 15;
client_header_timeout 15;
keepalive_timeout 15;
send_timeout 15;
site.conf
proxy_buffer_size 128k;
proxy_buffers 4 256k;
proxy_busy_buffers_size 256k;
fastcgi_connect_timeout 60;
fastcgi_send_timeout 180;
fastcgi_read_timeout 180;
fastcgi_buffer_size 128k;
fastcgi_buffers 4 256k;
#fastcgi_buffers 256 16k; #4096k total
fastcgi_busy_buffers_size 256k;
fastcgi_temp_file_write_size 256k;
fastcgi_intercept_errors on;
php5-fpm is connecting via TCP port
Thanks