Seinactive Software - Maker of Debug Assistant -- Walkthrough

1) Setup Trace Scope

Make sure debug assistant window is visible.

Build all projects in the solution. There is only one project in this case. Before build, check your project settings: C/C++->General->Debug information format, make sure "Disabled" is not selected. It is a good idea to switch your project to Debug build.

Click Setup Trace Scope to bring up Setup Trace Scope dialog. In Select modules for trace, check file SimpleTest.cpp, SimpleTestDlg.cpp.

Select SimpleTest (module) node (corresponding to project SimpleTest), module file location became editable. Leave the default: $(ProjectOutputFile), because that's where the module file (SimpleTest.exe) is located. This cell can not be blank. In "Trace all functions except" section, leave it blank, since at the moment, we have no idea which function will be hit. We trace all functions.

However, at the bottom of this section, there is Default Exceptions button, click this button shows all functions that will be excluded in trace. Those functions generally are not user's interest but can generate too many execution points. You may uncheck some functions in this list for them to be traced. This is usually undesirable.

At the bottom of this dialog, Startup program is the full path of the startup program and its command line arguments if there is any. Startup program has to be a valid executable. It can not be blank. You may click Browse button to find the executable. For our case it is "C:\VSIP\Test Projects\SimpleTest\debug\SimpleTest.exe".

Click OK button. That's all about setting up trace scope.

2) Start Process

Now it is time to startup the program for trace. Before that, click Turn On Trace button to switch trace on. Reason we turn trace on before start the program is we want to record the startup up stage as well.

Click Start Process to start program, then select Trace function only, because we don't know at the moment how large the trace result will be, it can be really big if trace every line. (for our SimpleTest project, it won't be large, but we want to demonstrate the normal tracing process.)

During the program startup process, you will see progress bar showing code loading process, then Visual Studio status bar will show instrumentation process, program is start and hooked up. For this test case, these all goes very fast. Depending on the size of your code and the scope you have selected. The process startup may take a few seconds. In extreme cases, it can take minutes.

You can click Show Trace Message to check if there is anything wrong during the trace.

3) Run Program and Record Result

Run Program. Remember the program is under trace. All activities happening in our selected code will be recorded. Now in SimpleTest program, click button Change Text. We shouldn't feel any noticeable slow down during the run of SimpleTest. Now, go to Debug Assistant window, click Turn Off Trace to stop recording. You may turn on trace later for further trace, but be aware there is gap in timing during the time the trace is off. So, the trace is stopped.

4) Analyze Result

Click Show Trace result to show result. The graphic part shows two function nodes in the root node (dash-lined rectangle). That says two functions are called on the highest level of the call hierarchy within our trace scope. Move mouse cursor over the two function nodes to see what they are. The message line on the top shows:

call -> CSimpleTestApp::CSimpleTestApp, meaning this is the lines that calls function CSimpleTestApp::CSimpleTestAp();

call -> CSimpleTestApp::InitInstance, meaning this is where CSimpleTestApp::InitInstance() is called.

CSimpleTestApp::InitInstance is of our interest. You may notice in this test project, all of the program execution except for the constructor of class CSimpleTestApp are contained in this function. Execution finished when this function returns. This is true at least from a programmer's point of view. So, most of the function calls are hidden in side of this function. Click this function node, it is then extended to the next line.

There are about 40 function nodes inside of CSimpleTestApp::InitInstance() as showed in the picture. Right click on CSimpleTestApp::InitInstance(), then click Functions calls. It shows there are actually 4 different functions called by CSimpleTestApp::InitInstance(), they are:
CSimpleTestDlg::CSimpleTestDlg(),
CSimpleTestDlg::OnInitDialog(),
CSimpleTestDlg::OnBnClickedChangeword(),
CSimpleTestDlg::OnCtlColor().
The first three each is called once, last function is called more than 30 times. In our case, we have no interest in last function. In real cases, things can go extreme, there can be hundreds of calls of some functions which we have no interest of, but it make a few interesting ones hard to find. Here is what we do to the make it easy:

5) Refine Trace Scope

First click Terminate Process button to stop current process. Current trace result will be replaced when we start the process again. Click Setup Trace Scope to bring up Setup Trace Scope dialog. Uncheck SimpleTest.cpp to exclude this file, because there is nothing we want to check in this file. Then select file SimpleTestDlg.cpp, at the right, in Trace all functions except, uncheck Inherit from parent, then add following text to the textbox:

CSimpleTestDlg::CSimpleTestDlg, CSimpleTestDlg::OnCtlColor

6) Trace Again

Now start process, choose trace every line, because we are quite sure there is not going to be a lot of trace point hit in our trace. Then turn on trace. Note here we turn on trace after program started, because it seems from last trace result there was not much we want to see in the program start up phase. From SimpleTest program, click Change Text button. Then go to Debug Assistant window, turn off trace. Click Show Trace Result to bring up result view.

7) Examine Result

This time, we see one node only on the root:

CSimpleTestDlg::OnBnClickedChangeword

This is the one we want to see. Expend this node, among other nodes, there is a function node: CSimpleTestDlg::SwapLetters, from its color (red) you know this node takes more than 50% of time in function CSimpleTestDlg::OnBnClickedChangeword. Put cursor on it you will see it actually take 86.9% of its parent's time. Again, expend this function, and click on the expended function. You can see that there is slider showing at left side of the line. Put cursor on the slider, you will see there is a arrow button on it. Drag and move the head of the slider, current line moves accordingly in the IDE code window, if the file is not open, it will open the code window first. Click the arrow button to play the result automatically. You can also check a special way to show loops. It is very compact no matter how long the loop is, but it still let you check execution of each loop. Please note, the way a loop is wrapped up is: only first N-1 loops are wrapped up in one node, the last loop is not.

Now we have got what we want to see. You can explore the execution flow freely. Debug Assistant provides you the best way to see it.

There are save/open buttons that let you save results and view them later.

Windows Phone 7 Blog