[Boost-users] [Log] How to use?

Subject: [Boost-users] [Log] How to use?
From: Olivier Tournaire (olitour_at_[hidden])
Date: 2010-08-17 16:43:18

Hi all,

i am currently trying to use Boost.Log in my application. After fighting the
two last days, I still do not understand how to correctly use the lib. I
would like the result to be the same as the one provided by the example
advanced_use.cpp. So, I wrote a simple class to make some tests.
As I want to use the logging library in a shared library (an application
plugin), I made a simple test: compile the class which uses Log in a shared
library and link an executable against this library. I also have created an
executable which directly compiles the class (so does not link against the
shared library). Basically, I have a test_boost_log class. The constructor
is a copy/paste of the code from the example advanced_use.cpp:

  #include "test_boost_log.hpp"

 #include <cassert>

#include <iostream>

#include <fstream>

#include <boost/shared_ptr.hpp>

#include <boost/log/common.hpp>

#include <boost/log/filters.hpp>

#include <boost/log/formatters.hpp>

#include <boost/log/attributes.hpp>

#include <boost/log/sinks.hpp>

#include <boost/log/utility/empty_deleter.hpp>

#include <boost/log/utility/scoped_attribute.hpp>

 namespace logging = boost::log;

namespace fmt = boost::log::formatters;

namespace flt = boost::log::filters;

namespace sinks = boost::log::sinks;

namespace attrs = boost::log::attributes;

namespace src = boost::log::sources;

namespace keywords = boost::log::keywords;

 using boost::shared_ptr;

 // Here we define our application severity levels.

enum severity_level

{

    normal,

    notification,

    warning,

    error,

    critical

};

 // The formatting logic for the severity level

template< typename CharT, typename TraitsT >

inline std::basic_ostream< CharT, TraitsT >& operator<< (

    std::basic_ostream< CharT, TraitsT >& strm, severity_level lvl)

{

    static const char* const str[] =

    {

        "normal",

        "notification",

        "warning",

        "error",

        "critical"

    };

    if (static_cast< std::size_t >(lvl) < (sizeof(str) / sizeof(*str)))

        strm << str[lvl];

    else

        strm << static_cast< int >(lvl);

    return strm;

}

 int foo(src::logger& lg)

{

    BOOST_LOG_FUNCTION();

    BOOST_LOG(lg) << "foo is being called";

    return 10;

}

 test_boost_log::test_boost_log()

{

    // For now we only create a text output sink:

    typedef sinks::synchronous_sink< sinks::text_ostream_backend > text_sink;

    shared_ptr< text_sink > pSink(new text_sink);

     {

        text_sink::locked_backend_ptr pBackend = pSink->locked_backend();

         shared_ptr< std::ostream > pStream(&std::clog,
logging::empty_deleter());

        pBackend->add_stream(pStream);

         shared_ptr< std::ofstream > pStream2(new std::ofstream("sample.log"));

        assert(pStream2->is_open());

        pBackend->add_stream(pStream2);

    }

     logging::core::get()->add_sink(pSink);

     src::logger lg;

     BOOST_LOG(lg) << "Hello, World!";

     pSink->locked_backend()->set_formatter(fmt::stream

        << fmt::attr("LineID") // First an attribute "LineID" is
written to the log

        << " [" << fmt::date_time< boost::posix_time::ptime
>("TimeStamp", "%d.%m.%Y %H:%M:%S.%f")

        << "] [" << fmt::attr< severity_level >("Severity", std::nothrow)

        << "] [" << fmt::time_duration<
boost::posix_time::time_duration >("Uptime")

        << "] [" // then this delimiter separates it from the rest of the line

        << fmt::if_(flt::has_attr("Tag"))

           [

               fmt::stream << fmt::attr< std::string >("Tag")

                << "] [" // yet another delimiter

           ]

        << fmt::named_scope("Scope", keywords::iteration = fmt::reverse) << "] "

        << fmt::message()); // here goes the log record text

     shared_ptr< logging::attribute > pCounter(new attrs::counter<
unsigned int >(1));

     // Since we intend to count all logging records ever made by the
application,

    // this attribute should clearly be global.

    logging::core::get()->add_global_attribute("LineID", pCounter);

     // And similarly add a time stamp

    shared_ptr< logging::attribute > pTimeStamp(new attrs::local_clock());

    logging::core::get()->add_global_attribute("TimeStamp", pTimeStamp);

     // And an up time stopwatch

    BOOST_LOG_SCOPED_THREAD_ATTR("Uptime", attrs::timer);

     // Let's also track the execution scope from which the records are made

    boost::shared_ptr< logging::attribute > pNamedScope(new
attrs::named_scope());

    logging::core::get()->add_thread_attribute("Scope", pNamedScope);

     // We can mark the current execution scope now - it's the 'main' function

    BOOST_LOG_FUNCTION();

     // Let's try out the counter attribute and formatting

    BOOST_LOG(lg) << "Some log line with a counter";

    BOOST_LOG(lg) << "Another log line with the counter";

     {

        BOOST_LOG_NAMED_SCOPE("Tagging scope");

         // Now these lines will be highlighted with the tag

        BOOST_LOG(lg) << "Some tagged log line";

        BOOST_LOG(lg) << "Another tagged log line";

    }

     // And this line is not highlighted anymore

    BOOST_LOG(lg) << "Now the tag is removed";

     pSink->set_filter(

        flt::attr< severity_level >("Severity", std::nothrow) >=
warning // Write all records with "warning" severity or higher

        || flt::attr< std::string >("Tag",
std::nothrow).begins_with("IMPORTANT")); // ...or specifically tagged

     src::severity_logger< severity_level > slg;

     // These two lines test filtering based on severity

    BOOST_LOG_SEV(slg, normal) << "A normal severity message, will not
pass to the output";

    BOOST_LOG_SEV(slg, error) << "An error severity message, will pass
to the output";

     {

        // Next we try if the second condition of the filter works

        // We mark following lines with a tag

        BOOST_LOG_SCOPED_THREAD_TAG("Tag", std::string, "IMPORTANT MESSAGES");

         BOOST_LOG(slg) << "Some really urgent line";

    }

     pSink->reset_filter();

     // And moreover, it is possible to nest logging records. For
example, this will

    // be processed in the order of evaluation:

    BOOST_LOG(lg) << "The result of foo is " << foo(lg);

}

I have added another method to test the logger state:

   void test_boost_log::a_test_method_to_see_if_the_logger_is_still_working()

{

    src::severity_logger< severity_level > slg;

    BOOST_LOG_SEV(slg, error) << "An error severity message, will pass
to the output";

}

My main:

  #include "test_boost_log.hpp"

 int main(int argc, char** argv)

{

    test_boost_log tbl;

    tbl.a_test_method_to_see_if_the_logger_is_still_working();

    return 0;

}

Here is the output of the program:

Hello, World!
1 [17.08.2010 21:22:43.083302] [] [00:00:00.000076]
[test_boost_log::test_boost_log()] Some log line with a counter
2 [17.08.2010 21:22:43.083445] [] [00:00:00.000217]
[test_boost_log::test_boost_log()] Another log line with the counter
3 [17.08.2010 21:22:43.083484] [] [00:00:00.000256] [Tagged line] [Tagging
scope<-test_boost_log::test_boost_log()] Some tagged log line
4 [17.08.2010 21:22:43.083517] [] [00:00:00.000289] [Tagged line] [Tagging
scope<-test_boost_log::test_boost_log()] Another tagged log line
5 [17.08.2010 21:22:43.083556] [] [00:00:00.000328]
[test_boost_log::test_boost_log()] Now the tag is removed
6 [17.08.2010 21:22:43.083598] [error] [00:00:00.000370]
[test_boost_log::test_boost_log()] An error severity message, will pass to
the output
7 [17.08.2010 21:22:43.083633] [normal] [00:00:00.000405] [IMPORTANT
MESSAGES] [test_boost_log::test_boost_log()] Some really urgent line
9 [17.08.2010 21:22:43.083673] [] [00:00:00.000444] [int
foo(boost::log_mt_posix::sources::logger&)<-test_boost_log::test_boost_log()]
foo is being called
8 [17.08.2010 21:22:43.083668] [] [00:00:00.000440]
[test_boost_log::test_boost_log()] The result of foo is 10
*terminate called after throwing an instance of
'boost::exception_detail::clone_impl<boost::exception_detail::error_info_injector<boost::log_mt_posix::missing_value>
>'*
*  what():  Requested attribute value not found*

So, the logger throws, sample.log is created, but empty. The library and the
executable are compiled with

-DBOOST_LOG_USE_CHAR

and

-DBOOST_LOG_DYN_LINK

If someone could help...

Best regards,

Olivier

PS: boost_1.42, log_1.0 (from sourceforge), g++4.3.4, 64bits ubuntu