Issue [Linux apache] Apache doesn't start anymore after an update (loop)

[CBE]

Hello,

Server and Plesk information
CentOS Linux 7.8.2003 (Core) - Plesk Obsidian Version 18.0.29 Update #2, last updated on Aug 23, 2020 03:23 PM

Problem description

I have issue on one of my plesk servers after an update of Obsidian. The load average of the server was increasing and tried to restart services (PHP, Apache, etc) and it fails and it's impossible since these restarts to have a correct state of the server. I have rebooter the server and PHP is not up and running but apache is still in unstable state (starting, failed, starting again, etc).
--> Impossible to have a correct state of apache on the server.

Aug 24 07:54:44 ns348524 monit[1413]: INFO: [Mon Aug 24 07:43:13 CEST 2020]: Service: httpd, Action: start
Aug 24 07:54:44 ns348524 monit[1413]: Trying to start service httpd... failed
Aug 24 07:54:44 ns348524 monit[1413]: Aug 24 07:43:13 ns348524 systemd[1]: Starting The Apache HTTP Server...
Aug 24 07:54:44 ns348524 monit[1413]: Aug 24 07:53:13 ns348524 systemd[1]: httpd.service start operation timed out. Terminating.
Aug 24 07:54:44 ns348524 monit[1413]: Aug 24 07:54:43 ns348524 systemd[1]: httpd.service stop-sigterm timed out. Killing.
Aug 24 07:54:44 ns348524 monit[1413]: Aug 24 07:54:43 ns348524 systemd[1]: httpd.service: main process exited, code=killed, status=9/KILL
Aug 24 07:54:44 ns348524 monit[1413]: Aug 24 07:54:43 ns348524 systemd[1]: Failed to start The Apache HTTP Server.
Aug 24 07:54:44 ns348524 monit[1413]: Aug 24 07:54:43 ns348524 systemd[1]: Unit httpd.service entered failed state.
Aug 24 07:54:44 ns348524 monit[1413]: Aug 24 07:54:43 ns348524 systemd[1]: httpd.service failed.
Aug 24 07:54:44 ns348524 monit[1413]: *****  problem report *****
Aug 24 07:54:44 ns348524 monit[1413]: Warning: start service httpd failed
Aug 24 07:54:44 ns348524 monit[1413]: /usr/local/psa/admin/sbin/pleskrc execution failed:
Aug 24 07:54:44 ns348524 monit[1413]: Job for httpd.service failed because a fatal signal was delivered to the control process. See "systemctl status httpd.service" and "journalctl -xe" for details.

What has been done to try to solve the issue:
- Update timeout (to 600 sec)
- Reboot of server

I have found these threads (It seems really the same) but I would like information/validation first before trying something and having websites down for a while because of that:

Resolved - Cannot restart web server apache is down!

Hi, how can I resolve this? I cannot find precise information about this error: ***** is my server name, the configuration files where generated again but issue persist. Configuration troubleshooter does not load, keeps loading forever New configuration files for the Apache web server were not...

talk.plesk.com

Plesk fails to restart services: control script doesn't exist or isn't executable

Applicable to: Plesk for Linux Symptoms The following error is shown in Plesk UI: PLESK_ERROR: New configuration flies for the Apache web server were not created due to the errors in configura...

support.plesk.com

Can someone help me?

Thanks in advance,
Regards
Christophe

Steps to reproduce
No need, it's a loop for the moment.

Actual result
Apache is down for few secondes/minutes when starting fails

Expected result
No more down time for apache (httpd)

 

[Bitpalast]

The timeout value does not affect the start/stop behavior of services. The operating system configuration defines how long the operating system waits on a service to start or stop. When the load of the system is so high that the service cannot start within n seconds (like 120 seconds), the start process will be interrupted. You can retry the start once the load comes down to a low level.

It is possible that after a system reboot the load is high for a few minutes. Services like fail2ban for example can create a very high load while they are starting. My suggestion in your case is to check what other processes are doing and how much load is caused by them first. You can use this for example to see the top 30 loads:

ps aux | sort -nrk 3,3 | head -n 30

 

[CBE]

Hello,
thanks for your response.

For the timeout, I know but previously it was failing after about 60sec and then try again to start, etc (loop also) but Apache was down.
After reboot and update of timeout to 600sec, Apache is still looping on the start but now it's "up" (sites are reachable).

For the loads, here is the result, but since the reboot, the load is very low but apache is still not starting correctly:

mysql     1580  0.5  0.9 1957744 303496 ?      Sl   Aug23   4:38 /usr/libexec/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --log-error=/var/log/mariadb/mariadb.log --pid-file=/var/run/mariadb/mariadb.pid --socket=/var/lib/mysql/mysql.sock
root      1119  0.3  0.0 1942124 29628 ?       Ssl  Aug23   3:00 /usr/bin/python2 /usr/bin/fail2ban-server -xf start
psaadm   12481  0.2  0.2 598336 73264 ?        S    09:02   0:13 sw-engine-fpm: pool plesk
psaadm   24352  0.1  0.3 601392 102964 ?       S    Aug23   1:16 sw-engine-fpm: pool plesk
psaadm   22038  0.1  0.2 601316 80344 ?        S    00:05   0:52 sw-engine-fpm: pool plesk
psaadm   17395  0.1  0.3 601900 101624 ?       S    Aug23   0:58 sw-engine-fpm: pool plesk
grafana   2515  0.1  0.2 1458564 69604 ?       Ssl  Aug23   1:11 /usr/sbin/grafana-server --config=/etc/grafana/grafana.ini --pidfile=/var/run/grafana/grafana-server.pid --packaging=rpm cfg:default.paths.logs=/var/log/grafana cfg:default.paths.data=/var/lib/grafana cfg:default.paths.plugins=/var/lib/grafana/plugins cfg:default.paths.provisioning=/etc/grafana/provisioning
sw-cp-s+  1211  0.0  0.0  54384  9000 ?        S    Aug23   0:08 sw-cp-server: worker process
root     30321  0.0  0.0      0     0 ?        I    07:12   0:00 [kworker/u16:0-d]
root     25963  0.0  0.0 108072  1784 pts/0    S+   10:34   0:00 head -n 30
root     25962  0.0  0.0 126824  2116 pts/0    S+   10:34   0:00 sort -nrk 3,3
root     25961  0.0  0.0 155456  3924 pts/0    R+   10:34   0:00 ps aux
root     25601  0.0  0.0      0     0 ?        I    10:32   0:00 [kworker/1:1-cgr]
root     25337  0.0  0.0      0     0 ?        I    10:30   0:00 [kworker/7:2-mm_]
root     25330  0.0  0.0 216128  7052 ?        S    10:30   0:00 /usr/sbin/CROND -n
root     25310  0.0  0.0      0     0 ?        I    10:29   0:00 [kworker/5:0-mm_]
root     25218  0.0  0.0      0     0 ?        I    10:29   0:00 [kworker/0:0-eve]
root     25078  0.0  0.0      0     0 ?        I    10:28   0:00 [kworker/2:1-cgr]
root     24995  0.0  0.0 1853792 19304 ?       Sl   10:27   0:00 Passenger core
root     24992  0.0  0.0 365812  9968 ?        Ssl  10:27   0:00 Passenger watchdog
root     24953  0.0  0.0 322184 20976 ?        Ss   10:27   0:00 /usr/sbin/httpd -DFOREGROUND
root     24952  0.0  0.0  31244  2760 ?        S    10:27   0:00 /bin/systemctl start httpd.service
root     24924  0.0  0.0  12232  3216 ?        S    10:27   0:00 /bin/bash -hB /usr/local/psa/admin/sbin/pleskrc httpd start
root     24864  0.0  0.0  83832  5752 ?        S    10:27   0:00 apache_control_adapter --start
root     24860  0.0  0.0  28560  3484 ?        S    10:27   0:00 /usr/local/psa/admin/bin/websrvmng --start
root     24575  0.0  0.0      0     0 ?        I    10:25   0:00 [kworker/3:2-mm_]
root     24514  0.0  0.0      0     0 ?        I    10:25   0:00 [kworker/6:0]
root     23806  0.0  0.0      0     0 ?        I    10:20   0:00 [kworker/4:0-cgr]
root     23801  0.0  0.0      0     0 ?        I    10:20   0:00 [kworker/1:2-eve]
root     23763  0.0  0.0      0     0 ?        I    10:19   0:00 [kworker/3:1-eve]

Do you have any idea?
The proposed threads to "solve" this issue seems not relevant for my problem?

Thanks,
Regards
Christophe

 

[Bitpalast]

What's the result of
apachectl -t

 

[CBE]

Hello,
Result is :
# apachectl -t
Syntax OK

Regards
Christophe

 

[Bitpalast]

When you run
service httpd start
and then look at
journalctl -xe
does this give more information on what's going on during the start attempt?

 

[CBE]

Hello,
when I run this, it's not giving any result only this (waiting response it seems ... I haven't the possibility to write something else) :

# service httpd start
Redirecting to /bin/systemctl start httpd.service

and when I do a journalctl -xe nothing neither concerning Apache/httpd ...
maybe because it's already starting but not started (timeout after 600sec) :

When i do a

# systemctl status httpd.service
● httpd.service - The Apache HTTP Server
Loaded: loaded (/usr/lib/systemd/system/httpd.service; enabled; vendor preset: disabled)
Active: deactivating (stop-sigterm) (Result: timeout)
Docs: man:httpd(8)
man:apachectl(8)
Main PID: 31960 (httpd)
Memory: 42.4M
CGroup: /system.slice/httpd.service
├─31960 /usr/sbin/httpd -DFOREGROUND
├─31998 /usr/sbin/httpd -DFOREGROUND
├─32000 Passenger watchdog
├─32003 Passenger core
├─32022 /usr/sbin/httpd -DFOREGROUND
├─32028 /usr/sbin/httpd -DFOREGROUND
├─32029 /usr/sbin/httpd -DFOREGROUND
├─32032 /usr/sbin/httpd -DFOREGROUND
├─32033 /usr/sbin/httpd -DFOREGROUND
├─32101 /usr/sbin/httpd -DFOREGROUND
└─32654 /usr/sbin/httpd -DFOREGROUND

Aug 24 11:18:15 systemd[1]: Starting The Apache HTTP Server...
Aug 24 11:28:15 systemd[1]: httpd.service start operation timed out. Terminating.

and now, it's starting again ...
and I receive this for the service httpd start (previously done above) :
# service httpd start
Redirecting to /bin/systemctl start httpd.service
Job for httpd.service failed because a fatal signal was delivered to the control process. See "systemctl status httpd.service" and "journalctl -xe" for details.

when I do a journalctl -xe now .. i have this, as always, for apache/httpd :

Aug 24 11:29:46 systemd[1]: httpd.service stop-sigterm timed out. Killing.
Aug 24 11:29:46 systemd[1]: httpd.service: main process exited, code=killed, status=9/KILL
Aug 24 11:29:46 systemd[1]: Failed to start The Apache HTTP Server.
-- Subject: Unit httpd.service has failed
-- Defined-By: systemd
-- Support: systemd-devel Info Page
--
-- Unit httpd.service has failed.
--
-- The result is failed.
Aug 24 11:29:46 systemd[1]: Unit httpd.service entered failed state.
Aug 24 11:29:46 systemd[1]: httpd.service failed.

 

[Bitpalast]

Have you tried to stop Passenger before trying to restart Apache? Normally when Apache cannot restart, it gives some sort of reason for that. If your overall cpu load is low on the machine and there are no reasons logged for Apache, probably Apache is waiting on another service to deliver something to it before it can continue. In your case, only Passenger shows up in the process list, so maybe that would be a thing to investigate.

 

[CBE]

Hello,
I didn't try to stop passenger because It was started "like" that when I have restarted the server so I thought that services starting was correctly done.
Do you know how to stop passenger properly and to be able to test the restart of apache correctly?
Thanks
Regards
Christophe

 

[Bitpalast]

Have you checked if something strange is logged in its log file?

Log file - Apache - Passenger Library

 

[CBE]

Hello,
here is what I have in error_log of httpd folder in var:

[ N 2020-08-24 11:29:47.1754 1139/T1 age/Wat/WatchdogMain.cpp:1373 ]: Starting Passenger watchdog...
[ N 2020-08-24 11:29:47.1878 1142/T1 age/Cor/CoreMain.cpp:1340 ]: Starting Passenger core...
[ N 2020-08-24 11:29:47.1879 1142/T1 age/Cor/CoreMain.cpp:256 ]: Passenger core running in multi-application mode.
[ N 2020-08-24 11:29:47.2431 1142/T1 age/Cor/CoreMain.cpp:1015 ]: Passenger core online, PID 1142
[Mon Aug 24 11:29:47.243840 2020] [core:warn] [pid 1085] AH00098: pid file /run/httpd/httpd.pid overwritten -- Unclean shutdown of previous Apache run?
[Mon Aug 24 11:29:47.246024 2020] [mpm_prefork:notice] [pid 1085] AH00163: Apache/2.4.6 (CentOS) OpenSSL/1.0.2k-fips mod_fcgid/2.3.9 Phusion_Passenger/6.0.2 configured -- resuming normal operations
[Mon Aug 24 11:29:47.246058 2020] [core:notice] [pid 1085] AH00094: Command line: '/usr/sbin/httpd -D FOREGROUND'
[ N 2020-08-24 11:29:47.2945 1095/T1 age/Cor/TelemetryCollector.h:531 ]: Message from Phusion: End time can not be before or equal to begin time
[ N 2020-08-24 11:29:47.3864 1095/T1 age/Cor/CoreMain.cpp:1325 ]: Passenger core shutdown finished
[ N 2020-08-24 11:29:49.4432 1142/T5 age/Cor/SecurityUpdateChecker.h:519 ]: Security update check: no update found (next check in 24 hours)


[ N 2020-08-24 11:43:26.4322 2976/T1 age/Wat/WatchdogMain.cpp:1373 ]: Starting Passenger watchdog...
[ N 2020-08-24 11:43:26.4443 2979/T1 age/Cor/CoreMain.cpp:1340 ]: Starting Passenger core...
[ N 2020-08-24 11:43:26.4444 2979/T1 age/Cor/CoreMain.cpp:256 ]: Passenger core running in multi-application mode.
[ N 2020-08-24 11:43:26.4865 2979/T1 age/Cor/CoreMain.cpp:1015 ]: Passenger core online, PID 2979

[ N 2020-08-24 11:43:26.4897 2979/T9 age/Cor/CoreMain.cpp:671 ]: Signal received. Gracefully shutting down... (send signal 2 more time(s) to force shutdown)
[ N 2020-08-24 11:43:26.4898 2979/T1 age/Cor/CoreMain.cpp:1246 ]: Received command to shutdown gracefully. Waiting until all clients have disconnected...
[ N 2020-08-24 11:43:26.4899 2979/Tj Ser/Server.h:902 ]: [ServerThr.6] Freed 0 spare client objects
[ N 2020-08-24 11:43:26.4899 2979/T9 Ser/Server.h:902 ]: [ServerThr.1] Freed 0 spare client objects
[ N 2020-08-24 11:43:26.4899 2979/Tk Ser/Server.h:902 ]: [ServerThr.7] Freed 0 spare client objects
[ N 2020-08-24 11:43:26.4899 2979/Tj Ser/Server.h:558 ]: [ServerThr.6] Shutdown finished
[ N 2020-08-24 11:43:26.4899 2979/Tg Ser/Server.h:902 ]: [ServerThr.5] Freed 0 spare client objects
[ N 2020-08-24 11:43:26.4899 2979/Td Ser/Server.h:902 ]: [ServerThr.3] Freed 0 spare client objects
[ N 2020-08-24 11:43:26.4899 2979/T9 Ser/Server.h:558 ]: [ServerThr.1] Shutdown finished
[ N 2020-08-24 11:43:26.4899 2979/Tm Ser/Server.h:902 ]: [ServerThr.8] Freed 0 spare client objects
[ N 2020-08-24 11:43:26.4899 2979/Tg Ser/Server.h:558 ]: [ServerThr.5] Shutdown finished
[ N 2020-08-24 11:43:26.4899 2979/Td Ser/Server.h:558 ]: [ServerThr.3] Shutdown finished
[ N 2020-08-24 11:43:26.4899 2979/Ta Ser/Server.h:902 ]: [ServerThr.2] Freed 0 spare client objects
[ N 2020-08-24 11:43:26.4899 2979/Tm Ser/Server.h:558 ]: [ServerThr.8] Shutdown finished
[ N 2020-08-24 11:43:26.4900 2979/Ta Ser/Server.h:558 ]: [ServerThr.2] Shutdown finished
[ N 2020-08-24 11:43:26.4899 2979/Tk Ser/Server.h:558 ]: [ServerThr.7] Shutdown finished
[ N 2020-08-24 11:43:26.4900 2979/Tp Ser/Server.h:902 ]: [ApiServer] Freed 0 spare client objects
[ N 2020-08-24 11:43:26.4899 2979/Te Ser/Server.h:902 ]: [ServerThr.4] Freed 0 spare client objects
[ N 2020-08-24 11:43:26.4900 2979/Tp Ser/Server.h:558 ]: [ApiServer] Shutdown finished
[ N 2020-08-24 11:43:26.4900 2979/Te Ser/Server.h:558 ]: [ServerThr.4] Shutdown finished

and then the same again ...

For your information, here is the apache web server settings (previously, when I had the problem, it was Event instead of Prefork as MPM mode - the rest is the same as before):


Thanks
Regards
Christophe

 

[Bitpalast]

I don't know, it's not really saying anything meaningful.
Just to rule out that Passenger is causing the problem, I'd probably remove the module (uncheck it) from the Apache configuration and see if Apache starts afterwards.

 

[moswak]

did you check the abandoned systemd scope units on the server ?

systemctl | grep abandoned | wc -l

 

[CBE]

Hello,
@moswak , here is the result for the abandoned :

# systemctl | grep abandoned | wc -l
3
# systemctl | grep abandoned
session-2.scope loaded active abandoned Session 2 of user psaadm
session-c1.scope loaded active abandoned Session c1 of user root
session-c2.scope loaded active abandoned Session c2 of user beamium

@Peter Debik , Ok thanks I will try and keep you posted end of day in order to not compromise the current state.

Thanks
Regards
Christophe

 

[CBE]

Hello,
@Peter Debik I have tried to uncheck and apply but it's looping to do the modification it seems.
I have done a ps -aef | grep httpd and I have this running
/bin/bash -hB /usr/local/psa/admin/sbin/httpd_modules_ctl --disable passenger -e
Since more than 10min ... and nothing happens.
It seems that starting of apache is looping (as explained before --> starting, then timeout then failed and then start again, etc) and that no other command can be executed ..

Result of ps :
# ps -aef | grep httpd
root 14437 5815 0 22:33 ? 00:00:00 /bin/bash -hB /usr/local/psa/admin/sbin/httpd_modules_ctl --disable passenger -e
root 15514 14497 0 22:40 ? 00:00:00 /bin/bash -hB /usr/local/psa/admin/sbin/pleskrc httpd start
root 15543 15514 0 22:40 ? 00:00:00 /bin/systemctl start httpd.service
root 15544 1 0 22:40 ? 00:00:00 /usr/sbin/httpd -DFOREGROUND
apache 15545 15544 0 22:40 ? 00:00:00 /usr/sbin/httpd -DFOREGROUND
apache 15546 15544 0 22:40 ? 00:00:00 /usr/sbin/httpd -DFOREGROUND
apache 15547 15544 0 22:40 ? 00:00:00 /usr/sbin/httpd -DFOREGROUND
apache 15548 15544 0 22:40 ? 00:00:00 /usr/sbin/httpd -DFOREGROUND
apache 15549 15544 0 22:40 ? 00:00:00 /usr/sbin/httpd -DFOREGROUND
apache 15550 15544 0 22:40 ? 00:00:00 /usr/sbin/httpd -DFOREGROUND
apache 15701 15544 0 22:42 ? 00:00:00 /usr/sbin/httpd -DFOREGROUND
root 15892 9169 0 22:43 pts/0 00:00:00 grep --color=auto httpd

@moswak do you have also an idea?
I have tried to launch the script of this page but nothing happens, still 3 abandoned sessions.
Plesk fails to restart services: control script doesn't exist or isn't executable

Thanks
Regards
Christophe

 

[moswak]

Sorry, I have no other ideas. maybe plesk support should take a look at this directly on the server.