2

We are running a Symfony application on Ubuntu 14.04 with Nginx and PHP-FPM

The problem is that individual PHP FPM will occasionally hang on our production servers.

I have the output from the status page:

pid:                  13416
state:                Finishing
start time:           08/Sep/2014:12:35:29 +1000
start since:          10548
requests:             3
request duration:     158138427297
request method:       GET
request URI:          /app.php?searchText=Search+term&page=2
content length:       0
user:                 -
script:               /var/projects/site_path/app.php
last request cpu:     0.00
last request memory:  0

I can't figure out why this process is hanging.

If I strace the process it is just looping with this:

# strace -p 13416
gettimeofday({1410154710, 385743}, NULL) = 0

I have checked the Nginx access logs and matched up the request and the request is fine, it's returning a 200 and no errors can be replicated using the url).

Any help would be greatly appreciated

Access logs:

172.30.12.110 - - [08/Sep/2014:12:35:29 +1000] "GET /search?searchText=Search+term&page=2 HTTP/1.1" 200 11174 "/search?searchText=Search+term" "Mozilla/5.0 (Windows NT 6.3; WOW64; Trident/7.0; MATPJS; rv:11.0) like Gecko"
172.30.12.110 - - [08/Sep/2014:12:35:32 +1000] "GET /search?searchText=Search+term&page=2 HTTP/1.1" 200 11174 "-" "Mediapartners-Google"
172.30.12.110 - - [08/Sep/2014:12:35:34 +1000] "GET /search?searchText=Search+term&page=2 HTTP/1.1" 200 11169 "-" "Mediapartners-Google"
172.30.12.110 - - [08/Sep/2014:12:35:51 +1000] "GET /search?searchText=OSearch+term&page=3 HTTP/1.1" 200 11158 "/search?searchText=Oven+baked+duck+and+shitake+rissotto&page=2" "Mozilla/5.0 (Windows NT 6.3; WOW64; Trident/7.0; MATPJS; rv:11.0) like Gecko"
172.30.12.110 - - [08/Sep/2014:12:36:50 +1000] "GET /profile/ HTTP/1.1" 200 8108 "/search?searchText=Oven+baked+duck+and+shitake+rissotto&page=4" "Mozilla/5.0 (Windows NT 6.3; WOW64; Trident/7.0; MATPJS; rv:11.0) like Gecko
masegaloeh
  • 17,978
  • 9
  • 56
  • 104
Joshua Cullen
  • 41
  • 1
  • 6

3 Answers3

2

It turns out we were using invalid Memcached keys in certain situations. This was causing Memcached to die without error and the PHP process was staying alive.

Joshua Cullen
  • 41
  • 1
  • 6
  • Hi Studduck! did you really solve your problem with php-fpm? What do you mean by "invalid memcached keys"? Thanks. – Beto Aveiga Dec 02 '14 at 05:53
  • 1
    Hi Beto. Yeah I managed to solve it. We were using a function to concatenate our search terms into a key to use when saving the search results to Memcached. There was a bug in our function that meant sometimes certain terms would return keys that weren't valid Memcached keys. Unfortunately the PHP driver we were using to save to Memcached did not catch this error and PHP would fail silently leaving the process running gettimeofday. If you're having a similar issue try see what process are open at the same time as the hanging process, i.e. Memcached, MySql e.t.c. – Joshua Cullen Dec 05 '14 at 05:16
  • Thanks a lot Studduck... So, -when PHP fail silently this occurs... possibly by other process that fail before-. It's reasonable. Anyway PHP-FPM should kill it's workers based on "max execution time" paramater (i don't remember the name exactly) but it doesn't until reload. – Beto Aveiga Dec 06 '14 at 16:50
  • Yeah something like that. We had set the params such as max execution time but they were ignored. – Joshua Cullen Dec 07 '14 at 22:03
1

In our case, we had configured mod_proxy_fastcgi with a Unix domain socket and connection reuse (enablereuse=on), however as mentioned in lkraav's comment at https://github.com/icing/mod_h2/issues/62:

# UDS does not currently support connection reuse

That was what was causing the FPM child processes to pile up in finishing state. Removing connection reuse solved the problem and greatly stabilized the system.

SerkanC
  • 111
  • 2
0

Since you say that fpm hangs, you should watch fpm logs instead of nginx. Turn on slow_log and debug logging in php-fpm.config. Also try strace with different options to see more. maybe it's related to a specific php function

sgohl
  • 1,373
  • 1
  • 11
  • 16
  • I've added the slow log but it seems that that request is not being logged even though it stays open for hours. I've also added a request_terminate_timeout which is also being ignored by the hanging process – Joshua Cullen Sep 17 '14 at 04:54
  • maybe pm-servers are too low? are they set to static or dynamic? or maybe you're reaching open files (man limit.conf)? are you connecting nginx to fpm via socket or tcp? – sgohl Sep 19 '14 at 19:12
  • These are our pm settings: pm = dynamic pm.max_children = 10 pm.start_servers = 2 pm.min_spare_servers = 2 pm.max_spare_servers = 2 We're connecting via socket. What issues would you expect by the pm-servers being too low? – Joshua Cullen Sep 21 '14 at 23:13