httpd-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Wilfredo Sanchez <wsanc...@apple.com>
Subject Re: Bug with graceful restarts?
Date Fri, 29 Jan 1999 00:44:35 GMT
Marc Slemko:
| See if you can reproduce your problem without the piped error log. 
|
| I think there is a PR (from the last month or so...) in the bugdb about 
| piped ErrorLogs and graceful restarts.

Slightly off-topic, I noticed that in a while (1) loop, apachectl  
graceful, when it does crap out, spews an error from kill about  
usage. I had the script go verbose and the problem is that sometime  
$PID is "". Somehow when apache dies, the pid file is still there,  
but is empty? Anyway, this patch to apachectl got rid of that:

--- apachectl   Tue Jan 12 14:47:25 1999
+++ /usr/sbin/apachectl Thu Jan 28 16:12:33 1999
@@ -50,7 +50,7 @@
     # check for pidfile
     if [ -f $PIDFILE ] ; then
        PID=`cat $PIDFILE`
-       if kill -0 $PID; then
+       if [ ! "x$PID" = "x" ] && kill -0 $PID; then
            STATUS="httpd (pid $PID) running"
            RUNNING=1
        else

Back to the piped logs... after running this while loop a while, I  
noticed this:

[joliet-jake:Library/WebServer/Configuration] root# ps -x | grep apache
 1760 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
 3034 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
 3984 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
 4913 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
 5833 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
 6559 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
 7047 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
 7557 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
 8253 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
 9280 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
10314 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
11320 ?  I     0:00 /bin/sh -c rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
11321 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
11322 ?  I     0:00 /bin/sh -c rotatelogs  
/Local/Library/WebServer/Logs/apache_access_log 86400
11323 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_access_log 86400
24365 ?  S     0:10 /usr/sbin/apache
26082 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
26449 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
26495 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
27041 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
27136 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
27234 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
27340 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
27451 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
27559 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
27657 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
28074 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
28528 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
28642 ?  I     0:00 rotatelogs  
/Local/Library/WebServer/Logs/apache_error_log 86400
19854 p3 S     0:00 grep apache

If I stop apache, these all go away. So it looks like graceful  
restarts are leaking error log pipes rather readily. I don't get so  
many of these normally. Note that the access log (CustomLog  
directive) is also rotating, but not leaking rotatelogs processes.

Some output from the error log:

apache: [Thu Jan 28 16:26:18 1999] [notice] SIGUSR1 received.  Doing  
graceful restart
apache: [Thu Jan 28 16:26:23 1999] [notice] Apache/1.3.4 (Unix)  
configured -- resuming normal operations
apache: [Thu Jan 28 16:26:23 1999] [warn] long lost child came home!  
(pid 26353)
apache: [Thu Jan 28 16:26:24 1999] [notice] SIGUSR1 received.  Doing  
graceful restart
apache: [Thu Jan 28 16:26:27 1999] [crit] (48)Address already in  
use: make_sock: could not bind to port 80
apache: [Thu Jan 28 16:26:31 1999] [notice] Apache/1.3.4 (Unix)  
configured -- resuming normal operations
apache: [Thu Jan 28 16:26:31 1999] [warn] long lost child came home!  
(pid 26658)
apache: [Thu Jan 28 16:26:31 1999] [notice] SIGUSR1 received.  Doing  
graceful restart
apache: [Thu Jan 28 16:26:35 1999] [notice] Apache/1.3.4 (Unix)  
configured -- resuming normal operations
apache: [Thu Jan 28 16:26:35 1999] [warn] long lost child came home!  
(pid 27085)

Then I took out the piped logs and I still have some trouble with it  
dying. As before, apachectl sees it's gone and starts a new one. The  
error log here does not complain about the long lost child:

apache: [Thu Jan 28 16:31:23 1999] [notice] Apache/1.3.4 (Unix)  
configured -- resuming normal operations
apache: [Thu Jan 28 16:31:26 1999] [notice] SIGUSR1 received.  Doing  
graceful restart
apache: [Thu Jan 28 16:31:33 1999] [notice] Apache/1.3.4 (Unix)  
configured -- resuming normal operations
apache: [Thu Jan 28 16:31:33 1999] [notice] SIGUSR1 received.  Doing  
graceful restart
apache: [Thu Jan 28 16:31:41 1999] [notice] Apache/1.3.4 (Unix)  
configured -- resuming normal operations
apache: [Thu Jan 28 16:31:41 1999] [notice] SIGUSR1 received.  Doing  
graceful restart
apache: [Thu Jan 28 16:31:50 1999] [notice] Apache/1.3.4 (Unix)  
configured -- resuming normal operations
apache: [Thu Jan 28 16:31:50 1999] [crit] (48)Address already in  
use: make_sock: could not bind to port 80
apache: [Thu Jan 28 16:31:50 1999] [crit] (48)Address already in  
use: make_sock: could not bind to port 80
apache: [Thu Jan 28 16:31:50 1999] [crit] (48)Address already in  
use: make_sock: could not bind to port 80
apache: [Thu Jan 28 16:31:50 1999] [crit] (48)Address already in  
use: make_sock: could not bind to port 80
apache: [Thu Jan 28 16:31:51 1999] [notice] SIGUSR1 received.  Doing  
graceful restart
apache: [Thu Jan 28 16:31:52 1999] [crit] (48)Address already in  
use: make_sock: could not bind to port 80
apache: [Thu Jan 28 16:31:55 1999] [notice] Apache/1.3.4 (Unix)  
configured -- resuming normal operations
apache: [Thu Jan 28 16:31:57 1999] [notice] SIGUSR1 received.  Doing  
graceful restart
apache: [Thu Jan 28 16:32:06 1999] [notice] Apache/1.3.4 (Unix)  
configured -- resuming normal operations
apache: [Thu Jan 28 16:32:06 1999] [crit] (48)Address already in  
use: make_sock: could not bind to port 80
apache: [Thu Jan 28 16:32:06 1999] [notice] SIGUSR1 received.  Doing  
graceful restart
apache: [Thu Jan 28 16:32:15 1999] [notice] Apache/1.3.4 (Unix)  
configured -- resuming normal operations
apache: [Thu Jan 28 16:32:15 1999] [notice] SIGUSR1 received.  Doing  
graceful restart

I'm assuming the cannot bind errors are apachectl running too soon  
again after starting a new server, which hasn't gotten around to  
writing out a pid file yet.

	-Fred

Mime
View raw message