IntelliTrace Events
IntelliTrace Events
(edited 1/27/2010 to update branding from Diagnostic Event to IntelliTrace Event)
If this post is the first time that you have heard about the IntelliTrace feature in Visual Studio Team System 2010, then you might want to first take a look at my little overview of this nifty new feature before diving into the info below (John Robbins also has an excellent blog post here). But if you don’t want the read that article the gist of it is that IntelliTrace records your debugging context at specific points during your program’s execution. Then, while debugging (or after finishing debugging if you load up one of the log files that we collect) you can move back to the locations where we collected data to examine things like locals, parameters and return values. You can set IntelliTrace to collect data at every function enter and exit but, to avoid the slowdown that this causes by default we just collected data at specifically defined IntelliTrace events. This article is here to give you some more information on IntelliTrace events and on how they are used.
What is an IntelliTrace event?
Simply put, a IntelliTrace event is a specific point during a debugging session that is likely to be of interest to the programmer when debugging. Examples of IntelliTrace events that we define are things like opening a file, writing to the registry or clicking on a WPF button. IntelliTrace events were selected with the duel criteria of being placed at interesting locations, but not being at any locations that would be called too often and create excessive slowdown in your application.
How will I see what IntelliTrace events are being collected?
Since collecting data on just IntelliTrace events is low overhead it will be on by default with all managed projects in Visual Studio 2010 Ultimate. So if you just start up a basic C# console application, set a break point and hit run you will see the new Debug History tool window pop up docked with the Solution Explorer. By default this window will show you a list of all the IntelliTrace events that have been collected during your current debugging session. Below I’ve posted a picture of the Debug History window for a little WinForms application that I created to exercise a few different IntelliTrace events (file open, button click and registry write). From this picture I’ll provide a brief walkthrough of the IntelliTrace Events control (Note: I’m working with the current Beta 2 in progress bits, so please understand both that it will look a little different from Beta 1 and that the final RTM product might also look somewhat different). At the point this picture was taken the program was stopped in the live debugger with a breakpoint at the end of the main function.
The main space in this control is occupied by a flat, chronological list of the most recent IntelliTrace events hit during your debugging session. If you look at the bottom of the list you will see the “Live Event” event, this entry corresponds to the current location of the live debugger and tells us that we are at a breakpoint at line 26 in the file form1.cs. Moving up from there you can see that we recorded a few registry access events, a few file events and a user input gesture. Each entry in this list represents a specific location where we grabbed much of the current debugger state and stuffed it into our log file. Using this flat list you can jump back in time to any of the IntelliTrace events that were captured. Note that there are page forward and page back buttons at the bottom of the control for if we get to large a number of events collected to browse easily.
If you are looking for a specific event or event type in the list we’ve provided a few browsing aides in this tool window. First off, if you start typing in the search box the events in the list will be filtered down to just those events containing your search text, very helpful when trying to track down a specific exception that was thrown. And secondly, if you use the “All Categories” and “All Threads” dropdowns you can restrict the list into showing just events from specific categories (see the below tools->options section to learn more about our categories) or just showing events from specific threads.
What happens to the debugger when I select an IntelliTrace event?
In the picture below I’ve selected the “File: Close” event. Also I’m showing the rest of the IDE along with the tool window so you can see how the debugging context changed with the switch over to historical mode.
Notice that in the IntelliTrace events tool window we’ve selected the event that you are currently at, as well giving some inline expanded information about the event. For this file close event we give a little more information about the event “Close a FileStream accessing the path C:\2xj3hs4l.aox,” we mention the thread the event took place on and we give some quick links to other debugger tool windows that might have some more information about the event.
Aside from the tool window being updated there were some other changes in the IDE when we selected an event in the flat list and moved back to historical mode. First off, if you look at the source editor you won’t see the usual yellow arrow indicating the next statement anywhere in the source file. Instead you will see a curved orange arrow located at the end of the “using(FileStream fs =…)” block of code. The curved orange arrow indicates that the current historical debugger context is somewhere in external code below the given statement, roughly corresponding to the green arrow that the live debugger uses when you are stopped in external code. In general when you move between IntelliTrace events your debugger context will not be located directly in user code, as the IntelliTrace events are all defined at specific points in Microsoft framework code.
This can be better illustrated by looking at the callstack window in the picture above. When we moved back to the IntelliTrace event the callstack updated to the time when we captured that event. The actual code context is down in mscorlib.dll at FileStream.Dispose, but since we don’t have code for that location we show the location in user code that triggered that specific event (that being when the end of the using statement disposed of the FileStream). When moving back in history we will also populate the values in the autos and the watch windows with some specific limitations. Those limitations being that we will just capture primitive values (strings, doubles, ints ect…) and two levels of primitive values off of any objects.
How can I change what IntelliTrace events are captured?
We’ve tried to pick a solid set of IntelliTrace events that provide coverage of some common problem areas and that are not called too often in a program (in which case collection could slow down your application too much). But in specific cases our default settings might not be the right solution for every user, so we’ve added the ability to trim or add to this initial set of events via a tools options page.
If you open up Tool->Options you will see a new option for IntelliTrace in the list. Clicking this item will first off take you to the general settings page shown below.
On this page you will notice that by default (for managed projects) IntelliTrace is turned on and is set to collect debugging data just at IntelliTrace events. In a later blog post I’ll cover more about the “Event, Methods and Parameters” setting but in a nutshell turning on that setting makes you collect data at IntelliTrace events and at all function enters and exits. This gives you much more complete data to look at, but comes at a much higher cost in terms of application performance while debugging.
For now, just we’ll just leave the general settings as they are and move on to the “IntelliTrace Events” tab shown below.
On this page you can see the selection of IntelliTrace events that we provide broken down by various framework categories. By checking or unchecking events you will either add them to or remove them from the set of events that we capture while debugging. A example could be if your application is doing tons of file opens and file closes you could turn off the collection of file events to keep collection from slowing down too much.
IntelliTrace Events Summary
With the above post I’ve tried to lay out a little bit of how IntelliTrace events work, how you can use them to browse back into debugging history and how to configure what events are collected. By collecting data at common fault areas / points of debugging interest we’ve think that they will be useful in solving many debugging issues and the low overhead allows us to turn them on by default for all users. However, there is much more to the IntelliTrace than just events collection. For example, one of the more interesting features is that the debugging log can be saved off and opened in the debugger later on a different machine. You can see how IntelliTrace events would be highly useful in this scenario, as a tester could collected a low overhead log, attach it to the bug and then the developer could debug back in time to specific events on their own machine at a later date. In my next blog posting I’ll be digging deeper into this log scenario and examining how it can help to solve the “no repro” issues that plague developer / tester communication.
Comments
Anonymous
June 18, 2009
PingBack from http://blog.a-foton.ru/index.php/2009/06/18/diagnostic-events-in-historical-debugging/Anonymous
June 18, 2009
Thank you for submitting this cool story - Trackback from DotNetShoutoutAnonymous
June 18, 2009
I'm interested to hear if there are any ideas for diagnostic events that we may have missed or not considered yet? What events would be helpful to you? Here are the categories of events we currently have defined: ADO.NET (DB calls) ASP.NET Console (console output Data Binding File Gestures (user actions) Registry Threading Tracing (debug trace output) WCF XML