Email administrators nowadays face several challenges: raised email traffic seen in the network in the past years came along with more and more spam and phising hitting quiet hard the mail infrastructure. Almost daily complaints about end users calling the hotline why they once more received spam right through to their mailbox even when it is 'so obvious that this is spam'. Thanks to the Cisco IronPort Email Security Appliance the helpdesk calls with spam complaints from end users can drop significantly so the email administrator can focus on different topics again.
Email is more and more seen as a real time communication media and is now far away from the first mail sent back in 1969 at a time where not everyone had a broadband access at home. Some email admins can still remember the 'good old days' where sending a mail to a specific destination involved relaying via another mailserver that had a dedicated line connected to the final destination. Email addresses such as firstname.lastname@example.org@otherdomain.com have been common and source routing was the way to get the email through the UUCP network based on dedicated connections between servers.This technique is now obsolete but still attempted by spammers as the RFC still allows it.
The world has changed and so the end user perception of the service 'email' has. A message sent around the globe should not take more than fraction of a second and even when the email administrator tries to tell the end users that 'email is not instant messaging' they still expect it certainly is. So the new challenge for the email administrator is now the hotline call from the end user with 'Where is my email?'
Also here the Cisco IronPort Email Security Appliance can assist the email administrator on this. The mail_logs files in plain text format as well as the GUI based Message Tracking feature allows to find the answer to the end user question right on the phone call.
As email messages are forwarded between several mail servers until it reaches the destination mailbox, they experience delays. How can the administrator tell where the delay occurrs? Let's dig into the mail_logs of a Cisco IronPort Email Security Appliance and see how we as an email administrator could tell where the email of the end user is and why it experienced a delay.
Connection timeouts occur more often in email than a normal end user would expect. The most favorite reason for this is ICMP being blocked on the firewall, so that the Path MTU Dicovery (RFC1191) does not work anymore. A typical Cisco IronPort Email Security log entry would look like the following:
Wed Jan 12 16:40:20 2011 Info: New SMTP ICID 12345 interface IncomingMail (10.10.10.10) address 10.10.10.11 reverse dns host test.example.com verified yes
Wed Jan 12 16:40:20 2011 Info: ICID 12345 ACCEPT SG UNKNOWNLIST match 10.10.10.11 SBRS rfc1918
Wed Jan 12 16:40:37 2011 Info: Start MID 23456 ICID 12345
Wed Jan 12 16:40:37 2011 Info: MID 23456 ICID 12345 From: <email@example.com>
Wed Jan 12 16:40:37 2011 Info: MID 23456 ICID 12345 RID 0 To: <firstname.lastname@example.org>
Wed Jan 12 16:45:37 2011 Info: ICID 12345 lost
Wed Jan 12 16:45:37 2011 Info: Message aborted MID 23456 Receiving aborted
Wed Jan 12 16:45:37 2011 Info: Message finished MID 23456 aborted
As the Cisco IronPort Email Security Appliance has an internal timer set to five minutes (by default configuration), the connection gets lost and closed by the appliance five minutes after the last SMTP interaction has been seen from the sender. The data transfer fails after the DATA command from the sender as the MTU size cannot be negotiated correctly due to the blocked ICMP protocol. Sent data from the sender simply crashes in the network and nether the sending nor the recieving mail server are aware of this. The entire email message is not received at all and the end users cannot expect to see the email message popping up in their inbox.
Another timeout seen quiet often is the delivery timeout where the destination mail server is not accepting SMTP sessions for a given period of time. Also this can result in mail transfer delay. A typical logging on the Email Security Appliance would show this:
Wed Jan 12 16:51:20 2011 Info: MID 656565 interim AV verdict using Sophos CLEAN
Wed Jan 12 16:51:20 2011 Info: MID 656565 antivirus negative
Wed Jan 12 16:51:20 2011 Info: MID 656565 queued for delivery
Wed Jan 12 17:21:21 2011 Info: New SMTP DCID 44444 interface 10.10.10.10 address 220.127.116.11 port 25
Wed Jan 12 17:21:22 2011 Info: Delivery start DCID 44444 MID 656565 to RID 
Wed Jan 12 17:21:23 2011 Info: Message done DCID 44444 MID 656565 to RID 
Wed Jan 12 17:21:23 2011 Info: MID 656565 RID  Response 'ok: Message 2244667788 accepted'
Please note the gap of 30 minutes before the outgoing SMTP session is established. The 'MID 656565 queued for delivery' log entry refers to the fact that the Email Security Appliance has finished processing the message (Anti-Spam/Anti-Virus scanning and policy enforcement) and that it is ready for a delivery to the next mail server. It does not mean that the message has already been delivered to it.
The mail_logs and especially the Message Tracking feature are the power tool box for the email administrator to find out where a given message is and where it is not and why.