[postfix-users] Absender spezifisches dsn=5.4.6?

Di Sep 11 11:46:14 CEST 2012

Hallo an alle,

Ich komme mit einem Problem nicht weiter und hoffe, dass Ihr mir dazu ein paar Hinweise geben könnt oder vielleicht ein ähnliches Problem schon selber gelöst habt.

Zum Problem:
Nach meiner Interpretation des Maillogs vermutet Postfix je nach Nutzer, oder nach Absender Adresse, einen Mail loop.
Das kann ich logisch nicht nachvollziehen aber es scheint so zu sein.

Bemerkenswert ist auch der unterschied in der Verzögerung. Was mag das bedeuten?

Auszug des Maillogs:

Sep 10 10:14:50 domäne1-sympa01 postfix/qmgr[971]: 8F1782780B5: from=<user1 at domäne2>, size=6613, nrcpt=1 (queue active)
Sep 10 10:14:50 domäne1-sympa01 postfix/local[25972]: 8F1782780B5: to=<domäne2-lists-personen at domäne1.info>, 
orig_to=<lists-personen at domäne2>, relay=local, delay=0.04,
delays=0.01/0/0/0.02, dsn=5.4.6, status=bounced (mail forwarding loop for domäne2-lists-personen at domäne1.info)
Sep 10 10:14:50 domäne1-sympa01 postfix/qmgr[971]: 8F1782780B5: removed

...

Sep 10 10:20:35 domäne1-sympa01 postfix/qmgr[971]: ACD72278115: from=<user2 at domäne2>, size=6295, nrcpt=1 (queue active)
Sep 10 10:20:36 domäne1-sympa01 postfix/local[26051]: ACD72278115: to=<domäne2-lists-personen at domäne1.info>, 
orig_to=<lists-personen at domäne2>, relay=local, delay=1,
delays=0.02/0/0/1, dsn=2.0.0, status=sent (delivered to command:  /home/sympa/bin/queue lists-personen at domäne2)
Sep 10 10:20:36 domäne1-sympa01 postfix/qmgr[971]: ACD72278115: removed

Hintergrund:

Auf dem Server, CentOS 5.5, läuft eine Sympa Instanz, ein mailing list manager, ähnlich wie der GNU Mailman, mit 3 Robots, virtuellen Instanzen zum trennen von Domänen. Postfix in der Version 2.7.1 dient diesem als MTA. Von Postfix werden die Instanzen postfix und postfix-out ausgeführt. postfix nimmt E-Mails entgegen und postfix-out versendet.

User1 kann an andere Listen schicken und andere User können an die besagte Liste schicken. User1 ist bisher der einzige Fall bei dem das passiert.

Weiter unten folgen Auszüge aus dem Maillog mit erweitertem loging, den Alias_maps und die Ergebnisse der Versions-Abfrage des Postfix und des OS.

Ich hoffe, dass irgendwer daraus schlau wird und bin für jede Art von Hilfe oder Hinweisen dankbar. Ich weiß nämlich nicht einmal mehr wo ich noch suchen soll.

Auszug eines späteren Versuchs mit erweitertem loging:

Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: input attribute value: EE14627813F
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: public/cleanup socket: wanted attribute: (list terminator)
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: input attribute name: (end)
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: send attr flags = 178
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: EE14627813F: client=domäne1-mxch02.domäne1.intern[172.17.1.117]
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: > domäne1-mxch02.domäne1.intern[172.17.1.117]: 250 2.1.5 Ok
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: watchdog_pat: 0x136c4f70
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: < domäne1-mxch02.domäne1.intern[172.17.1.117]: DATA
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: > domäne1-mxch02.domäne1.intern[172.17.1.117]: 354 End data with <CR><LF>.<CR><LF>
Sep 10 12:58:46 domäne1-sympa01 postfix/cleanup[28086]: EE14627813F: message-id=<D5DBDA00108E2B40B7EBD45806F5B394B89BB1BDA8 at DOMÄNE1-MBCL01.domäne1.intern>
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: public/cleanup socket: wanted attribute: status
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: input attribute name: status
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: input attribute value: 0
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: public/cleanup socket: wanted attribute: reason
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: input attribute name: reason
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: input attribute value: (end)
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: public/cleanup socket: wanted attribute: (list terminator)
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: input attribute name: (end)
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: > domäne1-mxch02.domäne1.intern[172.17.1.117]: 250 2.0.0 Ok: queued as EE14627813F
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: watchdog_pat: 0x136c4f70
Sep 10 12:58:46 domäne1-sympa01 postfix/qmgr[27895]: EE14627813F: from=<user1 at domäne2>, size=3387, nrcpt=1 (queue active)
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: < domäne1-mxch02.domäne1.intern[172.17.1.117]: QUIT
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: > domäne1-mxch02.domäne1.intern[172.17.1.117]: 221 2.0.0 Bye
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: match_hostname: domäne1-mxch02.domäne1.intern ~? 127.0.0.0/8
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: match_hostaddr: 172.17.1.117 ~? 127.0.0.0/8
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: match_hostname: domäne1-mxch02.domäne1.intern ~? 172.20.0.0/23
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: match_hostaddr: 172.17.1.117 ~? 172.20.0.0/23
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: match_list_match: domäne1-mxch02.domäne1.intern: no match
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: match_list_match: 172.17.1.117: no match
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: send attr request = disconnect
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: send attr ident = smtp:172.17.1.117
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: private/anvil: wanted attribute: status
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: input attribute name: status
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: input attribute value: 0
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: private/anvil: wanted attribute: (list terminator)
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: input attribute name: (end)
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: disconnect from domäne1-mxch02.domäne1.intern[172.17.1.117]
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: master_notify: status 1
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: connection closed
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: watchdog_stop: 0x136c4f70
Sep 10 12:58:46 domäne1-sympa01 postfix/smtpd[28082]: watchdog_start: 0x136c4f70
Sep 10 12:58:47 domäne1-sympa01 postfix/local[28087]: EE14627813F: to=<domäne2-lists-personen at domäne1.info>, orig_to=<lists-personen at domäne2>, relay=local, delay=0.05, delays=0.02/0/0/0.03, dsn=5.4.6, status=bounced (mail forwarding loop for domäne2-lists-personen at domäne1.info)
Sep 10 12:58:47 domäne1-sympa01 postfix/cleanup[28086]: 06FED278141: message-id=<20120910105847.06FED278141 at domäne1-sympa01.domäne1.intern>
Sep 10 12:58:47 domäne1-sympa01 postfix/qmgr[27895]: EE14627813F: removed

[root at domäne1-sympa01 ~]# cat /etc/redhat-release
CentOS release 5.5 (Final)

[root at domäne1-sympa01 ~]# postconf -d | grep mail_version
mail_version = 2.7.1

[root at domäne1-sympa01 ~]# postconf -n
alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases, hash:/home/sympa/etc/sympa_aliases
alternate_config_directories = /etc/postfix-out
command_directory = /usr/sbin
config_directory = /etc/postfix
daemon_directory = /usr/libexec/postfix
debug_peer_level = 2
html_directory = no
inet_interfaces = all
luser_relay = $user at domäne1.intern
mail_owner = postfix
mailq_path = /usr/bin/mailq.postfix
manpage_directory = /usr/share/man
message_size_limit = 20480000
multi_instance_directories = /etc/postfix-out
multi_instance_enable = yes
multi_instance_wrapper = ${command_directory}/postmulti -p --
mydestination = $mydomain
mydomain = domäne1.info
myhostname = domäne1-sympa01.domäne1.intern
myorigin = $mydomain
newaliases_path = /usr/bin/newaliases.postfix
queue_directory = /var/spool/postfix
readme_directory = /usr/share/doc/postfix-2.3.3/README_FILES
relay_domains =
sample_directory = /usr/share/doc/postfix-2.3.3/samples
sendmail_path = /usr/sbin/sendmail.postfix
setgid_group = postdrop
smtpd_recipient_restrictions = reject_unauth_destination
unknown_local_recipient_reject_code = 550
virtual_alias_domains = domäne2 domäne3 domäne1-sympa01.domäne1.intern
virtual_alias_maps = hash:/home/sympa/etc/sympa_virtual

Auszug der /home/sympa/etc/sympa_aliases:

#------------------------------ lists-personen: list alias created 08 Apr 2011
domäne2-lists-personen: "| /home/sympa/bin/queue lists-personen at domäne2"
domäne2-lists-personen-request: "| /home/sympa/bin/queue lists-personen-request at domäne2"
domäne2-lists-personen-editor: "| /home/sympa/bin/queue lists-personen-editor at domäne2"
#domäne2-lists-personen-subscribe: "| /home/sympa/bin/queue lists-personen-subscribe at domäne2"
domäne2-lists-personen-unsubscribe: "| /home/sympa/bin/queue lists-personen-unsubscribe at domäne2"
domäne2-lists-personen-owner: "| /home/sympa/bin/bouncequeue lists-personen at domäne2"

Auszug der /home/sympa/etc/sympa_virtual:

############### domäne2 - lists-personen ###############
lists-personen at domäne2 domäne2-lists-personen
lists-personen-request at domäne2 domäne2-lists-personen-request
lists-personen-editor at domäne2 domäne2-lists-personen-editor
lists-personen-unsubscribe at domäne2 domäne2-lists-personen-unsubscribe
lists-personen-owner at domäne2 domäne2-lists-personen-owner

Mit besten Grüßen
Marcel