https://svn.lrde.epita.fr/svn/oln/trunk/milena Index: ChangeLog from Thierry Geraud <thierry.geraud@lrde.epita.fr> Fix timer in trace entering/exiting. * mln/trace/quiet.hh: Layout. * mln/trace/exiting.hh: Rely on clock. * mln/trace/entering.hh (start_times, scopes): New. (entering): Use clock instead of gettimeofday. entering.hh | 15 ++++++++++++++- exiting.hh | 38 ++++++++++++++++++++++++++++++++++---- quiet.hh | 1 + 3 files changed, 49 insertions(+), 5 deletions(-) Index: mln/trace/quiet.hh --- mln/trace/quiet.hh (revision 3220) +++ mln/trace/quiet.hh (working copy) @@ -56,6 +56,7 @@ } // end of namespace mln::trace::internal + # ifndef MLN_INCLUDE_ONLY bool quiet = true; Index: mln/trace/exiting.hh --- mln/trace/exiting.hh (revision 3220) +++ mln/trace/exiting.hh (working copy) @@ -47,6 +47,8 @@ void exiting(const std::string& scope); + + # ifndef MLN_INCLUDE_ONLY inline @@ -55,8 +57,22 @@ if (quiet) return; - timeval after_time; - gettimeofday(&after_time, 0); + if (scopes.empty()) + { + std::cerr << "error: missing 'entering' scope (exiting is '" << scope << "')" << std::endl; + quiet = true; + } + else + { + if (scopes.top() != scope) + { + std::cerr << "error: bad matching scope (entering is '" << scopes.top() + << "' v. exiting is '" << scope << "')" << std::endl; + quiet = true; + } + scopes.pop(); + } + bool has_inner_trace = (internal::max_tab == tab); --tab; @@ -69,9 +85,23 @@ if (!has_inner_trace) std::cout << scope << " "; + mln_assertion(! start_times.empty()); + std::clock_t now = std::clock(); + + if (start_times.top() > now) + { + std::cerr << "warning: bad timer in trace handling" << std::endl; + // FIXME: So what? + } + + if (start_times.top() < now) + { std::cout << "- " - << (after_time.tv_usec - internal::start_time.tv_usec) / 1000. - << "ms "; + << ((float(now) - float(start_times.top())) / CLOCKS_PER_SEC) + << "s "; + } + + start_times.pop(); if (has_inner_trace || (internal::max_tab - tab > 1)) std::cout << std::endl; Index: mln/trace/entering.hh --- mln/trace/entering.hh (revision 3220) +++ mln/trace/entering.hh (working copy) @@ -35,6 +35,8 @@ # include <string> # include <iostream> +# include <stack> +# include <ctime> # include <mln/trace/quiet.hh> @@ -47,14 +49,26 @@ void entering(const std::string& scope); + extern std::stack<std::clock_t> start_times; + extern std::stack<std::string> scopes; // For testing purpose + // (entering/exiting scope matching). + + # ifndef MLN_INCLUDE_ONLY + std::stack<std::clock_t> start_times; + std::stack<std::string> scopes; + + inline void entering(const std::string& scope) { if (quiet) return; + start_times.push(std::clock()); + scopes.push(scope); + if ((tab != 0) && (internal::max_tab == tab)) std::cout << std::endl; @@ -63,7 +77,6 @@ std::cout << scope << " {"; internal::max_tab = ++tab; - gettimeofday(&internal::start_time, 0); } # endif // ! MLN_INCLUDE_ONLY