Tracking down a problem with php on FreeBSD

[Ivan Voras]

On 23.1.2011 23:58, Ruslan Mahmatkhanov wrote:
>
> Good day!
>
> We are using custom php application on FreeBSD 8.1R amd64. It is started
> with php-fpm 5.3.3 from ports as backend and nginx 0.8.54 as frontend.
> Several times per day this app is making self unavailable.

I think it would be more appropriate to ask this on the stable@ list.

> Simple php-fpm restart solves the problem, but i need to track it down
> to the cause of this situation and ask for your assistance and
> instructions on how to debug it. Some facts about this:

On one hand, FPM is said to be very experimental...

Personally, I've been using apache22-worker or apache22-event + 
mod_fcgid for years without trouble.

> - I don't know how to manually reproduce this, but it happens several
> times every day
> - It happens on FreeBSD 7.x too
> - It happens with apache+mod_php instead php-fpm
> - It happens with lighthttpd instead nginx
> - It happens with both SHED_4BSD and SHED_ULE
> - It doesn't happen on php =< 5.2.12
> - It happens with and w/o eaccelerator

It looks very application-specific, possibly not really an OS problem 
(or maybe a problem of different expectations from the OS when porting 
from Linux).

> - `top -mio` shows very high (80000-90000 for VCSW) VCSW/IVCSW values
> for php-fpm processes and LA is more than 120

How many "real" user request are in these 120? Do any users at the time 
of problem (this doesn't look like a "crash") receive valid responses?

> - user seeing http 502 error code in browser
> - php-fpm log has many of this lines in time of crash:
> Jan 23 17:56:58.176425 [WARNING] [pool world] server reached
> max_children setting (100), consider raising it

Did you try raising it? Does the error happen ONLY when this limit is 
reached?

> 2011/01/23 17:57:00 [error] 38018#0: *26006023 writev() failed (54:
> Connection reset by peer) while sending request to upstream, client:
> xx.xx.xx.xx, server: some.server.org, request: "POST /?ctrl=Chat&
> a=chatList&__path=chat_list&h=8093b9e1cf448762d5677e21bded97ae&
> h1=38ca8b747a46098c3b1a4f39e6658170 HTTP/1.1", upstream:
> "fastcgi://127.0.0.1:9002", host: "some.server.org", referrer:
> "http://some.server.org/"
> 2011/01/23 17:57:00 [error] 38016#0: *26029878 kevent() reported
> about an closed connection (54: Connection reset by peer) while
> reading response header from upstream, client: xx.xx.xx.xx, server:
> some.server.org, request: "POST /?ctrl=Location&a=refresh&
> __path=refresh&h=276f591df26a65d9a1736f6e1006f4ab&
> h1=3c0916c16b1fc2e7015b71e90bbc3d23 HTTP/1.1", upstream:
> "fastcgi://127.0.0.1:9002", host: "some.server.org", referrer:
> "http://some.server.org/"
> 2011/01/23 17:57:02 [crit] 38020#0: *26034390 open() "/tmp/nginx
> /client_temp/1/74/0000000741" failed (13: Permission denied) while
> sending request to upstream, client: xx.xx.xx.xx, server:
> some.server.org, request: "POST /?ctrl=Chat&a=send&__path=chat_send&
> h=4a27d8d382ba9b1059412323a451ef84&
> h1=b0a53c86e3c744a01356a5030559ed1a HTTP/1.1", upstream:
> "fastcgi://127.0.0.1:9002", host: "some.server.org", referrer:
> "http://some.server.org/"
> 2011/01/23 17:57:02 [alert] 38020#0: *26034390 http request count is
> zero while sending to client, client: xx.xx.xx.xx, server:
> some.server.org, request: "POST /?ctrl=Chat&a=send&__path=chat_send&
> h=4a27d8d382ba9b1059412323a451ef84&
> h1=b0a53c86e3c744a01356a5030559ed1a HTTP/1.1", upstream:
> "fastcgi://127.0.0.1:9002", host: "some.server.org", referrer:
> "http://some.server.org/"
> 2011/01/23 17:57:03 [error] 38014#0: *25997903 upstream prematurely
> closed connection while reading response header from upstream,
> client: 109.229.69.186, server: some.server.org, request: "POST
> /?ctrl=Chat&a=chatList&__path=chat_list&
> h=c8723de73c4f8ebb98f9bf746d75e965&
> h1=3ab289760a009b07b73c6d96cc94a509 HTTP/1.1", upstream:
> "fastcgi://127.0.0.1:9002", host: "some.server.org", referrer:
> "http://some.server.org/"

These are some very varied errors, not especially consistent with each 
other.

Did you try some generic socket & TCP tuning like described in 
http://serverfault.com/questions/64356/freebsd-performance-tuning-sysctls-loader-conf-kernel 
?

Other than that, you will probably have to debug the php-fpm processes. 
Start by observing in which state they are (top without "-mio"). If the 
processes are blocking, try "procstat -k <pid>" on them.