----- Original Message ----- From: "Gennadiy Rozental" <gennadiy.rozental@thomson.com> To: <boost@lists.boost.org> Sent: Monday, February 07, 2005 12:11 PM Subject: [boost] Re: Boost Profiler Proposal

...

If anyone has a POSIX high-resolution timer modeled on the Boost.Timer concept to share, it would be greatly appreciated! I would also appreciate new profiling policies, to include as examples.

Check ML archive. There was once an implementation posted.

Thanks.

...

PS: this profiling tool seems to be a natural fit for the Boost.Test macros like BOOST_CHECK_NO_THROW, I currently use something like:

BOOST_PROFILE_AND_CHECK_NO_THROW(TKN) BOOST_CHECK_NO_THROW(BOOST_PROFILE(TKN))

Could you please clarify what exactly it's suposed to do? BOOST_CHECK_NO_THROW makes sure that expression doesn't throw. How do you connect it with profiling?

My unit tests (and many other people's) are functions which throw exceptions on failure. By combining profiling and checking for exceptions, I can both time my test-case and assure its success. However, this is no longer an issue because you will be already including timing in the next version.

Couple notes:

1. Next version of Boost.Test includes test cases timing.

What is the status of this version?

2. I do interested in high resolution timer for both Windows and Unix(es). I found couple places online and in this ML archive that have what I need.

Would you consider submitting these as a separate high_res_timer mini-library for boost so that everyone can have easy access to them? It seems to me that these would be good additions to the Boost.Timer library?

3. I am interested in adding enhanced profiling abbilities to Boost.Test or somehow integrating standalone solution into Bosot.Test facilities. But to desing the integration I need to understand better what and how you are trying to do.

If you haven't already, please take a look at http://www.cdiggins.com/profiler/ , hopefully this explains my goals. If you have specific questions I will do my best to answer them. Best, Christopher

----- Original Message ----- From: "Gennadiy Rozental" <gennadiy.rozental@thomson.com> To: <boost@lists.boost.org> Sent: Monday, February 07, 2005 1:57 PM Subject: [boost] Re: Re: Boost Profiler Proposal [snip]

Well, I've read you docs and code. Here is what I think:

Once I started looking through proposed design it immideatly stroke me that you are making most common mistake in policy based designs (PBD): putting everything into one single policy. IMO PBD is not about providing complete implementation as template parameter (at least is not only about it). But mostly about finding small reusable and orthogonal! policies that in combination deliver flexibility and power. This is the reason why your policy are templates and why you need to implement counting, reporting and counting_and_reporting policies. These are orthogonal parts of profiler functionality. No need to combine them into single policy.

Good point, I agree that the timer_type should be extracted. However both reporting and collecting policies model the same concept, they react to when the profiler object is destroyed. Separating them does not seem neccessary to me. I think that particular point may be more of an issue of personal style, because overall it does not change the behaviour of the class.

Also I believe from my expirience that profiler model you chose is way too simple for real-life needs. Here is specific profiling modes I saw:

1. Take piece of code and wrap into timer. You cover this case 2. Take piece of code and time an average execution time during multiple code invokation. You model couldn't do that

Actually it can. The reporting_policy stores elasped_total and entry_count which can be used to construct averages. I have improved the collecting_policy to generate detailed reports: struct counted_sum : pair<int, double> { counted_sum() : pair<int, double>(0, 0) { } counted_sum(int x, double y) : pair<int, double>(x, y) { } void operator+=(double x) { first++; second += x; } }; typedef std::map<std::string, counted_sum> stats_map; struct collecting_policy { static stats_map stats; static void on_profiled(const char* name, double dSec, double dMin, double dMax) { stats[name] += dSec <= dMin ? 0.0 : dSec; } static void generate_report() { cout << "profile name" << '\t' << "total elapsed" << '\t' << "entry count" << '\t' << "average" << endl; for (stats_map::iterator i=0; i != stats.end(); i++) { string sName = i->first; int nCount = i->second.first; double dTotal = i->second.second; double dAvg = dTotal / nCount; cout << sName << '\t' << dTotal << '\t' << nCount << '\t' << dAvg << endl; } } }; stats_map collecting_policy::stats;

3. Frequently code you want to profile is "interrupted" with islands of code that you are not interested in. You need an ability to do accumulation

I would prefer to leave this to the user when they generate their report. I see no real obstacle for them to do the subtraction of stats.

4. Hierarchical checking points. Frequently you want to be able to see whe whole picture and easily add check points somewhere inside. In a result you want to see time from point A to point B then from point B to point C, compined time from A to C and so on.

See above.

Here is how I think policies could be designed:

1. TimerPolicy Responcible for "timing implementation", including timer, it's resolution e.t.c. Possible incarnations: BoostTimerPolicy, HighResolutionTimerPolicy, WallTimerPolicy. 2. CollectionPolicy Responcible for "what and how to collect" (elapsed time in one run, average time in multiple runs, profiler name, location, relations). Possible incarnations: SingleRunCollector. MultirunCollector, GlobalCollector e.t.c. This policy may need to be separated into two. 3. LoggingPolicy Responcible for "how to report". Here where Boost.Test integration kicks in. Possible incarnations: OstreamLogger, StdoutLogger, BoostTestLogger e.t.c. 4. ReportingPolicy Responcible for "when to report". Possible incarnations: ScopedReporter, ExplicitReporter, ReportNone (to be used with GlobalCollector that perform reporting itself)

and profiler definition would look like this:

template<typename TimerPolicy,typename CollectionPolicy,typename LoggingPolicy,typename ReportingPolicy> class profiler : public TimerPolicy, public CollectionPolicy, public LoggingPolicy, public ReportingPolicy { .... };

I have posted a new version of the code at http://www.cdiggins.com/profiler/profile2.hpp which separates the timer policy, and allows the generation of reports after execution. How do you feel about the new design, does it go far enough in your mind, or do you still want significantly more functionality? I feel relatively strongly that the library should simply provide the data to the user, and provide a minimal default functionality in terms of generating reports, and leave the rest up to the user. Thanks for your suggestions and feedback, Christopher Diggins

----- Original Message ----- From: "Gennadiy Rozental" <gennadiy.rozental@thomson.com>

...

Good point, I agree that the timer_type should be extracted. However both reporting and collecting policies model the same concept,

No they model completely different notions:

what to collect and how to report

I said "concept" not notion, referring to the fact that they were triggered under precisely the same circumstances and had the same function signatures.

...

they react to when the profiler object is destroyed.

Not necessarily. Both report and collection functionality may need to be invoked at other point explicitly

They couldn't be in my design. And I currently am entirely unconvinced of the need to further complicate the design.

...

Separating them does not seem necessary to me.

Now to implement custom logging into Boost.Test log I need to repeat counting logic, is it?

IMO repeating counting logic is trivial and does not neccessarily warrant a policy.

...

I think that particular point may be more of an issue of personal style, because overall it does not change the behavior of the class.

It does. It makes inflexible.

Not in the case of the current design at http://www.cdiggins.com/profiler/profiler2.hpp . Adding multiple policies to an RAII class which only calls 1 function would be needlessly complicating the design.

...

...

Also I believe from my experience that profiler model you chose is way too simple for real-life needs. Here is specific profiling modes I saw:

1. Take piece of code and wrap into timer. You cover this case 2. Take piece of code and time an average execution time during multiple code invocation. You model couldn't do that

Actually it can. The reporting_policy stores elapsed_total and entry_count

Actually you can't. Not without changing public interfaces.

You seem to be confusing structs with classes. The fields are public! In the old version ( http://www.cdiggins.com/profiler/profiler.hpp ) you would have written: double avg = collecting_policy::elapsed_totals["name"] / collecting_policy::entry_counts["name"]; With the new version ( http://www.cdiggins.com/profiler/profiler2.hpp ) the average can now be computed as: sum_count sc = collecting_policy::stats["name"]; avg = sc.first() / sc.second();

...

which can be used to construct averages. I have improved the collecting_policy to generate detailed reports:

struct counted_sum : pair<int, double> { counted_sum() : pair<int, double>(0, 0) { } counted_sum(int x, double y) : pair<int, double>(x, y) { } void operator+=(double x) { first++; second += x; } };

typedef std::map<std::string, counted_sum> stats_map;

struct collecting_policy { static stats_map stats;

And what if I have two independent profiling point?

Then they should have different names. Each profile is labelled according to a name, so it either occupies a unique location in the map, or it overlaps with another profile, if that is the desire.

...

...

3. Frequently code you want to profile is "interrupted" with islands of code that you are not interested in. You need an ability to do accumulation

I would prefer to leave this to the user when they generate their report. I see no real obstacle for them to do the subtraction of stats.

I don't know what substraction you mean. It's rather addition.

There are two ways to compute an island: Version 1) Subtraction method: { profile p1("name1") { profile p2("name2"); // island } } cout << collecting_policy["name1"].first - collecting_policy["name2"].first << endl; Version 2) Addition method: { profile p1("name1"); } // island { profiler p2("name2"); } cout << collecting_policy["name1"].first + collecting_policy["name2"].first << endl; Version 3) Shared Named method : { profile p1("name1"); } // island { profiler p1("name1"); } cout << collecting_policy["name1"].first;

And in any case I believe it's component responsibility.

I disagree.

{ profiler p; // some code p.stop(); // some other code we do not want to profile p.resume(); // continue profiling p.stop() } // here we print report

I expect report to be print only once

stop() and resume() are not part of the design. You would write the above code as: { { basic_profiler<collecting_policy> p("profile1"); // some code } // some other code we do not want to profile { basic_profiler<collecting_policy> p("profile1"); // continue profiling } collecting_policy::generate_report(); } } CD

----- Original Message ----- From: "Bob Bell" <belvis@pacbell.net> [snip]

A final data point is an answer to your original question "Would you use it?" Not without being able to pause and resume the profiler. I also wouldn't be interested in it as long as the reporting and collection concepts are confused.

Bob

Thanks for your comments, Okay, so the general consensus has been quite consistent: - ability to turn off globally - pause and resume - As unintrusive as possible (no requirement of code reporting) - hierarchical reporting (optional) I think perhaps the best approach then would be a macro library. I propose the following macros: BOOST_PROFILING_OFF // turns off the macros BOOST_PROFILE_START(profiler_type, name) BOOST_PROFILE_STOP(name) BOOST_PROFILE_PAUSE(name) BOOST_PROFILE_RESUME(name) BOOST_PROFILE_EXPR(expression) BOOST_PROFILE_REPORT(name) BOOST_PROFILE_ALL(name) I then will follow Gennadiy's suggestion of multiple policies: basic_profiler<reporting_policy, logging_policy, collecting_policy, timer_policy> How does this sound? My apologies to Gennadiy for having been hard-headed. Christopher Diggins Object Oriented Template Library (OOTL) http://www.ootl.org

----- Original Message ----- From: "Rob Stewart" <stewart@sig.com> To: <boost@lists.boost.org> Cc: <boost@lists.boost.org> Sent: Tuesday, February 08, 2005 5:36 PM Subject: Re: [boost] Re: Boost Profiler Proposal

From: christopher diggins <cdiggins@videotron.ca>

...

Okay, so the general consensus has been quite consistent: - ability to turn off globally - pause and resume - As unintrusive as possible (no requirement of code reporting)

^^^^^^^^^^^ (When you get to the docs, be sure to write that as "nonintrusive.")

Good point.

...

- hierarchical reporting (optional)

I think perhaps the best approach then would be a macro library. I propose

That is the only way to turn it off entirely. :-(

...

the following macros:

BOOST_PROFILING_OFF // turns off the macros

BOOST_PROFILE_START(profiler_type, name) BOOST_PROFILE_STOP(name) BOOST_PROFILE_PAUSE(name) BOOST_PROFILE_RESUME(name) BOOST_PROFILE_EXPR(expression) BOOST_PROFILE_REPORT(name) BOOST_PROFILE_ALL(name)

A better scheme would be to provide a null profiler class that BOOST_PROFILE_START instantiates when BOOST_PROFILE_OFF is defined. Then, there can be empty, inline member functions so that the following code compiles away to nothing in optimized builds:

void f() { BOOST_PROFILER(type) prof; // code to profile prof.pause(); // code to ignore prof.continue(); // more code to profile }

I like this. What if we took it a step further and wrote something like: template<typename T1, typename T2> struct profiler : if_<profiling_on, basic_profiler<T1, T2>, null_profiler>::type { }; This would entirely remove the need for macros. What do you think?

...

I then will follow Gennadiy's suggestion of multiple policies:

basic_profiler<reporting_policy, logging_policy, collecting_policy, timer_policy>

In keeping with the rest, should the latter be "timing_policy?"

That would be better. Or maybe it should be just timer_t since it doesn't really behave like a policy. Thanks for the comments, Christopher

From: christopher diggins <cdiggins@videotron.ca>

From: "Rob Stewart" <stewart@sig.com>

...

...

A better scheme would be to provide a null profiler class that BOOST_PROFILE_START instantiates when BOOST_PROFILE_OFF is defined. Then, there can be empty, inline member functions so that the following code compiles away to nothing in optimized builds:

void f() { BOOST_PROFILER(type) prof; // code to profile prof.pause(); // code to ignore prof.continue(); // more code to profile }

I like this. What if we took it a step further and wrote something like:

template<typename T1, typename T2> struct profiler : if_<profiling_on, basic_profiler<T1, T2>, null_profiler>::type { };

This would entirely remove the need for macros. What do you think?

Yes, that's good. You'd still probably want to use a macro to enable/disable profiling so that it can be managed from the compiler command line. Thus, if the macro is defined, profiling_on is defined appropriately to select basic_profiler. The only question is how well that optimizes to nothing in various compilers. -- Rob Stewart stewart@sig.com Software Engineer http://www.sig.com Susquehanna International Group, LLP using std::disclaimer;

You would write the above code as:

{ { basic_profiler<collecting_policy> p("profile1"); // some code } // some other code we do not want to profile { basic_profiler<collecting_policy> p("profile1"); // continue profiling } collecting_policy::generate_report(); } }

Personally, mu biggest problem with this is thats an awful lot of constructing and destructing. Remember my suggestion: Profiler p(profiler_group); // some code p.next("code1"); // more code p.next("code2"); And the intervening time between the next calls (or the profiler instantiation for that matter) would be added. This allows for two things. First, I could have: Profiler big(big_group), small(small_group); for (i=0; i<10; ++i) { small.next("other"); // some code small.next("code1"); // more code small.next("code2"); } big.next("my_for_loop"); allowing me to both profile individual components, of my for loop, as well as how much the for loop as a whole is taking, and it wouldn't be a problem. Second, the above approach constructs big and small ONCE, and relies on no static values, just that big_group and small_group are defined somewhere (they may be static variables, global variables, passed into the function, whatever). Oh, and something I also didn't mention, the interface is DEAD simple, and does not stop variables being defined in code block 1, and used in code block 2. You could also then just add a 'skip' function that would simply do the same as next, without passing on the time to your profile group, or you could use a value (say, "") that your profile group would ignore (obviously, the Profile class wouldn't know its going to be ignored, but your own profile group would). Simplicity is the key here, there is no need to have 8 macros, or static variables. Plus the above approach is quite flexible without relying on scoping syntax, and allows multiple granularity of profiling. For example, I could then figure out some way to disable small profiling group but still use the big profiling group (whatever it may do, print, etc). Its not an 'all or nothing' approach. -- PreZ :) Founder. The Neuromancy Society (http://www.neuromancy.net)

Does anyone have any idea about how the methods for computing time compare on a unix/linux system? Specifically I am interested in resolution and reliability. using namespace boost; using namespace date_time; { timer t; // code ... double sec = t.elapsed(); } { ptime start = microsec_clock::local_time(); // code ... time_duration total = microsec_clock::local_time() - start; double sec = total.seconds() + (1000000000 / total.fractional_seconds()); } Thanks Christopher Diggins