How to read SMTP logs

In my previous post I referenced common SMTP response codes and a general overview of how these responses are used in SMTP. This time I wanted to provide you with real examples using logs from VisNetic Mail Server.

Logs are such an important part of troubleshooting mail server delivery problems and outlining the basic SMTP conversation between a mail server and an email client or another mail server will help in understanding the logs. Let's start with a simplified log example showing the conversation. The following is a valid SMTP conversation.

S: = response from mail server.

C: = response from email client or Internet mail server

Mail server receiving incoming mail. Incoming mail can be from a mail server on the Internet or an email client located on your mail servers local network. This example shows an Internet mail server (yahoo.com, gmail.com, etc...) connecting to your mail server, and is after the Internet mail server made a successful connection to your mail server.

Incoming and Outgoing Explained. When an email client opens a connection for delivery it connects to a predefined hostname or IP address, when a mail server delivers mail it typically resolves the email address domain to an MX record (outgoing mail) and connects to a listening mail server on port 25. The mail server greets the connecting client with their domain name and possibly mail server type and version. The mail session continues with single responses from the mail server and client. For example, after the mail server responds with the server greeting message the client is required to respond with the next allowed command for SMTP. Once the client properly responses the mail server will respond accordingly. This continues until the message is delivered.

Mail Server sending outgoing mail. If your mail server is delivering outgoing mail the log will show commands in the reverse order. Your mail server is now acting as an email client sending outgoing mail to the Internet, here's an example,

VisNetic Mail Server log. The logs in VisNetic Mail Server are very detailed and provided information such as the IP address, session ID, whether it's a client or server response, incoming or outgoing, and all server/client code responses.

Read log from left to right, example,

IP Address, [Session ID], Time, '>>>' response from Server, '<<<' response from Client, command/response.

Successful Incoming Connection:

The IP address on an incoming connection is the IP of the remote mail server. If the message was to multiple recipients you would see multiple RCPT TO: commands referencing each recipient.

Failed Incoming Connection:

This incoming connection failed for unknown user.

>>> 550 5.1.1 unknown_user@test.com User unknown; rejecting

The response from the mail server was 550, which is a permanent delivery failure (all 5xx errors are permanent), and this would typically end the SMTP session unless multiple recipients were included in the message. See my SMTP Responses and Error Codes post for more info.

Successful Outgoing Connection:

The IP address for outgoing connections is the IP of the mail server it's connecting to, and the log also included 'Client session', indicating an outgoing message. Not all mail servers will log this way but a good indicator of an outgoing message is reference to resolving the MX record. Resolving the MX record is required for outgoing messages and VisNetic Mail Server indicates this with a system log entry 'DNS query 'yahoo.com' 0 (7) [OK - 1]'.

Failed Outgoing Connection:

This failed outgoing connection is to Yahoo.com.

<<< href="http://en.wikipedia.org/wiki/Greylisting">Greylisting. Your mail server will automatically retry delivery.

These SMTP log examples are fairly typical success/failure attempts and I hope it helps explains how to read SMTP logs.

SMTP Responses and Error Codes

The SMTP protocol is fairly complex and attempting to troubleshoot a problem sometimes requires an in depth knowledge of how SMTP works before you can fix the problem. You could read through the SMTP RFC 2821 and probably fall asleep within 10 minutes, so to help diagnose SMTP delivery problems I put together the more important elements of SMTP that can help you diagnose SMTP delivery problems.

Before we get started I have to mention that the information in this post is directly from RFC 2821 and the Full Copyright Statement is included at the bottom of RFC 2821.

http://www.ietf.org/rfc/rfc2821.txt

Common SMTP codes. SMTP response codes include success, intermediate, transient, and permanent responses. The SMTP protocol requires that server/client responses consist of a series of commands that will specify sender and recipient(s) and eventually the delivery of email. Responses are successional, which in my opinion helps when analyzing mail server logs. For example, when an email client makes a connection to the mail server the mail server must respond to the clients connection, after the server responds the client must respond, and so on and so on... receiving or not receiving a response can help isolate problems because of the successional requirement of SMTP.

Code Definitions

2xx codes = Success

3xx codes = Intermediate

4xx codes = Transient Negative reply

5xx codes = Permanent Negative reply

Common Reply Codes in Numeric Order

211 - System status, or system help reply
214 - Help message
220 - Service ready
221 - Service closing transmission channel
250 - Requested mail action okay, completed
251 - User not local; will forward to
252 - Cannot VRFY user, but will accept message and attempt delivery
354 - Start mail input; end with .
421 - Service not available, closing transmission channel
450 - Requested mail action not taken: mailbox unavailable
451 - Requested action aborted: local error in processing
452 - Requested action not taken: insufficient system storage
500 - Syntax error, command unrecognized
501 - Syntax error in parameters or arguments
502 - Command not implemented
503 - Bad sequence of commands
504 - Command parameter not implemented
550 - Requested action not taken: mailbox unavailable
551 - User not local; please try
552 - Requested mail action aborted: exceeded storage allocation
553 - Requested action not taken: mailbox name not allowed
554 - Transaction failed

SMTP Connection Overview

Command Reply Sequences. In the sequence example below each command is listed with its usual possible replies. The client connects, the mail server responds (greeting message), the client responds (EHLO name), the mail server responds (250 OK), client responds (MAIL FROM: client@domain.com), etc... The prefixes used before the possible replies are 'I' for intermediate, 'S' for success, and 'E' for error. Since some servers may generate other replies under special circumstances, and to allow for future extension, SMTP clients should, when possible, interpret only the first digit of the reply and must be prepared to deal with unrecognized reply codes by interpreting the first digit only. SMTP servers must not transmit reply codes to an SMTP client that are other than three digits or that do not start in a digit between 2 and 5 inclusive.

Specific sequences are:

Conclusion. Using the sequences above and referencing them to your SMTP logs will provide you with a guide to what type of failure occurred, at what point in the SMTP session it failed, and whether the SMTP session completed successfully with the QUIT command.

Why is it important to know when the failure occurred? Most mail servers have a host of security features that are implemented at certain command sequences, for example, after the MAIL FROM command your mail server may run ESMTP size checks, rDNS, MX record check, or DNSBL. If these tests fail your mail server will respond appropriately, with a 4xx or 5xx error which will end the SMTP session. Another example would be after the DATA command, any failures after the DATA command would indicate that your mail server ran tests for message headers, body, virus, or spam, then takes action based on the condition. The test may reject, delete, or accept (whitelist) the message. It is important to know where the failure occurred so you can review specific features on your mail server and make corrections or concede valid rejection.

How to find auto start-up programs in Windows

Here's another really good utility from Sysinternals that will show you start-up or auto-run programs in Windows.

AutoRuns for Windows v9.35

This utility, which has the most comprehensive knowledge of auto-starting locations of any startup monitor, shows you what programs are configured to run during system bootup or login, and shows you the entries in the order Windows processes them. These programs include ones in your startup folder, Run, RunOnce, and other Registry keys. You can configure Autoruns to show other locations, including Explorer shell extensions, toolbars, browser helper objects, Winlogon notifications, auto-start services, and much more. Autoruns goes way beyond the MSConfig utility bundled with Windows Me and XP.

You even have the option of removing or disabling auto-run items from this utility, which saves time when trying to find the start-up location in the harddrive or registry.

Even though this utility may be best suited for the desktop computer or laptop that's plagued by annoying spyware or viruses it's certainly not a bad idea to know what's auto starting on your mail server computer.