Rolling your own very simple profiler is not that hard. Insert into main():
int main()
{
profileCpuUsage(1); // start timer #1
well_written_function();
profileCpuUsage(2); // stop timer #1, and start timer #2
badly_written_function();
profileCpuUsage(-1); // print stats for timers #1 and #2
return 0;
}
where:
#define NUMBER(a) ((int)(sizeof(a) / sizeof(a)[0]))
void profileCpuUsage(int slice)
{
static struct {
int iterations;
double elapsedTime;
} slices[30]; // 0 is a don't care slice
if (slice < 0) { // -1 = print
if (slices[0].iterations)
for (slice = 1; slice < NUMBER(slices); slice++)
printf("Slice %2d Iterations %7d Seconds %7.3f\n", slice,
slices[slice].iterations, slices[slice].elapsedTime);
}
else {
static int i; // = previous slice
static double t; // = previous t1
const double t1 = realElapsedTime(); // see below for definition
assert (slice < NUMBER(slices));
slices[i].iterations += 1;
slices[i].elapsedTime += t1 - t; // i = 0 first time through
i = slice;
t = t1;
}
}
Now admittedly in your simple example using this profileCpuUsage() doesn't add much benefit. And it has disadvantage of requiring you to manually instrument your code by calling profileCpuUsage() at suitable locations.
But advantages include:
- You can time any code fragment, not just procedures.
- It is quick to add and delete, as you do a binary search to find and/or remove code hotspots.
- It focuses only on the code you are interested in.
- Portable!
- KISS
One tricky non-portable thing is to define the function realElapsedTime() so that it provides enough granularity to get valid times. This generally works for me (using the Windows API under CYGWIN):
#include <windows.h>
double realElapsedTime(void) // <-- granularity about 50 microsec on test machines
{
static LARGE_INTEGER freq, start;
LARGE_INTEGER count;
if (!QueryPerformanceCounter(&count))
assert(0 && "QueryPerformanceCounter");
if (!freq.QuadPart) { // one time initialization
if (!QueryPerformanceFrequency(&freq))
assert(0 && "QueryPerformanceFrequency");
start = count;
}
return (double)(count.QuadPart - start.QuadPart) / freq.QuadPart;
}
For straight Unix there is the common:
double realElapsedTime(void) // returns 0 first time called
{
static struct timeval t0;
struct timeval tv;
gettimeofday(&tv, 0);
if (!t0.tv_sec)
t0 = tv;
return tv.tv_sec - t0.tv_sec + (tv.tv_usec - t0.tv_usec) / 1000000.;
}
realElapsedTime() gives wall-clock time, not process time, which is usually what I want.
There are also other less-portable methods to achieve finer granularity using RDTSC; see for example http://en.wikipedia.org/wiki/Time_Stamp_Counter, and its links, but I haven't tried these.
Edit: ravenspoint's very nice answer seems to be not too dissimilar from mine. And his answer uses nice descriptive strings, rather than just ugly numbers, which I was often frustrated with. But this can be fixed with only about a dozen extra lines (but this almost doubles the line count!).
Note that we want to avoid any usage of malloc(), and I'm even a bit dubious about strcmp(). So the number of slices is never increased. And hash collisions are simply flagged it rather being resolved: the human profiler can fix this by manually bumping up the number of slices from 30, or by changing the description. Untested
static unsigned gethash(const char *str) // "djb2", for example
{
unsigned c, hash = 5381;
while ((c = *str++))
hash = ((hash << 5) + hash) + c; // hash * 33 + c
return hash;
}
void profileCpuUsage(const char *description)
{
static struct {
int iterations;
double elapsedTime;
char description[20]; // added!
} slices[30];
if (!description) {
// print stats, but using description, mostly unchanged...
}
else {
const int slice = gethash(description) % NUMBER(slices);
if (!slices[slice].description[0]) { // if new slice
assert(strlen(description) < sizeof slices[slice].description);
strcpy(slices[slice].description, description);
}
else if (!!strcmp(slices[slice].description, description)) {
strcpy(slices[slice].description, "!!hash conflict!!");
}
// remainder unchanged...
}
}
And another point is that typically you'll want to disable this profiling for release versions; this also applies to ravenspoint's answer. This can be done by the trick of using an evil macro to define it away:
#define profileCpuUsage(foo) // = nothing
If this is done, you will of course need to add parentheses to the definition to disable the disabling macro:
void (profileCpuUsage)(const char *description)...
