22

I'm using Boost(1.55.0) Logging in my C++ application. I have been able to generate log of this format

[2014-Jul-15 10:47:26.137959]: <debug>  A regular message

I want to be able to add source file name and line number where the log is generated.

[2014-Jul-15 10:47:26.137959]: <debug> [filename:line_no] A regular message

example:

[2014-Jul-15 10:47:26.137959]: <debug> [helloworld.cpp : 12] A regular message

Source Code:

#include <boost/log/core.hpp>
#include <boost/log/trivial.hpp>
#include <boost/log/expressions.hpp>
#include <boost/log/sinks/text_file_backend.hpp>
#include <boost/log/utility/setup/file.hpp>
#include <boost/log/utility/setup/common_attributes.hpp>
#include <boost/log/sources/severity_logger.hpp>
#include <boost/log/sources/record_ostream.hpp>
#include <boost/log/expressions.hpp>
#include <boost/log/support/date_time.hpp>
#include <boost/log/attributes/attribute.hpp>
#include <boost/log/attributes/attribute_cast.hpp>
#include <boost/log/attributes/attribute_value.hpp>
#include <boost/make_shared.hpp>
#include <boost/property_tree/ptree.hpp>

namespace logging = boost::log;
namespace src = boost::log::sources;
namespace sinks = boost::log::sinks;
namespace keywords = boost::log::keywords;

void init()
{
    logging::add_file_log
    (
        keywords::file_name = "sample_%N.log",                                        /*< file name pattern >*/
        keywords::rotation_size = 10*1024*1204,                                 /*< rotate files every 10 MiB... >*/
        keywords::time_based_rotation = sinks::file::rotation_at_time_point(0, 0, 0), /*< ...or at midnight >*/
        keywords::format =
        (
            boost::log::expressions::stream
                << boost::log::expressions::format_date_time< boost::posix_time::ptime >("TimeStamp", "%Y-%m-%d_%H:%M:%S.%f")
                << ": <" << boost::log::trivial::severity << "> "
                << boost::log::expressions::smessage
        )
    );
}

int main(int, char*[])
{
    init();
    logging::add_common_attributes();

    using namespace logging::trivial;
    src::severity_logger< severity_level > lg;

    BOOST_LOG_SEV(lg, debug) << "A regular message";
    return 0;
}
2

4 Answers 4

15

As Horus pointed out, you can use attributes to log file and line numbers. However it is best to avoid using multi-statements macros to avoid problems with expressions like this:

if (something)
   LOG_FILE_LINE(debug) << "It's true"; // Only the first statement is conditional!

You can do better creating a macro that leverages the underlying behavior of the Boost Log library. For example, BOOST_LOG_SEV is:

#define BOOST_LOG_SEV(logger, lvl) BOOST_LOG_STREAM_SEV(logger, lvl)
#define BOOST_LOG_STREAM_SEV(logger, lvl)\
    BOOST_LOG_STREAM_WITH_PARAMS((logger), (::boost::log::keywords::severity = (lvl)))

Using BOOST_LOG_STREAM_WITH_PARAMS you can set and get more attributes, like this:

// New macro that includes severity, filename and line number
#define CUSTOM_LOG(logger, sev) \
   BOOST_LOG_STREAM_WITH_PARAMS( \
      (logger), \
         (set_get_attrib("File", path_to_filename(__FILE__))) \
         (set_get_attrib("Line", __LINE__)) \
         (::boost::log::keywords::severity = (boost::log::trivial::sev)) \
   )

// Set attribute and return the new value
template<typename ValueType>
ValueType set_get_attrib(const char* name, ValueType value) {
   auto attr = logging::attribute_cast<attrs::mutable_constant<ValueType>>(logging::core::get()->get_thread_attributes()[name]);
   attr.set(value);
   return attr.get();
}

// Convert file path to only the filename
std::string path_to_filename(std::string path) {
   return path.substr(path.find_last_of("/\\")+1);
}

The complete source code is:

#include <boost/log/trivial.hpp>
#include <boost/log/sources/severity_logger.hpp>
#include <boost/log/utility/setup/file.hpp>
#include <boost/log/utility/setup/console.hpp>
#include <boost/log/expressions.hpp>
#include <boost/log/utility/setup/common_attributes.hpp>
#include <boost/log/attributes/mutable_constant.hpp>
#include <boost/date_time/posix_time/posix_time_types.hpp>
#include <boost/log/support/date_time.hpp>
#include <boost/log/attributes/mutable_constant.hpp>

namespace logging  = boost::log;
namespace attrs    = boost::log::attributes;
namespace expr     = boost::log::expressions;
namespace src      = boost::log::sources;
namespace keywords = boost::log::keywords;

// New macro that includes severity, filename and line number
#define CUSTOM_LOG(logger, sev) \
   BOOST_LOG_STREAM_WITH_PARAMS( \
      (logger), \
         (set_get_attrib("File", path_to_filename(__FILE__))) \
         (set_get_attrib("Line", __LINE__)) \
         (::boost::log::keywords::severity = (boost::log::trivial::sev)) \
   )

// Set attribute and return the new value
template<typename ValueType>
ValueType set_get_attrib(const char* name, ValueType value) {
   auto attr = logging::attribute_cast<attrs::mutable_constant<ValueType>>(logging::core::get()->get_thread_attributes()[name]);
   attr.set(value);
   return attr.get();
}

// Convert file path to only the filename
std::string path_to_filename(std::string path) {
   return path.substr(path.find_last_of("/\\")+1);
}

void init() {
   // New attributes that hold filename and line number
   logging::core::get()->add_thread_attribute("File", attrs::mutable_constant<std::string>(""));
   logging::core::get()->add_thread_attribute("Line", attrs::mutable_constant<int>(0));

   logging::add_file_log (
    keywords::file_name = "sample.log",
    keywords::format = (
     expr::stream
      << expr::format_date_time<boost::posix_time::ptime>("TimeStamp", "%Y-%m-%d_%H:%M:%S.%f")
      << ": <" << boost::log::trivial::severity << "> "
      << '['   << expr::attr<std::string>("File")
               << ':' << expr::attr<int>("Line") << "] "
      << expr::smessage
    )
   );
   logging::add_common_attributes();
}

int main(int argc, char* argv[]) {
   init();
   src::severity_logger<logging::trivial::severity_level> lg;

   CUSTOM_LOG(lg, debug) << "A regular message";
   return 0;
}

This generate a log like this:

2015-10-15_15:25:12.743153: <debug> [main.cpp:61] A regular message
7
  • 1
    +1. Looking at how it's implemented - it should work faster if you define attribute type as mutable_constant<boost::log::string_literal> and assign it with boost::log::string_literal(__FILE__) etc., as it will stop allocating / copying strings on each log line.
    – bobah
    Commented Sep 3, 2016 at 8:38
  • Good point. However, __LINE__ is an integer constant and __FILE__ is used to get a substring in this sample. boost::log::string_literal constructs from an array constant like char value[N]. Commented Oct 12, 2016 at 5:04
  • @Nature.Li has indicated that the code was not thread safe. I changed the global attributes for thread attributes in the code, but I have not tested with several threads. Commented Oct 12, 2016 at 5:14
  • @GuillermoRuiz Hi. Could you share the thread safe code? I've also some issues with threads.
    – unnamed
    Commented Nov 7, 2016 at 16:47
  • Does it work in multi-threaded code? I'm getting inconsistent line numbers with this solution
    – Pranav
    Commented Dec 29, 2016 at 22:10
9

As user2943014 pointed out, using scopes prints the line number where you opened that scope, not the line number where you emitted a log message using BOOST_LOG_SEV.

You can use attributes to log the line numbers etc at the place you actually logged.

Register global attributes in your logging initialization function:

using namespace boost::log;
core::get()->add_global_attribute("Line", attributes::mutable_constant<int>(5));
core::get()->add_global_attribute("File", attributes::mutable_constant<std::string>(""));
core::get()->add_global_attribute("Function", attributes::mutable_constant<std::string>(""));

Setting these attributes in your logging macro:

#define logInfo(methodname, message)                          \
  LOG_LOCATION;                                               \
  BOOST_LOG_SEV(_log, boost::log::trivial::severity_level::trace) << message

#define LOG_LOCATION                            \
  boost::log::attribute_cast<boost::log::attributes::mutable_constant<int>>(boost::log::core::get()->get_global_attributes()["Line"]).set(__LINE__); \
  boost::log::attribute_cast<boost::log::attributes::mutable_constant<std::string>>(boost::log::core::get()->get_global_attributes()["File"]).set(__FILE__); \
  boost::log::attribute_cast<boost::log::attributes::mutable_constant<std::string>>(boost::log::core::get()->get_global_attributes()["Function"]).set(__func__);

Not exactly beautiful, but it works and it was a long way for me. It's a pity boost doesn't offer this feature out of the box.

1
  • Looks nice to me. Will try this somtime Commented Aug 25, 2015 at 19:07
5

I would suggest to use the boost::log::add_value() function.

Define:

#define LOG_LOCATION(LEVEL, MSG)      \
  BOOST_LOG_SEV(logger::get(), LEVEL)     \
    << boost::log::add_value("Line", __LINE__)          \
    << boost::log::add_value("File", __FILE__)          \
    << boost::log::add_value("Function", __FUNCTION__) << MSG

And then you can format it as follows:

boost::log::add_common_attributes();

boost::log::register_simple_filter_factory<boost::log::trivial::severity_level, char>("Severity");
boost::log::register_simple_formatter_factory<boost::log::trivial::severity_level, char>("Severity");

auto syslog_format(
    boost::log::expressions::stream <<
        "["   << boost::log::expressions::format_date_time< boost::posix_time::ptime >("TimeStamp", "%Y-%m-%d %H:%M:%S") <<
        "] [" << boost::log::expressions::attr<boost::log::attributes::current_thread_id::value_type>("ThreadID") << 
        "] [" << std::left << std::setw(7) << std::setfill(' ') << boost::log::trivial::severity <<
        "] "  << boost::log::expressions::smessage <<
        " ("  << boost::log::expressions::attr<std::string>("Filename") <<
        ":"   << boost::log::expressions::attr<int>("Line") <<
        ":"   << boost::log::expressions::attr<std::string>("Function") <<
        ")"
);

boost::log::add_file_log(
    boost::log::keywords::file_name  = "sys_%d_%m_%Y.%N.log",
    boost::log::keywords::format = syslog_format
);

No need to add global attributes, and you can format it easily as seen above. I find this is a good compromise between other's solutions and the raw __FILE__ __LINE__ approach.

Full example here.

1
  • 2
    I know this is an old thread, but for those coming here from a search, I found (like others) that Guillermo Ruiz solution was not thread safe, but this one does seem to be (using logger_mt etc) , and seems to be much more straightforward.
    – bevis
    Commented Sep 13, 2019 at 14:28
1

Define

namespace attrs = boost::logging::attributes;
namespace expr = boost::logging::expressions;

Add

<< expr::format_named_scope("Scope", keywords::format = "[%f:%l]")

to your keywords::format = (...) in init.

Then add

logging::core::get()->add_global_attribute("Scope", attrs::named_scope());

after add_common_attributes() in main.

Then just before the BOOST_LOG_SEV line add BOOST_LOG_NAMED_SCOPE("whatever").

BOOST_LOG_NAMED_SCOPE("whatever") creates a "scope" named "whatever". The scope is implemented by a unused variable that contains the scope name and the file and the line where the scope was defined.

The format_named_scope line specifies how a scope should be formatted in the log line. %f is the file, %l is the line and %n is the scope name.

Note that the file line that appears in the log record is the line where the macro BOOST_LOG_NAMED_SCOPE appears and not the line of the BOOST_LOG_SEV macro.

I am not aware of simple method to record the file and line without using the BOOST_LOG_NAMED_SCOPE.

0

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.