Service Unavailable

Bugs in eFa 4
Post Reply
chris
Posts: 14
Joined: 16 Jan 2015 08:31

Service Unavailable

Post by chris »

Hi,

We have two identical mailserver (except hostname/ip eg) After latest update, one of the mailservers gives the followin messeage after Mailscanenr login:

Service Unavailable
The server is temporarily unable to service your request due to maintenance downtime or capacity problems. Please try again later.

The second server works fine, we can not find anything wierd.

All the services are up, we have tried to restart the server without any success. Anyone have any tips?

Regards
Chris
User avatar
shawniverson
Posts: 3644
Joined: 13 Jan 2014 23:30
Location: Indianapolis, Indiana USA
Contact:

Re: Service Unavailable

Post by shawniverson »

What does /var/log/httpd error logs and /var/log/php-fpm error logs have to say about the error?
chris
Posts: 14
Joined: 16 Jan 2015 08:31

Re: Service Unavailable

Post by chris »

/var/log/httpd/error_log:

[Mon Dec 14 12:13:29.528013 2020] [core:notice] [pid 2229:tid 2229] SELinux policy enabled; httpd running as context system_u:
system_r:httpd_t:s0
[Mon Dec 14 12:13:29.530477 2020] [suexec:notice] [pid 2229:tid 2229] AH01232: suEXEC mechanism enabled (wrapper: /usr/sbin/su
exec)
[Mon Dec 14 12:13:29.538474 2020] [alias:warn] [pid 2229:tid 2229] AH00671: The Alias directive in /etc/httpd/conf.d/welcome.c
onf at line 18 will probably never match because it overlaps an earlier Alias.
[Mon Dec 14 12:13:29.541491 2020] [mpm_event:notice] [pid 2229:tid 2229] AH00489: Apache/2.4.46 (IUS) OpenSSL/1.0.2k-fips conf
igured -- resuming normal operations
[Mon Dec 14 12:13:29.541517 2020] [core:notice] [pid 2229:tid 2229] AH00094: Command line: '/usr/sbin/httpd -D FOREGROUND'
[Mon Dec 14 12:15:13.778608 2020] [mpm_event:notice] [pid 2229:tid 2229] AH00493: SIGUSR1 received. Doing graceful restart
[Mon Dec 14 12:15:13.842373 2020] [alias:warn] [pid 2229:tid 2229] AH00671: The Alias directive in /etc/httpd/conf.d/welcome.c
onf at line 18 will probably never match because it overlaps an earlier Alias.
[Mon Dec 14 12:15:13.844698 2020] [mpm_event:notice] [pid 2229:tid 2229] AH00489: Apache/2.4.46 (IUS) OpenSSL/1.0.2k-fips conf
igured -- resuming normal operations
[Mon Dec 14 12:15:13.844736 2020] [core:notice] [pid 2229:tid 2229] AH00094: Command line: '/usr/sbin/httpd -D FOREGROUND'


/var/log/httpd/ssl_error_log:

[Mon Dec 14 12:12:44.817613 2020] [proxy_fcgi:error] [pid 21276:tid 21386] [client 10.100.10.202:45804] AH01067: Failed to re
ad FastCGI header, referer: https://mailfilter01.domain.xyz/mailscanner/login.php
[Mon Dec 14 12:12:44.817636 2020] [proxy_fcgi:error] [pid 21276:tid 21386] (104)Connection reset by peer: [client 10.100.10.2
02:45804] AH01075: Error dispatching request to : , referer: https://mailfilter01.domain.xyz/mailscanner/login.php
[Mon Dec 14 12:14:23.559429 2020] [proxy_fcgi:error] [pid 2275:tid 2406] [client 10.100.10.202:57704] AH01067: Failed to read
FastCGI header, referer: https://mailfilter01.domain.xyz/mailscanner/login.php
[Mon Dec 14 12:14:23.560128 2020] [proxy_fcgi:error] [pid 2275:tid 2406] (104)Connection reset by peer: [client 10.100.201.202
:57704] AH01075: Error dispatching request to : , referer: https://mailfilter01.domain.xyz/mailscanner/login.php
[Mon Dec 14 12:15:50.205586 2020] [proxy_fcgi:error] [pid 3844:tid 3966] [client 10.100.10.27:11636] AH01067: Failed to read



/var/log/php-fpm/error.log:

[14-Dec-2020 12:14:23] NOTICE: [pool www] child 3505 started
[14-Dec-2020 12:15:13] NOTICE: Reloading in progress ...
[14-Dec-2020 12:15:13] NOTICE: reloading: execvp("/usr/sbin/php-fpm", {"/usr/sbin/php-fpm", "--nodaemonize"})
[14-Dec-2020 12:15:13] NOTICE: using inherited socket fd=6, "127.0.0.1:9000"
[14-Dec-2020 12:15:13] NOTICE: using inherited socket fd=6, "127.0.0.1:9000"
[14-Dec-2020 12:15:13] NOTICE: fpm is running, pid 1577
[14-Dec-2020 12:15:13] NOTICE: ready to handle connections
[14-Dec-2020 12:15:13] NOTICE: systemd monitor interval set to 10000ms
[14-Dec-2020 12:15:50] WARNING: [pool www] child 4057 exited with code 124 after 36.350491 seconds from start
[14-Dec-2020 12:15:50] NOTICE: [pool www] child 5073 started
[14-Dec-2020 12:15:57] WARNING: [pool www] child 4058 exited with code 124 after 43.924910 seconds from start
[14-Dec-2020 12:15:57] NOTICE: [pool www] child 5087 started
[14-Dec-2020 12:16:31] WARNING: [pool www] child 4056 exited with code 124 after 77.183140 seconds from start
[14-Dec-2020 12:16:31] NOTICE: [pool www] child 5173 started
[14-Dec-2020 12:17:03] WARNING: [pool www] child 4060 exited with code 124 after 109.248616 seconds from start
[14-Dec-2020 12:17:03] NOTICE: [pool www] child 5245 started
[14-Dec-2020 12:17:13] WARNING: [pool www] child 5073 exited with code 124 after 83.684210 seconds from start
[14-Dec-2020 12:17:13] NOTICE: [pool www] child 5256 started
[14-Dec-2020 12:18:54] WARNING: [pool www] child 4160 exited with code 124 after 215.156561 seconds from start
[14-Dec-2020 12:18:54] NOTICE: [pool www] child 5522 started
[14-Dec-2020 12:20:28] WARNING: [pool www] child 5245 exited with code 124 after 205.457682 seconds from start
[14-Dec-2020 12:20:28] NOTICE: [pool www] child 6232 started
[14-Dec-2020 12:25:28] WARNING: [pool www] child 4059 exited with code 124 after 614.555768 seconds from start
[14-Dec-2020 12:25:28] NOTICE: [pool www] child 7061 started
[14-Dec-2020 12:33:33] WARNING: [pool www] child 5522 exited with code 124 after 879.726869 seconds from start
[14-Dec-2020 12:33:33] NOTICE: [pool www] child 8963 started
[14-Dec-2020 12:40:09] WARNING: [pool www] child 4185 exited with code 124 after 1483.462283 seconds from start
[14-Dec-2020 12:40:09] NOTICE: [pool www] child 10392 started
[14-Dec-2020 12:46:25] WARNING: [pool www] child 6232 exited with code 124 after 1556.865017 seconds from start
[14-Dec-2020 12:46:25] NOTICE: [pool www] child 11877 started
[14-Dec-2020 12:53:11] WARNING: [pool www] child 5256 exited with code 124 after 2157.501763 seconds from start
[14-Dec-2020 12:53:11] NOTICE: [pool www] child 13374 started



/var/log/php-fpm/www-error.log:

[14-Dec-2020 12:33:01 Europe/Stockholm] PHP Notice: Undefined variable: dir in /var/www/html/mailscanner/msmail.inc.php on li
ne 33
[14-Dec-2020 12:39:37 Europe/Stockholm] PHP Notice: Undefined variable: dir in /var/www/html/mailscanner/msmail.inc.php on li
ne 33
[14-Dec-2020 12:39:37 Europe/Stockholm] PHP Notice: Undefined variable: dir in /var/www/html/mailscanner/msmail.inc.php on li
ne 33
[14-Dec-2020 12:54:43 Europe/Stockholm] PHP Notice: Undefined variable: dir in /var/www/html/mailscanner/msmail.inc.php on li
ne 33
User avatar
shawniverson
Posts: 3644
Joined: 13 Jan 2014 23:30
Location: Indianapolis, Indiana USA
Contact:

Re: Service Unavailable

Post by shawniverson »

How much memory do you have, and is mariadb running?

Code: Select all

systemctl status mariadb
chris
Posts: 14
Joined: 16 Jan 2015 08:31

Re: Service Unavailable

Post by chris »

[root@mailfilter01 conf]# systemctl -l status mariadb
● mariadb.service - MariaDB 10.1 database server
Loaded: loaded (/usr/lib/systemd/system/mariadb.service; enabled; vendor preset: disabled)
Drop-In: /etc/systemd/system/mariadb.service.d
└─limit.conf, override.conf
Active: active (running) since Mon 2020-12-14 14:34:37 CET; 37min ago
Process: 2115 ExecStartPost=/usr/libexec/mysql-check-upgrade (code=exited, status=0/SUCCESS)
Process: 1645 ExecStartPre=/usr/libexec/mysql-prepare-db-dir %n (code=exited, status=0/SUCCESS)
Process: 1573 ExecStartPre=/usr/libexec/mysql-check-socket (code=exited, status=0/SUCCESS)
Main PID: 1744 (mysqld)
Status: "Taking your SQL requests now..."
CGroup: /system.slice/mariadb.service
└─1744 /usr/libexec/mysqld --basedir=/usr

Dec 14 14:34:36 mailfilter01.domain.xyz systemd[1]: Starting MariaDB 10.1 database server...
Dec 14 14:34:36 mailfilter01.domain.xyz mysql-prepare-db-dir[1645]: Database MariaDB is probably initialized in /var/lib/mysql already, nothing is done.
Dec 14 14:34:36 mailfilter01.domain.xyz mysql-prepare-db-dir[1645]: If this is not the case, make sure the /var/lib/mysql is empty before running mysql-prepare-db-dir.
Dec 14 14:34:36 mailfilter01.domain.xyz mysqld[1744]: 2020-12-14 14:34:36 140064769644800 [Note] /usr/libexec/mysqld (mysqld 10.1.41-MariaDB) starting as process 1744 ...
Dec 14 14:34:37 mailfilter01.domain.xyz systemd[1]: Started MariaDB 10.1 database server.

Memory:

[root@mailfilter01 conf]# free
total used free shared buff/cache available
Mem: 65808020 5266004 59378576 9988 1163440 60067500
Swap: 16515068 0 16515068
User avatar
shawniverson
Posts: 3644
Joined: 13 Jan 2014 23:30
Location: Indianapolis, Indiana USA
Contact:

Re: Service Unavailable

Post by shawniverson »

Check for SELinux interference

Code: Select all

sudo setenforce 0
and report back
chris
Posts: 14
Joined: 16 Jan 2015 08:31

Re: Service Unavailable

Post by chris »

Same error
chris
Posts: 14
Joined: 16 Jan 2015 08:31

Re: Service Unavailable

Post by chris »

I did a restore before update, and ran update again - server working.
chris
Posts: 14
Joined: 16 Jan 2015 08:31

Re: Service Unavailable

Post by chris »

Today service unavailable is back again :-(
User avatar
shawniverson
Posts: 3644
Joined: 13 Jan 2014 23:30
Location: Indianapolis, Indiana USA
Contact:

Re: Service Unavailable

Post by shawniverson »

Ok, let's troubleshoot some more...

Get OS version and kernel

Code: Select all

cat /etc/centos-release
uname -a
Find out everything that updated....

/var/log/yum.log
/var/log/dnf.log

Check disk capacity

Code: Select all

df -h
Check stats

Code: Select all

top -n1
free
Take another look at the logs as you try to connect.

/var/log/httpd/
/var/log/php-fpm/
/var/log/messages
/var/log/audit/

Check the status of the following:

Code: Select all

systemctl status mariadb
systemctl status php-fpm
systemctl status httpd
Check database connectivity

Code: Select all

sudo -i
mysql -u root
use mailscanner;
select username from users limit 1;
User avatar
shawniverson
Posts: 3644
Joined: 13 Jan 2014 23:30
Location: Indianapolis, Indiana USA
Contact:

Re: Service Unavailable

Post by shawniverson »

Also, your php-fpm thread pool was crashing last time, so we need to figure out why that is happening...
child #### exited with code 124
User avatar
shawniverson
Posts: 3644
Joined: 13 Jan 2014 23:30
Location: Indianapolis, Indiana USA
Contact:

Re: Service Unavailable

Post by shawniverson »

Also,

Do you ever see the login screen?

Take a look at this, I wonder if it is the same issue.

viewtopic.php?t=4372
chris
Posts: 14
Joined: 16 Jan 2015 08:31

Re: Service Unavailable

Post by chris »

It could be related, I have found the same message on both mailfilters, both now have the same issue :-)

How do I safely remove something from quaratine without break the database?
/var/spool/MailScanner/quarantine/20201216
User avatar
shawniverson
Posts: 3644
Joined: 13 Jan 2014 23:30
Location: Indianapolis, Indiana USA
Contact:

Re: Service Unavailable

Post by shawniverson »

Removing from quarantine won't break database, but what we really need to do is isolate to the message and remove the offending entries from the database. Do you know the specific message(s) that may be causing the fault?
chris
Posts: 14
Joined: 16 Jan 2015 08:31

Re: Service Unavailable

Post by chris »

Nope, havent been able to find specific mail.

But our first mailserver is up again, cleaning database by itself i guess. We think its a support mail with many of rar and md5 attachments.
User avatar
shawniverson
Posts: 3644
Joined: 13 Jan 2014 23:30
Location: Indianapolis, Indiana USA
Contact:

Re: Service Unavailable

Post by shawniverson »

I would be most interested in this message and finding out why it is doing that. If you can find the message let me know.

The best advice I can offer is maybe clearing out the database for the day of the incident. Something like this after backing things up...

Code: Select all

use mailscanner;
SELECT date,messageid,to_address,from_address FROM maillog WHERE date = '2020-12-16';
Review the results, then...

Code: Select all

DELETE from maillog WHERE date = '2020-12-16';
chris
Posts: 14
Joined: 16 Jan 2015 08:31

Re: Service Unavailable

Post by chris »

Thank you for all assistence!

I know for sure what post it is now. Unfortunately I can not share it as it contains privacy, but there were lots of md5 files and rar files and the mailserver stopped it as bad content.
Post Reply