Freigeben über


Using System.Net Tracing

In Whidbey (.NET Framework 2.0) System.Net has a new feature called Tracing.
This uses the builtin CLR Tracing functionality. What is interesting about the System.Net Tracing is that
You can easily  see the data that is being sent or received without having to use the NETMON.

If you have used Network Monitor tools like NETMON/Ethereal you will find that
there is so much noise that you need to weed through. This can be partially addressed through
capture filters and display filters. But then looking at a frame in the capture you can't
easily determine which process issued that request. Similarly if there are multiple threads,
you can't easily determine which thread issued that request. One more thing is that if the
client and server are on the same machine you can;t capture the loop back traffic. Perhaps the most limiting of all
is that if the application is using SSL (https or FTP with SSL) then it is not possible to look at the traffic.
You can at most see the TCP frames with encrypted payload. Not much of use. Right?

With System.Net, we addressed all these issues. System.Net tracing is
1) Per process
2) Shows threads
3) Works for SSL
4) Works for Loopback.
5) You don't need to recompile the code

With all these advantages I find the System.Net tracing a very compelling feature that will not be able to live without.
Lets look at some examples.

1. Consider the following code
//JScript.Net
import System;
import System.Net;
(new WebClient()).DownloadString(https://www.microsoft.com/office);

I wrote the above JScript.Net code. You can compile the code with Jsc <filename>
What if you really want to see the trace for that code and see what is going on the wire?

You can use the following configuration file. Save this file as app.exe.config file.
<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
<system.diagnostics>
<trace autoflush="true" />
<sources>
<source name="System.Net" maxdatasize="1024">
<listeners>
<add name="MyTraceFile"/>
</listeners>
</source>
</sources>

            <sharedListeners>
<add
name="MyTraceFile"
type="System.Diagnostics.TextWriterTraceListener"
initializeData="System.Net.trace.log"
/>
</sharedListeners>

            <switches>
<add name="System.Net" value="Verbose" />
</switches>

    </system.diagnostics>
</configuration>

<!--
You can use these two attributes on the Trace Sources
tracemode="protocolonly"
maxdatasize="1024"
-->

<!--
You can choose from 4 sources

<source name="System.Net" maxdatasize="1024">
<listeners>
<add name="MyTraceFile"/>
</listeners>
</source>

<source name="System.Net.Sockets">
<listeners>
<add name="MyTraceFile"/>
</listeners>
</source>
<source name="System.Net.Cache">
<listeners>
<add name="MyTraceFile"/>
</listeners>
</source>
<source name="System.Net.HttpListener">
<listeners>
<add name="MyTraceFile"/>
</listeners>
</source>
-->

Now when you run the application you will find the log file as System.Net.Trace.Log file

System.Net Information: 0 : [3560] HttpWebRequest#33736294 - Request: GET /office HTTP/1.1

System.Net Information: 0 : [3560] ConnectStream#31914638 - Sending headers
{
Host: www.microsoft.com
Connection: Keep-Alive
}.
System.Net Information: 0 : [3560] Connection#48285313 - Received status line: Version=1.1, StatusCode=301, StatusDescription=Moved Permanently.
System.Net Information: 0 : [3560] Connection#48285313 - Received headers
{
Connection: Keep-Alive
Proxy-Connection: Keep-Alive
Content-Length: 155
Content-Type: text/html
Date: Mon, 12 Sep 2005 21:51:00 GMT
Location: https://www.microsoft.com/office/
P3P: CP="ALL IND DSP COR ADM CONo CUR CUSo IVAo IVDo PSA PSD TAI TELo OUR SAMo CNT COM INT NAV ONL PHY PRE PUR UNI"
Server: Microsoft-IIS/6.0
Via: 1.1 MSCORPGATE12
X-Powered-By: ASP.NET
}.

You can see that the log file shows what is being sent on the wire and what headers are being received.
You don't need to use NETMON any more to see what traffic is being sent on the wire. Very good indeed.

You can also see that we show the objects and hash codes for each object so you can follow an object
using this log file. You can also see [3560]as the thread id of the thread that is issuing the request.

2.What about SSL? What about Local Host?
Lets consider the following code

using System;
using System.Collections.Generic;
using System.Text;
using System.Net;
using System.IO;
using System.Net.Security;
using System.Security.Policy;
using System.Security.Cryptography.X509Certificates;
using System.Security.Cryptography;
class Program
{
static void Main(string[] args)
{
Stream s = null;
StreamReader sr = null;
HttpWebResponse res = null;
try{
//Hook a callback to verify the remote certificate
ServicePointManager.ServerCertificateValidationCallback =
new RemoteCertificateValidationCallback(MyCertValidationCb); 

      HttpWebRequest req
= (HttpWebRequest)
WebRequest.Create("https://localhost/SecureNoClientCerts/test.htm");

   req.Proxy = null;

   res = req.GetResponse() as HttpWebResponse;
s = res.GetResponseStream();
sr = new StreamReader(s, Encoding.UTF8);
Console.WriteLine(sr.ReadToEnd());
}
catch(Exception ex){
Console.WriteLine(ex);
}
finally{
if(res != null) res.Close();
if(s != null) s.Close();
if(sr != null) sr.Close();
}
}

  public static bool MyCertValidationCb(
object sender,
X509Certificate certificate,
X509Chain chain,
SslPolicyErrors sslPolicyErrors)
{
if ((sslPolicyErrors & SslPolicyErrors.RemoteCertificateChainErrors)
== SslPolicyErrors.RemoteCertificateChainErrors)
{
return false;
}
else if ((sslPolicyErrors & SslPolicyErrors.RemoteCertificateNameMismatch)
== SslPolicyErrors.RemoteCertificateNameMismatch)
{
Zone z;
z = Zone.CreateFromUrl(((HttpWebRequest)sender).RequestUri.ToString());
if (z.SecurityZone == System.Security.SecurityZone.Intranet
|| z.SecurityZone == System.Security.SecurityZone.MyComputer)
{
return true;
}
return false;
}
return false;
}
}

This code is trying to make an SSL request to the local host. You will also find that the
RemoteCertificationCallback sample.

You can enable both the Sockets and System.Net sources with the following config file
<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
<system.diagnostics>
<trace autoflush="true" />
<sources>
<source name="System.Net" maxdatasize="1024">
<listeners>
<add name="MyTraceFile"/>
</listeners>
</source>
<source name="System.Net.Sockets" maxdatasize="1024">
<listeners>
<add name="MyTraceFile"/>
</listeners>
</source>
</sources>

            <sharedListeners>
<add
name="MyTraceFile"
type="System.Diagnostics.TextWriterTraceListener"
initializeData="System.Net.trace.log"
/>
</sharedListeners>
<switches>
<add name="System.Net" value="Verbose" />
<add name="System.Net.Sockets" value="Verbose" />
</switches>
</system.diagnostics>
</configuration>

Here is the log file produced

System.Net Verbose: 0 : [3848] WebRequest::Create(https://localhost/SecureNoClientCerts/test.htm)
System.Net Verbose: 0 : [3848] HttpWebRequest#33574638::HttpWebRequest(https://localhost/SecureNoClientCerts/test.htm#1109589874)
System.Net Verbose: 0 : [3848] Exiting HttpWebRequest#33574638::HttpWebRequest()
System.Net Verbose: 0 : [3848] Exiting WebRequest::Create() -> HttpWebRequest#33574638
System.Net Information: 0 : [3848] Associating HttpWebRequest#33574638 with ServicePoint#33736294
System.Net Verbose: 0 : [3848] HttpWebRequest#33574638::GetResponse()
System.Net Information: 0 : [3848] Associating Connection#35191196 with HttpWebRequest#33574638
System.Net.Sockets Verbose: 0 : [3848] Socket#48285313::Socket(InterNetwork#2)
System.Net.Sockets Verbose: 0 : [3848] Exiting Socket#48285313::Socket()
System.Net.Sockets Verbose: 0 : [3848] Socket#48285313::Connect(1:443#16777668)
System.Net.Sockets Verbose: 0 : [3848] Exiting Socket#48285313::Connect()
System.Net Information: 0 : [3848] TlsStream#31914638::.ctor(host=localhost, #certs=0)
System.Net Information: 0 : [3848] Associating HttpWebRequest#33574638 with ConnectStream#18796293
System.Net Information: 0 : [3848] HttpWebRequest#33574638 - Request: GET /SecureNoClientCerts/test.htm HTTP/1.1

System.Net Information: 0 : [3848] SecureChannel#34948909::.ctor(hostname=localhost, #clientCertificates=0)
System.Net Information: 0 : [3848] Enumerating security packages:
System.Net Information: 0 : [3848] Negotiate
System.Net Information: 0 : [3848] Kerberos
System.Net Information: 0 : [3848] NTLM
System.Net Information: 0 : [3848] Microsoft Unified Security Protocol Provider
System.Net Information: 0 : [3848] Schannel
System.Net Information: 0 : [3848] WDigest
System.Net Information: 0 : [3848] DPA
System.Net Information: 0 : [3848] Digest
System.Net Information: 0 : [3848] MSN
System.Net Information: 0 : [3848] SecureChannel#34948909 - Left with 0 client certificates to choose from.
System.Net Information: 0 : [3848] AcquireCredentialsHandle(package = Microsoft Unified Security Protocol Provider, intent = Outbound, scc = System.Net.SecureCredential)
System.Net Information: 0 : [3848] InitializeSecurityContext(credential = System.Net.SafeFreeCredential_SECURITY, context = (null), targetName = localhost, inFlags = ReplayDetect, SequenceDetect, Confidentiality, AllocateMemory, InitManualCredValidation)
System.Net Information: 0 : [3848] InitializeSecurityContext(In-Buffer length=0, Out-Buffer length=70, returned code=ContinueNeeded).
System.Net.Sockets Verbose: 0 : [3848] Socket#48285313::Send()
System.Net.Sockets Verbose: 0 : [3848] Data from Socket#48285313::Send
System.Net.Sockets Verbose: 0 : [3848] 00000000 : 16 03 00 00 41 01 00 00-3D 03 00 43 26 02 90 83 : ....A...=..C&...
System.Net.Sockets Verbose: 0 : [3848] 00000010 : 33 F1 48 D6 4B 74 DB E2-47 6E 7A 3D 55 D2 43 E2 : 3.H.Kt..Gnz=U.C.
System.Net.Sockets Verbose: 0 : [3848] 00000020 : FC 02 CF 0B AF D4 E0 83-40 59 33 00 00 16 00 04 : ........@Y3.....
System.Net.Sockets Verbose: 0 : [3848] 00000030 : 00 05 00 0A 00 09 00 64-00 62 00 03 00 06 00 13 : .......d.b......
System.Net.Sockets Verbose: 0 : [3848] 00000040 : 00 12 00 63 01 00 : ...c..
System.Net.Sockets Verbose: 0 : [3848] Exiting Socket#48285313::Send() -> 70#70
System.Net.Sockets Verbose: 0 : [3848] Socket#48285313::Receive()
System.Net.Sockets Verbose: 0 : [3848] Data from Socket#48285313::Receive
System.Net.Sockets Verbose: 0 : [3848] 00000000 : 16 03 00 06 09 : .....
System.Net.Sockets Verbose: 0 : [3848] Exiting Socket#48285313::Receive() -> 5#5
System.Net.Sockets Verbose: 0 : [3848] Socket#48285313::Receive()
System.Net.Sockets Verbose: 0 : [3848] Data from Socket#48285313::Receive
System.Net.Sockets Verbose: 0 : [3848] (printing 1024 out of 1545)
System.Net.Sockets Verbose: 0 : [3848] 00000005 : 02 00 00 46 03 00 43 26-02 90 92 8B 0F 1A 72 76 : ...F..C&......rv
System.Net.Sockets Verbose: 0 : [3848] 00000015 : A2 48 A6 F3 3D 43 22 ED-D5 63 15 8E E3 BD 4F AD : .H..=C"..c....O.
System.Net.Sockets Verbose: 0 : [3848] 00000025 : DD 5A F4 42 B3 72 20 2B-0D 00 00 A7 86 54 E0 9B : .Z.B.r +.....T..
System.Net.Sockets Verbose: 0 : [3848] 00000035 : C7 9A 00 FB 5D 3C AC DD-3E D9 50 FC 08 D8 AD 9F : ....]<..>.P.....
System.Net.Sockets Verbose: 0 : [3848] 00000045 : 14 C7 97 AB 56 98 D4 00-04 00 0B 00 05 B7 00 05 : ....V...........
System.Net.Sockets Verbose: 0 : [3848] 00000055 : B4 00 05 B1 30 82 05 AD-30 82 04 95 A0 03 02 01 : ....0...0.......
System.Net.Sockets Verbose: 0 : [3848] 00000065 : 02 02 0A 34 74 D0 6D 00-02 00 00 01 2B 30 0D 06 : ...4t.m.....+0..
System.Net.Sockets Verbose: 0 : [3848] 00000075 : 09 2A 86 48 86 F7 0D 01-01 05 05 00 30 77 31 13 : .*.H........0w1.
System.Net.Sockets Verbose: 0 : [3848] 00000085 : 30 11 06 0A 09 92 26 89-93 F2 2C 64 01 19 16 03 : 0.....&...,d....
System.Net.Sockets Verbose: 0 : [3848] 00000095 : 63 6F 6D 31 19 30 17 06-0A 09 92 26 89 93 F2 2C : com1.0.....&...,
System.Net.Sockets Verbose: 0 : [3848] 000000A5 : 64 01 19 16 09 6D 69 63-72 6F 73 6F 66 74 31 14 : d....microsoft1.
System.Net.Sockets Verbose: 0 : [3848] 000000B5 : 30 12 06 0A 09 92 26 89-93 F2 2C 64 01 19 16 04 : 0.....&...,d....
System.Net.Sockets Verbose: 0 : [3848] 000000C5 : 63 6F 72 70 31 17 30 15-06 0A 09 92 26 89 93 F2 : corp1.0.....&...
System.Net.Sockets Verbose: 0 : [3848] 000000D5 : 2C 64 01 19 16 07 72 65-64 6D 6F 6E 64 31 16 30 : ,d....redmond1.0
System.Net.Sockets Verbose: 0 : [3848] 000000E5 : 14 06 03 55 04 03 13 0D-4E 43 4C 43 45 52 54 53 : ...U....NCLCERTS
System.Net.Sockets Verbose: 0 : [3848] 000000F5 : 45 52 56 45 52 30 1E 17-0D 30 35 30 38 32 31 30 : ERVER0...0508210
System.Net.Sockets Verbose: 0 : [3848] 00000105 : 30 33 30 32 35 5A 17 0D-30 36 30 38 32 31 30 30 : 03025Z..06082100
System.Net.Sockets Verbose: 0 : [3848] 00000115 : 34 30 32 35 5A 30 2E 31-2C 30 2A 06 03 55 04 03 : 4025Z0.1,0*..U..
System.Net.Sockets Verbose: 0 : [3848] 00000125 : 13 23 64 67 6F 72 74 69-6C 74 2E 72 65 64 6D 6F : .#dgortilt.redmo
System.Net.Sockets Verbose: 0 : [3848] 00000135 : 6E 64 2E 63 6F 72 70 2E-6D 69 63 72 6F 73 6F 66 : nd.corp.microsof
System.Net.Sockets Verbose: 0 : [3848] 00000145 : 74 2E 63 6F 6D 30 81 9F-30 0D 06 09 2A 86 48 86 : t.com0..0...*.H.
System.Net.Sockets Verbose: 0 : [3848] 00000155 : F7 0D 01 01 01 05 00 03-81 8D 00 30 81 89 02 81 : ...........0....
System.Net.Sockets Verbose: 0 : [3848] 00000165 : 81 00 CF E2 93 87 AF 2A-19 56 47 CF E0 2F E3 13 : .......*.VG../..
System.Net.Sockets Verbose: 0 : [3848] 00000175 : B8 4F B7 20 C7 FA 1A 55-5F B0 3E 6E B6 4B 9B DC : .O. ...U_.>n.K..
System.Net.Sockets Verbose: 0 : [3848] 00000185 : 50 1F 7E A7 5A 13 49 6D-8B 4A B1 27 50 91 47 51 : P.~.Z.Im.J.'P.GQ
System.Net.Sockets Verbose: 0 : [3848] 00000195 : 6A 8D 21 D1 DC 6C C2 AD-1D 38 E2 20 8A 1A 75 24 : j.!..l...8. ..u$
System.Net.Sockets Verbose: 0 : [3848] 000001A5 : F3 8F 51 E9 BD E7 F9 FE-8D 11 C9 3A 9E 88 B4 D0 : ..Q........:....
System.Net.Sockets Verbose: 0 : [3848] 000001B5 : A3 A9 C7 A6 7B C0 91 D9-1D 10 AE 00 38 C6 A9 8E : ....{.......8...
System.Net.Sockets Verbose: 0 : [3848] 000001C5 : 27 52 A5 48 5D DD DF 4B-BF F8 D0 43 AE 43 11 0F : 'R.H]..K...C.C..
System.Net.Sockets Verbose: 0 : [3848] 000001D5 : 0D A5 5E 2C A6 0A 37 9C-EF 9B 5A 30 FC D3 8A 54 : ..^,..7...Z0...T
System.Net.Sockets Verbose: 0 : [3848] 000001E5 : 55 33 02 03 01 00 01 A3-82 03 06 30 82 03 02 30 : U3.........0...0
System.Net.Sockets Verbose: 0 : [3848] 000001F5 : 0E 06 03 55 1D 0F 01 01-FF 04 04 03 02 04 F0 30 : ...U...........0
System.Net.Sockets Verbose: 0 : [3848] 00000205 : 44 06 09 2A 86 48 86 F7-0D 01 09 0F 04 37 30 35 : D..*.H.......705
System.Net.Sockets Verbose: 0 : [3848] 00000215 : 30 0E 06 08 2A 86 48 86-F7 0D 03 02 02 02 00 80 : 0...*.H.........
System.Net.Sockets Verbose: 0 : [3848] 00000225 : 30 0E 06 08 2A 86 48 86-F7 0D 03 04 02 02 00 80 : 0...*.H.........
System.Net.Sockets Verbose: 0 : [3848] 00000235 : 30 07 06 05 2B 0E 03 02-07 30 0A 06 08 2A 86 48 : 0...+....0...*.H
System.Net.Sockets Verbose: 0 : [3848] 00000245 : 86 F7 0D 03 07 30 1D 06-03 55 1D 0E 04 16 04 14 : .....0...U......
System.Net.Sockets Verbose: 0 : [3848] 00000255 : 25 9C 39 A7 F3 81 B2 20-79 95 22 C4 BD E3 2E A3 : %.9.... y.".....
System.Net.Sockets Verbose: 0 : [3848] 00000265 : 01 98 E6 AF 30 13 06 03-55 1D 25 04 0C 30 0A 06 : ....0...U.%..0..
System.Net.Sockets Verbose: 0 : [3848] 00000275 : 08 2B 06 01 05 05 07 03-01 30 1F 06 03 55 1D 23 : .+.......0...U.#
System.Net.Sockets Verbose: 0 : [3848] 00000285 : 04 18 30 16 80 14 53 FA-E2 5F A8 9E B1 10 55 65 : ..0...S.._....Ue
System.Net.Sockets Verbose: 0 : [3848] 00000295 : E3 53 13 1B 9E EF 2B 23-D8 F5 30 82 01 56 06 03 : .S....+#..0..V..
System.Net.Sockets Verbose: 0 : [3848] 000002A5 : 55 1D 1F 04 82 01 4D 30-82 01 49 30 82 01 45 A0 : U.....M0..I0..E.
System.Net.Sockets Verbose: 0 : [3848] 000002B5 : 82 01 41 A0 82 01 3D 86-81 A8 6C 64 61 70 3A 2F : ..A...=...ldap:/
System.Net.Sockets Verbose: 0 : [3848] 000002C5 : 2F 2F 43 4E 3D 4E 43 4C-43 45 52 54 53 45 52 56 : //CN=NCLCERTSERV
System.Net.Sockets Verbose: 0 : [3848] 000002D5 : 45 52 28 32 29 2C 43 4E-3D 77 69 74 34 2C 43 4E : ER(2),CN=wit4,CN
System.Net.Sockets Verbose: 0 : [3848] 000002E5 : 3D 43 44 50 2C 43 4E 3D-50 75 62 6C 69 63 25 32 : =CDP,CN=Public%2
System.Net.Sockets Verbose: 0 : [3848] 000002F5 : 30 4B 65 79 25 32 30 53-65 72 76 69 63 65 73 2C : 0Key%20Services,
System.Net.Sockets Verbose: 0 : [3848] 00000305 : 43 4E 3D 53 65 72 76 69-63 65 73 2C 44 43 3D 55 : CN=Services,DC=U
System.Net.Sockets Verbose: 0 : [3848] 00000315 : 6E 61 76 61 69 6C 61 62-6C 65 43 6F 6E 66 69 67 : navailableConfig
System.Net.Sockets Verbose: 0 : [3848] 00000325 : 44 4E 3F 63 65 72 74 69-66 69 63 61 74 65 52 65 : DN?certificateRe
System.Net.Sockets Verbose: 0 : [3848] 00000335 : 76 6F 63 61 74 69 6F 6E-4C 69 73 74 3F 62 61 73 : vocationList?bas
System.Net.Sockets Verbose: 0 : [3848] 00000345 : 65 3F 6F 62 6A 65 63 74-43 6C 61 73 73 3D 63 52 : e?objectClass=cR
System.Net.Sockets Verbose: 0 : [3848] 00000355 : 4C 44 69 73 74 72 69 62-75 74 69 6F 6E 50 6F 69 : LDistributionPoi
System.Net.Sockets Verbose: 0 : [3848] 00000365 : 6E 74 86 48 66 69 6C 65-3A 2F 2F 5C 5C 77 69 74 : nt.Hfile://\\wit
System.Net.Sockets Verbose: 0 : [3848] 00000375 : 34 2E 72 65 64 6D 6F 6E-64 2E 63 6F 72 70 2E 6D : 4.redmond.corp.m
System.Net.Sockets Verbose: 0 : [3848] 00000385 : 69 63 72 6F 73 6F 66 74-2E 63 6F 6D 5C 43 65 72 : icrosoft.com\Cer
System.Net.Sockets Verbose: 0 : [3848] 00000395 : 74 45 6E 72 6F 6C 6C 5C-4E 43 4C 43 45 52 54 53 : tEnroll\NCLCERTS
System.Net.Sockets Verbose: 0 : [3848] 000003A5 : 45 52 56 45 52 28 32 29-2E 63 72 6C 86 46 68 74 : ERVER(2).crl.Fht
System.Net.Sockets Verbose: 0 : [3848] 000003B5 : 74 70 3A 2F 2F 77 69 74-34 2E 72 65 64 6D 6F 6E : tp://wit4.redmon
System.Net.Sockets Verbose: 0 : [3848] 000003C5 : 64 2E 63 6F 72 70 2E 6D-69 63 72 6F 73 6F 66 74 : d.corp.microsoft
System.Net.Sockets Verbose: 0 : [3848] 000003D5 : 2E 63 6F 6D 2F 43 65 72-74 45 6E 72 6F 6C 6C 2F : .com/CertEnroll/
System.Net.Sockets Verbose: 0 : [3848] 000003E5 : 4E 43 4C 43 45 52 54 53-45 52 56 45 52 28 32 29 : NCLCERTSERVER(2)
System.Net.Sockets Verbose: 0 : [3848] 000003F5 : 2E 63 72 6C 30 81 FA 06-08 2B 06 01 05 05 07 01 : .crl0....+......
System.Net.Sockets Verbose: 0 : [3848] Exiting Socket#48285313::Receive() -> 1545#1545
System.Net Information: 0 : [3848] InitializeSecurityContext(credential = System.Net.SafeFreeCredential_SECURITY, context = 185a20:daf80, targetName = localhost, inFlags = ReplayDetect, SequenceDetect, Confidentiality, AllocateMemory, InitManualCredValidation)
System.Net Information: 0 : [3848] InitializeSecurityContext(In-Buffer length=1550, Out-Buffer length=204, returned code=ContinueNeeded).
System.Net.Sockets Verbose: 0 : [3848] Socket#48285313::Send()
System.Net.Sockets Verbose: 0 : [3848] Data from Socket#48285313::Send
System.Net.Sockets Verbose: 0 : [3848] 00000000 : 16 03 00 00 84 10 00 00-80 32 CB FC 3B 3B A6 67 : .........2..;;.g
System.Net.Sockets Verbose: 0 : [3848] 00000010 : BF F8 89 3F 40 CE 20 E4-79 92 4C 9C 8D 84 4C 77 : ...?@. .y.L...Lw
System.Net.Sockets Verbose: 0 : [3848] 00000020 : E6 BC 1D EA 59 95 F5 FA-E6 7B 35 40 68 EA 97 23 : ....Y....{5@h..#
System.Net.Sockets Verbose: 0 : [3848] 00000030 : 89 20 DD A5 E1 DD 2C 48-98 2F 2E C5 C3 4B 87 59 : . ....,H./...K.Y
System.Net.Sockets Verbose: 0 : [3848] 00000040 : C8 86 7F BA 85 CF BC B0-5C 26 1C E7 AA A6 C3 54 : ........\&.....T
System.Net.Sockets Verbose: 0 : [3848] 00000050 : 55 59 AE B3 3B 04 24 40-18 D5 B3 C8 57 02 83 E2 : UY..;.$@....W...
System.Net.Sockets Verbose: 0 : [3848] 00000060 : 46 2E 2B EA 1B C1 8E 6D-4A 3C E5 C7 5E 2E 47 24 : F.+....mJ<..^.G$
System.Net.Sockets Verbose: 0 : [3848] 00000070 : 13 DB 03 30 76 CB C4 19-FA D1 85 11 BD 5B AC A6 : ...0v........[..
System.Net.Sockets Verbose: 0 : [3848] 00000080 : 0D 60 9D E4 FB 6A BA 33-CB 14 03 00 00 01 01 16 : .`...j.3........
System.Net.Sockets Verbose: 0 : [3848] 00000090 : 03 00 00 38 B9 4C CA CF-CD C2 FF 20 61 43 8E 02 : ...8.L..... aC..
System.Net.Sockets Verbose: 0 : [3848] 000000A0 : 54 03 55 7D 6F 84 BE F9-B2 5D 44 31 1D FF B1 1F : T.U}o....]D1....
System.Net.Sockets Verbose: 0 : [3848] 000000B0 : 0F 45 04 81 ED 09 3A 2E-72 44 3E 37 B1 F6 CE 56 : .E....:.rD>7...V
System.Net.Sockets Verbose: 0 : [3848] 000000C0 : DB 67 11 8A E8 CE 35 23-DF 0B F5 3E : .g....5#...>
System.Net.Sockets Verbose: 0 : [3848] Exiting Socket#48285313::Send() -> 204#204
System.Net.Sockets Verbose: 0 : [3848] Socket#48285313::Receive()
System.Net.Sockets Verbose: 0 : [3848] Data from Socket#48285313::Receive
System.Net.Sockets Verbose: 0 : [3848] 00000000 : 14 03 00 00 01 : .....
System.Net.Sockets Verbose: 0 : [3848] Exiting Socket#48285313::Receive() -> 5#5
System.Net.Sockets Verbose: 0 : [3848] Socket#48285313::Receive()
System.Net.Sockets Verbose: 0 : [3848] Data from Socket#48285313::Receive
System.Net.Sockets Verbose: 0 : [3848] 00000005 : 01 : .
System.Net.Sockets Verbose: 0 : [3848] Exiting Socket#48285313::Receive() -> 1#1
System.Net Information: 0 : [3848] InitializeSecurityContext(credential = System.Net.SafeFreeCredential_SECURITY, context = 185a20:daf80, targetName = localhost, inFlags = ReplayDetect, SequenceDetect, Confidentiality, AllocateMemory, InitManualCredValidation)
System.Net Information: 0 : [3848] InitializeSecurityContext(In-Buffer length=6, Out-Buffer length=0, returned code=ContinueNeeded).
System.Net.Sockets Verbose: 0 : [3848] Socket#48285313::Receive()
System.Net.Sockets Verbose: 0 : [3848] Data from Socket#48285313::Receive
System.Net.Sockets Verbose: 0 : [3848] 00000000 : 16 03 00 00 38 : ....8
System.Net.Sockets Verbose: 0 : [3848] Exiting Socket#48285313::Receive() -> 5#5
System.Net.Sockets Verbose: 0 : [3848] Socket#48285313::Receive()
System.Net.Sockets Verbose: 0 : [3848] Data from Socket#48285313::Receive
System.Net.Sockets Verbose: 0 : [3848] 00000005 : 51 35 A8 FC 48 38 37 66-51 6D A3 A7 0C 10 95 93 : Q5..H87fQm......
System.Net.Sockets Verbose: 0 : [3848] 00000015 : 6B FF 8A 41 00 38 42 F4-B8 AA 0F C9 DB 71 16 46 : k..A.8B......q.F
System.Net.Sockets Verbose: 0 : [3848] 00000025 : 67 CA 04 20 F4 EF EB 31-EE BB C7 AD E8 7E B5 76 : g.. ...1.....~.v
System.Net.Sockets Verbose: 0 : [3848] 00000035 : 8D 63 96 99 96 63 53 3C- : .c...cS<
System.Net.Sockets Verbose: 0 : [3848] Exiting Socket#48285313::Receive() -> 56#56
System.Net Information: 0 : [3848] InitializeSecurityContext(credential = System.Net.SafeFreeCredential_SECURITY, context = 185a20:daf80, targetName = localhost, inFlags = ReplayDetect, SequenceDetect, Confidentiality, AllocateMemory, InitManualCredValidation)
System.Net Information: 0 : [3848] InitializeSecurityContext(In-Buffer length=61, Out-Buffer length=0, returned code=OK).
System.Net Information: 0 : [3848] Remote certificate: [Version]
V3

[Subject]
CN=dgortilt.redmond.corp.microsoft.com
Simple Name: dgortilt.redmond.corp.microsoft.com
DNS Name: dgortilt.redmond.corp.microsoft.com

[Issuer]
CN=NCLCERTSERVER, DC=redmond, DC=corp, DC=microsoft, DC=com
Simple Name: NCLCERTSERVER
DNS Name: NCLCERTSERVER

[Serial Number]
3474D06D00020000012B

[Not Before]
8/20/2005 5:30:25 PM

[Not After]
8/20/2006 5:40:25 PM

[Thumbprint]
19E34D7F445E49ACBD5EEECFF606F10197098F16

[Signature Algorithm]
sha1RSA(1.2.840.113549.1.1.5)

[Public Key]
Algorithm: RSA
Length: 1024
Key Blob: 30 81 89 02 81 81 00 cf e2 93 87 af 2a 19 56 47 cf e0 2f e3 13 b8 4f b7 20 c7 fa 1a 55 5f b0 3e 6e b6 4b 9b dc 50 1f 7e a7 5a 13 49 6d 8b 4a b1 27 50 91 47 51 6a 8d 21 d1 dc 6c c2 ad 1d 38 e2 20 8a 1a 75 24 f3 8f 51 e9 bd e7 f9 fe 8d 11 c9 3a 9e 88 b4 d0 a3 a9 c7 a6 7b c0 91 d9 1d 10 ae 00 38 c6 a9 8e 27 52 a5 48 5d dd df 4b bf f8 d0 43 ae 43 11 0f 0d a5 5e 2c a6 0a 37 9c ef 9b 5a 30 fc d3 8a 54 55 33 02 03 01 ....
System.Net Information: 0 : [3848] SecureChannel#34948909 - Remote certificate has errors:
System.Net Information: 0 : [3848] SecureChannel#34948909 - Certificate name mismatch.
System.Net Information: 0 : [3848] SecureChannel#34948909 - Remote certificate was verified as valid by the user.
System.Net.Sockets Verbose: 0 : [3848] Socket#48285313::Send()
System.Net.Sockets Verbose: 0 : [3848] Data from Socket#48285313::Send
System.Net.Sockets Verbose: 0 : [3848] 00000000 : 17 03 00 00 67 79 FD 10-7F A4 92 38 C5 80 38 EE : ....gy.....8..8.
System.Net.Sockets Verbose: 0 : [3848] 00000010 : 3A 6C 66 B7 0C CC C7 29-0C EC 3C 3B 88 D0 BE 94 : :lf....)..<;....
System.Net.Sockets Verbose: 0 : [3848] 00000020 : 6E C6 0D 7D B4 12 29 BD-ED 86 05 8C 17 CA 1B 9D : n..}..).........
System.Net.Sockets Verbose: 0 : [3848] 00000030 : D6 1A D7 65 D9 77 AD 5A-7C 17 E7 1A 78 69 90 B0 : ...e.w.Z|...xi..
System.Net.Sockets Verbose: 0 : [3848] 00000040 : DB 68 89 D8 F3 56 C2 D4-F8 52 CF EB 4B 1E 38 4B : .h...V...R..K.8K
System.Net.Sockets Verbose: 0 : [3848] 00000050 : D4 0D AA 5A 5C A4 C4 15-E8 AF F2 79 93 E0 06 37 : ...Z\......y...7
System.Net.Sockets Verbose: 0 : [3848] 00000060 : 10 CA 42 A9 49 8C B2 AC-33 85 68 80 : ..B.I...3.h.
System.Net.Sockets Verbose: 0 : [3848] Exiting Socket#48285313::Send() -> 108#108
System.Net Information: 0 : [3848] ConnectStream#18796293 - Sending headers
{
Host: localhost
Connection: Keep-Alive
}.

You can see clearly that

1) The Remote Certificate is being clearly presented in the log file.
2) Any errors in the remote certificate are logged.
3) In this case we are returning true for NAME MISMATCH if the server is local or intranet [Please see the
remore certificate validation callback code]
4) The fact that we accepted the certificate is also logged.
5) Then at the sockets level you can see encrypted data being sent
6) At the System.Net level (application level) you can see the decrypted data.

You can see now how easy it is to debug SSL apps using the system.Net tracing.
Let me know your comments

Durgaprasad Gorti
Test Lead
System.Net
Microsoft

Comments

  • Anonymous
    September 18, 2005
    great entry!

  • Anonymous
    June 19, 2006
    For a detailed blog article on how to use System.Net Tracing go here http://blogs.msdn.com/dgorti/archive/2005/09/18/471003.aspxPlease...

  • Anonymous
    February 12, 2007
    Here is another problem I had a couple of days ago: the customer had a critical problem with on one of

  • Anonymous
    February 25, 2008
    PingBack from http://ossmall.info/2008/02/25/how-to-use-systemnet-tracing-to-troubleshoot-content-deployment-issues-and-search-issues-in-sharepoint-server-2007/

  • Anonymous
    July 25, 2008
    Sytem.Net tracing One of the easiest ways is to use the built in System.Net tracing. It is a matter of

  • Anonymous
    July 25, 2008
    PingBack from http://wordnew.acne-reveiw.info/?p=13050

  • Anonymous
    January 18, 2009
    PingBack from http://www.keyongtech.com/2836210-config-file-problems

  • Anonymous
    January 21, 2009
    PingBack from http://www.keyongtech.com/428557-getting-more-info-from-webexception

  • Anonymous
    March 20, 2009
    Hi, This article given some hope to solve my issue.  But i need some from you. My goal is to add some data with internal req/reps process between client and server application. i did a proxy class which contain 2 socket, one socket listen a port (1234) and another one listen server ip. once i get req from client i'll forward that request to server and i revert the response from server to client through my proxy class. while doing this i'm getting "HTTP/1.1 400 Bad Request" response from server and the connection was closed, so server not accepting any more request through proxy. without proxy if i communicate i'm getting proper "HTTP/1.1 200 OK" from server. can you help me to solve this issue.

  • Anonymous
    September 02, 2009
    The comment has been removed

  • Anonymous
    November 12, 2009
    so... where does the trace file get saved to?

  • Anonymous
    October 26, 2010
    In my experience the trace file is saved into the same folder as the app.exe.config file.

  • Anonymous
    November 09, 2010
    I owe you big time. This thing simply works, no sniffing whatsoever, fully verbose problem solving. Love it!

  • Anonymous
    January 14, 2014
    very nice post. deserve 5 star

  • Anonymous
    February 05, 2014
    I pasted the information into my app.exe.config (a console app) and receiving an exception (ConfigurationErrorsException). The system.diagnostics section doesn't seem to want to belong anywhere. I'm using .Net 4.0 and VS2014

  • Anonymous
    July 12, 2016
    thanks so much for this!