[test] RFC: speed up BOOST_CHECK by not formatting the check description if it isn't written anywhere

Hello,

I have a test that uses many BOOST_CHECKs (~ 10 thousands or so). Running that test is very slow and I have
noticed most of the time is spent by formatting the description string to be passed to check_impl, only to
be ignored, because I don't want to log successful checks (and they are successful).

I have improved this by using some kind of expression template for this (called lazy_output). It works like this:

lazy_output is a class that implements an expression template for "x << y << z" expressions. The expression

 o << a << b << c << (make_lazy_output() << x << y << z)

is the same as

 o << a << b << c << x << y << z

which is similar to

 o << a << b << c << (wrap_stringstream().ref() << x << y << z).ref()

The difference is that, in the call f(make_lazy_output() << x << y << z), the data is formatted only if f
outputs them to an ostream.

This reduced the time needed for running my test from ~12 minutes to ~7 minutes. There is more room for
similar (but more complicated) improvements.

Any comments or suggestions?

Regards
    Jiri Palecek

=== boost/test/lazy_output.hpp
==================================================================
--- boost/test/lazy_output.hpp	(revision 4821)
+++ boost/test/lazy_output.hpp	(revision 4822)
@@ -0,0 +1,74 @@
+#ifndef BOOST_TEST_LAZY_OUTPUT_HPP
+#define BOOST_TEST_LAZY_OUTPUT_HPP
+
+#include <iostream>
+
+namespace boost {
+  namespace unit_test {
+
+    class lazy_output
+    {
+      virtual void output(std::ostream& o) const=0;
+    public:
+      friend std::ostream& operator <<(std::ostream& o, const lazy_output& lo) {
+        lo.output(o);
+        return o;
+      }
+    };
+
+    class lazy_output_0 : public lazy_output
+    {
+      void output(std::ostream&) const {}
+    };
+
+    template <class T>
+    class lazy_output_1 : public lazy_output
+    {
+      const T& t_;
+      void output(std::ostream& o) const;
+    public:
+      lazy_output_1(const T& t) : t_(t) {}
+    };
+
+    template <class T, class Prev>
+    class lazy_output_2 : public lazy_output
+    {
+      const T& t_;
+      Prev p_;
+      void output(std::ostream& o) const;
+    public:
+      lazy_output_2(const T& t, const Prev& p) : t_(t), p_(p) {}
+    };
+
+    template <class T>
+    void lazy_output_1<T>::output(std::ostream& o) const {
+      o << t_;
+    }
+
+    template <class T, class Prev>
+    void lazy_output_2<T, Prev>::output(std::ostream& o) const {
+      o << p_;
+      o << t_;
+    }
+
+    lazy_output_0 make_lazy_output() { return lazy_output_0(); }
+
+    template <class T>
+    lazy_output_1<T> operator<<(lazy_output_0, const T& t) {
+      return lazy_output_1<T>(t);
+    }
+
+    template <class T, class U>
+    lazy_output_2<T, lazy_output_1<U> > operator<<(const lazy_output_1<U>& l, const T& t) {
+      return lazy_output_2<T, lazy_output_1<U> >(t, l);
+    }
+
+    template <class T, class U, class Prev>
+    lazy_output_2<T, lazy_output_2<U, Prev> > operator<<(const lazy_output_2<U, Prev>& l, const T& t) {
+      return lazy_output_2<T, lazy_output_2<U, Prev> >(t, l);
+    }
+
+  }
+}
+
+#endif
=== boost/test/impl/test_tools.ipp
==================================================================
--- boost/test/impl/test_tools.ipp	(revision 4821)
+++ boost/test/impl/test_tools.ipp	(revision 4822)
@@ -62,7 +62,7 @@
 // ************************************************************************** //

 void
-check_impl( predicate_result const& pr, wrap_stringstream& check_descr,
+check_impl( predicate_result const& pr, const lazy_output& check_descr,
             const_string file_name, std::size_t line_num,
             tool_level tl, check_type ct,
             std::size_t num_of_args, ... )
@@ -107,7 +107,7 @@
     switch( ct ) {
     case CHECK_PRED:
         unit_test_log << unit_test::log::begin( file_name, line_num ) 
-                      << ll << prefix << check_descr.str() << suffix;
+                      << ll << prefix << check_descr << suffix;

         if( !pr.has_empty_message() )
             unit_test_log << ". " << pr.message();
@@ -119,9 +119,9 @@
         unit_test_log << unit_test::log::begin( file_name, line_num ) << ll;

         if( tl == PASS )
-            unit_test_log << prefix << "'" << check_descr.str() << "'" << suffix;
+            unit_test_log << prefix << "'" << check_descr << "'" << suffix;
         else
-            unit_test_log << check_descr.str();
+            unit_test_log << check_descr;

         if( !pr.has_empty_message() )
             unit_test_log << ". " << pr.message();
@@ -216,7 +216,7 @@

     case CHECK_PRED_WITH_ARGS: {
         unit_test_log << unit_test::log::begin( file_name, line_num ) 
-                      << ll << prefix << check_descr.str();
+                      << ll << prefix << check_descr;

         // print predicate call description
         {
=== boost/test/impl/unit_test_log.ipp
==================================================================
--- boost/test/impl/unit_test_log.ipp	(revision 4821)
+++ boost/test/impl/unit_test_log.ipp	(revision 4822)
@@ -352,6 +352,16 @@
     return *this;
 }

+unit_test_log_t&
+unit_test_log_t::operator<<( const lazy_output& value )
+{
+    if( s_log_impl().m_entry_data.m_level >= s_log_impl().m_threshold_level) {
+      return (*this) << (wrap_stringstream().ref() << value).str();
+    }
+
+    return *this;
+}
+
 //____________________________________________________________________________//

 void
=== boost/test/unit_test_log.hpp
==================================================================
--- boost/test/unit_test_log.hpp	(revision 4821)
+++ boost/test/unit_test_log.hpp	(revision 4822)
@@ -27,6 +27,7 @@
 #include <boost/test/utils/wrap_stringstream.hpp>
 #include <boost/test/utils/trivial_singleton.hpp>

+#include <boost/test/lazy_output.hpp>
 // Boost
 #include <boost/utility.hpp>

@@ -119,6 +120,7 @@
     unit_test_log_t&    operator<<( log::end const& );          // end entry
     unit_test_log_t&    operator<<( log_level );                // set entry level
     unit_test_log_t&    operator<<( const_string );             // log entry value
+    unit_test_log_t&    operator<<( const lazy_output& );             // log entry value

     ut_detail::entry_value_collector operator()( log_level );   // initiate entry collection

=== boost/test/test_tools.hpp
==================================================================
--- boost/test/test_tools.hpp	(revision 4821)
+++ boost/test/test_tools.hpp	(revision 4822)
@@ -49,6 +49,8 @@

 #include <boost/test/detail/suppress_warnings.hpp>

+#include <boost/test/lazy_output.hpp>
+
 //____________________________________________________________________________//

 // ************************************************************************** //
@@ -69,7 +71,7 @@
 #define BOOST_TEST_TOOL_IMPL( func, P, check_descr, TL, CT ) \
     ::boost::test_tools::tt_detail::func(                    \
         P,                                                   \
-        ::boost::wrap_stringstream().ref() << check_descr,   \
+        make_lazy_output() << check_descr,                   \
         BOOST_TEST_L(__FILE__),                              \
         (std::size_t)__LINE__,                               \
         ::boost::test_tools::tt_detail::TL,                  \
@@ -460,7 +462,7 @@
 // ************************************************************************** //

 BOOST_TEST_DECL 
-void check_impl( predicate_result const& pr, wrap_stringstream& check_descr,
+void check_impl( predicate_result const& pr, const boost::unit_test::lazy_output& check_descr,
                  const_string file_name, std::size_t line_num,
                  tool_level tl, check_type ct,
                  std::size_t num_args, ... );
@@ -486,7 +488,7 @@
 template<typename Pred                                                              \
          BOOST_PP_REPEAT_ ## z( BOOST_PP_ADD( n, 1 ), TEMPL_PARAMS, _ )>            \
 inline void                                                                         \
-check_frwd( Pred P, wrap_stringstream& check_descr,                                 \
+ check_frwd( Pred P, const boost::unit_test::lazy_output& check_descr,  \
             const_string file_name, std::size_t line_num,                           \
             tool_level tl, check_type ct                                            \
             BOOST_PP_REPEAT_ ## z( BOOST_PP_ADD( n, 1 ), FUNC_PARAMS, _ )           \

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