Logging the SMTP Service

by Amit Zinman [Published on 21 Jan. 2004 / Last Updated on 21 Jan. 2004]

SMTP logging can, at times, the key to troubleshooting many mail problems by providing valuable information regarding incoming mail. It can also be used for providing statistics on mail flow from the Internet. The following article describes the secrets of logging SMTP activities for troubleshooting and other purposes.

In Exchange 5.5, logging could be done using the Event Viewer. Thankfully, SMTP logging is now provided by IIS, the foundation to Exchange 2000/3 is now separate and writes the information to regular text-based log files. It can also write the log files to a SQL database using ODBC allowing integration of SMTP logging and general monitoring software.

To enable logging go to the SMTP virtual service property page General tab.

The logging as can be seen in these screen shots is general and intended also for protocols other than SMTP.

The log files are typically located under %systemroot%\system32\logfiles.

As you can see from this screenshot my server logs all kinds of IIS activity. The Exchange log files are located under the SMTPSVC1 directory. The default file names for these logs include the date of creation.

A typical log file would look like this:

#Software: Microsoft Internet Information Services 5.0
#Version: 1.0
#Date: 2003-11-25 08:20:10
#Fields: date time c-ip cs-username s-sitename s-computername s-ip s-port cs-method cs-uri-stem cs-uri-query sc-status sc-win32-status sc-bytes cs-bytes time-taken cs-version cs-host cs(User-Agent) cs(Cookie) cs(Referer)
2003-11-25 08:20:10 300.300.300.5 yweb SMTPSVC1 EXCHANGE1 192.168.1.100 0 EHLO - +yweb 250 0 325 13 60 SMTP - - - -
2003-11-25 08:20:10 300.300.300.5 yweb SMTPSVC1 EXCHANGE1 192.168.1.100 0 MAIL - +FROM:<nfcnews@hothothot.com> 250 0 46 33 20 SMTP - - - -
2003-11-25 08:20:10 300.300.300.5 yweb SMTPSVC1 EXCHANGE1 192.168.1.100 0 RCPT - +TO:<dani@domain.com> 250 0 31 28 10 SMTP - - - -
2003-11-25 08:20:10 300.300.300.5 yweb SMTPSVC1 EXCHANGE1 192.168.1.100 0 BDAT - +<YWEBWgtc2S6AATi0000b0ae@yweb> 250 0 76 101761 831 SMTP - - - -
2003-11-25 08:20:11 300.300.300.5 yweb SMTPSVC1 EXCHANGE1 192.168.1.100 0 QUIT - yweb 240 1512 69 4 0 SMTP - - - -
2003-11-25 08:22:17 100.100.100.5 OutboundConnectionResponse SMTPSVC1 EXCHANGE1 - 25 - - 220+mail.elpelpelp.com+SMTP;+Tue,+25+Nov+2003+11:18:14++0200 0 0 57 0 10656 SMTP - - - -
2003-11-25 08:22:17 100.100.100.5 OutboundConnectionCommand SMTPSVC1 EXCHANGE1 - 25 EHLO - EXCHANGE1.domain.local 0 0 4 0 10656 SMTP - - - -
2003-11-25 08:22:17 100.100.100.5 OutboundConnectionResponse SMTPSVC1 EXCHANGE1 - 25 - - 250+mail.elpelpelp.com+Hello 0 0 25 0 10696 SMTP - - - -
2003-11-25 08:22:17 100.100.100.5 OutboundConnectionCommand SMTPSVC1 EXCHANGE1 - 25 MAIL - FROM:<haya@domain.com> 0 0 4 0 10826 SMTP - - - -
2003-11-25 08:22:17 100.100.100.5 OutboundConnectionResponse SMTPSVC1 EXCHANGE1 - 25 - - 250+<haya@domain.com>...+Sender+ok 0 0 37 0 10966 SMTP - - - -
2003-11-25 08:22:17 100.100.100.5 OutboundConnectionCommand SMTPSVC1 EXCHANGE1 - 25 RCPT - TO:<zolpzolp@elpelpelp.com> 0 0 4 0 10966 SMTP - - - -
2003-11-25 08:22:17 100.100.100.5 OutboundConnectionResponse SMTPSVC1 EXCHANGE1 - 25 - - 250+<zolpzolp@elpelpelp.com>...+Recipient+ok 0 0 41 0 11006 SMTP - - - -
2003-11-25 08:22:17 100.100.100.5 OutboundConnectionCommand SMTPSVC1 EXCHANGE1 - 25 DATA - - 0 0 4 0 11026 SMTP - - - -
2003-11-25 08:22:17 100.100.100.5 OutboundConnectionResponse SMTPSVC1 EXCHANGE1 - 25 - - 354+Enter+mail,+end+with+"."+on+a+line+by+itself 0 0 48 0 11056 SMTP - - - -
2003-11-25 08:25:12 200.200.200.5 relay.mepmepmep.co.ilSMTPSVC1 EXCHANGE1 192.168.1.100 0 EHLO - +relay.mepmepmep.co.il250 0 324 36 0 SMTP - - - -
2003-11-25 08:25:16 200.200.200.5 relay.mepmepmep.co.ilSMTPSVC1 EXCHANGE1 192.168.1.100 0 MAIL - +FROM:<alex@ininin.org.il> 250 0 45 53 0 SMTP - - - -
2003-11-25 08:25:45 200.200.200.5 relay.mepmepmep.co.ilSMTPSVC1 EXCHANGE1 192.168.1.100 0 RCPT - +TO:<israel@domain.com> 250 0 33 51 0 SMTP - - - -

This, especially for large volumes of mail traffic, is not that easy to read. To simplify matters you can import this file to Excel or any other spreadsheet application. To do this copy the log files contents beginning rights after where it says "#Fields :"  to a new text file using notepad or any other text editor. This leaves a space delimited file ready for import.

I've deleted some columns that are repetitive such as the Exchange server name and IP address, and the port used. What's left is the time that the connection was made, the IP address of the mail server from which the connection was made, the SMTP command also called verb), how many bytes were transferred and the time it took (in milliseconds).

Once the information is in Excel it is easier to view the information and use it to find out how much mail is coming in and out, who mails you the most (in some cases these is might not be friendly people) and you can be sure that you a certain mail item, even if a user or some virus protection program deleted this item. 

Featured Links