From owner-freebsd-hackers@FreeBSD.ORG Sun Jan 23 21:11:21 2011 Return-Path: Delivered-To: freebsd-hackers@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 6A78B1065672 for ; Sun, 23 Jan 2011 21:11:21 +0000 (UTC) (envelope-from cvs-src@yandex.ru) Received: from forward18.mail.yandex.net (forward18.mail.yandex.net [95.108.253.143]) by mx1.freebsd.org (Postfix) with ESMTP id F31E78FC16 for ; Sun, 23 Jan 2011 21:11:20 +0000 (UTC) Received: from smtp19.mail.yandex.net (smtp19.mail.yandex.net [95.108.252.19]) by forward18.mail.yandex.net (Yandex) with ESMTP id 29C2D29A05FE for ; Sun, 23 Jan 2011 23:55:29 +0300 (MSK) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yandex.ru; s=mail; t=1295816129; bh=OVLh646veNO4m30Ogjk7AQJ/j7EwZf/UHvWOLF1s8AY=; h=Message-ID:Date:From:MIME-Version:To:CC:Subject:Content-Type: Content-Transfer-Encoding; b=YsoRwbQgpozXfTZeidlQIItIjnKXggo8l8KLeRF+3SKoHSiqrD9P87ouf4J4lk14q eLFqKXv6mSX8lyyp7Kg+lQGSfO42Oy2Or5jzwgK2EY+EuXqvSltBBidbdEeHc0RHtK oIkIqaiFaj1VVyh5LN/9aV5JN3Y4Ojfd5woHgCdk= Received: from smeshariki2.local (unknown [213.138.87.92]) by smtp19.mail.yandex.net (Yandex) with ESMTPSA id D89C6287005C; Sun, 23 Jan 2011 23:55:28 +0300 (MSK) Message-ID: <4D3C957F.6080209@yandex.ru> Date: Sun, 23 Jan 2011 23:54:23 +0300 From: Ruslan Mahmatkhanov User-Agent: Mozilla/5.0 (X11; U; FreeBSD i386; ru-RU; rv:1.9.2.13) Gecko/20110106 Thunderbird/3.1.7 MIME-Version: 1.0 To: freebsd-hackers@freebsd.org Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 7bit X-Mailman-Approved-At: Mon, 24 Jan 2011 01:48:40 +0000 Cc: cvs-src@yandex.ru Subject: Tracking down a problem with php on FreeBSD X-BeenThere: freebsd-hackers@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Technical Discussions relating to FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 23 Jan 2011 21:11:21 -0000 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. 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: - 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 - `top -mio` shows very high (80000-90000 for VCSW) VCSW/IVCSW values for php-fpm processes and LA is more than 120 - 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 Jan 23 17:56:59.528873 [WARNING] [pool world] child 686, script '/usr/local/www/world/public_html/script.php' execution timed out (10.074251 sec), terminating Jan 23 17:57:03.221677 [WARNING] [pool world] child 686 exited on signal 15 (SIGTERM) after 59.424804 seconds from start Jan 23 17:57:03.222580 [NOTICE] [pool world] child 4407 started Jan 23 17:57:03.222709 [NOTICE] Finishing ... Jan 23 17:57:03.260991 [WARNING] [pool site] child 3962, script '/usr/local/www/site/public_html/script.php' execution timed out (12.644470 sec), terminating - nginx log has many of this lines in time of crash: 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://world.mist-game.ru/" 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://world.mist-game.ru/" 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/" `top -mio` output in time of crash: http://pastebin.com/yrCwxnbr kernel config: http://pastebin.com/nGA0518A php port options: # cat /var/db/ports/php5/options WITH_CLI=true WITH_CGI=true WITH_FPM=true WITH_APACHE=true WITHOUT_AP2FILTER=true WITHOUT_DEBUG=true WITH_SUHOSIN=true WITH_MULTIBYTE=true WITHOUT_IPV6=true WITH_MAILHEAD=true WITHOUT_LINKTHR=true php-fpm pool configuration: [world] listen = 127.0.0.1:9002 listen.allowed_clients = 127.0.0.1 listen.owner = www listen.group = www listen.mode = 0666 user = www group = www pm = dynamic pm.max_children = 100 pm.start_servers = 20 pm.min_spare_servers = 5 pm.max_spare_servers = 35 pm.max_requests = 5000 pm.status_path = /JWorldStatus request_terminate_timeout = 10s Any help is highly appreciated. Thank you all in advance. PS. Please keep me in cc:. I'm not subscribed to freebsd-hackers@. -- Regards, Ruslan