Score:2

Different postfix logfile format when logging to separate file (maillog_file)

gh flag

In order to separate the mail logs from the general system logs, I added this line to /etc/postfix/main.cf

maillog_file = /var/log/postfix.log

As expected, a file /var/log/postfix.log is created, and there are no more postfix entries in the var/log/syslog. Unfortunately, it seems that this will also change the contents of the log entries. This is what I get in the postfix.log (changed my original domain name against example.com here)

May 23 17:33:15 example postfix/qmgr[662299]: E7DB742646: from=<[email protected]>, size=549252, nrcpt=1 (queue active)
May 23 17:33:15 example postfix/qmgr[662299]: D7DA646E85: removed

When changing it back (and I changed back and forth several times to be sure), and after sending the same email again, I get this in syslog.

May 23 17:33:52 example2020 postfix/smtp[664151]: DE7EA4265D: to=<[email protected]>, relay=mail.example.com[11.111.11.111]:25, delay=1.7, delays=0.07/0.02/0.11/1.5, dsn=2.0.0,     status=sent (250 2.0.0 Ok: queued as 1BC7874B3A)
May 23 17:33:52 example2020 postfix/qmgr[664141]: DE7EA4265D: removed

Obviously, there are a lot of differences. First, a different server name is given after the date (example is set in /etc/mailname, example2020 is specified in /etc/hostname). Second, only the postfix/qmgr entries are logged, but not the postfix/smtp that contain additional information. The same is true for the var/log/mail.log that does not receive these entries any more.

So, here are two question...

(1) Why does postfix (mail_version = 3.4.13) log different information (no more postfix/smtp) as soon as I specify a maillog_file?

(2) Any ideas how to tell postfix that I want my postfix/smtp information back?

Postfix Configuration

$ postconf -n

alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
append_dot_mydomain = no
biff = no
bounce_queue_lifetime = 24h
compatibility_level = 2
home_mailbox = Maildir/
inet_interfaces = all
inet_protocols = all
mailbox_size_limit = 0
maillog_file = /var/log/postfix.log   # This is the trouble maker
maximal_queue_lifetime = 36h
message_size_limit = 67108864
milter_default_action = accept
milter_protocol = 6
mydestination = example2020   # Host name replaced by "example"
myhostname = example.com
mynetworks = 127.0.0.0/8 [::ffff:127.0.0.0]/104 [::1]/128
myorigin = /etc/mailname
non_smtpd_milters = inet:localhost:8892
readme_directory = no
recipient_delimiter = +
relayhost =
sender_canonical_maps = hash:/etc/postfix/senders
smtp_bind_address = 11.111.11.111
smtp_bind_address6 = 2a02:xxxx:0:xxxx::xx
smtp_destination_concurrency_limit = 3
smtp_tls_CApath = /etc/ssl/certs
smtp_tls_cert_file = /var/www/ssl/example.cert
smtp_tls_key_file = /var/www/ssl/example.key
smtp_tls_security_level = may
smtp_tls_session_cache_database = btree:${data_directory}/smtp_scache
smtpd_banner = $myhostname ESMTP $mail_name (Ubuntu)
smtpd_milters = inet:localhost:8892  # This one is for OpenDKIM
smtpd_relay_restrictions = permit_mynetworks permit_sasl_authenticated defer_unauth_destination
smtpd_sasl_security_options = noanonymous
smtpd_tls_cert_file = /var/www/ssl/example.cert
smtpd_tls_exclude_ciphers = ECDHE-RSA-RC4-SHA
smtpd_tls_key_file = /var/www/ssl/example.key
smtpd_tls_mandatory_ciphers = high
smtpd_tls_mandatory_exclude_ciphers = ECDHE-RSA-RC4-SHA
smtpd_tls_mandatory_protocols = !SSLv2, !SSLv3
smtpd_tls_security_level = may
smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache
smtpd_use_tls = yes
tls_high_cipherlist = EDH+CAMELLIA:EDH+aRSA:EECDH+aRSA+AESGCM:EECDH+aRSA+SHA384:EECDH+aRSA+SHA256:EECDH:+CAMELLIA256:+AES256:+CAMELLIA128:+AES128:+SSLv3:!aNULL:!eNULL:!LOW:!3DES:!MD5:!EXP:!PSK:!DSS:!RC4:!SEED:!ECDSA:CAMELLIA256-SHA:AES256-SHA:CAMELLIA128-SHA:AES128-SHA
tls_ssl_options = NO_COMPRESSION
virtual_alias_maps = hash:/etc/postfix/virtual


$ postconf -M

smtp       inet  n       -       y       -       -       smtpd
pickup     unix  n       -       y       60      1       pickup
cleanup    unix  n       -       y       -       0       cleanup
qmgr       unix  n       -       n       300     1       qmgr
tlsmgr     unix  -       -       y       1000?   1       tlsmgr
rewrite    unix  -       -       y       -       -       trivial-rewrite
bounce     unix  -       -       y       -       0       bounce
defer      unix  -       -       y       -       0       bounce
trace      unix  -       -       y       -       0       bounce
verify     unix  -       -       y       -       1       verify
flush      unix  n       -       y       1000?   0       flush
proxymap   unix  -       -       n       -       -       proxymap
proxywrite unix  -       -       n       -       1       proxymap
smtp       unix  -       -       y       -       -       smtp
relay      unix  -       -       y       -       -       smtp -o syslog_name=postfix/$service_name
showq      unix  n       -       y       -       -       showq
error      unix  -       -       y       -       -       error
retry      unix  -       -       y       -       -       error
discard    unix  -       -       y       -       -       discard
local      unix  -       n       n       -       -       local
virtual    unix  -       n       n       -       -       virtual
lmtp       unix  -       -       y       -       -       lmtp
anvil      unix  -       -       y       -       1       anvil
scache     unix  -       -       y       -       1       scache
postlog    unix-dgram n  -       n       -       1       postlogd
maildrop   unix  -       n       n       -       -       pipe flags=DRhu user=vmail argv=/usr/bin/maildrop -d ${recipient}
uucp       unix  -       n       n       -       -       pipe flags=Fqhu user=uucp argv=uux -r -n -z -a$sender - $nexthop!rmail ($recipient)
ifmail     unix  -       n       n       -       -       pipe flags=F user=ftn argv=/usr/lib/ifmail/ifmail -r $nexthop ($recipient)
bsmtp      unix  -       n       n       -       -       pipe flags=Fq. user=bsmtp argv=/usr/lib/bsmtp/bsmtp -t$nexthop -f$sender $recipient
scalemail-backend unix - n       n       -       2       pipe flags=R user=scalemail argv=/usr/lib/scalemail/bin/scalemail-store ${nexthop} ${user} ${extension}
mailman    unix  -       n       n       -       -       pipe flags=FR user=list argv=/usr/lib/mailman/bin/postfix-to-mailman.py ${nexthop} ${user}
anx avatar
fr flag
anx
I *highly* recommend leaving logging formatting and decisions to your system logging daemon (rsyslog, systemd-journal, ..) and configuring tweaks there or in tools parsing their files. I *suspect* your problem lies with conflicting overrides rendering your alternate log destination ineffective, so please [share](https://serverfault.com/posts/1101621/edit) your configuration as [recommended in the tag](https://serverfault.com/questions/tagged/postfix).
gh flag
Thanks for the hint about tag recommendations! I have added the configuration above. Regardings the recommendation to leave logging to the daemon ... I would, if there were not regulary reasons that would require me to store the mail logs (that include email addresses, i.e., personal data) separately from general system logs.
anx avatar
fr flag
anx
Have you fully restarted postfix? Because logging is configured via passed down ENV, a partial reload might create the appearance of postfix using new setting, but only because *some* of the services start logging there.
gh flag
The restart is a good idea, but I do not think that it caused the issue: The server had done a full reboot before I had observed the "missing" log entries for postfix/smtp. After commenting out the `maillog_file` option and doing a `systemctl restart postfix`, new postfix/smtp entries were written to the `syslog` for new mails. And no more were written after re-enabling the option plus `systemctl restart postfix`.
Score:1
in flag

In order to separate the mail logs from the general system logs, I added this line to /etc/postfix/main.cf

This is not the best way, as @anx has commented, highly recommend leaving logging formatting and decisions to your system logging daemon.

For you information rsylogd already gathers postfix logs from the /var/spool/postfix/dev/log socket file (see inside /etc/rsyslog.d/postfix.conf) and this remains the cleanest way.

Have a look at your /etc/rsyslog.conf and there must be a line that looks like this:

*.*;mail,auth,authpriv.none     -/var/log/syslog

In order to tell rsyslogd not to write mail related log entries inside /var/log/syslog, change it to (note the .none):

*.*;mail.none,auth,authpriv.none        -/var/log/syslog

There is already a line that tells it to log all mail related things to /var/log/mail.log (change it to any file if you want) further down so you do not need to edit your postfix configuration file:

mail.*              -/var/log/mail.log

To answer your questions:

(1) Why does postfix (mail_version = 3.4.13) log different information (no more postfix/smtp) as soon as I specify a maillog_file?

Your master.cf tells us you are using postfix in chrooted mode. But your qmgr daemon is not chrooted so it can basically write in any log file unlike your smtp daemon.

(2) Any ideas how to tell postfix that I want my postfix/smtp information back?

Your information is not gone but many of your daemons cannot break the chroot so they cannot directly write in /var/log/postfix.log as you intend. An option would be un-chrooting them by switching the chroot column to n in your master.cf but again, no sane people would recommend that.

CONCLUSION: Your best and safest option is tweaking your rsylogd configuration as described earlier.

anx avatar
fr flag
anx
This explains how to do it with rsyslog, but I don't think this explains why the original approach does not work. Check the `postlog unix-dgram` line in `master.cf`, that looks correct and should forward logging for chrooted services.
anx avatar
fr flag
anx
Postfix `3.4.13` sounds like a version someone using a Debian(-derivative) would use (someone directly tracking upstream stable 3.4.x would use `3.4.24` by now), so while logs might be passed to `rsyslogd`, there would still exist additional persistent log storage via `systemd-journald`.
gh flag
Very elaborate answer, thank you! For those seeking the same answer, I would like to ad that the respective line may be found in `/etc/rsyslog.d/50-default.conf` and that there may not be an explicit `mail`, but adding `mail.none` in the line with `-/var/log/syslog` works exactly as specified in the answer.
mangohost

Post an answer

Most people don’t grasp that asking a lot of questions unlocks learning and improves interpersonal bonding. In Alison’s studies, for example, though people could accurately recall how many questions had been asked in their conversations, they didn’t intuit the link between questions and liking. Across four studies, in which participants were engaged in conversations themselves or read transcripts of others’ conversations, people tended not to realize that question asking would influence—or had influenced—the level of amity between the conversationalists.