Arch Linux

logrotate should send USR1 instead of HUP, but I guess the result is the same.

I tried to send SIGHUP to the apache process

kill -HUP `cat /run/httpd/httpd.pid`

and it does not hang the process. Apache service still works fine for me. I tried it with Apache service and running Apache in a separate terminal like you do. I do not see the issue.

Here is output from error_log:

[Wed Nov 18 10:19:04.905767 2015] [mpm_event:notice] [pid 41055:tid 139777583294336] AH00493: SIGUSR1 received. Doing graceful restart
AH00558: httpd: Could not reliably determine the server's fully qualified domain name, using 192.168.31.128. Set the 'ServerName' directive globally to suppress this message
[Wed Nov 18 10:19:04.913397 2015] [http2:warn] [pid 41055:tid 139777583294336] AH02951: mod_ssl does not seem to be enabled
[Wed Nov 18 10:19:04.913450 2015] [lbmethod_heartbeat:notice] [pid 41055:tid 139777583294336] AH02282: No slotmem from mod_heartmonitor
[Wed Nov 18 10:19:04.913497 2015] [mpm_event:notice] [pid 41055:tid 139777583294336] AH00489: Apache/2.4.17 (Unix) configured -- resuming normal operations
[Wed Nov 18 10:19:04.913504 2015] [core:notice] [pid 41055:tid 139777583294336] AH00094: Command line: '/usr/bin/httpd -D FOREGROUND'
[Wed Nov 18 10:19:35.458679 2015] [mpm_event:notice] [pid 41055:tid 139777583294336] AH00494: SIGHUP received. Attempting to restart
AH00558: httpd: Could not reliably determine the server's fully qualified domain name, using 192.168.31.128. Set the 'ServerName' directive globally to suppress this message
[Wed Nov 18 10:19:35.467092 2015] [http2:warn] [pid 41055:tid 139777583294336] AH02951: mod_ssl does not seem to be enabled
[Wed Nov 18 10:19:35.467183 2015] [lbmethod_heartbeat:notice] [pid 41055:tid 139777583294336] AH02282: No slotmem from mod_heartmonitor
[Wed Nov 18 10:19:35.469366 2015] [mpm_event:notice] [pid 41055:tid 139777583294336] AH00489: Apache/2.4.17 (Unix) configured -- resuming normal operations
[Wed Nov 18 10:19:35.469413 2015] [core:notice] [pid 41055:tid 139777583294336] AH00094: Command line: '/usr/bin/httpd -D FOREGROUND'
[Wed Nov 18 10:19:43.634707 2015] [mpm_event:notice] [pid 41055:tid 139777583294336] AH00494: SIGHUP received. Attempting to restart
AH00558: httpd: Could not reliably determine the server's fully qualified domain name, using 192.168.31.128. Set the 'ServerName' directive globally to suppress this message
[Wed Nov 18 10:19:43.641948 2015] [http2:warn] [pid 41055:tid 139777583294336] AH02951: mod_ssl does not seem to be enabled
[Wed Nov 18 10:19:43.642007 2015] [lbmethod_heartbeat:notice] [pid 41055:tid 139777583294336] AH02282: No slotmem from mod_heartmonitor
[Wed Nov 18 10:19:43.643276 2015] [mpm_event:notice] [pid 41055:tid 139777583294336] AH00489: Apache/2.4.17 (Unix) configured -- resuming normal operations
[Wed Nov 18 10:19:43.643315 2015] [core:notice] [pid 41055:tid 139777583294336] AH00094: Command line: '/usr/bin/httpd -D FOREGROUND'

Also check if adding following line to the service fixes the problem for you

ExecReload=/usr/bin/httpd -k graceful

On my machines apachectl exits by SIGHUP and systemctl shows:

# systemctl status httpd
● httpd.service - Apache Web Server
Loaded: loaded (/usr/lib/systemd/system/httpd.service; enabled; vendor preset: disabled)
Drop-In: /etc/systemd/system/httpd.service.d
└─override.conf
Active: activating (auto-restart) since Wed 2015-11-18 21:46:52 MSK; 946ms ago
Process: 26858 ExecStop=/usr/bin/apachectl graceful-stop (code=exited, status=0/SUCCESS)
Process: 26818 ExecStart=/usr/bin/apachectl start -DFOREGROUND (code=killed, signal=HUP)
Main PID: 26818 (code=killed, signal=HUP)

because of Type=simple

my override.conf contains workaround

[Service]
Restart=always
RestartSec=10

"ExecReload=/usr/bin/httpd -k graceful" also does not fix it, not sure how it can be related to SIGHUP.

Following workaround fixes issue because of it does not use apachectl which exits for unknown reason on SIGHUP:

override.conf
[Service]
Restart=always
RestartSec=10
ExecReload=/usr/bin/httpd -k graceful
ExecStart=
ExecStart=/usr/bin/httpd -k start -DFOREGROUND

What is 'systemctl status httpd' output without override.conf (i.e. what apache service hangs)?

What is /var/log/httpd/error_log content?

Without override.conf it crashes
> AH00060: seg fault or similar nasty error detected in the parent process
(can it be result of killing processes by systemd?)

Running from command line "/usr/bin/apachectl start -DFOREGROUND" does not crash it and apache is still running after SIGHUP, but apachectl command exits with "Hangup" message.

Tail of error_log:

[Wed Nov 18 22:09:11.305493 2015] [mpm_prefork:notice] [pid 30463] AH00173: SIGHUP received. Attempting to restart
[Wed Nov 18 22:09:11.327851 2015] [core:notice] [pid 30463] AH00060: seg fault or similar nasty error detected in the parent process
[Wed Nov 18 22:09:47.479124 2015] [ssl:warn] [pid 30687] AH01909: www.example.com:443:0 server certificate does NOT include an ID which matches the server name
[Wed Nov 18 22:09:47.488162 2015] [ssl:warn] [pid 30687] AH01873: Init: Session Cache is not configured [hint: SSLSessionCache]
[Wed Nov 18 22:09:47.488487 2015] [ssl:warn] [pid 30687] AH01909: www.example.com:443:0 server certificate does NOT include an ID which matches the server name
[Wed Nov 18 22:09:47.488576 2015] [lbmethod_heartbeat:notice] [pid 30687] AH02282: No slotmem from mod_heartmonitor
[Wed Nov 18 22:09:47.489637 2015] [core:warn] [pid 30687] AH00098: pid file /run/httpd/httpd.pid overwritten -- Unclean shutdown of previous Apache run?
[Wed Nov 18 22:09:47.490831 2015] [mpm_prefork:notice] [pid 30687] AH00163: Apache/2.4.17 (Unix) OpenSSL/1.0.2d mod_fcgid/2.3.9 configured -- resuming normal operations
[Wed Nov 18 22:09:47.490857 2015] [core:notice] [pid 30687] AH00094: Command line: '/usr/bin/httpd -D FOREGROUND'
[Wed Nov 18 22:09:51.125671 2015] [mpm_prefork:notice] [pid 30687] AH00173: SIGHUP received. Attempting to restart
[Wed Nov 18 22:09:51.184540 2015] [ssl:warn] [pid 30687] AH01873: Init: Session Cache is not configured [hint: SSLSessionCache]
[Wed Nov 18 22:09:51.184973 2015] [ssl:warn] [pid 30687] AH01909: www.example.com:443:0 server certificate does NOT include an ID which matches the server name
[Wed Nov 18 22:09:51.185084 2015] [lbmethod_heartbeat:notice] [pid 30687] AH02282: No slotmem from mod_heartmonitor
[Wed Nov 18 22:09:51.187680 2015] [mpm_prefork:notice] [pid 30687] AH00163: Apache/2.4.17 (Unix) OpenSSL/1.0.2d mod_fcgid/2.3.9 configured -- resuming normal operations
[Wed Nov 18 22:09:51.187711 2015] [core:notice] [pid 30687] AH00094: Command line: '/usr/bin/httpd -D FOREGROUND'
[Wed Nov 18 22:10:50.138301 2015] [mpm_prefork:notice] [pid 30687] AH00169: caught SIGTERM, shutting down
[Wed Nov 18 22:10:54.143533 2015] [ssl:warn] [pid 30766] AH01909: www.example.com:443:0 server certificate does NOT include an ID which matches the server name
[Wed Nov 18 22:10:54.152673 2015] [ssl:warn] [pid 30766] AH01873: Init: Session Cache is not configured [hint: SSLSessionCache]
[Wed Nov 18 22:10:54.153004 2015] [ssl:warn] [pid 30766] AH01909: www.example.com:443:0 server certificate does NOT include an ID which matches the server name
[Wed Nov 18 22:10:54.153090 2015] [lbmethod_heartbeat:notice] [pid 30766] AH02282: No slotmem from mod_heartmonitor
[Wed Nov 18 22:10:54.155332 2015] [mpm_prefork:notice] [pid 30766] AH00163: Apache/2.4.17 (Unix) OpenSSL/1.0.2d mod_fcgid/2.3.9 configured -- resuming normal operations
[Wed Nov 18 22:10:54.155371 2015] [core:notice] [pid 30766] AH00094: Command line: '/usr/bin/httpd -D FOREGROUND'
[Wed Nov 18 22:11:02.951552 2015] [mpm_prefork:notice] [pid 30766] AH00173: SIGHUP received. Attempting to restart
[Wed Nov 18 22:11:03.010443 2015] [ssl:warn] [pid 30766] AH01873: Init: Session Cache is not configured [hint: SSLSessionCache]
[Wed Nov 18 22:11:03.010899 2015] [ssl:warn] [pid 30766] AH01909: www.example.com:443:0 server certificate does NOT include an ID which matches the server name
[Wed Nov 18 22:11:03.011007 2015] [lbmethod_heartbeat:notice] [pid 30766] AH02282: No slotmem from mod_heartmonitor
[Wed Nov 18 22:11:03.013652 2015] [mpm_prefork:notice] [pid 30766] AH00163: Apache/2.4.17 (Unix) OpenSSL/1.0.2d mod_fcgid/2.3.9 configured -- resuming normal operations
[Wed Nov 18 22:11:03.013684 2015] [core:notice] [pid 30766] AH00094: Command line: '/usr/bin/httpd -D FOREGROUND'

Status is the same:

# systemctl status httpd
● httpd.service - Apache Web Server
Loaded: loaded (/usr/lib/systemd/system/httpd.service; enabled; vendor preset: disabled)
Active: inactive (dead) since Wed 2015-11-18 22:17:29 MSK; 4s ago
Process: 31418 ExecStop=/usr/bin/apachectl graceful-stop (code=exited, status=0/SUCCESS)
Process: 31377 ExecStart=/usr/bin/apachectl start -DFOREGROUND (code=killed, signal=HUP)
Main PID: 31377 (code=killed, signal=HUP)

Nov 18 22:17:23 pupykin systemd[1]: Started Apache Web Server.

[core:notice] [pid 30463] AH00060: seg fault or similar nasty error detected in the parent process

Apache is not killed by the (graceful) restart, but because one of your loaded modules doens't like to be restarted and causes a segmentation fault.

But it does not happen if I start apache from command line.

Also I don't use 3rdparty modules and checked it switching new http2 module off:

LoadModule authn_file_module modules/mod_authn_file.so
LoadModule authn_core_module modules/mod_authn_core.so
LoadModule authz_host_module modules/mod_authz_host.so
LoadModule authz_groupfile_module modules/mod_authz_groupfile.so
LoadModule authz_user_module modules/mod_authz_user.so
LoadModule authz_core_module modules/mod_authz_core.so
LoadModule access_compat_module modules/mod_access_compat.so
LoadModule auth_basic_module modules/mod_auth_basic.so
LoadModule reqtimeout_module modules/mod_reqtimeout.so
LoadModule include_module modules/mod_include.so
LoadModule filter_module modules/mod_filter.so
LoadModule mime_module modules/mod_mime.so
LoadModule log_config_module modules/mod_log_config.so
LoadModule env_module modules/mod_env.so
LoadModule headers_module modules/mod_headers.so
LoadModule setenvif_module modules/mod_setenvif.so
LoadModule version_module modules/mod_version.so
LoadModule proxy_module modules/mod_proxy.so
LoadModule proxy_connect_module modules/mod_proxy_connect.so
LoadModule proxy_ftp_module modules/mod_proxy_ftp.so
LoadModule proxy_http_module modules/mod_proxy_http.so
LoadModule proxy_fcgi_module modules/mod_proxy_fcgi.so
LoadModule proxy_scgi_module modules/mod_proxy_scgi.so
LoadModule proxy_wstunnel_module modules/mod_proxy_wstunnel.so
LoadModule proxy_ajp_module modules/mod_proxy_ajp.so
LoadModule proxy_balancer_module modules/mod_proxy_balancer.so
LoadModule proxy_express_module modules/mod_proxy_express.so
LoadModule slotmem_shm_module modules/mod_slotmem_shm.so
LoadModule ssl_module modules/mod_ssl.so
LoadModule lbmethod_byrequests_module modules/mod_lbmethod_byrequests.so
LoadModule lbmethod_bytraffic_module modules/mod_lbmethod_bytraffic.so
LoadModule lbmethod_bybusyness_module modules/mod_lbmethod_bybusyness.so
LoadModule lbmethod_heartbeat_module modules/mod_lbmethod_heartbeat.so
LoadModule mpm_prefork_module modules/mod_mpm_prefork.so
LoadModule unixd_module modules/mod_unixd.so
LoadModule status_module modules/mod_status.so
LoadModule autoindex_module modules/mod_autoindex.so
LoadModule cgid_module modules/mod_cgid.so
LoadModule fcgid_module modules/mod_fcgid.so
LoadModule vhost_alias_module modules/mod_vhost_alias.so
LoadModule negotiation_module modules/mod_negotiation.so
LoadModule dir_module modules/mod_dir.so
LoadModule userdir_module modules/mod_userdir.so
LoadModule alias_module modules/mod_alias.so
LoadModule rewrite_module modules/mod_rewrite.so
LoadModule http2_module modules/mod_http2.so

It seems to happen when using "mpm_prefork_module", but not when using "mpm_event_module" (which is the default in the Arch package of Apache). Also take a close look at the different labels in the log exerpts from Anatol and Sergej above - one is event (works), one is prefork (doesn't work). I'm using prefork in order to use libphp5.so as described on the wiki (https://wiki.archlinux.org/index.php/Apache_HTTP_Server#PHP), otherwise that module doesn't work. Guess I'll disable logrotate for the time being, or try the other method to run PHP as described on the wiki.

Some googling routed me to this Apache commit http://svn.apache.org/viewvc?view=revision&revision=1618555 it sounds related. Could anyone try to build and test Apache with this patch?

Built the apache 2.4.17-3 package including the aforementioned patch. Does not seem to make a difference when sending the httpd process a SIGHUP like logrotate does. Httpd dies.

But another thing: I tried sending USR1 instead of HUP like Jan proposed in the first comment. Apache seems to restart (see its error_log) but doesn't stop/hang like with HUP. So would sending USR1 actually be a (correct) fix for this?

EDIT: Okay, USR1 may not be suitable; from the Apache 2.4 docs: "At present there is no way for a log rotation script using USR1 to know for certain that all children writing the pre-restart log have finished. We suggest that you use a suitable delay after sending the USR1 signal before you do anything with the old log. For example if most of your hits take less than 10 minutes to complete for users on low bandwidth links then you could wait 15 minutes before doing anything with the old log."

This happens to me too! I just updated our machine nov 20.

[2015-11-20 09:24] [ALPM] upgraded thin-provisioning-tools (0.4.1-1 -> 0.5.6-1)
[2015-11-20 09:24] [ALPM] upgraded lvm2 (2.02.125-1 -> 2.02.133-1)
[2015-11-20 09:24] [ALPM] upgraded man-db (2.7.2-1 -> 2.7.5-1)
[2015-11-20 09:24] [ALPM] upgraded mariadb-clients (10.0.21-2 -> 10.0.22-1)
[2015-11-20 09:24] [ALPM] upgraded mariadb (10.0.21-2 -> 10.0.22-1)
[2015-11-20 09:24] [ALPM] upgraded sqlite (3.8.11.1-3 -> 3.9.2-1)
[2015-11-20 09:24] [ALPM] upgraded python2 (2.7.10-1 -> 2.7.10-2)
[2015-11-20 09:24] [ALPM] upgraded mercurial (3.5-1 -> 3.5.1-1)
[2015-11-20 09:24] [ALPM] upgraded python (3.4.3-2 -> 3.5.0-2)
[2015-11-20 09:24] [ALPM] upgraded mod_wsgi (4.4.11-1 -> 4.4.21-1)
[2015-11-20 09:24] [ALPM] upgraded nano (2.4.2-1 -> 2.4.2-2)
[2015-11-20 09:24] [ALPM] installed http-parser (2.6.0-1)
[2015-11-20 09:24] [ALPM] upgraded nodejs (0.12.7-1 -> 5.1.0-1)
[2015-11-20 09:24] [ALPM] upgraded ntp (4.2.8.p3-1 -> 4.2.8.p4-1)
[2015-11-20 09:24] [ALPM] upgraded openresolv (3.7.0-1 -> 3.7.1-1)
[2015-11-20 09:24] [ALPM] upgraded pacman-mirrorlist (20150909-1 -> 20151115-1)
[2015-11-20 09:24] [ALPM] upgraded pacman (4.2.1-2 -> 4.2.1-4)
[2015-11-20 09:24] [ALPM] upgraded php (5.6.13-1 -> 5.6.15-3)
[2015-11-20 09:24] [ALPM] upgraded php-apache (5.6.13-1 -> 5.6.15-3)
[2015-11-20 09:24] [ALPM] upgraded php-gd (5.6.13-1 -> 5.6.15-3)
[2015-11-20 09:24] [ALPM] upgraded php-intl (5.6.13-1 -> 5.6.15-3)
[2015-11-20 09:24] [ALPM] upgraded php-mcrypt (5.6.13-1 -> 5.6.15-3)
[2015-11-20 09:24] [ALPM] upgraded php-sqlite (5.6.13-1 -> 5.6.15-3)
[2015-11-20 09:24] [ALPM] warning: /etc/webapps/phpmyadmin/config.inc.php installed as /etc/webapps/phpmyadmin/config.inc.php.pacnew
[2015-11-20 09:24] [ALPM] upgraded phpmyadmin (4.4.14.1-1 -> 4.5.1-1)
[2015-11-20 09:24] [ALPM] upgraded pkg-config (0.28-2 -> 0.29-1)
[2015-11-20 09:24] [ALPM] upgraded procps-ng (3.3.11-1 -> 3.3.11-2)
[2015-11-20 09:24] [ALPM] upgraded psmisc (22.21-2 -> 22.21-3)
[2015-11-20 09:24] [ALPM] upgraded screen (4.3.1-1 -> 4.3.1-2)
[2015-11-20 09:24] [ALPM] upgraded sudo (1.8.14.p3-2 -> 1.8.15-1)
[2015-11-20 09:24] [ALPM] upgraded systemd-sysvcompat (225-1 -> 227-1)
[2015-11-20 09:24] [ALPM] warning: /etc/fonts/conf.d/75-yes-terminus.conf saved as /etc/fonts/conf.d/75-yes-terminus.conf.pacsave
[2015-11-20 09:24] [ALPM] upgraded terminus-font (4.40-1 -> 4.40-2)
[2015-11-20 09:24] [ALPM] upgraded unrar (1:5.2.7-1 -> 1:5.3.4-1)
[2015-11-20 09:24] [ALPM] upgraded unzip (6.0-10 -> 6.0-11)
[2015-11-20 09:24] [ALPM] upgraded vi (1:070224-1 -> 1:070224-2)
[2015-11-20 09:24] [ALPM] upgraded xdebug (2.3.2-2 -> 2.3.3-1)
[2015-11-20 09:24] [ALPM] upgraded xfsprogs (3.2.4-1 -> 4.2.0-1)
[2015-11-20 09:24] [ALPM] transaction completed

then the bug occurred.
Some articles suggest it has something to do with the modules being loaded by apache.
The thing is, when I use apache graceful command manually, apache doesn't crash.
Only when logrotate does it's thing in the midnight, apache crashes.
An article also recommends recompiling apache + modules to fix the bug. I haven't done that yet.

What article you are referring to?

1. http://blog.kavoori.com/2015-03-21/apache-crash-with-seg-fault.html

2. https://www.ateamsystems.com/tech-blog/freebsd-apache-crashes-at-midnight/

I think this issue is caused by this commit https://projects.archlinux.org/svntogit/packages.git/commit/trunk?h=packages/apache&id=7e862c952493c891ddc3497824138574438a4c76

I am going to revert it until we clarify the issue.

apache-2.4.17-4 is in [testing]. Please verify that it fixes your issue.

Did a quick test using the updated version and it seems to work for me. What I tested:

- For mpm_event_module, mpm_prefork_module, and mpm_worker_module style configs:
- systemctl httpd start -> httpd runs.
- Sending HUP as done by logrotate (/bin/kill -HUP `cat /run/httpd/httpd.pid 2>/dev/null` 2> /dev/null || true) does not kill httpd anymore.
- systemctl httpd stop -> All httpd processes gone (ps aux | grep httpd).
- systemctl httpd restart -> All httpd processes have new PIDs.
- systemctl httpd reload -> All httpd processes except for the main process have new PIDs.

Edit - one more thing: Sending HUP also replaces the child processes by new ones like "reload" does which is a good sign, I suppose.

What I did not test is whether "reload" actually applied config changes, or whether the updated version has some possible race conditions when processing log files too quickly after logrotate.

Thank you!

Thanks for verifying it. I will keep apache-2.4.17-4 in [testing] for a while to let people test it more carefully and then push it to stable.

I will work on proper fix for the problem. Attached files (I think) fix it. Could you please check it as well?

Doing the same tests as before, the attached files seem to eliminate the symptoms just like the testing version of the package. In addition to the steps above, I did a daemon-reload after replacing the service file and I used a forced logrotate instead of executing the configured logrotate action manually, but I guess this should be equivalent.

Note however that the attached logrotate file has an error in it, I think the "> 2>" should be just "2>"? I made this change for testing, otherwise it doesn't work.

apache-2.4.17-4 Seems to fix it for me as well, thanks.

Just pushed apache-2.4.17-5 to [testing]. apache-2.4.17-5 contains systemd changes from 2.4.17-3 plus fixes.

Please check that it works as expected.