Apache exited on signal 11 (core dumped) when logrotate

Aknot

Aknot

Dear Forum!

Our Apache24 server is exiting on signal 11 (core dumped) when logrotate is run.

Messages tells us that:
Code: 
Feb 22 00:00:01 srv02 kernel: pid 92975 (httpd), uid 0: exited on signal 11 (core dumped)

When we add this to newsyslog.conf:
Code: 
/var/log/www.domain.yz-access.log       644  7     *    @T00  J      /var/run/httpd.pid 30
/var/log/www.domain.yz-error.log        644  7     *    @T00  J      /var/run/httpd.pid 30

When we run gdb on httpd.core, we see this:
Code: 
Loaded symbols for /libexec/ld-elf.so.1
#0  0x0000000000000000 in ?? ()
[New Thread 802806400 (LWP 100157/httpd)]

Code: 
root@srv02:/ # uname -a
FreeBSD srv02 10.0-RELEASE FreeBSD 10.0-RELEASE #0 r260789: Thu Jan 16 22:34:59 UTC 2014     root@snap.freebsd.org:/usr/obj/usr/src/sys/GENERIC  amd64

Code: 
root@srv02:/ # httpd -V
Server version: Apache/2.4.6 (FreeBSD)
Server built:   Feb 21 2014 07:38:15
Server's Module Magic Number: 20120211:23
Server loaded:  APR 1.4.8, APR-UTIL 1.5.3
Compiled using: APR 1.4.8, APR-UTIL 1.5.3
Architecture:   64-bit
Server MPM:     prefork
threaded:     no
forked:     yes (variable process count)
Server compiled with....
-D APR_HAS_SENDFILE
-D APR_HAS_MMAP
-D APR_USE_FLOCK_SERIALIZE
-D APR_USE_PTHREAD_SERIALIZE
-D SINGLE_LISTEN_UNSERIALIZED_ACCEPT
-D APR_HAS_OTHER_CHILD
-D AP_HAVE_RELIABLE_PIPED_LOGS
-D DYNAMIC_MODULE_LIMIT=256
-D HTTPD_ROOT="/usr/local"
-D SUEXEC_BIN="/usr/local/bin/suexec"
-D DEFAULT_PIDLOG="/var/run/httpd.pid"
-D DEFAULT_SCOREBOARD="logs/apache_runtime_status"
-D DEFAULT_ERRORLOG="logs/error_log"
-D AP_TYPES_CONFIG_FILE="etc/apache24/mime.types"
-D SERVER_CONFIG_FILE="etc/apache24/httpd.conf"

Code: 
root@srv02:/ # php -v
PHP 5.4.25 (cli) (built: Feb 20 2014 14:29:08)
Copyright (c) 1997-2014 The PHP Group
Zend Engine v2.4.0, Copyright (c) 1998-2014 Zend Technologies

One thing we know we have done, is changing the BDB-version, then we added this to make.conf and reinstalled apache:
Code: 
WITH_BDB_VER=6

Restarting like this is working just fine:
Code: 
root@srv02:/ # /usr/local/etc/rc.d/apache24 restart

Our skills is limited, please let us know if we can provide any other information
Anything else is working really fine :beergrin

Thanks in advance,
 
Does it also crash if you send the signal by hand? kill -30 `cat /var/run/httpd.pid`
 
The first time I installed apache (2.2.x not 2.4.x version) I run into this problem, there was something wrong about log rotation with newsyslog. I did search for a solution in Internet and found one, the magic is to send signal 30 at the last log.
Put all the logs in a block into newsyslog or in a separate file (see include in newsyslog.conf(5)), at last line send the signal 30.

Code: 
/var/log/1st.log       644  7     *    @T00  J
/var/log/2nd.log       644  7     *    @T00  J
/var/log/3rd.log       644  7     *    @T00  J
...
/var/log/last.log      644  7     *    @T00  J      /var/run/httpd.pid 30

It works for apache22, I tested apache24 for few months and used the same method for log files. I hope this help you.
 
freethread said:
...the magic is to send signal 30 at the last log...
Click to expand...

Thanks both of you for your answers.

I moved the two lines to the last in newsyslog.conf and then ran newsyslog -v -F and that seems to be working right now.
Final test tonight at 00:00.
 
Alldo said:
I moved the two lines to the last in newsyslog.conf and then ran newsyslog -v -F and that seems to be working right now.
Final test tonight at 00:00.
Click to expand...

Reviewing my example I found it not so clear (I have a lot of logs of any kind and a lot of apache logs), the right example is

Code: 
### Original newsyslog logs (set at FreeBSD installation time, usually I don't modify them)
/var/log/all.log			600  7	   *	@T00  J
/var/log/amd.log			644  7	   100	*     J
/var/log/auth.log			600  7     100  @0101T JC
...
/var/log/weekly.log			640  5	   *	$W6D0 JN
/var/log/xferlog			600  7	   100	*     JC

### Non Apache httpd logs
...

### Apache httpd logs
/var/log/apache_1st.log       644  7     *    @T00  J
/var/log/apache_2nd.log       644  7     *    @T00  J
/var/log/apache_3rd.log       644  7     *    @T00  J
...
/var/log/apache_last.log      644  7     *    @T00  J      /var/run/httpd.pid 30

### Non Apache httpd logs
...

It doesn't matter where apache logs are, if in the middle or at the end of the whole file. It matter only the last apache log entry has the signal. In other words, the signal is fired only one time when the logs was been rotated.
 
Experimentation with my apache httpd 2.4.6 seems to indicate that:
  • SIGHUP triggers a restart
  • SIGUSR1 triggers a graceful restart
From the apachectl manual page:
Code: 
       graceful
              Gracefully  restarts  the  Apache httpd daemon. If the daemon is
              not running, it is started. This differs from a  normal  restart
              in  that  currently  open  connections  are  not aborted. A side
              effect is that old log files will  not  be  closed  immediately.
              This  means that if used in a log rotation script, a substantial
              delay may be necessary to ensure that  the  old  log  files  are
              closed before processing them. This command automatically checks
              the configuration files as in configtest before  initiating  the
              restart  to  make sure Apache doesn't die. This is equivalent to
              apachectl -k graceful.
So maybe it is not the rotation of the logfiles that apache is having a problem with, but the fact that newsyslog compresses the old log file using bzip2 ('J' flag specified in newsyslog.conf) while apache is still using it?

The simple solution would probably be to send a SIGHUP instead, to make sure the logfile is really closed before being compressed or otherwise processed. But this also implicates, that any currently open connections are aborted when the SIGHUP is received. It's up to you to decide whether that is acceptable or not.
 
mickey said:
So maybe it is not the rotation of the logfiles that apache is having a problem with, but the fact that newsyslog compresses the old log file using bzip2 ('J' flag specified in newsyslog.conf) while apache is still using it?
Click to expand...
It's a good suggestion but somehow I doubt that. First of all I can't help think that if this was the case it would have surfaced sooner (but I agree that this holds a lot of assumptions too). However, I think the newsyslog(8) manualpage gives the full explanation:

Code: 
     When it is executed it archives log files if necessary.  If a log file is
     determined to require archiving, newsyslog rearranges the files so that
     ``logfile'' is empty, ``logfile.0'' has the last period's logs in it,
     ``logfile.1'' has the next to last period's logs in it, and so on, up to
     a user-specified number of archived logs.
Now, I agree that this is a bit vague; but the way I picked this up is that the initial logfile remains "as is" but is merely truncated (which won't cause any side effects); it's contents go straight into a copy and when required the copies will get compressed. So not the initial logfile.
 
ShelLuser said:
Code: 
     When it is executed it archives log files if necessary.  If a log file is
     determined to require archiving, newsyslog rearranges the files so that
     ``logfile'' is empty, ``logfile.0'' has the last period's logs in it,
     ``logfile.1'' has the next to last period's logs in it, and so on, up to
     a user-specified number of archived logs.
Now, I agree that this is a bit vague; but the way I picked this up is that the initial logfile remains "as is" but is merely truncated (which won't cause any side effects); it's contents go straight into a copy and when required the copies will get compressed. So not the initial logfile.
Click to expand...
I would rather tend to think it works the other way round: The last logfile number is deleted, then all preceding logfiles are renamed to (number+1), the initial logfile is renamed to logfile.0 and a new empty logfile without number is created from scratch (if the 'C' flag is specified) after which the process is signalled to re-open the logfile. This way the process can still write to the old logfile after it has been renamed cause the file decriptor will still reference that file. After signalling the process however, newsyslog has to assume that the process has now stopped accessing the old logfile, and compresses it.

I agree that this would probably have surfaced sooner, but it's worth a shot. Removing the 'J' flag from newsyslog.conf will leave the log rotation in place, just without compression. Should the problem then persist, the cause is located elsewhere.
 
I followed the steps from @freethread and everything seems to be working fine right now. We might need to test this further some time later, but right now we're gonna leave it as is. Thanks all for your input on this issue :i
 
Last edited by a moderator:
You must log in or register to reply here.
Back
Top