Hallo zusammen,
ich setzte im moment auf einem Centos 7.2 Server Postfix in der Version 2.10 ein, zusammen mit ispconfig, dovecot, amavisd-new und clamav.
Beim Mailversand tritt folgendes Problem auf, versende ich eine Nachricht, erhalte ich einen ca. ~40 sekündigen delay und danach geht die Mail raus. Dies tritt aber nur mit TLS / SSL auf. Ohne Verschlüsselung geht die Email instant raus. In den logfiles sieht das dann so aus:
######################################################################################## May 11 22:20:06 localhost postfix/submission/smtpd[11027]: connect from xxx-xxx-xxx-xxx-xxx.xxx.xxxnet[xxx.xxx.xxx.xxx] May 11 22:20:06 localhost postfix/submission/smtpd[11027]: Anonymous TLS connection established from xxx-xxx-xxx-xxx-xxx.xxx.xxxnet[xxx.xxx.xxx.xxx]: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits) ########################################################################################
hier kommt der ~40 Sekunden delay
######################################################################################## May 11 22:20:53 localhost postfix/submission/smtpd[11027]: NOQUEUE: filter: RCPT from xxx-xxx-xxx-xxx-xxx.xxx.xxxnet[xxx.xxx.xxx.xxx]: info@absender.eu: Sender address triggers FILTER amavis:[127.0.0.1]:10026; from=info@absender.eu to=info@empfaenger.com proto=ESMTP helo=<[192.168.1.225]> May 11 22:20:53 localhost postfix/submission/smtpd[11027]: 8E7E1809638C: client=xxx-xxx-xxx-xxx-xxx.xxx.xxxnet[xxx.xxx.xxx.xxx], sasl_method=PLAIN, sasl_username=info@absender.eu May 11 22:20:53 localhost postfix/cleanup[11043]: 8E7E1809638C: message-id=157e9b6f-6aef-28aa-f4fc-ce5377398852@absender.eu May 11 22:20:53 localhost postfix/qmgr[10095]: 8E7E1809638C: from=info@absender.eu, size=989, nrcpt=1 (queue active) May 11 22:20:53 localhost postfix/submission/smtpd[11027]: disconnect from xxx-xxx-xxx-xxx-xxx.xxx.xxxnet[xxx.xxx.xxx.xxx] May 11 22:20:55 localhost postfix/smtpd[11048]: connect from localhost[127.0.0.1] May 11 22:20:55 localhost postfix/smtpd[11048]: 3718181160CC: client=localhost[127.0.0.1] May 11 22:20:55 localhost postfix/cleanup[11043]: 3718181160CC: message-id=157e9b6f-6aef-28aa-f4fc-ce5377398852@absender.eu May 11 22:20:55 localhost postfix/qmgr[10095]: 3718181160CC: from=info@absender.eu, size=1989, nrcpt=1 (queue active) May 11 22:20:55 localhost amavis[10157]: (10157-01) Passed CLEAN {RelayedOutbound}, ORIGINATING LOCAL [xxx.xxx.xxx.xxx]:53302 [xxx.xxx.xxx.xxx] info@absender.eu -> info@empfaenger.com, Queue-ID: 8E7E1809638C, Message-ID: 157e9b6f-6aef-28aa-f4fc-ce5377398852@absender.eu, mail_id: bpiaBB8r-c6x, Hits: -0.999, size: 989, queued_as: 3718181160CC, dkim_new=default:absender.eu, 1517 ms May 11 22:20:55 localhost postfix/smtp[11044]: 8E7E1809638C: to=info@empfaenger.com, relay=127.0.0.1[127.0.0.1]:10026, delay=1.8, delays=0.22/0.02/0.03/1.5, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10027): 250 2.0.0 Ok: queued as 3718181160CC) May 11 22:20:55 localhost postfix/qmgr[10095]: 8E7E1809638C: removed May 11 22:20:55 localhost postfix/smtp[11050]: Untrusted TLS connection established to empfaenger.com[xx.xx.xxx.xxx]:25: TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits) May 11 22:20:55 localhost postfix/smtp[11050]: 3718181160CC: to=info@empfaenger.com, relay=empfaenger.com[xx.xx.xxx.xxx]:25, delay=0.34, delays=0.06/0.04/0.12/0.13, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as BC9857EE0B8) May 11 22:20:55 localhost postfix/qmgr[10095]: 3718181160CC: removed ########################################################################################
Hab hier noch einmal das debug level etwas aufgeschraubt:
######################################################################################## May 11 22:06:07 localhost postfix/smtpd[912]: name_mask: ipv4 May 11 22:06:07 localhost postfix/smtpd[912]: name_mask: subnet May 11 22:06:07 localhost postfix/smtpd[912]: inet_addr_local: configured 2 IPv4 addresses May 11 22:06:07 localhost postfix/smtpd[912]: been_here: 127.0.0.0/8: 0 May 11 22:06:07 localhost postfix/smtpd[912]: been_here: xx.xxx.xxx.xxx/32: 0 May 11 22:06:07 localhost postfix/smtpd[912]: mynetworks: 127.0.0.0/8 xx.xxx.xxx.xxx/32 May 11 22:06:07 localhost postfix/submission/smtpd[912]: process generation: 3 (3) May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: mynetworks ~? debug_peer_list May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: mynetworks ~? fast_flush_domains May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: mynetworks ~? mynetworks May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: relay_domains ~? debug_peer_list May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: relay_domains ~? fast_flush_domains May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: relay_domains ~? mynetworks May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: relay_domains ~? permit_mx_backup_networks May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: relay_domains ~? qmqpd_authorized_clients May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: relay_domains ~? relay_domains May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relaydomains.cf: user = ispconfig May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relaydomains.cf: password = xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relaydomains.cf: dbname = dbispconfig May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relaydomains.cf: result_format = %s May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_int: /etc/postfix/mysql-virtual_relaydomains.cf: expansion_limit = 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relaydomains.cf: query = <NULL> May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relaydomains.cf: table = mail_transport May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relaydomains.cf: select_field = domain May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relaydomains.cf: where_field = domain May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relaydomains.cf: additional_conditions = and active = 'y' and server_id = 1 May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relaydomains.cf: domain = May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relaydomains.cf: hosts = 127.0.0.1 May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_open: mysql:/etc/postfix/mysql-virtual_relaydomains.cf May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: permit_mx_backup_networks ~? debug_peer_list May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: permit_mx_backup_networks ~? fast_flush_domains May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: permit_mx_backup_networks ~? mynetworks May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: permit_mx_backup_networks ~? permit_mx_backup_networks May 11 22:06:07 localhost postfix/submission/smtpd[912]: connect to subsystem private/proxymap May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr request = open May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr table = unix:passwd.byname May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr flags = 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: flags May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: flags May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 16 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: (list terminator) May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_proxy_open: connect to map=unix:passwd.byname status=0 server_flags=fixed May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_open: proxy:unix:passwd.byname May 11 22:06:07 localhost postfix/submission/smtpd[912]: Compiled against Berkeley DB: 5.3.21? May 11 22:06:07 localhost postfix/submission/smtpd[912]: Run-time linked against Berkeley DB: 5.3.21? May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_open: hash:/etc/aliases May 11 22:06:07 localhost postfix/submission/smtpd[912]: Compiled against Berkeley DB: 5.3.21? May 11 22:06:07 localhost postfix/submission/smtpd[912]: Run-time linked against Berkeley DB: 5.3.21? May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_open: hash:/etc/mailman/virtual-mailman May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr request = open May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr table = mysql:/etc/postfix/mysql-virtual_forwardings.cf May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr flags = 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: flags May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: flags May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 16 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: (list terminator) May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_proxy_open: connect to map=mysql:/etc/postfix/mysql-virtual_forwardings.cf status=0 server_flags=fixed May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_open: proxy:mysql:/etc/postfix/mysql-virtual_forwardings.cf May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr request = open May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr table = mysql:/etc/postfix/mysql-virtual_email2email.cf May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr flags = 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: flags May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: flags May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 16 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: (list terminator) May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_proxy_open: connect to map=mysql:/etc/postfix/mysql-virtual_email2email.cf status=0 server_flags=fixed May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_open: proxy:mysql:/etc/postfix/mysql-virtual_email2email.cf May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr request = open May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr table = mysql:/etc/postfix/mysql-virtual_mailboxes.cf May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr flags = 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: flags May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: flags May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 16 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: (list terminator) May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_proxy_open: connect to map=mysql:/etc/postfix/mysql-virtual_mailboxes.cf status=0 server_flags=fixed May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_open: proxy:mysql:/etc/postfix/mysql-virtual_mailboxes.cf May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relayrecipientmaps.cf: user = ispconfig May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relayrecipientmaps.cf: password = xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relayrecipientmaps.cf: dbname = dbispconfig May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relayrecipientmaps.cf: result_format = %s May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_int: /etc/postfix/mysql-virtual_relayrecipientmaps.cf: expansion_limit = 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relayrecipientmaps.cf: query = <NULL> May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relayrecipientmaps.cf: table = mail_relay_recipient May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relayrecipientmaps.cf: select_field = access May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relayrecipientmaps.cf: where_field = source May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relayrecipientmaps.cf: additional_conditions = and active = 'y' and server_id = 1 May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relayrecipientmaps.cf: domain = May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_relayrecipientmaps.cf: hosts = 127.0.0.1 May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_open: mysql:/etc/postfix/mysql-virtual_relayrecipientmaps.cf May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: smtpd_access_maps ~? debug_peer_list May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: smtpd_access_maps ~? fast_flush_domains May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: smtpd_access_maps ~? mynetworks May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: smtpd_access_maps ~? permit_mx_backup_networks May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: smtpd_access_maps ~? qmqpd_authorized_clients May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: smtpd_access_maps ~? relay_domains May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: smtpd_access_maps ~? smtpd_access_maps May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr request = open May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr table = mysql:/etc/postfix/mysql-virtual_sender_login_maps.cf May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr flags = 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: flags May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: flags May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 16 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: (list terminator) May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_proxy_open: connect to map=mysql:/etc/postfix/mysql-virtual_sender_login_maps.cf status=0 server_flags=fixed May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_open: proxy:mysql:/etc/postfix/mysql-virtual_sender_login_maps.cf May 11 22:06:07 localhost postfix/submission/smtpd[912]: warning: regexp map /etc/postfix/helo_access, line 1: Invalid preceding regular expression May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_open: regexp:/etc/postfix/helo_access May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_open: regexp:/etc/postfix/blacklist_helo May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_open: regexp:/etc/postfix/tag_as_originating.re May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_sender.cf: user = ispconfig May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_sender.cf: password = xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_sender.cf: dbname = dbispconfig May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_sender.cf: result_format = %s May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_int: /etc/postfix/mysql-virtual_sender.cf: expansion_limit = 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_sender.cf: query = <NULL> May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_sender.cf: table = mail_access May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_sender.cf: select_field = access May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_sender.cf: where_field = source May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_sender.cf: additional_conditions = and type = 'sender' and active = 'y' and server_id = 1 May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_sender.cf: domain = May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_sender.cf: hosts = 127.0.0.1 May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_open: mysql:/etc/postfix/mysql-virtual_sender.cf May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_open: regexp:/etc/postfix/tag_as_foreign.re May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_recipient.cf: user = ispconfig May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_recipient.cf: password = xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_recipient.cf: dbname = dbispconfig May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_recipient.cf: result_format = %s May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_int: /etc/postfix/mysql-virtual_recipient.cf: expansion_limit = 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_recipient.cf: query = <NULL> May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_recipient.cf: table = mail_access May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_recipient.cf: select_field = access May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_recipient.cf: where_field = source May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_recipient.cf: additional_conditions = and type = 'recipient' and active = 'y' and server_id = 1 May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_recipient.cf: domain = May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_recipient.cf: hosts = 127.0.0.1 May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_open: mysql:/etc/postfix/mysql-virtual_recipient.cf May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_policy_greylist.cf: user = ispconfig May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_policy_greylist.cf: password = xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_policy_greylist.cf: dbname = dbispconfig May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_policy_greylist.cf: result_format = %s May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_int: /etc/postfix/mysql-virtual_policy_greylist.cf: expansion_limit = 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_policy_greylist.cf: query = SELECT 'greylisting' FROM (SELECT greylisting, source AS email FROM mail_forwarding WHERE server_id = 1 UNION SELECT greylisting, email FROM mail_user WHERE server_id = 1) addresses WHERE addresses.email='%s' AND addresses.greylisting='y' May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_policy_greylist.cf: domain = May 11 22:06:07 localhost postfix/submission/smtpd[912]: cfg_get_str: /etc/postfix/mysql-virtual_policy_greylist.cf: hosts = 127.0.0.1 May 11 22:06:07 localhost postfix/submission/smtpd[912]: dict_open: mysql:/etc/postfix/mysql-virtual_policy_greylist.cf May 11 22:06:07 localhost postfix/submission/smtpd[912]: auto_clnt_create: transport=inet endpoint=127.0.0.1:10023 May 11 22:06:07 localhost postfix/submission/smtpd[912]: unknown_helo_hostname_tempfail_action = defer_if_permit May 11 22:06:07 localhost postfix/submission/smtpd[912]: unknown_address_tempfail_action = defer_if_permit May 11 22:06:07 localhost postfix/submission/smtpd[912]: unverified_recipient_tempfail_action = defer_if_permit May 11 22:06:07 localhost postfix/submission/smtpd[912]: unverified_sender_tempfail_action = defer_if_permit May 11 22:06:07 localhost postfix/submission/smtpd[912]: name_mask: 1 May 11 22:06:07 localhost postfix/submission/smtpd[912]: auto_clnt_create: transport=local endpoint=private/tlsmgr May 11 22:06:07 localhost postfix/submission/smtpd[912]: auto_clnt_open: connected to private/tlsmgr May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr request = seed May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr size = 32 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/tlsmgr: wanted attribute: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/tlsmgr: wanted attribute: seed May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: seed May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: N/5WOooKxY1E4EiZdFhRUPiQeMjmQOEpEBOSDrjCECQ= May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/tlsmgr: wanted attribute: (list terminator) May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr request = policy May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr cache_type = smtpd May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/tlsmgr: wanted attribute: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/tlsmgr: wanted attribute: cachable May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: cachable May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/tlsmgr: wanted attribute: (list terminator) May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: fast_flush_domains ~? debug_peer_list May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_string: fast_flush_domains ~? fast_flush_domains May 11 22:06:07 localhost postfix/submission/smtpd[912]: name_mask: no_address_mappings May 11 22:06:07 localhost postfix/submission/smtpd[912]: auto_clnt_create: transport=local endpoint=private/anvil May 11 22:06:07 localhost postfix/submission/smtpd[912]: connection established May 11 22:06:07 localhost postfix/submission/smtpd[912]: master_notify: status 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: name_mask: resource May 11 22:06:07 localhost postfix/submission/smtpd[912]: name_mask: software May 11 22:06:07 localhost postfix/submission/smtpd[912]: connect from xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx] May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_list_match: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net: no match May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_list_match: xxx.xxx.xxx.xxx: no match May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_list_match: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net: no match May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_list_match: xxx.xxx.xxx.xxx: no match May 11 22:06:07 localhost postfix/submission/smtpd[912]: smtp_stream_setup: maxtime=300 enable_deadline=0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_hostname: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net ~? 127.0.0.0/8 May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_hostaddr: xxx.xxx.xxx.xxx ~? 127.0.0.0/8 May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_hostname: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net ~? xx.xxx.xxx.xxx/32 May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_hostaddr: xxx.xxx.xxx.xxx ~? xx.xxx.xxx.xxx/32 May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_list_match: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net: no match May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_list_match: xxx.xxx.xxx.xxx: no match May 11 22:06:07 localhost postfix/submission/smtpd[912]: auto_clnt_open: connected to private/anvil May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr request = connect May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr ident = submission:xxx.xxx.xxx.xxx May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/anvil: wanted attribute: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/anvil: wanted attribute: count May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: count May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 1 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/anvil: wanted attribute: rate May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: rate May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 1 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/anvil: wanted attribute: (list terminator) May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:07 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 220 xxx-xxx-xxx-xx.xxx.eu ESMTP Postfix May 11 22:06:07 localhost postfix/submission/smtpd[912]: < xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: EHLO [192.168.1.xxx] May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_list_match: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net: no match May 11 22:06:07 localhost postfix/submission/smtpd[912]: match_list_match: xxx.xxx.xxx.xxx: no match May 11 22:06:07 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-xxx-xxx-xxx-xx.xxx.eu May 11 22:06:07 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-PIPELINING May 11 22:06:07 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-SIZE May 11 22:06:07 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-VRFY May 11 22:06:07 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-ETRN May 11 22:06:07 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-STARTTLS May 11 22:06:07 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-ENHANCEDSTATUSCODES May 11 22:06:07 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-8BITMIME May 11 22:06:07 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250 DSN May 11 22:06:07 localhost postfix/submission/smtpd[912]: < xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: STARTTLS May 11 22:06:07 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 220 2.0.0 Ready to start TLS May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr request = seed May 11 22:06:07 localhost postfix/submission/smtpd[912]: send attr size = 32 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/tlsmgr: wanted attribute: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: status May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/tlsmgr: wanted attribute: seed May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: seed May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute value: 8n64Pdoxt9UtM1fd7CmCxF1YZAYqFZK+vYALyetBq1I= May 11 22:06:07 localhost postfix/submission/smtpd[912]: private/tlsmgr: wanted attribute: (list terminator) May 11 22:06:07 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:07 localhost postfix/submission/smtpd[912]: Anonymous TLS connection established from xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits) May 11 22:06:07 localhost postfix/submission/smtpd[912]: xsasl_dovecot_server_create: SASL service=smtp, realm=(null) May 11 22:06:07 localhost postfix/submission/smtpd[912]: name_mask: noanonymous May 11 22:06:07 localhost postfix/submission/smtpd[912]: xsasl_dovecot_server_connect: Connecting May 11 22:06:07 localhost postfix/submission/smtpd[912]: xsasl_dovecot_server_connect: auth reply: VERSION?1?1 May 11 22:06:07 localhost postfix/submission/smtpd[912]: xsasl_dovecot_server_connect: auth reply: MECH?PLAIN?plaintext May 11 22:06:07 localhost postfix/submission/smtpd[912]: name_mask: plaintext May 11 22:06:07 localhost postfix/submission/smtpd[912]: xsasl_dovecot_server_connect: auth reply: MECH?LOGIN?plaintext May 11 22:06:07 localhost postfix/submission/smtpd[912]: name_mask: plaintext May 11 22:06:07 localhost postfix/submission/smtpd[912]: xsasl_dovecot_server_connect: auth reply: SPID?916 May 11 22:06:07 localhost postfix/submission/smtpd[912]: xsasl_dovecot_server_connect: auth reply: CUID?1 May 11 22:06:07 localhost postfix/submission/smtpd[912]: xsasl_dovecot_server_connect: auth reply: COOKIE?7bcc1aa1133cccbaab793f34a17e587d May 11 22:06:07 localhost postfix/submission/smtpd[912]: xsasl_dovecot_server_connect: auth reply: DONE May 11 22:06:07 localhost postfix/submission/smtpd[912]: xsasl_dovecot_server_mech_filter: keep mechanism: PLAIN May 11 22:06:07 localhost postfix/submission/smtpd[912]: xsasl_dovecot_server_mech_filter: keep mechanism: LOGIN ########################################################################################
Wieder der Delay:
########################################################################################
May 11 22:06:53 localhost postfix/submission/smtpd[912]: < xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: EHLO [192.168.1.xxx] May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: xxx.xxx.xxx.xxx: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-xxx-xxx-xxx-xx.xxx.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-PIPELINING May 11 22:06:53 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-SIZE May 11 22:06:53 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-VRFY May 11 22:06:53 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-ETRN May 11 22:06:53 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-AUTH PLAIN LOGIN May 11 22:06:53 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-AUTH=PLAIN LOGIN May 11 22:06:53 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-ENHANCEDSTATUSCODES May 11 22:06:53 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250-8BITMIME May 11 22:06:53 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250 DSN May 11 22:06:53 localhost postfix/submission/smtpd[912]: < xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: AUTH PLAIN AGluZm9AYW5zdG9zcy5ldQBNckYyMjk5 May 11 22:06:53 localhost postfix/submission/smtpd[912]: xsasl_dovecot_server_first: sasl_method PLAIN, init_response AGluZm9AYW5zdG9zcy5ldQBNckYyMjk5 May 11 22:06:53 localhost postfix/submission/smtpd[912]: xsasl_dovecot_handle_reply: auth reply: OK?1?user=info@absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 235 2.7.0 Authentication successful May 11 22:06:53 localhost postfix/submission/smtpd[912]: < xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: MAIL FROM:info@absender.eu BODY=8BITMIME SIZE=616 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_hostname: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net ~? 127.0.0.0/8 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_hostaddr: xxx.xxx.xxx.xxx ~? 127.0.0.0/8 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_hostname: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net ~? xx.xxx.xxx.xxx/32 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_hostaddr: xxx.xxx.xxx.xxx ~? xx.xxx.xxx.xxx/32 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: xxx.xxx.xxx.xxx: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr request = message May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr ident = submission:xxx.xxx.xxx.xxx May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/anvil: wanted attribute: status May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: status May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/anvil: wanted attribute: rate May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: rate May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: 1 May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/anvil: wanted attribute: (list terminator) May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:53 localhost postfix/submission/smtpd[912]: extract_addr: input: info@absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: smtpd_check_addr: addr=info@absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: connect to subsystem private/rewrite May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr request = rewrite May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr rule = local May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr address = info@absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: flags May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: flags May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: address May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: address May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: info@absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: (list terminator) May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:53 localhost postfix/submission/smtpd[912]: rewrite_clnt: local: info@absender.eu -> info@absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr request = resolve May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr sender = May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr address = info@absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: flags May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: flags May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: transport May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: transport May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: dovecot May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: nexthop May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: nexthop May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: recipient May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: recipient May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: info@absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: flags May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: flags May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: 1024 May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: (list terminator) May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:53 localhost postfix/submission/smtpd[912]: resolve_clnt: `' -> `info@absender.eu' -> transp=`dovecot' host=`absender.eu' rcpt=`info@absender.eu' flags= class=virtual May 11 22:06:53 localhost postfix/submission/smtpd[912]: ctable_locate: install entry key info@absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: extract_addr: in: info@absender.eu, result: info@absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr request = rewrite May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr rule = local May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr address = double-bounce May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: flags May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: flags May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: address May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: address May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: double-bounce@xxx-xxx-xxx-xx.xxx.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: (list terminator) May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:53 localhost postfix/submission/smtpd[912]: rewrite_clnt: local: double-bounce -> double-bounce@xxx-xxx-xxx-xx.xxx.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: smtpd_check_rewrite: trying: permit_inet_interfaces May 11 22:06:53 localhost postfix/submission/smtpd[912]: permit_inet_interfaces: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net xxx.xxx.xxx.xxx May 11 22:06:53 localhost postfix/submission/smtpd[912]: fsspace: .: block size 4096, blocks free 24738671 May 11 22:06:53 localhost postfix/submission/smtpd[912]: smtpd_check_queue: blocks 4096 avail 24738671 min_free 0 msg_size_limit 0 May 11 22:06:53 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250 2.1.0 Ok May 11 22:06:53 localhost postfix/submission/smtpd[912]: < xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: RCPT TO:info@empfaender.de May 11 22:06:53 localhost postfix/submission/smtpd[912]: extract_addr: input: info@empfaender.de May 11 22:06:53 localhost postfix/submission/smtpd[912]: smtpd_check_addr: addr=info@empfaender.de May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr request = rewrite May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr rule = local May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr address = info@empfaender.de May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: flags May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: flags May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: address May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: address May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: info@empfaender.de May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: (list terminator) May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:53 localhost postfix/submission/smtpd[912]: rewrite_clnt: local: info@empfaender.de -> info@empfaender.de May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr request = resolve May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr sender = May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr address = info@empfaender.de May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: flags May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: flags May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: transport May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: transport May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: smtp May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: nexthop May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: nexthop May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: empfaender.de May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: recipient May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: recipient May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: info@empfaender.de May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: flags May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: flags May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: 4096 May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/rewrite socket: wanted attribute: (list terminator) May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:53 localhost postfix/submission/smtpd[912]: resolve_clnt: `' -> `info@empfaender.de' -> transp=`smtp' host=`empfaender.de' rcpt=`info@empfaender.de' flags= class=default May 11 22:06:53 localhost postfix/submission/smtpd[912]: ctable_locate: install entry key info@empfaender.de May 11 22:06:53 localhost postfix/submission/smtpd[912]: extract_addr: in: info@empfaender.de, result: info@empfaender.de May 11 22:06:53 localhost postfix/submission/smtpd[912]: >>> START Client host RESTRICTIONS <<< May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=permit_sasl_authenticated May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: permit_sasl_authenticated: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=permit_sasl_authenticated status=1 May 11 22:06:53 localhost postfix/submission/smtpd[912]: >>> END Client host RESTRICTIONS <<< May 11 22:06:53 localhost postfix/submission/smtpd[912]: >>> START Helo command RESTRICTIONS <<< May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=permit_sasl_authenticated May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: permit_sasl_authenticated: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=permit_sasl_authenticated status=1 May 11 22:06:53 localhost postfix/submission/smtpd[912]: >>> END Helo command RESTRICTIONS <<< May 11 22:06:53 localhost postfix/submission/smtpd[912]: >>> START Sender address RESTRICTIONS <<< May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=check_sender_access May 11 22:06:53 localhost postfix/submission/smtpd[912]: check_mail_access: info@absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: ctable_locate: move existing entry key info@absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: check_access: info@absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: dict_regexp_lookup: /etc/postfix/tag_as_originating.re: info@absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: check_table_result: regexp:/etc/postfix/tag_as_originating.re FILTER amavis:[127.0.0.1]:10026 info@absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: NOQUEUE: filter: RCPT from xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: info@absender.eu: Sender address triggers FILTER amavis:[127.0.0.1]:10026; from=info@absender.eu to=info@empfaender.de proto=ESMTP helo=<[192.168.1.xxx]> May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=check_sender_access status=0 May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=permit_mynetworks May 11 22:06:53 localhost postfix/submission/smtpd[912]: permit_mynetworks: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net xxx.xxx.xxx.xxx May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_hostname: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net ~? 127.0.0.0/8 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_hostaddr: xxx.xxx.xxx.xxx ~? 127.0.0.0/8 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_hostname: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net ~? xx.xxx.xxx.xxx/32 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_hostaddr: xxx.xxx.xxx.xxx ~? xx.xxx.xxx.xxx/32 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: xxx.xxx.xxx.xxx: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=permit_mynetworks status=0 May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=permit_sasl_authenticated May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: permit_sasl_authenticated: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=permit_sasl_authenticated status=1 May 11 22:06:53 localhost postfix/submission/smtpd[912]: >>> END Sender address RESTRICTIONS <<< May 11 22:06:53 localhost postfix/submission/smtpd[912]: >>> START Recipient address RESTRICTIONS <<< May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=permit_mynetworks May 11 22:06:53 localhost postfix/submission/smtpd[912]: permit_mynetworks: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net xxx.xxx.xxx.xxx May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_hostname: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net ~? 127.0.0.0/8 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_hostaddr: xxx.xxx.xxx.xxx ~? 127.0.0.0/8 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_hostname: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net ~? xx.xxx.xxx.xxx/32 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_hostaddr: xxx.xxx.xxx.xxx ~? xx.xxx.xxx.xxx/32 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: xxx.xxx.xxx.xxx: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=permit_mynetworks status=0 May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=permit_sasl_authenticated May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: permit_sasl_authenticated: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=permit_sasl_authenticated status=1 May 11 22:06:53 localhost postfix/submission/smtpd[912]: >>> END Recipient address RESTRICTIONS <<< May 11 22:06:53 localhost postfix/submission/smtpd[912]: >>> START Recipient address RESTRICTIONS <<< May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=permit_mynetworks May 11 22:06:53 localhost postfix/submission/smtpd[912]: permit_mynetworks: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net xxx.xxx.xxx.xxx May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_hostname: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net ~? 127.0.0.0/8 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_hostaddr: xxx.xxx.xxx.xxx ~? 127.0.0.0/8 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_hostname: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net ~? xx.xxx.xxx.xxx/32 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_hostaddr: xxx.xxx.xxx.xxx ~? xx.xxx.xxx.xxx/32 May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: xxx.xxx.xxx.xxx: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=permit_mynetworks status=0 May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=permit_sasl_authenticated May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: permit_sasl_authenticated: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: generic_checks: name=permit_sasl_authenticated status=1 May 11 22:06:53 localhost postfix/submission/smtpd[912]: >>> END Recipient address RESTRICTIONS <<< May 11 22:06:53 localhost postfix/submission/smtpd[912]: >>> CHECKING RECIPIENT MAPS <<< May 11 22:06:53 localhost postfix/submission/smtpd[912]: ctable_locate: move existing entry key info@empfaender.de May 11 22:06:53 localhost postfix/submission/smtpd[912]: maps_find: recipient_canonical_maps: info@empfaender.de: not found May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_string: empfaender.de ~? xxx-xxx-xxx-xx.xxx.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_string: empfaender.de ~? xxx.xxx.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_string: empfaender.de ~? localhost May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: empfaender.de: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: maps_find: recipient_canonical_maps: @empfaender.de: not found May 11 22:06:53 localhost postfix/submission/smtpd[912]: mail_addr_find: info@empfaender.de -> (not found) May 11 22:06:53 localhost postfix/submission/smtpd[912]: maps_find: canonical_maps: info@empfaender.de: not found May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_string: empfaender.de ~? xxx-xxx-xxx-xx.xxx.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_string: empfaender.de ~? xxx.xxx.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_string: empfaender.de ~? localhost May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: empfaender.de: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: maps_find: canonical_maps: @empfaender.de: not found May 11 22:06:53 localhost postfix/submission/smtpd[912]: mail_addr_find: info@empfaender.de -> (not found) May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr request = lookup May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr table = mysql:/etc/postfix/mysql-virtual_forwardings.cf May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr flags = 16448 May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr key = info@empfaender.de May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: status May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: status May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: 1 May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: value May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: value May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: (end) May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: (list terminator) May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:53 localhost postfix/submission/smtpd[912]: dict_proxy_lookup: table=mysql:/etc/postfix/mysql-virtual_forwardings.cf flags=lock|fold_fix key=info@empfaender.de -> status=1 result= May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr request = lookup May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr table = mysql:/etc/postfix/mysql-virtual_email2email.cf May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr flags = 16448 May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr key = info@empfaender.de May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: status May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: status May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: 1 May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: value May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: value May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: (end) May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: (list terminator) May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:53 localhost postfix/submission/smtpd[912]: dict_proxy_lookup: table=mysql:/etc/postfix/mysql-virtual_email2email.cf flags=lock|fold_fix key=info@empfaender.de -> status=1 result= May 11 22:06:53 localhost postfix/submission/smtpd[912]: maps_find: virtual_alias_maps: info@empfaender.de: not found May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_string: empfaender.de ~? xxx-xxx-xxx-xx.xxx.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_string: empfaender.de ~? xxx.xxx.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_string: empfaender.de ~? localhost May 11 22:06:53 localhost postfix/submission/smtpd[912]: match_list_match: empfaender.de: no match May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr request = lookup May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr table = mysql:/etc/postfix/mysql-virtual_forwardings.cf May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr flags = 16448 May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr key = @empfaender.de May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: status May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: status May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: 1 May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: value May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: value May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: (end) May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: (list terminator) May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:53 localhost postfix/submission/smtpd[912]: dict_proxy_lookup: table=mysql:/etc/postfix/mysql-virtual_forwardings.cf flags=lock|fold_fix key=@empfaender.de -> status=1 result= May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr request = lookup May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr table = mysql:/etc/postfix/mysql-virtual_email2email.cf May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr flags = 16448 May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr key = @empfaender.de May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: status May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: status May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: 1 May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: value May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: value May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: (end) May 11 22:06:53 localhost postfix/submission/smtpd[912]: private/proxymap socket: wanted attribute: (list terminator) May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:53 localhost postfix/submission/smtpd[912]: dict_proxy_lookup: table=mysql:/etc/postfix/mysql-virtual_email2email.cf flags=lock|fold_fix key=@empfaender.de -> status=1 result= May 11 22:06:53 localhost postfix/submission/smtpd[912]: maps_find: virtual_alias_maps: @empfaender.de: not found May 11 22:06:53 localhost postfix/submission/smtpd[912]: mail_addr_find: info@empfaender.de -> (not found) May 11 22:06:53 localhost postfix/submission/smtpd[912]: before input_transp_cleanup: cleanup flags = enable_header_body_filter enable_automatic_bcc enable_address_mapping enable_milters May 11 22:06:53 localhost postfix/submission/smtpd[912]: after input_transp_cleanup: cleanup flags = enable_header_body_filter May 11 22:06:53 localhost postfix/submission/smtpd[912]: connect to subsystem public/cleanup May 11 22:06:53 localhost postfix/submission/smtpd[912]: public/cleanup socket: wanted attribute: queue_id May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: queue_id May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute value: EF296809638B May 11 22:06:53 localhost postfix/submission/smtpd[912]: public/cleanup socket: wanted attribute: (list terminator) May 11 22:06:53 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:53 localhost postfix/submission/smtpd[912]: send attr flags = 130 May 11 22:06:53 localhost postfix/submission/smtpd[912]: EF296809638B: client=xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx], sasl_method=PLAIN, sasl_username=info@absender.eu May 11 22:06:53 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250 2.1.5 Ok May 11 22:06:54 localhost postfix/submission/smtpd[912]: < xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: DATA May 11 22:06:54 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 354 End data with <CR><LF>.<CR><LF> May 11 22:06:54 localhost postfix/cleanup[930]: EF296809638B: message-id=d9fde519-0b1f-893a-8669-9a2ea5f37049@absender.eu May 11 22:06:54 localhost postfix/qmgr[32688]: EF296809638B: from=info@absender.eu, size=995, nrcpt=1 (queue active) May 11 22:06:54 localhost postfix/submission/smtpd[912]: public/cleanup socket: wanted attribute: status May 11 22:06:54 localhost postfix/submission/smtpd[912]: input attribute name: status May 11 22:06:54 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:54 localhost postfix/submission/smtpd[912]: public/cleanup socket: wanted attribute: reason May 11 22:06:54 localhost postfix/submission/smtpd[912]: input attribute name: reason May 11 22:06:54 localhost postfix/submission/smtpd[912]: input attribute value: (end) May 11 22:06:54 localhost postfix/submission/smtpd[912]: public/cleanup socket: wanted attribute: (list terminator) May 11 22:06:54 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:54 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 250 2.0.0 Ok: queued as EF296809638B May 11 22:06:54 localhost postfix/submission/smtpd[912]: < xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: QUIT May 11 22:06:54 localhost postfix/submission/smtpd[912]: > xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: 221 2.0.0 Bye May 11 22:06:54 localhost postfix/submission/smtpd[912]: match_hostname: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net ~? 127.0.0.0/8 May 11 22:06:54 localhost postfix/submission/smtpd[912]: match_hostaddr: xxx.xxx.xxx.xxx ~? 127.0.0.0/8 May 11 22:06:54 localhost postfix/submission/smtpd[912]: match_hostname: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net ~? xx.xxx.xxx.xxx/32 May 11 22:06:54 localhost postfix/submission/smtpd[912]: match_hostaddr: xxx.xxx.xxx.xxx ~? xx.xxx.xxx.xxx/32 May 11 22:06:54 localhost postfix/submission/smtpd[912]: match_list_match: xxx-xxx-xxx-xxx-xxx.xxxx.xxx.net: no match May 11 22:06:54 localhost postfix/submission/smtpd[912]: match_list_match: xxx.xxx.xxx.xxx: no match May 11 22:06:54 localhost postfix/submission/smtpd[912]: send attr request = disconnect May 11 22:06:54 localhost postfix/submission/smtpd[912]: send attr ident = submission:xxx.xxx.xxx.xxx May 11 22:06:54 localhost postfix/submission/smtpd[912]: private/anvil: wanted attribute: status May 11 22:06:54 localhost postfix/submission/smtpd[912]: input attribute name: status May 11 22:06:54 localhost postfix/submission/smtpd[912]: input attribute value: 0 May 11 22:06:54 localhost postfix/submission/smtpd[912]: private/anvil: wanted attribute: (list terminator) May 11 22:06:54 localhost postfix/submission/smtpd[912]: input attribute name: (end) May 11 22:06:54 localhost amavis[29363]: loaded policy bank "ORIGINATING" May 11 22:06:54 localhost amavis[29363]: process_request: fileno sock=18, STDIN=0, STDOUT=1 May 11 22:06:54 localhost amavis[29363]: (29363-02) ESMTP [127.0.0.1]:10026 /var/spool/amavisd/tmp/amavis-20160511T173437-29363-Qzq8cJip: info@absender.eu -> info@empfaender.de Received: from xxx-xxx-xxx-xx.xxx.eu ([127.0.0.1]) by localhost (xxx-xxx-xxx-xx.xxx.eu [127.0.0.1]) (amavisd-new, port 10026) with ESMTP for info@empfaender.de; Wed, 11 May 2016 22:06:54 +0200 (CEST) May 11 22:06:54 localhost postfix/submission/smtpd[912]: disconnect from xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx] May 11 22:06:54 localhost postfix/submission/smtpd[912]: master_notify: status 1 May 11 22:06:54 localhost postfix/submission/smtpd[912]: connection closed May 11 22:06:54 localhost postfix/submission/smtpd[912]: auto_clnt_close: disconnect private/tlsmgr stream May 11 22:06:54 localhost amavis[29363]: (29363-02) smtp connection cache, dt: 16333.6, state: 1 May 11 22:06:54 localhost amavis[29363]: (29363-02) smtp connection cache, dt: 16333.6 -> disabling May 11 22:06:54 localhost amavis[29363]: (29363-02) body hash: 5934ff89a5deb18b8d13fb499160e86f May 11 22:06:54 localhost amavis[29363]: (29363-02) trace: ESMTP://[127.0.0.1]:47932 < ESMTPSA://[xxx.xxx.xxx.xxx]:53121 May 11 22:06:54 localhost amavis[29363]: (29363-02) Checking: TZOuTG_zpFzU ORIGINATING [xxx.xxx.xxx.xxx] info@absender.eu -> info@empfaender.de May 11 22:06:54 localhost amavis[29363]: (29363-02) 2822.From: info@absender.eu May 11 22:06:54 localhost amavis[29363]: (29363-02) p001 1 Content-Type: text/plain, size: 67 B, name: May 11 22:06:54 localhost amavis[29363]: (29363-02) Checking for banned types and filenames May 11 22:06:54 localhost amavis[29363]: (29363-02) skipping banned check: all recipients bypass banned checks May 11 22:06:54 localhost amavis[29363]: (29363-02) run_av Using (ClamAV-clamd): (code) CONTSCAN /var/spool/amavisd/tmp/amavis-20160511T173437-29363-Qzq8cJip/parts\n May 11 22:06:54 localhost amavis[29363]: (29363-02) ClamAV-clamd: Connecting to socket /var/run/clamav/clamd.sock May 11 22:06:54 localhost amavis[29363]: (29363-02) new socket by IO::Socket::UNIX to /var/run/clamav/clamd.sock, timeout set to 10 May 11 22:06:54 localhost amavis[29363]: (29363-02) ClamAV-clamd: Sending CONTSCAN /var/spool/amavisd/tmp/amavis-20160511T173437-29363-Qzq8cJip/parts\n to socket /var/run/clamav/clamd.sock May 11 22:06:54 localhost amavis[29363]: (29363-02) rw_loop read: got eof May 11 22:06:54 localhost amavis[29363]: (29363-02) run_av (ClamAV-clamd): CLEAN May 11 22:06:54 localhost amavis[29363]: (29363-02) run_av (ClamAV-clamd) result: clean May 11 22:06:54 localhost amavis[29363]: (29363-02) calling SA parse (0), SA vers 3.4.0, 3.004000, data as STRING_REF, recips_ind [0], user: "amavis" May 11 22:06:55 localhost amavis[29363]: (29363-02) spam_scan: score=-0.999 autolearn=ham autolearn_force=no tests=[ALL_TRUSTED=-1,URIBL_BLOCKED=0.001] recips=0 May 11 22:06:55 localhost amavis[29363]: (29363-02) do_notify_and_quar: ccat=Clean (1,0) ("1":Clean, "0":CatchAll) ccat_block=(), qar_mth= May 11 22:06:55 localhost amavis[29363]: (29363-02) delivery method is 1, recips: info@empfaender.de May 11 22:06:55 localhost amavis[29363]: (29363-02) dkim: candidate originators: From:info@absender.eu May 11 22:06:55 localhost amavis[29363]: (29363-02) dkim: signing (author), From: info@absender.eu (From:info@absender.eu), KEY.key_ind=>0, a=>rsa-sha256, c=>relaxed/simple, d=>absender.eu, s=>default, ttl=>1814400, x=>1464811615 May 11 22:06:55 localhost amavis[29363]: (29363-02) smtp session reuse (smtp:[127.0.0.1]:10027), 1 transactions so far May 11 22:06:55 localhost amavis[29363]: (29363-02) smtp cmd> NOOP May 11 22:06:55 localhost amavis[29363]: (29363-02) smtp resp to NOOP (idle 16334.9 s): 421 4.4.2 xxx-xxx-xxx-xx.xxx.eu Error: timeout exceeded May 11 22:06:55 localhost amavis[29363]: (29363-02) Amavis::Out::SMTP::Session close, disconnecting May 11 22:06:55 localhost amavis[29363]: (29363-02) new socket using IO::Socket::IP to [127.0.0.1]:10027, timeout 35 May 11 22:06:55 localhost postfix/smtpd[935]: connect from localhost[127.0.0.1] May 11 22:06:55 localhost amavis[29363]: (29363-02) smtp greeting: 220 xxx-xxx-xxx-xx.xxx.eu ESMTP Postfix, dt: 27.4 ms May 11 22:06:55 localhost amavis[29363]: (29363-02) smtp cmd> EHLO localhost May 11 22:06:55 localhost amavis[29363]: (29363-02) smtp resp to EHLO: 250 xxx-xxx-xxx-xx.xxx.eu\nPIPELINING\nSIZE\nVRFY\nETRN\nSTARTTLS\nENHANCEDSTATUSCODES\n8BITMIME\nDSN May 11 22:06:55 localhost amavis[29363]: (29363-02) AUTH not needed, user='', MTA offers '' May 11 22:06:55 localhost amavis[29363]: (29363-02) smtp cmd> MAIL FROM:info@absender.eu BODY=7BIT May 11 22:06:55 localhost amavis[29363]: (29363-02) smtp cmd> RCPT TO:info@empfaender.de ORCPT=rfc822;info@empfaender.de May 11 22:06:55 localhost amavis[29363]: (29363-02) smtp cmd> DATA May 11 22:06:55 localhost postfix/smtpd[935]: 89EE481160C6: client=localhost[127.0.0.1] May 11 22:06:55 localhost amavis[29363]: (29363-02) smtp resp to MAIL (pip): 250 2.1.0 Ok May 11 22:06:55 localhost amavis[29363]: (29363-02) smtp resp to RCPT (pip) (info@empfaender.de): 250 2.1.5 Ok May 11 22:06:55 localhost amavis[29363]: (29363-02) smtp resp to DATA: 354 End data with <CR><LF>.<CR><LF> May 11 22:06:55 localhost amavis[29363]: (29363-02) smtp cmd> QUIT May 11 22:06:55 localhost postfix/cleanup[930]: 89EE481160C6: message-id=d9fde519-0b1f-893a-8669-9a2ea5f37049@absender.eu May 11 22:06:55 localhost postfix/qmgr[32688]: 89EE481160C6: from=info@absender.eu, size=1995, nrcpt=1 (queue active) May 11 22:06:55 localhost postfix/smtpd[935]: disconnect from localhost[127.0.0.1] May 11 22:06:55 localhost amavis[29363]: (29363-02) smtp resp to data-dot (info@empfaender.de): 250 2.0.0 Ok: queued as 89EE481160C6, dt: 47.1 ms May 11 22:06:55 localhost amavis[29363]: (29363-02) Amavis::Out::SMTP::Session close, disconnecting May 11 22:06:55 localhost amavis[29363]: (29363-02) TZOuTG_zpFzU FWD from info@absender.eu -> info@empfaender.de, BODY=7BIT 250 2.0.0 from MTA(smtp:[127.0.0.1]:10027): 250 2.0.0 Ok: queued as 89EE481160C6 May 11 22:06:55 localhost amavis[29363]: (29363-02) DSN: sender is credible (orig), SA: -0.999, info@absender.eu May 11 22:06:55 localhost amavis[29363]: (29363-02) status counters: InMsgsStatus{Relayed,RelayedUntagged,RelayedUntaggedOriginating,RelayedUntaggedOutbound} May 11 22:06:55 localhost amavis[29363]: (29363-02) Passed CLEAN {RelayedOutbound}, ORIGINATING LOCAL [xxx.xxx.xxx.xxx]:53121 [xxx.xxx.xxx.xxx] info@absender.eu -> info@empfaender.de, Queue-ID: EF296809638B, Message-ID: d9fde519-0b1f-893a-8669-9a2ea5f37049@absender.eu, mail_id: TZOuTG_zpFzU, Hits: -0.999, size: 995, queued_as: 89EE481160C6, dkim_new=default:absender.eu, 1450 ms May 11 22:06:55 localhost amavis[29363]: (29363-02) TIMING-SA total 1203 ms - parse: 1.80 (0.1%), extract_message_metadata: 13 (1.1%), get_uri_detail_list: 0.99 (0.1%), tests_pri_-1000: 23 (1.9%), tests_pri_-950: 1.80 (0.1%), tests_pri_-900: 1.15 (0.1%), tests_pri_-400: 0.89 (0.1%), tests_pri_0: 837 (69.6%), check_dkim_adsp: 17 (1.4%), check_spf: 0.47 (0.0%), check_razor2: 769 (64.0%), check_pyzor: 0.32 (0.0%), tests_pri_500: 5 (0.4%), learn: 307 (25.5%), b_learn: 305 (25.3%), b_count_change: 6 (0.5%), get_report: 0.44 (0.0%) May 11 22:06:55 localhost amavis[29363]: (29363-02) sending SMTP response: "250 2.0.0 from MTA(smtp:[127.0.0.1]:10027): 250 2.0.0 Ok: queued as 89EE481160C6" May 11 22:06:55 localhost amavis[29363]: (29363-02) size: 995, TIMING [total 1461 ms] - SMTP greeting: 9 (1%)1, SMTP EHLO: 0.8 (0%)1, SMTP pre-MAIL: 0.6 (0%)1, lookup_sql: 7 (0%)1, SMTP pre-DATA-flush: 1.5 (0%)1, SMTP DATA: 31 (2%)3, check_init: 1.0 (0%)4, digest_hdr: 1.8 (0%)4, digest_body_dkim: 0.3 (0%)4, collect_info: 2.5 (0%)4, mime_decode: 13 (1%)5, get-file-type1: 44 (3%)8, decompose_part: 1.1 (0%)8, parts_decode: 0.0 (0%)8, check_header: 0.7 (0%)8, AV-scan-1: 9 (1%)8, spam-wb-list: 1.0 (0%)9, SA msg read: 0.9 (0%)9, SA parse: 3.1 (0%)9, SA check: 1199 (82%)91, decide_mail_destiny: 5 (0%)91, notif-quar: 0.8 (0%)91, write-header: 11 (1%)92, fwd-data-dkim: 7 (0%)93, fwd-connect: 32 (2%)95, fwd-mail-pip: 8 (1%)95, fwd-rcpt-pip: 0.3 (0%)95, fwd-data-chkpnt: 0.0 (0%)95, write-header: 0.5 (0%)95, fwd-data-contents: 0.1 (0%)95, fwd-end-chkpnt: 48 (3%)99, prepare-dsn: 1.5 (0%)99, report: 2.2 (0%)99, main_log_entry: 6 (0%)99, update_snmp: 8 (1%)100, SMTP pre-response: 0.3 (0%)100, SMTP response: 0.3 (0%)10... May 11 22:06:55 localhost amavis[29363]: (29363-02) ...0, unlink-1-files: 0.6 (0%)100, rundown: 0.9 (0%)100 May 11 22:06:55 localhost amavis[29363]: (29363-02) load: 0 %, total idle 16333.547 s, busy 4.859 s May 11 22:06:55 localhost postfix/smtp[931]: EF296809638B: to=info@empfaender.de, relay=127.0.0.1[127.0.0.1]:10026, delay=1.8, delays=0.26/0.03/0.01/1.5, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10027): 250 2.0.0 Ok: queued as 89EE481160C6) May 11 22:06:55 localhost postfix/qmgr[32688]: EF296809638B: removed May 11 22:06:55 localhost postfix/smtp[938]: Untrusted TLS connection established to empfaender.de[xx.xx.xxx.xxx]:25: TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits) May 11 22:06:56 localhost postfix/smtp[938]: 89EE481160C6: to=info@empfaender.de, relay=empfaender.de[xx.xx.xxx.xxx]:25, delay=0.86, delays=0.05/0.05/0.15/0.61, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as BC0E37EE0B8) May 11 22:06:56 localhost postfix/qmgr[32688]: 89EE481160C6: removed May 11 22:06:58 localhost postfix/submission/smtpd[912]: rewrite stream disconnect May 11 22:06:58 localhost postfix/submission/smtpd[912]: proxymap stream disconnect ########################################################################################
Ausschließen kann ich schon mal DNS Probleme, die Resolver lösen alles korrekt auf. Bin über jeden Tipp dankbar.
Am 11.05.2016 um 22:44 schrieb mhxhxhx@web.de:
May 11 22:06:07 localhost postfix/submission/smtpd[912]: xsasl_dovecot_server_mech_filter: keep mechanism: LOGIN ########################################################################################
Wieder der Delay:
########################################################################################
May 11 22:06:53 localhost postfix/submission/smtpd[912]: < xxx-xxx-xxx-xxx-xxx.xxxi.xxx.net[xxx.xxx.xxx.xxx]: EHLO [192.168.1.xxx]
kannst du mal das setup des submission zeigen und die logs von dovecot mit dem selben timestamp
May 11 22:20:06 localhost postfix/submission/smtpd[11027]: Anonymous TLS connection established from xxx-xxx-xxx-xxx-xxx.xxx.xxxnet[xxx.xxx.xxx.xxx]: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits) ########################################################################################
hier kommt der ~40 Sekunden delay
######################################################################################## May 11 22:20:53 localhost postfix/submission/smtpd[11027]: NOQUEUE: filter: RCPT from xxx-xxx-xxx-xxx-xxx.xxx.xxxnet[xxx.xxx.xxx.xxx]: info@absender.eu: Sender address triggers FILTER amavis:[127.0.0.1]:10026; from=info@absender.eu to=info@empfaenger.com proto=ESMTP helo=<[192.168.1.225]>
kannst du fuer einen test mal amavis rausnehmen ?
Best Regards MfG Robert Schetterer
participants (2)
-
mhxhxhx@web.de
-
Robert Schetterer