Stop working after X minutes. All TCP connections on port 9000 seems to be busy

112 views
Skip to first unread message

Zillo

unread,
Mar 31, 2010, 11:22:28 PM3/31/10
to highload-php-en
Hello,

I have the following problem with PHP-FPM. Every X minutes, nginx (or
lighttpd) can not connect with the fastcgi server. I realized that
when this happens all the TCP connections on port 9000 are established
or busy in some way while when it's working all of them are in
LISTEN_WAIT status. What can be te problem and solution? Here is a
paste bin with an example of what I mean: http://pastebin.com/8fXRfHmT

This happens with 5 children I tried with 25 and with 300 and same
result. Always around 100 TCP connections in LISTEN_WAIT until they
become all busy and nginx can not connect with fastcgi.

Jérôme Loyet

unread,
Apr 1, 2010, 1:39:18 AM4/1/10
to highloa...@googlegroups.com
2010/4/1 Zillo <anyw...@gmail.com>:

When you say it's working you have only TIME_WAIT connections. This is
a normal state and those connections are only known from the kernel,
not from FPM or nginx. See
http://stackoverflow.com/questions/41602/how-to-forcibly-close-a-socket-in-time-wait
for more details

When you say it's not working, there is a LOT of ESTABLISHED
connection. These means there is activity. In the netstat output you
pastbin, there is about 50 connections established between nginx and
fpm.

You can try to play with the number of children (you already did) and
with backlog (set it to 1 to be more agressiv). Look also at nginx
error log to see if it works correctly.

By the way, what is "4820/php-cgi" in your netstat output ? Are you
sure you're using fpm ?

++ Jerome

>
>
> --
> To unsubscribe, reply using "remove me" as the subject.
>

Zillo

unread,
Apr 1, 2010, 10:14:59 AM4/1/10
to highload-php-en
> You can try to play with the number of children (you already did) and
> with backlog (set it to 1 to be more agressiv). Look also at nginx
> error log to see if it works correctly.

php-fpm error log:

Apr 01 16:05:13.053665 [ERROR] fpm_trace_get_long(), line 78:
ptrace(PEEKDATA) failed: Input/output error (5)
Apr 01 16:05:13.053725 [NOTICE] fpm_php_trace(), line 172: finished
trace of 15497
Apr 01 16:05:13.706012 [WARNING] fpm_request_check_timed_out(), line
146: child 15498, script '/home/myaccount/public_html/forum/
search.php' (pool default) executing too slow (20.082817 sec), logging
Apr 01 16:05:13.706085 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
Apr 01 16:05:13.706111 [NOTICE] fpm_children_bury(), line 196: child
15498 stopped for tracing
Apr 01 16:05:13.706131 [NOTICE] fpm_php_trace(), line 144: about to
trace 15498
Apr 01 16:05:13.706653 [ERROR] fpm_trace_get_long(), line 78:
ptrace(PEEKDATA) failed: Input/output error (5)
Apr 01 16:05:13.706710 [NOTICE] fpm_php_trace(), line 172: finished
trace of 15498
Apr 01 16:05:15.402049 [WARNING] fpm_request_check_timed_out(), line
146: child 15499, script '/home/myaccount/public_html/forum/
showthread.php' (pool default) executing too slow (20.036711 sec),
logging
Apr 01 16:05:15.402137 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
Apr 01 16:05:15.402165 [NOTICE] fpm_children_bury(), line 196: child
15499 stopped for tracing
Apr 01 16:05:15.402187 [NOTICE] fpm_php_trace(), line 144: about to
trace 15499
Apr 01 16:05:15.402716 [ERROR] fpm_trace_get_long(), line 78:
ptrace(PEEKDATA) failed: Input/output error (5)
Apr 01 16:05:15.402776 [NOTICE] fpm_php_trace(), line 172: finished
trace of 15499
Apr 01 16:05:17.619075 [WARNING] fpm_request_check_timed_out(), line
146: child 15500, script '/home/myaccount/public_html/forum/
index.php' (pool default) executing too slow (20.039504 sec), logging
Apr 01 16:05:17.619163 [NOTICE] fpm_got_signal(), line 48: received
SIGCHLD
Apr 01 16:05:17.619224 [NOTICE] fpm_children_bury(), line 196: child
15500 stopped for tracing
Apr 01 16:05:17.619248 [NOTICE] fpm_php_trace(), line 144: about to
trace 15500
Apr 01 16:05:17.619771 [ERROR] fpm_trace_get_long(), line 78:
ptrace(PEEKDATA) failed: Input/output error (5)
Apr 01 16:05:17.619833 [NOTICE] fpm_php_trace(), line 172: finished
trace of 15500


> By the way, what is "4820/php-cgi" in your netstat output ? Are you
> sure you're using fpm ?

Sure. If I run service php-fpm stop that kind of connections
disappears from netstat

Jérôme Loyet

unread,
Apr 1, 2010, 10:18:37 AM4/1/10
to highloa...@googlegroups.com
2010/4/1 Zillo <anyw...@gmail.com>:

your requests seams to be very long, don't you have a database leak or
something which slow down your request process ?

>
>> By the way, what is "4820/php-cgi" in your netstat output ? Are you
>> sure you're using fpm ?
>
> Sure. If I run service php-fpm stop that kind of connections
> disappears from netstat
>
>

Zillo

unread,
Apr 1, 2010, 10:40:42 AM4/1/10
to highload-php-en
slow log (it seems that all the long connections has a mysql request)
but I have no idea if that is just a coincidence since probably all
the php connect with mysql. If that would be the problem I assume that
a simple php file with no sql connection should be easily opened and
if I am not wrong it was not possible to open a simple phpinfo during
these problems. Although maybe it was because all the childrens were
busy:

Apr 01 05:07:24.515507 pid 9565 (pool default)
script_filename = /home/myaccount/public_html/forum/showthread.php
[0x09b8ab60] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x09b8aa0c] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:498
[0x09b8a960] query_first() /home/myaccount/public_html/forum/includes/
class_core.php:529
[0x09b89ae0] query_first_slave() /home/myaccount/public_html/forum/
includes/class_core.php:3243
[0x09b868f0] vB_Session() /home/myaccount/public_html/forum/includes/
init.php:431
[0x09b865e4] +++ dump failed

Apr 01 05:07:26.060183 pid 9566 (pool default)
script_filename = /home/myaccount/public_html/forum/showthread.php
[0x098ef328] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x098ef1d4] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:498
[0x098ef128] query_first() /home/myaccount/public_html/forum/includes/
class_core.php:529
[0x098ee2a8] query_first_slave() /home/myaccount/public_html/forum/
includes/class_core.php:3243
[0x098eb0b8] vB_Session() /home/myaccount/public_html/forum/includes/
init.php:431
[0x098eadac] +++ dump failed

Apr 01 05:07:26.916937 pid 9567 (pool default)
script_filename = /home/myaccount/public_html/forum/showthread.php
[0x098a120c] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x098a10b8] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:498
[0x098a100c] query_first() /home/myaccount/public_html/forum/includes/
class_core.php:529
[0x098a0750] query_first_slave() /home/myaccount/public_html/forum/
includes/class_core.php:3569
[0x0989d578] fetch_userinfo() /home/myaccount/public_html/forum/
includes/init.php:435
[0x0989d26c] +++ dump failed

Apr 01 05:07:28.241276 pid 9568 (pool default)
script_filename = /home/myaccount/public_html/forum/showthread.php
[0x09cd4d98] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x09cd4c44] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:498
[0x09cd4b98] query_first() /home/myaccount/public_html/forum/includes/
class_core.php:529
[0x09cd45b0] query_first_slave() /home/myaccount/public_html/forum/
includes/class_bootstrap.php:772
[0x09cd43e4] fetch_style_record() /home/myaccount/public_html/forum/
includes/class_bootstrap.php:184
[0x09cd403c] load_style() /home/myaccount/public_html/forum/global.php:
31
[0x09cc4460] +++ dump failed

Apr 01 05:07:28.763639 pid 9569 (pool default)
script_filename = /home/myaccount/public_html/forum/index.php
[0x098926f4] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x09892628] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:468
[0x09891888] query_read_slave() /home/myaccount/public_html/forum/
includes/functions.php:4097
[0x0988d1d8] cache_ordered_forums() /home/myaccount/public_html/forum/
forum.php:584
[0x0988d128] +++ dump failed

Apr 01 05:07:30.133787 pid 9571 (pool default)
script_filename = /home/myaccount/public_html/forum/showthread.php
[0x098ee63c] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x098ee570] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:468
[0x098ee074] query_read_slave() /home/myaccount/public_html/forum/
includes/functions.php:3891
[0x098edca4] cache_templates() /home/myaccount/public_html/forum/
includes/class_bootstrap.php:1148
[0x098ec16c] cache_templates() /home/myaccount/public_html/forum/
includes/class_bootstrap.php:207
[0x098ec058] process_templates() /home/myaccount/public_html/forum/
includes/class_core.php:3821
[0x098ebefc] __construct() /home/myaccount/public_html/forum/includes/
class_core.php:3799
[0x098eb3a8] create() /home/myaccount/public_html/forum/includes/
functions.php:4184
[0x098ea84c] construct_quick_nav() /home/myaccount/public_html/forum/
includes/functions.php:4190
[0x098dac68] construct_quick_nav() /home/myaccount/public_html/forum/
showthread.php:361

Apr 01 05:07:30.986745 pid 9572 (pool default)
script_filename = /home/myaccount/public_html/forum/forumdisplay.php
[0x09895f68] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x09895e9c] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:468
[0x098950fc] query_read_slave() /home/myaccount/public_html/forum/
includes/functions.php:4097
[0x0988d128] cache_ordered_forums() /home/myaccount/public_html/forum/
forumdisplay.php:240

Apr 01 05:07:33.442751 pid 9574 (pool default)
script_filename = /home/myaccount/public_html/forum/showthread.php
[0x0989ebec] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x0989ea98] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:498
[0x0989e9ec] query_first() /home/myaccount/public_html/forum/includes/
class_core.php:529
[0x0989e764] query_first_slave() /home/myaccount/public_html/forum/vb/
cache/db.php:125
[0x0989e49c] readCache() /home/myaccount/public_html/forum/vb/
cache.php:364
[0x0989e2fc] read() /home/myaccount/public_html/forum/vb/types.php:151
[0x0989e284] loadTypes() /home/myaccount/public_html/forum/vb/
types.php:120
[0x0989e134] __construct() /home/myaccount/public_html/forum/vb/
types.php:136
[0x0989e00c] instance() /home/myaccount/public_html/forum/packages/
vbattach/attach.php:1255
[0x0989dd4c] __construct() /home/myaccount/public_html/forum/includes/
class_postbit.php:478
[0x0989cd0c] process_attachments() /home/myaccount/public_html/forum/
includes/class_postbit.php:300
[0x0988d128] construct_postbit() /home/myaccount/public_html/forum/
showthread.php:1036

Apr 01 05:07:35.386957 pid 9575 (pool default)
script_filename = /home/myaccount/public_html/forum/search.php
[0x098df2dc] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x098df210] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:439
[0x098defd8] query_write() /home/myaccount/public_html/forum/vb/search/
results.php:493
[0x098dea94] cache_results() /home/myaccount/public_html/forum/vb/
search/results.php:298
[0x098dac58] get_page() /home/myaccount/public_html/forum/search.php:
474

Apr 01 05:07:36.619008 pid 9576 (pool default)
script_filename = /home/myaccount/public_html/forum/forumdisplay.php
[0x099f9548] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x099f947c] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:468
[0x099f14b0] query_read_slave() /home/myaccount/public_html/forum/
forumdisplay.php:928

Apr 01 05:07:46.329858 pid 9579 (pool default)
script_filename = /home/myaccount/public_html/forum/showthread.php
[0x0989cdd8] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x0989cd0c] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:454
[0x0988d128] query_read() /home/myaccount/public_html/forum/
showthread.php:945

Apr 01 05:16:05.890115 pid 10172 (pool default)
script_filename = /home/myaccount/public_html/forum/search.php
[0x08b84db0] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x08b84ce4] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:468
[0x08b84888] query_read_slave() /home/myaccount/public_html/forum/
includes/functions_forumdisplay.php:42
[0x08b84224] fetch_dot_threads_array() /home/myaccount/public_html/
forum/packages/vbforum/search/type/thread.php:93
[0x08b83aa0] prepare_render() /home/myaccount/public_html/forum/vb/
search/resultsview.php:70
[0x08b82f68] render_searchbits() /home/myaccount/public_html/forum/vb/
search/resultsview.php:158
[0x08b7f128] showpage() /home/myaccount/public_html/forum/search.php:
386

Apr 01 05:41:18.386509 pid 10481 (pool default)
script_filename = /home/myaccount/public_html/forum/showthread.php
[0x08bde660] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x08bde50c] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:498
[0x08bde460] query_first() /home/myaccount/public_html/forum/includes/
class_core.php:529
[0x08bdd0b0] query_first_slave() /home/myaccount/public_html/forum/
includes/functions.php:1507
[0x08bdc228] fetch_userinfo() /home/myaccount/public_html/forum/
includes/class_core.php:3253
[0x08bd9038] vB_Session() /home/myaccount/public_html/forum/includes/
init.php:431
[0x08bd8d2c] +++ dump failed

Apr 01 05:41:25.426457 pid 10482 (pool default)
script_filename = /home/myaccount/public_html/forum/member.php
[0x08b885d0] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x08b8847c] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:498
[0x08b883d0] query_first() /home/myaccount/public_html/forum/includes/
class_core.php:529
[0x08b87020] query_first_slave() /home/myaccount/public_html/forum/
includes/functions.php:1507
[0x08b86198] fetch_userinfo() /home/myaccount/public_html/forum/
includes/class_core.php:3263
[0x08b82fa8] vB_Session() /home/myaccount/public_html/forum/includes/
init.php:431
[0x08b82c9c] +++ dump failed

Apr 01 05:41:29.339466 pid 10484 (pool default)
script_filename = /home/myaccount/public_html/forum/forumdisplay.php
[0x08eda9b8] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x08eda8ec] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:468
[0x08ed9b4c] query_read_slave() /home/myaccount/public_html/forum/
includes/functions.php:4097
[0x08ed1b78] cache_ordered_forums() /home/myaccount/public_html/forum/
forumdisplay.php:240

Apr 01 05:41:30.644420 pid 10480 (pool default)
script_filename = /home/myaccount/public_html/forum/showthread.php
[0x08b8edd8] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x08b8ed0c] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:454
[0x08b7f128] query_read() /home/myaccount/public_html/forum/
showthread.php:945

Apr 01 05:41:35.466448 pid 10490 (pool default)
script_filename = /home/myaccount/public_html/forum/showthread.php
[0x08bd87e8] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x08bd871c] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:454
[0x08bc8b38] query_read() /home/myaccount/public_html/forum/
showthread.php:945

Apr 01 16:05:09.647233 pid 15496 (pool default)
script_filename = /home/myaccount/public_html/forum/showthread.php
[0x08c242b8] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x08c24164] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:498
[0x08c240b8] query_first() /home/myaccount/public_html/forum/includes/
class_core.php:529
[0x08c23238] query_first_slave() /home/myaccount/public_html/forum/
includes/class_core.php:3297
[0x08c20048] vB_Session() /home/myaccount/public_html/forum/includes/
init.php:431
[0x08c1fd3c] +++ dump failed

Apr 01 16:05:13.053171 pid 15497 (pool default)
script_filename = /home/myaccount/public_html/forum/showthread.php
[0x08c242b8] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x08c24164] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:498
[0x08c240b8] query_first() /home/myaccount/public_html/forum/includes/
class_core.php:529
[0x08c23238] query_first_slave() /home/myaccount/public_html/forum/
includes/class_core.php:3297
[0x08c20048] vB_Session() /home/myaccount/public_html/forum/includes/
init.php:431
[0x08c1fd3c] +++ dump failed

Apr 01 16:05:13.706160 pid 15498 (pool default)
script_filename = /home/myaccount/public_html/forum/search.php
[0x08c18508] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x08c183b4] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:498
[0x08c18308] query_first() /home/myaccount/public_html/forum/includes/
class_core.php:529
[0x08c17488] query_first_slave() /home/myaccount/public_html/forum/
includes/class_core.php:3243
[0x08c14298] vB_Session() /home/myaccount/public_html/forum/includes/
init.php:431
[0x08c13f8c] +++ dump failed

Apr 01 16:05:15.402219 pid 15499 (pool default)
script_filename = /home/myaccount/public_html/forum/showthread.php
[0x08c242b8] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x08c24164] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:498
[0x08c240b8] query_first() /home/myaccount/public_html/forum/includes/
class_core.php:529
[0x08c23238] query_first_slave() /home/myaccount/public_html/forum/
includes/class_core.php:3297
[0x08c20048] vB_Session() /home/myaccount/public_html/forum/includes/
init.php:431
[0x08c1fd3c] +++ dump failed

Apr 01 16:05:17.619279 pid 15500 (pool default)
script_filename = /home/myaccount/public_html/forum/index.php
[0x08c18e30] mysqli_query() /home/myaccount/public_html/forum/includes/
class_core.php:1299
[0x08c18cdc] execute_query() /home/myaccount/public_html/forum/
includes/class_core.php:498
[0x08c18c30] query_first() /home/myaccount/public_html/forum/includes/
class_core.php:529
[0x08c17db0] query_first_slave() /home/myaccount/public_html/forum/
includes/class_core.php:3297
[0x08c14bc0] vB_Session() /home/myaccount/public_html/forum/includes/
init.php:431
[0x08c148b4] +++ dump failed

Anyway I understand that if a mysql connection takes too much time
there should be a way to set some kind of timeout in order to avoid
all php-fpm childrens to be busy.


On 1 abr, 16:18, Jérôme Loyet <m...@fatbsd.com> wrote:
> 2010/4/1 Zillo <anywhe...@gmail.com>:

Jérôme Loyet

unread,
Apr 1, 2010, 10:48:26 AM4/1/10
to highloa...@googlegroups.com
2010/4/1 Zillo <anyw...@gmail.com>:

It's maybe the mysql server which is busy. Lookat at the mysqli
extension documentation about timeouts:
http://www.php.net/manual/fr/mysqli.constants.php

Which versions of FPM and PHP are you using ?

Zillo

unread,
Apr 1, 2010, 11:01:52 AM4/1/10
to highload-php-en
php 5.3.2-1.el5 Development/Languages PHP scripting language for
creating dynamic web sites
php-fpm 5.3.2-1.el5 System Environment/Libraries A module for PHP
applications for using php-fpm interfaces

I am also happing problems with apache + mod_php to deal with this
forum. I installed several versions of php, several webservers,
spawncgi, php-fpm... Everything. In fact I think this problem also
existed before we imported phpbb2 forum to vBulletin a few weeks ago.
Both run a different database but the same database server and the
same webserver (two machines: webserver + db server)

I also have seen this:
mysqladmin proc sta
Uptime: 1449536 Threads: 1 Questions: 84754150 Slow queries: 19843
Opens: 1658570 Flush tables: 1 Open tables: 512 Queries per second
avg: 58.469

Slow queries: 19843

So do you think mysql must be the problem? If so no idea from where to
start to find the problem

Zillo

unread,
Apr 1, 2010, 12:38:52 PM4/1/10
to highload-php-en
Looks like mysql is the problem. Every time everything stops working I
restart mysql and everything works again. When it stops working I
check the mysql connections and there are a lot opened since more than
one minute ago.

> ...
>
> leer más »

Ammon Lauritzen

unread,
Apr 1, 2010, 7:56:15 PM4/1/10
to highloa...@googlegroups.com
This looks like it's just a standard case of an
overworked/overused/underpowered database server versus the web
traffic coming at it.

So a few easy places to start looking to fix this:
- stop using persistent mysql connections
- set your idle timeout on connections lower
- attempt to manually close connections when finished rendering your page
- make sure you only consume one connection per page request if at all possible

And always, if you can start looking at ways to avoid going directly
to the database and in stead go through a caching layer or use a
different fcgi pool for page renders that don't require a database hit
etc... Lots of options ;)

Ammon Lauritzen

unread,
Apr 1, 2010, 8:05:30 PM4/1/10
to highloa...@googlegroups.com
Or mysql simply could be misconfigured or your queries could just be
inefficient and need more/less indexes/joins, etc... ;)

You might want to make sure you still render something if a mysql
connection fails. But if the cgi pool is running out of workers
because they're all blocked on slow queries... the only thing I can
think of immediately is to make sure you don't ever run out of
workers. If mysql can be set not to allow more connections than your
workers, you'll need code to handle cases when you failed to get a
connection, but you will at least be able to render something more
interesting than a 504.

Reply all
Reply to author
Forward
0 new messages