Apache 2.4.25 crashes at midnight

wattie

Verified User
Joined
May 31, 2008
Messages
1,234
Location
Bulgaria
Since the last few days my httpd always crashes at midnight. Here is what I get in the error log:

Code:
[Thu Jan 12 00:00:12.694422 2017] [lbmethod_heartbeat:notice] [pid 38405] AH02282: No slotmem from mod_heartmonitor
[Thu Jan 12 00:00:12.697241 2017] [core:emerg] [pid 38405] (17)File exists: AH00023: Couldn't create the watchdog-callback mutex (file /var/logs/watchdog-callback-_proxy_hcheck_.38405)
[Thu Jan 12 00:00:12.697287 2017] [:emerg] [pid 38405] AH00020: Configuration Failed, exiting

A simple start (/usr/local/etc/rc.d/httpd start) and it comes back up and running again. There doesn't seem to be any cron jobs that will make it fail at the exact hour. Here's my crontab:

Code:
SHELL=/bin/sh
PATH=/etc:/bin:/sbin:/usr/bin:/usr/sbin
#minute hour    mday    month   wday    who     command
*/5     *       *       *       *       root    /usr/libexec/atrun
# Save some entropy so that /dev/random can re-seed on boot.
*/11    *       *       *       *       operator /usr/libexec/save-entropy
# Rotate log files every hour, if necessary.
0       *       *       *       *       root    newsyslog
# Perform daily/weekly/monthly maintenance.
1       3       *       *       *       root    periodic daily
15      4       *       *       6       root    periodic weekly
30      5       1       *       *       root    periodic monthly
# Adjust the time zone if the CMOS clock keeps local time, as opposed to
# UTC time.  See adjkerntz(8) for details.
1,31    0-5     *       *       *       root    adjkerntz -a
* * * * * root /usr/local/directadmin/dataskq
2 0-23/6 * * * root echo 'action=vacation&value=all' >> /usr/local/directadmin/data/task.queue;
#5 0 * * * root /usr/sbin/quotaoff -a; /sbin/quotacheck -aug; /usr/sbin/quotaon -a;
30 0 * * * root echo 'action=tally&value=all' >> /usr/local/directadmin/data/task.queue
40 1 1 * * root echo 'action=reset&value=all' >> /usr/local/directadmin/data/task.queue
0 4 * * * root echo 'action=check&value=license' >> /usr/local/directadmin/data/task.queue

Any ideas?
 
Could be something with Apache 2.4.25 and the rest was it ok before update to Apache 2.4.25 ?

Then change if box is centos7 the default for httpd reload/gracefull restart to
https://www.directadmin.com/features.php?id=980 add graceful_restarts=0

Is timely workarround for how long a don't now also other scripts/crons are often doing only reloads the log rotate for example could do this also. ( so if logs full..... the sh..t is )


The reload one you have now is the basic default tally "cleanup" in DA i think see explanation here
http://forum.directadmin.com/showthread.php?t=54261&p=278190#post278190

http://forum.directadmin.com/showthread.php?t=54240

http://forum.directadmin.com/showthread.php?t=54170

If your BOX has HTTP2 then probably this is causing it in combi with the apache 2.4.25 bugs

You should probably see in log something like this wen it is reload
2016:12:22-00:34:56: Tally All Complete
2016:12:22-00:35:05: httpd reloaded
 
Last edited:
It was fine with 2.4.23.

I am not using the graceful restarts feature, nor I am using http2...
 
It was fine with 2.4.23.

I am not using the graceful restarts feature, nor I am using http2...

You should to have a workarround for the time being ( if it is a apache 2.4.25 bug ) use the restart option in directadmin.conf
you have to add this rule default is with centos7 that reload ( default situation is namly gracefull restarts is 1 so yes it does do only reloads).
So ad the rule to forge to do restarts. instead of reload wich is default.

Switch back to version 2.4.23 and wait if version 2.4.26 solves is also possible.
http://forum.directadmin.com/showthread.php?t=52590&page=3

Maybe a support ticket at DA SUPPORT also could help?
 
I reverted back to 2.4.23. I will post if this midnight it will crash again.
 
I started to experience it again on a brand new server with FreeBSD 11. It was working fine for few weeks and suddenly started yesterday. What a mistery.
 
It's definitely something with newsyslog daily log rotation. The issue happens when I run this command:

Code:
newsyslog -v -F

Apache falls down after :(
 
Last edited:
Confirmed - it's newsyslog!

As soon as I run it:

Code:
root@srv2:/etc # newsyslog -v -F
Processing /etc/newsyslog.conf
Found: <include> /etc/newsyslog.conf.d/*
Found: <include> /usr/local/etc/newsyslog.conf.d/*
/var/log/all.log <7J>: does not exist, skipped.
/var/log/amd.log <7J>: does not exist, skipped.
/var/log/auth.log <7J>: size (Kb): 33 [100] --> trimming log....
/var/log/console.log <5J>: does not exist, skipped.
/var/log/cron <3J>: size (Kb): 6 [100] --> trimming log....
/var/log/daily.log <7J>: does not exist, skipped.
/var/log/debug.log <7J>: size (Kb): 27 [100] --> trimming log....
/var/log/init.log <3J>: does not exist, skipped.
/var/log/kerberos.log <7J>: does not exist, skipped.
/var/log/lpd-errs <7J>: size (Kb): 1 [100] --> trimming log....
/var/log/maillog <7J>: --> trimming log....
/var/log/messages <5J>: size (Kb): 11 [100] --> trimming log....
/var/log/monthly.log <12J>: does not exist, skipped.
/var/log/pflog <3J>: does not exist, skipped.
/var/log/ppp.log <3J>: size (Kb): 1 [100] --> trimming log....
/var/log/devd.log <3J>: size (Kb): 1 [100] --> trimming log....
/var/log/security <10J>: size (Kb): 56 [100] --> trimming log....
/var/log/sendmail.st <10>:  age (hr): 1 [168] --> trimming log....
/var/log/utx.log <3>: --> trimming log....
/var/log/weekly.log <5J>: does not exist, skipped.
/var/log/xferlog <7J>: size (Kb): 1 [100] --> trimming log....
/var/log/chrootshell.log <4>: does not exist, skipped.
/var/log/proftpd/auth.log <4>: --> trimming log....
/var/log/proftpd/xferlog.legacy <4>: --> trimming log....
/var/log/proftpd/access.log <4>: --> trimming log....
/var/log/pureftp.log <4>: does not exist, skipped.
/var/log/httpd/access_log <4>: --> trimming log....
/var/log/httpd/fpexe_log <4>: does not exist, skipped.
/var/log/httpd/suexec_log <4>: does not exist, skipped.
/var/log/httpd/error_log <4>: --> trimming log....
/var/log/suphp.log <4>: --> trimming log....
/var/log/exim/paniclog <4>: --> trimming log....
/var/log/exim/exim_paniclog <4>: does not exist, skipped.
/var/log/exim/rejectlog <4>: --> trimming log....
/var/log/exim/exim_rejectlog <4>: does not exist, skipped.
/var/log/exim/processlog <4>: does not exist, skipped.
/var/log/exim/exim_processlog <4>: does not exist, skipped.
/var/log/exim/mainlog <4>: --> trimming log....
/var/log/exim/exim_mainlog <4>: does not exist, skipped.
/var/log/directadmin/error.log <4>: --> trimming log....
/var/log/directadmin/errortaskq.log <4>: --> trimming log....
/var/log/directadmin/security.log <4>: --> trimming log....
/var/log/directadmin/system.log <4>: --> trimming log....
/var/log/directadmin/login.log <4>: --> trimming log....
/usr/local/php53/var/log/php-fpm.log <4>: does not exist, skipped.
/usr/local/php54/var/log/php-fpm.log <4>: does not exist, skipped.
/usr/local/php60/var/log/php-fpm.log <4>: does not exist, skipped.
/var/www/html/roundcube/logs/errors <4>: --> trimming log....
/var/www/html/squirrelmail/data/squirrelmail_access_log <4>: --> trimming log....
/var/www/html/phpMyAdmin/log/auth.log <4>: --> trimming log....
/var/log/dovecot-lmtp-errors.log <4>: --> trimming log....
/var/log/dovecot-lmtp.log <4>: --> trimming log....
Signal all daemon process(es)...
Notified daemon pid 631 = /var/run/syslog.pid
Pause 1 second(s) between signals
Notified daemon pid 77671 = /var/run/proftpd/proftpd.pid
Pause 1 second(s) between signals
Notified daemon pid 79512 = /var/run/httpd.pid
Pause 1 second(s) between signals
Notified daemon pid 69509 = /var/run/exim.pid
Pause 10 seconds to allow daemon(s) to close log file(s)
Compress all rotated log file(s)...
root@srv2:/etc #

now httpd is down!

Error log from apache:

Code:
eb 24 01:33:30 srv2 newsyslog[90129]: logfile turned over due to -F request
[Fri Feb 24 01:33:32.810266 2017] [auth_digest:notice] [pid 79512:tid 34408062976] AH01757: generating secret for digest authentication ...
[Fri Feb 24 01:33:33.234314 2017] [ssl:warn] [pid 79512:tid 34408062976] AH01909: shared.domain:443:0 server certificate does NOT include an ID which matches the server name
[Fri Feb 24 01:33:33.235466 2017] [ssl:warn] [pid 79512:tid 34408062976] AH01909: shared.domain:443:0 server certificate does NOT include an ID which matches the server name
[Fri Feb 24 01:33:33.236584 2017] [ssl:warn] [pid 79512:tid 34408062976] AH01909: shared.domain:443:0 server certificate does NOT include an ID which matches the server name
[Fri Feb 24 01:33:33.237709 2017] [ssl:warn] [pid 79512:tid 34408062976] AH01909: www.example.com:443:0 server certificate does NOT include an ID which matches the server name
[Fri Feb 24 01:33:33.238011 2017] [lbmethod_heartbeat:notice] [pid 79512:tid 34408062976] AH02282: No slotmem from mod_heartmonitor
[Fri Feb 24 01:33:33.239545 2017] [core:emerg] [pid 79512:tid 34408062976] (17)File exists: AH00023: Couldn't create the watchdog-callback mutex (file /var/logs/watchdog-callback-_proxy_hcheck_.79512)
[Fri Feb 24 01:33:33.239565 2017] [:emerg] [pid 79512:tid 34408062976] AH00020: Configuration Failed, exiting

I can then start it and it will work normally.
 
Last edited:
... and it looks like it happens only with graceful apache restarts. I got apache down after making a graceful restart manually. I was not able to reproduce on several normal restarts.
 
I suspect that it could be related to a recent update I made with freebsd-update. It upgraded openssl from 1.0.2f to 1.0.2k.

I rebuilt apache and php but no luck in fixing the issue. Now I am rebuilding all ports... It will take some time.
 
I suspect that it could be related to a recent update I made with freebsd-update. It upgraded openssl from 1.0.2f to 1.0.2k.

I rebuilt apache and php but no luck in fixing the issue. Now I am rebuilding all ports... It will take some time.

The basic prob(s) if using http2 is in the Apache 2.4.25 Update as you can get/read out of the fixes for version 2.4.26 in the links.
 
I'm also experiencing this problem with FreeBSD 10.3 and Apache 2.4.25. I was at 2.4.23 and everything was perfectly fine. Upgrade Apache and now I have serious problems.

Code:
newsyslog -v -F

That also crashed my Apache.

Something is seriously wrong. Been spending days trying to fix it too.

I get almost exactly this guys problem:
http://apache-http-server.18135.x6....aults-with-v2-4-23-and-2-24-25-td5034024.html

So I know it's not my setup, there is a bug.
 
Last edited:
Hi labrocca - I am not sure to be happy that I am not alone or not.

So far I found out that the bug occurs only on graceful apache restarts. You can test it that way:

1. If you run:

Code:
/usr/local/etc/rc.d/httpd graceful

most probably apache will (most probably) go down.

2. If you run:

Code:
/usr/local/etc/rc.d/httpd restart

it will not go down.

Obviously newsyslog is doing a graceful restart after rotating the logs.

I don't want to stop the 0 o'clock DA tally which runs newsyslog. So my (ugly) fix is a cron job which is doing httpd restart at 00:01. That way the server is down only like 30-40 seconds. Not good of course but that's the reality until we find a solution.

The odd thing is that it was not happening at the beginning. I am with a clean installation now. Something happened recently and I don't know what. I was thinking that it may be a recent openssl update...

Did you do freebsd-update recently too?
 
I didn't do a freebsd-update but I did do some openssl changes.

Here is example of my error_log which used to be empty but as of the now...


Code:
Feb 26 00:00:00 ns1 newsyslog[72918]: logfile turned over
[Sun Feb 26 00:00:14.131810 2017] [auth_digest:notice] [pid 39148:tid 34410095616] AH01757: generating secret for digest authentication ...
[Sun Feb 26 00:00:15.003444 2017] [lbmethod_heartbeat:notice] [pid 39148:tid 34410095616] AH02282: No slotmem from mod_heartmonitor
[Sun Feb 26 00:00:15.003580 2017] [core:emerg] [pid 39148:tid 34410095616] (17)File exists: AH00023: Couldn't create the watchdog-callback m
utex (file /var/logs/watchdog-callback-_proxy_hcheck_.39148)
[Sun Feb 26 00:00:15.003600 2017] [:emerg] [pid 39148:tid 34410095616] AH00020: Configuration Failed, exiting
[Sun Feb 26 00:31:01.054612 2017] [suexec:notice] [pid 74818:tid 34410095616] AH01232: suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Sun Feb 26 00:31:01.072222 2017] [auth_digest:notice] [pid 74869:tid 34410095616] AH01757: generating secret for digest authentication ...
[Sun Feb 26 00:31:02.060707 2017] [lbmethod_heartbeat:notice] [pid 74869:tid 34410095616] AH02282: No slotmem from mod_heartmonitor
[Sun Feb 26 00:31:02.060892 2017] [core:warn] [pid 74869:tid 34410095616] AH00098: pid file /var/run/httpd.pid overwritten -- Unclean shutdo
wn of previous Apache run?
[Sun Feb 26 00:31:02.063653 2017] [mpm_event:notice] [pid 74869:tid 34410095616] AH00489: Apache/2.4.23 (Unix) OpenSSL/1.0.1s-freebsd config
ured -- resuming normal operations
[Sun Feb 26 00:31:02.063687 2017] [core:notice] [pid 74869:tid 34410095616] AH00094: Command line: '/usr/sbin/httpd'
[Sun Feb 26 05:55:12.362644 2017] [mpm_event:notice] [pid 74869:tid 34410095616] AH00493: SIGUSR1 received.  Doing graceful restart
[Sun Feb 26 05:55:12.395320 2017] [auth_digest:notice] [pid 74869:tid 34410095616] AH01757: generating secret for digest authentication ...
[Sun Feb 26 05:55:13.041025 2017] [lbmethod_heartbeat:notice] [pid 74869:tid 34410095616] AH02282: No slotmem from mod_heartmonitor
[Sun Feb 26 05:55:13.041166 2017] [core:emerg] [pid 74869:tid 34410095616] (17)File exists: AH00023: Couldn't create the watchdog-callback m
utex (file /var/logs/watchdog-callback-_proxy_hcheck_.74869)
[Sun Feb 26 05:55:13.041194 2017] [:emerg] [pid 74869:tid 34410095616] AH00020: Configuration Failed, exiting
[Sun Feb 26 05:55:58.010829 2017] [suexec:notice] [pid 96015:tid 34410095616] AH01232: suEXEC mechanism enabled (wrapper: /usr/sbin/suexec)
[Sun Feb 26 05:55:58.027606 2017] [auth_digest:notice] [pid 96017:tid 34410095616] AH01757: generating secret for digest authentication ...
[Sun Feb 26 05:55:59.024970 2017] [lbmethod_heartbeat:notice] [pid 96017:tid 34410095616] AH02282: No slotmem from mod_heartmonitor
[Sun Feb 26 05:55:59.025150 2017] [core:warn] [pid 96017:tid 34410095616] AH00098: pid file /var/run/httpd.pid overwritten -- Unclean shutdo
wn of previous Apache run?
[Sun Feb 26 05:55:59.027935 2017] [mpm_event:notice] [pid 96017:tid 34410095616] AH00489: Apache/2.4.23 (Unix) OpenSSL/1.0.1s-freebsd config
ured -- resuming normal operations
[Sun Feb 26 05:55:59.027972 2017] [core:notice] [pid 96017:tid 34410095616] AH00094: Command line: '/usr/sbin/httpd -D SSL'
~
 
Back
Top