6

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

2
  • The CPU's are : Intel(R) Xeon(R) CPU E3-1230 V2 @ 3.30GHz ... but the system load is very low i.e. < 1.8
    – B p
    Jun 5, 2013 at 3:08
  • 1
    OK, the first thing you need to do is figure out where your bottleneck is. Jun 5, 2013 at 3:19

4 Answers 4

4

I think you are probably running far too many concurrent php processes, but it's hard to know without more info on where your resource bottlenecks are. I imagine that you are probably constrained by Disk IO and/or CPU, and that all your parallel PHP processes are competing for those and slowing each other down. At some point the overhead of process switching becomes a significant factor, and you get less throughput rather than more by having lots of processes running. You may also be getting into, or risking, situations where you run out of RAM and start swapping, which is very bad. Trust in nginx being able to queue requests up and keep a higher throughput of quicker requests going while doing less of them simultaneously.

I'd generally go for anything from 5 to 50 PHP processes, with both ends of that range being a little exceptional. More usually 10-15. With very high performance disk systems, and more than the usual 16 or so cores it might make sense to have more processes, but that's usually a false economy compared to having a larger number of cheaper servers. In my experience, unless you have a lot of really badly written code, there's usually little benefit to having more than about 15 php processes in parallel on a single server, and if there's a benefit it's likely to be stability rather than throughput, in the face of pathologically long-running requests piling up and leaving no spare processes available.

If you have multiple code bases with separate process pools, you might want a large number of processes, but you probably don't want more than 3 to 5 processes per pool.

You do want a lot of nginx worker connections handling static files. There's unlikely to be any improvement beyond 4096, and only in unusual circumstances would you see a difference between 1000 and 4000. (Unless you are primarily serving static files - that's quite a different scenario, but since you're talking about php processes on this box I don't imagine that's the case here).

I suspect your timeouts are too long. If there's nothing going on, drop the connection and get on to the next one.

4
  • If each PHP process is waiting 2-3 seconds for an external resource to be fetched (e.g. SQL query) wouldn't that be a case where having many more processes than CPU cores would help throughput?
    – Danack
    Jun 7, 2013 at 14:33
  • Maybe, but if they are all waiting for queries against the same DB server, and it's at capacity, then running more queries in parallel doesn't help (and may hurt) overall throughput after the first few parallel tasks.
    – mc0e
    Jun 7, 2013 at 17:57
  • Yeah - I meant if the were running different queries against different tables, or just queries that weren't blocking each other.
    – Danack
    Jun 7, 2013 at 19:36
  • Besides bottlenecks, disk IO and CPU are likely to be issues. Your DB issue can put through more queries per minute if it does 5 in parallel than if it does 50 or 500.
    – mc0e
    Jun 27, 2013 at 16:07
2

1) Memory - The first thing I'd look at is why your scripts need 50MB of memory if all they're doing is a simple search - I'm assuming you're not actually returned multiple megabytes of data per user, if you're serving hundreds of requests a second.

There is a bug in the MySQL connector library that makes PHP allocate the maximum size possible for any TEXT or BLOB, rather than just the actual amount of memory needed. This can be fixed by moving to the MySQLND library, with no code change required.

2) Your setting of pm.max_requests = 10000 is probably not a great choice. If each request is taking 2 seconds, then you're telling the process manager to restart each process after 20,000 seconds or almost 6 hours. That seems a very long time, and would be enough time for any memory leak to bring the process down. Putting it back to 500 would still only be a restart every 15 minutes, which would have no effect on performance but be likely to be more stable.

3) As Michael said, even if you are able to allow as many processes as you have users connecting, you still need to figure out where the bottleneck actually is. Even though you have multiple hundred PHP processes at once, if they're all just waiting for the SQL server to become available then they'll always just queue up to wait and eventually start timing out.

Unless you can remove the bottle-neck you'll need to either implement a rate-limiting mechanism to only allow as many queries as your server setup can handle, or a graceful degradation to reject requests that your server is currently unable to handle.

1

I can't comment yet ( not enough rep ) so I will post an answer : It would be good to have your nginx logs too.

About your pool.d/www config : If you put your pm in static, most of your variables won't have any effect, it's max_children which will mainly impact your setup. (http://php.net/manual/en/install.fpm.configuration.php ) Try maybe with a PM "ondemand".

You should not start with a pm.start_servers that high. You should lower too your min_spare_servers.

About your nginx config : http://wiki.nginx.org/CoreModule#worker_processes "max_clients = worker_processes * worker_connections"

Your value "worker_rlimit_nofile" looks incorrect to me.

Look at http://wiki.nginx.org/CoreModule#worker_cpu_affinity to use all your cores too.

2
  • 1
    Oh and by the way : Could you add "slowlog" with the location of your log for slow requests in your /etc/php5/php-fpm/www.conf file ? And then give us the output of this log file ?
    – Yannovitch
    Jun 5, 2013 at 8:05
  • 1
    Could you give us too your php.ini conf ? Sometimes, such problems are produced because of too high values for memory_limit for your PHP processes for example.
    – Yannovitch
    Jun 5, 2013 at 8:08
1

If everything else fails... I think maybe you can handle this in code. You can create a "ticket system" to allow a certain number of searches simultaneously, and give your users an approximate waiting time. Something like "your search will start in N seconds".

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .