Logging fix

include/fc/log/log_message.hpp

@@ -11,10 +11,10 @@
 
 namespace fc
 {
-   namespace detail 
-   { 
-       class log_context_impl; 
-       class log_message_impl; 
+   namespace detail
+   {
+      class log_context_impl;
+      class log_message_impl;
    }
 
    /**
@@ -24,19 +24,19 @@ namespace fc
    {
       public:
          /**
-          * @brief Define's the various log levels for reporting.  
+          * @brief Define's the various log levels for reporting.
           *
-          * Each log level includes all higher levels such that 
+          * Each log level includes all higher levels such that
           * Debug includes Error, but Error does not include Debug.
           */
          enum values
          {
-             all, 
-             debug, 
-             info, 
-             warn, 
-             error, 
-             off  
+            all,
+            debug,
+            info,
+            warn,
+            error,
+            off
          };
          log_level( values v = off ):value(v){}
          explicit log_level( int v ):value( static_cast<values>(v)){}
@@ -53,14 +53,14 @@ namespace fc
     *
     *  @see FC_LOG_CONTEXT
     */
-   class log_context 
+   class log_context
    {
       public:
         log_context();
         log_context( log_level ll,
-                    const char* file, 
-                    uint64_t line, 
-                    const char* method );
+                     const char* file,
+                     uint64_t line,
+                     const char* method );
         ~log_context();
         explicit log_context( const variant& v, uint32_t max_depth );
         variant to_variant( uint32_t max_depth )const;
@@ -108,16 +108,16 @@ namespace fc
       public:
          log_message();
          /**
-          *  @param ctx - generally provided using the FC_LOG_CONTEXT(LEVEL) macro 
+          *  @param ctx - generally provided using the FC_LOG_CONTEXT(LEVEL) macro
           */
          log_message( log_context ctx, std::string format, variant_object args = variant_object() );
          ~log_message();
 
          log_message( const variant& v, uint32_t max_depth );
          variant        to_variant(uint32_t max_depth)const;
-                              
+
          string         get_message()const;
-                              
+
          log_context    get_context()const;
          string         get_format()const;
          variant_object get_data()const;
@@ -148,7 +148,7 @@ FC_REFLECT_TYPENAME( fc::log_message );
  */
 #define FC_LOG_CONTEXT(LOG_LEVEL) \
    fc::log_context( fc::log_level::LOG_LEVEL, __FILE__, __LINE__, __func__ )
-   
+
 /**
  * @def FC_LOG_MESSAGE(LOG_LEVEL,FORMAT,...)
  *
@@ -159,5 +159,7 @@ FC_REFLECT_TYPENAME( fc::log_message );
  * @param ...  A set of key/value pairs denoted as ("key",val)("key2",val2)...
  */
 #define FC_LOG_MESSAGE( LOG_LEVEL, FORMAT, ... ) \
-   fc::log_message( FC_LOG_CONTEXT(LOG_LEVEL), FORMAT, fc::limited_mutable_variant_object(FC_MAX_LOG_OBJECT_DEPTH)__VA_ARGS__ )
+   fc::log_message( FC_LOG_CONTEXT(LOG_LEVEL), \
+                    FORMAT, \
+                    fc::limited_mutable_variant_object( FC_MAX_LOG_OBJECT_DEPTH, true )__VA_ARGS__ )
 

include/fc/log/logger.hpp

@@ -5,7 +5,7 @@
 #include <fc/shared_ptr.hpp>
 #include <fc/log/log_message.hpp>
 
-namespace fc  
+namespace fc
 {
 
    class appender;
@@ -14,13 +14,13 @@ namespace fc
     *
     *
     @code
-      void my_class::func() 
+      void my_class::func()
       {
          fc_dlog( my_class_logger, "Format four: ${arg}  five: ${five}", ("arg",4)("five",5) );
       }
     @endcode
     */
-   class logger 
+   class logger
    {
       public:
          static logger get( const fc::string& name = "default");
@@ -149,19 +149,46 @@ namespace fc
   BOOST_PP_LPAREN() BOOST_PP_STRINGIZE(base),fc::variant(base,FC_MAX_LOG_OBJECT_DEPTH) BOOST_PP_RPAREN()
 
 #define FC_FORMAT( SEQ )\
-    BOOST_PP_SEQ_FOR_EACH( FC_FORMAT_ARG, v, SEQ ) 
+    BOOST_PP_SEQ_FOR_EACH( FC_FORMAT_ARG, v, SEQ )
 
-// takes a ... instead of a SEQ arg because it can be called with an empty SEQ 
+// takes a ... instead of a SEQ arg because it can be called with an empty SEQ
 // from FC_CAPTURE_AND_THROW()
 #define FC_FORMAT_ARG_PARAMS( ... )\
-    BOOST_PP_SEQ_FOR_EACH( FC_FORMAT_ARGS, v, __VA_ARGS__ ) 
+    BOOST_PP_SEQ_FOR_EACH( FC_FORMAT_ARGS, v, __VA_ARGS__ )
 
+#define FC_DUMP_FORMAT_ARG_NAME(r, unused, base) \
+   "(" BOOST_PP_STRINGIZE(base) ")"
+
+#define FC_DUMP_FORMAT_ARG_NAMES( SEQ )\
+   BOOST_PP_SEQ_FOR_EACH( FC_DUMP_FORMAT_ARG_NAME, v, SEQ )
+
+// TODO FC_FORMAT_ARG_PARAMS(...) may throw exceptions when calling fc::variant(...) inside,
+//      as a quick-fix / workaround, we catch all exceptions here.
+//      However, to log as much info as possible, it's better to catch exceptions when processing each argument
 #define idump( SEQ ) \
-    ilog( FC_FORMAT(SEQ), FC_FORMAT_ARG_PARAMS(SEQ) )  
+{ \
+   try { \
+      ilog( FC_FORMAT(SEQ), FC_FORMAT_ARG_PARAMS(SEQ) ); \
+   } catch( ... ) { \
+      ilog ( "[ERROR: Got exception while trying to dump ( ${args} )]",("args",FC_DUMP_FORMAT_ARG_NAMES(SEQ)) ); \
+   } \
+}
 #define wdump( SEQ ) \
-    wlog( FC_FORMAT(SEQ), FC_FORMAT_ARG_PARAMS(SEQ) )  
+{ \
+   try { \
+      wlog( FC_FORMAT(SEQ), FC_FORMAT_ARG_PARAMS(SEQ) ); \
+   } catch( ... ) { \
+      wlog ( "[ERROR: Got exception while trying to dump ( ${args} )]",("args",FC_DUMP_FORMAT_ARG_NAMES(SEQ)) ); \
+   } \
+}
 #define edump( SEQ ) \
-    elog( FC_FORMAT(SEQ), FC_FORMAT_ARG_PARAMS(SEQ) )  
+{ \
+   try { \
+      elog( FC_FORMAT(SEQ), FC_FORMAT_ARG_PARAMS(SEQ) ); \
+   } catch( ... ) { \
+      elog ( "[ERROR: Got exception while trying to dump ( ${args} )]",("args",FC_DUMP_FORMAT_ARG_NAMES(SEQ)) ); \
+   } \
+}
 
 // this disables all normal logging statements -- not something you'd normally want to do,
 // but it's useful if you're benchmarking something and suspect logging is causing
@@ -177,4 +204,4 @@ namespace fc
 # define ilog(...) FC_MULTILINE_MACRO_BEGIN FC_MULTILINE_MACRO_END
 # undef dlog
 # define dlog(...) FC_MULTILINE_MACRO_BEGIN FC_MULTILINE_MACRO_END
-#endif
+#endif

include/fc/variant_object.hpp

@@ -221,18 +221,35 @@ namespace fc
    class limited_mutable_variant_object : public mutable_variant_object
    {
       public:
-         limited_mutable_variant_object( uint32_t max_depth );
+         limited_mutable_variant_object( uint32_t max_depth, bool skip_on_exception = false );
 
          template<typename T>
          limited_mutable_variant_object& operator()( string key, T&& var )
          {
-            set( std::move(key), variant( fc::forward<T>(var), _max_depth ) );
+            if( _reached_depth_limit )
+               // _skip_on_exception will always be true here
+               return *this;
+
+            optional<variant> v;
+            try
+            {
+               v = variant( fc::forward<T>(var), _max_depth );
+            }
+            catch( ... )
+            {
+               if( !_skip_on_exception )
+                  throw;
+               v = variant( "[ERROR: Caught exception while converting data to variant]" );
+            }
+            set( std::move(key), *v );
             return *this;
          }
          limited_mutable_variant_object& operator()( const variant_object& vo );
 
       private:
-         const uint32_t _max_depth;
+         const uint32_t _max_depth;       ///< The depth limit
+         const bool _reached_depth_limit; ///< Indicates whether we've reached depth limit
+         const bool _skip_on_exception;   ///< If set to true, won't rethrow exceptions when reached depth limit
    };
 
    /** @ingroup Serializable */

src/variant_object.cpp

@@ -365,15 +365,35 @@ namespace fc
       return *this;
    }
 
-   limited_mutable_variant_object::limited_mutable_variant_object( uint32_t m )
-         : mutable_variant_object(), _max_depth(m - 1)
+   limited_mutable_variant_object::limited_mutable_variant_object( uint32_t m, bool skip_on_exception )
+         : mutable_variant_object(),
+           _max_depth(m - 1),
+           _reached_depth_limit(m == 0),
+           _skip_on_exception(skip_on_exception)
    {
-      FC_ASSERT( m > 0, "Recursion depth exceeded!" );
+      if( !skip_on_exception )
+         FC_ASSERT( m > 0, "Recursion depth exceeded!" );
+      else if( m == 0 )
+         set( "__err_msg", "[ERROR: Recusion depth exceeded!]" );
    }
 
    limited_mutable_variant_object& limited_mutable_variant_object::operator()( const variant_object& vo )
    {
-      mutable_variant_object::operator()( vo );
+      if( _reached_depth_limit )
+         // _skip_on_exception will always be true here
+         return *this;
+
+      try
+      {
+         mutable_variant_object::operator()( vo );
+      }
+      catch( ... )
+      {
+         if( !_skip_on_exception )
+            throw;
+         else
+            set( "__err_msg", "[ERROR: Caught exception in operator()( const variant_object& ).]" );
+      }
       return *this;
    }
 

tests/CMakeLists.txt

@@ -59,5 +59,6 @@ add_executable( all_tests all_tests.cpp
                           serialization_test.cpp
                           time_test.cpp
                           utf8_test.cpp
+                          variant_test.cpp
                           )
 target_link_libraries( all_tests fc )