CProfile - A Simple Class to Do Code Profiling and Tracing

• Download source files - 4.1 KB

Introduction

I wrote the CProfiler class to continue my learning of the Win32 API and C++ programming. The basic idea was to implement a simple class to do code and function profiling functions, in a very easy manner. I searched through the Platform SDK and found the QueryPerformanceCounter and QueryPerformanceFrequency functions in the Win32 API. I started from here and I've finished with a raw, but functional class. It was fun to program (at least for me, a hobbyist and novice C++ programmer.)

This code was written (and tested only) in Visual C++ 7.0 (2002).

Using the Code

The CProfiler class declaration is the following:

class CProfiler 
{
public:
    
   CProfiler(void);
   ~CProfiler(void);    
   void    ProfileStart(LOGTYPE logtype = LOGNONE);
   __int64 ProfileEnd  (char* TraceStr = "");
   double  SecsFromTicks ( __int64 ticks);
   DWORD   GetLastRetVal(void);
        
private:
    
   LARGE_INTEGER m_QPFrequency;     // ticks/sec resolution
   LARGE_INTEGER m_StartCounter;    // start time
   LARGE_INTEGER m_EndCounter;      // finish time
   __int64       m_ElapsedTime;     // elapsed time
   DWORD         m_Retval;          // return value for API functions
   LOGTYPE       m_LogType;         // logging type

};

Well, let's start, from looking at the class declaration, at how to use it.

First, of course, you need to create an object of type CProfiler. As you see above, the constructor does not take any parameters; it does the following initialization tasks: clears all LARGE_INTEGER unions with ZeroMemory API, and gets the high resolution counter frequency for the local machine through the QueryPerformanceFrequency API. This is stored in the m_QPFrequency data member.

The constructor, the ProfileStart function and the ProfileEnd function use the m_Retval private data member to store the return values from the APIs. You can check if you want, if the API has failed after the object construction, a call to ProfileStart or ProfileEnd using the member function GetLastRetVal.

After a successful object construction, you can begin using the ProfileStart and ProfileEnd functions, which are PLAY/STOP buttons for the timer.

If you look at those functions, they are defined as:

void        ProfileStart(LOGTYPE logtype = LOGNONE); // starts profiling
__int64     ProfileEnd  (char* TraceStr = "");       // end profiling

Observe that I've defined the ProfileStart function to take an argument of type LOGTYPE, which defaults to LOGNONE... What is this? It's an enumeration which I use for indicating what type of debug logging is used. The enum is declared as follows:

enum LOGTYPE { LOGNONE, LOGTICKS, LOGSECS, LOGALL, LOGMSGBOX };

With this enumeration, I'm assured that only those five values can be used as arguments.

Let's explain what the different logging types are for the ProfileStart function: LOGNONE does not log anything to anywhere, LOGTICKS logs the elapsed time in clock ticks; LOGSEGS logs the elapsed time in seconds; LOGALL logs the elapsed time in both formats; and finally LOGMSGBOX also displays the time in both formats, both displaying a dialog (exactly like the dialog in the top of this article...). Note that LOGTICKS, LOGSECS and LOGALL arguments write to the VC++ debugger results window, using the OutputDebugString function.

The general usage mode of the CProfiler class can be expressed in the following code:

#include <iostream>
#include "profiler.h"
using namespace std;

int main(void)
{
    // create object
    CProfiler cprof;
    int i;
    float f;
    __int64 ptime;
    
    // start profiling (no debug output)
    cprof.ProfileStart(LOGNONE);
    for (i = 0, f =    0.0; i  < 10000;  i++, f+ = 0.5)
         cout<<  static_cast<float>((i)*f/2) << endl;

    // end profile here and save the result
    ptime = cprof.ProfileEnd();
    
    cout << "Function time: " << ptime << " ticks ("
         << cprof.SecsFromTicks(ptime) << " seconds)" << endl;
    

    system("pause");
    return 0;
}

In the above code, we are profiling a quite stupid and senseless function, for demonstration purpose only: a function that calculates (i)*f/2 where i goes from 0 to 10000, and f, which is a float, from 0.0 to 500.0. Here we are using no debug logging, as indicates the line expressing ProfileStart(LOGNONE).

Next, we see ptime = ProfileEnd(). This function ends the profiling and returns the elapsed time (clock ticks) in a 64-bit signed integer (__int64). Last, we use this value to express the elapsed time in clock ticks (ptime), and also in seconds, which can be obtained using the SecsFromTicks member function and passing an __int64 value expressing the elapsed ticks. This is SecsFromTicks(ptime), which returns a double.

Tracing

To trace where the code is executing, we can also output a string with the debug logging output, using a char* parameter with the ProfileEnd member function. For example, you could write:

float MyComplexCalc (float x, float y, float z)
{
    ... // complex function code ;)
    return fResult;
}
// profile the MyComplexCalc function
            
int main(void)
{
    CProfile prof;
    ProfileStart (LOGTICKS);
    double fcalc = MyComplexCalc (7.0, 0.6, 8.2);
    ProfileEnd ("Mycomplex calc function finished...");
}

Look at the ProfileEnd function. Now the parameter of the function is a string to trace where you are in the code, what function profiling are you doing, or whatever message you want to output along with the debug output logging specified with the LogType parameter in the ProfileStart member function.

The above code will output to the results window of the VC++ debugger (or to a debugging utility like SysInternals DebugView).

Logging Modes

The following screenshots will show you an example, taken from the above sample code, on what to expect for each logging mode. The screenshots are from the DebugView utility. Expect a similar result in the output window of the Visual C++ debugger.

1. Profiling with the above code, but with LOGALL logging type:

   

2. Now with LOGTICKS...

   

3. Next, with LOGSECS...

   

4. And finally, the fancy (useful?) LOGMSGBOX.

   

Conclusion

This class was fun to write, was very helpful to continue learning my VC++ techniques. Note that I'm not a professional programmer, actually, I'm studying Social Science at the University, but I like very much to develop software.

The purpose, in fact, of this little code is to receive criticism and recommendations on how to improve my coding style, to avoid errors, etc. If someone finds this CProfiler class useful (or as a base for a better class implementation), I would be very glad to hear comments.

History

• 2^nd May, 2003 - V1.0 first release