----- Original Message ----- From: "Gennadiy Rozental" <gennadiy.rozental@thomson.com> To: <boost@lists.boost.org> Sent: Friday, February 04, 2005 2:17 PM Subject: [boost] Re: Profiling Library suggestion

How is it better than what boost::timer provide?

Gennadiy

Hello, I was unaware of timer's existance, thanks for pointing it out. I had searched for "profiling", and "profiler". So I just took a look at: http://www.boost.org/libs/timer/timer.htm and I would humbly submit that perhaps what is lacking in progress_timer is a policy, and the ability to name profiles. I would like then to propose: struct profiler_default_policy { typedef boost::timer timer_t; static void on_profiled(const char* name, const timer_t& t) { double sec = t.elapsed(); cout << "time elapsed (msec) during profile " << name << " was " << sec / 1000; if (sec <= t.elapsed_min()) { cout << " *underflow* "; } if (sec >= t.elapsed_max()) cout << " *overflow* "; } cout << endl; } }; struct interesting_profiler_policy { typedef boost::timer timer_t; static map<string, double> profiles; static void on_profiled(const char* name, const timer_t& t) { double sec = t.elapsed(); profiles[name] = sec; } }; template<typename policy_t> class basic_profiler { public: profiler(char const* s = "") : name(s) { }; ~profiler() { policy_t::on_profiled(name, timer); }; private: char const* name; typename policy_t::timer_t timer; }; typedef basic_profiler<default_profiler_policy> profiler; This would have an advantage over progress_timer that library users may modify the behaviour of the profiler, without rewriting the class. It can also be used with more high-performance timers if the user has one at their disposal. Any comments or suggestions? Christopher Diggins Object Oriented Template Library (OOTL) http://www.ootl.org

----- Original Message ----- From: "Pavel Vozenilek" <pavel_vozenilek@hotmail.com>

...

Any comments or suggestions?

Useful would be to have: - ability to report data only when certain threshold is reached

Threshold of what?

- collecting min/max/average statistics where needed

This could be done relatively easily, I believe by writing a new policy. Would you be interested in writing a statistics collecting policy? One thing that concerns me is that as far as statistics go, this will likely have far too coarsely grained resolution to be used, as one would a real profiler. Due to the resolution of the underlying boost::timer. This is instead useful only for large and extremely CPU intensive blocks of code. Perhaps "profile" is a bad name, and instead it should be called "progress_timer", because it is little more than a high-powered version of the original progress_timer. Christopher Diggins Object Oriented Template Library (OOTL) http://www.ootl.org

christopher diggins wrote:

...

- collecting min/max/average statistics where needed

This could be done relatively easily, I believe by writing a new policy. Would you be interested in writing a statistics collecting policy?

One thing that concerns me is that as far as statistics go, this will likely have far too coarsely grained resolution to be used, as one would a real profiler. Due to the resolution of the underlying boost::timer. This is instead useful only for large and extremely CPU intensive blocks of code.

I have a boost::timer interface compatible high resolution timer here, which I can submit, if anybody is interested. Regards Hartmut

christopher diggins wrote:

...

I have a boost::timer interface compatible high resolution timer here, which I can submit, if anybody is interested.

Regards Hartmut

I am most definitely interested, and I am quite sure the others who have already expressed interest in the profiler library would be as well. Would it be appropriate as the default polciy timer for the library, or would it be more appropriate as part of the examples? How high is the resolution, and what platforms does it work on?

Works currently on Windows only, but could be easily extended to work on Posix systems as well (using the Posix high resolution timers). The resolution is platform dependent because it currently uses the Windows high-resolution performance counters, which are based on the cycle rate of the processor clock. The attached implementation simply falls back to boost::timer when used on non-system platforms.

A general question w.r.t platform dependencies, what is the standard way to proceed when authouring a boost library which varies on the platform? For instance is the following acceptable for Boost:

#ifdef BOOST_WINDOWS typdef win32_profiler_policy default_profiler_policy; #elif BOOST_POSIX typdef posix_profiler_policy default_profiler_policy; #else typdef boost_default_profiler_policy default_profiler_policy; #endif

Sure, why not? Maybe you want have a look at the Boost.Threads library, which uses a similar technique internally. Regards Hartmut

At 10:26 AM 2/5/2005, christopher diggins wrote:

A general question w.r.t platform dependencies, what is the standard way to proceed when authouring a boost library which varies on the platform? For

instance is the following acceptable for Boost:

#ifdef BOOST_WINDOWS typdef win32_profiler_policy default_profiler_policy; #elif BOOST_POSIX typdef posix_profiler_policy default_profiler_policy; #else typdef boost_default_profiler_policy default_profiler_policy; #endif

That's done in several existing libraries. Try to limit inclusion of platform dependent headers to implementation (.cpp) files; don't include platform dependent headers from the public boost headers. That isn't always possible, but a lot of users find inclusion of headers like <windows.h> to be very distasteful, and don't like to get such headers as a side effect of including a boost header. --Beman

sorry for the long delay, it´s carnaval here in Brasil, and I forgot to send a message telling I was gone for a few days, I will catch up with the discussion and try some code very soon. On Fri, 04 Feb 2005 17:24:49 -0500, christopher diggins <cdiggins@videotron.ca> wrote:

----- Original Message ----- From: "Sérgio Vale e Pace" <svpace.forum@gmail.com> To: <boost@lists.boost.org> Sent: Friday, February 04, 2005 1:50 PM Subject: Re: [boost] Profiling Library suggestion

...

if there is interest in it I would like to boostify it, I´m frequently use something like this and I find it very useful.

Hi Sergio,

What do you think of the latest version of the profiler mini-library? Would you be interested in writing the documentation, and taking care of the submission to boost? How would you like to progress, I am inexperienced at collaboration.

Christopher Diggins Object Oriented Template Library (OOTL) http://www.ootl.org

_______________________________________________ Unsubscribe & other changes: http://lists.boost.org/mailman/listinfo.cgi/boost

christopher diggins wrote:

I am still looking for a posix high-resolution timer. Hartmut suggested a couple of Posix timers which he got off of Google, which unfortunately were unusable: one was GPL'ed and the other lacked source code.

You don't have to include these timers into Boost, these timers are part of the operating systems already for a couple of years IIRC. Just use them as an API. Regards Hartmut

Gennadiy said there were some on the mailing list (I couldn't find ), and that he uses one in the CVS but I don't know how to use the CVS. I also can not test Posix timers, since I only use visual C++. I believe that perhaps boost::date_time contains a good resolution timer, but I can't tell.

Christopher Diggins Object Oriented Template Library (OOTL) http://www.ootl.org

_______________________________________________ Unsubscribe & other changes: http://lists.boost.org/mailman/listinfo.cgi/boost

----- Original Message ----- From: "Gennadiy Rozental" <gennadiy.rozental@thomson.com> To: <boost@lists.boost.org> Sent: Thursday, February 10, 2005 12:13 PM Subject: [boost] Re: Latest version of the profiler

news:004401c50f7c$779fa640$d9958242@heronnest...

...

The latest version is at: http://www.cdiggins.com/profiler

The major changes are: - defining BOOST_PROFILING_OFF causes all member calls to become empty statements

Why didn't you go with MACRO-less solution?

Because it is a non-standard way of doing things. The majority of boost libraries use macros to control compilation.

...

- basic_profiler now has three policies: logging, stats, timer - profiler now supports: restart, stop, pause, resume, generate_report - fixed QueryPerformanceCounter() api bug in HighResolutionTimer

1. Logging Policy

This policy supposed ot be responsible for *how* you do logging (not what or when).

That seem unneccessarily inflexible. How can you determine in advance what should be logged and when it should be logged? Also, why do you say "supposed to"? What are the specific reasons why the logging policy design is flawed. I give the option to the user through the policy. I could separate the logging policy into three separate policies: when_to_log_policy, how_to_log_policy, what_to_log_policy. But it is to simple to warrant this extra refactoring IMO.

Accordingly it shoud't be event driven. It should be ... feature driven: log_start(...), log_finish(...) e.t.c. I don't really understand how you intend to use your current interface.

I don't see how this confusion could arise given the simplicity of the design. Could you ask a more specific question?

2. Stats Policy Fron you docs (emphasis is mine): "The stats policy is responsible for collecting *and* reporting statistics". Did you notice 'and'? You still tring to put two eggs into same basket.

The collecting and reporting of statistics is inextricably linked. You can only report stats that you have collected. I do not see how you could separate the two.

What if you want 2 different profilers, both scoped, but first measure wall-clock time, second measure process time?

That is beyond the scope of the library. I can not imagine a profiling tool which would want to measure wall clock time. The profiler library measures time durations only.

3. Timer concept I am not sure that boost::timer interface present the best abstraction for Timer concept.

However it is what we have to build off of. There was a lot of work that went into it, and I am confident in the design decisions that were made. I also like the simplicity of it.

Amoung other things I believe you also need time_type (long, long long, int64_t, timeval e.t.c). Also using double for elapsed in general may not be desirable also.

I agree that this would make it more powerful, however it would also give a false sense of security w.r.t the robustness of the tool. I don't want to spend an inordinate amount of time dealing with the quirkiness of timers. It is a very complex subject, and virtually impossible to do both portably and correctly. I believe that what was good enough for boost::timer, is good enough for boost::profiler.

...

I am still looking for a posix high-resolution timer. Hartmut suggested a couple of Posix timers which he got off of Google, which unfortunately were unusable: one was GPL'ed and the other lacked source code. Gennadiy said there were some on the mailing list (I couldn't find ),

Look here:

http://lists.boost.org/MailArchives/boost/msg47483.php http://lists.boost.org/MailArchives/boost-users/msg08974.php http://lists.boost.org/MailArchives/boost/msg64458.php

Gennadiy

Thanks, Christopher Diggins Object Oriented Template Library (OOTL) http://www.ootl.org

I do understand that you do not want spend time/effort more on this, but don't expect us(me) to blindly agree to what you have right now.

I am hardly asking anyone to blindly agree with me! All I ask is for people to simply try out the code, and point out specific problems. Christopher Diggins Object Oriented Template Library (OOTL) http://www.ootl.org

----- Original Message ----- From: "Gennadiy Rozental" <gennadiy.rozental@thomson.com> To: <boost@lists.boost.org> Sent: Thursday, February 10, 2005 2:12 PM Subject: [boost] Re: Re: Latest version of the profiler

...

That seem unnecessarily inflexible. How can you determine in advance what should be logged and when it should be logged? Also, why do you say "supposed to"? What are the specific reasons why the logging policy design is flawed.

I couldn't. But most importantly I shouldn't. PBD is not about providing single logging policy that do everything related to logging. PBD is about providing orthogonal (independent) policies each one with specific responsibilities. In this case Logging Policy responsibility is to define "how to do logging". Collection Policy defines what to log and Reporting policy defines when to log. Each one independent and easily substituted. If you policy responsible for everything and you component is just hollow forwarder, then such component doesn't bring any value and in most cases it would be easier to write custom component itself then custom policy. Yes it is not simple to design PB component that both flexible to cover most important cases and is not hollow so that it has real value. With proper design every policy has specific responsibilities with specific interfaces related to these responsibilities, while you component orchestrates policies interactions.

This is too general. Please state a specific problem with the current code.

...

...

2. Stats Policy From you docs (emphasis is mine): "The stats policy is responsible for collecting *and* reporting statistics". Did you notice 'and'? You still trying to put two eggs into same basket.

The collecting and reporting of statistics is inextricably linked. You can only report stats that you have collected. I do not see how you could separate the two.

Collecting is responsible for WHAT to collect. Reporting is responsible for WHEN to report.

I do not see why would I want to unit them into single concept.

I would appraciate a specific use case which shows the failure of the current code, and how an alternative design specifically solves the problem.

...

...

3. Timer concept I am not sure that boost::timer interface present the best abstraction for Timer concept.

However it is what we have to build off of. There was a lot of work that went into it, and I am confident in the design decisions that were made. I also like the simplicity of it.

Where did you get your confidence from? Does your design passed through challenges presented in variety of possible profilers out there? Simplicity is good until it cause inflexibility.

I was talking about the Boost.Timer not my own design.

The thing is that boost::timer is not good enough for many non-trivial profiling tasks (and it was discussed here on ML many times). Overflow is one of the major issues for example. So without larger time type you couldn't get around it's deficiencies.

It is not a bad idea then to update the timer resolution. However, I find it strange that the expectations on the Profiler library would be greater than those placed on the Boost.Timer library. Christopher Diggins Object Oriented Template Library (OOTL) http://www.ootl.org

----- Original Message ----- From: "Gennadiy Rozental" <gennadiy.rozental@thomson.com> To: <boost@lists.boost.org> Sent: Thursday, February 10, 2005 3:49 PM Subject: [boost] Re: Re: Re: Latest version of the profiler

...

I would appraciate a specific use case which shows the failure of the current code, and how an alternative design specifically solves the problem.

I gave trivial example your design couldn't handle (without code repetitions).

1. Profiler type 1 Log clock units and report mks into ostream 2. Profiler type 2 Log system/user time anf reports into Boost.Test log

Both profiler I want to be able to use as scoped or accumulating.

Gennadiy

Can you please be more specific. I don't understand what you want and precisely what the problem is. I am pretty sure we have different ideas of what a "report" is and what it means to "log". Christopher Diggins Object Oriented Template Library (OOTL) http://www.ootl.org

----- Original Message ----- From: "Gennadiy Rozental" <gennadiy.rozental@thomson.com> To: <boost@lists.boost.org> Sent: Thursday, February 10, 2005 5:16 PM Subject: [boost] Re: Re: Re: Re: Latest version of the profiler

...

...

1. Profiler type 1 Log clock units and report mks into ostream 2. Profiler type 2 Log system/user time anf reports into Boost.Test log

Both profiler I want to be able to use as scoped or accumulating.

Gennadiy

Can you please be more specific. I don't understand what you want and precisely what the problem is. I am pretty sure we have different ideas of what a "report" is and what it means to "log".

1. Profiler type 1 Collect clock units and report mks into ostream 2. Profiler type 2 Collect system/user time anf reports into Boost.Test log

Both profiler I want to be able to use as scoped or accumulating.

Gennadiy

Gennadiy, Your post makes almost as little sense as before, simply changing "Log" to "Collect" doesn't help me out much. What you wrote is virtually incomprehensible! It seems to me that you aren't really making an effort to help me out here. What does "report mks into ostream" mean? When do you want to do these reports? What do you want reported. As far as I can tell you can do this with my code. Why do you think you can't? How and when do you want to "collect system/user time"? Why would you want to log it? How would you report it? And why can't you do this with the current library? Is "anf" some kind of acronym? If you don't want to take the time to respond to my questions carefully, and respectfully than I would ask that you simply don't respond. I am at the limit of my patience with your negative attitude and lack of courtesy. Christopher Diggins Object Oriented Template Library (OOTL) http://www.ootl.org

On Thu, 17 Feb 2005 21:05:55 -0500, Beman Dawes wrote

At 03:08 PM 2/10/2005, christopher diggins wrote:

...

...

The thing is that boost::timer is not good enough for many non-trivial profiling tasks (and it was discussed here on ML many times). Overflow is >> one of the major issues for example. So without larger time type you >> couldn't get around it's deficiencies. > >It is not a bad idea then to update the timer resolution. However, I find >it strange that the expectations on the Profiler library would be greater >than those placed on the Boost.Timer library.

Jeff Garland and I have discussed replacing the Boost.Timer library by adding a new timer component in the date-time library. The Boost.Timer design isn't how we would tackle the problem today. There is or was a wiki-page discussing some of the issues, but I'm not finding it at the moment.

Sorry I've been busy so I haven't had time to read or chime in on this thread. Bringing timer into date-time has been on the back burner, but I expect to pick it up either before or right after 1.33. The wiki page is at: http://www.crystalclearsoftware.com/cgi-bin/boost_wiki/wiki.pl?GDTL/Timer Please add your requirements / thoughts there. Jeff

Hey Sergio, It's nice to have a friendly and supportive voice. So what do you think of the library so far? Personally I don't want to add much more functionality at this time. I am however very open to helping out anyone who wants to make changes and/or take over the responsibility of submitting it to boost. Is this something you still might be interested in? CD

----- Original Message ----- From: "Sérgio Vale e Pace" <svpace.forum@gmail.com> To: <boost@lists.boost.org> Sent: Friday, February 11, 2005 8:48 AM Subject: Re: [boost] Re: Re: Latest version of the profiler

Hi, the library evolved a lot since your first proposal, and it seens very impressive.

Thanks.

I agree with you about do not adding new functionalities, in fact I would even remove some, I´m not particularly liked the pause/resume thing, but that´s just me.

I don't like it much neither, but it was at the top of list of requests. What concerns me is that it might lead people to think that maybe they can use the profiler to time just a few statements. This isn't a great idea because the default timer doesn't have a good enough resolution. I need to make it clear that this is intended as a quick and dirty profiler rather than a commercial tool. Another big problem with pause and resume, is that it increases error and increases the chance of underflow. Oh well, caveat user I say.

I am interested in submitting it to boost, but I have to say: I would never be able to develop it as fast as you been doing,

Not a problem, I am going to be stopping development very soon. I am just completely a final version which is satisfactory for my needs and I think those of a few others. Part of the rush, is I need it for my current library, and some of the potential users need it soon as well.

and I never made a boost submission before, but I would like to give it a try.

That is good because I don't have enough patience to do it. So do you mind taking over after my next release (probably today)? You can of course do whatever you want to the code, including simplifying the design and/or removing features.

still I do think there is need to polish and stabilize the design a little, gather some more use cases and document a fill "best pratices" before trying to submitting it

I agree.

Sérgio

Brian's suggestions have motivated me to redesign the implementation of a profiler as follows: template<typename policy_t> class basic_profiler { typedef policy_t::timer_type timer_type; typedef policy_t::duration_type duration_type; typedef policy_t::ident_type id_type; public: basic_profiler() : timing(true), elapsed(0.0), underflow(false), overflow(false) { policy_t::on_start(id); t.restart(); } basic_profiler(ident_type id) : id(ident_type), timing(true), elapsed(0.0), underflow(false), overflow(false) { policy_t::on_start(id); t.restart(); } ~basic_profiler() { if (timing) { stop(); } } void stop() { duration_type tmp = t.elapsed(); if (tmp <= t.elapsed_min()) { underflow = true; } if (tmp >= t.elapsed_max()) { overflow = true; } tmp += elapsed; elapsed = 0.0; timing = false; policy_t::on_stop(id, tmp, underflow, overflow); } void restart() { timing = true; elapsed = 0.0; policy_t::on_restart(id); timer.restart(); } void resume() { timing = true; policy_t::on_resume(id); timer.restart(); } void pause() { time_elapsed tmp = t.elapsed(); if (tmp <= t.elapsed_min()) { underflow = true; } if (tmp >= t.elapsed_max()) { overflow = true; } elapsed += tmp; timer.pause(); timing = false; policy_t::on_pause(id); } private: bool underflow; bool overflow; bool timing; ident_type id; duration_type elapsed; timer_type t; }; Now Brian can now squeeze metadata into the id. He simply has to make sure that the type can be used as a key in a map. I think this is a much more open-ended design, which anticipates things like possible bigger time durations in the policy (motivated by Gennadiy's suggestions). I'd suggest to consider looking at boost::date_time::time_duration if one wants to do this in the best possible way. That would require rewriting the timer however, yuck. Another thing about this design, is it delegates almost all of the interesting work to the policy. Which is perfect I think, because it seems there are just far too many usage scenarios to anticipate them all. Some issues which I still find lacking, are the handling of underflow / overflow conditions. Any comments or suggestions? CD.

On Thu, 10 Feb 2005 15:58:55 -0500, Gennadiy Rozental <gennadiy.rozental@thomson.com> wrote:

...

I do agree with you about the fact that good PBD should provide orthogonal policies, but the fundamental use for PBD is to delay implementation details to when they are needed,

It's only a side effect. Fundamental reason to use PBD is to introduce granulation into your solution moving toward: one entity - one task principle

indeed, breaking a big and ugly task into a set of smaller, self-contained and simple mini-tasks has been one of the main porpuses of almost all programming techiniques since before the fortran guys first walked on earth, the main issue is how do you acomplish that. PBD is about customization and separation of concerns, otherwise you could just hardcode your policies in the object hierarchy, avoiding templates all together: class profiler : timer, logger, whatever {}; but independent of these conceptual details do we agree that delayed implementation details, side effect or not, is an advantage we could use?

...

allowing easy to create and maintain yet flexible and extensible implementation. IMHO two policies (one for timer and one for logging) is more than enough for a profiling tool, how to collect data, when to report it how to report it, what estatistical analysis should be used are all policies for the logging policy, not the profiler.

And how does making logging policy parameterized with components simplify your design?

class simple_log_policy { public: void begin(string x) {}; void end(string x, double, t) { cout << x << " = " << t << endl; }; template<typename p1, typename p2, typename p3, typename p4, typename p5> class big_and_mean_log_policy { public: void begin(string x) { ...do bif stuff ... }; void end(string x, double t) { ... do mean stuff... }; }; small task, small code. big task, big code.

...

Some simple reports like "foo() - 50% - 10 ms" are usually more than enough for simple tasks. Let´s save the big guns for the big tasks ;)

We already have boost::timer for simple tasks.

indeed, and everytime I wanto to time things I will use it,the same way everytime I want to profile things I will use the profiler.

I don't see how 4 policies make design more complex (IMO vice versa). And in any case correct design is better in long run.

when I buy a car I usually don´t want a tow-car attached to it, even knowing that same day I might eventually need a tow-car. the same way if a profiler needs 4 policies then 4 policies is fine, but if single one policy deals with things that don´t regard a profiler, this policy shoudn´t be a profiler policy. everything above IMO

Gennadiy

Sérgio

----- Original Message ----- From: "Jonathan Turkanis" <technews@kangaroologic.com> To: <boost@lists.boost.org> Sent: Friday, February 04, 2005 5:45 PM Subject: [boost] Re: Profiling Library suggestion

How about:

typedef profiled< MyClass, Interface, Profiler<> > > MyProfiledClass;

?

This would be a good application of aspect-oriented programming.

Jonathan

What an excellent idea! That would be an excellect application of AOP. What do you think of the profiler code I submitted? Any suggestions? Christopher Diggins Object Oriented Template Library (OOTL) http://www.ootl.org

Hi, Sorry in advance for heavy editing of the email. ----- Original Message ----- From: "Preston A. Elder" <prez@neuromancy.net> To: <boost@lists.boost.org> Sent: Saturday, February 05, 2005 3:24 AM Subject: [boost] Re: Profiling Library suggestion

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.

Good point.

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).

How about: { basic_profiler<custom_collecting_policy> p("op1") op1(); } { basic_profiler<custom_collecting_policy> p("op2") op2(); } { basic_profiler<custom_collecting_policy> p("op3") op3(); } ? And if you like macros, you could always write out: #define PROFILE(TKN0) { basic_profiler<custom_collecting_policy> profiler_(#TKN); TKN0(); } PROFILE(op1) PROFILE(op2) PROFILE(op3)

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.

Yes definitely, I agree.

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

Thanks for your contributions. Christopher Diggins Object Oriented Template Library (OOTL) http://www.ootl.org

On Fri, 11 Feb 2005 16:34:36 -0500, Preston A. Elder <prez@neuromancy.net> wrote:

BTW, I'm wondering why you don't use something like this as the basis for your high-resolution timer:

boost::posix_time::ptime get_highres_time()

One subtle difference is that the current implementation uses CPU-cycle timings (via std::clock or Win32 QueryPerformanceCounter) and not wall-clock timings. Using the xtime_get approach would give you a wall-clock based timer which may not be what you want. Christopher: a couple of comments on the current implementation of the basic_profiler: * std::map and std::string are used unqualified and w/o headers being included * string arguments to methods should be passed by const ref * There should be a public elapsed() method to extract the elapsed time from a profiler. Perhaps it should just be public? * basic_profiler::restart invokes logging_policy::on_restart which is not implemented (should this be on_resume?) * basic_profiler::restart, ::resume and ::pause all call methods on an undefined object "timer". Should be "t". * basic_profiler::pause calls (when fixed) t.pause which is not implemented. * In the private section of basic_profiler, the typename in "typename timer_t t" is (I think) spurious. * The basic_profiler ctor initializes members in a different order than they are declared in the class Might I also suggest that the basic_profiler.stop method not zero out the elapsed time. Leave it to restart to do that. Think of it like a stop-watch. -- Caleb Epstein caleb dot epstein at gmail dot com

On Fri, 11 Feb 2005 17:55:26 -0500, christopher diggins <cdiggins@videotron.ca> wrote:

...

* There should be a public elapsed() method to extract the elapsed time from a profiler. Perhaps it should just be public?

Yes.

Actually, elapsed() should be a method and should return elapsed + t.elapsed(). It will need to have a name other than "elapsed" though or you'll need to change the name of the member (I'd recommend the latter).

...

* The basic_profiler ctor initializes members in a different order than they are declared in the class

Does that matter?

Not really, but gcc -Wall warns about it. Its worth fixing if only for that. -- Caleb Epstein caleb dot epstein at gmail dot com

Here's a use case that I had trouble getting to work with the current profiler implementation. I have some code that is benchmarking a relatively fast routine. I was using boost::timer and keeping track of the number of calls I could do before the timer reached some reasonable value (say 5 seconds). I then report the number of calls/sec I can make by dividing these values. I had difficulty converting this to use the profiler code because of the small run-time of the routine. Using a timer inside my for loop just resulted in timer underflows. I think what I'm looking for is a way to bump the "count" portion of the counted_sum for a profiler without stopping it. -- Caleb Epstein caleb dot epstein at gmail dot com

How about this alternative. The profiler stores its own counter which defaults to 1. It implements an operator++ or a suitably named method (iterations? count?). then the on_* interfaces would receive a counted_sum object instead of just a duration_t. Basically, I'm looking for the ability to use a single instance of a profiler to collect stats for number of operations each of which are too brief to profile on their own, but when taken in aggregate you get meaningful data. Does this make sense? -- Caleb Epstein caleb dot epstein at gmail dot com

On Sun, 13 Feb 2005 19:42:18 -0500, christopher diggins <cdiggins@videotron.ca> wrote:

...

Basically, I'm looking for the ability to use a single instance of a profiler to collect stats for number of operations each of which are too brief to profile on their own, but when taken in aggregate you get meaningful data.

Does this make sense?

Actually I am a little confused, sorry. If the operation is too brief, do you mean it underflows? An aggregate which includes even a single underflow would be inaccurate, if that is what you intend to do. However, I am probably just confused.

Basically I want to keep a counter + timer running until the timer has reached some statistically valid value so I can divide timer / counter and get an average time-per-operation. I don't plan to start and stop the timer for each call, but keep it running until I've collected enough data. Here's an f'rinstance using boost::timer: size_t iterations = 0; boost::timer t; while (t.elapsed () < 1.0) { size_t i; for (i = 0; i < 100000; ++i) { do_some_fast_call (); } iterations += i; } double elapsed = t.elapsed (); std::cout << "do_some_fast_call: " << iterations << " calls in " << elapsed << " seconds: " << std::fixed << (iterations / elapsed) << " calls/sec, " << std::fixed << (elapsed / iterations) << " sec/call" << std::endl; I realize this collects some overhead due to the while/for loops, but the bulk of the processing should be do_some_fast_call. With the profiler, I can't do this "natively". If I add a profiler inside my 'for' loop, I will get underflows on each iteration (and I'll need to disable logging to keep the default IO from overwhelming my timings). If I use a profiler outside the loop, it will only report a single iteration, not the many tens/hundreds of thousands that actually happened. -- Caleb Epstein caleb dot epstein at gmail dot com

----- Original Message ----- From: "Preston A. Elder" <prez@neuromancy.net> To: <boost@lists.boost.org> Sent: Friday, February 11, 2005 6:05 PM Subject: [boost] Re: Re: Re: Profiling Library suggestion

On Fri, 11 Feb 2005 17:41:16 -0500, Caleb Epstein wrote:

...

One subtle difference is that the current implementation uses CPU-cycle timings (via std::clock or Win32 QueryPerformanceCounter) and not wall-clock timings. Using the xtime_get approach would give you a wall-clock based timer which may not be what you want.

I thought boost::timer (which the high_res_timer is modelled on) used wall clock values though. This makes sense, because if you're using the timer to say "X task to Y seconds", you hardly want to tell them how much CPU time it spent on it. It would look odd to use a timer that told the user X task took 20 seconds, when its been over a minute, it just got 20s CPU time.

This is basically something that needs to be decided, though I suppose policies could take care of it (wall_clock or cpu_time for accumulation), but do you want to profile how long it took something to run, or how much time was spent doing it? As you say, they're subtly different things.

I am confused. I don't see how measuring time intervals with either xtime_get() or QueryPerformanceCounter or std::clock() would differ apart from resolution and accuracy. CD

----- Original Message ----- From: "Preston A. Elder" <prez@neuromancy.net> To: <boost@lists.boost.org> Sent: Friday, February 11, 2005 7:57 PM Subject: [boost] Re: Re: Re: Re: Profiling Library suggestion

On Fri, 11 Feb 2005 19:30:36 -0500, christopher diggins wrote:

...

I am confused. I don't see how measuring time intervals with either xtime_get() or QueryPerformanceCounter or std::clock() would differ apart from resolution and accuracy.

xtime_get retrieves the current wall clock time. This means that a difference between xtime_get values will tell you the actual amount of seconds passed, you could duplicate its results with your watch.

std::clock() and I assume QueryPerformanceCounter() give you an amount of clock ticks. This number is only incremented when the CPU works on your task.

Does "your task" here mean the current thread or does it mean the current process (or does it depend)?

Say you have a very highly loaded system, 100% CPU usage, lots of threads (say, 1000), you name it.

The std::clock() difference would be very different from the xtime_get difference. Why? Because under those circumstances, the kernel may only get to run your task infrequently, and may not give it as much CPU time as it would get on a system with no load.

Therefore, std::clock() is saying 'this is how much of the kernel CPU timeslice I got', where as xtime_get is telling you what the current time is, regardless of how much or how little CPU time the kernel is allocating to your process.

I don't know of any windows commandline utilities to track this, but If you, say, had an application on linux/unix and ran 'time' on it, like so:

time tar xvfz ../mtxdrivers-rh9.0-v1.1.0-pro-beta.tar.gz

You would get the following output:

real 0m0.414s user 0m0.166s sys 0m0.104s

The 'real' is how much the difference between the wall clock times at the start and end of the task.

The user and sys are how much time in 'CPU seconds' (aka. how many CPU clock cycles) the application was given to perform its task ('user' being how much time the user-space portion of the code used, and 'sys' being how much time the kernel took to execute its part of it (eg. disk I/O, etc).

As you can see, the real time is greater than the sum of the other two because the kernel did not give the application 1 whole CPU to use for the entire duration of the application.

So xtime_get is equivalent to 'real', and std::clock() is equivalent to 'user + sys'. Otherwise known as 'how long did this run for?' and 'how long did this take two run?', which are different questions :)

Assuming the kernel gave the application 1 whole CPU to use from start to end of the application's invocation, they would be equal. This rarely happens.

Thank you very much for the explanation. What advantage would wall-clock-time have for profiling tasks? Christopher Diggins Object Oriented Template Library (OOTL) http://www.ootl.org

On Fri, 11 Feb 2005 19:57:56 -0500, Preston A. Elder <prez@neuromancy.net> wrote:

On Fri, 11 Feb 2005 19:30:36 -0500, christopher diggins wrote: [...] std::clock() and I assume QueryPerformanceCounter() give you an amount of clock ticks. This number is only incremented when the CPU works on your task. AFAIK your assumption is wrong.

The only problem with QueryPerformanceCounter() is that it can "jump" on some chipsets. A good idea is to use a "control timer" with lower frequency (or just timeBeginPeriod() + timeGetTime(), if its precision is good enough for the task). Michael

...

...

On Fri, 11 Feb 2005 19:30:36 -0500, christopher diggins wrote: [...] std::clock() and I assume QueryPerformanceCounter() give you an amount of clock ticks. This number is only incremented when the CPU works on your task.

AFAIK your assumption is wrong.

http://msdn.microsoft.com/library/default.asp?url=/library/en-us/winui/winui... watch the line wrap. QueryPerformanceCounter uses the CPU clock and is not per task but system wide.

Can you point me to documentation which supports your assertion?

...

The only problem with QueryPerformanceCounter() is that it can "jump" on some chipsets.

I believe this problem is perhaps not restricted to QueryPerformanceCounter() but to any counter counting mechanism, as the problem is at the chipset level not the API level.

No, there is a very particualar problem relating to QueryPerformanceCounter() on some (old?) chipsets the can cause it go backwards in time and wrap after approximately 20 minutes. I reported this to microsoft some years ago and it was confirmed an issue. (at the time only happened to me on one particualar celeron / motherboard configuration). By backwards in time I mean you could call the counter in a loop and have a reported time earlier than one got the previous iteration. This bit me on commercial code and I resorted to timeBeginPeriod(1); timeGetTime(); instead with no issues. Martin

Really?

Unfortuantely yes ;( Not sure if any of these motherboards are still in widespread use though. Martin

----- Original Message ----- From: "Beman Dawes" <bdawes@acm.org> To: <boost@lists.boost.org>; <boost@lists.boost.org> Sent: Friday, February 18, 2005 5:00 PM Subject: Re: [boost] Re: Re: Re: Re: Profiling Library suggestion

At 07:30 PM 2/13/2005, christopher diggins wrote:

...

...

iteration.

Really? That is different than the issue documentation I found at http://support.microsoft.com/default.aspx?scid=kb;EN-US;q274323 which stats that the QueryPerformanceCounter() can jump *ahead* a few seconds. I wonder if the status of the issue has changed to this new version or the documentation just sux.

There is another problem with QueryPerformanceCounter(); the latency (time spent executing the call itself) varies dramatically depending on (1) the version on Windows, and (2) which compiler was used. Why the compiler should have a strong effect on the latency of an API call is a mystery.

John Maddock and I ran some tests several years ago, and both of us could reproduce the effects. I recently downloaded some timing code written by someone else, tried it with several compilers and the effect still appears to exist with current compilers. So be careful, and be sure to test with different versions of Windows and different compilers.

--Beman

Thanks for the advice Beman. I would like to submit the profiler library to boost *without* a high-resolution timer, and rather only provide the guarantee of satsifactory performance when used with boost::timer. I am using a policy driven design and the user can supply an arbitrary timer class which models boost::timer. I see timers as a separate problem from the profiler, that I don't want to get into. What do you think, would this kill the chances of a profiler ever becoming part of boost? best, Christopher

From: "Preston A. Elder" <prez@neuromancy.net>

I don't know of any windows commandline utilities to track this, but If you, say, had an application on linux/unix and ran 'time' on it, like so:

time tar xvfz ../mtxdrivers-rh9.0-v1.1.0-pro-beta.tar.gz

You would get the following output:

real 0m0.414s user 0m0.166s sys 0m0.104s

The 'real' is how much the difference between the wall clock times at the start and end of the task.

The user and sys are how much time in 'CPU seconds' (aka. how many CPU clock cycles) the application was given to perform its task ('user' being how much time the user-space portion of the code used, and 'sys' being how much time the kernel took to execute its part of it (eg. disk I/O, etc).

Note that the times are all reported in seconds. Whatever internal type is used to track the values, time converts it to seconds. The profiler must support the same thing, and I think it does. Whatever the timing policy uses as the timing type, the reporting policy must interpret correctly. It would be nice if there was a means to ensure they are assembled correctly so that a report of elapsed time in seconds isn't mislabeled as clock ticks. -- Rob Stewart stewart@sig.com Software Engineer http://www.sig.com Susquehanna International Group, LLP using std::disclaimer;

Christopher Diggins Object Oriented Template Library (OOTL) http://www.ootl.org ----- Original Message ----- From: "Preston A. Elder" <prez@neuromancy.net> To: <boost@lists.boost.org> Sent: Friday, February 11, 2005 4:34 PM Subject: [boost] Re: Re: Profiling Library suggestion

Hum

I don't know why, but my last e-mail on this subject went AWOL, so I'm going to re-type it (which is a shame, as it was quite long).

:(

I think the profiler is making great progress, however I still have two major issues with it.

Thanks.

First, that the policy stuff is all static. This makes it impossible for me to have two or more individual profilers going, using the same policy, but, say, a different output file, without making the policy extremely complex and doing all kinds of string matching to sort out whats what.

How would you propose doing it differently? In the latest version You can now use meta-data to associate extra tags with data to help for generating different reports. Consider the code at http://www.cdiggins.com/profiler/v2/custom_profile_manager.hpp , one can introduce a new field into meta_profile_data, which would hopefully be satisfactory for grouping profiles?

I want the 'huge', 'big' and 'small' profile instances to use different collectors that all use the same policy (accumulate and count, plus print to file every, say, 30s), but, say, output to different files. With the static nature of everything you have in there regarding this, I would need to either: a) create a separate policy just to change the output file.

Would this be so bad?

or b) in the policy, some how determine which named entries go to which accumulator, and then record as such.

And now c) add extra metadata and switch on it.

Having them separate would allow me to disable them separately, too.

One solution for disabling groups of profiles is to define multiple profile managers for the different profile groups: struct huge_profile_manager : default_profile_manager { } struct big_profile_manager : default_profile_manager { } struct small_profile_manager : default_profile_manager { } profiler<huge_profile_manager> p1; profiler<big_profile_manager> p2; profiler<small_profile_manager> p3; // turn off only big_profiles template<> struct profiler<big_profile_manager> : empty_profiler { }; (note: empty_profiler doesn't exist yet, but I will add it).

For example, I could use the 'huge' to get a general idea of what section of code on average takes the longest. Then I could drill down slightly further to find out which portion of that code is taking the longest, and then even further to find out which particular options are taking longest, and I could do it all individually.

Second is the syntax, which requires me to either declare all profiled sections ahead of time, pause them, then when I get to the part I want resume and pause them again, or use ugly scoping syntax to encapsulate multiple blocks of code.

For an example of the first, assume in the MyFunc I want every opX_* call profiled as one. The goal here is to find out, over calls to MyFunc, how much time opX_* is taking, not how many times opX_* is called and the average time for that call. Like so:

void MyFunc() { Profile p_op1("op1"), p_op2("op2"), p_op3("op3"); p_op1.pause(); p_op2.pause(); p_op3.pause();

for (i=0; i<100; ++i) { p_op1.resume(); op1_part1(); op1_part2(); p_op1.pause();

p_op2.resume(); op2_part1(); op2_part2(); p_op2.pause();

p_op3.resume(); op3_part1(); op3_part2(); p_op3.pause(); }

do_something();

for (i=0; i<100; ++i) { p_op1.resume(); op1_part1(); op1_part2(); p_op1.pause();

p_op2.resume(); op2_part1(); op2_part2(); p_op2.pause();

p_op3.resume(); op3_part1(); op3_part2(); p_op3.pause(); } }

This is the only way to get all opX_* functions accumulated together, so that the count goes up by 1 for each call to MyFunc, and the time for all instances of opX_* is added, as opposed to getting a 200 count opX_* function calls, and then the averaging being the time per call (which is not what I want in this case).

Why is this code so bad and what is the alternative?

For an example of the second, try this:

void MyFunc() { { Profile op1("op1"); op1_part1(); int rv1 = op1_part2(); }

{ Profile op2("op2"); op2_part1(); op2_part2(); }

if (rv > 30)

rv is not accessible here.

Profile::generate_report();

{ Profile op1("op1"); op1_part1(); op1_part2(); } }

Obviously, in the example, I want the profiling data done before the report generate in the report generated. And the stuff afterwards not. So I can't, as in the previous example, declare it at the beginning. Either way, the scoping operators used here are kind of ugly.

I don't follow your intent here sorry. Thanks for your feedback, CD

----- Original Message ----- From: "Rob Stewart" <stewart@sig.com> To: <boost@lists.boost.org> Cc: <boost@lists.boost.org> Sent: Monday, February 14, 2005 4:12 PM Subject: Re: [boost] Re: Re: Profiling Library suggestion

From: christopher diggins <cdiggins@videotron.ca>

...

From: "Preston A. Elder" <prez@neuromancy.net>

...

First, that the policy stuff is all static. This makes it impossible for me to have two or more individual profilers going, using the same policy, but, say, a different output file, without making the policy extremely complex and doing all kinds of string matching to sort out whats what.

How would you propose doing it differently?

I think he is referring to the approach of deriving from the policies such that they can have non-static data members. This also means that you would typically call the policy member functions without qualifying them with the policy class name.

What do you think of the idea of passing of pointers to profile_manager variables to the profilers? Christopher Diggins Object Oriented Template Library (OOTL) http://www.ootl.org

From: christopher diggins <cdiggins@videotron.ca>

What do you think of the idea of passing of pointers to profile_manager variables to the profilers?

I have not followed that part of the discussion well enough to provide any feedback. Sorry. -- Rob Stewart stewart@sig.com Software Engineer http://www.sig.com Susquehanna International Group, LLP using std::disclaimer;