RE: Mails time before queue manager
Hi Viktor,
Thanks for your time and patience. I added the relay transport to reach
conrepmail.com and it became a bit faster yesterday. And today it is somehow
smooth but I still want to fasten it up. Is there any method through which
the mails to conrepmail.com can be stored on a local account and later I can
read them through POP3?
Kindly suggest.
-Original Message-
From: owner-postfix-us...@postfix.org
[mailto:owner-postfix-us...@postfix.org] On Behalf Of Viktor Dukhovni
Sent: Wednesday, April 02, 2014 9:27 PM
To: postfix-users@postfix.org
Subject: Re: Mails time before queue manager
On Wed, Apr 02, 2014 at 09:48:05AM +0530, KK Patnaik wrote:
1) [root@smtp2]#qshape incoming active deferred
T5 10204080 160
TOTAL 95414 8130 5019 11477 13835 33457 23496
conrepmail.com 16397 1871 606 1255 3142 6792 2731
aol.com 743 30 458397 308 180
vsoftconsulting.com 356 10 124943 14696
nihaki.com 308892447 13090
baanyan.com 277782642 11579
sbcglobal.net 270 1163037 10977
net.com 265 30 1928388367
erpanderp.com 2534 112932 10968
techgene.com 240 10 1219429166
stansource.com 2307 1135298563
a1k.com 2257826339358
canvasinfotech.com 2228733328458
comsys.com 221 25 1435296949
rsrit.com 2148 1128358844
usmsystems.com 2134 1326248759
compunnel.com 2118925289150
Out of ~96000 still queued messages that arrived in a 2--3 hour window, 1 in
6 is a bounce back to your own domain. If you're not a spammer, your list
management practices are extremely poor. If your intent is to process mail
for legitimate non-spamming customers, you are not doing a good job of
keeping the folks with garbage lists away.
Furthermore, why are bounces back to your own domain not delivered promptly?
Your bounce rate should probably be well below 2%, not 16%. You should be
using the relay transport to reach conrepmail.com so that bounces don't
queue behind outbound mail.
I asked for collated samples for delayed mail from some of the above most
delayed domains, below you show mail that was not substantially delayed.
You're wasting everyone's time presenting tiny crumbs of information, and
often the wrong crumbs.
There are still no c+d statistics (moving expontially decaying average
over time is best).
# If handling multi-recipient mail, process only the first of
# multiple log entries with same smtpd[pid] and same queue-id
# logged during the same minute.
#
foreach SMTP delivery # insert real code here
$meancd = 0.99 * $meancd + 0.01 * ($c + $d);
if ($count % 100 == 0) {
printf %s %s\n, $delivery_time, $meancd;
}
Mar 31 09:11:15 smtp2 postfix/smtpd[16466]: connect from
mm3.conrep.com[76.12.143.99] Mar 31 09:11:15 smtp2 postfix/qmgr[10231]:
8872C12400DC:
from=uemlmm3_87001237348238_100130003...@conrepmail.com, size=53529,
nrcpt=1 (queue active)
No delay entering the active queue, and this is not one of the domains at
the top of the qshape listing AND:
Mar 31 09:11:18 smtp2 postfix/smtp[15252]: 8872C12400DC:
to=ab...@promorphics.com,
relay=promorphics-com.mail.protection.outlook.com[207.46.163.138]:25,
delay=2.9, delays=0.07/0/0.16/2.6, dsn=2.6.0, status=sent
(250 2.6.0 20140331131115.8872c1240...@smtp2.conrepmail.com
[InternalId=22514218568637,
Hostname=DM2PR04MB527.namprd04.prod.outlook.com]
Queued mail for delivery)
the a + b delays here sum to 0.07 seconds. This is not a delayed message,
you're wasting everyone's time with this.
Mar 31 09:11:18 smtp2 postfix/smtp[12171]: A594712400EF:
to=ab...@itssonline.com,
relay=smtp.secureserver.net[68.178.213.37]:25,
delay=14, delays=0.05/0/5.6/8.3, dsn=5.2.0, status=bounced (host
smtp.secureserver.net[68.178.213.37] said: 552 5.2.0 kDB41n0172ClyZo01
- kDB41n0172ClyZo01DBAKn IB212 msg rejected as spam (in reply to end
of DATA
command))
Ditto, but now we see that some receving systems concur that the messages
are likely spam.
Apr 1 09:38:57 smtp2 postfix/smtp[20003]: 944671240115:
to=ab...@thoughtmill.com, relay=none, delay=6.1,
delays=0.04/3.5/2.6/0, dsn=4.4.3, status=deferred (Host or domain name
not found. Name service error for name=thoughtmill.com type=MX: Host
not found, try again)
Mail to a bogus domain, still low total delay, ...
Apr 1 09:38:58 smtp2 postfix/bounce[28306]: 944671240115: sender
non-delivery notification: 2769A124008B
Premature bounce
Re: Mails time before queue manager
On Wed, Apr 02, 2014 at 09:48:05AM +0530, KK Patnaik wrote:
1) [root@smtp2]#qshape incoming active deferred
T5 10204080 160
TOTAL 95414 8130 5019 11477 13835 33457 23496
conrepmail.com 16397 1871 606 1255 3142 6792 2731
aol.com 743 30 458397 308 180
vsoftconsulting.com 356 10 124943 14696
nihaki.com 308892447 13090
baanyan.com 277782642 11579
sbcglobal.net 270 1163037 10977
net.com 265 30 1928388367
erpanderp.com 2534 112932 10968
techgene.com 240 10 1219429166
stansource.com 2307 1135298563
a1k.com 2257826339358
canvasinfotech.com 2228733328458
comsys.com 221 25 1435296949
rsrit.com 2148 1128358844
usmsystems.com 2134 1326248759
compunnel.com 2118925289150
Out of ~96000 still queued messages that arrived in a 2--3 hour
window, 1 in 6 is a bounce back to your own domain. If you're not
a spammer, your list management practices are extremely poor. If
your intent is to process mail for legitimate non-spamming customers,
you are not doing a good job of keeping the folks with garbage lists
away.
Furthermore, why are bounces back to your own domain not delivered
promptly? Your bounce rate should probably be well below 2%, not
16%. You should be using the relay transport to reach
conrepmail.com so that bounces don't queue behind outbound mail.
I asked for collated samples for delayed mail from some of the
above most delayed domains, below you show mail that was not
substantially delayed. You're wasting everyone's time presenting
tiny crumbs of information, and often the wrong crumbs.
There are still no c+d statistics (moving expontially decaying
average over time is best).
# If handling multi-recipient mail, process only the first of
# multiple log entries with same smtpd[pid] and same queue-id
# logged during the same minute.
#
foreach SMTP delivery # insert real code here
$meancd = 0.99 * $meancd + 0.01 * ($c + $d);
if ($count % 100 == 0) {
printf %s %s\n, $delivery_time, $meancd;
}
Mar 31 09:11:15 smtp2 postfix/smtpd[16466]: connect from
mm3.conrep.com[76.12.143.99]
Mar 31 09:11:15 smtp2 postfix/qmgr[10231]: 8872C12400DC:
from=uemlmm3_87001237348238_100130003...@conrepmail.com, size=53529,
nrcpt=1 (queue active)
No delay entering the active queue, and this is not one of the domains
at the top of the qshape listing AND:
Mar 31 09:11:18 smtp2 postfix/smtp[15252]: 8872C12400DC:
to=ab...@promorphics.com,
relay=promorphics-com.mail.protection.outlook.com[207.46.163.138]:25,
delay=2.9, delays=0.07/0/0.16/2.6, dsn=2.6.0, status=sent
(250 2.6.0 20140331131115.8872c1240...@smtp2.conrepmail.com
[InternalId=22514218568637,
Hostname=DM2PR04MB527.namprd04.prod.outlook.com]
Queued mail for delivery)
the a + b delays here sum to 0.07 seconds. This is not a delayed
message, you're wasting everyone's time with this.
Mar 31 09:11:18 smtp2 postfix/smtp[12171]: A594712400EF:
to=ab...@itssonline.com, relay=smtp.secureserver.net[68.178.213.37]:25,
delay=14, delays=0.05/0/5.6/8.3, dsn=5.2.0, status=bounced (host
smtp.secureserver.net[68.178.213.37] said: 552 5.2.0 kDB41n0172ClyZo01 -
kDB41n0172ClyZo01DBAKn IB212 msg rejected as spam (in reply to end of DATA
command))
Ditto, but now we see that some receving systems concur that the
messages are likely spam.
Apr 1 09:38:57 smtp2 postfix/smtp[20003]: 944671240115:
to=ab...@thoughtmill.com, relay=none, delay=6.1, delays=0.04/3.5/2.6/0,
dsn=4.4.3, status=deferred (Host or domain name not found. Name service
error for name=thoughtmill.com type=MX: Host not found, try again)
Mail to a bogus domain, still low total delay, ...
Apr 1 09:38:58 smtp2 postfix/bounce[28306]: 944671240115: sender
non-delivery notification: 2769A124008B
Premature bounce due to disabled retries preventing interoperation
with greylisting...
Apr 1 09:38:56 smtp2 postfix/smtp[19719]: 6E35F1240105:
to=aks...@reliableassociates.com,
relay=mailstore1.secureserver.net[216.69.186.201]:25, delay=31,
delays=0.22/0.48/29/1.6, dsn=5.0.0, status=bounced (host
mailstore1.secureserver.net[216.69.186.201] said: 550 #5.1.0 Address
rejected. (in reply to RCPT TO command))
Poor list management still low cumulative delay, but finally a very
high $c, connecting to the backup MX.
Apr 1 09:38:57 smtp2 postfix/smtp[19972]: 7A0FD1240142:
to=ab...@betheltech.net, relay=none,
RE: Mails time before queue manager
Viktor, Do you think that the emails which are being delivered to conrepmail.com are posing problem, do you think the conrepmail.com domain is receiving slowly?
RE: Mails time before queue manager
Hi Viktor, 1) Please find the output of qshape in the link http://pastebin.com/pQ4h4pNY 2) Please find the top output at the time of peak hours top - 13:22:52 up 10:22, 3 users, load average: 5.36, 5.62, 5.62 Tasks: 276 total, 1 running, 275 sleeping, 0 stopped, 0 zombie Cpu0 : 1.0%us, 0.4%sy, 0.5%ni, 90.9%id, 7.2%wa, 0.0%hi, 0.0%si, 0.0%st Cpu1 : 1.9%us, 1.6%sy, 0.5%ni, 71.0%id, 24.3%wa, 0.1%hi, 0.7%si, 0.0%st Cpu2 : 0.9%us, 0.9%sy, 0.3%ni, 92.4%id, 5.3%wa, 0.0%hi, 0.3%si, 0.0%st Cpu3 : 0.9%us, 1.6%sy, 0.5%ni, 71.0%id, 25.1%wa, 0.2%hi, 0.8%si, 0.0%st Mem: 4138404k total, 457076k used, 3681328k free,44916k buffers Swap: 4096532k total,8k used, 4096524k free, 151240k cached 3) I ran the collate script sent by you. Checking that. Can you please suggest on the basis of qshape output and the CPU load?
Re: Mails time before queue manager
On Wed, Apr 02, 2014 at 04:28:48AM +0530, KK Patnaik wrote: 1) Please find the output of qshape in the link http://pastebin.com/pQ4h4pNY Sorry, I don't read pastebins. You need to post the output (or at least lines for the top 20 or so domains) to the list. 2) Please find the top output at the time of peak hours top - 13:22:52 up 10:22, 3 users, load average: 5.36, 5.62, 5.62 Tasks: 276 total, 1 running, 275 sleeping, 0 stopped, 0 zombie Cpu0 : 1.0%us, 0.4%sy, 0.5%ni, 90.9%id, 7.2%wa, 0.0%hi, 0.0%si, 0.0%st Cpu1 : 1.9%us, 1.6%sy, 0.5%ni, 71.0%id, 24.3%wa, 0.1%hi, 0.7%si, 0.0%st Cpu2 : 0.9%us, 0.9%sy, 0.3%ni, 92.4%id, 5.3%wa, 0.0%hi, 0.3%si, 0.0%st Cpu3 : 0.9%us, 1.6%sy, 0.5%ni, 71.0%id, 25.1%wa, 0.2%hi, 0.8%si, 0.0%st Mem: 4138404k total, 457076k used, 3681328k free,44916k buffers Swap: 4096532k total,8k used, 4096524k free, 151240k cached System is idle, which suggests high network latency, but impossible to tell without analyzing the logs! 3) I ran the collate script sent by you. Checking that. It will show the collated history of various messages in the queue, based on the qshape output's top domains, look for any clues to the delay experienced by the corresponding domains. If these destinations are throttled in the queue manager look for the messages for which delivery is actually attempted: postfix/smtp[pid]: qid: to=..., ... dsn=... rather than immediately deferred because the destination is throttled: postfix/qmgr[pid]: qid: to=... Can you please suggest on the basis of qshape output and the CPU load? Once you post the qshape output and some collated log entries for representative messages for highly delayed destinations. Feel free to obfuscate only the local part (user name) of the sender and recipient addresses, but NOT the domains, the actual domains may be essential to understanding why the queue is congested. -- Viktor.
RE: Mails time before queue manager
Hi Viktor, 1) [root@smtp2]#qshape incoming active deferred T5 10204080 160 320 640 1280 1280+ TOTAL 95414 8130 5019 11477 13835 33457 23496 0 00 0 conrepmail.com 16397 1871 606 1255 3142 6792 2731 0 00 0 aol.com 743 30 458397 308 180 0 00 0 vsoftconsulting.com 356 10 124943 14696 0 00 0 nihaki.com 308892447 13090 0 00 0 baanyan.com 277782642 11579 0 00 0 sbcglobal.net 270 1163037 10977 0 00 0 net.com 265 30 1928388367 0 00 0 erpanderp.com 2534 112932 10968 0 00 0 techgene.com 240 10 1219429166 0 00 0 stansource.com 2307 1135298563 0 00 0 a1k.com 2257826339358 0 00 0 canvasinfotech.com 2228733328458 0 00 0 comsys.com 221 25 1435296949 0 00 0 rsrit.com 2148 1128358844 0 00 0 usmsystems.com 2134 1326248759 0 00 0 compunnel.com 2118925289150 0 00 0 2) Mar 31 09:11:15 smtp2 postfix/smtpd[16466]: connect from mm3.conrep.com[76.12.143.99] Mar 31 09:11:15 smtp2 postfix/smtpd[16466]: 8872C12400DC: client=mm3.conrep.com[76.12.143.99], sasl_method=LOGIN, sasl_username=et2smtp Mar 31 09:11:15 smtp2 postfix/cleanup[16470]: 8872C12400DC: message-id=20140331131115.8872c1240...@smtp2.conrepmail.com Mar 31 09:11:15 smtp2 postfix/smtpd[16466]: disconnect from mm3.conrep.com[76.12.143.99] Mar 31 09:11:15 smtp2 postfix/qmgr[10231]: 8872C12400DC: from=uemlmm3_87001237348238_100130003...@conrepmail.com, size=53529, nrcpt=1 (queue active) Mar 31 09:11:18 smtp2 postfix/smtp[15252]: 8872C12400DC: to=ab...@promorphics.com, relay=promorphics-com.mail.protection.outlook.com[207.46.163.138]:25, delay=2.9, delays=0.07/0/0.16/2.6, dsn=2.6.0, status=sent (250 2.6.0 20140331131115.8872c1240...@smtp2.conrepmail.com [InternalId=22514218568637, Hostname=DM2PR04MB527.namprd04.prod.outlook.com] Queued mail for delivery) Mar 31 09:11:18 smtp2 postfix/qmgr[10231]: 8872C12400DC: removed Mar 31 09:11:04 smtp2 postfix/smtpd[16466]: connect from mm3.conrep.com[76.12.143.99] Mar 31 09:11:04 smtp2 postfix/smtpd[16466]: A594712400EF: client=mm3.conrep.com[76.12.143.99], sasl_method=LOGIN, sasl_username=et2smtp Mar 31 09:11:04 smtp2 postfix/cleanup[16500]: A594712400EF: message-id=20140331131104.a59471240...@smtp2.conrepmail.com Mar 31 09:11:04 smtp2 postfix/smtpd[16466]: disconnect from mm3.conrep.com[76.12.143.99] Mar 31 09:11:04 smtp2 postfix/qmgr[10231]: A594712400EF: from=uemlmm3_87001237344889_100130003...@conrepmail.com, size=52656, nrcpt=1 (queue active) Mar 31 09:11:18 smtp2 postfix/smtp[12171]: A594712400EF: to=ab...@itssonline.com, relay=smtp.secureserver.net[68.178.213.37]:25, delay=14, delays=0.05/0/5.6/8.3, dsn=5.2.0, status=bounced (host smtp.secureserver.net[68.178.213.37] said: 552 5.2.0 kDB41n0172ClyZo01 - kDB41n0172ClyZo01DBAKn IB212 msg rejected as spam (in reply to end of DATA command)) Mar 31 09:11:18 smtp2 postfix/bounce[15744]: A594712400EF: sender non-delivery notification: 89C8512400E9 Mar 31 09:11:18 smtp2 postfix/qmgr[10231]: A594712400EF: removed Apr 1 09:38:58 smtp2 postfix/bounce[28302]: 191E8124012C: sender non-delivery notification: 36CB512400FA Apr 1 09:38:58 smtp2 postfix/qmgr[2728]: 191E8124012C: removed Apr 1 09:38:49 smtp2 postfix/smtpd[26815]: connect from mm3.conrep.com[76.12.143.99] Apr 1 09:38:49 smtp2 postfix/smtpd[26815]: 944671240115: client=mm3.conrep.com[76.12.143.99], sasl_method=LOGIN, sasl_username=et2smtp Apr 1 09:38:49 smtp2 postfix/cleanup[25611]: 944671240115: message-id=20140401133849.944671240...@smtp2.conrepmail.com Apr 1 09:38:49 smtp2 postfix/smtpd[26815]: disconnect from mm3.conrep.com[76.12.143.99] Apr 1 09:38:49 smtp2 postfix/qmgr[2728]: 944671240115: from=uemlmm3_87001238209071_100130003...@conrepmail.com, size=33790, nrcpt=1 (queue active) Apr 1 09:38:57 smtp2 postfix/smtp[20003]: 944671240115: to=ab...@thoughtmill.com, relay=none, delay=6.1, delays=0.04/3.5/2.6/0, dsn=4.4.3, status=deferred (Host or domain name not found. Name service error for name=thoughtmill.com type=MX: Host not found, try again) Apr 1 09:38:57 smtp2 postfix/qmgr[2728]: 944671240115: from=uemlmm3_87001238209071_100130003...@conrepmail.com, status=expired, returned to sender Apr 1 09:38:58 smtp2 postfix/bounce[28306]: 944671240115: sender non-delivery notification: 2769A124008B Apr 1 09:38:58 smtp2 postfix/qmgr[2728]: 944671240115: removed Apr 1 09:38:25 smtp2 postfix/smtpd[26077]: connect from
RE: Mails time before queue manager
Hi Victor, I have emptied the notify_classes 1) Bounces are for outbound sent to lot of email addresses. And this is not spamming. We have mailing list server 4 numbers, those are maintained for around 80 clients, from there emails will be triggered through 9 SMTP servers where postfix is installed. Every server almost send half a million emails a day. These are only outbound servers. We have another one server oursmtpmail.com which receives all the bounces, etc. From this we read the inbox and include those hard / soft bouced emails to the skipped list and soft bounces would be released as per their reasons for skip. 2) qshape -s T5 10 20 40 80 160 320 640 1280 1280+ TOTAL 2466 2465 1 0 0 0 0 0 00 0 oursmtpmail.com 2118 2117 1 0 0 0 0 0 00 0 MAILER-DAEMON 348 348 0 0 0 0 0 0 00 0 The qshape information is around an hour back information. Now for last 40mins it's still at the command prompt and I am not seeing any output as of now. 3) Can you please suggest any tool which can give me ASCII histogram for the emails for the c+d delays. Now the postconf -n -- alias_database = hash:/etc/aliases alias_maps = hash:/etc/aliases bounce_queue_lifetime = 0 broken_sasl_auth_clients = yes command_directory = /usr/sbin config_directory = /etc/postfix daemon_directory = /usr/libexec/postfix debug_peer_level = 2 html_directory = no inet_interfaces = all local_recipient_maps = mail_owner = postfix mailq_path = /usr/bin/mailq.postfix manpage_directory = /usr/share/man maximal_queue_lifetime = 0 message_size_limit = 5024 mydestination = $myhostname, localhost.$mydomain, localhost mydomain = smtp2.oursmtpmail.com myhostname = smtp2.oursmtpmail.com newaliases_path = /usr/bin/newaliases.postfix non_smtpd_milters = unix:/var/run/dkim-milter/dkim-milter.sock, unix:/var/run/dk-milter/dk-milter.sock notify_classes = queue_directory = /var/spool/postfix queue_run_delay = 2m readme_directory = /usr/share/doc/postfix-2.3.3/README_FILES relay_domains = sample_directory = /usr/share/doc/postfix-2.3.3/samples sendmail_path = /usr/sbin/sendmail.postfix setgid_group = postdrop smtpd_banner = smtp2.oursmtpmail.com smtpd_client_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination, reject_unknown_sender_domain smtpd_delay_reject = yes smtpd_error_sleep_time = 1s smtpd_hard_error_limit = 20 smtpd_milters = unix:/var/run/dkim-milter/dkim-milter.sock, unix:/var/run/dk-milter/dk-milter.sock smtpd_recipient_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination smtpd_reject_unlisted_sender = yes smtpd_sasl_auth_enable = yes smtpd_sasl_path = private/auth smtpd_sasl_security_options = noanonymous smtpd_sasl_type = dovecot smtpd_soft_error_limit = 10 transport_maps = hash:/etc/postfix/transport unknown_local_recipient_reject_code = 550 virtual_alias_maps = hash:/etc/postfix/virtual virtual_mailbox_limit = 10240 -- Can you please suggest how to address the issue now?
Re: Mails time before queue manager
On Mon, Mar 31, 2014 at 10:55:04PM +0530, KK Patnaik wrote: 1) Bounces are for outbound sent to lot of email addresses. And this is not spamming. Many bulk email senders believe the spammers are all the other bulk senders, but not they. These are only outbound servers. 2) qshape -s Why -s, this gives no information about the destination of slow email. You should probably also scan the deferred queue, thus: # qshape incoming active deferred If the output device is a terminal, qshape will give you progressive output for every 1000 messages found. The qshape information is around an hour back information. Now for last 40mins it's still at the command prompt and I am not seeing any output as of now. Sounds like you got slammed with a bunch of new mail and your disk sub-system in not fast enough for qshape to read the entire queue in a timely manner, especially with mail processing competing. 3) Can you please suggest any tool which can give me ASCII histogram for the emails for the c+d delays. You write a Perl or Python script to parse this from delays=a/b/c/d in your own logs. bounce_queue_lifetime = 0 maximal_queue_lifetime = 0 Bad idea. non_smtpd_milters = unix:/var/run/dkim-milter/dkim-milter.sock, unix:/var/run/dk-milter/dk-milter.sock smtpd_milters = unix:/var/run/dkim-milter/dkim-milter.sock, unix:/var/run/dk-milter/dk-milter.sock Is this keeping up with the mail stream? Perhaps this is a bottleneck. You must read your logs and determine what's going on. Have you tried the collate script I've sent? Can you please suggest how to address the issue now? The data is in your logs, understanding them well enough to identify the problem source is your responsibility. You need to determine whether your CPU, network, disk or output concurrency are maxed out, or whether remote destinations are throttling your deliveries, ... Perhaps you syslogd is misconfigured and is logging synchronously. See LINUX_README.html. That would cause the disk to be swamped. -- Viktor.
RE: Mails time before queue manager
Hi Viktor, I have done the changes mentioned by you and now I see the delay has decreased from around 6hours to 1hour. Now I would still like to reduce the delay please suggest. About the questions raised by you, yes the SMTP server generates bounces messages and yes too many postmaster notices. Please suggest.
Re: Mails time before queue manager
On Sat, Mar 29, 2014 at 10:09:51PM +0530, KK Patnaik wrote: About the questions raised by you, yes the SMTP server generates bounces messages and yes too many postmaster notices. http://www.postfix.org/postconf.5.html#notify_classes (set it empty) 1. You have said nothing about whether the bounces are for inbound mail to invalid recipients (fix recipient validation, which you disabled) or caused by outbound mail sent to invalid addresses (fix your mailing lists). http://www.postfix.org/ADDRESS_CLASS_README.html http://www.postfix.org/postconf.5.html#local_recipient_maps http://www.postfix.org/postconf.5.html#virtual_mailbox_maps http://www.postfix.org/postconf.5.html#relay_recipient_maps 2. You have not posted any information from QSHAPE despite multiple attempts to point you at: http://www.postfix.org/QSHAPE_README.html 3. You have not posted the requested statistics of c+d delays sampled over a few hours of mail deliveries (mean, median, and an ASCII histogram would be useful). 4. Congestion is not a single message phenomenon, you MUST identify the bottleneck by understanding which destinations account for the majority of the delays, where that mail originates, and why its delivery is slow. Please don't waste our time with further questions that are not backed by the relevant quantitative information. -- Viktor.
RE: Mails time before queue manager
Please find my actual logs for the delays only. Please advise on how to handle this. I need to see that the delivery doesn't slow down because in this rate the emails are delivered after around 3-4hours. [root@smtp9 ~]# tail -f /var/log/maillog | grep delays Mar 24 13:58:33 smtp9 postfix/smtp[41918]: BC419297520: to=soh...@techpatch.com, relay=ASPMX.L.GOOGLE.com[74.125.142.26]:25, delay=8382, delays=8303/78/0.12/0.72, dsn=2.0.0, status=sent (250 2.0.0 OK 1395770359 j5si28607068igj.39 - gsmtp) Mar 24 13:58:33 smtp9 postfix/smtp[41638]: 3295D299F17: to=hgir...@skillstorm.com, relay=barr01.krns-inc.com[69.43.181.38]:25, delay=3937, delays=3857/79/0.22/0.95, dsn=2.0.0, status=sent (250 Ok: queued as CE7B791043) Mar 24 13:58:33 smtp9 postfix/error[41901]: B632CF2948D: to=indr...@softpros.com, relay=none, delay=94251, delays=94251/0.03/0/0.09, dsn=4.4.3, status=deferred (delivery temporarily suspended: Host or domain name not found. Name service error for name=softpros.com type=MX: Host not found, try again) Mar 24 13:58:34 smtp9 postfix/error[41880]: B8A8D2A445C: to=btal...@techpeople.com, relay=none, delay=87344, delays=87344/0.1/0/0.12, dsn=4.4.1, status=deferred (delivery temporarily suspended: connect to techpeople.com[199.59.243.107]:25: Connection timed out) Mar 24 13:58:34 smtp9 postfix/smtp[41918]: BBCC12A26EC: to=sul...@dsysinfotech.com, relay=ALT1.ASPMX.L.GOOGLE.com[173.194.68.26]:25, delay=87726, delays=87647/78/0.52/0.08, dsn=4.2.2, status=deferred (host ALT1.ASPMX.L.GOOGLE.com[173.194.68.26] said: 452-4.2.2 The email account that you tried to reach is over quota. Please direct 452-4.2.2 the recipient to 452 4.2.2 http://support.google.com/mail/bin/answer.py?answer=6558 u15si11052933qge.3 - gsmtp (in reply to RCPT TO command)) Mar 24 13:58:34 smtp9 postfix/smtp[41212]: B4DA7298D3C: to=ta...@ravebsi.com, relay=none, delay=7953, delays=7852/81/20/0, dsn=4.4.3, status=deferred (Host or domain name not found. Name service error for name=ravebsi.com type=MX: Host not found, try again) Mar 24 13:58:34 smtp9 postfix/error[41891]: B53FBF28174: to=st...@iqinc.com, relay=none, delay=99163, delays=99163/0.05/0/0.23, dsn=4.4.3, status=deferred (delivery temporarily suspended: Host or domain name not found. Name service error for name=iqinc.com type=MX: Host not found, try again) Mar 24 13:58:34 smtp9 postfix/smtp[41526]: BAF70288F50: to=fai...@jobaccord.com, relay=none, delay=81540, delays=81433/77/30/0, dsn=4.4.1, status=deferred (connect to jobaccord.com[207.189.109.121]:25: Connection timed out) Mar 24 13:58:34 smtp9 postfix/smtp[41212]: B10BF29F6A9: to=d...@win-sys.com, relay=none, delay=5877, delays=5798/79/0.39/0, dsn=4.4.1, status=deferred (connect to win-sys.com[219.94.217.210]:25: Connection refused) Mar 24 13:58:35 smtp9 postfix/smtp[41510]: B431DD698F0: to=saty...@capsinnovative.com, relay=none, delay=93923, delays=93823/80/20/0, dsn=4.4.3, status=deferred (Host or domain name not found. Name service error for name=capsinnovative.com type=MX: Host not found, try again) Mar 24 13:58:35 smtp9 postfix/smtp[41490]: 08796295060: to=sg_san...@sbcglobal.net, relay=mx2.sbcglobal.am0.yahoodns.net[98.138.206.39]:25, delay=9052, delays=8973/78/0.13/1.2, dsn=2.0.0, status=sent (250 ok dirdel) Mar 24 13:58:35 smtp9 postfix/error[41882]: BC864DA9F92: to=m...@globaltek-inc.com, relay=none, delay=352755, delays=352755/0.11/0/0.13, dsn=4.4.1, status=deferred (delivery temporarily suspended: connect to globaltek-inc.com[208.73.211.164]:25: Connection timed out) Mar 24 13:58:35 smtp9 postfix/error[41879]: A0F4528EAC0: to=prak...@psdinc.com, relay=none, delay=10813, delays=10812/0.09/0/0.06, dsn=4.4.3, status=deferred (delivery temporarily suspended: Host or domain name not found. Name service error for name=psdinc.com type=MX: Host not found, try again) Mar 24 13:58:35 smtp9 postfix/smtp[41720]: B7310D319AF: to=jnell...@entersoftsolutions.com, relay=none, delay=100406, delays=100306/80/20/0, dsn=4.4.3, status=deferred (Host or domain name not found. Name service error for name=entersoftsolutions.com type=MX: Host not found, try again) Mar 24 13:58:35 smtp9 postfix/error[41891]: B1D52D2CB9E: to=a...@globaltek-inc.com, relay=none, delay=343163, delays=343162/0.06/0/0.09, dsn=4.4.1, status=deferred (delivery temporarily suspended: connect to globaltek-inc.com[208.73.211.164]:25: Connection timed out) Mar 24 13:58:35 smtp9 postfix/error[41807]: B39EED2C7A8: to=d...@careerconsultation.net, relay=none, delay=98252, delays=98252/0.02/0/0.07, dsn=4.4.1, status=deferred (delivery temporarily suspended: connect to careerconsultation.net[68.168.84.111]:25: Connection timed out) Mar 24 13:58:35 smtp9 postfix/smtp[41918]: A9230D48EA3: to=na...@dvinfotek.com, relay=mx00.1and1.com[74.208.5.3]:25, delay=14355, delays=14275/79/0.23/0.87, dsn=2.0.0, status=sent (250 Message 0Lm1wv-1X1IDZ3s37-00aH7V accepted by mxus2.perfora.net) Mar 24 13:58:35 smtp9 postfix/smtp[41490]: F3129290DB9: to=vkat...@bpm-solutions.net,
Re: Mails time before queue manager
On 3/25/2014 1:02 PM, KK Patnaik wrote: Please find my actual logs for the delays only. Please advise on how to handle this. I need to see that the delivery doesn't slow down because in this rate the emails are delivered after around 3-4hours. Did you see Viktor's reply last week? https://www.mail-archive.com/postfix-users@postfix.org/msg56980.html [root@smtp9 ~]# tail -f /var/log/maillog | grep delays This is uninteresting except many of these seem to be undeliverable for various reasons. See Viktor's reply for how to find useful information. I'm guessing these are undeliverable bounces. A queue clogged with undeliverable bounces will perform poorly. You must not accept mail that can't be delivered. Find answers to the questions Viktor raises, and review the documentation links he sent. -- Noel Jones
RE: Mails time before queue manager
Mar 20 10:06:59 smtp2 postfix/smtpd[9007]: 25142124292D: client=mm3. oursmtpmail.com[xx.xx.xx.xx], sasl_method=LOGIN, sasl_username=2smtp Mar 20 10:06:59 smtp2 postfix/cleanup[10918]: 25142124292D: message-id=20140320140659.25142124292D@smtp2. oursmtpmail.com Mar 20 10:19:52 smtp2 postfix/qmgr[7470]: 25142124292D: from=uemlmm1_87001230297...@oursmtpmail.com, size=58126, nrcpt=1 (queue active) Mar 20 10:43:55 smtp2 postfix/smtp[13548]: 25142124292D: to=s...@gmail.net, relay=aspmx.l.google.com[74.125.142.26]:25, delay=2217, delays=775/1441/0.14/1.4, dsn=2.0.0, status=sent (250 2.0.0 OK 1395326635 ac8si2519638icc.108 - gsmtp) Mar 20 10:43:55 smtp2 postfix/qmgr[7470]: 25142124292D: removed -Original Message- From: owner-postfix-us...@postfix.org [mailto:owner-postfix-us...@postfix.org] On Behalf Of Wietse Venema Sent: Thursday, March 20, 2014 9:51 PM To: Postfix users Subject: Re: Mails time before queue manager KK Patnaik: I am having issue with my SMTP servers where the mails are taking long time before the queue manager. Mar 20 10:43:55 smtp2 postfix/smtp[13548]: 25142124292D: to=s...@gmail.net, relay=aspmx.l.google.com[74.125.142.26]:25, delay=29217, delays=29775/1441/0.14/1.4, dsn=2.0.0, status=sent (250 2.0.0 OK 1395326635 ac8si2519638icc.108 - gsmtp What is the output from: $ grep 25142124292D /the/maillog/file Wietse
Re: Mails time before queue manager
KK Patnaik: Mar 20 10:43:55 smtp2 postfix/smtp[13548]: 25142124292D: to=s...@gmail.net, relay=aspmx.l.google.com[74.125.142.26]:25, delay=29217, delays=29775/1441/0.14/1.4, dsn=2.0.0, status=sent (250 2.0.0 OK 1395326635 ac8si2519638icc.108 - gsmtp Here, the message is in the queue for 29217 seconds. Wietse: What is the output from: $ grep 25142124292D /the/maillog/file KK Patnaik: Mar 20 10:06:59 smtp2 postfix/smtpd[9007]: 25142124292D: client=mm3. oursmtpmail.com[xx.xx.xx.xx], sasl_method=LOGIN, sasl_username=2smtp ... Mar 20 10:43:55 smtp2 postfix/smtp[13548]: 25142124292D: to=s...@gmail.net, relay=aspmx.l.google.com[74.125.142.26]:25, delay=2217, delays=775/1441/0.14/1.4, dsn=2.0.0, status=sent (250 2.0.0 OK 1395326635 ac8si2519638icc.108 - gsmtp) This message has been in the queue for 2217 seconds, which is consistent with arrival at 10:06:59 and delivery at 10:43:55. Why did you report (see top of this message) that this message was queued for 29217 seconds? Wietse
RE: Mails time before queue manager
Most of the messages are staying in the queue for such long time and that is delaying the delivery of the mail to the recipient. -Original Message- From: owner-postfix-us...@postfix.org [mailto:owner-postfix-us...@postfix.org] On Behalf Of Wietse Venema Sent: Friday, March 21, 2014 5:18 PM To: Postfix users Subject: Re: Mails time before queue manager KK Patnaik: Mar 20 10:43:55 smtp2 postfix/smtp[13548]: 25142124292D: to=s...@gmail.net, relay=aspmx.l.google.com[74.125.142.26]:25, delay=29217, delays=29775/1441/0.14/1.4, dsn=2.0.0, status=sent (250 2.0.0 OK 1395326635 ac8si2519638icc.108 - gsmtp Here, the message is in the queue for 29217 seconds. Wietse: What is the output from: $ grep 25142124292D /the/maillog/file KK Patnaik: Mar 20 10:06:59 smtp2 postfix/smtpd[9007]: 25142124292D: client=mm3. oursmtpmail.com[xx.xx.xx.xx], sasl_method=LOGIN, sasl_username=2smtp ... Mar 20 10:43:55 smtp2 postfix/smtp[13548]: 25142124292D: to=s...@gmail.net, relay=aspmx.l.google.com[74.125.142.26]:25, delay=2217, delays=775/1441/0.14/1.4, dsn=2.0.0, status=sent (250 2.0.0 OK 1395326635 ac8si2519638icc.108 - gsmtp) This message has been in the queue for 2217 seconds, which is consistent with arrival at 10:06:59 and delivery at 10:43:55. Why did you report (see top of this message) that this message was queued for 29217 seconds? Wietse
Re: Mails time before queue manager
KK Patnaik: Most of the messages are staying in the queue for such long time and that is delaying the delivery of the mail to the recipient. So you just added 29 thousand seconds of delay by hand. You just wasted my time with false evidence. Goodbye. Wietse -Original Message- From: owner-postfix-us...@postfix.org [mailto:owner-postfix-us...@postfix.org] On Behalf Of Wietse Venema Sent: Friday, March 21, 2014 5:18 PM To: Postfix users Subject: Re: Mails time before queue manager KK Patnaik: Mar 20 10:43:55 smtp2 postfix/smtp[13548]: 25142124292D: to=s...@gmail.net, relay=aspmx.l.google.com[74.125.142.26]:25, delay=29217, delays=29775/1441/0.14/1.4, dsn=2.0.0, status=sent (250 2.0.0 OK 1395326635 ac8si2519638icc.108 - gsmtp Here, the message is in the queue for 29217 seconds. Wietse: What is the output from: $ grep 25142124292D /the/maillog/file KK Patnaik: Mar 20 10:06:59 smtp2 postfix/smtpd[9007]: 25142124292D: client=mm3. oursmtpmail.com[xx.xx.xx.xx], sasl_method=LOGIN, sasl_username=2smtp ... Mar 20 10:43:55 smtp2 postfix/smtp[13548]: 25142124292D: to=s...@gmail.net, relay=aspmx.l.google.com[74.125.142.26]:25, delay=2217, delays=775/1441/0.14/1.4, dsn=2.0.0, status=sent (250 2.0.0 OK 1395326635 ac8si2519638icc.108 - gsmtp) This message has been in the queue for 2217 seconds, which is consistent with arrival at 10:06:59 and delivery at 10:43:55. Why did you report (see top of this message) that this message was queued for 29217 seconds? Wietse
RE: Mails time before queue manager
No I didn't add anything. There are lot of logs like that in my server. I am just trying to resolve the delay of the emails. Please advise. -Original Message- From: owner-postfix-us...@postfix.org [mailto:owner-postfix-us...@postfix.org] On Behalf Of Wietse Venema Sent: Friday, March 21, 2014 8:06 PM To: Postfix users Subject: Re: Mails time before queue manager KK Patnaik: Most of the messages are staying in the queue for such long time and that is delaying the delivery of the mail to the recipient. So you just added 29 thousand seconds of delay by hand. You just wasted my time with false evidence. Goodbye. Wietse -Original Message- From: owner-postfix-us...@postfix.org [mailto:owner-postfix-us...@postfix.org] On Behalf Of Wietse Venema Sent: Friday, March 21, 2014 5:18 PM To: Postfix users Subject: Re: Mails time before queue manager KK Patnaik: Mar 20 10:43:55 smtp2 postfix/smtp[13548]: 25142124292D: to=s...@gmail.net, relay=aspmx.l.google.com[74.125.142.26]:25, delay=29217, delays=29775/1441/0.14/1.4, dsn=2.0.0, status=sent (250 2.0.0 OK 1395326635 ac8si2519638icc.108 - gsmtp Here, the message is in the queue for 29217 seconds. Wietse: What is the output from: $ grep 25142124292D /the/maillog/file KK Patnaik: Mar 20 10:06:59 smtp2 postfix/smtpd[9007]: 25142124292D: client=mm3. oursmtpmail.com[xx.xx.xx.xx], sasl_method=LOGIN, sasl_username=2smtp ... Mar 20 10:43:55 smtp2 postfix/smtp[13548]: 25142124292D: to=s...@gmail.net, relay=aspmx.l.google.com[74.125.142.26]:25, delay=2217, delays=775/1441/0.14/1.4, dsn=2.0.0, status=sent (250 2.0.0 OK 1395326635 ac8si2519638icc.108 - gsmtp) This message has been in the queue for 2217 seconds, which is consistent with arrival at 10:06:59 and delivery at 10:43:55. Why did you report (see top of this message) that this message was queued for 29217 seconds? Wietse
RE: Mails time before queue manager
On Sat, 22 Mar 2014, KK Patnaik wrote: No I didn't add anything. There are lot of logs like that in my server. I am just trying to resolve the delay of the emails. Please advise. Please do not top-post on this mailing list. KK Patnaik: Mar 20 10:43:55 smtp2 postfix/smtp[13548]: 25142124292D: to=s...@gmail.net, relay=aspmx.l.google.com[74.125.142.26]:25, delay=29217, delays=29775/1441/0.14/1.4, dsn=2.0.0, status=sent (250 2.0.0 OK 1395326635 ac8si2519638icc.108 - gsmtp Mar 20 10:43:55 smtp2 postfix/smtp[13548]: 25142124292D: to=s...@gmail.net, relay=aspmx.l.google.com[74.125.142.26]:25, delay=2217, delays=775/1441/0.14/1.4, dsn=2.0.0, status=sent (250 2.0.0 OK 1395326635 ac8si2519638icc.108 - gsmtp) You are either deliberately lying or you are in so far over your head that you have no business being anywhere near any computer as an administrator. Do you not see that two log excertps above, both sent by you, are the same except that the delays in the first one have been changed from 2217 to 29217 and from 775 to 29775? The first (which was what you sent originally) is obviously doctored as the delay componenents do not equal the total delay (29775 is greater than 29217 so even before getting to the last three delay components, it's obviously bogus). As Wietse said, you've wasted our time. And if you don't know who Wietse is, I suggest you do a search on his name before posting here again. -- Larry Stone lston...@stonejongleux.com
Re: Mails time before queue manager
On Fri, Mar 21, 2014 at 03:25:58PM -0500, Larry Stone wrote: You are either deliberately lying or you are in so far over your head that you have no business being anywhere near any computer as an administrator. While the OP is not helping by modifying the very information that could be used to solve his problem, the above is taking the admonition way to far. Please apologize and try to stay calm. The OP needs to analyze his logs as a body of data, not single points. One message does not create congestion, which is a result of many messages. Therefore, in addition to employing the tools described in QSHAPE_README, the OP needs to disclose any relevant configuration settings, in particular any rate limited transports, non-default concurrency settings, ... What's critical is to understand where most of the mail is going, whether there are any DNS misconfiguration issues slowing down MX resolution, ... The message input rates and output rates need to be measured and compared. Also the mean c+d value needs to be computed to determine whether there is sufficient output concurrency to deliver the input rate. Notification settings need to be adjusted to reduce congestion from notices about congestion, and recipient validation MUST be enabled properly. -- Viktor.
Re: Mails time before queue manager
On Fri, 21 Mar 2014, Viktor Dukhovni wrote: While the OP is not helping by modifying the very information that could be used to solve his problem, the above is taking the admonition way to far. Please apologize and try to stay calm. I'm calm. But I apologize for the apparent tone of my reply. -- Larry Stone lston...@stonejongleux.com
Mails time before queue manager
Hi, I am having issue with my SMTP servers where the mails are taking long time before the queue manager. Mar 20 10:43:55 smtp2 postfix/smtp[13548]: 25142124292D: to=s...@gmail.net, relay=aspmx.l.google.com[74.125.142.26]:25, delay=29217, delays=29775/1441/0.14/1.4, dsn=2.0.0, status=sent (250 2.0.0 OK 1395326635 ac8si2519638icc.108 - gsmtp Output of postconf -n --- alias_database = hash:/etc/aliases alias_maps = hash:/etc/aliases bounce_queue_lifetime = 0 broken_sasl_auth_clients = yes command_directory = /usr/sbin config_directory = /etc/postfix daemon_directory = /usr/libexec/postfix debug_peer_level = 2 html_directory = no inet_interfaces = all local_recipient_maps = mail_owner = postfix mailq_path = /usr/bin/mailq.postfix manpage_directory = /usr/share/man maximal_queue_lifetime = 0 message_size_limit = 5024 mydestination = $myhostname, localhost.$mydomain, localhost mydomain = smtp2.oursmtpmail.com myhostname = smtp2.oursmtpmail.com newaliases_path = /usr/bin/newaliases.postfix non_smtpd_milters = unix:/var/run/dkim-milter/dkim-milter.sock, unix:/var/run/dk-milter/dk-milter.sock notify_classes = bounce, delay, resource queue_directory = /var/spool/postfix queue_run_delay = 2m readme_directory = /usr/share/doc/postfix-2.3.3/README_FILES sample_directory = /usr/share/doc/postfix-2.3.3/samples sendmail_path = /usr/sbin/sendmail.postfix setgid_group = postdrop smtpd_banner = smtp2.oursmtpmail.com smtpd_client_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination, reject_unknown_sender_domain smtpd_delay_reject = no smtpd_error_sleep_time = 1s smtpd_hard_error_limit = 20 smtpd_milters = unix:/var/run/dkim-milter/dkim-milter.sock, unix:/var/run/dk-milter/dk-milter.sock smtpd_recipient_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination smtpd_reject_unlisted_sender = yes smtpd_sasl_auth_enable = yes smtpd_sasl_path = private/auth smtpd_sasl_security_options = noanonymous smtpd_sasl_type = dovecot smtpd_soft_error_limit = 10 transport_maps = hash:/etc/postfix/transport unknown_local_recipient_reject_code = 550 virtual_alias_maps = hash:/etc/postfix/virtual virtual_mailbox_limit = 10240 Please advise on how to resolve this.
Re: Mails time before queue manager
KK Patnaik: I am having issue with my SMTP servers where the mails are taking long time before the queue manager. Mar 20 10:43:55 smtp2 postfix/smtp[13548]: 25142124292D: to=s...@gmail.net, relay=aspmx.l.google.com[74.125.142.26]:25, delay=29217, delays=29775/1441/0.14/1.4, dsn=2.0.0, status=sent (250 2.0.0 OK 1395326635 ac8si2519638icc.108 - gsmtp What is the output from: $ grep 25142124292D /the/maillog/file Wietse
Re: Mails time before queue manager
On Thu, Mar 20, 2014 at 09:26:12PM +0530, KK Patnaik wrote: I am having issue with my SMTP servers where the mails are taking long time before the queue manager. http://www.postfix.org/QSHAPE_README.html http://www.postfix.org/TUNING_README.html Mar 20 10:43:55 smtp2 postfix/smtp[13548]: 25142124292D: to=s...@gmail.net, relay=aspmx.l.google.com[74.125.142.26]:25, delay=29217, delays=29775/1441/0.14/1.4, dsn=2.0.0, status=sent (250 2.0.0 OK 1395326635 ac8si2519638icc.108 - gsmtp Is this a bounce? Or a regular outbound message. With congested queues, a single log entry is not that interesting, you need to understand the average behaviour of the queue. You MUST analyze your logs. - Where is most mail coming from? - At what rate? - Where is mail going? - At what rate? - What is the typical delivery latency (c+d in delays=a/b/c/d)? - Are you generating bounces? Too many postmaster notices? - ... Understand what your system is doing, then ask for help. bounce_queue_lifetime = 0 maximal_queue_lifetime = 0 These are rather unwise. Why have you disabled delivery retries? mydomain = smtp2.oursmtpmail.com myhostname = smtp2.oursmtpmail.com mydestination = $myhostname, localhost.$mydomain, localhost local_recipient_maps = Why have you disabled recipient validation? You accept and then bounce mail to invalid recipients, this congests your queue. Consider setting: # Empty, default is (effectively sub-domains of) $mydestination relay_domains = notify_classes = bounce, delay, resource On a congested mailserver, you're far better off setting: # empty notify_classes = and monitor logs instead. smtpd_delay_reject = no smtpd_client_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination, reject_unknown_sender_domain With smtpd_delay_reject = no, there is no login, recipient or sender information at connect time, so this setting is pointless. smtpd_recipient_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination An RBL or two might help. smtpd_reject_unlisted_sender = yes There are no unlisted senders, because local_recipient_maps is empty, and you have no virtual_mailbox_domains. -- Viktor.
