Resolved Apache restarts randomly

Nicola Urbinati · Nov 26, 2020

We're experiencing a lot of random Apache restarts, like once a day.

What's going on?

IgorG · Nov 26, 2020

Any additional details: logs, error messages, results of troubleshooting? This KB article may help with it Plesk for Linux services logs and configuration files

G J Piper · Nov 26, 2020

Nicola Urbinati said:
We're experiencing a lot of random Apache restarts, like once a day.

What's going on?

It may be that the log rotation is set up to rotate when a given size is reached, which can be random lengths of time depending on server traffic. When the apache logs are rotated and archived, it restarts to re-initialize the new empty log files. You should be able to see the times logs were rotated in the logs, and compare to see if the random restarts coincide with that timing to verify.

Nicola Urbinati · Nov 27, 2020

/var/log/apache2/error.log and other_vhosts_access.log seem to be rotated correctly at 06.45 all days. So this should not be the case.

I can't see anyting valuable in the logs (error, access... what other logs should I check?), not even the restart instance.

I also do not see any memory/cpu spikes related to those restarts (from advanced monitoring).

Only thing I see is:

Code:

# grep resuming /var/log/apache2/error.log


[Fri Nov 27 13:20:13.630134 2020] [mpm_event:notice] [pid 17687:tid 140465329728448] AH00489: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 mod_fcgid/2.3.9 configured -- resuming normal operations
[Fri Nov 27 13:25:12.827971 2020] [mpm_event:notice] [pid 19705:tid 139702004890560] AH00489: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 mod_fcgid/2.3.9 configured -- resuming normal operations
[Fri Nov 27 13:30:12.697888 2020] [mpm_event:notice] [pid 21413:tid 139841244543936] AH00489: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 mod_fcgid/2.3.9 configured -- resuming normal operations
[Fri Nov 27 13:35:16.743154 2020] [mpm_event:notice] [pid 23164:tid 139956536921024] AH00489: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 mod_fcgid/2.3.9 configured -- resuming normal operations
[Fri Nov 27 13:40:16.019062 2020] [mpm_event:notice] [pid 25006:tid 139943726578624] AH00489: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 mod_fcgid/2.3.9 configured -- resuming normal operations
[Fri Nov 27 13:45:14.406098 2020] [mpm_event:notice] [pid 26820:tid 140599530253248] AH00489: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 mod_fcgid/2.3.9 configured -- resuming normal operations
[Fri Nov 27 13:50:14.257489 2020] [mpm_event:notice] [pid 28498:tid 140056077114304] AH00489: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 mod_fcgid/2.3.9 configured -- resuming normal operations
[Fri Nov 27 13:55:13.337247 2020] [mpm_event:notice] [pid 30261:tid 140295014218688] AH00489: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 mod_fcgid/2.3.9 configured -- resuming normal operations
[Fri Nov 27 14:00:14.099973 2020] [mpm_event:notice] [pid 32029:tid 140329832569792] AH00489: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 mod_fcgid/2.3.9 configured -- resuming normal operations
[Fri Nov 27 14:05:12.982764 2020] [mpm_event:notice] [pid 1487:tid 140478582430656] AH00489: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 mod_fcgid/2.3.9 configured -- resuming normal operations
[Fri Nov 27 14:10:13.069545 2020] [mpm_event:notice] [pid 3259:tid 140259874917312] AH00489: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 mod_fcgid/2.3.9 configured -- resuming normal operations
[Fri Nov 27 14:15:13.558304 2020] [mpm_event:notice] [pid 4993:tid 140616797019072] AH00489: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 mod_fcgid/2.3.9 configured -- resuming normal operations
[Fri Nov 27 14:20:14.414735 2020] [mpm_event:notice] [pid 6836:tid 139669036268480] AH00489: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 mod_fcgid/2.3.9 configured -- resuming normal operations

This is every 5 minutes (I should be using FPM-PHP), not related to the restarts as I see it

Nicola Urbinati · Nov 27, 2020

I also verify there are restarts every 5 minutes:

Code:

root@srvurb01:/var/log/apache2# service apache2 status
● apache2.service - The Apache HTTP Server
   Loaded: loaded (/etc/systemd/system/apache2.service; enabled; vendor preset: enabled)
  Drop-In: /lib/systemd/system/apache2.service.d
           └─apache2-systemd.conf, limit_nofile.conf
   Active: active (running) since Fri 2020-11-27 14:25:12 CET; 2min 48s ago
  Process: 8580 ExecStop=/usr/sbin/apachectl stop (code=exited, status=0/SUCCESS)
  Process: 8615 ExecStart=/usr/sbin/apachectl start (code=exited, status=0/SUCCESS)
 Main PID: 22094 (code=exited, status=0/SUCCESS)
    Tasks: 68 (limit: 4915)
   CGroup: /system.slice/apache2.service
           ├─8640 /usr/sbin/apache2 -k start
           ├─8642 /opt/psa/admin/sbin/pipelog 7081
           ├─8644 /usr/sbin/apache2 -k start
           ├─8646 /usr/sbin/apache2 -k start
           ├─8647 /usr/sbin/apache2 -k start
           └─9358 /opt/plesk/php/7.3/bin/php-cgi -c /etc/psa-webmail/roundcube/php.ini

Nov 27 14:25:11 srvurb01.urbaman.it systemd[1]: Starting The Apache HTTP Server...
Nov 27 14:25:12 srvurb01.urbaman.it systemd[1]: Started The Apache HTTP Server.

-----------------------------------------------------

root@srvurb01:/var/log/apache2# service apache2 status
● apache2.service - The Apache HTTP Server
   Loaded: loaded (/etc/systemd/system/apache2.service; enabled; vendor preset: enabled)
  Drop-In: /lib/systemd/system/apache2.service.d
           └─apache2-systemd.conf, limit_nofile.conf
   Active: active (running) since Fri 2020-11-27 14:50:13 CET; 4s ago
  Process: 17323 ExecStop=/usr/sbin/apachectl stop (code=exited, status=0/SUCCESS)
  Process: 17412 ExecStart=/usr/sbin/apachectl start (code=exited, status=0/SUCCESS)
 Main PID: 22094 (code=exited, status=0/SUCCESS)
    Tasks: 57 (limit: 4915)
   CGroup: /system.slice/apache2.service
           ├─17449 /usr/sbin/apache2 -k start
           ├─17451 /opt/psa/admin/sbin/pipelog 7081
           ├─17453 /usr/sbin/apache2 -k start
           ├─17455 /usr/sbin/apache2 -k start
           └─17456 /usr/sbin/apache2 -k start

Nov 27 14:50:12 srvurb01.urbaman.it systemd[1]: Starting The Apache HTTP Server...
Nov 27 14:50:13 srvurb01.urbaman.it systemd[1]: Started The Apache HTTP Server.

Could it be some of those (graceful?) restarts that goes longer/worse?
The actual random symptom is that all websites are down for some minutes until apahce gets up again.

Bitpalast · Nov 27, 2020

Your log output is limited to the messages containing the string "resuming". Could you please provide the full context for one of these operations? Before Apache restarts, there should be more lines that give more details.

Also please make sure that you have turned graceful restarts on.

How to enable/disable Apache graceful restart in Plesk

Applicable to: Plesk for Linux Question How to enable/disable graceful restart for Apache in Plesk? How to make Apache reload instead of restarting when applying settings in Plesk? Answer ...

support.plesk.com

You should also check your crontab entries whether there are entries anywhere that can cause such restarts, e.g. additional log rotations.

It could also be possible for example that a user on the system has configured log rotation extremely tight, e.g. every 1 KB, and if you have not set Apache to graceful restarts, that would cause downtime.

Nicola Urbinati · Nov 27, 2020

Ok,

Just happend again.

Apache restarts settings:

I received two mails:

Web Server (Apache) on srvurb01.urbaman.it is down

The Web Server (Apache) service on host srvurb01.urbaman.it is down.
The problem was discovered on Nov 27, 2020 03:50 PM.

Web Server (Apache) on srvurb01.urbaman.it has been started

The Web Server (Apache) service on host srvurb01.urbaman.it has been started on Nov 27, 2020 03:55 PM.

Syslog:

Code:

Nov 27 15:20:11 srvurb01 systemd[1]: Stopped The Apache HTTP Server.
Nov 27 15:20:11 srvurb01 systemd[1]: Starting The Apache HTTP Server...
Nov 27 15:20:11 srvurb01 systemd[1]: Started The Apache HTTP Server.
Nov 27 15:24:58 srvurb01 monit[819]: 'apache' process PID changed to 30630
Nov 27 15:25:12 srvurb01 systemd[1]: Stopped The Apache HTTP Server.
Nov 27 15:25:12 srvurb01 systemd[1]: Starting The Apache HTTP Server...
Nov 27 15:25:12 srvurb01 systemd[1]: Started The Apache HTTP Server.
Nov 27 15:30:00 srvurb01 monit[819]: 'apache' process PID changed to 32336
Nov 27 15:30:12 srvurb01 systemd[1]: Stopped The Apache HTTP Server.
Nov 27 15:30:12 srvurb01 systemd[1]: Starting The Apache HTTP Server...
Nov 27 15:30:12 srvurb01 systemd[1]: Started The Apache HTTP Server.
Nov 27 15:50:09 srvurb01 monit[819]: 'apache' process PID changed to 6875
Nov 27 15:50:12 srvurb01 monit[819]: GENERIC: error receiving data -- Connection reset by peer
Nov 27 15:50:12 srvurb01 monit[819]: 'apache' failed protocol test [generic] at INET[127.0.0.1:7080].
Nov 27 15:50:12 srvurb01 monit[819]: 'apache' trying to restart
Nov 27 15:50:12 srvurb01 monit[819]: 'apache' start: /opt/psa/admin/bin/websrvmng
Nov 27 15:50:12 srvurb01 systemd[1]: Stopped The Apache HTTP Server.
Nov 27 15:50:12 srvurb01 systemd[1]: Starting The Apache HTTP Server...
Nov 27 15:50:12 srvurb01 systemd[1]: Started The Apache HTTP Server.
Nov 27 15:50:13 srvurb01 wdcollect[22277]: Connection to server has been established.
Nov 27 15:50:13 srvurb01 wdcollect[22277]: Connection to server has been established.
Nov 27 15:51:14 srvurb01 wdcollect[22277]: Connection to SMTP server has been closed.
Nov 27 15:51:14 srvurb01 wdcollect[22277]: Connection to SMTP server has been closed.
Nov 27 15:55:12 srvurb01 systemd[1]: Stopped The Apache HTTP Server.
Nov 27 15:55:12 srvurb01 systemd[1]: Starting The Apache HTTP Server...
Nov 27 15:55:13 srvurb01 systemd[1]: Started The Apache HTTP Server.
Nov 27 15:55:14 srvurb01 monit[819]: 'apache' connection passed
Nov 27 15:55:15 srvurb01 wdcollect[22277]: Connection to server has been established.
Nov 27 15:55:15 srvurb01 wdcollect[22277]: Connection to server has been established.
Nov 27 15:56:16 srvurb01 wdcollect[22277]: Connection to SMTP server has been closed.
Nov 27 15:56:16 srvurb01 wdcollect[22277]: Connection to SMTP server has been closed.

Apache error log:

Code:

[Fri Nov 27 15:45:12.926195 2020] [core:notice] [pid 6875:tid 140377770978240] AH00094: Command line: '/usr/sbin/apache2'
[Fri Nov 27 15:50:12.085913 2020] [mpm_event:notice] [pid 6875:tid 140377770978240] AH00491: caught SIGTERM, shutting down
[Fri Nov 27 15:50:12.442347 2020] [ssl:warn] [pid 8571:tid 139830551804864] AH01909: webmail.gdrunplugged.it:443:0 server certificate does NOT include an ID which matches the server name
[Fri Nov 27 15:50:12.448090 2020] [ssl:warn] [pid 8571:tid 139830551804864] AH01909: lists:443:0 server certificate does NOT include an ID which matches the server name
[Fri Nov 27 15:50:12.449340 2020] [ssl:warn] [pid 8571:tid 139830551804864] AH01909: default-207_180_243_98:443:0 server certificate does NOT include an ID which matches the server name
[Fri Nov 27 15:50:12.449613 2020] [:notice] [pid 8571:tid 139830551804864] ModSecurity for Apache/2.9.3 (http://www.modsecurity.org/) configured.
[Fri Nov 27 15:50:12.449627 2020] [:notice] [pid 8571:tid 139830551804864] ModSecurity: APR compiled version="1.6.3"; loaded version="1.6.3"
[Fri Nov 27 15:50:12.449633 2020] [:notice] [pid 8571:tid 139830551804864] ModSecurity: PCRE compiled version="8.39 "; loaded version="8.39 2016-06-14"
[Fri Nov 27 15:50:12.449638 2020] [:notice] [pid 8571:tid 139830551804864] ModSecurity: LUA compiled version="Lua 5.1"
[Fri Nov 27 15:50:12.449642 2020] [:notice] [pid 8571:tid 139830551804864] ModSecurity: LIBXML compiled version="2.9.4"
[Fri Nov 27 15:50:12.449646 2020] [:notice] [pid 8571:tid 139830551804864] ModSecurity: Status engine is currently disabled, enable it by set SecStatusEngine to On.
[Fri Nov 27 15:50:12.726731 2020] [suexec:notice] [pid 8571:tid 139830551804864] AH01232: suEXEC mechanism enabled (wrapper: /usr/lib/apache2/suexec)
[Fri Nov 27 15:50:12.965558 2020] [:notice] [pid 8648:tid 139830551804864] mod_bw : Memory Allocated 0 bytes (each conf takes 48 bytes)
[Fri Nov 27 15:50:12.965589 2020] [:notice] [pid 8648:tid 139830551804864] mod_bw : Version 0.92 - Initialized [0 Confs]
[Fri Nov 27 15:50:12.986611 2020] [ssl:warn] [pid 8648:tid 139830551804864] AH01909: webmail.gdrunplugged.it:443:0 server certificate does NOT include an ID which matches the server name
[Fri Nov 27 15:50:12.991256 2020] [ssl:warn] [pid 8648:tid 139830551804864] AH01909: lists:443:0 server certificate does NOT include an ID which matches the server name
[Fri Nov 27 15:50:12.992240 2020] [ssl:warn] [pid 8648:tid 139830551804864] AH01909: default-207_180_243_98:443:0 server certificate does NOT include an ID which matches the server name
[Fri Nov 27 15:50:13.316603 2020] [mpm_event:notice] [pid 8648:tid 139830551804864] AH00489: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 mod_fcgid/2.3.9 configured -- resuming normal operations
[Fri Nov 27 15:50:13.316683 2020] [core:notice] [pid 8648:tid 139830551804864] AH00094: Command line: '/usr/sbin/apache2'
[Fri Nov 27 15:55:12.346056 2020] [mpm_event:notice] [pid 8648:tid 139830551804864] AH00491: caught SIGTERM, shutting down
[Fri Nov 27 15:55:12.751165 2020] [ssl:warn] [pid 10366:tid 140024880257984] AH01909: webmail.gdrunplugged.it:443:0 server certificate does NOT include an ID which matches the server name
[Fri Nov 27 15:55:12.756111 2020] [ssl:warn] [pid 10366:tid 140024880257984] AH01909: lists:443:0 server certificate does NOT include an ID which matches the server name
[Fri Nov 27 15:55:12.757263 2020] [ssl:warn] [pid 10366:tid 140024880257984] AH01909: default-207_180_243_98:443:0 server certificate does NOT include an ID which matches the server name
[Fri Nov 27 15:55:12.757593 2020] [:notice] [pid 10366:tid 140024880257984] ModSecurity for Apache/2.9.3 (http://www.modsecurity.org/) configured.
[Fri Nov 27 15:55:12.757611 2020] [:notice] [pid 10366:tid 140024880257984] ModSecurity: APR compiled version="1.6.3"; loaded version="1.6.3"
[Fri Nov 27 15:55:12.757620 2020] [:notice] [pid 10366:tid 140024880257984] ModSecurity: PCRE compiled version="8.39 "; loaded version="8.39 2016-06-14"
[Fri Nov 27 15:55:12.757628 2020] [:notice] [pid 10366:tid 140024880257984] ModSecurity: LUA compiled version="Lua 5.1"
[Fri Nov 27 15:55:12.757634 2020] [:notice] [pid 10366:tid 140024880257984] ModSecurity: LIBXML compiled version="2.9.4"
[Fri Nov 27 15:55:12.757640 2020] [:notice] [pid 10366:tid 140024880257984] ModSecurity: Status engine is currently disabled, enable it by set SecStatusEngine to On.
[Fri Nov 27 15:55:13.179391 2020] [suexec:notice] [pid 10366:tid 140024880257984] AH01232: suEXEC mechanism enabled (wrapper: /usr/lib/apache2/suexec)
[Fri Nov 27 15:55:13.374126 2020] [:notice] [pid 10381:tid 140024880257984] mod_bw : Memory Allocated 0 bytes (each conf takes 48 bytes)
[Fri Nov 27 15:55:13.374174 2020] [:notice] [pid 10381:tid 140024880257984] mod_bw : Version 0.92 - Initialized [0 Confs]
[Fri Nov 27 15:55:13.398196 2020] [ssl:warn] [pid 10381:tid 140024880257984] AH01909: webmail.gdrunplugged.it:443:0 server certificate does NOT include an ID which matches the server name
[Fri Nov 27 15:55:13.403786 2020] [ssl:warn] [pid 10381:tid 140024880257984] AH01909: lists:443:0 server certificate does NOT include an ID which matches the server name
[Fri Nov 27 15:55:13.404629 2020] [ssl:warn] [pid 10381:tid 140024880257984] AH01909: default-207_180_243_98:443:0 server certificate does NOT include an ID which matches the server name
[Fri Nov 27 15:55:13.693355 2020] [mpm_event:notice] [pid 10381:tid 140024880257984] AH00489: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 mod_fcgid/2.3.9 configured -- resuming normal operations
[Fri Nov 27 15:55:13.693472 2020] [core:notice] [pid 10381:tid 140024880257984] AH00094: Command line: '/usr/sbin/apache2'

Bitpalast · Nov 27, 2020

Please enter at least 600 seconds into the Apache restart interval. 0 seconds means that every single configuration change will trigger a restart. It is much better to accumulate configuration changes over a short period of time like 10 minutes (600 seconds) or longer to minimize the impact that configuration changes can have. 900 seconds is also a good value. Frequent restarts could lead to overlapping processes which cause crashes and could maybe even cause the symptoms you are describing (although in this case I don't think that is the root cause).

The restart interval of exactly 5 minutes you are experiencing is almost certainly caused by a script that requests this. The log entries do not look like there are general issues with the system, e.g. not enough RAM, disk space etc. It look smore like a deliberate restart, like in

[Fri Nov 27 15:50:13.316683 2020] [core:notice] [pid 8648:tid 139830551804864] AH00094: Command line: '/usr/sbin/apache2'

So you will need to find the script that is doing it. It can be a log rotation setting, it can also be another script. Not easy to find.

Nicola Urbinati · Nov 27, 2020

Put 600 as apache restart interval, let's see if it mitigates or solves the issue.

G J Piper · Nov 27, 2020

Nicola Urbinati said:
Put 600 as apache restart interval, let's see if it mitigates or solves the issue.

If this causes Apache to restart every 10 or 15 minutes, I would still be concerned with whatever is changing your settings so often as to cause Plesk to think it needs to restart every 5 minutes.

Bitpalast · Nov 27, 2020

Please apologize if I was not clear enough on that.

Advice to change the setting was not meant to solve the issue. It was meant to rule out additional issues as recommended by the Plesk documentation where it is recommended to set the value higher then zero because else each configuration change will trigger a webserver restart. I always try to give users a more solid basis from where to start, that's why I also mentioned that change.

The advice part regarding the 5 minute interval was to look for crontab entries or log file rotation directives, because the log file shows that an apache restart command is issued. There is probably no software error, but some other script that causes the restarts deliberately.

Nicola Urbinati · Nov 27, 2020

Yes, I understood the advice, and I am actually also trying to debug which script is causing the restarts.
I'm suspecting something is happening in a specific domain at the moment.
My previous answer is actually too much hopeful as it is.

I'll keep you updated on what I get (if I get something)

Nicola Urbinati · Nov 28, 2020

Ok, solved the mistery.

There where two cron scripts dedicated to whitelist IPs via Dynamic DNS.
They also whitelisted the IPs in ModEvasive, then restarting Apache.
That should happen just once or twice a day, but a misconfiguration of the scripts made them actually restart Apache every 5 minutes.

Now switched restarts to reloads, and started a deeper debugging the misconfiguration.

The symptom should be solved (the logs confirm it).

Thanks everybody for the help and the insight.

Resolved Apache restarts randomly

Nicola Urbinati

Basic Pleskian

IgorG

Plesk addicted!

G J Piper

Regular Pleskian

Nicola Urbinati

Basic Pleskian

Nicola Urbinati

Basic Pleskian

Bitpalast

Plesk addicted!

How to enable/disable Apache graceful restart in Plesk

Nicola Urbinati

Basic Pleskian

Web Server (Apache) on srvurb01.urbaman.it is down

Web Server (Apache) on srvurb01.urbaman.it has been started

Bitpalast

Plesk addicted!

Nicola Urbinati

Basic Pleskian

G J Piper

Regular Pleskian

Bitpalast

Plesk addicted!

Nicola Urbinati

Basic Pleskian

Nicola Urbinati

Basic Pleskian

Similar threads

Resolved Apache restarts randomly

Basic Pleskian

Plesk addicted!

Regular Pleskian

Basic Pleskian

Basic Pleskian

Plesk addicted!

Basic Pleskian

Web Server (Apache) on srvurb01.urbaman.it is down​

Web Server (Apache) on srvurb01.urbaman.it has been started​

Plesk addicted!

Basic Pleskian

Regular Pleskian

Plesk addicted!

Basic Pleskian

Basic Pleskian

Similar threads

Web Server (Apache) on srvurb01.urbaman.it is down

Web Server (Apache) on srvurb01.urbaman.it has been started