Service Trace Viewer

by Matt 27. July 2007 04:58

Audience participation time! Download this file, it contains a copy of the Service Trace Viewer program and some demo files (as far as I can see the viewer is only available as part of the Windows SDK, which makes it a little hard to get a hold of).

The demo files are a set of verbose logs from a simple WCF client calling an equally simple WCF service to add 2 numbers and return the result.

Two important links for this one - again, MSDN has the docs in two different places. Here's the doc for the .exe, which provides a metric truckload of information on how to use the viewer. Then this page is a bit more of a tutorial style page, with lots of pictures. I'd strongly suggest reading them both.

Not that you will, so let's crack on. Fire up the viewer and load the service.stvproj file to load all the service .svclog files. You'll see something like this:

image

The left hand pane is a flattened list of all the activities in all the trace files. Select an item here, and on the top right, you see all the events in that activity, including transfers to and from other activities. Bottom right is the details of a given event, including details such as timestamp, callstack, process details and even the actual WCF message.

If you double click an activity on the left pane ("Listen at http://localhost:8000/CalculateService" is a good candidate for exploring), you'll get taken to the graph view.

image

Here it is, all things collapsed. It starts on the left with the root activity, and then transfers through all activities (without showing details) until it reaches the Listen activity. The two yellow boxes are events, one of which is the activity boundary, the other is that the client is now actually starting to listen for messages. Select any of these events, and the associated event is highlighted in the two window panes on the right, showing more details.

You can see that this "listen" activity transfers back to the calling (and eventually root) activity, but still continues. When a message does arrive, it is logged in the "listen" activity. We can switch the display mode to Thread (top of the graph view) to see this a bit more explicitly.

image

Each of the collapsed boxes in the new thread are activities that represent messages arriving. Expanding this first gives us a "receive bytes" activity, with another nested activity - "Processing message 1". One of the events in this nested activity is a "received message" event. Select this and on the bottom right we see a new tab called "Message" which displays the actual SOAP message received (minus any private information - WCF automatically strips known personal information). And we see that this is a request for a security token (WCF is secure out of the box - I would have to create more config to disable security).

Expanding the next activity event gives a whole heap of events and we now start to wish we hadn't enabled verbose logging.

image

Now what we have here is 4 activities - listen, receive bytes, process message, and the huge process action "http://schemas.xmlsoap.org/ws/2005/02/trust/RST/Issue", which is the SOAP action for issuing a security token via WS-Trust. We can see that processing the Issue action is continuing while several other activities are occurring (the listen activity in the first column has several other activities that are timestamped during the lifetime of the Issue activity). That's because there are several messages exchanged to bootstrap the secure conversation. If you're feeling brave, open up all the activities (leave the fourth one for the minute) and look at the messages. You'll soon find you're looking at encrypted data.

This is a complex example to show as a demo, but it's worth seeing what a real-world trace would look like, how much data is in the verbose traces and especially important to see that activities are not stacks and can happen in parallel.

Incidentally, if there's too much of the verbose logging, you can filter it out, either with the options at the top of the graph view, or by changing the level in the search filter at the top of the main window - this gets rid of a lot of noise.

It's probably worth collapsing all the Listen sub-activities and just look at the fourth one. This is finally the call to the Add service method. Expand its sub-activities, and you'll end up with 5 activities in all - listen, process message 4, receive bytes, process action "http://tempuri.org/ICalculator/Add" and execute service "WcfService.ICalculator.Add". This very last activity is the actual code for the service method. And in it, you should see a simple trace output I added with the following code:

TraceSource ts = new TraceSource("WcfService.TraceSource", SourceLevels.Information);
ts.TraceInformation("Adding {0} and {1} = {2}", a, b, a + b);

(No reference to activities here - the trace automatically picks up the current activity.)

So that's activities and correlation. Let's have a quick look at propagation. Close that project and open all.stvproj. This contains both the service and the client logs, again at full logging levels.

In the Activity list on the left, find the activity called Process action 'http://tempuri.org/ICalculator/Add'. This is the client calling the Add web service operation. Double click the activity, and you'll see a graph of what the client goes through before calling into the server. And it all nicely joins up to the server trace logs, so you now see a full end to end call.

image

And that's a quick run around with Service Trace Viewer. It's certainly powerful, but I don't think it's the most intuitive program - there's a lot of data, and lot of axes to be looking along, which can be a bit overwhelming. The best thing to do is just play around - select things, double click things, filter things and see what happens.

I think its biggest failing is the difficulty of finding that one trace you're looking for. It's awkward not being able to select the root activity - you have to jump in at the right start activity (clearly displaying the root activity as a graph is just asking for trouble - everything starts off in the root activity, so you're going to get a huge graph). I think searching is going to work best here - but again, you need to know what you're searching for. If you're just looking at errors, then the tool helps; any activity that contains an exception gets highlighted.

But hey - nice graphs!

Tags:

Comments (25) -

Leopoldo Wigdor
Leopoldo Wigdor
2/23/2011 5:07:22 AM #

HiI located your website on Google the other day and I am rather grateful that I did!

Reply

St. Louis Wedding Venues
St. Louis Wedding Venues
2/26/2011 9:33:56 PM #

You presented some very nice specifics there. I did a search on the niche and uncovered a lot of people may consent having your blog.

Reply

Motorcycle LED Lighting
Motorcycle LED Lighting
4/2/2011 4:10:42 AM #

Wow, didn't realize you could get this on a blog now, saved me a trip to the campus - Love it posts like this on campus

Reply

San Francisco Roofing
San Francisco Roofing
5/14/2011 9:27:46 AM #

Thank you for this awesome piece.  I liked it a lot! Smile
Whoa, THANKS for what you wrote!
thank you for posting this Smile
This post was interesting.
This post was interesting to see, thank you.
I truly enjoyed your post.
thanks a million for putting the thought in and writing it
Thanks for posting this, I enjoyed the read.
You have an interesting point of view Smile
I like what you have to say
thanks a million for posting this
One of the greatest things about the blogging community is all the stuff people freely share.  Thanks! :
Great post!
thanks a million!
Stumbled on your post listed in Google Smile
Stumbled on your website marked on Delicious
I'll Digg this, thanks!
Love the post.
I liked seeing that
Awesome post, thx for putting it up.
Cool Read
Cool post, I can't wait for the rest
Enjoyed your style
I really like your website
Your blog is nice
Cool, thanks a bunch for putting it out there!
I just came by to say thanks for this
Hey, I just want to drop a note and say nice read!
Thanks for posting this.  It's sometimes a struggle to keep up with my blogging.  Seeing a blog that puts off such a great vibe is quite inspirational.
Thank you very much for your post, I enjoy your blog.  Long time lurker, first time commenter, if you will.  I tried to comment this once before, I do not think it posted correctly...hopefully it will this time! LOL

Reply

LAURENCE  Debora
LAURENCE Debora
5/22/2011 4:56:06 AM #

Recherche thématique sur plusieurs thèmes, c'est sukoga.com, moteur.

Reply

LAURENCE  Debora
LAURENCE Debora
5/27/2011 8:31:58 AM #

Liste d'annuaires détaillées pour faciliter le référencement, Créez votre propre article.

Reply

best suv
best suv
7/20/2011 10:33:56 PM #

Una pagina sarà dedicata agli accessori, una alle giacche e ai giubbotti. Troverai le indicazioni per lo spaccio o negozio Moncler più vicino a casa tua e tutte le offerte più vantaggiose di questo prestigioso marchio.

Reply

iphone os
iphone os
7/23/2011 8:25:04 PM #

I've recently began a weblog, the data you provide on this site has helped me tremendously. Thanks for all your time & work.

Reply

ipad apps
ipad apps
7/24/2011 4:19:24 AM #

Hi,what an excellent article this is,I found it on bing and I like it very much,I agree with what you have said, lots of things will be learned form your site,but I still have some questions with the last part,can you explain it for me ?I will appreciate your answer,and I will be back again!

Reply

LAURENCE  Debora
LAURENCE Debora
7/27/2011 10:47:51 AM #

Bienvenue sur annuaires-gratuit.com.Des fonctionnalités inédites, nombreuses annuaires.

Reply

DEBORA Laurence
DEBORA Laurence
8/1/2011 8:34:48 AM #

Il ne vous reste plus qu' à créer votre propre annuaire, l'inscription est  gratuite .

Reply

real estate in bangalore
real estate in bangalore
8/7/2011 11:56:07 PM #

Plz stop using plastic

Reply

DEBORA Laurence
DEBORA Laurence
8/8/2011 6:45:04 PM #

Répondre à vos questions sur la gestion de votre annuaire mais bien plus encore.

Reply

DEBORA Laurence
DEBORA Laurence
8/12/2011 11:43:53 PM #

Service Top enchère sur sibeys.com, vendez aux enchères vos objets neuf ou occasions.

Reply

Michael Jefferson
Michael Jefferson United States
9/5/2011 7:58:51 AM #

Very entertaining thank you, There's no doubt that your current followers may very well want a great deal more reviews like that continue the good hard work.

Reply

Stettin Polen
Stettin Polen
10/14/2011 11:52:02 AM #

Nice blog, visit my and post some comments.

Reply

Robert
Robert
10/23/2011 12:00:59 PM #

Hello

Nice, post here will came back

Reply

Eric
Eric
10/23/2011 12:02:01 PM #

Hi

nice post here may come back soon
keep update

Reply

Lisa
Lisa
10/23/2011 7:27:00 PM #

Hello

Nice, post here will came back
Keep like this

Reply

Btissam
Btissam
10/23/2011 8:46:45 PM #

Hi

Interresting post here

Reply

Lisa
Lisa
10/23/2011 10:54:00 PM #

Hello

interresting, post here may come back soon

Reply

Lisa
Lisa
10/24/2011 12:25:26 AM #

hi,

Nice, post here may come back soon
keep update

Reply

Robert
Robert
10/24/2011 12:27:17 AM #

hello there,

Interresting post here will came back

Reply

monster dr dre
monster dr dre
10/30/2011 5:11:49 PM #

A person, be good to yourself; Two person, treat each other.

Reply

pacquiao vs marquez  online
pacquiao vs marquez online
11/6/2011 12:45:11 AM #

your blog is very useful and informative....",)

Reply

Add comment

biuquote
  • Comment
  • Preview
Loading

Month List

RecentComments

Comment RSS