apache2 event mpm: keeps hanging in gracefully finishing when reloading (logrotate)

[Claudio Kuenzler]

This is Apache2 bug 53555 (https://bz.apache.org/bugzilla/show_bug.cgi?id=53555).
It was fixed in 2.4.25 but on Ubuntu Xenial, Apache2 runs with 2.4.18 and the fix was not backported yet.

This particular Apache2 setup runs with event mpm and is used as reverse proxy in front of a Tomcat (but that's irrelevant I guess). A daily log rotation happens on the Apache2 logs, causing an Apache2 reload (graceful restart). A check of apache-status each day confirms Apache bug 53555.

February 4th:

   Current Time: Tuesday, 04-Feb-2020 17:19:28 CET
   Restart Time: Monday, 03-Feb-2020 09:20:48 CET
   Parent Server Config. Generation: 2
   Parent Server MPM Generation: 1
   Server uptime: 1 day 7 hours 58 minutes 39 seconds
   Server load: 0.00 0.00 0.00
   Total accesses: 59027 - Total Traffic: 1.7 GB
   CPU Usage: u175.56 s424.83 cu0 cs0 - .522% CPU load
   .513 requests/sec - 15.7 kB/second - 30.6 kB/request
   1 requests currently being processed, 49 idle workers

    PID Connections Threads Async connections
         total accepting busy idle writing keep-alive closing
   31339 1 no 0 0 0 0 0
   31340 1 no 0 0 0 0 0
   21534 0 yes 0 25 0 0 0
   21535 0 yes 1 24 0 0 0
   Sum 2 1 49 0 0 0

GGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGG______________
__________________________________W_............................
......................

A couple of days later, February 7th:

   Current Time: Friday, 07-Feb-2020 14:06:52 CET
   Restart Time: Monday, 03-Feb-2020 09:20:48 CET
   Parent Server Config. Generation: 5
   Parent Server MPM Generation: 4
   Server uptime: 4 days 4 hours 46 minutes 3 seconds
   Server load: 0.00 0.00 0.00
   Total accesses: 152913 - Total Traffic: 20.9 GB
   CPU Usage: u520.6 s1424.31 cu0 cs0 - .536% CPU load
   .422 requests/sec - 60.5 kB/second - 143.5 kB/request
   1 requests currently being processed, 24 idle workers

    PID Connections Threads Async connections
         total accepting busy idle writing keep-alive closing
   31339 1 no 0 0 0 0 0
   31340 1 no 0 0 0 0 0
   11925 0 yes 1 24 0 0 0
   21535 1 no 0 0 0 0 0
   4156 1 no 0 0 0 0 0
   29454 1 no 0 0 0 0 0
   Sum 5 1 24 0 0 0

GGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGG______W_______
___________GGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGG
GGGGGGGGGGGGGGGGGGGGGG

On February 8th, the remaining open slots were fully used and HTTP didn't respond anymore. Error logs filling up with the following message: "[mpm_event:error] [pid 5587:tid 139748587677568] AH00485: scoreboard is full, not at MaxRequestWorkers"

Solution a) Update package to a newer upstream version for xenial-updates
Solution b) Backport the fix from Apache bug 53555

ProblemType: Bug
DistroRelease: Ubuntu 16.04
Package: apache2 2.4.18-2ubuntu3.1
ProcVersionSignature: Ubuntu 4.4.0-75.96-generic 4.4.59
Uname: Linux 4.4.0-75-generic x86_64
Apache2ConfdDirListing: False
ApportVersion: 2.20.1-0ubuntu2.5
Architecture: amd64
Date: Fri Feb 14 07:43:55 2020
InstallationDate: Installed on 2017-01-26 (1113 days ago)
InstallationMedia: Ubuntu-Server 16.04 LTS "Xenial Xerus" - Release amd64 (20160420.3)
ProcEnviron:
 LANGUAGE=en_US:en
 TERM=xterm
 PATH=(custom, no user)
 LANG=en_US.UTF-8
 SHELL=/bin/bash
SourcePackage: apache2
UpgradeStatus: No upgrade log present (probably fresh install)
error.log:
 [Fri Feb 14 06:25:06.928096 2020] [ssl:warn] [pid 27506:tid 140172129879936] AH01909: mcp-somcwc01-p.nzzmg.local:443:0 server certificate does NOT include an ID which matches the server name
 [Fri Feb 14 06:25:06.930524 2020] [mpm_event:notice] [pid 27506:tid 140172129879936] AH00489: Apache/2.4.18 (Ubuntu) mod_jk/1.2.41 OpenSSL/1.0.2g configured -- resuming normal operations
 [Fri Feb 14 06:25:06.930532 2020] [core:notice] [pid 27506:tid 140172129879936] AH00094: Command line: '/usr/sbin/apache2'
modified.conffile..etc.apache2.sites-available.000-default.conf: [modified]
modified.conffile..etc.apache2.sites-available.default-ssl.conf: [modified]
mtime.conffile..etc.apache2.sites-available.000-default.conf: 2017-02-14T07:38:24.570441
mtime.conffile..etc.apache2.sites-available.default-ssl.conf: 2018-04-09T15:47:05.141386

[Christian Ehrhardt  (paelzer)]

Hi Claudio,
the patches you referred sounded familiar and indeed I found bug 1466926 - it is fixed in later releases but the backports to Xenial turned out to cause more issues than they would fix.
Since then the bug is a known issue, but didn't get attention again :-/

Back on that issue it was closely tied to reloading (due to logrotate or others) too often.
And everyone affected there got around the issue by adapting the config.

Please chime in there after reading through that bug if you think this can't be solved by setup changes, try to add steps to reproduce there to give it a bump in prio, but I'm not sure there is a great way out - see https://bugs.launchpad.net/ubuntu/+source/apache2/+bug/1466926/comments/24.

I'll mark your bug here as a dup.