node side postfix behavior

Jarkko

Active Member
Mar 6, 2019
13
0
41
50
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