I am trying to profile my .NET dll while running it from VS unit testing tools but I am having problems. I am using the standalone command-line profiler as VS2008 Professional does not come with an inbuilt profiler.

I have an open CMD window and have run the following commands (I instrumented it earlier which is why vsinstr gave the warning that it did):

C:\...\BusinessRules\obj\Debug>vsperfclrenv /samplegclife /tracegclife /globalsamplegclife /globaltracegclife
Enabling VSPerf Sampling Attach Profiling. Allows to 'attaching' to managed applications.

Current Profiling Environment variables are:
COR_ENABLE_PROFILING=1
COR_PROFILER={0a56a683-003a-41a1-a0ac-0f94c4913c48}
COR_LINE_PROFILING=1
COR_GC_PROFILING=2

C:\...\BusinessRules\obj\Debug>vsinstr BusinessRules.dll
Microsoft (R) VSInstr Post-Link Instrumentation 9.0.30729 x86
Copyright (C) Microsoft Corp. All rights reserved.

Error VSP1018 : VSInstr does not support processing binaries that are already instrumented.

C:\...\BusinessRules\obj\Debug>vsperfcmd /start:trace /output:foo.vsp
Microsoft (R) VSPerf Command Version 9.0.30729 x86
Copyright (C) Microsoft Corp. All rights reserved.

C:\...\BusinessRules\obj\Debug>

I then ran the unit tests that exercised the instrumented code. When the unit tests were complete, I did...

C:\...\BusinessRules\obj\Debug>vsperfcmd /shutdown
Microsoft (R) VSPerf Command Version 9.0.30729 x86
Copyright (C) Microsoft Corp. All rights reserved.


Waiting for process 4836 ( C:\Program Files\Microsoft Visual Studio 9.0\Common7\IDE\vstesthost.exe) to shutdown...

It was clearly waiting for VS2008 to close so I closed it...

Shutting down the Profile Monitor
------------------------------------------------------------

C:\...\BusinessRules\obj\Debug>

All looking good, there was a 3.2mb foo.vsp file in the directory. I next did...

C:\...\BusinessRules\obj\Debug>vsperfreport foo.vsp /summary:all

Microsoft (R) VSPerf Report Generator, Version 9.0.0.0
Copyright (C) Microsoft Corporation. All rights reserved.

VSP2340: Environment variables were not properly set during profiling run and managed symbols may not resolve.  Please use vsperfclrenv before profiling.
File opened
Successfully opened the file.
A report file, foo_Header.csv, has been generated.
A report file, foo_MarksSummary.csv, has been generated.
A report file, foo_ProcessSummary.csv, has been generated.
A report file, foo_ThreadSummary.csv, has been generated.
Analysis completed
A report file, foo_FunctionSummary.csv, has been generated.
A report file, foo_CallerCalleeSummary.csv, has been generated.
A report file, foo_CallTreeSummary.csv, has been generated.
A report file, foo_ModuleSummary.csv, has been generated.

C:\...\BusinessRules\obj\Debug>

Notice the warning about environment variables and using vsperfclrenv? But I had run it! Maybe I used the wrong switches? I don't know. Anyway, loading the csv files into Excel or using the perfconsole tool gives loads of useful info with useless symbol names:

*** Loading commands from: C:\temp\PerfConsole\bin\commands\timebytype.dll
***   Adding command: timebytype
*** Loading commands from: C:\temp\PerfConsole\bin\commands\partition.dll
***   Adding command: partition

Welcome to PerfConsole 1.0 (for bugs please email: [email protected]), for help type: ?, for a quickstart type: ??

> load foo.vsp
*** Couldn't match to either expected sampled or instrumented profile schema, defaulting to sampled
*** Couldn't match to either expected sampled or instrumented profile schema, defaulting to sampled
*** Profile loaded from 'foo.vsp' into @foo

> 
> functions @foo
>>>>> Function Name

Exclusive            Inclusive            Function Name  Module Name
-------------------- -------------------- -------------- ---------------
900,798,600,000.00 % 900,798,600,000.00 % 0x0600003F     20397910
14,968,500,000.00 %  44,691,540,000.00 %  0x06000040     14736385
8,101,253,000.00 %   14,836,330,000.00 %  0x06000041     5491345
3,216,315,000.00 %   6,876,929,000.00 %   0x06000042     3924533
<snip>
71,449,430.00 %      71,449,430.00 %      0x0A000074     42572
52,914,200.00 %      52,914,200.00 %      0x0A000073     0
14,791.00 %          13,006,010.00 %      0x0A00007B     0
199,177.00 %         6,082,932.00 %       0x2B000001     5350072
2,420,116.00 %       2,420,116.00 %       0x0A00008A     0
836.00 %             451,888.00 %         0x0A000045     0
9,616.00 %           399,436.00 %         0x0A000039     0
18,202.00 %          298,223.00 %         0x06000046     1479900

I am so close to being able to find the bottlenecks, if only it will give me the function and module names instead of hex numbers!

What am I doing wrong?

--- Alistair.