Solved Postfix problem receiving email to relay
-
I have a CentOS 7 box at a site simply being a mail relay. Has been working fine for the last year.
Today it is not working right. It is accepting the incoming connection, but then nothing else. The sending devices are reporting a timeout.
Here is the
/var/log/maillog
showing nothing helpful.Mar 7 09:21:33 relay01 postfix/smtpd[880]: connect from ljcm6040.domain.local[10.201.1.11] Mar 7 09:22:33 relay01 postfix/smtpd[880]: lost connection after CONNECT from ljcm6040.domain.local[10.201.1.11] Mar 7 09:22:33 relay01 postfix/smtpd[880]: disconnect from ljcm6040.domain.local[10.201.1.11] Mar 7 09:22:34 relay01 postfix/smtpd[880]: connect from ljcm6040.domain.local[10.201.1.11] Mar 7 09:23:34 relay01 postfix/smtpd[880]: warning: non-SMTP command from ljcm6040.domain.local[10.201.1.11]: Content-Type: text/plain; Mar 7 09:23:34 relay01 postfix/smtpd[880]: disconnect from ljcm6040.domain.local[10.201.1.11] Mar 7 09:23:58 relay01 postfix/smtpd[880]: connect from ljcm6040.domain.local[10.201.1.11] Mar 7 09:24:58 relay01 postfix/smtpd[880]: warning: non-SMTP command from ljcm6040.domain.local[10.201.1.11]: Content-Type: text/plain; Mar 7 09:24:58 relay01 postfix/smtpd[880]: disconnect from ljcm6040.domain.local[10.201.1.11] Mar 7 09:40:05 relay01 postfix/smtpd[10169]: connect from owncloud.domain.local[10.201.1.17] Mar 7 09:40:15 relay01 postfix/smtpd[10169]: lost connection after CONNECT from owncloud.domain.local[10.201.1.17] Mar 7 09:40:15 relay01 postfix/smtpd[10169]: disconnect from owncloud.domain.local[10.201.1.17]
-
And problem resolved.
On the 1st, the damned DHCP lease had failed again due to the mysterious time drift issues I have been tracking down in another thread.
But I needed this system up so I launched
nmtui
and set a static IP.... Wait for it.. to 10.201.1.12/32/fucking sigh....
I also enabled the Time Synchronization in Hyper-V on March 1st. As soon as I fixed the /32, this morning, the Hyper-V integration started fixing the time every 5 seconds.. screw that. Turned it back off. I will count on
chronyd
it works well as long as the IP stays online.[root@relay01 ~]# tail -f /var/log/messages Mar 7 11:18:33 relay01 systemd: Time has been changed Mar 7 11:18:38 relay01 systemd: Time has been changed Mar 7 11:18:43 relay01 systemd: Time has been changed Mar 7 11:18:48 relay01 systemd: Time has been changed Mar 7 11:18:53 relay01 systemd: Time has been changed Mar 7 11:18:58 relay01 systemd: Time has been changed Mar 7 11:19:03 relay01 systemd: Time has been changed Mar 7 11:19:08 relay01 systemd: Time has been changed Mar 7 11:19:13 relay01 systemd: Time has been changed Mar 7 11:19:18 relay01 systemd: Time has been changed
-
Any chance that you are experiencing packet loss or something like that?
-
@scottalanmiller said in Postfix problem receiving email to relay:
Any chance that you are experiencing packet loss or something like that?
From the first one, which is a copier, yes. That is why I did a test send in owncloud. That is a VM on the same hypervisor..
-
NIC on the fritz?
-
@art_of_shred said in Postfix problem receiving email to relay:
NIC on the fritz?
VM to VM on the same HV would bypass that, even if the NIC caught fire and was in a pile of goo.
-
Any clue of another log to look into? Server was rebooted, drive space is stupid extra. because when the VM was created, I apparently neglected to change the Hyper-V default of 127GB
[root@relay01 ~]# df -h Filesystem Size Used Avail Use% Mounted on /dev/mapper/centos_relay01-root 50G 1.7G 49G 4% / devtmpfs 229M 0 229M 0% /dev tmpfs 240M 0 240M 0% /dev/shm tmpfs 240M 4.3M 235M 2% /run tmpfs 240M 0 240M 0% /sys/fs/cgroup /dev/sda2 497M 280M 218M 57% /boot /dev/sda1 200M 9.5M 191M 5% /boot/efi /dev/mapper/centos_relay01-home 76G 33M 76G 1% /home tmpfs 48M 0 48M 0% /run/user/0
-
maillog and messages should cover anything likely to have happened.
No package updates?
-
@scottalanmiller said in Postfix problem receiving email to relay:
maillog and messages should cover anything likely to have happened.
No package updates?
nope.
[root@relay01 ~]# yum update Loaded plugins: fastestmirror Loading mirror speeds from cached hostfile * base: mirror.team-cymru.org * extras: mirror.compevo.com * updates: repos.lax.quadranet.com No packages marked for update
-
@JaredBusch said in Postfix problem receiving email to relay:
@scottalanmiller said in Postfix problem receiving email to relay:
maillog and messages should cover anything likely to have happened.
No package updates?
nope.
[root@relay01 ~]# yum update Loaded plugins: fastestmirror Loading mirror speeds from cached hostfile * base: mirror.team-cymru.org * extras: mirror.compevo.com * updates: repos.lax.quadranet.com No packages marked for update
Sorry, I meant historically, like yesterday before the issue came up. Check the yumlog.
-
@scottalanmiller said in Postfix problem receiving email to relay:
@JaredBusch said in Postfix problem receiving email to relay:
@scottalanmiller said in Postfix problem receiving email to relay:
maillog and messages should cover anything likely to have happened.
No package updates?
nope.
[root@relay01 ~]# yum update Loaded plugins: fastestmirror Loading mirror speeds from cached hostfile * base: mirror.team-cymru.org * extras: mirror.compevo.com * updates: repos.lax.quadranet.com No packages marked for update
Sorry, I meant historically, like yesterday before the issue came up. Check the yumlog.
March 4th was the last update.
Mar 04 09:11:26 Updated: systemd-libs.x86_64 219-30.el7_3.7 Mar 04 09:11:27 Updated: libgudev1.x86_64 219-30.el7_3.7 Mar 04 09:11:27 Updated: audit-libs.x86_64 2.6.5-3.el7_3.1 Mar 04 09:11:32 Updated: systemd.x86_64 219-30.el7_3.7 Mar 04 09:11:32 Updated: systemd-sysv.x86_64 219-30.el7_3.7 Mar 04 09:11:33 Updated: wpa_supplicant.x86_64 1:2.0-21.el7_3 Mar 04 09:11:33 Updated: device-mapper-libs.x86_64 7:1.02.135-1.el7_3.3 Mar 04 09:11:33 Updated: device-mapper.x86_64 7:1.02.135-1.el7_3.3 Mar 04 09:11:33 Updated: device-mapper-event-libs.x86_64 7:1.02.135-1.el7_3.3 Mar 04 09:11:33 Updated: NetworkManager-libnm.x86_64 1:1.4.0-17.el7_3 Mar 04 09:11:34 Updated: device-mapper-event.x86_64 7:1.02.135-1.el7_3.3 Mar 04 09:11:34 Updated: lvm2-libs.x86_64 7:2.02.166-1.el7_3.3 Mar 04 09:11:34 Updated: polkit.x86_64 0.112-11.el7_3 Mar 04 09:11:36 Updated: NetworkManager.x86_64 1:1.4.0-17.el7_3 Mar 04 09:11:37 Updated: NetworkManager-wwan.x86_64 1:1.4.0-17.el7_3 Mar 04 09:11:38 Updated: kernel-tools-libs.x86_64 3.10.0-514.10.2.el7 Mar 04 09:11:38 Updated: python-firewall.noarch 0.4.3.2-8.1.el7_3.2 Mar 04 09:11:53 Updated: selinux-policy.noarch 3.13.1-102.el7_3.15 Mar 04 09:11:53 Updated: firewalld-filesystem.noarch 0.4.3.2-8.1.el7_3.2 Mar 04 09:11:54 Updated: firewalld.noarch 0.4.3.2-8.1.el7_3.2 Mar 04 09:12:12 Updated: selinux-policy-targeted.noarch 3.13.1-102.el7_3.15 Mar 04 09:12:14 Updated: kernel-tools.x86_64 3.10.0-514.10.2.el7 Mar 04 09:12:14 Updated: NetworkManager-bluetooth.x86_64 1:1.4.0-17.el7_3 Mar 04 09:12:14 Updated: NetworkManager-wifi.x86_64 1:1.4.0-17.el7_3 Mar 04 09:12:14 Updated: NetworkManager-tui.x86_64 1:1.4.0-17.el7_3 Mar 04 09:12:14 Updated: NetworkManager-adsl.x86_64 1:1.4.0-17.el7_3 Mar 04 09:12:14 Updated: NetworkManager-team.x86_64 1:1.4.0-17.el7_3 Mar 04 09:12:16 Updated: lvm2.x86_64 7:2.02.166-1.el7_3.3 Mar 04 09:12:16 Updated: audit.x86_64 2.6.5-3.el7_3.1 Mar 04 09:12:17 Updated: microcode_ctl.x86_64 2:2.1-16.3.el7_3 Mar 04 09:12:17 Updated: NetworkManager-glib.x86_64 1:1.4.0-17.el7_3 Mar 04 09:12:18 Updated: python-perf.x86_64 3.10.0-514.10.2.el7 Mar 04 09:12:29 Installed: kernel.x86_64 3.10.0-514.10.2.el7
-
Looks like it started march 2
Mar 1 08:44:04 relay01 postfix/smtpd[4139]: connect from ljcm6040.domain.local[10.201.1.11] Mar 1 08:44:05 relay01 postfix/smtpd[4139]: 04E9EC0C82C7: client=ljcm6040.domain.local[10.201.1.11] Mar 1 08:44:07 relay01 postfix/cleanup[4141]: 04E9EC0C82C7: message-id=<> Mar 1 08:44:08 relay01 postfix/qmgr[1710]: 04E9EC0C82C7: from=<[email protected]>, size=70941, nrcpt=1 (queue active) Mar 1 08:44:08 relay01 postfix/smtpd[4139]: disconnect from ljcm6040.domain.local[10.201.1.11] Mar 1 08:44:11 relay01 postfix/smtp[4142]: 04E9EC0C82C7: to=<[email protected]>, relay=domain-com.mail.protection.out$ Mar 1 08:44:11 relay01 postfix/qmgr[1710]: 04E9EC0C82C7: removed Mar 1 16:13:58 relay01 postfix/postfix-script[1620]: starting the Postfix mail system Mar 1 16:13:58 relay01 postfix/master[1630]: daemon started -- version 2.10.1, configuration /etc/postfix Mar 2 07:11:11 relay01 postfix/smtpd[10917]: connect from nginx.domain.local[10.201.1.18] Mar 2 07:16:11 relay01 postfix/smtpd[10917]: timeout after CONNECT from nginx.domain.local[10.201.1.18] Mar 2 07:16:11 relay01 postfix/smtpd[10917]: disconnect from nginx.domain.local[10.201.1.18]
The yum.log went from Feb 23 to March 4, so I would say nothing there.
Feb 23 04:05:31 Installed: kernel.x86_64 3.10.0-514.6.2.el7 Mar 04 09:11:26 Updated: systemd-libs.x86_64 219-30.el7_3.7
-
Do you have any TLS here? Any cert expire?
-
Not yet for postfix. That is on my to do list, https://mangolassi.it/topic/12545/how-do-i-setup-tls-on-a-postfix-relay
-
Maybe your firewall is blocking connection. Try to stop firewall and check if it works. Maybe you or somebody else changed some rules.
-
The odd part is that the initial connection works, then it drops afterwards.
-
@scottalanmiller said in Postfix problem receiving email to relay:
The odd part is that the initial connection works, then it drops afterwards.
right. that is what has me confused.
-
@triple9 said in Postfix problem receiving email to relay:
Maybe your firewall is blocking connection. Try to stop firewall and check if it works. Maybe you or somebody else changed some rules.
No one else even knows how to handle this.
Related note, I need to get more documentation in place.
-
firewalld has port 25 allowed.
[root@relay01 ~]# firewall-cmd --list-all public (active) target: default icmp-block-inversion: no interfaces: eth0 sources: services: dhcpv6-client ssh ports: 25/tcp protocols: masquerade: no forward-ports: sourceports: icmp-blocks: rich rules:
-
Postfix config has not been touched since setup a year ago.
[root@relay01 ~]# ls -l /etc/postfix/main.cf -rw-r--r--. 1 root root 27281 Mar 14 2016 /etc/postfix/main.cf
-
Is there any filtering in postfix, like amavis, spamassassin?