2.1.3 Killed My Website

[bkonia]

I upgraded to 2.1.3 and it totally killed my site. When I tried to open a page in my browser, the web server just hung indefinitely and finally returned a 503 error. I couldn't even get phpinfo to display. After reverting back to 2.1.2, everything worked fine again.

I'm running PHP 5.0.5 with the LSAPI.

 

[mistwang]

Sorry to hear about that.

We tried PHP 5.0.5 with LSAPI interface, works fine. Which version of LSAPI code are you using? we tried both 1.5 and 1.6.

Do you have a test machine to play with, I wish you can provide more information to help us identify the problem, like some detailed debug log by using our "toggle debug logging" feature.

Thanks,
George

 

[illidan]

2.1.3 killed my site too

I'm using php with fastcgi and after the upgrade all php scripts goes down, it gives 408 timeout error. I have switched to 2.1.2 again and it is ok now.

 

[SyNeo]

I got this problem as well, on PHP 5.0.4, with FastCGI. Had to rollback to the 2.1RC3 version in order to correct it. I did the update via the admin interface, rather then manual installation - perhaps there is some problem with this method of installation?

P.S.: Perhaps there is a way I can fetch the 2.1.2 version meanwhile?

 

[mistwang]

I need more information to trouble shoot this, like:
OS:
PHP accelerator used:
Memory used for opcode cache:
Resource limit setting for CGI scripts:
Which level the PHP external app being defined, server or vhost?
Is the vhost being configured to start CGI in setuid mode?

It is better if I can logon to your box and take a look, please PM me if you want to.

Also, please check your lsws/logs/stderr.log, see if any thing related to starting PHP.

Thanks.

 

[ts77]

I had the same problem as well.
gentoo-linux with lsws-2.1.2 before, php-4.4.0 (fast-cgi), PECL-apc installed.

Somewhen it just worked, I think some complete /etc/init.d/lsws stop; wait a while; /etc/init.d/lsws start;

solved that.
I can't put the finger on it but I think that helped. Otherwise I didn't change anything.

 

[mistwang]

If this problem can be fixed this way, we will stop investigating this issue.

Thomas, can you please comfirm that graceful restart from admin interface still works properly with 2.1.3.

Thanks!

 

[ts77]

graceful restart works but I think I was on the wrong track.

thats the situation now:
I have one php-4.4.0 install which is used for most sites and globally defined as handler for php.
Those work.

I have on php-5.0.5 install which is used for just *one* vhost for testing.
That one *doesn't* work since the upgrade.
I get that in the logs for it:

2005-10-19 22:43:26.011 [NOTICE] [194.97.161.79:3456-0#phorumdev] ExtConn timed out while processing.
2005-10-19 22:43:56.015 [NOTICE] [194.97.161.79:3456-0#phorumdev] ExtConn timed out while processing.
2005-10-19 22:44:26.019 [NOTICE] [194.97.161.79:3456-0#phorumdev] ExtConn timed out while processing.
2005-10-19 22:44:26.019 [NOTICE] [php5] try to fix 503 error by restarting external application
2005-10-19 22:44:47.021 [NOTICE] [php5] Send SIGTERM to process [19514].

Switching to 2.1.2 makes that vhost working again. Switching to 2.1.3 again makes this vhost defunct.


Let me know what I should try. Toggle Debug Log didn't return more information.

 

[mistwang]

Thanks Thomas.

Is the php-5.0.5 with LSAPI or FastCGI? With PHP_xxx_CHILDREN environment or not?

Let me know what I should try. Toggle Debug Log didn't return more information.

Please set "Log Level" to DEBUG at server level and the testing vhost.

 

[ts77]

its fcgi

   Configure Command                   './configure' '--prefix=/usr/local/php-5.0.5' '--enable-fastcgi' '--with-mysql'
   Server API                          CGI/FastCGI

......... WTF? ........

Another finding from me:
Its not that given script-handler, its the *second script-handler*. If I call that vhost first then the other with php4 doesn't work.
Its just that only one script-handler works.

Here is the output from the debug-log:

2005-10-19 23:32:34.089 [DEBUG] [194.97.161.79:4016-0#phorumdev] Find handler [php5] for [.php]
2005-10-19 23:32:34.089 [DEBUG] [194.97.161.79:4016-0#phorumdev] processContextPath() return 0
2005-10-19 23:32:34.089 [DEBUG] [194.97.161.79:4016-0#phorumdev] run fcgi processor.
2005-10-19 23:32:34.092 [DEBUG] [php5] add child process pid: 22485
2005-10-19 23:32:34.092 [DEBUG] [UDS://tmp/lshttpd/php-fcgi-5.sock] create new connection succeed!
2005-10-19 23:32:34.092 [DEBUG] [UDS://tmp/lshttpd/php-fcgi-5.sock] request [194.97.161.79:4016-0#phorumdev:fcgi] is assigned with connection!
2005-10-19 23:32:34.092 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] [ExtConn] reconnect()
2005-10-19 23:32:34.092 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] [ExtConn] connecting to [UDS://tmp/lshttpd/php-fcgi-5.sock]...
2005-10-19 23:32:34.092 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] ExtConn::onWrite()
2005-10-19 23:32:34.092 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::doWrite()
2005-10-19 23:32:34.092 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::beginRequest()
2005-10-19 23:32:34.093 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::pendingWrite(),m_iCurStreamHeader=16
2005-10-19 23:32:34.093 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] request header is done
2005-10-19 23:32:34.093 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::beginReqBody()
2005-10-19 23:32:34.093 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::pendingEndStream()
2005-10-19 23:32:34.093 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] ExtConn::continueRead()
2005-10-19 23:32:34.093 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] Request body done!
2005-10-19 23:32:34.093 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::endOfReqBody()
2005-10-19 23:32:34.093 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::pendingEndStream()
2005-10-19 23:32:34.093 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::flush()
2005-10-19 23:32:34.093 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::suspendWrite()
2005-10-19 23:32:34.093 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] processNewReq() return 0.
2005-10-19 23:32:34.093 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] readToHeaderBuf() return 0.
2005-10-19 23:32:34.098 [DEBUG] Remove pid: 22485
2005-10-19 23:32:44.010 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] No response in 10 seconds, possible dead lock, try starting a new instance.
2005-10-19 23:32:44.017 [DEBUG] [php5] add child process pid: 22496
2005-10-19 23:32:44.018 [DEBUG] Remove pid: 22496
2005-10-19 23:33:04.012 [NOTICE] [194.97.161.79:4016-0#phorumdev:fcgi] ExtConn timed out while processing.
2005-10-19 23:33:04.012 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] connection to [UDS://tmp/lshttpd/php-fcgi-5.sock] on request #0, error: Connection timed out!
2005-10-19 23:33:04.012 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] [ExtConn] close()
2005-10-19 23:33:04.012 [DEBUG] [UDS://tmp/lshttpd/php-fcgi-5.sock] No Request has been processed successfully through this connection, the maximum connections allowed will be reduced!
2005-10-19 23:33:04.012 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] HttpExtConnector::tryRecover()...
2005-10-19 23:33:04.012 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] trying to recover from connection problem, attempt: #1!
2005-10-19 23:33:04.012 [DEBUG] [UDS://tmp/lshttpd/php-fcgi-5.sock] request [194.97.161.79:4016-0#phorumdev:fcgi] is assigned with connection!
2005-10-19 23:33:04.012 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] [ExtConn] reconnect()
2005-10-19 23:33:04.016 [DEBUG] [php5] add child process pid: 22515
2005-10-19 23:33:04.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] [ExtConn] connecting to [UDS://tmp/lshttpd/php-fcgi-5.sock]...
2005-10-19 23:33:04.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] ExtConn::onWrite()
2005-10-19 23:33:04.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::doWrite()
2005-10-19 23:33:04.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::beginRequest()
2005-10-19 23:33:04.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::pendingWrite(),m_iCurStreamHeader=16
2005-10-19 23:33:04.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] request header is done
2005-10-19 23:33:04.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::beginReqBody()
2005-10-19 23:33:04.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::pendingEndStream()
2005-10-19 23:33:04.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] ExtConn::continueRead()
2005-10-19 23:33:04.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] Request body done!
2005-10-19 23:33:04.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::endOfReqBody()
2005-10-19 23:33:04.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::pendingEndStream()
2005-10-19 23:33:04.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::flush()
2005-10-19 23:33:04.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::suspendWrite()
2005-10-19 23:33:04.021 [DEBUG] Remove pid: 22515
2005-10-19 23:33:14.013 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] No response in 10 seconds, possible dead lock, try starting a new instance.
2005-10-19 23:33:14.021 [DEBUG] [php5] add child process pid: 22525
2005-10-19 23:33:14.022 [DEBUG] Remove pid: 22525
2005-10-19 23:33:29.902 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] HttpIOLink::handleEvents() events=1!
2005-10-19 23:33:29.902 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] HttpConnection::onReadEx(), state: 5!
2005-10-19 23:33:29.902 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] HttpIOLink::suspendRead()...
2005-10-19 23:33:30.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] peer connection close detected!
2005-10-19 23:33:30.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] HttpExtConnector::cleanUp() ...
2005-10-19 23:33:30.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] abort request...
2005-10-19 23:33:30.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] FcgiConnection::abort()
2005-10-19 23:33:30.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] read 0 bytes from Fast CGI.
2005-10-19 23:33:30.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] [ExtConn] close()
2005-10-19 23:33:30.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] [EXT] EndResponse( endCode=0, protocolStatus=0 )
2005-10-19 23:33:30.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] release ExtProcessor!
2005-10-19 23:33:30.016 [DEBUG] [UDS://tmp/lshttpd/php-fcgi-5.sock] add recycled connection to connection pool!
2005-10-19 23:33:30.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] HttpIOLink::continueWrite()...
2005-10-19 23:33:30.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] write resumed!
2005-10-19 23:33:30.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] release ExtProcessor!
2005-10-19 23:33:30.016 [DEBUG] [194.97.161.79:4016-0#phorumdev:fcgi] Close socket ...

And the stderr-log tells:

php (pre-forking): Resource temporarily unavailable

In many lines .

 

[mistwang]

OK, I knew what's wrong.
You need to increase server wide Process soft/hard limit under "server"->"Security"->"CGI Resource Contorl" or per external application level settings added in 2.1.3 .
Process limit was not enforced for FCGI and LSAPI application in earlier releases.

 

[ts77]

Yes, works now, thx.

Don't you think that this should be more widely spread if you change that major stuff in a minor release?

I guess thats what most of the bug-reports from above are running into too.

 

[mistwang]

Yes, you are right. probably should not do that.
Anyway, will release a new release to adjust the limit to a more propriate value for each external application automatically.