with respect to my previous question about address verification, i think
i'm not understanding address_verify_poll_delay correctly. while
working on troubleshooting the 6.2 second delay during the smtp
handshake, i'd set address_verify_poll_delay to 15 seconds, expecting
that postfix would then wait up to that long for verification of an
address to occur. after doing this, i noticed 15 second delays in
between each recipient verification, which i wasn't expecting [see below
log excerpt]. is this expected? i interpreted an address verification
request to be each of the individual probes shown in the log excerpt,
and so expected postfix to wait up to that long for each to complete,
but not wait that long in between each probe once successful.
thanks
-ben
Jul 9 16:48:16 msa01 postfix/smtpd[31514]: connect from
clientl.example.com[10.68.15.100]
Jul 9 16:48:16 msa01 postfix/smtpd[31514]: Anonymous TLS connection
established from clientl.example.com[10.68.15.100]: TLSv1 with cipher
ECDHE-RSA-AES256-SHA (256/256 bits)
Jul 9 16:48:16 msa01 postfix/cleanup[31493]: 3h7szh5t3yzJnMV:
message-id=<3h7szh5t3yzj...@msa.example.com>
Jul 9 16:48:16 msa01 postfix/qmgr[24500]: 3h7szh5t3yzJnMV:
from=<double-bou...@example.com>, size=216, nrcpt=1 (queue active)
Jul 9 16:48:16 msa01 postfix/lmtp[31505]: 3h7szh5t3yzJnMV:
to=<testuser-3...@example.com>, relay=mda.example.com[10.59.1.57]:7025,
delay=0.04, delays=0.03/0/0.01/0.01, dsn=2.1.5, status=deliverable (250
2.1.5 Recipient OK)
Jul 9 16:48:16 msa01 postfix/qmgr[24500]: 3h7szh5t3yzJnMV: removed
Jul 9 16:48:31 msa01 postfix/smtpd[31514]: 3h7szz6skPzJnMV:
client=clientl.example.com[10.68.15.100], sasl_method=PLAIN,
sasl_username=user01
Jul 9 16:48:32 msa01 postfix/cleanup[31520]: 3h7szz74sKzJnP1:
message-id=<3h7szz74skzj...@msa.example.com>
Jul 9 16:48:32 msa01 postfix/qmgr[24500]: 3h7szz74sKzJnP1:
from=<double-bou...@example.com>, size=216, nrcpt=1 (queue active)
Jul 9 16:48:32 msa01 postfix/lmtp[31512]: 3h7szz74sKzJnP1:
to=<testuser-3...@example.com>, relay=mda.example.com[10.59.1.57]:7025,
delay=0.25, delays=0.24/0/0.01/0.01, dsn=2.1.5, status=deliverable (250
2.1.5 Recipient OK)
Jul 9 16:48:32 msa01 postfix/qmgr[24500]: 3h7szz74sKzJnP1: removed
Jul 9 16:48:47 msa01 postfix/cleanup[31520]: 3h7t0H0BFrzJnP1:
message-id=<3h7t0h0bfrzj...@msa.example.com>
Jul 9 16:48:47 msa01 postfix/qmgr[24500]: 3h7t0H0BFrzJnP1:
from=<double-bou...@example.com>, size=216, nrcpt=1 (queue active)
Jul 9 16:48:47 msa01 postfix/lmtp[31505]: 3h7t0H0BFrzJnP1:
to=<testuser-3...@example.com>, relay=mda.example.com[10.59.1.57]:7025,
delay=0.04, delays=0.01/0/0.01/0.01, dsn=2.1.5, status=deliverable (250
2.1.5 Recipient OK)
Jul 9 16:48:47 msa01 postfix/qmgr[24500]: 3h7t0H0BFrzJnP1: removed
Jul 9 16:49:02 msa01 postfix/cleanup[31520]: 3h7t0Z0VHwzJnP1:
message-id=<3h7t0z0vhwzj...@msa.example.com>
Jul 9 16:49:02 msa01 postfix/qmgr[24500]: 3h7t0Z0VHwzJnP1:
from=<double-bou...@example.com>, size=216, nrcpt=1 (queue active)
Jul 9 16:49:02 msa01 postfix/lmtp[31512]: 3h7t0Z0VHwzJnP1:
to=<testuser-3...@example.com>, relay=mda.example.com[10.59.1.57]:7025,
delay=0.02, delays=0.01/0/0/0.01, dsn=2.1.5, status=deliverable (250
2.1.5 Recipient OK)
Jul 9 16:49:02 msa01 postfix/qmgr[24500]: 3h7t0Z0VHwzJnP1: removed
Jul 9 16:49:17 msa01 postfix/cleanup[31520]: 3h7t0s0qsyzJnP1:
message-id=<3h7t0s0qsyzj...@msa.example.com>
Jul 9 16:49:17 msa01 postfix/qmgr[24500]: 3h7t0s0qsyzJnP1:
from=<double-bou...@example.com>, size=216, nrcpt=1 (queue active)
Jul 9 16:49:17 msa01 postfix/lmtp[31505]: 3h7t0s0qsyzJnP1:
to=<testuser-3...@example.com>, relay=mda.example.com[10.59.1.57]:7025,
delay=0.03, delays=0.01/0/0.01/0, dsn=2.1.5, status=deliverable (250
2.1.5 Recipient OK)
Jul 9 16:49:17 msa01 postfix/qmgr[24500]: 3h7t0s0qsyzJnP1: removed
