Postfix - main.cf changed for unknown reasons

Like i said in the title main.cf was changed for unknown reasons during server reboot. When i configured the virtual server, applied SSL, made few changes in main.cf i tested email several times with virtual server admin user and 2 more (in Usermin). Everything was perfect even connecting from Thunderbird was easy and without problems. Today i went to check my domain with mxtoolbox.com and i saw several (email) warnings what previously was not there (yesterday last time tested). Went to check the file and i saw immediately that the date was from today, maybe 1-2 hours before i notice the problem. Last time i edit this file was before 3 or 4 days and only thing what happened between yesterday (when the email was working) and today was one server restart (intentional from my side). Just to know this was not the first time server was rebooted in the last few days so if something was waiting to happen after the reboot it would happen way before.

This is part from maillog covering the time when was the server reboot:

Jun 16 01:25:21 jenkins dovecot: master: Dovecot v2.2.10 starting up for imap, pop3 (core dumps disabled)
Jun 16 01:25:21 jenkins spamd[170]: logger: removing stderr method
Jun 16 01:25:21 jenkins postfix/postfix-script[651]: starting the Postfix mail system
Jun 16 01:25:21 jenkins postfix/master[655]: daemon started -- version 2.10.1, configuration /etc/postfix
Jun 16 01:25:22 jenkins opendkim[1123]: OpenDKIM Filter v2.9.2 starting (args: -b sv)
Jun 16 01:25:23 jenkins spamd[380]: spamd: server started on IO::Socket::IP [127.0.0.1]:783, IO::Socket::IP [::1]:783 (running version 3.4.0)
Jun 16 01:25:23 jenkins spamd[380]: spamd: server pid: 380
Jun 16 01:25:23 jenkins spamd[380]: spamd: server successfully spawned child process, pid 1163
Jun 16 01:25:23 jenkins spamd[380]: spamd: server successfully spawned child process, pid 1164
Jun 16 01:25:23 jenkins spamd[380]: prefork: child states: SI
Jun 16 01:25:23 jenkins spamd[380]: prefork: child states: II
Jun 16 04:22:37 jenkins postfix/smtpd[7138]: warning: hostname 89-248-172-201.constellationservers.net does not resolve to address 89.248.172.201: Name or service not known
Jun 16 04:22:37 jenkins postfix/smtpd[7138]: connect from unknown[89.248.172.201]
Jun 16 04:23:07 jenkins postfix/smtpd[7138]: warning: connect to Milter service inet:localhost:8891: Connection timed out
Jun 16 04:23:08 jenkins postfix/smtpd[7138]: SSL_accept error from unknown[89.248.172.201]: Connection reset by peer
Jun 16 04:23:08 jenkins postfix/smtpd[7138]: lost connection after STARTTLS from unknown[89.248.172.201]
Jun 16 04:23:08 jenkins postfix/smtpd[7138]: disconnect from unknown[89.248.172.201]
Jun 16 04:26:28 jenkins postfix/anvil[7141]: statistics: max connection rate 1/60s for (smtp:89.248.172.201) at Jun 16 04:22:37
Jun 16 04:26:28 jenkins postfix/anvil[7141]: statistics: max connection count 1 for (smtp:89.248.172.201) at Jun 16 04:22:37
Jun 16 04:26:28 jenkins postfix/anvil[7141]: statistics: max cache size 1 at Jun 16 04:22:37

Server restart was at 1:25 and before that aside of few failed attempt to connect from spam IP's (all rejected) nothing unusual. After that every restart of postfix gives this log (from maillog):

Jun 16 07:55:31 jenkins postfix/master[5975]: terminating on signal 15
Jun 16 07:55:31 jenkins postfix/postfix-script[6621]: starting the Postfix mail system
Jun 16 07:55:31 jenkins postfix/master[6623]: daemon started -- version 2.10.1, configuration /etc/postfix

Messages log doesnt show anything unusual during the reboot. Later when mxtoolbox.com reported the errors i went to restart postfix and this is what i got from messages log:

Jun 16 07:55:30 jenkins systemd: Stopping Postfix Mail Transport Agent...
Jun 16 07:55:31 jenkins postfix: /usr/sbin/postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_sender_restrictions
Jun 16 07:55:31 jenkins postfix: /usr/sbin/postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_client_restrictions
Jun 16 07:55:31 jenkins postfix: /usr/sbin/postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_helo_restrictions
Jun 16 07:55:31 jenkins systemd: Starting Postfix Mail Transport Agent...
Jun 16 07:55:31 jenkins aliasesdb: /usr/sbin/postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_sender_restrictions
Jun 16 07:55:31 jenkins aliasesdb: /usr/sbin/postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_client_restrictions
Jun 16 07:55:31 jenkins aliasesdb: /usr/sbin/postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_helo_restrictions
Jun 16 07:55:31 jenkins postfix: /usr/sbin/postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_sender_restrictions  (**)
Jun 16 07:55:31 jenkins postfix: /usr/sbin/postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_client_restrictions  (**)
Jun 16 07:55:31 jenkins postfix: /usr/sbin/postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_helo_restrictions  (**)
....
Jun 16 07:55:31 jenkins systemd: Started Postfix Mail Transport Agent.
Jun 16 07:56:10 jenkins systemd-logind: New session 36825 of user root.
Jun 16 07:56:10 jenkins systemd: Started Session 36825 of user root.
Jun 16 07:56:10 jenkins systemd: Starting Session 36825 of user root.

** This 3 lines will repeat several times, usually from 3 to 5 more blocks of them:

Another thing, usermin cant send or receive emails and when i try to send i get this error:

Failed to send mail : Failed to connect to localhost:25 : Connection timed out

I tested port 25 with telnet and its open, i can connect to other mail servers without problem and from other location to my server:

[root@jenkins ~]# telnet mail.virtualmin.com 25
Trying 198.154.100.99...
Connected to mail.virtualmin.com.
Escape character is '^]'.
[root@xxxxxxxx ~]# telnet mail.mydomain.com 25
Trying 37.247.53.235...
Connected to mail.mydomain.com.
Escape character is '^]'.

All modifications done in main.cf are gone, e.g. it looks like from fresh install. From yesterday when the email was working up to the problem i didnt make any changes to postfix or anything else related to email.

Last but not least, this same problem i encounter before few months (5-6) when i was testing Vmin. To be honest after postfix imploded i just deleted entire server and ended my test. Now several months later i get same problem back. I try to modify main.cf but regardless of what i do the problem doesn't go away. Only way how to make email and Usermin to work again is to comment out this lines in master.cf (all of them):

-o smtpd_client_restrictions=$mua_client_restrictions
-o smtpd_helo_restrictions=$mua_helo_restrictions
-o smtpd_sender_restrictions=$mua_sender_restrictions

But i checked master.cf (date, content) and it was not changed from the day i applied SSL (before 8-10 days) so i dont think something happen with this file. As I previously said if something was waiting for server restart to make changes it would happen before few days.

This is random bug poping out or somewhere is the trigger? I know postfix would not reset main.cf out of nowhere and it could be Vmin/Wmin related. Any ideas what is going on here?

Status: 
Active

Comments

Howdy -- I don't believe Virtualmin would be making any changes to the main.cf upon bootup, it doesn't wait for restarts in order to apply a change. Any time it's told to make a change, it should apply that immediately.

Now, as to why you're seeing "$mua_client_restrictions" mentioned in the master.cf, Jamie may need to comment on that one... I'm not quite sure what that is, or when it's used. But that could indeed be a bug if it's preventing Postfix from starting up properly.

Lastly, regarding Usermin -- when testing your telnet command, try telnet'ing to "localhost 25", rather than "mail.mydomain.com 25". Usermin is mentioning that localhost is the issue. I'm curious if that shows a different result.

Virtualmin doesn't set the mua_client_restrictions option at boot, or in fact anywhere..

Diabolico's picture
Submitted by Diabolico on Thu, 06/16/2016 - 19:16

I tried now to connect to localhost 25 and doesnt work e.g. it times out. To be sure i check if firewalld is present but is not and i even disabled iptables but didnt make any difference. Whatever happened was during last reboot but the problem is i cant find anything.

Diabolico's picture
Submitted by Diabolico on Thu, 06/16/2016 - 19:21

--> Virtualmin doesn't set the mua_client_restrictions option at boot, or in fact anywhere.

I know and i said in my previous post that master.cf was not changed so i dont think there is the problem. Still something must triggered this problem and my only action between working email and this problem was server reboot. I encounter this problem in the past but like now i was not able to find any cause what could explain what happened.

This seems to have happened on my system this morning when i installed DKIM/Grey listing package to control the spam. May be these packages wrote into the postfix config file..

I dont know what this warning means? Do we have to action this or as the name suggests its just a warning?

postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_sender_restrictions postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_client_restrictions postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_helo_restrictions

We're not yet sure what causes that, but I'd suggest removing that from your master.cf file.