Hi list,
I'm getting this error:
May 12 21:53:15 altair postfix/error[19875]: DB8D1C10BC:
to=<mikes...@john-doe-domain.com>, orig_to=<t...@altair.moofriend.de>,
relay=none, delay=0.3, delays=0.3/0/0/0, dsn=5.1.1, status=bounced (User
unknown in virtual alias table)
and just can't figure out what I'm doing wrong. Had a very similiar setup
working a while back and now I can't figure out what's wrong for the life of
me. But first things first. Let me say that all domains and names in the mail
will be anonymized by a sed script of mine, so they'll all be consistent.
Here's my main.cf:
message_size_limit = 52428800
biff = no
append_dot_mydomain = no
readme_directory = no
smtpd_tls_cert_file=/etc/certificates/postfix.crt
smtpd_tls_key_file=/etc/certificates/postfix.key
smtpd_use_tls=yes
smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache
smtp_tls_session_cache_database = btree:${data_directory}/smtp_scache
myhostname = altair.moofriend.de
alias_maps = hash:/etc/aliases
alias_database = hash:/etc/aliases
myorigin = /etc/mailname
mydestination = localhost.localdomain, localhost, moofriend.de
relayhost =
mynetworks = 127.0.0.0/8 [::ffff:127.0.0.0]/104 [::1]/128
mailbox_size_limit = 0
recipient_delimiter = +
inet_interfaces = all
virtual_alias_domains = moofriend.de, john-doe-domain.com, nextdomain.org,
thirddomain.de, fourthdomain.de, fifthdomain.de, sixthdomain.de
virtual_alias_maps = mysql:/etc/postfix/mysql_virtual.cf
disable_vrfy_command = yes
smtpd_reject_unlisted_sender = yes
smtpd_delay_reject = yes
smtpd_helo_required = no
smtpd_helo_restrictions = reject_non_fqdn_hostname, reject_invalid_hostname,
reject_non_fqdn_sender, reject_non_fqdn_recipient, reject_unknown_sender_domain
smtpd_error_sleep_time = 1s
smtpd_soft_error_limit = 10
smtpd_hard_error_limit = 20
smtpd_sasl_security_options = noanonymous
smtpd_tls_auth_only = yes
smtpd_sasl_local_domain = $myhostname
smtpd_sasl_type = dovecot
smtpd_sasl_path = private/auth
smtpd_sasl_auth_enable = yes
smtpd_sender_restrictions = reject_authenticated_sender_login_mismatch
smtpd_sender_login_maps = mysql:/etc/postfix/mysql_sender_maps.cf
smtpd_recipient_restrictions = permit_sasl_authenticated, permit_mynetworks,
reject_unauth_destination, check_sender_access hash:/etc/postfix/sender_access
maximal_queue_lifetime = 35m
bounce_queue_lifetime = 35m
smtpd_relay_restrictions = permit_sasl_authenticated, permit_mynetworks,
reject_unauth_destination
I'm trying to forward mails that are sent to t...@altair.moofriend.de to a
local drop at mikes...@john-doe-domain.com. That's the dropbox and I wish
postfix would connect to dovecot trying to get the mail in. However, it's not.
It's trying to look up mikes...@john-doe-domain.com again (which isn't in the
virtual table), then fails. Here's the script which I use to drop off a test
mail locally:
#!/bin/bash
msg() {
echo "$1"
sleep 0.1
}
(
msg "MAIL FROM:foo@bar.invalid"
msg "RCPT TO:t...@altair.moofriend.de"
msg "DATA"
echo "Subject: Foo bar test mail"
echo "From: foo@bar.invalid"
echo
echo "This is a test mail."
msg "."
msg "QUIT"
) | nc 127.0.0.1 25
Here's the log:
May 12 21:53:14 altair postfix/smtpd[19866]: connection established
May 12 21:53:14 altair postfix/smtpd[19866]: master_notify: status 0
May 12 21:53:14 altair postfix/smtpd[19866]: name_mask: resource
May 12 21:53:14 altair postfix/smtpd[19866]: name_mask: software
May 12 21:53:14 altair postfix/smtpd[19866]: connect from localhost[127.0.0.1]
May 12 21:53:14 altair postfix/smtpd[19866]: match_list_match: localhost: no
match
May 12 21:53:14 altair postfix/smtpd[19866]: match_list_match: 127.0.0.1: no
match
May 12 21:53:14 altair postfix/smtpd[19866]: match_list_match: localhost: no
match
May 12 21:53:14 altair postfix/smtpd[19866]: match_list_match: 127.0.0.1: no
match
May 12 21:53:14 altair postfix/smtpd[19866]: smtp_stream_setup: maxtime=300
enable_deadline=0
May 12 21:53:14 altair postfix/smtpd[19866]: match_hostname: localhost ~?
127.0.0.0/8
May 12 21:53:14 altair postfix/smtpd[19866]: match_hostaddr: 127.0.0.1 ~?
127.0.0.0/8
May 12 21:53:14 altair postfix/smtpd[19866]: > localhost[127.0.0.1]: 220 Hi
there
May 12 21:53:14 altair postfix/smtpd[19866]: < localhost[127.0.0.1]: MAIL
FROM:foo@bar.invalid
May 12 21:53:14 altair postfix/smtpd[19866]: extract_addr: input:
foo@bar.invalid
May 12 21:53:14 altair postfix/smtpd[19866]: smtpd_check_addr:
addr=foo@bar.invalid
May 12 21:53:14 altair postfix/smtpd[19866]: ctable_locate: move existing entry
key foo@bar.invalid
May 12 21:53:14 altair postfix/smtpd[19866]: extract_addr: in: foo@bar.invalid,
result: foo@bar.invalid
May 12 21:53:14 altair postfix/smtpd[19866]: smtpd_check_rewrite: trying:
permit_inet_interfaces
May 12 21:53:14 altair postfix/smtpd[19866]: permit_inet_interfaces: localhost
127.0.0.1
May 12 21:53:14 altair postfix/smtpd[19866]: fsspace: .: block size 4096,
blocks free 4173316
May 12 21:53:14 altair postfix/smtpd[19866]: smtpd_check_queue: blocks 4096
avail 4173316 min_free 0 msg_size_limit 52428800
May 12 21:53:14 altair postfix/smtpd[19866]: > localhost[127.0.0.1]: 250 2.1.0
Ok
May 12 21:53:14 altair postfix/smtpd[19866]: < localhost[127.0.0.1]: RCPT
TO:t...@altair.moofriend.de
May 12 21:53:14 altair postfix/smtpd[19866]: extract_addr: input:
t...@altair.moofriend.de
May 12 21:53:14 altair postfix/smtpd[19866]: smtpd_check_addr:
addr=t...@altair.moofriend.de
May 12 21:53:14 altair postfix/smtpd[19866]: ctable_locate: move existing entry
key t...@altair.moofriend.de
May 12 21:53:14 altair postfix/smtpd[19866]: extract_addr: in:
t...@altair.moofriend.de, result: t...@altair.moofriend.de
May 12 21:53:14 altair postfix/smtpd[19866]: >>> START Sender address
RESTRICTIONS <<<
May 12 21:53:14 altair postfix/smtpd[19866]: generic_checks:
name=reject_authenticated_sender_login_mismatch
May 12 21:53:14 altair postfix/smtpd[19866]: generic_checks:
name=reject_authenticated_sender_login_mismatch status=0
May 12 21:53:14 altair postfix/smtpd[19866]: >>> END Sender address
RESTRICTIONS <<<
May 12 21:53:14 altair postfix/smtpd[19866]: >>> CHECKING RECIPIENT MAPS <<<
May 12 21:53:14 altair postfix/smtpd[19866]: ctable_locate: move existing entry
key foo@bar.invalid
May 12 21:53:14 altair postfix/smtpd[19866]: maps_find:
recipient_canonical_maps: foo@bar.invalid: not found
May 12 21:53:14 altair postfix/smtpd[19866]: match_string: bar.invalid ~?
localhost.localdomain
May 12 21:53:14 altair postfix/smtpd[19866]: match_string: bar.invalid ~?
localhost
May 12 21:53:14 altair postfix/smtpd[19866]: match_string: bar.invalid ~?
moofriend.de
May 12 21:53:14 altair postfix/smtpd[19866]: match_list_match: bar.invalid: no
match
May 12 21:53:14 altair postfix/smtpd[19866]: maps_find:
recipient_canonical_maps: @bar.invalid: not found
May 12 21:53:14 altair postfix/smtpd[19866]: mail_addr_find: foo@bar.invalid ->
(not found)
May 12 21:53:14 altair postfix/smtpd[19866]: maps_find: canonical_maps:
foo@bar.invalid: not found
May 12 21:53:14 altair postfix/smtpd[19866]: match_string: bar.invalid ~?
localhost.localdomain
May 12 21:53:14 altair postfix/smtpd[19866]: match_string: bar.invalid ~?
localhost
May 12 21:53:14 altair postfix/smtpd[19866]: match_string: bar.invalid ~?
moofriend.de
May 12 21:53:14 altair postfix/smtpd[19866]: match_list_match: bar.invalid: no
match
May 12 21:53:14 altair postfix/smtpd[19866]: maps_find: canonical_maps:
@bar.invalid: not found
May 12 21:53:14 altair postfix/smtpd[19866]: mail_addr_find: foo@bar.invalid ->
(not found)
May 12 21:53:14 altair postfix/smtpd[19866]: dict_mysql_get_active: found
active connection to host 127.0.0.1
May 12 21:53:14 altair postfix/smtpd[19866]: dict_mysql: successful query from
host 127.0.0.1
May 12 21:53:14 altair postfix/smtpd[19866]: dict_mysql_lookup: retrieved 0 rows
May 12 21:53:14 altair postfix/smtpd[19866]: maps_find: virtual_alias_maps:
foo@bar.invalid: not found
May 12 21:53:14 altair postfix/smtpd[19866]: match_string: bar.invalid ~?
localhost.localdomain
May 12 21:53:14 altair postfix/smtpd[19866]: match_string: bar.invalid ~?
localhost
May 12 21:53:14 altair postfix/smtpd[19866]: match_string: bar.invalid ~?
moofriend.de
May 12 21:53:14 altair postfix/smtpd[19866]: match_list_match: bar.invalid: no
match
May 12 21:53:14 altair postfix/smtpd[19866]: dict_mysql_get_active: found
active connection to host 127.0.0.1
May 12 21:53:14 altair postfix/smtpd[19866]: dict_mysql: successful query from
host 127.0.0.1
May 12 21:53:14 altair postfix/smtpd[19866]: dict_mysql_lookup: retrieved 0 rows
May 12 21:53:14 altair postfix/smtpd[19866]: maps_find: virtual_alias_maps:
@bar.invalid: not found
May 12 21:53:14 altair postfix/smtpd[19866]: mail_addr_find: foo@bar.invalid ->
(not found)
May 12 21:53:14 altair postfix/smtpd[19866]: >>> START Recipient address
RESTRICTIONS <<<
May 12 21:53:14 altair postfix/smtpd[19866]: generic_checks:
name=permit_sasl_authenticated
May 12 21:53:14 altair postfix/smtpd[19866]: generic_checks:
name=permit_sasl_authenticated status=0
May 12 21:53:14 altair postfix/smtpd[19866]: generic_checks:
name=permit_mynetworks
May 12 21:53:14 altair postfix/smtpd[19866]: permit_mynetworks: localhost
127.0.0.1
May 12 21:53:14 altair postfix/smtpd[19866]: match_hostname: localhost ~?
127.0.0.0/8
May 12 21:53:14 altair postfix/smtpd[19866]: match_hostaddr: 127.0.0.1 ~?
127.0.0.0/8
May 12 21:53:14 altair postfix/smtpd[19866]: match_list_match:
permit_mynetworks: no match
May 12 21:53:14 altair postfix/smtpd[19866]: generic_checks:
name=permit_mynetworks status=1
May 12 21:53:14 altair postfix/smtpd[19866]: >>> END Recipient address
RESTRICTIONS <<<
May 12 21:53:14 altair postfix/smtpd[19866]: >>> START Recipient address
RESTRICTIONS <<<
May 12 21:53:14 altair postfix/smtpd[19866]: generic_checks:
name=permit_sasl_authenticated
May 12 21:53:14 altair postfix/smtpd[19866]: generic_checks:
name=permit_sasl_authenticated status=0
May 12 21:53:14 altair postfix/smtpd[19866]: generic_checks:
name=permit_mynetworks
May 12 21:53:14 altair postfix/smtpd[19866]: permit_mynetworks: localhost
127.0.0.1
May 12 21:53:14 altair postfix/smtpd[19866]: match_hostname: localhost ~?
127.0.0.0/8
May 12 21:53:14 altair postfix/smtpd[19866]: match_hostaddr: 127.0.0.1 ~?
127.0.0.0/8
May 12 21:53:14 altair postfix/smtpd[19866]: match_list_match:
permit_mynetworks: no match
May 12 21:53:14 altair postfix/smtpd[19866]: generic_checks:
name=permit_mynetworks status=1
May 12 21:53:14 altair postfix/smtpd[19866]: >>> END Recipient address
RESTRICTIONS <<<
May 12 21:53:14 altair postfix/smtpd[19866]: >>> CHECKING RECIPIENT MAPS <<<
May 12 21:53:14 altair postfix/smtpd[19866]: ctable_locate: move existing entry
key t...@altair.moofriend.de
May 12 21:53:14 altair postfix/smtpd[19866]: maps_find:
recipient_canonical_maps: t...@altair.moofriend.de: not found
May 12 21:53:14 altair postfix/smtpd[19866]: maps_find:
recipient_canonical_maps: test: not found
May 12 21:53:14 altair postfix/smtpd[19866]: maps_find:
recipient_canonical_maps: @altair.moofriend.de: not found
May 12 21:53:14 altair postfix/smtpd[19866]: mail_addr_find:
t...@altair.moofriend.de -> (not found)
May 12 21:53:14 altair postfix/smtpd[19866]: maps_find: canonical_maps:
t...@altair.moofriend.de: not found
May 12 21:53:14 altair postfix/smtpd[19866]: maps_find: canonical_maps: test:
not found
May 12 21:53:14 altair postfix/smtpd[19866]: maps_find: canonical_maps:
@altair.moofriend.de: not found
May 12 21:53:14 altair postfix/smtpd[19866]: mail_addr_find:
t...@altair.moofriend.de -> (not found)
May 12 21:53:14 altair postfix/smtpd[19866]: dict_mysql_get_active: found
active connection to host 127.0.0.1
May 12 21:53:14 altair postfix/smtpd[19866]: dict_mysql: successful query from
host 127.0.0.1
May 12 21:53:14 altair postfix/smtpd[19866]: dict_mysql_lookup: retrieved 1 rows
May 12 21:53:14 altair postfix/smtpd[19866]: maps_find: virtual_alias_maps:
mysql:/etc/postfix/mysql_virtual.cf(0,lock|fold_fix): t...@altair.moofriend.de
= mikes...@john-doe-domain.com
May 12 21:53:14 altair postfix/smtpd[19866]: mail_addr_find:
t...@altair.moofriend.de -> mikes...@john-doe-domain.com
May 12 21:53:14 altair postfix/smtpd[19866]: before input_transp_cleanup:
cleanup flags = enable_header_body_filter enable_automatic_bcc
enable_address_mapping enable_milters
May 12 21:53:14 altair postfix/smtpd[19866]: after input_transp_cleanup:
cleanup flags = enable_header_body_filter enable_automatic_bcc
enable_address_mapping
May 12 21:53:14 altair postfix/smtpd[19866]: connect to subsystem public/cleanup
May 12 21:53:14 altair postfix/smtpd[19866]: public/cleanup socket: wanted
attribute: queue_id
May 12 21:53:14 altair postfix/smtpd[19866]: input attribute name: queue_id
May 12 21:53:14 altair postfix/smtpd[19866]: input attribute value: DB8D1C10BC
May 12 21:53:14 altair postfix/smtpd[19866]: public/cleanup socket: wanted
attribute: (list terminator)
May 12 21:53:14 altair postfix/smtpd[19866]: input attribute name: (end)
May 12 21:53:14 altair postfix/smtpd[19866]: send attr flags = 178
May 12 21:53:14 altair postfix/smtpd[19866]: DB8D1C10BC:
client=localhost[127.0.0.1]
May 12 21:53:14 altair postfix/smtpd[19866]: > localhost[127.0.0.1]: 250 2.1.5
Ok
May 12 21:53:14 altair postfix/smtpd[19866]: < localhost[127.0.0.1]: DATA
May 12 21:53:14 altair postfix/smtpd[19866]: > localhost[127.0.0.1]: 354 End
data with <CR><LF>.<CR><LF>
May 12 21:53:15 altair postfix/cleanup[19871]: DB8D1C10BC:
message-id=<20160512195314.db8d1c1...@altair.moofriend.de>
May 12 21:53:15 altair postfix/smtpd[19866]: public/cleanup socket: wanted
attribute: status
May 12 21:53:15 altair postfix/smtpd[19866]: input attribute name: status
May 12 21:53:15 altair postfix/smtpd[19866]: input attribute value: 0
May 12 21:53:15 altair postfix/smtpd[19866]: public/cleanup socket: wanted
attribute: reason
May 12 21:53:15 altair postfix/smtpd[19866]: input attribute name: reason
May 12 21:53:15 altair postfix/smtpd[19866]: input attribute value: (end)
May 12 21:53:15 altair postfix/smtpd[19866]: public/cleanup socket: wanted
attribute: (list terminator)
May 12 21:53:15 altair postfix/smtpd[19866]: input attribute name: (end)
May 12 21:53:15 altair postfix/smtpd[19866]: > localhost[127.0.0.1]: 250 2.0.0
Ok: queued as DB8D1C10BC
May 12 21:53:15 altair postfix/qmgr[19809]: DB8D1C10BC: from=<foo@bar.invalid>,
size=364, nrcpt=1 (queue active)
May 12 21:53:15 altair postfix/error[19875]: DB8D1C10BC:
to=<mikes...@john-doe-domain.com>, orig_to=<t...@altair.moofriend.de>,
relay=none, delay=0.3, delays=0.3/0/0/0, dsn=5.1.1, status=bounced (User
unknown in virtual alias table)
May 12 21:53:15 altair postfix/cleanup[19871]: 1495BC10BE:
message-id=<20160512195315.1495bc1...@altair.moofriend.de>
May 12 21:53:15 altair postfix/bounce[19876]: DB8D1C10BC: sender non-delivery
notification: 1495BC10BE
May 12 21:53:15 altair postfix/qmgr[19809]: 1495BC10BE: from=<>, size=2250,
nrcpt=1 (queue active)
May 12 21:53:15 altair postfix/qmgr[19809]: DB8D1C10BC: removed
May 12 21:53:15 altair postfix/smtp[19877]: 1495BC10BE: to=<foo@bar.invalid>,
relay=none, delay=0.02, delays=0.01/0/0/0, dsn=5.4.4, status=bounced (Host or
domain name not found. Name service error for name=bar.invalid type=AAAA: Host
not found)
May 12 21:53:15 altair postfix/qmgr[19809]: 1495BC10BE: removed
May 12 21:53:15 altair postfix/smtpd[19866]: < localhost[127.0.0.1]: QUIT
May 12 21:53:15 altair postfix/smtpd[19866]: > localhost[127.0.0.1]: 221 2.0.0
Bye
May 12 21:53:15 altair postfix/smtpd[19866]: match_hostname: localhost ~?
127.0.0.0/8
May 12 21:53:15 altair postfix/smtpd[19866]: match_hostaddr: 127.0.0.1 ~?
127.0.0.0/8
May 12 21:53:15 altair postfix/smtpd[19866]: disconnect from
localhost[127.0.0.1]
May 12 21:53:15 altair postfix/smtpd[19866]: master_notify: status 1
May 12 21:53:15 altair postfix/smtpd[19866]: connection closed
Here's the mysql queries it executes during this:
160512 21:53:35 57 Query SELECT dropat FROM postfix_virtual WHERE email
= 'foo@bar.invalid'
57 Query SELECT dropat FROM postfix_virtual WHERE email
= '@bar.invalid'
57 Query SELECT dropat FROM postfix_virtual WHERE email
= 't...@altair.moofriend.de'
58 Query SELECT dropat FROM postfix_virtual WHERE email
= 't...@altair.moofriend.de'
58 Query SELECT dropat FROM postfix_virtual WHERE email
= 'mikes...@john-doe-domain.com'
58 Query SELECT dropat FROM postfix_virtual WHERE email
= '@john-doe-domain.com'
58 Query SELECT dropat FROM postfix_virtual WHERE email
= 'foo@bar.invalid'
58 Query SELECT dropat FROM postfix_virtual WHERE email
= '@bar.invalid'
Of those, the only query that returns data is this:
$ postmap -q t...@altair.moofriend.de mysql:/etc/postfix/mysql_virtual.cf
mikes...@john-doe-domain.com
In my previous setup, I had instead of "dropat" a "dropbox" (which just
referred to a locally existing user). Now I want complete email addresses (and
have dovecot handle it), because I have much more users. However, out of
desparation, I just tried changing the result of the query from
mikes...@john-doe-domain.com to just mikespam -- this failed with the identical
message (i.e. it was trying to look up "mikespam" as query #5, which also
didn't return anything and then it failed.
Really hope you can help me out. Thank you so much!
Thanks, Fred
