Sometimes it is very hard to troubleshoot SMTP issues that occur with your DotNetNuke application. Sure, you can view the SMTP log of your mail server, but that may be either misconfigured, or not even accessible at all (this is especially true in a shared hosting environment).
Luckily, there is a very simple way to enable logging for all network traffic DotNetNuke is generating, which includes SMTP traffic
This starts with realizing that the DotNetNuke email implementation is using System.Net.Mail. Apart from the documentation on MSDN about the System.Net.Mail namespace, there is also an excellent FAQ site about it: www.systemnetmail.com.
On that site, we can find a very easy way to configure logging for the mail system. In fact, the way it is explained there, it will actually set up logging for all network requests done by the application. That can be very useful when troubleshooting.
The set up is very simple:
<system.diagnostics>
<trace autoflush="true" />
<sources>
<source name="System.Net" >
<listeners>
<add name="MyTraceFile"/>
</listeners>
</source>
<source name="System.Net.Sockets">
<listeners>
<add name="MyTraceFile"/>
</listeners>
</source>
</sources>
<sharedListeners>
<add
name="MyTraceFile"
type="System.Diagnostics.TextWriterTraceListener"
initializeData="Portals/_Default/Logs/System.Net.trace.log.resources" />
</sharedListeners>
<switches>
<add name="System.Net" value="Verbose" />
<add name="System.Net.Sockets" value="Verbose" />
</switches>
</system.diagnostics>
Just put this configuration inside the node of web.config, and everything will start working. The log file will be created in /Portals/_default/Logs, and will also be accessible through Host > Host Settings > Logs.
This is a sample of what is logged when sending a test email from HostSettings:
System.Net Verbose: 0 : [6708] SmtpClient::.ctor()
System.Net Information: 0 : [6708] Associating SmtpClient#49589702 with SmtpTransport#5072988
System.Net Verbose: 0 : [6708] Exiting SmtpClient::.ctor() -> SmtpClient#49589702
System.Net Verbose: 0 : [6708] SmtpClient#49589702::Send(MailMessage#21248308)
System.Net Information: 0 : [6708] SmtpClient#49589702::Send(DeliveryMethod=Network)
System.Net Information: 0 : [6708] Associating SmtpClient#49589702 with MailMessage#21248308
System.Net Verbose: 0 : [6708] ServicePoint#19000239::ServicePoint(127.0.0.1:25)
System.Net Information: 0 : [6708] Associating SmtpTransport#5072988 with SmtpConnection#18163917
System.Net Information: 0 : [6708] Associating SmtpConnection#18163917 with ServicePoint#19000239
System.Net.Sockets Verbose: 0 : [6708] Socket#34257155::Socket(AddressFamily#2)
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#34257155::Socket()
System.Net.Sockets Verbose: 0 : [6708] Socket#9311726::Socket(AddressFamily#23)
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#9311726::Socket()
System.Net.Sockets Verbose: 0 : [6708] DNS::TryInternalResolve(127.0.0.1)
System.Net.Sockets Verbose: 0 : [6708] Socket#34257155::Connect(127.0.0.1:25#16777318)
System.Net.Sockets Information: 0 : [6708] Socket#34257155 - Created connection from 127.0.0.1:1516 to 127.0.0.1:25.
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#34257155::Connect()
System.Net.Sockets Verbose: 0 : [6708] Socket#9311726::Close()
System.Net.Sockets Verbose: 0 : [6708] Socket#9311726::Dispose()
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#9311726::Close()
System.Net Information: 0 : [6708] SmtpPooledStream#31144392 - Created connection from 127.0.0.1:1516 to 127.0.0.1:25.
System.Net Information: 0 : [6708] Associating SmtpConnection#18163917 with SmtpPooledStream#31144392
System.Net.Sockets Verbose: 0 : [6708] Socket#34257155::Receive()
System.Net.Sockets Verbose: 0 : [6708] Data from Socket#34257155::Receive
System.Net.Sockets Verbose: 0 : [6708] 00000000 : 32 32 30 20 6C 6F 63 61-6C 68 6F 73 74 20 73 6D : 220 localhost sm
System.Net.Sockets Verbose: 0 : [6708] 00000010 : 74 70 34 64 65 76 20 72-65 61 64 79 0D 0A : tp4dev ready..
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#34257155::Receive() -> Int32#30
System.Net.Sockets Verbose: 0 : [6708] Socket#34257155::Send()
System.Net.Sockets Verbose: 0 : [6708] Data from Socket#34257155::Send
System.Net.Sockets Verbose: 0 : [6708] 00000000 : 45 48 4C 4F 20 44 4E 4E-2D 50 43 36 37 0D 0A : EHLO DNN-PC67..
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#34257155::Send() -> Int32#15
System.Net.Sockets Verbose: 0 : [6708] Socket#34257155::Receive()
System.Net.Sockets Verbose: 0 : [6708] Data from Socket#34257155::Receive
System.Net.Sockets Verbose: 0 : [6708] 00000000 : 32 35 30 2D 4E 69 63 65-20 74 6F 20 6D 65 65 74 : 250-Nice to meet
System.Net.Sockets Verbose: 0 : [6708] 00000010 : 20 79 6F 75 2E 0D 0A 32-35 30 2D 38 42 49 54 4D : you...250-8BITM
System.Net.Sockets Verbose: 0 : [6708] 00000020 : 49 4D 45 0D 0A 32 35 30-2D 53 54 41 52 54 54 4C : IME..250-STARTTL
System.Net.Sockets Verbose: 0 : [6708] 00000030 : 53 0D 0A 32 35 30 2D 41-55 54 48 3D 43 52 41 4D : S..250-AUTH=CRAM
System.Net.Sockets Verbose: 0 : [6708] 00000040 : 2D 4D 44 35 20 50 4C 41-49 4E 20 4C 4F 47 49 4E : -MD5 PLAIN LOGIN
System.Net.Sockets Verbose: 0 : [6708] 00000050 : 20 41 4E 4F 4E 59 4D 4F-55 53 0D 0A 32 35 30 2D : ANONYMOUS..250-
System.Net.Sockets Verbose: 0 : [6708] 00000060 : 41 55 54 48 20 43 52 41-4D 2D 4D 44 35 20 50 4C : AUTH CRAM-MD5 PL
System.Net.Sockets Verbose: 0 : [6708] 00000070 : 41 49 4E 20 4C 4F 47 49-4E 20 41 4E 4F 4E 59 4D : AIN LOGIN ANONYM
System.Net.Sockets Verbose: 0 : [6708] 00000080 : 4F 55 53 0D 0A 32 35 30-20 53 49 5A 45 0D 0A : OUS..250 SIZE..
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#34257155::Receive() -> Int32#143
System.Net.Sockets Verbose: 0 : [6708] Socket#34257155::Send()
System.Net.Sockets Verbose: 0 : [6708] Data from Socket#34257155::Send
System.Net.Sockets Verbose: 0 : [6708] 00000000 : 4D 41 49 4C 20 46 52 4F-4D 3A 3C 73 75 70 70 6F : MAIL FROM:System.Net.Sockets Verbose: 0 : [6708] 00000010 : 72 74 40 64 6E 6E 37 30-33 65 65 2D 36 34 2D 69 : rt@dnn703ee-64-i
System.Net.Sockets Verbose: 0 : [6708] 00000020 : 6E 73 74 2E 64 6E 6E 64-65 76 2E 6D 65 3E 0D 0A : nst.dnndev.me>..
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#34257155::Send() -> Int32#48
System.Net.Sockets Verbose: 0 : [6708] Socket#34257155::Receive()
System.Net.Sockets Verbose: 0 : [6708] Data from Socket#34257155::Receive
System.Net.Sockets Verbose: 0 : [6708] 00000000 : 32 35 30 20 4F 6B 65 79-20 64 6F 6B 65 79 0D 0A : 250 Okey dokey..
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#34257155::Receive() -> Int32#16
System.Net.Sockets Verbose: 0 : [6708] Socket#34257155::Send()
System.Net.Sockets Verbose: 0 : [6708] Data from Socket#34257155::Send
System.Net.Sockets Verbose: 0 : [6708] 00000000 : 52 43 50 54 20 54 4F 3A-3C 73 75 70 70 6F 72 74 : RCPT TO:System.Net.Sockets Verbose: 0 : [6708] 00000010 : 40 64 6E 6E 37 30 33 65-65 2D 36 34 2D 69 6E 73 : @dnn703ee-64-ins
System.Net.Sockets Verbose: 0 : [6708] 00000020 : 74 2E 64 6E 6E 64 65 76-2E 6D 65 3E 0D 0A : t.dnndev.me>..
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#34257155::Send() -> Int32#46
System.Net.Sockets Verbose: 0 : [6708] Socket#34257155::Receive()
System.Net.Sockets Verbose: 0 : [6708] Data from Socket#34257155::Receive
System.Net.Sockets Verbose: 0 : [6708] 00000000 : 32 35 30 20 52 65 63 69-70 69 65 6E 74 20 61 63 : 250 Recipient ac
System.Net.Sockets Verbose: 0 : [6708] 00000010 : 63 65 70 74 65 64 0D 0A- : cepted..
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#34257155::Receive() -> Int32#24
System.Net.Sockets Verbose: 0 : [6708] Socket#34257155::Send()
System.Net.Sockets Verbose: 0 : [6708] Data from Socket#34257155::Send
System.Net.Sockets Verbose: 0 : [6708] 00000000 : 44 41 54 41 0D 0A : DATA..
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#34257155::Send() -> Int32#6
System.Net.Sockets Verbose: 0 : [6708] Socket#34257155::Receive()
System.Net.Sockets Verbose: 0 : [6708] Data from Socket#34257155::Receive
System.Net.Sockets Verbose: 0 : [6708] 00000000 : 33 35 34 20 45 6E 64 20-6D 65 73 73 61 67 65 20 : 354 End message
System.Net.Sockets Verbose: 0 : [6708] 00000010 : 77 69 74 68 20 70 65 72-69 6F 64 0D 0A : with period..
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#34257155::Receive() -> Int32#29
System.Net Information: 0 : [6708] Associating Message#21078404 with HeaderCollection#58383834
System.Net Information: 0 : [6708] HeaderCollection#58383834::Remove(Content-Type)
System.Net Information: 0 : [6708] HeaderCollection#58383834::Set(MIME-Version=1.0)
System.Net Information: 0 : [6708] HeaderCollection#58383834::Remove(Sender)
System.Net Information: 0 : [6708] HeaderCollection#58383834::Remove(Cc)
System.Net Information: 0 : [6708] HeaderCollection#58383834::Remove(Bcc)
System.Net Information: 0 : [6708] HeaderCollection#58383834::Remove(X-Priority)
System.Net Information: 0 : [6708] HeaderCollection#58383834::Remove(Priority)
System.Net Information: 0 : [6708] HeaderCollection#58383834::Remove(Importance)
System.Net Information: 0 : [6708] HeaderCollection#58383834::Get(MIME-Version)
System.Net Information: 0 : [6708] HeaderCollection#58383834::Get(From)
System.Net Information: 0 : [6708] HeaderCollection#58383834::Get(To)
System.Net Information: 0 : [6708] HeaderCollection#58383834::Get(Reply-To)
System.Net Information: 0 : [6708] HeaderCollection#58383834::Get(Date)
System.Net Information: 0 : [6708] HeaderCollection#58383834::Get(Subject)
System.Net Information: 0 : [6708] HeaderCollection#10714253::Get(Content-Type)
System.Net Information: 0 : [6708] HeaderCollection#10714253::Get(Content-Transfer-Encoding)
System.Net.Sockets Verbose: 0 : [6708] Socket#34257155::Send()
System.Net.Sockets Verbose: 0 : [6708] Data from Socket#34257155::Send
System.Net.Sockets Verbose: 0 : [6708] 00000000 : 4D 49 4D 45 2D 56 65 72-73 69 6F 6E 3A 20 31 2E : MIME-Version: 1.
System.Net.Sockets Verbose: 0 : [6708] 00000010 : 30 0D 0A 46 72 6F 6D 3A-20 73 75 70 70 6F 72 74 : 0..From: support
System.Net.Sockets Verbose: 0 : [6708] 00000020 : 40 64 6E 6E 37 30 33 65-65 2D 36 34 2D 69 6E 73 : @dnn703ee-64-ins
System.Net.Sockets Verbose: 0 : [6708] 00000030 : 74 2E 64 6E 6E 64 65 76-2E 6D 65 0D 0A 54 6F 3A : t.dnndev.me..To:
System.Net.Sockets Verbose: 0 : [6708] 00000040 : 20 73 75 70 70 6F 72 74-40 64 6E 6E 37 30 33 65 : support@dnn703e
System.Net.Sockets Verbose: 0 : [6708] 00000050 : 65 2D 36 34 2D 69 6E 73-74 2E 64 6E 6E 64 65 76 : e-64-inst.dnndev
System.Net.Sockets Verbose: 0 : [6708] 00000060 : 2E 6D 65 0D 0A 52 65 70-6C 79 2D 54 6F 3A 20 73 : .me..Reply-To: s
System.Net.Sockets Verbose: 0 : [6708] 00000070 : 75 70 70 6F 72 74 40 64-6E 6E 37 30 33 65 65 2D : upport@dnn703ee-
System.Net.Sockets Verbose: 0 : [6708] 00000080 : 36 34 2D 69 6E 73 74 2E-64 6E 6E 64 65 76 2E 6D : 64-inst.dnndev.m
System.Net.Sockets Verbose: 0 : [6708] 00000090 : 65 0D 0A 44 61 74 65 3A-20 36 20 46 65 62 20 32 : e..Date: 6 Feb 2
System.Net.Sockets Verbose: 0 : [6708] 000000A0 : 30 31 33 20 32 31 3A 34-39 3A 34 39 20 2B 30 31 : 013 21:49:49 +01
System.Net.Sockets Verbose: 0 : [6708] 000000B0 : 30 30 0D 0A 53 75 62 6A-65 63 74 3A 20 44 6F 74 : 00..Subject: Dot
System.Net.Sockets Verbose: 0 : [6708] 000000C0 : 4E 65 74 4E 75 6B 65 20-53 4D 54 50 20 43 6F 6E : NetNuke SMTP Con
System.Net.Sockets Verbose: 0 : [6708] 000000D0 : 66 69 67 75 72 61 74 69-6F 6E 20 54 65 73 74 0D : figuration Test.
System.Net.Sockets Verbose: 0 : [6708] 000000E0 : 0A 43 6F 6E 74 65 6E 74-2D 54 79 70 65 3A 20 74 : .Content-Type: t
System.Net.Sockets Verbose: 0 : [6708] 000000F0 : 65 78 74 2F 70 6C 61 69-6E 3B 20 63 68 61 72 73 : ext/plain; chars
System.Net.Sockets Verbose: 0 : [6708] 00000100 : 65 74 3D 75 73 2D 61 73-63 69 69 0D 0A 43 6F 6E : et=us-ascii..Con
System.Net.Sockets Verbose: 0 : [6708] 00000110 : 74 65 6E 74 2D 54 72 61-6E 73 66 65 72 2D 45 6E : tent-Transfer-En
System.Net.Sockets Verbose: 0 : [6708] 00000120 : 63 6F 64 69 6E 67 3A 20-71 75 6F 74 65 64 2D 70 : coding: quoted-p
System.Net.Sockets Verbose: 0 : [6708] 00000130 : 72 69 6E 74 61 62 6C 65-0D 0A 0D 0A : rintable....
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#34257155::Send() -> Int32#316
System.Net Information: 0 : [6708] HeaderCollection#10714253::Get(Content-Transfer-Encoding)
System.Net Information: 0 : [6708] HeaderCollection#10714253::Get(Content-Transfer-Encoding)
System.Net.Sockets Verbose: 0 : [6708] Socket#34257155::Send()
System.Net.Sockets Verbose: 0 : [6708] Data from Socket#34257155::Send
System.Net.Sockets Verbose: 0 : [6708] 00000000 : 0D 0A : ..
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#34257155::Send() -> Int32#2
System.Net.Sockets Verbose: 0 : [6708] Socket#34257155::Send()
System.Net.Sockets Verbose: 0 : [6708] Data from Socket#34257155::Send
System.Net.Sockets Verbose: 0 : [6708] 00000000 : 0D 0A 2E 0D 0A : .....
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#34257155::Send() -> Int32#5
System.Net.Sockets Verbose: 0 : [6708] Socket#34257155::Receive()
System.Net.Sockets Verbose: 0 : [6708] Data from Socket#34257155::Receive
System.Net.Sockets Verbose: 0 : [6708] 00000000 : 32 35 30 20 4D 61 69 6C-20 61 63 63 65 70 74 65 : 250 Mail accepte
System.Net.Sockets Verbose: 0 : [6708] 00000010 : 64 0D 0A : d..
System.Net.Sockets Verbose: 0 : [6708] Exiting Socket#34257155::Receive() -> Int32#19
System.Net Verbose: 0 : [6708] Exiting SmtpClient#49589702::Send()
System.Net Information: 0 : [10080] ServicePoint#19000239 - Closed as idle.
System.Net Verbose: 0 : [10080] SmtpPooledStream::Dispose #31144392
System.Net.Sockets Verbose: 0 : [10080] Socket#34257155::Send()
System.Net.Sockets Verbose: 0 : [10080] Data from Socket#34257155::Send
System.Net.Sockets Verbose: 0 : [10080] 00000000 : 51 55 49 54 0D 0A : QUIT..
System.Net.Sockets Verbose: 0 : [10080] Exiting Socket#34257155::Send() -> Int32#6
System.Net.Sockets Verbose: 0 : [10080] Socket#34257155::Receive()
System.Net.Sockets Error: 0 : [10080] Socket#34257155::UpdateStatusAfterSocketError() - ConnectionAborted
System.Net.Sockets Error: 0 : [10080] Exception in Socket#34257155::Receive - An established connection was aborted by the software in your host machine.
As you can see, you can follow the full flow of events from connecting to the SMTP server:
System.Net.Sockets Verbose: 0 : [6708] 00000000 : 32 32 30 20 6C 6F 63 61-6C 68 6F 73 74 20 73 6D : 220 localhost sm
System.Net.Sockets Verbose: 0 : [6708] 00000010 : 74 70 34 64 65 76 20 72-65 61 64 79 0D 0A : tp4dev ready..
This shows that the mail server (in this case smtp4dev) has accepted the connection with a 220 status and is ready to continue. After some niceties (the client authorizing with the server), the client commences with sending the actual message, the server replies that everything is ok, recipient accepted, and the full message is sent (in encoded text) to the server. Finally, the message is accepted, and the connection is closed:
System.Net.Sockets Verbose: 0 : [6708] 00000000 : 32 35 30 20 4D 61 69 6C-20 61 63 63 65 70 74 65 : 250 Mail accepte
System.Net.Sockets Verbose: 0 : [6708] 00000010 : 64 0D 0A : d..
System.Net.Sockets Verbose: 0 : [6708] Exiting
This is a very powerful option to really troubleshoot communication between DotNetNuke and the configured SMTP server. A fair warning though: if you keep this trace active, it will generate 1 potentially very large file. If you want to keep this type of logging in your application, it is probably a good idea to make sure the log file is a rolling type. The standard TextWriterTraceListener cannot do that, but it is not very hard to create your own listener that can. See this excellent blog by Dave Bost on how to do that: Rolling over TextWriterTraceListner logs
Have fun troubleshooting!
(This is a repost from my personal blog)