Email Security: How to verify successful TLS sessions through SMTP logs?

Email Security: How to verify successful TLS sessions through SMTP logs?

Howto verify successful TLS sessions through SMTP logs

In order to verify successful TLS sessions you need to review the SMTP (mlfasgsmtp) logs in Debug Level 2 (System>Advanced). In this log you will need to locate the TLS email transaction in the SMTP log. 
See sample log entries below:

Successful TLS session:

 

2009-02-26 07:19:44 debug SMTPSession.cpp:1456 [32652:2823400368] (session=200902260719440005718) Connect from [122.166.16.238]

2009-02-26 07:19:44 debug SMTPSession.cpp:1657 [32652:2823400368] (session=200902260719440005718) Tarpit bad recipients for 0 second(s)

2009-02-26 07:19:44 debug IOSession.cpp:162 [32652:2823400368] (session=200902260719440005718) beginConnect - attempting connection to server: 127.0.0.1:4025 (0)

2009-02-26 07:19:44 debug SMTPSession.cpp:1681 [32652:2823400368] (session=200902260719440005718) open sockets:   6

2009-02-26 07:19:44 debug SMTPSession.cpp:1715 [32652:2823400368] (session=200902260719440005718) REMOTE MSG: 220 blrmailsecurity.trianz.com ESMTP SonicWall (6.2.3.1219)

2009-02-26 07:19:44 debug SMTPconnect.cpp:188 [32652:2823400368] (session=200902260719440005718) run: queued session (0x0xa184bd68) for dispatch

2009-02-26 07:19:44 debug IODispatch.cpp:145 [32652:2815011760] (session=200902260719440005718) run - got session (0x0xa184bd68)

2009-02-26 07:19:44 debug IOSession.cpp:487 [32652:2815011760] (session=200902260719440005718) addToSelector - put session back in IODispatch list

2009-02-26 07:19:44 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 220 blrmailsecurity.trianz.com (MlfMTA v3.2r9) ESMTP service ready

2009-02-26 07:19:44 debug SMTPSession.cpp:7033 [32652:2815011760] (session=200902260719440005718) HandleRealStatus: 2

2009-02-26 07:19:44 debug SMTPSession.cpp:730 [32652:2815011760] (session=200902260719440005718) REAL CMD: EHLO blrmailsecurity.trianz.com

2009-02-26 07:19:44 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 250-blrmailsecurity.trianz.com says hello

2009-02-26 07:19:44 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 250-ENHANCEDSTATUSCODES

2009-02-26 07:19:44 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 250-PIPELINING

2009-02-26 07:19:44 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 250-CHUNKING

2009-02-26 07:19:44 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 250-8BITMIME

2009-02-26 07:19:44 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 250-AUTH CRAM-MD5

2009-02-26 07:19:44 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 250-XACK

2009-02-26 07:19:44 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 250-SIZE 0

2009-02-26 07:19:44 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 250-VERP

2009-02-26 07:19:44 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 250 DSN

2009-02-26 07:19:44 debug SMTPSession.cpp:7033 [32652:2815011760] (session=200902260719440005718) HandleRealStatus: 2

2009-02-26 07:19:44 debug SMTPSession.cpp:6129 [32652:2815011760] (session=200902260719440005718) REMOTE SAID: EHLO emailsecurity2.blrlab.com

2009-02-26 07:19:44 debug SMTPSession.cpp:609 [32652:2815011760] (session=200902260719440005718) QUEUED REMOTE MSG: 250-blrmail.trianz.com

2009-02-26 07:19:44 debug SMTPSession.cpp:609 [32652:2815011760] (session=200902260719440005718) QUEUED REMOTE MSG: 250-8BITMIME

2009-02-26 07:19:44 debug SMTPSession.cpp:609 [32652:2815011760] (session=200902260719440005718) QUEUED REMOTE MSG: 250-ENHANCEDSTATUSCODES

2009-02-26 07:19:44 debug SMTPSession.cpp:609 [32652:2815011760] (session=200902260719440005718) QUEUED REMOTE MSG: 250-STARTTLS

2009-02-26 07:19:44 debug SMTPSession.cpp:609 [32652:2815011760] (session=200902260719440005718) QUEUED REMOTE MSG: 250 SIZE

2009-02-26 07:19:44 debug SMTPSession.cpp:528 [32652:2815011760] (session=200902260719440005718) ECHO REMOTE MSG: 250-blrmail.trianz.com

2009-02-26 07:19:44 debug SMTPSession.cpp:528 [32652:2815011760] (session=200902260719440005718) ECHO REMOTE MSG: 250-8BITMIME

2009-02-26 07:19:44 debug SMTPSession.cpp:528 [32652:2815011760] (session=200902260719440005718) ECHO REMOTE MSG: 250-ENHANCEDSTATUSCODES

2009-02-26 07:19:44 debug SMTPSession.cpp:528 [32652:2815011760] (session=200902260719440005718) ECHO REMOTE MSG: 250-STARTTLS

2009-02-26 07:19:44 debug SMTPSession.cpp:528 [32652:2815011760] (session=200902260719440005718) ECHO REMOTE MSG: 250 SIZE

2009-02-26 07:19:44 debug SMTPSession.cpp:6129 [32652:2815011760] (session=200902260719440005718) REMOTE SAID: STARTTLS

2009-02-26 07:19:44 debug SMTPSession.cpp:609 [32652:2815011760] (session=200902260719440005718) QUEUED REMOTE MSG: 220 2.2.0 Ready to start TLS

2009-02-26 07:19:44 debug SMTPSession.cpp:742 [32652:2815011760] (session=200902260719440005718) QUEING REAL CMD: RSET

2009-02-26 07:19:44 debug SMTPSession.cpp:528 [32652:2815011760] (session=200902260719440005718) ECHO REMOTE MSG: 220 2.2.0 Ready to start TLS

2009-02-26 07:19:44 debug MlfSocketChannel.cpp:776 [32652:2815011760] (session=200902260719440005718) negotiateTlsHandshake: attempting to switch to secure layer...

2009-02-26 07:19:44 debug MlfSocketChannel.cpp:803 [32652:2815011760] (session=200902260719440005718) negotiateTlsHandshake: handshake negotiation in progress (-1)

2009-02-26 07:19:44 debug MlfSocketChannel.cpp:836 [32652:2815011760] (session=200902260719440005718) negotiateTlsHandshake: waiting for read availability...

2009-02-26 07:19:44 debug SMTPSession.cpp:939 [32652:2815011760] (session=200902260719440005718) TLS handshake negotiation pending

2009-02-26 07:19:44 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 250 2.0.0 reset

2009-02-26 07:19:44 debug SMTPSession.cpp:7033 [32652:2815011760] (session=200902260719440005718) HandleRealStatus: 2

2009-02-26 07:19:44 debug MlfSocketChannel.cpp:565 [32652:2815011760] (session=200902260719440005718) read: attempt #1 to negotiate TLS handshake

2009-02-26 07:19:44 debug MlfSocketChannel.cpp:776 [32652:2815011760] (session=200902260719440005718) negotiateTlsHandshake: attempting to switch to secure layer...

2009-02-26 07:19:44 debug MlfSocketChannel.cpp:803 [32652:2815011760] (session=200902260719440005718) negotiateTlsHandshake: handshake negotiation in progress (-1)

2009-02-26 07:19:44 debug MlfSocketChannel.cpp:836 [32652:2815011760] (session=200902260719440005718) negotiateTlsHandshake: waiting for read availability...

2009-02-26 07:19:44 debug SMTPSession.cpp:7927 [32652:2815011760] (session=200902260719440005718) remoteDataHandler - continue to negotiate TLS handshake...

2009-02-26 07:19:44 debug MlfSocketChannel.cpp:565 [32652:2815011760] (session=200902260719440005718) read: attempt #2 to negotiate TLS handshake

2009-02-26 07:19:44 debug MlfSocketChannel.cpp:776 [32652:2815011760] (session=200902260719440005718) negotiateTlsHandshake: attempting to switch to secure layer...

2009-02-26 07:19:44 debug MlfSocketChannel.cpp:789 [32652:2815011760] (session=200902260719440005718) negotiateTlsHandshake: switch to secure layer successful

2009-02-26 07:19:44 debug SMTPSession.cpp:6129 [32652:2815011760] (session=200902260719440005718) REMOTE SAID: EHLO emailsecurity2.blrlab.com

2009-02-26 07:19:44 debug SMTPSession.cpp:609 [32652:2815011760] (session=200902260719440005718) QUEUED REMOTE MSG: 250-blrmail.trianz.com

2009-02-26 07:19:44 debug SMTPSession.cpp:609 [32652:2815011760] (session=200902260719440005718) QUEUED REMOTE MSG: 250-8BITMIME

2009-02-26 07:19:44 debug SMTPSession.cpp:609 [32652:2815011760] (session=200902260719440005718) QUEUED REMOTE MSG: 250-ENHANCEDSTATUSCODES

2009-02-26 07:19:44 debug SMTPSession.cpp:609 [32652:2815011760] (session=200902260719440005718) QUEUED REMOTE MSG: 250 SIZE

2009-02-26 07:19:44 debug SMTPSession.cpp:528 [32652:2815011760] (session=200902260719440005718) ECHO REMOTE MSG: 250-blrmail.trianz.com

2009-02-26 07:19:44 debug SMTPSession.cpp:1024 [32652:2815011760] (session=200902260719440005718) buildTlsHeaderInfo: TLS cipher info: TLSv1/SSLv3 AES256-SHA(256)

2009-02-26 07:19:44 debug SMTPSession.cpp:528 [32652:2815011760] (session=200902260719440005718) ECHO REMOTE MSG: 250-8BITMIME

2009-02-26 07:19:44 debug SMTPSession.cpp:528 [32652:2815011760] (session=200902260719440005718) ECHO REMOTE MSG: 250-ENHANCEDSTATUSCODES

2009-02-26 07:19:44 debug SMTPSession.cpp:528 [32652:2815011760] (session=200902260719440005718) ECHO REMOTE MSG: 250 SIZE

2009-02-26 07:19:44 debug SMTPSession.cpp:6129 [32652:2815011760] (session=200902260719440005718) REMOTE SAID: MAIL FROM:<prvs=13080614e6=administrator@testlab.com>

2009-02-26 07:19:44 debug SMTPSession.cpp:742 [32652:2815011760] (session=200902260719440005718) QUEING REAL CMD: MAIL FROM: <prvs=13080614e6=administrator@testlab.com>

2009-02-26 07:19:44 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 250 2.1.0 MAIL ok

2009-02-26 07:19:44 debug SMTPSession.cpp:7033 [32652:2815011760] (session=200902260719440005718) HandleRealStatus: 2

2009-02-26 07:19:44 debug SMTPSession.cpp:648 [32652:2815011760] (session=200902260719440005718) QUEUE orig msg from real server to remote: [250 2.1.0 MAIL ok

2009-02-26 07:19:44 debug SMTPSession.cpp:528 [32652:2815011760] (session=200902260719440005718) ECHO REMOTE MSG: 250 2.1.0 MAIL ok

2009-02-26 07:19:44 debug SMTPSession.cpp:6129 [32652:2815011760] (session=200902260719440005718) REMOTE SAID: RCPT TO:<vijesh.rajan@trianz.com>

2009-02-26 07:19:44 debug SMTPSession.cpp:4424 [32652:2815011760] (session=200902260719440005718) Checking for rewrite ops to Inbound RCPT TO: [vijesh.rajan@trianz.com]

2009-02-26 07:19:44 debug SMTPSession.cpp:742 [32652:2815011760] (session=200902260719440005718) QUEING REAL CMD: RCPT TO: <vijesh.rajan@trianz.com>

2009-02-26 07:19:44 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 250 2.1.5 <vijesh.rajan@trianz.com> ok

2009-02-26 07:19:44 debug SMTPSession.cpp:7033 [32652:2815011760] (session=200902260719440005718) HandleRealStatus: 2

2009-02-26 07:19:44 debug SMTPSession.cpp:609 [32652:2815011760] (session=200902260719440005718) QUEUED REMOTE MSG: 250 2.0.0 Ok

2009-02-26 07:19:44 debug SMTPSession.cpp:528 [32652:2815011760] (session=200902260719440005718) ECHO REMOTE MSG: 250 2.0.0 Ok

2009-02-26 07:19:44 debug SMTPSession.cpp:6129 [32652:2815011760] (session=200902260719440005718) REMOTE SAID: DATA

2009-02-26 07:19:44 debug SMTPSession.cpp:6334 [32652:2815011760] (session=200902260719440005718) begin data

2009-02-26 07:19:44 debug SMTPSession.cpp:609 [32652:2815011760] (session=200902260719440005718) QUEUED REMOTE MSG: 354 3.0.0 End Data with <CR><LF>.<CR><LF>

2009-02-26 07:19:44 debug SMTPSession.cpp:528 [32652:2815011760] (session=200902260719440005718) ECHO REMOTE MSG: 354 3.0.0 End Data with <CR><LF>.<CR><LF>

2009-02-26 07:19:44 debug MlfSocketChannel.cpp:1035 [32652:2815011760] (session=200902260719440005718) tlsRead: waiting for read availability...

2009-02-26 07:19:44 debug MlfSocketChannel.cpp:1035 [32652:2815011760] (session=200902260719440005718) tlsRead: waiting for read availability...

2009-02-26 07:19:44 debug SMTPSession.cpp:6638 [32652:2815011760] (session=200902260719440005718) found end of data (2176 bytes)

2009-02-26 07:19:45 debug SMTPSession.cpp:742 [32652:2890509232] (session=200902260719440005718) QUEING REAL CMD: DATA

2009-02-26 07:19:45 debug SMTPSession.cpp:8181 [32652:2890509232] (session=200902260719440005718) Put session (0x0xa184bd68) back in IO dispatch queue

2009-02-26 07:19:45 debug IODispatch.cpp:145 [32652:2815011760] (session=200902260719440005718) run - got session (0x0xa184bd68)

2009-02-26 07:19:45 debug IOSession.cpp:487 [32652:2815011760] (session=200902260719440005718) addToSelector - put session back in IODispatch list

2009-02-26 07:19:45 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 354 send message

2009-02-26 07:19:45 debug SMTPSession.cpp:7033 [32652:2815011760] (session=200902260719440005718) HandleRealStatus: 3

2009-02-26 07:19:45 debug SMTPSession.cpp:2639 [32652:2815011760] (session=200902260719440005718) GetCopyOfHeadersAndReturnOffsetOfStartOfBody (2173 bytes)

2009-02-26 07:19:45 debug SMTPSession.cpp:7701 [32652:2815011760] (session=200902260719440005718) handleRealStatus - data length: 2173; body offset: 1438

2009-02-26 07:19:45 debug SMTPSession.cpp:742 [32652:2815011760] (session=200902260719440005718) QUEING REAL CMD: .

2009-02-26 07:19:45 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 250 2.6.0 message received

2009-02-26 07:19:45 debug SMTPSession.cpp:7033 [32652:2815011760] (session=200902260719440005718) HandleRealStatus: 2

2009-02-26 07:19:45 debug MessageProcessor.cpp:3033 [32652:2815011760] (session=200902260719440005718) Message Status: sent successfully => from: prvs=13080614e6=administrator@testlab.com; to: vijesh.rajan@trianz.com

2009-02-26 07:19:45 debug SMTPSession.cpp:648 [32652:2815011760] (session=200902260719440005718) QUEUE orig msg from real server to remote: [250 2.6.0 message received

2009-02-26 07:19:45 debug SMTPSession.cpp:528 [32652:2815011760] (session=200902260719440005718) ECHO REMOTE MSG: 250 2.6.0 message received

2009-02-26 07:19:46 debug SMTPSession.cpp:6129 [32652:2815011760] (session=200902260719440005718) REMOTE SAID: QUIT

2009-02-26 07:19:46 debug SMTPSession.cpp:609 [32652:2815011760] (session=200902260719440005718) QUEUED REMOTE MSG: 221 2.0.0 Bye

2009-02-26 07:19:46 debug SMTPSession.cpp:742 [32652:2815011760] (session=200902260719440005718) QUEING REAL CMD: QUIT

2009-02-26 07:19:46 debug SMTPSession.cpp:528 [32652:2815011760] (session=200902260719440005718) ECHO REMOTE MSG: 221 2.0.0 Bye

2009-02-26 07:19:46 debug SMTPSession.cpp:6912 [32652:2815011760] (session=200902260719440005718) REAL SAID: 221 2.0.0 blrmailsecurity.trianz.com says goodbye

2009-02-26 07:19:46 debug SMTPSession.cpp:7033 [32652:2815011760] (session=200902260719440005718) HandleRealStatus: 2

2009-02-26 07:19:46 debug SMTPSession.cpp:2466 [32652:2815011760] (session=200902260719440005718) Closing remote: [122.166.16.238]

2009-02-26 07:19:46 debug MlfSocketChannel.cpp:1294 [32652:2815011760] (session=200902260719440005718) TLS cleanup: free ssl resources

2009-02-26 07:19:46 debug IOSession.cpp:330 [32652:2815011760] (session=200902260719440005718) closing Remote (socket=181)

2009-02-26 07:19:46 debug SMTPSession.cpp:2454 [32652:2815011760] (session=200902260719440005718) Closing real for this remote host's session: [122.166.16.238]

2009-02-26 07:19:46 debug IOSession.cpp:303 [32652:2815011760] (session=200902260719440005718) closing Real (socket=189)

2009-02-26 07:19:46 debug IOSession.cpp:565 [32652:2815011760] (session=200902260719440005718) handleSelectorData remote channel is null