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
Â