| Author |
|
djc
Joined: 04 Dec 2007
Posts: 37
|
 Posted: Thu 19 Feb '09 22:23 Post subject: Apache hangs - gives http 500 messages |
 |
|
Hello all,
An odd problem developed for me this week. So far, twice this week my Apache has 'hung' per se, stuck doing something at 3.30am, loading up a bunch of busyworkers and starts issuing http 500 error messages to anyone attempting to connect.
As you can see in the day graph, it seems to build on itself until it reaches some type of limit (memory perhaps). Apache error log only shows PHP stating max execution time exceeded, which is a result of the problem, not really helping discern what the problem is.
The automated mysql backup of some forums kicks off around that time, however the MS event view shows no anomaly, short of only one of them actually started (there are two backup batch files).
Ideas? I can't rdesktop into the server when this happens and I have to call the host for a reboot (although I can ping and ftp into it). I can set up a scheduled stop and restart of Apache services in the morning to remediate the downtime, however would obviously prefer to determine the root cause. Any suggestions? Did I overlook anything?
Thanks
day
week |
|
| Back to top |
|
James Blond
Moderator
Joined: 19 Jan 2006
Posts: 7371
Location: Germany, Next to Hamburg
|
| Posted: Wed 04 Mar '09 23:34 Post subject: |
|
|
| Do you run php as module or over fcgid? Anything in your errorl.log about that? Have you enabled php error log? |
|
| Back to top |
|
djc
Joined: 04 Dec 2007
Posts: 37
|
| Posted: Sun 08 Mar '09 9:42 Post subject: |
|
|
Hi James,
It is running as s module.
Nothing in the Apache error.log, except 'Max execution time of 30 seconds has exceeded...'
I have this for error reporting set:
error_reporting = E_COMPILE_ERROR|E_RECOVERABLE_ERROR|E_ERROR|E_CORE_ERROR
I just changed it to:
error_reporting = E_ALL |
|
| Back to top |
|
James Blond
Moderator
Joined: 19 Jan 2006
Posts: 7371
Location: Germany, Next to Hamburg
|
| Posted: Wed 11 Mar '09 0:40 Post subject: |
|
|
is it only one script or several script which crashes? Are at that time many requests?
If PHP runs out of memory you should try PHP over FCGID for me it helped a lot. |
|
| Back to top |
|
djc
Joined: 04 Dec 2007
Posts: 37
|
| Posted: Sun 03 May '09 3:23 Post subject: |
|
|
The server is hosting multiple sites. It happened again the other nite.. Apache spawned 240 busyworkers total and it has the same step-climb as before. It appears it is spawning workers and not releasing them. Once again, the CPU was at 100% utilization when I remoted in. Unfortunately, I didn't get to the server for hours so the sites were down for almost 10 hours.
What seems to be weird is that this tends to happen early.. around 4.30am. There are no scheduled tasks that run at this time. The problem seemed to persist after a reboot until I manually ended the 100% CPU httpd.exe tasks.
error logs show nothing out of the ordinary.
I am baffled. |
|
| Back to top |
|
Steffen
Moderator
Joined: 15 Oct 2005
Posts: 3092
Location: Hilversum, NL, EU
|
| Posted: Sun 03 May '09 13:11 Post subject: |
|
|
James already asked you: Are at that time many requests?
Do you see in the access.log lot's of traffic ?
And what Janes said, php with mod_fcgid is preferable.
Steffen |
|
| Back to top |
|
djc
Joined: 04 Dec 2007
Posts: 37
|
| Posted: Mon 04 May '09 9:15 Post subject: |
|
|
I checked all the logs and even used a log analyzer and nothing out of the ordinary appears. There is traffic, but nothing more than 2am or 3am etc.
it appears there was a spider on one of the sites and for an unknown reason, the .htaccess was missing from the home folder and thus there were a lot of broken links which populated the error log. that was the last thing in the error log before I restarted.
[Fri May 01 14:46:49 2009] [notice] Parent: Received restart signal -- Restarting the server.
[Fri May 01 14:46:49 2009] [notice] Child 1616: Exit event signaled. Child process is ending.
[Fri May 01 14:46:50 2009] [notice] Apache/2.2.8 (Win32) configured -- resuming normal operations
[Fri May 01 14:46:50 2009] [notice] Server built: Mar 8 2008 14:15:40
[Fri May 01 14:46:50 2009] [notice] Parent: Created child process 3964
[Fri May 01 14:46:50 2009] [notice] Disabled use of AcceptEx() WinSock2 API
[Fri May 01 14:46:50 2009] [notice] Child 1616: Released the start mutex
[Fri May 01 14:46:50 2009] [notice] Child 3964: Child process is running
[Fri May 01 14:46:50 2009] [notice] Child 3964: Acquired the start mutex.
[Fri May 01 14:46:50 2009] [notice] Child 3964: Starting 250 worker threads.
[Fri May 01 14:47:23 2009] [notice] Child 1616: Waiting 270 more seconds for 250 worker threads to finish.
[Fri May 01 14:47:56 2009] [notice] Child 1616: Waiting 240 more seconds for 250 worker threads to finish.
[Fri May 01 14:48:28 2009] [notice] Child 1616: Waiting 210 more seconds for 250 worker threads to finish.
[Fri May 01 14:49:01 2009] [notice] Child 1616: Waiting 180 more seconds for 250 worker threads to finish.
[Fri May 01 14:49:34 2009] [notice] Child 1616: Waiting 150 more seconds for 250 worker threads to finish.
[Fri May 01 14:50:07 2009] [notice] Child 1616: Waiting 120 more seconds for 250 worker threads to finish.
[Fri May 01 14:50:40 2009] [notice] Child 1616: Waiting 90 more seconds for 250 worker threads to finish.
[Fri May 01 14:51:12 2009] [notice] Child 1616: Waiting 60 more seconds for 250 worker threads to finish.
[Fri May 01 14:52:24 2009] [warn] pid file D:/Logs/httpd.pid overwritten -- Unclean shutdown of previous Apache run?
[Fri May 01 14:52:24 2009] [notice] Apache/2.2.8 (Win32) configured -- resuming normal operations
[Fri May 01 14:52:24 2009] [notice] Server built: Mar 8 2008 14:15:40
[Fri May 01 14:52:24 2009] [notice] Parent: Created child process 1600
[Fri May 01 14:52:25 2009] [notice] Disabled use of AcceptEx() WinSock2 API
[Fri May 01 14:52:25 2009] [notice] Child 1600: Child process is running
[Fri May 01 14:52:25 2009] [notice] Child 1600: Acquired the start mutex.
[Fri May 01 14:52:25 2009] [notice] Child 1600: Starting 250 worker threads.
[Fri May 01 14:52:25 2009] [notice] Child 1600: Listening on port 80.
after that, i got a lot of these for all the sites on the box:
PHP Fatal error: Maximum execution time of 30 seconds exceeded ...
Could that, coupled with a 15 second KeepAliveTimeout be the culprit? I lowered that to 5 afterwards.
I will have to read up on this mod_fcgid and implement as you two suggested. |
|
| Back to top |
|
James Blond
Moderator
Joined: 19 Jan 2006
Posts: 7371
Location: Germany, Next to Hamburg
|
| Posted: Mon 04 May '09 9:46 Post subject: |
|
|
| djc wrote: | | PHP Fatal error: Maximum execution time of 30 seconds exceeded ... |
means that your script is to slow. Often a slow connection to the mysql server is the factor. |
|
| Back to top |
|
djc
Joined: 04 Dec 2007
Posts: 37
|
| Posted: Mon 04 May '09 10:51 Post subject: |
|
|
those errors are a result of the CPU being pegged at 100%. The script can't process in the allocated time due to lack of CPU time.
On to mod_fcgid
I have some very novice questions.
Currently I load php by:
LoadModule php5_module c:/php/php5apache2_2.dll
in my httpd.conf. I assume this will need to be commented out?
second, it appears I have to add some info to the conf file. I tried outside of a virtualhost but it didn't work, so I assume it needs to be added to each virtualhost.
Here is a virtualhost from my configuation:
| Code: | <VirtualHost *:80>
ServerName www.example.com
ServerAlias example.com *.example.com
DocumentRoot d:/htdocs/example
Options +FollowSymLinks
RewriteEngine On
RewriteCond %{HTTP_HOST} ^example.com
RewriteRule (.*) http://www.example.com$1 [R=301,L]
DirectoryIndex index.html index.php
LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"" combined
LogFormat "%h %l %u %t \"%r\" %>s %b" common
LogFormat "%{Referer}i -> %U" referer
LogFormat "%{User-agent}i" agent
<Directory "D:/htdocs/example">
Options Indexes
Order allow,deny
Allow from all
</Directory>
<IfModule log_config_module>
<IfModule log_rotate_module>
RotateLogs On
RotateLogsLocalTime On
RotateInterval 86400
CustomLog "d:/logs/example/access.%Y%m%d.log" combined
</IfModule>
</IfModule>
#Customlog "|c:/apache2/bin/rotatelogs.exe c:/apache2/logs/example/access_log 86400" combined
</VirtualHost> |
from another post of James', I see this as a suggestion:
| Code: | LoadModule fcgid_module modules/mod_fcgid.so
<IfModule mod_fcgid.c>
IPCCommTimeout 40
IPCConnectTimeout 10
MaxProcessCount 8
OutputBufferSize 64
ProcessLifeTime 240
MaxRequestsPerProcess 500
SetEnv PHPRC "C:/php"
DefaultInitEnv TEMP "c:/tmp"
DefaultMinClassProcessCount 0
Alias /fcgi/ "c:/fcgi/"
<Directory c:/fcgi>
AddHandler fcgid-script .php
Options Indexes FollowSymLinks ExecCGI
FCGIWrapper "c:/php5/php-cgi.exe" .php
AllowOverride all
Order allow,deny
Allow from all
Satisfy any
</Directory>
</IfModule> |
Since I lack a detailed understanding of fcgi, how would the above be integrated properly into my virtualhost? Should some be in the main conf file and some under each virtualhost? |
|
| Back to top |
|
James Blond
Moderator
Joined: 19 Jan 2006
Posts: 7371
Location: Germany, Next to Hamburg
|
| Posted: Mon 04 May '09 17:21 Post subject: |
|
|
Hi!
You can run both. PHP as module and in some vhosts over fcgid.
For the vhosts with PHP as module don't need to change anything
here an short example
| Code: |
PHPIniDir "c:/server2/php"
LoadModule php5_module "c:/server2/php/php5apache2_2.dll"
AddType application/x-httpd-php .php .php5
AddType application/x-httpd-php-source .phps
LoadModule fcgid_module modules/mod_fcgid.so
<IfModule mod_fcgid.c>
IPCCommTimeout 40
IPCConnectTimeout 10
MaxProcessCount 8
OutputBufferSize 64
ProcessLifeTime 60
MaxRequestsPerProcess 500
DefaultMinClassProcessCount 0
SetEnv PHPRC "c:/server2/php"
PHP_Fix_Pathinfo_Enable 1
</IfModule>
NameVirtualHost *:80
<VirtualHost *:80>
DocumentRoot c:/server2/www_fcgi
ServerName fcgi.local
ErrorLog c:/server2/logs/fcgi.error.log
CustomLog c:/server2/logs/fcgi.access.log common
<Directory "c:/server2/www_fcgi">
AddHandler fcgid-script .php
Options Indexes FollowSymLinks ExecCGI
FCGIWrapper "c:/server2/php/php-cgi.exe" .php
AllowOverride All
Order allow,deny
Allow from all
</Directory>
</VirtualHost>
<VirtualHost *:80>
DocumentRoot c:/server2/www_module
ServerName module.local
ErrorLog c:/server2/logs/module.error.log
CustomLog c:/server2/logs/module.access.log common
<Directory "c:/server2/www_module">
Options Indexes FollowSymLinks
AllowOverride All
Order allow,deny
Allow from all
</Directory>
</VirtualHost>
|
if you have any question. Please ask again! |
|
| Back to top |
|
djc
Joined: 04 Dec 2007
Posts: 37
|
| Posted: Sun 10 May '09 0:55 Post subject: |
|
|
Thanks James. I will play around with the fcgi this weekend.
However, I think I found would could be the problem! You guys were right when you kept going back to asking about activity (although the Apache logs weren't revealing much). I was looking at my bandwidth logs for the server and there are some significant spikes in usage on certain days... the same days Apache would have hundreds of busyworkers. I think I am getting hit by an over-aggressive bot. I set up a robots.txt file and implemented a delay of 10 seconds to see if that helps, but I wanted to ask:
What is the best way to configure Apache to survive an over-aggressive bot? I lowered the busyworkers to 100, however that didn't solve the problem 100%. It kept the server from achieving 100% CPU utilization (which would make me unable to RDP into the box to reset Apache), but Apache was flat-lined at 100 busyworkers for hours.
I also lowered the Keepalive from 15 to 5.
 |
|
| Back to top |
|
djc
Joined: 04 Dec 2007
Posts: 37
|
| Posted: Sun 10 May '09 12:07 Post subject: |
|
|
| on a sidenote, I did get fcgi working, however oddly, xcache was not caching the site I configured to use fcgi. I did read that I should expect more cache to be used with fast cgi, but the site was significantly slower under fcgi without xcache doing its thing... Any ideas why? |
|
| Back to top |
|
James Blond
Moderator
Joined: 19 Jan 2006
Posts: 7371
Location: Germany, Next to Hamburg
|
| Posted: Sun 10 May '09 19:25 Post subject: |
|
|
| djc wrote: | | however oddly, xcache was not caching the site I configured to use fcgi. |
Did you configure SetEnv PHPRC "c:/server2/php"? If you use phpfinfo(); is the xcache extension loaded in the fcgid vhost? |
|
| Back to top |
|
djc
Joined: 04 Dec 2007
Posts: 37
|
| Posted: Sun 10 May '09 23:27 Post subject: |
|
|
| Yes, it is set to c:/php which is where my PHP files and .ini are located. |
|
| Back to top |
|
James Blond
Moderator
Joined: 19 Jan 2006
Posts: 7371
Location: Germany, Next to Hamburg
|
| Posted: Mon 11 May '09 10:00 Post subject: |
|
|
| James Blond wrote: | | If you use phpfinfo(); is the xcache extension loaded in the fcgid vhost? |
Do you see xcache?
For debugging in php.ini
display_errors = On
display_startup_errors = On
log_errors = On
error_log = C:\php\phperror.log |
|
| Back to top |
|
djc
Joined: 04 Dec 2007
Posts: 37
|
| Posted: Sat 16 May '09 5:55 Post subject: |
|
|
Thanks James, Will try that.
So the mysterious occurrence happened again this morning.
Here some MRTG output:
Busyworkers:
Accesses:
Traffic:
MySQL:
I would surmise that the problem is internal as the traffic and accesses are low, but I defer to you all, the experts.
Anyone recommend a good log analyzer? The access logs are divided up by site and aren't easy to read through to see what may be happening. MRTG went nuts with a bunch of stuff in the Windows app log, but I think it is due to Apache not responding... or could MRTG be the problem? |
|
| Back to top |
|
djc
Joined: 04 Dec 2007
Posts: 37
|
| Posted: Sat 16 May '09 10:56 Post subject: |
|
|
| James Blond wrote: |
Do you see xcache?
|
yes, i even copied phpinfo.php into that vhosts dir and opened it via the browser. says xcache is loaded (in general, don't see any vhost info in phpinfo.php), but xcache admin screen shows no items cached from that site.
weird |
|
| Back to top |
|
glsmith
Moderator
Joined: 16 Oct 2007
Posts: 2268
Location: Sun Diego, USA
|
| Posted: Sat 16 May '09 18:13 Post subject: |
|
|
| djc wrote: | | ... or could MRTG be the problem? |
Only one way to find out .. drop MRTG for a couple days. |
|
| Back to top |
|
djc
Joined: 04 Dec 2007
Posts: 37
|
| Posted: Sat 16 May '09 23:16 Post subject: |
|
|
| glsmith wrote: | | djc wrote: | | ... or could MRTG be the problem? |
Only one way to find out .. drop MRTG for a couple days. |
Trouble is, the box can work fine for weeks! |
|
| Back to top |
|
djc
Joined: 04 Dec 2007
Posts: 37
|
| Posted: Wed 20 May '09 6:35 Post subject: |
|
|
| I think it may be a rogue bot or some sort that isn't abiding to the robots.txt. I have disabled Keepalives for now to see how that works. |
|
| Back to top |
|
