[Olena-patches] olena-2.0-451-gd86fc9a Improve time logging in Scribo.

* scribo/debug/logger.hh: Use a stack to handle several simultaneous logs. * scribo/binarization/sauvola_ms.hh: Fix an invalid time stop. * scribo/binarization/internal/local_threshold_core.hh, * src/binarization/sauvola.cc, * src/binarization/sauvola_ms.cc, * src/binarization/sauvola_ms_debug.cc: Rename time logging functions. --- milena/mln/util/timer.hh | 15 ++++- scribo/ChangeLog | 15 +++++ .../binarization/internal/local_threshold_core.hh | 8 +- scribo/scribo/binarization/sauvola_ms.hh | 21 +++---- scribo/scribo/debug/logger.hh | 59 +++++++------------ scribo/src/binarization/sauvola.cc | 4 +- scribo/src/binarization/sauvola_ms.cc | 4 +- scribo/src/binarization/sauvola_ms_debug.cc | 4 +- 8 files changed, 70 insertions(+), 60 deletions(-) diff --git a/milena/mln/util/timer.hh b/milena/mln/util/timer.hh index 4fbca3d..7afff72 100644 --- a/milena/mln/util/timer.hh +++ b/milena/mln/util/timer.hh @@ -1,4 +1,4 @@ -// Copyright (C) 2008, 2009, 2011 EPITA Research and Development +// Copyright (C) 2008, 2009, 2011, 2013 EPITA Research and Development // Laboratory (LRDE) // // This file is part of Olena. @@ -49,8 +49,11 @@ namespace mln timer(); + // Explicit copy constructor (in most cases should not be + // used...). + explicit timer(const timer&); + // Without impl. - timer(const timer&); void operator=(const timer&); ~timer(); @@ -102,6 +105,14 @@ namespace mln } inline + timer::timer(const timer& t) + { + running_ = t.running_; + start_ = t.start_; + time_ = t.time_; + } + + inline timer::~timer() { reset(); diff --git a/scribo/ChangeLog b/scribo/ChangeLog index a438ae0..d7e7547 100644 --- a/scribo/ChangeLog +++ b/scribo/ChangeLog @@ -1,3 +1,18 @@ +2013-04-02 Guillaume Lazzara &lt;lazzara(a)caroussel.lrde.epita.fr&gt; + + Improve time logging in Scribo. + + * scribo/debug/logger.hh: Use a stack to handle several + simultaneous logs. + + * scribo/binarization/sauvola_ms.hh: Fix an invalid time stop. + + * scribo/binarization/internal/local_threshold_core.hh, + * src/binarization/sauvola.cc, + * src/binarization/sauvola_ms.cc, + * src/binarization/sauvola_ms_debug.cc: Rename time logging + functions. + 2013-03-26 Guillaume Lazzara &lt;z(a)lrde.epita.fr&gt; Small fixes in scribo. diff --git a/scribo/scribo/binarization/internal/local_threshold_core.hh b/scribo/scribo/binarization/internal/local_threshold_core.hh index 5de9761..16dc1be 100644 --- a/scribo/scribo/binarization/internal/local_threshold_core.hh +++ b/scribo/scribo/binarization/internal/local_threshold_core.hh @@ -127,7 +127,7 @@ namespace scribo mln_trace("scribo::binarization::internal::impl::generic::local_threshold_core"); mln_precondition(exact(input).is_valid()); - scribo::debug::logger().start_local_time_logging(); + scribo::debug::logger().start_time_logging(); int integral_scale_ratio = F::step; @@ -148,7 +148,7 @@ namespace scribo sub_domains[2].first(), sub_domains[2].second()); - scribo::debug::logger().stop_local_time_logging("image integrale -"); + scribo::debug::logger().stop_time_logging("image integrale -"); # ifdef SCRIBO_LOCAL_THRESHOLD_DEBUG initialize(internal::debug_mean, input); @@ -159,7 +159,7 @@ namespace scribo initialize(internal::debug_alphacond, input); # endif // ! SCRIBO_LOCAL_THRESHOLD_DEBUG - scribo::debug::logger().start_local_time_logging(); + scribo::debug::logger().start_time_logging(); window_size /= integral_scale_ratio; if (window_size % 2) @@ -171,7 +171,7 @@ namespace scribo window_size, integral_scale_ratio, f); - scribo::debug::logger().stop_local_time_logging("Binarization -"); + scribo::debug::logger().stop_time_logging("Binarization -"); } diff --git a/scribo/scribo/binarization/sauvola_ms.hh b/scribo/scribo/binarization/sauvola_ms.hh index 6a9751c..70df030 100644 --- a/scribo/scribo/binarization/sauvola_ms.hh +++ b/scribo/scribo/binarization/sauvola_ms.hh @@ -878,7 +878,7 @@ namespace scribo typedef image2d<mln::util::couple<double,double> > integral_t; // integral_t integral_sum_sum_2; - scribo::debug::logger().start_local_time_logging(); + scribo::debug::logger().start_time_logging(); // Subsampling from scale 1 to 2. { @@ -891,8 +891,8 @@ namespace scribo sub_ima.append(fi.sub); } - scribo::debug::logger().stop_local_time_logging("1. subsampling and integral -"); - scribo::debug::logger().start_local_time_logging(); + scribo::debug::logger().stop_time_logging("1. subsampling and integral -"); + scribo::debug::logger().start_time_logging(); // Subsampling to scale 3 and 4. // @@ -903,8 +903,8 @@ namespace scribo sub_domains[i].first(), sub_domains[i].second())); - scribo::debug::logger().stop_local_time_logging("2. More subsampling -"); - scribo::debug::logger().start_local_time_logging(); + scribo::debug::logger().stop_time_logging("2. More subsampling -"); + scribo::debug::logger().start_time_logging(); // Compute threshold images. image2d<int_u8> e_2; @@ -963,8 +963,8 @@ namespace scribo integral_sum_sum_2); } - scribo::debug::logger().stop_local_time_logging("3. Multi-scale processing -"); - scribo::debug::logger().start_local_time_logging(); + scribo::debug::logger().stop_time_logging("3. Multi-scale processing -"); + scribo::debug::logger().start_time_logging(); # ifdef SCRIBO_LOCAL_THRESHOLD_DEBUG @@ -980,8 +980,8 @@ namespace scribo // Propagate scale values. e_2 = transform::influence_zone_geodesic(e_2, c8()); - scribo::debug::logger().stop_local_time_logging("4. Influence Zone on Scale image -"); - scribo::debug::logger().start_local_time_logging(); + scribo::debug::logger().stop_time_logging("4. Influence Zone on Scale image -"); + scribo::debug::logger().start_time_logging(); # ifdef SCRIBO_LOCAL_THRESHOLD_DEBUG @@ -1015,8 +1015,7 @@ namespace scribo image2d<bool> output = internal::multi_scale_binarization(input_1, e_2, t_ima, s); - scribo::debug::logger().stop_local_time_logging("5. Final binarization -"); - scribo::debug::logger().start_local_time_logging(); + scribo::debug::logger().stop_time_logging("5. Final binarization -"); return output; } diff --git a/scribo/scribo/debug/logger.hh b/scribo/scribo/debug/logger.hh index b65b04a..0b29aaf 100644 --- a/scribo/scribo/debug/logger.hh +++ b/scribo/scribo/debug/logger.hh @@ -31,6 +31,7 @@ #ifndef SCRIBO_CORE_LOGGER_HH # define SCRIBO_CORE_LOGGER_HH +# include <stack> # include <iostream> # include <ctype.h> # include <mln/core/concept/image.hh> @@ -139,24 +140,15 @@ namespace scribo /*! \brief Time Logging - This class provides two timers in order to performs - benchmarks inside a program. - - Local time logging is meant to be used for benchmarking a - small portion of code, whereas global time logging is meant - to benchmark a whole program. - - They can be used both at the same time. + This class provides timers in order to performs benchmarks + inside a program. Stopping time logging will output the computed time if Verbose mode is higher or equal to #Time. */ /// @{ - void start_local_time_logging(); - void stop_local_time_logging(const std::string& time_title); - - void start_global_time_logging(); - void stop_global_time_logging(const std::string& time_title); + void start_time_logging(); + void stop_time_logging(const std::string& time_title); /// @} @@ -171,6 +163,8 @@ namespace scribo logger_(); logger_(const logger_&); + ~logger_(); + template <unsigned n, typename I> void log_image_dispatch(const value::int_u<n>&, const Image<I>& ima, const char *name); @@ -209,8 +203,7 @@ namespace scribo std::string verbose_prefix_; std::ostream& stream_; - mln::util::timer t_local_; - mln::util::timer t_global_; + std::stack<mln::util::timer> t_locals_; }; } // end of namespace scribo::debug::internal @@ -264,6 +257,12 @@ namespace scribo abort(); } + inline + logger_::~logger_() + { + // If this is not True, then a timer has not been stopped! + mln_assertion(t_locals_.size() == 0); + } inline bool @@ -410,37 +409,23 @@ namespace scribo inline void - logger_::start_local_time_logging() + logger_::start_time_logging() { - t_local_.restart(); + t_locals_.push(mln::util::timer()); + t_locals_.top().restart(); } inline void - logger_::stop_local_time_logging(const std::string& time_title) + logger_::stop_time_logging(const std::string& time_title) { - t_local_.stop(); - if (verbose_mode_ >= Time) - std::cerr << time_title << " " << t_local_ << "s" << std::endl; - } - + mln_assertion(! t_locals_.empty()); - inline - void - logger_::start_global_time_logging() - { - t_global_.restart(); - } - - - inline - void - logger_::stop_global_time_logging(const std::string& time_title) - { - t_global_.stop(); + t_locals_.top().stop(); if (verbose_mode_ >= Time) - std::cerr << time_title << " " << t_global_ << "s" << std::endl; + std::cerr << time_title << " " << t_locals_.top() << "s" << std::endl; + t_locals_.pop(); } diff --git a/scribo/src/binarization/sauvola.cc b/scribo/src/binarization/sauvola.cc index aa66565..603b815 100644 --- a/scribo/src/binarization/sauvola.cc +++ b/scribo/src/binarization/sauvola.cc @@ -95,12 +95,12 @@ int main(int argc, char *argv[]) image2d<value::int_u8> input_1_gl = data::transform(input, mln::fun::v2v::rgb_to_luma<value::int_u8>()); - scribo::debug::logger().start_local_time_logging(); + scribo::debug::logger().start_time_logging(); // Binarize image2d<bool> out = scribo::binarization::sauvola(input_1_gl, w, k); - scribo::debug::logger().stop_local_time_logging("Binarized in"); + scribo::debug::logger().stop_time_logging("Binarized in"); io::magick::save(out, options.arg("output.*")); diff --git a/scribo/src/binarization/sauvola_ms.cc b/scribo/src/binarization/sauvola_ms.cc index 3b51dad..c81509c 100644 --- a/scribo/src/binarization/sauvola_ms.cc +++ b/scribo/src/binarization/sauvola_ms.cc @@ -138,13 +138,13 @@ int main(int argc, char *argv[]) mln::fun::v2v::rgb_to_luma<value::int_u8>()); - scribo::debug::logger().start_local_time_logging(); + scribo::debug::logger().start_time_logging(); // Binarize image2d<bool> output = scribo::binarization::sauvola_ms(input_1_gl, w_1, s); - scribo::debug::logger().stop_local_time_logging("Binarized in"); + scribo::debug::logger().stop_time_logging("Binarized in"); if (options.is_enabled("negate")) io::magick::save(logical::not_(output), options.arg("output.*")); diff --git a/scribo/src/binarization/sauvola_ms_debug.cc b/scribo/src/binarization/sauvola_ms_debug.cc index d01a4a2..b940b43 100644 --- a/scribo/src/binarization/sauvola_ms_debug.cc +++ b/scribo/src/binarization/sauvola_ms_debug.cc @@ -172,13 +172,13 @@ int main(int argc, char *argv[]) input_1_gl = data::transform(input_1, mln::fun::v2v::rgb_to_luma<value::int_u8>()); - scribo::debug::logger().start_local_time_logging(); + scribo::debug::logger().start_time_logging(); // Binarize. image2d<bool> output = scribo::binarization::sauvola_ms(input_1_gl, w_1, s); - scribo::debug::logger().stop_local_time_logging("Binarized in"); + scribo::debug::logger().stop_time_logging("Binarized in"); # ifdef SCRIBO_LOCAL_THRESHOLD_DEBUG { -- 1.7.2.5