Hello!
Ok, here comes the info. I hope it will be useful:
---------------------------postconf -n-------------------------
alias_database =
alias_maps =
append_dot_mydomain = yes
biff = no
broken_sasl_auth_clients = yes
config_directory = /etc/postfix
debugger_command = PATH=/bin:/usr/bin:/usr/local/bin; (strace -p
$process_id 2>&1 | logger -p mail.info) & sleep 5
deliver_lock_attempts = 40
deliver_lock_delay = 5s
inet_interfaces = all
local_recipient_maps =
local_transport = error:5.1.2 Mailbox unavailable
mydestination =
mydomain = irf.se
myhostname = outgoingmail-2.irf.se
myorigin = $mydomain
readme_directory = no
relay_domains = irf.se
smtp_use_tls = yes
smtpd_banner = $myhostname ESMTP $mail_name (Ubuntu)
smtpd_client_restrictions = permit_sasl_authenticated
smtpd_relay_restrictions = permit_sasl_authenticated,
reject_unauth_destination
smtpd_sasl_auth_enable = yes
smtpd_sasl_path = smtpd
smtpd_sasl_security_options = noanonymous, noplaintext
smtpd_sasl_tls_security_options = noanonymous
smtpd_tls_CAfile = /etc/ssl/certs/chain-9466--.irf.se.pem
smtpd_tls_auth_only = yes
smtpd_tls_cert_file = /etc/ssl/certs/cert-9466--.irf.se.pem
smtpd_tls_key_file = /etc/ssl/private/wildcard.irf.se.key
smtpd_use_tls = yes
tls_random_source = dev:/dev/urandom
transport_maps = hash:/etc/postfix/transport
-------------------------------------------------------------------------
----------------------------postconf -Mf---------------------------------
smtp inet n - - - - smtpd
-o smtpd_enforce_tls=yes
-o smtpd_sasl_auth_enable=yes
-o syslog_name=postfix/smtp
-o
smtpd_relay_restrictions=permit_sasl_authenticated,reject_unauth_destination,reject_unlisted_recipient
submission inet n - - - - smtpd
-o smtpd_enforce_tls=yes
-o smtpd_sasl_auth_enable=yes
-o syslog_name=postfix/submission
-o
smtpd_relay_restrictions=permit_sasl_authenticated,reject_unauth_destination,reject_unlisted_recipient
smtps inet n - - - - smtpd
-o smtpd_tls_wrappermode=yes
-o smtpd_sasl_auth_enable=yes
-o syslog_name=postfix/smtps
-o
smtpd_relay_restrictions=permit_sasl_authenticated,reject_unauth_destination,reject_unlisted_recipient
pickup unix n - - 60 1 pickup
cleanup unix n - - - 0 cleanup
qmgr unix n - n 300 1 qmgr
tlsmgr unix - - - 1000? 1 tlsmgr
rewrite unix - - - - - trivial-rewrite
bounce unix - - - - 0 bounce
defer unix - - - - 0 bounce
trace unix - - - - 0 bounce
verify unix - - - - 1 verify
flush unix n - - 1000? 0 flush
proxymap unix - - n - - proxymap
proxywrite unix - - n - 1 proxymap
smtp unix - - - - - smtp
relay unix - - - - - smtp
showq unix n - - - - showq
error unix - - - - - error
retry unix - - - - - error
discard unix - - - - - discard
local unix - n n - - local
virtual unix - n n - - virtual
lmtp unix - - - - - lmtp
anvil unix - - - - 1 anvil
scache unix - - - - 1 scache
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}
outgoingmail inet n - n - - smtpd
-o smtpd_enforce_tls=yes
-o smtpd_sasl_auth_enable=yes
-o smtpd_client_restrictions=permit_mynetworks
-o
mynetworks=127.0.0.0/8,[::ffff:127.0.0.0]/104,[::1]/128,192.71.13.58/32,192.71.13.21/32,[2001:6b0:27::]/48
-o maps_rbl_domains=
-o content_filter=
-------------------------------------------------------------------------
Logging without debug for mail from
ma...@irf.se->nonexistingm...@telia.com (bcc to ma...@irf.se) (not
working).
------------------------------------------------------------------------------
2015-02-13T23:41:27+02:00 outgoingmail-2
postfix/submission/smtpd[10209]: connect from
c83-254-49-236.bredband.comhem.se[83.254.49.236]
2015-02-13T23:41:28+02:00 outgoingmail-2
postfix/submission/smtpd[10209]: 61BDCBEF4:
client=c83-254-49-236.bredband.comhem.se[83.254.49.236],
sasl_method=PLAIN, sasl_username=matsl
2015-02-13T23:41:28+02:00 outgoingmail-2 postfix/cleanup[10212]:
61BDCBEF4: message-id=<54de7d98.1000...@irf.se>
2015-02-13T23:41:28+02:00 outgoingmail-2 postfix/qmgr[10071]:
61BDCBEF4: from=<ma...@irf.se>, size=571, nrcpt=2 (queue active)
2015-02-13T23:41:28+02:00 outgoingmail-2
postfix/submission/smtpd[10209]: disconnect from
c83-254-49-236.bredband.comhem.se[83.254.49.236]
2015-02-13T23:41:28+02:00 outgoingmail-2 postfix/smtp[10213]:
61BDCBEF4: to=<ma...@irf.se>, relay=mail.irf.se[193.10.33.138]:60180,
delay=0.34, delays=0.19/0.01/0.02/0.12, dsn=2.0.0, status=sent (250
2.0.0 Ok: queued as D948E200D2)
2015-02-13T23:41:33+02:00 outgoingmail-2 postfix/smtp[10214]:
61BDCBEF4: to=<nonexistingm...@telia.com>,
relay=mail.telia.com[62.20.233.128]:25, delay=5.4,
delays=0.19/0.01/0.15/5.1, dsn=4.3.0, status=deferred (bounce or trace
service failure)
2015-02-13T23:41:33+02:00 outgoingmail-2 postfix/cleanup[10212]:
C1960BEF7: message-id=<20150213224133.c1960b...@outgoingmail-2.irf.se>
2015-02-13T23:41:33+02:00 outgoingmail-2 postfix/bounce[10215]:
61BDCBEF4: sender non-delivery notification: C1960BEF7
2015-02-13T23:41:33+02:00 outgoingmail-2 postfix/qmgr[10071]:
C1960BEF7: from=<>, size=2531, nrcpt=1 (queue active)
2015-02-13T23:41:33+02:00 outgoingmail-2 postfix/qmgr[10071]:
61BDCBEF4: status=deferred (bounce failed)
2015-02-13T23:41:33+02:00 outgoingmail-2 postfix/smtp[10213]:
C1960BEF7: to=<ma...@irf.se>,
relay=mail.irf.se[2001:6b0:27:ff::c]:60180, delay=0.13,
delays=0/0/0.01/0.11, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as
1DFF4200D2)
2015-02-13T23:41:33+02:00 outgoingmail-2 postfix/qmgr[10071]:
C1960BEF7: removed
--------------------------------------------------------------------------------
Logging with debug of bounce process for mail from
ma...@irf.se->nonexistingm...@telia.com (bcc to ma...@irf.se) (working).
--------------------------------------------------------------------------------
2015-02-13T23:47:07+02:00 outgoingmail-2
postfix/submission/smtpd[10235]: connect from
c83-254-49-236.bredband.comhem.se[83.254.49.236]^M
2015-02-13T23:47:07+02:00 outgoingmail-2
postfix/submission/smtpd[10235]: 9BE77BF04:
client=c83-254-49-236.bredband.comhem.se[83.254.49.236],
sasl_method=PLAIN, sasl_username=matsl^M
2015-02-13T23:47:07+02:00 outgoingmail-2 postfix/cleanup[10239]:
9BE77BF04: message-id=<54de7eec.5060...@irf.se>^M
2015-02-13T23:47:07+02:00 outgoingmail-2 postfix/qmgr[10234]:
9BE77BF04: from=<ma...@irf.se>, size=571, nrcpt=2 (queue active)^M
2015-02-13T23:47:07+02:00 outgoingmail-2
postfix/submission/smtpd[10235]: disconnect from
c83-254-49-236.bredband.comhem.se[83.254.49.236]^M
2015-02-13T23:47:07+02:00 outgoingmail-2 postfix/smtp[10241]:
9BE77BF04: to=<ma...@irf.se>,
relay=mail.irf.se[2001:6b0:27:ff::c]:60180, delay=0.34,
delays=0.21/0/0.01/0.11, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued
as 1EE4E200D2)^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: epoll_wait(9,
{{EPOLLIN, {u32=6, u64=9327653705362702342}}}, 100, 100000) = 1^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: accept(6, 0, NULL)
= 12^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: flock(8, LOCK_UN)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: fcntl(12, F_GETFL)
= 0x2 (flags O_RDWR)^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: fcntl(12, F_SETFL,
O_RDWR) = 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: fcntl(12, F_GETFD)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: fcntl(12, F_SETFD,
FD_CLOEXEC) = 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: write(5,
"\2(\0\0\37\0\0\0\0\0\0\0", 12) = 12^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: poll([{fd=12,
events=POLLIN}], 1, 3600000) = 1 ([{fd=12, revents=POLLIN}])^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: read(12,
"nrequest\0000\0flags\0000\0queue_id\0009BE7"..., 4096) = 467^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root:
open("bounce/9BE77BF04", O_WRONLY|O_CREAT|O_APPEND, 0600) = 13^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: flock(13,
LOCK_EX|LOCK_NB) = 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: lseek(13, 0, SEEK_END)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: write(13,
"\n<nonexistingm...@telia.com>: ho"..., 523) = 523^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: fsync(13)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: close(13)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: poll([{fd=12,
events=POLLOUT}], 1, 3600000) = 1 ([{fd=12, revents=POLLOUT}])^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: write(12,
"status\0000\0\0", 10) = 10^M
2015-02-13T23:47:12+02:00 outgoingmail-2 postfix/smtp[10240]:
9BE77BF04: to=<nonexistingm...@telia.com>,
relay=mail.telia.com[62.20.233.128]:25, delay=5.3,
delays=0.21/0/0.06/5.1, dsn=5.0.0, status=bounced (host
mail.telia.com[62.20.233.128] said: 550 RCPT
TO:<nonexistingm...@telia.com> User unknown (in reply to RCPT TO
command))^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: close(12)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: write(5,
"\2(\0\0\37\0\0\0\1\0\0\0", 12) = 12^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: alarm(0)
= 5915^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: flock(8, LOCK_EX)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: alarm(6000)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: epoll_wait(9,
{{EPOLLIN, {u32=6, u64=9327653705362702342}}}, 100, 100000) = 1^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: accept(6, 0, NULL)
= 12^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: flock(8, LOCK_UN)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: fcntl(12, F_GETFL)
= 0x2 (flags O_RDWR)^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: fcntl(12, F_SETFL,
O_RDWR) = 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: fcntl(12, F_GETFD)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: fcntl(12, F_GETFD)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: fcntl(12, F_SETFD,
FD_CLOEXEC) = 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: write(5,
"\2(\0\0\37\0\0\0\0\0\0\0", 12) = 12^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: poll([{fd=12,
events=POLLIN}], 1, 3600000) = 1 ([{fd=12, revents=POLLIN}])^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: read(12,
"nrequest\0001\0flags\0000\0queue_name\0ac"..., 4096) = 112^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root:
open("bounce/9BE77BF04", O_RDONLY) = 13^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root:
open("active/9BE77BF04", O_RDWR) = 14^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: flock(14,
LOCK_SH|LOCK_NB) = 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: read(14, "CO
571 84"..., 4096) = 1418^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: socket(PF_LOCAL,
SOCK_STREAM, 0) = 15^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: fcntl(15, F_GETFL)
= 0x2 (flags O_RDWR)^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: fcntl(15, F_SETFL,
O_RDWR) = 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: connect(15,
{sa_family=AF_LOCAL, sun_path="public/cleanup"}, 110) = 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: stat("/etc/localtime",
{st_mode=S_IFREG|0644, st_size=1892, ...}) = 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: poll([{fd=15,
events=POLLIN}], 1, 3600000) = 1 ([{fd=15, revents=POLLIN}])^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: read(15,
"queue_id\0E87B0BF06\0\0", 4096) = 20^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: lseek(13, 0, SEEK_SET)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: read(13,
"\n<nonexistingm...@telia.com>: ho"..., 4096) = 523^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: read(13, "", 4096)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: stat("/etc/localtime",
{st_mode=S_IFREG|0644, st_size=1892, ...}) = 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: lseek(13, 0, SEEK_SET)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: read(13,
"\n<nonexistingm...@telia.com>: ho"..., 4096) = 523^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: read(13, "", 4096)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: lseek(14, 843,
SEEK_SET) = 843^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: read(14, "NRReceived:
from [192.168.1.131]"..., 4096) = 575^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: poll([{fd=15,
events=POLLOUT}], 1, 3600000) = 1 ([{fd=15, revents=POLLOUT}])^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: write(15,
"flags\00032\0\0T\0211423867632 952105A\30l"..., 2554) = 2554^M
2015-02-13T23:47:12+02:00 outgoingmail-2 postfix/cleanup[10239]:
E87B0BF06: message-id=<20150213224712.e87b0b...@outgoingmail-2.irf.se>^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: poll([{fd=15,
events=POLLIN}], 1, 3600000) = 1 ([{fd=15, revents=POLLIN|POLLHUP}])^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: read(15,
"status\0000\0reason\0\0\0", 4096) = 18^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: close(15)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 postfix/bounce[10242]:
9BE77BF04: sender non-delivery notification: E87B0BF06^M
2015-02-13T23:47:12+02:00 outgoingmail-2 postfix/qmgr[10234]:
E87B0BF06: from=<>, size=2531, nrcpt=1 (queue active)^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: sendto(7, "<22>Feb 13
23:47:12 postfix/boun"..., 97, MSG_NOSIGNAL, NULL, 0) = 97^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root:
unlink("bounce/9BE77BF04") = 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: close(13)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: close(14)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: poll([{fd=12,
events=POLLOUT}], 1, 3600000) = 1 ([{fd=12, revents=POLLOUT}])^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: write(12,
"status\0000\0\0", 10) = 10^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: close(12)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: write(5,
"\2(\0\0\37\0\0\0\1\0\0\0", 12) = 12^M
2015-02-13T23:47:12+02:00 outgoingmail-2 postfix/qmgr[10234]:
9BE77BF04: removed^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: alarm(0)
= 6000^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: flock(8, LOCK_EX)
= 0^M
2015-02-13T23:47:12+02:00 outgoingmail-2 root: alarm(6000)
= 0^M
2015-02-13T23:47:13+02:00 outgoingmail-2 postfix/smtp[10241]:
E87B0BF06: to=<ma...@irf.se>,
relay=mail.irf.se[2001:6b0:27:ff::c]:60180, delay=0.13,
delays=0/0/0.01/0.12, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as
438F8200D2)^M
2015-02-13T23:47:13+02:00 outgoingmail-2 postfix/qmgr[10234]:
E87B0BF06: removed^M
--------------------------------------------------------------------------------
Quoting Wietse Venema <wie...@porcupine.org>:
Mats Luspa:
Thanks for the reply.
I've now looked at the log files and I think this problem has been
from beginning of this server because I started it a few days ago.
Everything work fine when I send to addresses that exists. The problem
is that when I send to addresses that don't exists the bounce doesn't
work properly.
Sorry, at this point I am not looking for an eye witness report
of what you think happens. Instead, I look for first-hand information
from Postfix itself.
Specifically, a complete record of the non-verbose logging for an
entire mail transaction starting with entry into Postfix, that
includes the logging for failed delivery (user unknown), and that
shows the problem with the bounce or trace service.
http://www.postfix.org/DEBUG_README.html#mail has instructions to
anonymize user names (or domains if necessary).
But wait, there is more.
It is also good to provide "postconf -n" output, and if using Postfix
2.9 or later, "postconf -Mf" output, otherwise provide master.cf.
Needless to say, this configuration should match the non-verbose
logging that I asked a few paragraphs ago.
Wietse
