[boost] Re: Profiling Library suggestion

From: Preston A. Elder (prez_at_[hidden])
Date: 2005-02-05 03:24:51

On Fri, 04 Feb 2005 10:07:59 -0500, christopher diggins wrote:

>   template<typename Policy_T = ProfilerDefaultPolicy>
>   class Profiler {
<majority of email snipped>

Problem is, usually a profiler is used to tell you both how many calls are
made to a function, how long they took cumulatively, and an average.

Personally, I have some simple timers myself that I use for the cause,
like so:

void MyFunc()
{
    static unsigned long p_op1 = 0, p_op2 = 0, p_op3 = 0;
    static struct timeval timer = StartTimer();
    struct timeval instance_timer = StartTimer();

    op1();
    p_op1 += NextTimer(instance_timer);

    op2();
    p_op2 += NextTimer(instance_timer);

    op3();
    p_op3 += NextTimer(instance_timer);

    // Result after 30s ...
    if (instance_timer.tv_sec - timer.tv_sec > 30)
    {
        unsigned long cycletime = NextTimer(timer);
        printf("Cycle %.03fms: op1 %.03fms (%.02f%%), "
               "op2 %.03fms (%.02f%%), op3 %.03fms (%.02f%%).",
            (double) cycletime / 1000.0,
            (double) p_op1 / 1000.0,
            (double) p_op1 / (double) cycletime * 100.0,
            (double) p_op2 / 1000.0,
            (double) p_op2 / (double) cycletime * 100.0,
            (double) p_op3 / 1000.0,
            (double) p_op3 / (double) cycletime * 100.0);
        p_op1 = p_op2 = p_op3 = 0;
    }
};

Obviously, NextTimer returns the amount of microseconds since the last
timer (which is why I divide by 1000.0 to get milliseconds), and sets the
timer value passed to the current time.

I'll be the first to admit this is ugly, but it DOES give a nice way of
accumulating times, as well as separating stuff out by operations within a
function, as opposed to just by function.

Now, I'm sure there must be a better way to codify the above, possibly
even have a ProfileCollection or something, so you have:

void MyFunc()
{
    static ProfileCollection pc;

    ProfileOp(pc, op1());
    ProfileOp(pc, op2());
    ProfileOp(pc, op3());

    EndProfile(pc);
}

And the profile collection could then have policy traits, or whatever to
determine what to do on end, and when a valid end is (for example, if it
will only print a message every 30s, then EndProfile will do nothing until
30s has elapsed, or whatever).

Alternatively, you could have begin/end sections to profile multiple
operations:

void MyFunc()
{
    static ProfileCollection pc;

    StartProfileOp(pc, op1);
    op1();
    EndProfileOp(pc, op1);

    StartProfileOp(pc, op2);
    op1();
    EndProfileOp(pc, op2);

    StartProfileOp(pc, op3);
    op1();
    EndProfileOp(pc, op3);

    EndProfile(pc);
}

This would allow multiple operations to be profiled as one group (the
second parameter of StartProfileOp and EndProfileOp being just an
identifier, meaning they'd have to be macros).

Or alternatively, of course, going back to something similar to my
original design:

void MyFunc()
{
    static ProfileCollection pc;
    ProfileOperations pop(pc);

    op1();
    NextProfileOp(pop, op1);
    
    op2();
    NextProfileOp(pop, op2);

    op3();
    NextProfileOp(pop, op3);
}

In this case, the 'EndProfile' would be basically called automatically by
the destruction of ProfileOperations, and this would have a similar
operation to my original example (except the conditions for 'ending a
cycle', and what is done is still defined by ProfileCollection).

Basically, cumulative timers like my original example have often been the
best tool I've tried in efficiency programming - or at least, focussing my
efforts on tuning a specific area of code.

Also, btw, one of the biggest things would be the ability to DISABLE it
all, whether by policy or whatever.  The last thing I want is to have all
this timer code active when I'm compiling a production release and not
trying to tune the code.

Anyway, if you're looking at a library for this purpose, thats my $.02c :)

-- 
PreZ :)
Founder. The Neuromancy Society (http://www.neuromancy.net)