Programming Stuff

Sunday, March 23, 2014

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.

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.

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.

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.

<E2ETraceEvent xmlns="http://schemas.microsoft.com/2004/06/E2ETraceEvent">
    <System xmlns="http://schemas.microsoft.com/2004/06/windows/eventlog/system">
        <EventID>0</EventID>
        <Type>3</Type>
        <SubType Name="Information">0</SubType>
        <Level>8</Level>
        <TimeCreated SystemTime="2011-04-12T05:09:50.1644952Z" />
        <Source Name="System.ServiceModel.MessageLogging" />
        <Correlation ActivityID="{4e5dfe15-fb15-4097-bf66-5f1a28f85d74}" />
        <Execution ProcessName="ClientApplication" ProcessID="7208" ThreadID="1" />
        <Channel />
        <Computer>MyComputer</Computer>
    </System>
    <ApplicationData>
        <TraceData>
            <DataItem>
                <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">
                    <s:Envelope xmlns:a="http://www.w3.org/2005/08/addressing" xmlns:s="http://www.w3.org/2003/05/soap-envelope">
                        <s:Header>
                            <a:Action s:mustUnderstand="1">http://tempuri.org/ILearnWcfService/AddInt</a:Action>
                            <a:MessageID>urn:uuid:438598db-0d89-4e42-a955-11e9be43088f</a:MessageID>
                            <a:ReplyTo>
                                <a:Address>http://www.w3.org/2005/08/addressing/anonymous</a:Address>
                            </a:ReplyTo>
                        </s:Header>
                        <s:Body>
                            <AddInt xmlns="http://tempuri.org/">
                                <arg1>1</arg1>
                                <arg2>2</arg2>
                            </AddInt>
                        </s:Body>
                    </s:Envelope>
                </MessageLogTraceRecord>
            </DataItem>
        </TraceData>
    </ApplicationData>
</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.

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.

<E2ETraceEvent xmlns="http://schemas.microsoft.com/2004/06/E2ETraceEvent">
    <System xmlns="http://schemas.microsoft.com/2004/06/windows/eventlog/system">
        <EventID>0</EventID>
        <Type>3</Type>
        <SubType Name="Information">0</SubType>
        <Level>8</Level>
        <TimeCreated SystemTime="2011-04-12T05:10:11.9866772Z" />
        <Source Name="System.ServiceModel.MessageLogging" />
        <Correlation ActivityID="{c4060ea9-a788-4490-b228-03dd04f6de28}" />
        <Execution ProcessName="ClientApplication" ProcessID="7208" ThreadID="1" />
        <Channel />
        <Computer>MyComputer</Computer>
    </System>
    <ApplicationData>
        <TraceData>
            <DataItem>
                <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">
                    <HttpResponse>
                        <StatusCode>OK</StatusCode>
                        <StatusDescription>OK</StatusDescription>
                        <WebHeaders>
                            <Connection>Close</Connection>
                            <Content-Length>5094</Content-Length>
                            <Cache-Control>private</Cache-Control>
                            <Content-Type>application/soap+xml; charset=utf-8</Content-Type>
                            <Date>Tue, 12 Apr 2011 05:10:11 GMT</Date>
                            <Server>ASP.NET Development Server/10.0.0.0</Server>
                            <X-AspNet-Version>4.0.30319</X-AspNet-Version>
                        </WebHeaders>
                    </HttpResponse>
                    <s:Envelope xmlns:s="http://www.w3.org/2003/05/soap-envelope">
                        <s:Header>
                            <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>
                            <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>
                            <o:Security s:mustUnderstand="1" xmlns:o="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-secext-1.0.xsd">
                                <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">
                                    <u:Created>2011-04-12T05:10:11.964Z</u:Created>
                                    <u:Expires>2011-04-12T05:15:11.964Z</u:Expires>
                                </u:Timestamp>
                                <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">
                                    <o:SecurityTokenReference>
                                        <o:Reference URI="urn:uuid:c10f0ecb-1c3e-4afe-b6f3-240d19318329" ValueType="http://schemas.xmlsoap.org/ws/2005/02/sc/sct"></o:Reference>
                                    </o:SecurityTokenReference>
                                    <c:Offset>0</c:Offset>
                                    <c:Length>24</c:Length>
                                    <c:Nonce>
                                        
                                    </c:Nonce>
                                </c:DerivedKeyToken>
                                <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">
                                    <o:SecurityTokenReference>
                                        <o:Reference URI="urn:uuid:c10f0ecb-1c3e-4afe-b6f3-240d19318329" ValueType="http://schemas.xmlsoap.org/ws/2005/02/sc/sct"></o:Reference>
                                    </o:SecurityTokenReference>
                                    <c:Nonce>
                                        
                                    </c:Nonce>
                                </c:DerivedKeyToken>
                                <e:ReferenceList xmlns:e="http://www.w3.org/2001/04/xmlenc#">
                                    <e:DataReference URI="#_1"></e:DataReference>
                                    <e:DataReference URI="#_4"></e:DataReference>
                                </e:ReferenceList>
                                <Signature xmlns="http://www.w3.org/2000/09/xmldsig#">
                                    <SignedInfo>
                                        <CanonicalizationMethod Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"></CanonicalizationMethod>
                                        <SignatureMethod Algorithm="http://www.w3.org/2000/09/xmldsig#hmac-sha1"></SignatureMethod>
                                        <Reference URI="#_0">
                                            <Transforms>
                                                <Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"></Transform>
                                            </Transforms>
                                            <DigestMethod Algorithm="http://www.w3.org/2000/09/xmldsig#sha1"></DigestMethod>
                                            <DigestValue>iXK6QpgkLD0hNgV4zbd2p8UZTMk=</DigestValue>
                                        </Reference>
                                        <Reference URI="#_2">
                                            <Transforms>
                                                <Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"></Transform>
                                            </Transforms>
                                            <DigestMethod Algorithm="http://www.w3.org/2000/09/xmldsig#sha1"></DigestMethod>
                                            <DigestValue>dd5TBRTJOCia0ttk9jZrsX/BIwY=</DigestValue>
                                        </Reference>
                                        <Reference URI="#_3">
                                            <Transforms>
                                                <Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"></Transform>
                                            </Transforms>
                                            <DigestMethod Algorithm="http://www.w3.org/2000/09/xmldsig#sha1"></DigestMethod>
                                            <DigestValue>wUCHZwK/oA2Zf1DW7teWcpC60DE=</DigestValue>
                                        </Reference>
                                        <Reference URI="#uuid-5d226149-f6d5-4f95-bf27-63a2be952b57-11">
                                            <Transforms>
                                                <Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"></Transform>
                                            </Transforms>
                                            <DigestMethod Algorithm="http://www.w3.org/2000/09/xmldsig#sha1"></DigestMethod>
                                            <DigestValue>UdX3NPo64fNoC7c5BTaTu45ORvY=</DigestValue>
                                        </Reference>
                                    </SignedInfo>
                                    <SignatureValue>9i+ypgIBP6F6GCs81fikfS/Sly8=</SignatureValue>
                                    <KeyInfo>
                                        <o:SecurityTokenReference xmlns:o="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-secext-1.0.xsd">
                                            <o:Reference ValueType="http://schemas.xmlsoap.org/ws/2005/02/sc/dk" URI="#uuid-5d226149-f6d5-4f95-bf27-63a2be952b57-7"></o:Reference>
                                        </o:SecurityTokenReference>
                                    </KeyInfo>
                                </Signature>
                            </o:Security>
                        </s:Header>
                        <s:Body u:Id="_0" xmlns:u="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-utility-1.0.xsd">
                            <AddIntResponse xmlns="http://tempuri.org/">
                                <AddIntResult>3</AddIntResult>
                            </AddIntResponse>
                        </s:Body>
                    </s:Envelope>
                </MessageLogTraceRecord>
            </DataItem>
        </TraceData>
    </ApplicationData>
</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

WCF Service Trace Viewer Part 1

I hit upon this tool SvcTraceViewer.exe and found it quite interesting. Usually located at :\Program Files\Microsoft SDKs\Windows\v7.0A\bin\NETFX 4.0 Tools (for version .net 4.0), this tool helps you to locate an error that’s happening behind the scenes. It also gives you a better understanding of how things flow with a service.

I have this service that exposes two operation contracts – AddInt and AddDouble. On the client-side (a console app), all I do is to call these two operations. That’s it – a very simplistic application. The only variation I’m going to do is to make the first call through Basic Http Binding and the second one using WSHttp Binding. Let’s see the differences.

I have the following settings in my app.config file.


<system.diagnostics>
    <sources>
        <source name="System.ServiceModel" 
                switchValue="All">
            <listeners>
                <add name="xmlTraceListener" />
            </listeners>
        </source>
        <source name="System.ServiceModel.MessageLogging" 
                switchValue="All">
            <listeners>
                <add name="xmlTraceListener" />
            </listeners>
        </source>
    </sources>
    <sharedListeners>
        <add name="xmlTraceListener" 
             type="System.Diagnostics.XmlWriterTraceListener" 
             initializeData="ClientLogBasic.svclog" />
    </sharedListeners>
    <trace autoflush="true" />
</system.diagnostics>
  

<diagnostics>
    <messageLogging maxMessagesToLog="10000"
    logEntireMessage="true"
    logMessagesAtServiceLevel="true"
    logMalformedMessages="true"
    logMessagesAtTransportLevel="true">
        <filters>
            <clear/>
        </filters>
    </messageLogging>
</diagnostics>

A couple of things to note here. I’m using the XmlWriterTraceListener to log all the messages. All these messages will be written to ClientLogBasic.svclog file, set through the initializeData attribute. A switch value of ‘All’ means I’ll be logging a LOT of information. You can have a comma-separated list of the following trace levels – Critical, Error, Warning, Information, Verbose, ActivityTracing. You can also set the trace level to Off to turn off all tracing. See details on configuration settings here. You can have these settings on either the client- or the server-side config file.

I’ll begin by making a call to the WCF service using the basic Http binding.

private static void CallWcfService()
{
    LearnWcfServiceClient learnWcfServiceClient = new LearnWcfServiceClient(BasicEndPointName);
    //LearnWcfServiceClient learnWcfServiceClient = new LearnWcfServiceClient(WsHttpEndPointName);
    int sumInt = learnWcfServiceClient.AddInt(1, 2);
    double sumDouble = learnWcfServiceClient.AddDouble(1.1, 3.3);
    Console.WriteLine("{0} - {1}", sumInt, sumDouble);
    learnWcfServiceClient.Close();
}

As expected the ClientLogBasic.svclog file gets created:

I open the file only to be a little overwhelmed! I have uploaded the .svclog files here so you can see what I’m talking here as you read through.

So you see Activity tab on the left, a list of traces on the right top and the actual XML for these traces just below. An activity is nothing but a grouping of related traces. You can also view the message in a formatted way, but I prefer XML. I click on the second activity Construct ChannelFactory on the activity tab and GetChannelEndpointElement trace.

We see in the xml that it’s reading some of the elements of the config file - BasicHttpBinding_ILearnWcfService as the endpoint, ServiceProxy.ILearnWcfService as the contract, basicHttpBinding as the binding and the url of the endpoint along with a bunch of other information.

There another cool thing about this tool – it displays the flow graphically as well. Just double click on any activity and it’ll switch to the Graph tab and show a hierarchy of the trace flow.

Clicking on one of the messages, shows the details of the call to the AddInt operation. Let’s get to the Message tab.

There are a total of 8 messages here. Expand the left column in the log files and you’ll see that the first 4 belong to AddInt and the rest belong to AddDouble. You can see the full xml of the first message.

<E2ETraceEvent xmlns="http://schemas.microsoft.com/2004/06/E2ETraceEvent">
    <System xmlns="http://schemas.microsoft.com/2004/06/windows/eventlog/system">
        <EventID>0</EventID>
        <Type>3</Type>
        <SubType Name="Information">0</SubType>
        <Level>8</Level>
        <TimeCreated SystemTime="2011-04-12T05:05:35.8170630Z" />
        <Source Name="System.ServiceModel.MessageLogging" />
        <Correlation ActivityID="{9fab5e4d-4608-490e-bbf0-4b1ba0393227}" />
        <Execution ProcessName="ClientApplication" ProcessID="4144" ThreadID="1" />
        <Channel />
        <Computer>MyComputer</Computer>
    </System>
    <ApplicationData>
        <TraceData>
            <DataItem>
                <MessageLogTraceRecord Time="2011-04-12T10:35:35.8110624+05:30" Source="ServiceLevelSendRequest" Type="System.ServiceModel.Channels.BodyWriterMessage" xmlns="http://schemas.microsoft.com/2004/06/ServiceModel/Management/MessageTrace">
                    <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
                        <s:Header>
                            <Action s:mustUnderstand="1" xmlns="http://schemas.microsoft.com/ws/2005/05/addressing/none">http://tempuri.org/ILearnWcfService/AddInt</Action>
                        </s:Header>
                        <s:Body>
                            <AddInt xmlns="http://tempuri.org/">
                                <arg1>1</arg1>
                                <arg2>2</arg2>
                            </AddInt>
                        </s:Body>
                    </s:Envelope>
                </MessageLogTraceRecord>
            </DataItem>
        </TraceData>
    </ApplicationData>
</E2ETraceEvent>

See that the Source attribute of the MessageLogTraceRecord element says ServiceLevelSendRequest (above). The Action element points to the operation contract and the AddInt element shows the two arguments that were passed to the method.

Coming to the second trace (left image), we see traces like ‘Sent a message over a channel’, ‘Received a message over a channel’ and ‘Received reply over the request channel’, giving us a visual of everything that’s going on to call the service and receive response from it. The Source attribute for this one says TransportSend.

The third trace shows the Source as TransportReceive and the fourth one show it as ServiceLevelReceiveReply. You see the full xml of the fourth trace below with the sum value of 3 as a return from the AddInt operation method.


<E2ETraceEvent xmlns="http://schemas.microsoft.com/2004/06/E2ETraceEvent">
        <System xmlns="http://schemas.microsoft.com/2004/06/windows/eventlog/system">
            <EventID>0</EventID>
            <Type>3</Type>
            <SubType Name="Information">0</SubType>
            <Level>8</Level>
            <TimeCreated SystemTime="2011-04-12T05:05:36.6061419Z" />
            <Source Name="System.ServiceModel.MessageLogging" />
            <Correlation ActivityID="{9fab5e4d-4608-490e-bbf0-4b1ba0393227}" />
            <Execution ProcessName="ClientApplication" ProcessID="4144" ThreadID="1" />
            <Channel />
            <Computer>MyComputer</Computer>
        </System>
        <ApplicationData>
            <TraceData>
                <DataItem>
                    <MessageLogTraceRecord Time="2011-04-12T10:35:36.6061419+05:30" Source="ServiceLevelReceiveReply" Type="System.ServiceModel.Channels.BufferedMessage" xmlns="http://schemas.microsoft.com/2004/06/ServiceModel/Management/MessageTrace">
                        <HttpResponse>
                            <StatusCode>OK</StatusCode>
                            <StatusDescription>OK</StatusDescription>
                            <WebHeaders>
                                <Connection>Close</Connection>
                                <Content-Length>185</Content-Length>
                                <Cache-Control>private</Cache-Control>
                                <Content-Type>text/xml; charset=utf-8</Content-Type>
                                <Date>Tue, 12 Apr 2011 05:05:36 GMT</Date>
                                <Server>ASP.NET Development Server/10.0.0.0</Server>
                                <X-AspNet-Version>4.0.30319</X-AspNet-Version>
                            </WebHeaders>
                        </HttpResponse>
                        <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
                            <s:Header></s:Header>
                            <s:Body>
                                <AddIntResponse xmlns="http://tempuri.org/">
                                    <AddIntResult>3</AddIntResult>
                                </AddIntResponse>
                            </s:Body>
                        </s:Envelope>
                    </MessageLogTraceRecord>
                </DataItem>
            </TraceData>
        </ApplicationData>
    </E2ETraceEvent>

The same process repeats itself for the AddDouble method.

There’s more in the next part.

Saturday, March 22, 2014

SSIS 2012 Parameters Model

SSIS Configuration objective is to make sure that the package can work on different environments and in SSIS 2012 this is achieved using new featured called parameters. Is this method new? Rather not, in previous version of SSIS (2005 to 2008 R2) we had variables in a package and 'package configuration' that allowed us to change variables from "outside".

The new method is nothing than break down of variables into:

Parameters which are:
- Project Parameters
- Package Parameters
Variables (that stays the same but without functionality that was replaced by Parameters)

To give you a better picture of the new model look the picture below.

The major difference between SSIS 2005 up to 2008 R2 is that the model changes from 'package configuration' to 'project configuration' and that means that we now create a project and add packages and parameters to it. Package on it's own can no longer be used (unless you use 'legacy' option). Package MUST be part of a project which undoubtedly will spark a few discussion (pros and cons) but I presume best practice will soon appear.

Coming back to the subject what we now have are Parameters and make note there are two types of parameters which are:

Project Parameters - They live outside of the package on project level and you parameterize your packages using project parameters (which you can also think like Global variables or Global Parameters). Project Parameters will most likely be used for things that change between environment but don't change on the same environment (during execution) which means that majority of it will be connection strings.

Below is a screenshot of SSIS 2012 in SSDT that shows Project Parameters

Package Parameters - We can also define Package Parameters and those live inside the package. Package Parameters work in a similar way as variable and the main difference is that when we execute a package for instance from another package we pass values to package parameters not directly to variables which in SSIS 2012 basically simplifies it in my opinion (as we don't have variables that do everything like in SSIS 2005 to 2008 R2)

Below is a screenshot of SSIS 2012 in SSDT that shows Package Parameters

Note to myself.... write article about Package Parameters (In depth) and provide link here

Variables - They work inside the package and often change during execution of the package (loops etc) but they no longer have responsibility of managing more static values which now are managed by package parameters and project parameters.

Important: There is one very important aspect I didn't mention and that is how to change parameter value depending on environment which is the key element of SSIS Configuration. The reason why I didn't mention it is that you cannot do that during development, which is a good thing I believe and you can do that during deployment (or take development values which I don't recommend) or after deployment and I will dedicate separate articles on this subject. What you can do during development is specify parameter design values and you can have collection of values for different purpose which will make development life easier. These values can be deploy as 'final' but I do not recommend it as it miss the point of having parameters.... I will write more about it soon but I thought I will give you a quick answer here.

So that is high level view about parameters in SSIS 2012. It is not intended to give you in-depth knowledge or knowledge to build projects using new model but hopefully it will give you better understanding of the new model and we will write new articles soon that will go into more details.

Home

Sunday, March 23, 2014

WCF Service Trace Viewer Part 2

WCF Service Trace Viewer Part 2

WCF Service Trace Viewer Part 1

WCF Service Trace Viewer Part 1

Saturday, March 22, 2014

SSIS 2012 Parameters Model

About Me

Contact Form