Use System.Net Trace and SSL Alert Protocol to troubleshoot SSL connection issue.

[Hui Zhu]

First published on MSDN on Nov 05, 2012

WCF client and ASMX webservice client all use the System.Net.HttpWebRequest object to create underlying SSL connection. If you experience any SSL related problem, you can take a System.Net trace first.

If System.Net trace shows the pattern of following SSL alert sequence 15 03 01 00 02, we can use RFC 2246, http://www.ietf.org/rfc/rfc2246.txt , section 7.2 to get the possible root cause of SSL failure.

Sample snippet in System.Net trace.

System.Ne.Sockets Verbose: 0 : [5136] 00000000 : 15 03 01 00 02 :

Step 1: Taking System.Net trace.

1.)    Add the contents of the listed XML file to your application configuration file.

If you have a desktop application, the configuration file will be a file called YourApp.exe.config
If it is an asp.net application, the configuration file will be a file called web.config residing in your asp.net application directory.

2.)    Please create a folder called c:\traces, and give full permissions to “Everyone”. This will ensure that the log will get created regardless of the process/thread identity.

3.)    Restart your application process (YourApp.exe for desktop applications and w3wp.exe for asp.net applications)

4.)    Reproduce the problem

5.)    You should see a file called System.Net.trace.log in the c:\traces folder.

Note: If you want to change the location of where the log gets generated, you can do it by changing the following section:

initializeData="yourDrive:\YourFolder\YourSubFolder……\System.Net.trace.log"

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
<system.diagnostics>
<trace autoflush="true" />
<sources>
<source name="System.Net">
<listeners>
<add name="System.Net"/>
</listeners>
</source>
<source name="System.Net.HttpListener">
<listeners>
<add name="System.Net"/>
</listeners>
</source>
<source name="System.Net.Sockets">
<listeners>
<add name="System.Net"/>
</listeners>
</source>
<source name="System.Net.Cache">
<listeners>
<add name="System.Net"/>
</listeners>
</source>
</sources>
<sharedListeners>
<add
name="System.Net"
type="System.Diagnostics.TextWriterTraceListener"
initializeData="c:\traces\System.Net.trace.log"
traceOutputOptions="DateTime"
/>
</sharedListeners>
<switches>
<add name="System.Net" value="Verbose" />
<add name="System.Net.Sockets" value="Verbose" />
<add name="System.Net.Cache" value="Verbose" />
<add name="System.Net.HttpListener" value="Verbose" />
</switches>
</system.diagnostics>
</configuration>

Additional information on taking System.Net trace, please check http://msdn.microsoft.com/en-us/library/ty48b824.aspx and http://blogs.msdn.com/b/jpsanders/archive/2009/03/24/my-favorite-system-net-trace-configuration...

Step 2: Review System.Net trace.

SSL connection always starts with a client hello payload. In the System.Net trace, you will see something like this:

System.Net.Sockets Verbose: 0 : [5712] Data from Socket#33420276::Send
System.Net.Sockets Verbose: 0 : [5712] 00000000 : 16 03 01 00 6B 01 00 00-67 03 01 4F 8A 0F 82 CB : ....k...g..O....
System.Net.Sockets Verbose: 0 : [5712] 00000010 : FD 08 6F 6C 6F DC AD 20-D2 02 13 4F D8 F0 AD D9 : ..olo.. ...O....
System.Net.Sockets Verbose: 0 : [5712] 00000020 : 5C 22 3C 63 C6 53 AE B2-3D 21 81 00 00 18 C0 14 : \"<c.S..=!......
System.Net.Sockets Verbose: 0 : [5712] 00000030 : C0 13 00 2F 00 35 00 05-00 0A C0 09 C0 0A 00 32 : .../.5.........2
System.Net.Sockets Verbose: 0 : [5712] 00000040 : 00 38 00 13 00 04 01 00-00 26 FF 01 00 01 00 00 : .8.......&......
System.Net.Sockets Verbose: 0 : [5712] 00000050 : 00 00 0B 00 09 00 00 06-68 7A 64 73 6B 38 00 0A : ........hzdsk8..
System.Net.Sockets Verbose: 0 : [5712] 00000060 : 00 08 00 06 00 19 00 18-00 17 00 0B 00 02 01 00 : ................
System.Net.Sockets Verbose: 0 : [5712] Exiting Socket#33420276::Send()  -> 112#112

16  --- > decimal 22, means handshake(22),

03 01 --- > SSL version 3.1, so it is TLS 1.0

00 6B -- > payload size

To possibly detect some certain SSL connection failure from text based System.Net log, now we can leverage RFC 2246,
http://www.ietf.org/rfc/rfc2246.txt

7.2.   Alert protocol

The Raw Bytes Pattern is  15 03 01 00 02

like this trace file sample:

System.Net.Sockets Verbose: 0 : [5792] 00000000 : 15 03 01 00 02

15: --- > Hex, means 21, it is a signature for alert in RFC 2246, alert(21),

enum {
change_cipher_spec(20), alert(21), handshake(22),
application_data(23), (255)
} ContentType;

03 0x  --- > SSL version

03 01 means SSL V 3.1, which is TLS 1.0

03 00 means SSL V 3.0

00 02 --- > Content Size: which is 2 bytes:

The format is following RFC 2246 SSL struct

struct {
ContentType type;                 ---  > 1 byte
ProtocolVersion version;        --- > 2 bytes
uint16 length;                         --- > 2 bytes
opaque fragment[TLSPlaintext.length];
} TLSPlaintext;

Now we can look at the data for 2 bytes Content:

trace file:

System.Net.Sockets Verbose: 0 : [5792] 00000005 : 02 30

DateTime=2009-07-09T19:13:26.1341615Z
System.Net.Sockets Verbose: 0 : [5792] Exiting
Socket#37472519::Receive() -> 2#2
DateTime=2009-07-09T19:13:26.1341615Z

02 means:

enum { warning(1), fatal(2), (255) } AlertLevel;

30 means: 0x30 --- > 0n48, which is
unknow_ca (the issuer of certificate authority is not trusted).

Here is the entire enum list of error code from http://www.ietf.org/rfc/rfc2246.txt

enum {
close_notify(0),
unexpected_message(10),
bad_record_mac(20),
decryption_failed(21),
record_overflow(22),
decompression_failure(30),
handshake_failure(40),
bad_certificate(42),
unsupported_certificate(43),
certificate_revoked(44),
certificate_expired(45),
certificate_unknown(46),
illegal_parameter(47),
unknown_ca(48),
access_denied(49),
decode_error(50),
decrypt_error(51),
export_restriction(60),
protocol_version(70),
insufficient_security(71),
internal_error(80),
user_canceled(90),
no_renegotiation(100),
(255)
} AlertDescription;

Here is the sample snippet for raw trace file:

… ….
System.Net.Sockets Verbose: 0 : [5792] Socket#37472519::Receive()
DateTime=2009-07-09T19:13:26.1341615Z
System.Net.Sockets Verbose: 0 : [5792] Data from Socket#37472519::Receive
DateTime=2009-07-09T19:13:26.1341615Z
System.Net.Sockets Verbose: 0 : [5792] 00000000 : 15 03 01 00 02                                  : .....
DateTime=2009-07-09T19:13:26.1341615Z
System.Net.Sockets Verbose: 0 : [5792] Exiting Socket#37472519::Receive() -> 5#5
DateTime=2009-07-09T19:13:26.1341615Z
System.Net.Sockets Verbose: 0 : [5792] Socket#37472519::Receive()
DateTime=2009-07-09T19:13:26.1341615Z
System.Net.Sockets Verbose: 0 : [5792] Data from Socket#37472519::Receive
DateTime=2009-07-09T19:13:26.1341615Z
System.Net.Sockets Verbose: 0 : [5792] 00000005 : 02 30                                           : .0
DateTime=2009-07-09T19:13:26.1341615Z
System.Net.Sockets Verbose: 0 : [5792] Exiting Socket#37472519::Receive() -> 2#2
DateTime=2009-07-09T19:13:26.1341615Z
System.Net Information: 0 : [5792] InitializeSecurityContext(credential = System.Net.SafeFreeCredential_SECURITY, context = 225480:1107220, targetName = gmservices.pp.gm.com, inFlags = ReplayDetect, SequenceDetect, Confidentiality, AllocateMemory, InitManualCredValidation)
DateTime=2009-07-09T19:13:26.1341615Z
System.Net Information: 0 : [5792] InitializeSecurityContext(In-Buffers count=2, Out-Buffer length=0, returned code=UntrustedRoot).
DateTime=2009-07-09T19:13:26.1497868Z
System.Net.Sockets Verbose: 0 : [5792] Socket#37472519::Dispose()
DateTime=2009-07-09T19:13:26.1654121Z
System.Net Error: 0 : [5792] Exception in the HttpWebRequest#55855606:: - The request was aborted: Could not create SSL/TLS secure channel.
DateTime=2009-07-09T19:13:26.1654121Z