/etc/init.d/apache2 restart fails on busy webservers

[James Troup]

Binary package hint: apache2

We have a recurring problem with the weekly logrotation restart of apache not coming back on busy web servers. It doesn't happen every week, but it's no fun when it does because it means someone gets calls early on a Sunday morning.

[Andy Loughran (andylockran)]

Please can you provide the versions of logrotate, apache, and ubuntu you are using please. As well as kernel version.

Do you have any steps you can take to reproduce this action?

[James Troup (elmo)]

andylockran <email address hidden> writes:

> Please can you provide the versions of logrotate, apache, and ubuntu you
> are using please. As well as kernel version.

Well, Hardy, so:

apache2-mpm-worker 2.2.8-1ubuntu0.3
logrotate 3.7.1-3
Kernel 2.6.24-19-server

> Do you have any steps you can take to reproduce this action?

Actually, sorry, I've just noticed that the default logrotate file
uses 'reload' rather than 'restart', which is great but I still think
'restart' should work better for a busy server. The fundamental
problem seems to be that it tries to shut down gracefully, but that
takes too long for a busy server. Rather than then shutting down hard
(e.g. kill -9), it just gives up, and immediately tries to start again
(which of course fails).

Anyway, to reproduce: run a very busy webserver and run
'/etc/init.d/apache2 restart'.

--
James

[Chuck Short (zulcss)]

Sounds reasonable to me. Ill do some testing locally here before uploading to proposed.

chuck

[Launchpad Janitor (janitor)]

This bug was fixed in the package apache2 - 2.2.9-7ubuntu2

---------------
apache2 (2.2.9-7ubuntu2) intrepid; urgency=low

  * debian/logrotate: Restart rather than reload for busy websites.
    (LP: #270899)

 -- Chuck Short <email address hidden> Thu, 18 Sep 2008 08:42:22 -0400

[Daniel Hahler (blueyed)]

This change has been reverted in 2.2.9-7ubuntu3 - setting back to Triaged.

[Daniel Hahler (blueyed)]

See also bug 23938 ("Apache2 logrotate kills existing connections on server") - where "restart" has been changed to "graceful-reload".

[Matt Zimmerman (mdz)]

Per Rick, Chuck is working on this, so setting to In Progress

[Stefan Fritsch (sf-sfritsch)]

Since 2.2.9-2, "/etc/init.d/apache2 restart" does a hard (non-graceful) restart again, so this should already be fixed in Intrepid.

James, do you also experience hangs with the default action "/etc/init.d/apache2 reload" during logrotate? If the problem is only with restart, you could just get the init script from Intrepid.

[Chuck Short (zulcss)]

Hi,

I have backported the fix from karmic to fix this in hardy.

Thanks
chuck

[Andreas Tauscher (ta-lonestar-bbs)]

Is it fixed or back again?
On 6th of June Apche stopped after logrotating.
Reproducable this hapend when using graceful for reloading.

Installed Software:
Lucid 32Bit
apache2.2_2.2.14-5ubuntu8

The strange thing it happens only on one server. I compared it with other servers, having the exact same setup: No difference, except on this server are SSL-VHosts. But even disabling them: apace2ctl graceful and apache hangs / the task are not stopping.

For now I have no idea what I can check.

[Dave Walker (davewalker)]

@Andreas, I'm really confused that you are experiencing this on some servers - but not others. Have you been able to find out any further information?

Thanks.

[Stefan Fritsch (sf-sfritsch)]

A possible culprit is mod_php. Andreas, do you use mod_php and if yes, which php extensions have you loaded?

[Thierry Carrez (ttx)]

Chuck, can you please update status on this one ?

[cooolman (coolman)]

Please update apache2 for ununtu 15.10 to version 2.4.16

[Joshua Powers (powersj)]

Hi, I know this bug is very old, but it showed up during the server team's daily bug triage.

Based on the comments it appears this was fixed, but waiting on confirmation and/or additional information from the reporter. Because this isn't clear I am going to mark this as incomplete and allow someone to add additional information as to whether it still exists or is fixed.

Thanks!

[Ville Pouhula (villepouhula)]

Hello!

I can confirm this bug. We have four servers running ubuntu xenial. Three of them had automatically updated apache2 to this version and after update apache service was not running! I had to manually start them again.

And with one another server I did manual update to apache2 package and also after that, apache2 service was stopped.

[Joshua Powers (powersj)]

Can you get the journal (journalctl -b > file) to help determine what prevented it from starting?

[Ville Pouhula (villepouhula)]

Well not much information there:

Jun 27 02:24:43 ip-10-15-0-98 systemd[1]: Starting Daily apt activities...
Jun 27 02:25:10 ip-10-15-0-98 systemd[1]: Reloading.
Jun 27 02:25:11 ip-10-15-0-98 systemd[1]: snapd.refresh.timer: Adding 1h 21min 48.884882s random time.
Jun 27 02:25:11 ip-10-15-0-98 systemd[1]: Started ACPI event daemon.
Jun 27 02:25:11 ip-10-15-0-98 systemd[1]: Stopping LSB: Apache2 web server...
Jun 27 02:25:11 ip-10-15-0-98 apache2[22198]: * Stopping Apache httpd web server apache2
Jun 27 02:25:13 ip-10-15-0-98 apache2[22198]: *
Jun 27 02:25:13 ip-10-15-0-98 systemd[1]: Stopped LSB: Apache2 web server.
Jun 27 02:25:13 ip-10-15-0-98 systemd[1]: Reloading.
Jun 27 02:25:13 ip-10-15-0-98 systemd[1]: snapd.refresh.timer: Adding 4h 45min 16.224693s random time.
Jun 27 02:25:13 ip-10-15-0-98 systemd[1]: Started ACPI event daemon.
Jun 27 02:25:14 ip-10-15-0-98 systemd[1]: Reloading.
Jun 27 02:25:14 ip-10-15-0-98 systemd[1]: snapd.refresh.timer: Adding 3h 3min 52.839206s random time.
Jun 27 02:25:14 ip-10-15-0-98 systemd[1]: Started ACPI event daemon.
Jun 27 02:25:16 ip-10-15-0-98 systemd[1]: Reloading.
Jun 27 02:25:16 ip-10-15-0-98 systemd[1]: snapd.refresh.timer: Adding 3h 45min 34.137843s random time.
Jun 27 02:25:16 ip-10-15-0-98 systemd[1]: Started ACPI event daemon.
Jun 27 02:25:16 ip-10-15-0-98 systemd[1]: Reloading.
Jun 27 02:25:17 ip-10-15-0-98 systemd[1]: snapd.refresh.timer: Adding 14min 59.404091s random time.
Jun 27 02:25:17 ip-10-15-0-98 systemd[1]: Started ACPI event daemon.
Jun 27 02:25:25 ip-10-15-0-98 systemd[1]: Started Daily apt activities.
Jun 27 02:25:25 ip-10-15-0-98 systemd[1]: apt-daily.timer: Adding 5h 4min 2.832906s random time.
Jun 27 02:25:25 ip-10-15-0-98 systemd[1]: apt-daily.timer: Adding 4h 14min 17.749588s random time.

[Andreas Hasenack (ahasenack)]

Please also take a look at the apache error log files in /var/log/apache2/error.log

[Ville Pouhula (villepouhula)]

Hi again and sorry for the delay, here are some more logfiles:

/var/log/unattended-upgrades/unattended-upgrades.log:
2017-06-27 03:59:09,379 INFO Initial blacklisted packages:
2017-06-27 03:59:09,379 INFO Initial whitelisted packages:
2017-06-27 03:59:09,379 INFO Starting unattended upgrades script
2017-06-27 03:59:09,380 INFO Allowed origins are: ['o=Ubuntu,a=xenial', 'o=Ubuntu,a=xenial-security']
2017-06-27 03:59:25,333 INFO Packages that will be upgraded: apache2 apache2-bin apache2-data apache2-utils
2017-06-27 03:59:25,333 INFO Writing dpkg log to '/var/log/unattended-upgrades/unattended-upgrades-dpkg.log'
2017-06-27 03:59:33,931 INFO All upgrades installed

/var/log/unattended-upgrades/unattended-upgrades-dpkg.log:
Log started: 2017-06-27 03:59:25
(Reading database ...
(Reading database ... 5%
(Reading database ... 10%
(Reading database ... 15%
(Reading database ... 20%
(Reading database ... 25%
(Reading database ... 30%
(Reading database ... 35%
(Reading database ... 40%
(Reading database ... 45%
(Reading database ... 50%
(Reading database ... 55%
(Reading database ... 60%
(Reading database ... 65%
(Reading database ... 70%
(Reading database ... 75%
(Reading database ... 80%
(Reading database ... 85%
(Reading database ... 90%
(Reading database ... 95%
(Reading database ... 100%
(Reading database ... 346214 files and directories currently installed.)
Preparing to unpack .../apache2_2.4.18-2ubuntu3.3_amd64.deb ...
Unpacking apache2 (2.4.18-2ubuntu3.3) over (2.4.18-2ubuntu3.2) ...
Preparing to unpack .../apache2-bin_2.4.18-2ubuntu3.3_amd64.deb ...
Unpacking apache2-bin (2.4.18-2ubuntu3.3) over (2.4.18-2ubuntu3.2) ...
Preparing to unpack .../apache2-utils_2.4.18-2ubuntu3.3_amd64.deb ...
Unpacking apache2-utils (2.4.18-2ubuntu3.3) over (2.4.18-2ubuntu3.2) ...
Preparing to unpack .../apache2-data_2.4.18-2ubuntu3.3_all.deb ...
Unpacking apache2-data (2.4.18-2ubuntu3.3) over (2.4.18-2ubuntu3.2) ...
Processing triggers for systemd (229-4ubuntu10) ...
Processing triggers for ureadahead (0.100.0-19) ...
Processing triggers for ufw (0.35-0ubuntu2) ...
Processing triggers for man-db (2.7.5-1) ...
Setting up apache2-bin (2.4.18-2ubuntu3.3) ...
Setting up apache2-utils (2.4.18-2ubuntu3.3) ...
Setting up apache2-data (2.4.18-2ubuntu3.3) ...
Setting up apache2 (2.4.18-2ubuntu3.3) ...
insserv: warning: current start runlevel(s) (empty) of script `apache2' overrides LSB defaults (2 3 4 5).
insserv: warning: current stop runlevel(s) (0 1 2 3 4 5 6) of script `apache2' overrides LSB defaults (0 1 6).
Log ended: 2017-06-27 03:59:33

/var/log/dpkg.log:
2017-06-27 03:59:26 upgrade apache2:amd64 2.4.18-2ubuntu3.2 2.4.18-2ubuntu3.3
2017-06-27 03:59:26 status half-configured apache2:amd64 2.4.18-2ubuntu3.2
2017-06-27 03:59:28 status unpacked apache2:amd64 2.4.18-2ubuntu3.2
2017-06-27 03:59:28 status half-installed apache2:amd64 2.4.18-2ubuntu3.2
2017-06-27 03:59:28 status triggers-pending systemd:amd64 229-4ubuntu10
2017-06-27 03:59:28 status triggers-pending ureadahead:amd64 0.100.0-19
2017-06-27 03:59:28 status triggers-pending ufw:all 0.35-0ubuntu2
2017-06-27 03:59:28 status triggers-pending man-db:amd64 2.7.5-1
2017-06-27 03:59:28 status half-installed...