3

One of our SMTP servers is slow accepting emails, here is the typical output (response time 30+ seconds) from a smtp client script:

2014-02-26 11:44:11 +0800 BEGIN
2014-02-26 11:44:11 +0800 LOGGED IN
2014-02-26 11:44:11 +0800 BEFORE SEND
2014-02-26 11:44:59 +0800 AFTER SEND
2014-02-26 11:44:59 +0800 END

The ruby script:

message = <<MESSAGE_END
From: One <[email protected]>
To: Two <[email protected]>
Subject: SMTP e-mail test

Testing 123
MESSAGE_END

def timelog(msg)
  puts "#{Time.now} #{msg}"
end

timelog("BEGIN")
Net::SMTP.start(host, 25, 'localhost', username, password, :plain) do |smtp|
  timelog("LOGGED IN")
  timelog("BEFORE SEND")
  smtp.send_message message, '[email protected]', ['[email protected]']
  timelog("AFTER SEND")
end
timelog("END")

How can I improve the performance?

UPDATE (with DNS time info, loading):

# time dig yahoo.com mx

; <<>> DiG 9.8.2rc1-RedHat-9.8.2-0.17.rc1.el6_4.5 <<>> yahoo.com mx
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 57858
;; flags: qr rd ra; QUERY: 1, ANSWER: 3, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;yahoo.com.         IN  MX

;; ANSWER SECTION:
yahoo.com.      528 IN  MX  1 mta7.am0.yahoodns.net.
yahoo.com.      528 IN  MX  1 mta5.am0.yahoodns.net.
yahoo.com.      528 IN  MX  1 mta6.am0.yahoodns.net.

;; Query time: 5 msec
;; SERVER: 8.8.8.8#53(8.8.8.8)
;; WHEN: Fri Mar 21 12:26:09 2014
;; MSG SIZE  rcvd: 106


real        0m1.013s
user        0m0.004s
sys         0m0.004s

top, it's a new server so there is almost no loading:

Cpu(s):  0.2%us,  0.0%sy,  0.0%ni, 99.5%id,  0.3%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:   1903696k total,  1310776k used,   592920k free,   311492k buffers
Swap:  4095992k total,        0k used,  4095992k free,   822692k cached

UPDATE (telnet):

# telnet 127.0.0.1 25
Trying 127.0.0.1...
Connected to 127.0.0.1.
Escape character is '^]'.
220 m1.example.com ESMTP Sendmail 8.14.4/8.14.4; Tue, 25 Mar 2014 14:47:04 +0800
HELO 127.0.0.1
250 m1.example.com Hello localhost [127.0.0.1], pleased to meet you
AUTH LOGIN
334 VXNlcm5hbWU6
bWUuY29t
334 UGFzc3dvcmQ6
cGFzc3dvcmQ=
235 2.0.0 OK Authenticated
MAIL FROM: [email protected]
250 2.1.0 [email protected]... Sender ok
RCPT TO: [email protected]
250 2.1.5 [email protected]... Recipient ok
DATA
354 Enter mail, end with "." on a line by itself
Testing 12345
.
250 2.0.0 s2P6l4Dj012326 Message accepted for delivery
QUIT
221 2.0.0 m1.example.com closing connection
Connection closed by foreign host.

Note, both MAIL FROM and RCPT TO takes around 20 seconds before OK is returned. The other commands response instantly.

UPDATE, FEATURE('delay_checks'):

Enable FEATURE('delay_checks') greatly improves the response time from 30+ seconds to ~10 seconds. The ~10 second delay is between MAIL FROM: and Sender ok:

MAIL FROM: [email protected]
(- 10 second delay -)
250 2.1.0 [email protected]... Sender ok

UPDATE again, it looks like the delay is very similar to what is described in the book Sendmail by Bryan Costales, page 258:

enter image description here

It is not a DNS issue, as dig and nslookup response quickly:

# time nslookup mta5.am0.yahoodns.net
Server:     8.8.8.8
Address:    8.8.8.8#53

Non-authoritative answer:
Name:   mta5.am0.yahoodns.net
Address: 66.196.118.240
Name:   mta5.am0.yahoodns.net
Address: 98.138.112.34
Name:   mta5.am0.yahoodns.net
Address: 66.196.118.37
Name:   mta5.am0.yahoodns.net
Address: 98.138.112.32
Name:   mta5.am0.yahoodns.net
Address: 98.136.217.203
Name:   mta5.am0.yahoodns.net
Address: 98.138.112.33
Name:   mta5.am0.yahoodns.net
Address: 98.138.112.38
Name:   mta5.am0.yahoodns.net
Address: 63.250.192.46


real        0m1.016s
user        0m0.001s
sys         0m0.006s

UPDATE with sendmail.mc:

# cat /etc/mail/sendmail.mc | grep -v "^dnl"
divert(-1)dnl
include(`/usr/share/sendmail-cf/m4/cf.m4')dnl
VERSIONID(`setup for linux')dnl
OSTYPE(`linux')dnl
define(`confLOG_LEVEL', `14')dnl
define(`SMART_HOST', `mail03.example.com')dnl
define(`confDEF_USER_ID', ``8:12'')dnl
define(`confTO_CONNECT', `1m')dnl
define(`confTRY_NULL_MX_LIST', `True')dnl
define(`confDONT_PROBE_INTERFACES', `True')dnl
define(`PROCMAIL_MAILER_PATH', `/usr/bin/procmail')dnl
define(`ALIAS_FILE', `/etc/aliases')dnl
define(`STATUS_FILE', `/var/log/mail/statistics')dnl
define(`UUCP_MAILER_MAX', `2000000')dnl
define(`confUSERDB_SPEC', `/etc/mail/userdb.db')dnl
define(`confPRIVACY_FLAGS', `authwarnings,novrfy,noexpn,restrictqrun')dnl
define(`confAUTH_OPTIONS', `A y')dnl
define(`confCW_FILE', `/etc/mail/local-host-names')dnl
define(`confDOMAIN_NAME', `domain.example.com')dnl
define(`confMAX_MESSAGE_SIZE',`23271520')dnl
TRUST_AUTH_MECH(`LOGIN PLAIN DIGEST-MD5 CRAM-MD5')dnl
define(`confAUTH_MECHANISMS', `LOGIN PLAIN DIGEST-MD5 CRAM-MD5')dnl
define(`confTO_QUEUERETURN', `1d')dnl
define(`confTO_IDENT', `0')dnl
FEATURE(`delay_checks')dnl
FEATURE(`no_default_msa', `dnl')dnl
FEATURE(`smrsh', `/usr/sbin/smrsh')dnl
FEATURE(`mailertable', `hash -o /etc/mail/mailertable.db')dnl
FEATURE(`virtusertable', `hash -o /etc/mail/virtusertable.db')dnl
FEATURE(redirect)dnl
FEATURE(always_add_domain)dnl
FEATURE(use_cw_file)dnl
FEATURE(use_ct_file)dnl
FEATURE(local_procmail, `', `procmail -t -Y -a $h -d $u')dnl
FEATURE(`access_db', `hash -T<TMPF> -o /etc/mail/access.db')dnl
FEATURE(`blacklist_recipients')dnl
EXPOSED_USER(`root')dnl
DAEMON_OPTIONS(`Port=smtp,Addr=0.0.0.0, Name=MTA M=a')dnl
FEATURE(`accept_unresolvable_domains')dnl
LOCAL_DOMAIN(`localhost.localdomain')dnl
MASQUERADE_AS(`example.com')dnl
FEATURE(masquerade_entire_domain)dnl
MAILER(smtp)dnl
MAILER(procmail)dnl
8
  • 1
    i suspect dns on the mail server... but there is really absolutely no way for us to know anything with the provided details Feb 26, 2014 at 4:15
  • 2
    Please provide more details: system, MTA, configuration. What is load, iops and cputime for this machine?
    – neutrinus
    Feb 26, 2014 at 10:05
  • Yeah. this smells like some configuration issue and while you are wonderuflly describin "IT IS SLOW" you never even tell us what IT is.
    – TomTom
    Mar 21, 2014 at 6:20
  • You never provided the requested information, so this question remains unanswerable. You need to provide at least the mail server information and check the mail server logs. Mar 21, 2014 at 11:24
  • The information requested is still not provided.
    – Jenny D
    Mar 25, 2014 at 8:32

6 Answers 6

4

I would suggest if possible executing some manual commands to interact with the SMTP server and see what step is causing the delay.

Note that you should execute this from the same machine that your code is running from. If the results are slow then try the same commands from a different machine to see if it related to the machine being sent from or if it is the same regardless of the location being sent from.

• Type: telnet smtp.server.com 25 and hit enter
     The Command will connect to the smtp server on port 25 
     which is used by the SMTP server to communicate
• Type: HELO localhost and hit enter 
     You can type anything instead of localhost like yourdomain.com
• Type: MAIL FROM: [email protected] and hit enter
     Replace [email protected] with your email address
• Type RCPT TO: [email protected] and hit enter
     Replace [email protected] to the email address you want to send the email to
• Type: DATA and hit enter
• Type: this is a test email and hit enter
• Type: . and hit enter
• Type: QUIT and hit enter
2
  • Both MAIL FROM and RCPT TO take about 20 seconds to return OK, details in UPDATE (telnet) part of question.
    – ohho
    Mar 25, 2014 at 7:03
  • RCPT TO responses instantly after enabling FEATURE('delay_checks'). MAIL FROM still takes ~10 seconds.
    – ohho
    Mar 26, 2014 at 3:44
2

You do not tell us anything about your configuration, but according to your "log", connexion time and enveloppe-processing time are ok, it is only the processing of the body of the mail which is slow.

So here are 2 explanations, in order of probabilty:

  1. You have a mail filter ( spamassassin or anything ) which processes all incoming emails. This is where your problem is.
  2. The mail queue of your server is located on a network share which is incredibly slow to access.

If you need more clues, please detail your smtp configuration: software, configuration files, os configuration.

0

A mail server can perform a lot of validations of the sender address. Most of these validations involve DNS lookups. If DNS is misconfigured on the server or if the sender domain is misconfigured some of these DNS lookups can time out. Reverse DNS on the client IP could also have been misconfigured such that lookups time out.

Two checks that are sometimes performed involve other network communication.

The mail server may connect to the auth daemon on the client IP address. If the client uses a misconfigured firewall, the SYN packet send to port 113 is lost. After a few attempts the server will give up.

The mail server may also connect to the MX for the sender domain to validate that the sender address exists. That particular check is rarely used since it can fail spectacularly if done wrong.

To identify which of the above is the case, one need to inspect the network traffic. That inspection can be done using tcpdump or wireshark.

0

Try attaching strace to your sendmail process and see what it gives you acter the you manually type the mail from command (of course you should make sure nobody else is using the SMTP service by that time. This should give you a better idea of which sender check is slow. If unsure how to use Steve this simple blog post may be of some help (especially chapter 3 and 4).

http://www.hokstad.com/5-simple-ways-to-troubleshoot-using-strace

0

The fact that you're seeing delay between "MAIL FROM" and next command implies that sendmail is validating the sender address. This does strongly suggest a DNS/networking issue but you say that DNS lookups by hand are OK. If this mail server is using a DNS server under your control, could you try turning on query logging to see what questions are being asked (and how long the DNS server is taking to respond)?

You say "one of our SMTP servers is slow accepting emails". This implies that your other SMTP servers don't exhibit this behaviour. Is that the case? If so what's different about this one?

If the problem server is in production use you might like to try starting up an extra instance of sendmail listening on a different port so that you can turn up the debug level. An alternative would be to use strace as alxgomz suggests. If you make an initial connection using telnet you can just strace the child process that's handling your message rather than all SMTP connections.

-2

Are you using example.com in your test (as your ruby script states)? Perhaps you're having trouble when there are no MX records to be returned. Have you tried this with real email addresses? Is the delay only for certain domains?

1
  • example.com is for hiding the real domains. the smtp runs OK (all mails are delivered properly), I just don't know where to check why it takes so long to accept a email.
    – ohho
    Mar 21, 2014 at 6:02

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .