Menu

Migrating to the latest version

Oleg
2013-04-23
2013-06-03
1 2 > >> (Page 1 of 2)
  • Oleg

    Oleg - 2013-04-23

    We have a few custom things (attributes, formatters, sinks) written against Boost.Log version1. They all broke into pieces as soon as we tried to upgrade to the current trunk.  Is there any guide (a sample or a doc) on code migration? If there's not, I hope I won't trouble you too much if I ask for some guidance here. I'll start with the simplest thing hoping that a solution to it may shed light on more complicated ones.

    There was no way (or at least I couldn't see one) to specify a custom Timestamp formatter in the settings file. One could do it in code but not through the configuration. To work around that we added  a custom 'formatter' which is used like this:
    Format=%TimeStamp(formatter="%Y-%m-%dT%H:%M:%S%F")% %_%

    The implementation looked like this:

      

     std::string dt_fmt = "%Y-%m-%d %H:%M:%S%F";
        auto timestamp_formatter_factory = [dt_fmt](types::string_type const &attr_name_, types::formatter_factory_args const &args_)-> types::formatter_type{
          std::string f = dt_fmt;
          auto i = args_.find("formatter");
          if (i != args_.end())
            f = i->second;
          return date_time_formatter(attr_name_, f, std::nothrow);
        };
       register_formatter_factory(log_attibutes::timestamp, timestamp_formatter_factory);
    

    None of this works any more. If you have any suggestions on how this can be made to work again, they'd be greatly appreciated.

     
  • Andrey Semashev

    Andrey Semashev - 2013-04-23

    Sorry, there is no dedicated migration guide, although I probably should have written one. The list of changes is available in the changelog, there are also links to other relevant sections of the docs. I'll be glad to answer your questions if you have any.

    Regarding the custom formatter, the principle stayed the same - you have to register a formatter factory for your "Timestamp" attribute. The factory is now an object rather than a finction object, so you'll have to replace a lambda with a class. The process is described here, with a reference to the compilable example.

    Regarding formatters (and filters as well), they don't throw by default now, so you don't have to use std::nothrow anymore. Filters and formatters are now unified and implemented on top of Boost.Phoenix, so in many cases you can use phoenix::bind to inject your custom bits into expressions. The date_time_formatter should probably be replaced with a streaming expression involving the format_date_time formatter.

    I should also note that the "%_%" is deprecated now and should be replaced with "%Message%". It'll work now but I will remove it at some point.

     
  • Oleg

    Oleg - 2013-04-23

    Thanks for the prompt reply.
    My Timestamp is actually the native Boost.Log TimeStamp. I just need to be able to specify the format string in the configuration. Your suggestion worked. The only thing I had to change was the fractional seconds formatting flag: %f instead of %F in the previous version. I figure that configuring the way timestamps are output could be useful for others. So it might make sense to put this into the library itself.
    My next question is about adding custom formatting flags. We have a special formatting mode 'raw' where to avoid a performance hit, the timestamp is dumped simply as an int. (number of microsecs since epoch).  In the config it looks like this:

    Format=%TimeStamp(formatter=raw)%

    To make this work required jumping through some hoops. I had to create my own date_time formatter and intercept the 'raw' flag:

    template <typename _Char = char>
    class custom_date_time_formatter :
      public blog::formatters::aux::basic_date_time_formatter<_Char>
    {
      /*...*/
      void operator()(posix_time::ptime tm_)
      {
        static const std::string raw = "raw";
        static const posix_time::ptime epoch(boost::gregorian::date(1970,1,1));
        if (this->m_Format == raw){
          this->m_Stream << (tm_ - epoch).total_microseconds();
          this->m_Stream.flush();
        }
        else 
          base_type::operator()(tm_);
      }
    };
    

    I noticed that now there's the notion of a placeholder (on_placholder) where unknown flags get forwarded. There isn't documentation or examples on how to provide your own one, however. If you can spare us the effort of trying to figure it out, I'd be very grateful again.

     
  • Andrey Semashev

    Andrey Semashev - 2013-04-23

    I think the best way to handle this "raw" format in config files is to detect it in the formatter factory and create different formatters for different cases. As I mentioned, you can bind your own raw formatter with phoenix::bind.

    I'm not sure what placeholders (on_placholder) you're referring to.

     
  • Oleg

    Oleg - 2013-04-23

    I am referring to this

        /*!
         * \brief The method is called when an unknown placeholder is found in the format string
         *
         * \param ph The placeholder with the leading percent sign
         */
        virtual void on_placeholder(iterator_range< const char_type* > const& ph)
        {
            // By default interpret all unrecognized placeholders as literals
            on_literal(ph);
        }
    

    Do you have an example on how to bind a new formatter?

     
  • Andrey Semashev

    Andrey Semashev - 2013-04-23

    I am referring to this

    This is a part of the internal library interface, I wouldn't recommend using it unless there is no other way.

    Do you have an example on how to bind a new formatter?

    Sure, just see how point_formatter_factory is implemented on the page I linked earlier.

     
  • Oleg

    Oleg - 2013-04-24

    Thanks. This worked fine. I ended up with this:

        struct timestamp_formatter_factory : public blog::formatter_factory<char>
        {
        public:
          formatter_type create_formatter(blog::attribute_name const& name_, args_map const &args_)
          {
            std::string fmt = "%Y-%m-%d %H:%M:%S%f";
            auto i = args_.find("formatter");
            if (i != args_.end())
              fmt = i->second;
            if (fmt == "raw"){
              namespace phx = boost::phoenix;
              posix_time::ptime epoch(boost::gregorian::date(1970,1,1));              
              return phx::if_(expr::attr<posix_time::ptime>(name_))[
                expr::stream << 
                    phx::bind
                    (
                      &b::posix_time::time_duration::total_microseconds
                      ,phx::bind(&blog::value_ref<posix_time::ptime>::get, expr::attr<posix_time::ptime>(name_)) - epoch
                    )
                  ];
            }else
              return expr::stream << expr::format_date_time< boost::posix_time::ptime >(log_attibutes::timestamp, fmt);
          }
        };
    

    Another problem we ran into while porting is that the boost log formatting stream intercepts all operator << calls and explicitly forwards them to std::ostream. This will break existing code where the streaming operator for T is defined outside of T's namespace. If the goal is to enable seamless logging for anything that can stream itself to std::ostream, then this is broken. For now I put it in a hack using enable_basic_formatting_ostream_generic_insert_operator to turn off the << operator for our types.

     
  • Andrey Semashev

    Andrey Semashev - 2013-04-24

    phx::if_(expr::attr<posix_time::ptime>(name_))

    I guess, this should be

    expr::if_(expr::has_attr<posix_time::ptime>(name_))
    

    and name_ should be used instead of log_attibutes::timestamp in the format_date_time call.

    Another problem we ran into while porting is that the boost log formatting stream intercepts all operator << calls and explicitly forwards them to std::ostream. This will break existing code where the streaming operator for T is defined outside of T's namespace.

    Streaming operators should normally be found by ADL, which is possible if the operators reside in the T's namespace or at least are imported with using directives. This is a normal practice in C++ and having operators in an unrelated namespace is bound to pose problems (regardless of Boost.Log specifics). Could you describe in more details why it doesn't work for you?

     
  • Andrey Semashev

    Andrey Semashev - 2013-04-24

    Oh, I also forgot to mention. It is typically a bad idea to bind member functions of third party libraries, like time_duration::total_microseconds or value_ref::get, because their signatures may change and break your code. A better approach is to create your own function that takes the value_ref and performs the needed calculations normally. This would also simplify code.

     
  • Oleg

    Oleg - 2013-04-24

    I tried expr::if_, it didn't work.

    Streaming operators should normally be found by ADL, which is possible if the operators reside in the T's namespace or at least are imported with using directives. This is a normal practice in C++ and having operators in an unrelated namespace is bound to pose problems (regardless of Boost.Log specifics). Could you describe in more details why it doesn't work for you?

    In theory, yes. In practice, no. We have a bunch of 3rd library stuff, some of it code-generated, which don't define streaming operators where they should.
    The point is that right now not everything that compiles for std::ostream compiles for boost::log::_xxx_stream_xxx_, which adds unnecessary headaches.

     
  • Andrey Semashev

    Andrey Semashev - 2013-04-25

    I tried expr::if_, it didn't work.

    Why? What was the problem?

    The point is that right now not everything that compiles for std::ostream compiles for boost::log::_xxx_stream_xxx_

    Could you give an example of such code? If it works for std::ostream without any hassle on your side, it should also work for log::formatting_ostream.

     
  • Oleg

    Oleg - 2013-04-25

    #1.
    c:\dev\exb++.libs\boost_log\r860\common\include\boost/log/detail/light_function_pp.hpp(280): error C2064: term does not evaluate to a function taking 2 arguments
    1>          c:\dev\exb++.libs\boost_log\r860\common\include\boost/log/detail/light_function_pp.hpp(279) : while compiling class template member function 'boost::log::v2_mt_nt6::aux::light_function<SignatureT>::result_type boost::log::v2_mt_nt6::aux::light_function<SignatureT>::impl<FunT>::invoke_impl(boost::log::v2_mt_nt6::aux::light_function<SignatureT>::impl_base *,ArgT0,ArgT1)'
    1>          with
    1>          [
    1>              SignatureT=void (const boost::log::v2_mt_nt6::record_view &,boost::log::v2_mt_nt6::basic_formatting_ostream<char> &),
    1>              FunT=boost::log::v2_mt_nt6::expressions::aux::if_then_gen<boost::log::v2_mt_nt6::expressions::attribute_actor<boost::posix_time::ptime,boost::log::v2_mt_nt6::fallback_to_none,void,boost::phoenix::actor>,boost::phoenix::actor<boost::proto::exprns_::expr<boost::proto::tagns_::tag::shift_left,boost::proto::argsns_::list2<boost::phoenix::actor<boost::proto::exprns_::basic_expr<boost::proto::tagns_::tag::terminal,boost::proto::argsns_::term<boost::phoenix::argument<2>>,0>>,boost::phoenix::actor<boost::proto::exprns_::basic_expr<boost::phoenix::detail::tag::function_eval,boost::proto::argsns_::list2<boost::proto::exprns_::basic_expr<boost::proto::tagns_::tag::terminal,boost::proto::argsns_::term<boost::phoenix::detail::member_function_ptr<0,__int64,__int64 (__thiscall boost::date_time::time_duration<boost::posix_time::time_duration,boost::posix_time::time_res_traits>::* )(void) const>>,0>,boost::phoenix::actor<boost::proto::exprns_::expr<boost::proto::tagns_::tag::minus,boost::proto::argsns_::list2<boost::phoenix::actor<boost::proto::exprns_::basic_expr<boost::phoenix::detail::tag::function_eval,boost::proto::argsns_::list2<boost::proto::exprns_::basic_expr<boost::proto::tagns_::tag::terminal,boost::proto::argsns_::term<boost::phoenix::detail::member_function_ptr<0,const boost::posix_time::ptime &,const boost::posix_time::ptime &(__thiscall boost::log::v2_mt_nt6::aux::singular_ref<boost::posix_time::ptime,void>::* )(void) const>>,0>,boost::log::v2_mt_nt6::expressions::attribute_actor<boost::posix_time::ptime,boost::log::v2_mt_nt6::fallback_to_none,void,boost::phoenix::actor>>,2>>,boost::phoenix::actor<boost::proto::exprns_::expr<boost::proto::tagns_::tag::terminal,boost::proto::argsns_::term<boost::posix_time::ptime>,0>>>,2>>>,2>>>,2>>>,
    1>              ArgT0=const boost::log::v2_mt_nt6::record_view &,
    1>              ArgT1=boost::log::v2_mt_nt6::basic_formatting_ostream<char> &

    etc…

    #2.

    namespace theirs{
    struct foo{};
    }
    namespace mine{
    std::ostream & operator <<(std::ostream &s_, theirs::foo)
    {
      return s_ << "foo";
    }
    }
    

    1>c:\dev\exb++.libs\boost_log\r860\common\include\boost\log\utility\formatting_ostream.hpp(410): error C2679: binary '<<' : no operator found which takes a right-hand operand of type 'const theirs::foo' (or there is no acceptable conversion)
    1>          e:\soft\microsoft visual studio 11.0\vc\include\ostream(695): could be 'std::basic_ostream<_Elem,_Traits> &std::operator <<<char,std::char_traits<char>>(std::basic_ostream<_Elem,_Traits> &,const char *)'
    1>          with
    1>          [
    1>              _Elem=char,
    1>              _Traits=std::char_traits<char>
    1>          ]

     
  • Andrey Semashev

    Andrey Semashev - 2013-04-25

    1. This is probably because there's missing streaming expression in the formatter. Try this:

    return expr::stream << expr::if_(expr::has_attr<posix_time::ptime>(name_)) [ ...
    

    2. But you can't use this operator either, can you? You have to do using declarations in order to make this operator visible for the compiler from the point where you're calling it.

     
  • Oleg

    Oleg - 2013-04-25

    1. OK. What's the downside of keeping phoenix::if_?
    2. That's right. Actually, in our case everything is done from inside mine{} namespace, so it works.

    Next issue:
    We had a custom formatter for the severity attribute that would color the output depending on the severity level on color capable terminals. Th was implemented with:

    class colored_severity_fmt_attr : public boost::log::formatters::fmt_attr_formatted<char, log_priority, blog::formatters::no_throw_policy>
    {
    public:
      typedef boost::log::formatters::fmt_attr_formatted<char, log_priority, blog::formatters::no_throw_policy> base_type;
      //! Character type
      typedef base_type::char_type char_type;
      //! Attribute name type
      typedef base_type::attribute_name_type attribute_name_type;
      //! Stream type
      typedef base_type::ostream_type ostream_type;
      //! Log record type
      typedef base_type::record_type record_type;
    public:
      explicit colored_severity_fmt_attr(attribute_name_type const &name_, bool color_ = false);
      void operator() (ostream_type &strm_, record_type const &record_) const;
    /*****/
    };
    

    How do we do it in version 2? I need to be able to do it both from settings and in code:

    <<  "[" << colored_severity_fmt_attr(log_attibutes::severity, true) << "] " <<
    

    I'm hoping there's a simpler solution than implementing my own phoenix/proto terminals for something as simple as this.

     
  • Oleg

    Oleg - 2013-04-25

    It would be nice if any formatting/filtering expression I can use in code, I could also do in the configuration. Something along the lines:

    %Scope(format=(%n:(%f:%l)), iteration=reverse, depth=3, etc)%

     
  • Andrey Semashev

    Andrey Semashev - 2013-04-25

    1. OK. What's the downside of keeping phoenix::if_?

    Well, it does a bit different thing. It extracts the value and then checks that it is present instead of just checking that the attribute is in the record. Also, if you ever want to extend your formatter so that it has a fixed part in addition to the conditional expression you will find out that it is not possible with phoenix::if_ because it returns void instead of the stream.

    2. That's right. Actually, in our case everything is done from inside mine{} namespace, so it works.

    I see. Well, there's nothing I can do in Boost.Log to help that. I wouldn't recommend using the aux trait as it can be removed or changed in future (and I have intention to do it), so I would suggest fixing the namespace mismatch to alleviate the problem. If moving the operators to namespace theirs is not an option then you can try importing them into the global namespace instead, so they are visible to Boost.Log as well.

    We had a custom formatter for the severity attribute that would color the output depending on the severity level on color capable terminals.

    You can use phoenix::bind or log::expressions::wrap_formatter to inject your functions into formatting expressions:

    std::string get_colored_severity_string(log::value_ref<severity> const& pri);
    expr::stream << phoenix::bind(&get_colored_severity_string, expr::attr<severity>(log_attibutes::severity));
    

    or

    struct colored_severity_fmt
    {
        typedef void result_type;
        result_type operator() (log::record_view const& rec, log::formatting_ostream& stream) const;
    };
    expr::stream << expr::wrap_formatter(colored_severity_fmt());
    

    Either variant can be used with the settings file, if the appropriate formatter factory is registered.

    It would be nice if any formatting/filtering expression I can use in code, I could also do in the configuration.

    Yes, that would be a nice feature. Unfortunately, the library cannot know the type of the "Scope" attribute, so it cannot interpret the additional arguments and perform advanced formatting. That's why you have to register factories.

     
  • Oleg

    Oleg - 2013-05-24

    Thank for your help again. I am still not convinced that intercepting calls to operator << is the right choice here. We've had a lot of issues related to that. For example, operator << (const char *) ignores the stream's formatting flags (like width) since you chose to skip the formatting output operator in this case. Just to work around that I had to create my own formatter, register a factory, etc. All that in place of a simple << setw(x).
    Logging a null char * leads to a crash whereas in the iostream library shipped with gcc it just set the badbit on the stream. Technically it's undefined behavior but still it creates unnecessary resistance in people's minds.
    There's also the issue of things breaking when the output operator for a type is defined in a namespace other than where the type itself is defined. Also, I'm a bit concerned that even a minor customization requires a much deeper knowledge of the library than most people are willing acquire. For instance, I wanted to add another formatting flag for the scope attribute to print only the file name portion of the source file path. It turned out to be impossible without replicating lots of code.
    Another issue is the limited support for configuring the library from a settings file. Why, for example, I can't pass a format string to the timestamp attribute? I had to create custom formatter just for that.
    I happen to be pushing for the use of  boost.log in a pretty big organization and rough edges like these in an otherwise fine library just build up people's skepticism.  

     
  • Andrey Semashev

    Andrey Semashev - 2013-05-24

    You have a good point about setw, I'll fix this in future versions.

    Regarding other things, there are good reasons for these choices. For example, you cannot implement a character converting stream without intercepting all operator<< calls, just to return a reference to my own stream wrapper instead of std::basic_ostream. Having your custom operators in a different namespace from your classes is just wrong. Such code will break in many contexts, Boost.Log being just one of them.

    The issue with format strings in the config file is caused by the fact that the library has no idea of the type of the attribute you named "Timestamp". Thus it is impossible to guess any additional parameters and their meaning when parsing formatters from a string. You really didn't have to write your own formatter and could just reuse the one provided by the library and use it in your factory. Surely I would prefer a simpler way, but I didn't find one. If you have suggestions, I would be interested to hear them.

     
  • Oleg

    Oleg - 2013-05-24

    Fair enough. As far as attribute types, can't we just  say that certain well-defined attribute names are reserved and have certain meanings and well-defined restrictions on their types. This will make things a lot easier for people who just want to have a convenient logging facility and don't really care much to learn its internals. For the rest of us things will remain the same with the exception that we'd have to chose different attribute names.

     
  • Andrey Semashev

    Andrey Semashev - 2013-05-24

    No, I don't want to hardcode this kind of restriction in a generic library.

     
  • Oleg

    Oleg - 2013-05-24

    Well, you are the boss here. I'd give it another thought though. C++ is a generic language, yet you can't use its keywords in your variable names for example. And you've already got add_common_attributes() anyway.

     
  • Andrey Semashev

    Andrey Semashev - 2013-05-24

    The add_common_attributes() function doesn't lock the library to particular attributes and names. It's just a convenience helper that the user may or may not use. Actually, an add_common_factories() function might be a good idea. I'll have to think it over.

     
  • Andrey Semashev

    Andrey Semashev - 2013-05-24

    BTW, regarding the setw problem, could you create a ticket for Boost.Log at https://svn.boost.org/trac/boost/? Would be great if you reproduce it with the 2.1 version that will be released with Boost 1.54.

     
  • Andrey Semashev

    Andrey Semashev - 2013-05-24

    Oops, the url should be https://svn.boost.org/trac/boost/.

     
  • Oleg

    Oleg - 2013-05-24

    I don't I'll get to it before boost is released. Upgrading to yet another intermediate version of boost.log would be looked upon kindly here.

     
1 2 > >> (Page 1 of 2)

Log in to post a comment.