node side postfix behavior

Jarkko

Member
Mar 6, 2019
13
0
21
49
Hi,

Is it normal that node side postfix is restarting about every 2-3 minutes ?

Mar 6 15:36:09 mgw02 postfix/postfix-script[8667]: stopping the Postfix mail system
Mar 6 15:36:09 mgw02 postfix/master[8606]: terminating on signal 15
Mar 6 15:36:10 mgw02 postfix/postfix-script[8827]: starting the Postfix mail system
Mar 6 15:36:10 mgw02 postfix/master[8829]: daemon started -- version 3.1.9, configuration /etc/postfix
Mar 6 15:36:34 mgw02 pmgpolicy[902]: starting policy database maintainance (greylist, rbl)
Mar 6 15:36:34 mgw02 pmgpolicy[902]: end policy database maintainance (25 ms, 4 ms)
Mar 6 15:37:21 mgw02 pmg-smtp-filter[4000]: starting database maintainance
Mar 6 15:37:21 mgw02 pmg-smtp-filter[4000]: end database maintainance (20 ms)
Mar 6 15:38:08 mgw02 postfix/postfix-script[8884]: stopping the Postfix mail system
Mar 6 15:38:08 mgw02 postfix/master[8829]: terminating on signal 15
Mar 6 15:38:08 mgw02 postfix/postfix-script[9044]: starting the Postfix mail system
Mar 6 15:38:08 mgw02 postfix/master[9046]: daemon started -- version 3.1.9, configuration /etc/postfix
Mar 6 15:38:44 mgw02 pmgpolicy[902]: starting policy database maintainance (greylist, rbl)
Mar 6 15:38:44 mgw02 pmgpolicy[902]: end policy database maintainance (23 ms, 3 ms)
Mar 6 15:39:21 mgw02 pmg-smtp-filter[4000]: starting database maintainance
Mar 6 15:39:21 mgw02 pmg-smtp-filter[4000]: end database maintainance (16 ms)
Mar 6 15:40:09 mgw02 postfix/postfix-script[9102]: stopping the Postfix mail system
Mar 6 15:40:09 mgw02 postfix/master[9046]: terminating on signal 15
Mar 6 15:40:10 mgw02 postfix/postfix-script[9261]: starting the Postfix mail system
Mar 6 15:40:10 mgw02 postfix/master[9263]: daemon started -- version 3.1.9, configuration /etc/postfix
 
syslog is fine, i think

Mar 6 15:36:06 mgw02 pmgmirror[901]: starting cluster syncronization
Mar 6 15:36:10 mgw02 pmgmirror[901]: cluster syncronization finished (0 errors, 3.15 seconds (files 0.22, database 2.67, config 0.26))
Mar 6 15:36:34 mgw02 pmgpolicy[902]: starting policy database maintainance (greylist, rbl)
Mar 6 15:36:34 mgw02 pmgpolicy[902]: end policy database maintainance (25 ms, 4 ms)
Mar 6 15:37:21 mgw02 pmg-smtp-filter[4000]: starting database maintainance
Mar 6 15:37:21 mgw02 pmg-smtp-filter[4000]: end database maintainance (20 ms)
Mar 6 15:37:23 mgw02 pmgdaemon[923]: successful auth for user 'root@pam'
Mar 6 15:38:06 mgw02 pmgmirror[901]: starting cluster syncronization
Mar 6 15:38:08 mgw02 pmgmirror[901]: cluster syncronization finished (0 errors, 2.74 seconds (files 0.18, database 2.30, config 0.27))
Mar 6 15:38:44 mgw02 pmgpolicy[902]: starting policy database maintainance (greylist, rbl)
Mar 6 15:38:44 mgw02 pmgpolicy[902]: end policy database maintainance (23 ms, 3 ms)
Mar 6 15:39:21 mgw02 pmg-smtp-filter[4000]: starting database maintainance
Mar 6 15:39:21 mgw02 pmg-smtp-filter[4000]: end database maintainance (16 ms)
Mar 6 15:40:06 mgw02 pmgmirror[901]: starting cluster syncronization
Mar 6 15:40:10 mgw02 pmgmirror[901]: cluster syncronization finished (0 errors, 3.20 seconds (files 0.23, database 2.71, config 0.27))
Mar 6 15:40:54 mgw02 pmgpolicy[902]: starting policy database maintainance (greylist, rbl)
Mar 6 15:40:54 mgw02 pmgpolicy[902]: end policy database maintainance (21 ms, 4 ms)
Mar 6 15:41:22 mgw02 pmg-smtp-filter[4000]: starting database maintainance
Mar 6 15:41:22 mgw02 pmg-smtp-filter[4000]: end database maintainance (13 ms)
Mar 6 15:41:47 mgw02 pmgpolicy[5591]: reloading configuration Proxmox_ruledb
 
This is what i've found from journalctl, it seems that postfix is terminating right after cluster sync is starting

Mar 06 20:30:38 mgw02 pmgmirror[958]: starting cluster syncronization
Mar 06 20:30:41 mgw02 systemd[1]: Stopping Postfix Mail Transport Agent (instance -)...
Mar 06 20:32:38 mgw02 pmgmirror[958]: starting cluster syncronization
Mar 06 20:32:40 mgw02 systemd[1]: Stopping Postfix Mail Transport Agent (instance -)...
Mar 06 20:36:38 mgw02 pmgmirror[958]: starting cluster syncronization
Mar 06 20:36:40 mgw02 systemd[1]: Stopping Postfix Mail Transport Agent (instance -)...
Mar 06 20:38:38 mgw02 pmgmirror[958]: starting cluster syncronization
Mar 06 20:38:40 mgw02 systemd[1]: Stopping Postfix Mail Transport Agent (instance -)...
 
and from the master and node side at the same time (IP and key "removed" from this post)

node mgw02

Mar 06 21:08:42 mgw02 pmgmirror[958]: starting cluster syncronization
Mar 06 21:08:45 mgw02 systemd[1]: Stopping Postfix Mail Transport Agent (instance -)...
Mar 06 21:08:45 mgw02 postfix/postfix-script[5970]: stopping the Postfix mail system
Mar 06 21:08:45 mgw02 postfix/master[5917]: terminating on signal 15
Mar 06 21:08:45 mgw02 systemd[1]: Stopped Postfix Mail Transport Agent (instance -).
Mar 06 21:08:45 mgw02 systemd[1]: Starting Postfix Mail Transport Agent (instance -)...
Mar 06 21:08:45 mgw02 postfix/postfix-script[6129]: starting the Postfix mail system
Mar 06 21:08:45 mgw02 postfix/master[6131]: daemon started -- version 3.1.9, configuration /etc/postfix
Mar 06 21:08:45 mgw02 systemd[1]: Started Postfix Mail Transport Agent (instance -).
Mar 06 21:08:45 mgw02 pmgmirror[958]: cluster syncronization finished (0 errors, 3.09 seconds (files 0.23, database 2.60, config 0.26))

master mgw01

Mar 06 21:08:43 mgw01 sshd[2840]: Accepted publickey for root from xx.xx.xx.xx port 46820 ssh2: RSA SHA256:XXXXXXXXXXXXXXXXXXXX
Mar 06 21:08:43 mgw01 sshd[2840]: pam_unix(sshd:session): session opened for user root by (uid=0)
Mar 06 21:08:43 mgw01 systemd[1]: Started Session 46 of user root.
Mar 06 21:08:43 mgw01 systemd-logind[459]: New session 46 of user root.
Mar 06 21:08:43 mgw01 sshd[2840]: Received disconnect from xx.xx.xx.xx port 46820:11: disconnected by user
Mar 06 21:08:43 mgw01 sshd[2840]: Disconnected from xx.xx.xx.xx port 46820
Mar 06 21:08:43 mgw01 sshd[2840]: pam_unix(sshd:session): session closed for user root
Mar 06 21:08:43 mgw01 systemd-logind[459]: Removed session 46.
Mar 06 21:08:43 mgw01 sshd[2874]: Accepted publickey for root from xx.xx.xx.xx port 46824 ssh2: RSA SHA256:XXXXXXXXXXXXXXXXXXXX
Mar 06 21:08:43 mgw01 sshd[2874]: pam_unix(sshd:session): session opened for user root by (uid=0)
Mar 06 21:08:43 mgw01 systemd[1]: Started Session 47 of user root.
Mar 06 21:08:43 mgw01 systemd-logind[459]: New session 47 of user root.
Mar 06 21:08:43 mgw01 sshd[2874]: Received disconnect from xx.xx.xx.xx port 46824:11: disconnected by user
Mar 06 21:08:43 mgw01 sshd[2874]: Disconnected from xx.xx.xx.xx port 46824
Mar 06 21:08:43 mgw01 sshd[2874]: pam_unix(sshd:session): session closed for user root
Mar 06 21:08:43 mgw01 systemd-logind[459]: Removed session 47.
 
We only restart postfix if there are configuration or rule database changes. Maybe you change something on a regular interval?
 
ok, but i'm not changing a bit, but i checked postfix files and noticed this one

master: Mar 6 22:05 main.cf
node: Mar 7 07:31 main.cf

node is updating that file for some reason
 
I compared those files and only these lines are differend

myhostname =
mynetworks =
 
hm - sounds a bit odd indeed.
could you please post the (redacted) output of `pmgconfig dump`
(please leave the mynetworks line as pristine as possible (i.e. if you have public ips inside mask the first 2 octets))
 
Hi, it was this line in main.cf.in template file:
mynetworks = [% postfix.mynetworks %]

It forced both master and node side servers to use their own IP:s + my trusted networks from the gui so the loop was ready
as there where difference in that main.cf file

What i did was that i removed my networks from gui and edit that config line in main.cf.in template file by hand so it's working now.
Now it's something like this:
mynetworks = 127.0.0.0/8 [::1]/128 xx.xx.xx.xx/32 xx.xx.xx.xx/32
where xx is SMTP servers.

Now the both servers are in sync and working smoothly
 
* don't quite understand where the loop comes in here?
* anyways if you adapt the templates make sure to copy them to '/etc/pmg/templates' as described in the admin-guide - otherwise your changes will get lost upon upgrading
 
Hi, yes i edit templates in /etc/pmg/templates folder

This is what i've noticed if the line "mynetworks = [% postfix.mynetworks %]" is in original state in main.cf.in template file
and there is no any trusted networks added.

Result:

master: /etc/postfix/main.cf file
mynetworks = 127.0.0.0/8 [::1]/128 xx.xxx.217.30/32

node: /etc/postfix/main.cf file
mynetworks = 127.0.0.0/8 [::1]/128 xx.xxx.216.222/32

And for some reason the node side server starts looping postfix up and down.
Is it because that line is differend ? I don't know..
Why it doesn't loop when the line "myhostname = [% dns.hostname %].[% dns.domain %]" is different too with a good reason though.

Any way, it work fine if i change the line "mynetworks = [% postfix.mynetworks %]" to "mynetworks = 127.0.0.0/8 [::1]/128"

Br,
Jarkko
 

About

The Proxmox community has been around for many years and offers help and support for Proxmox VE, Proxmox Backup Server, and Proxmox Mail Gateway.
We think our community is one of the best thanks to people like you!

Get your subscription!

The Proxmox team works very hard to make sure you are running the best software and getting stable updates and security enhancements, as well as quick enterprise support. Tens of thousands of happy customers have a Proxmox subscription. Get yours easily in our online shop.

Buy now!