Sunday, March 23, 2014

WCF Service Trace Viewer Part 2

WCF Service Trace Viewer Part 2

Continuing from the previous part, now we’ll have a look at what happens when we call the service using WSHttpBinding. For this, I have to instantiate my LearnWcfService service passing the WSHttp binding endpoint to the constructor. The rest of the method runs the exact same instructions as before. I have also changed the instantiateData attribute in the app.config file to ClientLogWsHttp.svclog, just to keep the log files separate.
image_thumb11
Clearly, there are more activities than the ‘basic’ version. As done before, I click on the Construct ChannelFactory… activity and the Get ChannelEndpointElement trace and see that we’re now binding through wsHttpBinding.
image_thumb6
In addition to other things, we see an activity called ‘Set up Secure Session’. This is where a secure session information is instantiated. The next few activities – Processing message 1, 2, 3 are all related to this hand-shake.
We’ll see some details on this even on the Message tab.
image_thumb2
Just to compare, scroll up and compare the number of messages on Basic Http binding 8 : 22. I think we can account so much of data-exchange and bandwidth usage as the price paid for security. Here’s what I learned about those messages:
RST – Request Secure Token
RSTR – Request Secure Token Response
SCT – Secure Context Token
Looking at the first message, you’ll find the full ‘xml’ised version of the request that is being sent.
   1: <E2ETraceEvent xmlns="http://schemas.microsoft.com/2004/06/E2ETraceEvent">
   2:     <System xmlns="http://schemas.microsoft.com/2004/06/windows/eventlog/system">
   3:         <EventID>0</EventID>
   4:         <Type>3</Type>
   5:         <SubType Name="Information">0</SubType>
   6:         <Level>8</Level>
   7:         <TimeCreated SystemTime="2011-04-12T05:09:50.1644952Z" />
   8:         <Source Name="System.ServiceModel.MessageLogging" />
   9:         <Correlation ActivityID="{4e5dfe15-fb15-4097-bf66-5f1a28f85d74}" />
  10:         <Execution ProcessName="ClientApplication" ProcessID="7208" ThreadID="1" />
  11:         <Channel />
  12:         <Computer>MyComputer</Computer>
  13:     </System>
  14:     <ApplicationData>
  15:         <TraceData>
  16:             <DataItem>
  17:                 <MessageLogTraceRecord Time="2011-04-12T10:39:50.1584946+05:30" Source="ServiceLevelSendRequest" Type="System.ServiceModel.Channels.BodyWriterMessage" xmlns="http://schemas.microsoft.com/2004/06/ServiceModel/Management/MessageTrace">
  18:                     <s:Envelope xmlns:a="http://www.w3.org/2005/08/addressing" xmlns:s="http://www.w3.org/2003/05/soap-envelope">
  19:                         <s:Header>
  20:                             <a:Action s:mustUnderstand="1">http://tempuri.org/ILearnWcfService/AddInt</a:Action>
  21:                             <a:MessageID>urn:uuid:438598db-0d89-4e42-a955-11e9be43088f</a:MessageID>
  22:                             <a:ReplyTo>
  23:                                 <a:Address>http://www.w3.org/2005/08/addressing/anonymous</a:Address>
  24:                             </a:ReplyTo>
  25:                         </s:Header>
  26:                         <s:Body>
  27:                             <AddInt xmlns="http://tempuri.org/">
  28:                                 <arg1>1</arg1>
  29:                                 <arg2>2</arg2>
  30:                             </AddInt>
  31:                         </s:Body>
  32:                     </s:Envelope>
  33:                 </MessageLogTraceRecord>
  34:             </DataItem>
  35:         </TraceData>
  36:     </ApplicationData>
  37: </E2ETraceEvent>
Notice the arguments and the method call that is being mentioned in the xml. Also see the Source attribute that says ServiceLevelSendRequest. But if you continue looking at the next message for AddInt, you’ll find that the request has now been fully encrypted and totally unreadable (CipherValue element). The message is now in the TransportSend status. This is WSHttpBinding at work.
image_thumb7
The very next message (first of the AddIntResponse message) is the TransportReceive stage where the data is still encrypted and it is only in the last of the AddIntResponse messages does it come the ServiceLevelReceiveReply stage where it becomes readable. We see how WSHttp secures the data during the different layers. If you cross check, the data remains as plain- readable-text throughout the process of Basic Http binding.
   1: <E2ETraceEvent xmlns="http://schemas.microsoft.com/2004/06/E2ETraceEvent">
   2:     <System xmlns="http://schemas.microsoft.com/2004/06/windows/eventlog/system">
   3:         <EventID>0</EventID>
   4:         <Type>3</Type>
   5:         <SubType Name="Information">0</SubType>
   6:         <Level>8</Level>
   7:         <TimeCreated SystemTime="2011-04-12T05:10:11.9866772Z" />
   8:         <Source Name="System.ServiceModel.MessageLogging" />
   9:         <Correlation ActivityID="{c4060ea9-a788-4490-b228-03dd04f6de28}" />
  10:         <Execution ProcessName="ClientApplication" ProcessID="7208" ThreadID="1" />
  11:         <Channel />
  12:         <Computer>MyComputer</Computer>
  13:     </System>
  14:     <ApplicationData>
  15:         <TraceData>
  16:             <DataItem>
  17:                 <MessageLogTraceRecord Time="2011-04-12T10:40:11.9856771+05:30" Source="ServiceLevelReceiveReply" Type="System.ServiceModel.Security.SecurityVerifiedMessage" xmlns="http://schemas.microsoft.com/2004/06/ServiceModel/Management/MessageTrace">
  18:                     <HttpResponse>
  19:                         <StatusCode>OK</StatusCode>
  20:                         <StatusDescription>OK</StatusDescription>
  21:                         <WebHeaders>
  22:                             <Connection>Close</Connection>
  23:                             <Content-Length>5094</Content-Length>
  24:                             <Cache-Control>private</Cache-Control>
  25:                             <Content-Type>application/soap+xml; charset=utf-8</Content-Type>
  26:                             <Date>Tue, 12 Apr 2011 05:10:11 GMT</Date>
  27:                             <Server>ASP.NET Development Server/10.0.0.0</Server>
  28:                             <X-AspNet-Version>4.0.30319</X-AspNet-Version>
  29:                         </WebHeaders>
  30:                     </HttpResponse>
  31:                     <s:Envelope xmlns:s="http://www.w3.org/2003/05/soap-envelope">
  32:                         <s:Header>
  33:                             <a:Action s:mustUnderstand="1" u:Id="_2" xmlns:u="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-utility-1.0.xsd" xmlns:a="http://www.w3.org/2005/08/addressing">http://tempuri.org/ILearnWcfService/AddIntResponse</a:Action>
  34:                             <a:RelatesTo u:Id="_3" xmlns:u="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-utility-1.0.xsd" xmlns:a="http://www.w3.org/2005/08/addressing">urn:uuid:438598db-0d89-4e42-a955-11e9be43088f</a:RelatesTo>
  35:                             <o:Security s:mustUnderstand="1" xmlns:o="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-secext-1.0.xsd">
  36:                                 <u:Timestamp u:Id="uuid-5d226149-f6d5-4f95-bf27-63a2be952b57-11" xmlns:u="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-utility-1.0.xsd">
  37:                                     <u:Created>2011-04-12T05:10:11.964Z</u:Created>
  38:                                     <u:Expires>2011-04-12T05:15:11.964Z</u:Expires>
  39:                                 </u:Timestamp>
  40:                                 <c:DerivedKeyToken u:Id="uuid-5d226149-f6d5-4f95-bf27-63a2be952b57-7" xmlns:c="http://schemas.xmlsoap.org/ws/2005/02/sc" xmlns:u="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-utility-1.0.xsd">
  41:                                     <o:SecurityTokenReference>
  42:                                         <o:Reference URI="urn:uuid:c10f0ecb-1c3e-4afe-b6f3-240d19318329" ValueType="http://schemas.xmlsoap.org/ws/2005/02/sc/sct"></o:Reference>
  43:                                     </o:SecurityTokenReference>
  44:                                     <c:Offset>0</c:Offset>
  45:                                     <c:Length>24</c:Length>
  46:                                     <c:Nonce>
  47:                                         
  48:                                     </c:Nonce>
  49:                                 </c:DerivedKeyToken>
  50:                                 <c:DerivedKeyToken u:Id="uuid-5d226149-f6d5-4f95-bf27-63a2be952b57-8" xmlns:c="http://schemas.xmlsoap.org/ws/2005/02/sc" xmlns:u="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-utility-1.0.xsd">
  51:                                     <o:SecurityTokenReference>
  52:                                         <o:Reference URI="urn:uuid:c10f0ecb-1c3e-4afe-b6f3-240d19318329" ValueType="http://schemas.xmlsoap.org/ws/2005/02/sc/sct"></o:Reference>
  53:                                     </o:SecurityTokenReference>
  54:                                     <c:Nonce>
  55:                                         
  56:                                     </c:Nonce>
  57:                                 </c:DerivedKeyToken>
  58:                                 <e:ReferenceList xmlns:e="http://www.w3.org/2001/04/xmlenc#">
  59:                                     <e:DataReference URI="#_1"></e:DataReference>
  60:                                     <e:DataReference URI="#_4"></e:DataReference>
  61:                                 </e:ReferenceList>
  62:                                 <Signature xmlns="http://www.w3.org/2000/09/xmldsig#">
  63:                                     <SignedInfo>
  64:                                         <CanonicalizationMethod Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"></CanonicalizationMethod>
  65:                                         <SignatureMethod Algorithm="http://www.w3.org/2000/09/xmldsig#hmac-sha1"></SignatureMethod>
  66:                                         <Reference URI="#_0">
  67:                                             <Transforms>
  68:                                                 <Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"></Transform>
  69:                                             </Transforms>
  70:                                             <DigestMethod Algorithm="http://www.w3.org/2000/09/xmldsig#sha1"></DigestMethod>
  71:                                             <DigestValue>iXK6QpgkLD0hNgV4zbd2p8UZTMk=</DigestValue>
  72:                                         </Reference>
  73:                                         <Reference URI="#_2">
  74:                                             <Transforms>
  75:                                                 <Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"></Transform>
  76:                                             </Transforms>
  77:                                             <DigestMethod Algorithm="http://www.w3.org/2000/09/xmldsig#sha1"></DigestMethod>
  78:                                             <DigestValue>dd5TBRTJOCia0ttk9jZrsX/BIwY=</DigestValue>
  79:                                         </Reference>
  80:                                         <Reference URI="#_3">
  81:                                             <Transforms>
  82:                                                 <Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"></Transform>
  83:                                             </Transforms>
  84:                                             <DigestMethod Algorithm="http://www.w3.org/2000/09/xmldsig#sha1"></DigestMethod>
  85:                                             <DigestValue>wUCHZwK/oA2Zf1DW7teWcpC60DE=</DigestValue>
  86:                                         </Reference>
  87:                                         <Reference URI="#uuid-5d226149-f6d5-4f95-bf27-63a2be952b57-11">
  88:                                             <Transforms>
  89:                                                 <Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"></Transform>
  90:                                             </Transforms>
  91:                                             <DigestMethod Algorithm="http://www.w3.org/2000/09/xmldsig#sha1"></DigestMethod>
  92:                                             <DigestValue>UdX3NPo64fNoC7c5BTaTu45ORvY=</DigestValue>
  93:                                         </Reference>
  94:                                     </SignedInfo>
  95:                                     <SignatureValue>9i+ypgIBP6F6GCs81fikfS/Sly8=</SignatureValue>
  96:                                     <KeyInfo>
  97:                                         <o:SecurityTokenReference xmlns:o="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-secext-1.0.xsd">
  98:                                             <o:Reference ValueType="http://schemas.xmlsoap.org/ws/2005/02/sc/dk" URI="#uuid-5d226149-f6d5-4f95-bf27-63a2be952b57-7"></o:Reference>
  99:                                         </o:SecurityTokenReference>
 100:                                     </KeyInfo>
 101:                                 </Signature>
 102:                             </o:Security>
 103:                         </s:Header>
 104:                         <s:Body u:Id="_0" xmlns:u="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-utility-1.0.xsd">
 105:                             <AddIntResponse xmlns="http://tempuri.org/">
 106:                                 <AddIntResult>3</AddIntResult>
 107:                             </AddIntResponse>
 108:                         </s:Body>
 109:                     </s:Envelope>
 110:                 </MessageLogTraceRecord>
 111:             </DataItem>
 112:         </TraceData>
 113:     </ApplicationData>
 114: </E2ETraceEvent>
Once again, the same process repeats for the AddDouble operation.
.SvcLog files used for the article
References:
http://msdn.microsoft.com/en-us/library/aa751795.aspx – Using Service Trace Viewer
http://msdn.microsoft.com/en-us/library/ms733025.aspx – Configuring Tracing
http://msdn.microsoft.com/en-us/library/ms732023.aspx – Service Trace Viewer Tool
http://msdn.microsoft.com/en-us/library/ms751526.aspx – Tracing and Message Logging
Published Friday, June 10, 2011 6:29 AM by nmarun

No comments:

Post a Comment