Delay bei Mailversand

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
2 messages Options
Reply | Threaded
Open this post in threaded view
|

Delay bei Mailversand

mhxhxhx
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]: <[hidden email]>: Sender address triggers FILTER amavis:[127.0.0.1]:10026; from=<[hidden email]> to=<[hidden email]> 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=[hidden email]
May 11 22:20:53 localhost postfix/cleanup[11043]: 8E7E1809638C: message-id=<[hidden email]>
May 11 22:20:53 localhost postfix/qmgr[10095]: 8E7E1809638C: from=<[hidden email]>, 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=<[hidden email]>
May 11 22:20:55 localhost postfix/qmgr[10095]: 3718181160CC: from=<[hidden email]>, 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] <[hidden email]> -> <[hidden email]>, Queue-ID: 8E7E1809638C, Message-ID: <[hidden email]>, 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=<[hidden email]>, 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=<[hidden email]>, 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=[hidden email]
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:<[hidden email]> 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: <[hidden email]>
May 11 22:06:53 localhost postfix/submission/smtpd[912]: smtpd_check_addr: addr=[hidden email]
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 = [hidden email]
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: [hidden email]
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: [hidden email] -> [hidden email]
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 = [hidden email]
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: [hidden email]
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: `' -> `[hidden email]' -> transp=`dovecot' host=`absender.eu' rcpt=`[hidden email]' flags= class=virtual
May 11 22:06:53 localhost postfix/submission/smtpd[912]: ctable_locate: install entry key [hidden email]
May 11 22:06:53 localhost postfix/submission/smtpd[912]: extract_addr: in: <[hidden email]>, result: [hidden email]
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: [hidden email]
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 -> [hidden email]
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:<[hidden email]>
May 11 22:06:53 localhost postfix/submission/smtpd[912]: extract_addr: input: <[hidden email]>
May 11 22:06:53 localhost postfix/submission/smtpd[912]: smtpd_check_addr: addr=[hidden email]
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 = [hidden email]
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: [hidden email]
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: [hidden email] -> [hidden email]
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 = [hidden email]
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: [hidden email]
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: `' -> `[hidden email]' -> transp=`smtp' host=`empfaender.de' rcpt=`[hidden email]' flags= class=default
May 11 22:06:53 localhost postfix/submission/smtpd[912]: ctable_locate: install entry key [hidden email]
May 11 22:06:53 localhost postfix/submission/smtpd[912]: extract_addr: in: <[hidden email]>, result: [hidden email]
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: [hidden email]
May 11 22:06:53 localhost postfix/submission/smtpd[912]: ctable_locate: move existing entry key [hidden email]
May 11 22:06:53 localhost postfix/submission/smtpd[912]: check_access: [hidden email]
May 11 22:06:53 localhost postfix/submission/smtpd[912]: dict_regexp_lookup: /etc/postfix/tag_as_originating.re: [hidden email]
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 [hidden email]
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]: <[hidden email]>: Sender address triggers FILTER amavis:[127.0.0.1]:10026; from=<[hidden email]> to=<[hidden email]> 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 [hidden email]
May 11 22:06:53 localhost postfix/submission/smtpd[912]: maps_find: recipient_canonical_maps: [hidden email]: 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: [hidden email] -> (not found)
May 11 22:06:53 localhost postfix/submission/smtpd[912]: maps_find: canonical_maps: [hidden email]: 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: [hidden email] -> (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 = [hidden email]
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=[hidden email] -> 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 = [hidden email]
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=[hidden email] -> status=1 result=
May 11 22:06:53 localhost postfix/submission/smtpd[912]: maps_find: virtual_alias_maps: [hidden email]: 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: [hidden email] -> (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=[hidden email]
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=<[hidden email]>
May 11 22:06:54 localhost postfix/qmgr[32688]: EF296809638B: from=<[hidden email]>, 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: <[hidden email]> -> <[hidden email]> 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 <[hidden email]>; 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] <[hidden email]> -> <[hidden email]>
May 11 22:06:54 localhost amavis[29363]: (29363-02) 2822.From: <[hidden email]>
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: [hidden email]
May 11 22:06:55 localhost amavis[29363]: (29363-02) dkim: candidate originators: From:<[hidden email]>
May 11 22:06:55 localhost amavis[29363]: (29363-02) dkim: signing (author), From: <[hidden email]> (From:<[hidden email]>), 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:<[hidden email]> BODY=7BIT
May 11 22:06:55 localhost amavis[29363]: (29363-02) smtp cmd> RCPT TO:<[hidden email]> ORCPT=rfc822;[hidden email]
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) (<[hidden email]>): 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=<[hidden email]>
May 11 22:06:55 localhost postfix/qmgr[32688]: 89EE481160C6: from=<[hidden email]>, 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 (<[hidden email]>): 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 <[hidden email]> -> <[hidden email]>, 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, <[hidden email]>
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] <[hidden email]> -> <[hidden email]>, Queue-ID: EF296809638B, Message-ID: <[hidden email]>, 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=<[hidden email]>, 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=<[hidden email]>, 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.
Reply | Threaded
Open this post in threaded view
|

Re: Delay bei Mailversand

Robert Schetterer-2
Am 11.05.2016 um 22:44 schrieb [hidden email]:

> 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]:
<[hidden email]>: Sender address triggers FILTER
amavis:[127.0.0.1]:10026; from=<[hidden email]>
to=<[hidden email]> proto=ESMTP helo=<[192.168.1.225]>

kannst du fuer einen test mal amavis rausnehmen ?


Best Regards
MfG Robert Schetterer

--
[*] sys4 AG

http://sys4.de, +49 (89) 30 90 46 64
Franziskanerstraße 15, 81669 München

Sitz der Gesellschaft: München, Amtsgericht München: HRB 199263
Vorstand: Patrick Ben Koetter, Marc Schiffbauer
Aufsichtsratsvorsitzender: Florian Kirstein