Boost.log: How to prevent the output will be duplicated to all added streams when it uses the add_file_log() function?

Question

I use the add_file_log() function to initialize a logging sink that stores log records into a text file. When I define several sinks, I have observed:

• a file is created for each sink.
• the output is copied to all files.

This is my logger:

class logger
{
public:
  logger(const logger&) =delete;
  logger(logger&&) =delete;
  logger& operator=(const logger&) =delete;
  logger& operator=(logger&&) =delete;

  static logger& get_instance(
    const std::string& file,
    bool console
  )
  {
      boost::log::register_simple_formatter_factory<
                                                    boost::log::trivial::severity_level,
                                                    char
                                                   >("Severity");

      std::string the_format = "[%TimeStamp%] (%LineID%) [%Severity%]: %Message%";

      if(!file.empty()) {
        boost::log::add_file_log(
          boost::log::keywords::file_name = file + "_%N.log",
          boost::log::keywords::rotation_size = 10 * 1024 * 1024,
          boost::log::keywords::time_based_rotation =
            boost::log::sinks::file::rotation_at_time_point(0, 0, 0),
          boost::log::keywords::auto_flush = true,
          //boost::log::keywords::open_mode = (std::ios::out | std::ios::app),
          boost::log::keywords::format = the_format
        );
      }

      boost::log::add_common_attributes();
      static logger instance{ the_format, console };
      return instance;
  }

  void log(
    const std::string& msg
  )
  {
      BOOST_LOG_SEV ( m_log_, boost::log::trivial::info ) << msg;
  }

private:
  boost::log::sources::severity_logger<
                                       boost::log::trivial::severity_level
                                      > m_log_;

  logger(
    const std::string& format,
    bool console
  )
  {
      if(console) {
        boost::log::add_console_log(
          std::clog,
          boost::log::keywords::format = format
        );
      }
  }
}; // logger

This is my main() function:

void test(
  const std::string& file
)
{
  logger& lg1 = logger::get_instance( file, false );
  lg1.log( "Hello" );
  lg1.log( "World" );
  lg1.log( "Bye" );
} // test

int main()
{
  unsigned char result = EXIT_SUCCESS;

  try
  {
    std::string file1 = "a.txt",
                file2 = "b.txt";
    logger& lg = logger::get_instance( file1, false );

    for(int i = 1; i<=10; i++) {
       lg.log( std::to_string(i) );
       if(i == 5) {
         test( file2 );
       }
    }
  }
  catch ( std::exception& e )
  {
    std::cerr << "Error: " << e.what() << std::endl;
    result = EXIT_FAILURE;
  }
  return result;
}

After running the example, the files contain:

a.txt_0.log

[2016-Aug-31 11:49:48.584353] (1) [info]: 1
[2016-Aug-31 11:49:48.585376] (2) [info]: 2
[2016-Aug-31 11:49:48.585418] (3) [info]: 3
[2016-Aug-31 11:49:48.585442] (4) [info]: 4
[2016-Aug-31 11:49:48.585462] (5) [info]: 5
[2016-Aug-31 11:49:48.585505] (6) [info]: Hello  <-- 
[2016-Aug-31 11:49:48.585610] (7) [info]: World  <-- Generated by second logger
[2016-Aug-31 11:49:48.585672] (8) [info]: Bye    <--
[2016-Aug-31 11:49:48.585709] (9) [info]: 6
[2016-Aug-31 11:49:48.585744] (10) [info]: 7
[2016-Aug-31 11:49:48.585777] (11) [info]: 8
[2016-Aug-31 11:49:48.585813] (12) [info]: 9
[2016-Aug-31 11:49:48.585842] (13) [info]: 10

b.txt_0.log

[2016-Aug-31 11:49:48.585505] (6) [info]: Hello
[2016-Aug-31 11:49:48.585610] (7) [info]: World
[2016-Aug-31 11:49:48.585672] (8) [info]: Bye
[2016-Aug-31 11:49:48.585709] (9) [info]: 6    <--
[2016-Aug-31 11:49:48.585744] (10) [info]: 7   <--
[2016-Aug-31 11:49:48.585777] (11) [info]: 8   <-- Generated by the first logger
[2016-Aug-31 11:49:48.585813] (12) [info]: 9   <--
[2016-Aug-31 11:49:48.585842] (13) [info]: 10  <--

How I can prevent this behavior? I want each file only stores the information generated by its associated logger.

Answer 1

You seem to have a misunderstanding of how Boost.Log works.

There are sources and sinks. A source takes data, such as a string, and creates an entry with it. The entry is then given to the core, which dispatches it to all the sinks. The sinks can then filter, format and output the entries to wherever they want, such as stdout or a file.

An example of a source would be the severity_logger you are using. You might be used to the term "logger" instead of "source", but "logger" isn't very precise because logging is a multi-stage process.

You don't usually have to create multiple sources ("loggers"). Instead, you can add multiple global sinks. In your case, you'll need a filtered sink per file.

                                  +--------------+
                            +---> | console sink | ----> stdout
                            |     +--------------+
                            |
+--------+      +------+    |     +--------------+
| source | ---> | core | ---+---> | file sink    | ----> log1.txt
+--------+      +------+    |     +--------------+
                            |
                            |     +--------------+
                            +---> | file sink    | ----> log2.txt
                                  +--------------+

Now, you could have multiple sources, each with their own threading model, attributes, character type, etc., but they would still all generate entries and give them to the core. In your case, it wouldn't be very useful.

Let's get the headers out of the way:

#include <string>
#include <fstream>
#include <boost/log/sinks.hpp>
#include <boost/log/utility/setup/formatter_parser.hpp>
#include <boost/log/sources/severity_channel_logger.hpp>
#include <boost/log/trivial.hpp>
#include <boost/log/utility/setup/file.hpp>
#include <boost/log/utility/setup/common_attributes.hpp>
#include <boost/log/utility/setup/console.hpp>
#include <boost/log/expressions.hpp>
#include <boost/log/attributes/scoped_attribute.hpp>

namespace bl = boost::log;

Let's start:

BOOST_LOG_ATTRIBUTE_KEYWORD(tag_attr, "Tag", std::string);

A log entry has attributes which can be set every time something is logged. These attributes are usually used in formatting (such as "[%TimeStamp%] [%Message%]"), but we'll add a new attribute to allow for differentiating between the different files. I called the attribute "Tag".

using logger_type = bl::sources::severity_logger<bl::trivial::severity_level>;
static logger_type g_logger;

const std::string g_format = "[%TimeStamp%] (%LineID%) [%Severity%] [%Tag%]: %Message%";

Now, in this example, the actual boost logger is a global object (g_logger). You may want to restrict its scope and pass it around to your own logger objects. I've also made the format a global constant. YMMV.

This is the logger class:

class logger
{
public:
    logger(std::string file)
        : tag_(file)
    {
        using backend_type = bl::sinks::text_file_backend;
        using sink_type = bl::sinks::synchronous_sink<backend_type>;
        namespace kw = bl::keywords;

        auto backend = boost::make_shared<backend_type>(
            kw::file_name = file + "_%N.log",
            kw::rotation_size = 10 * 1024 * 1024,
            kw::time_based_rotation = bl::sinks::file::rotation_at_time_point(0, 0, 0),
            kw::auto_flush = true);

        auto sink = boost::make_shared<sink_type>(backend);
        sink->set_formatter(bl::parse_formatter(g_format));
        sink->set_filter(tag_attr == tag_);

        bl::core::get()->add_sink(sink);
    }

    void log(const std::string& s)
    {
        BOOST_LOG_SCOPED_THREAD_TAG("Tag", tag_);
        BOOST_LOG_SEV(g_logger, bl::trivial::info) << s;
    }

private:
    const std::string tag_;
};

I've used the file name as a tag, but it could be anything else as long as it's unique. Every log entry will have this tag as an attribute, which will be used in the sink filter.

First, a text_file_backend is created and is given to a new sink, which is then added to the core. This is actually what happens when you call add_file_log(), it's just a helper function. I've reused the same parameters you had in your example (filename pattern, rotation, etc.)

The interesting line is this one:

sink->set_filter(tag_attr == tag_);

Here, tag_attr was defined above as an attribute keyword. Keywords are a bit unusual in Boost.Log: they can be used to create expressions that will be evaluated at runtime. In this case, the sink will only accept entries where tag_attr == tag_. So when a logger logs something, it sets its own tag as an attribute, and the sink will ignore anything that doesn't have this tag. In log(), you can see the "Tag" attribute being set.

Here's main():

int main()
{
    bl::register_simple_formatter_factory<bl::trivial::severity_level, char>("Severity");
    boost::log::add_common_attributes();

    bl::add_console_log(std::clog, bl::keywords::format=g_format);

    logger lg1("1");
    logger lg2("2");

    lg1.log("a");
    lg1.log("b");
    lg1.log("c");

    lg2.log("d");
    lg2.log("e");
    lg2.log("f");
}

You'll see that I've moved the common stuff outside of logger since it doesn't really belong there. Entries "a", "b" and "c" will be written to "1_0.txt" and "d", "e" and "f" to "2_0.txt". All six entries will be written to the console.

     +--------------+
     | lg1.log("a") |
     +--------------+
            |
            v
+-------------------------+
| Entry:                  |
|   Timestamp: 1472660811 |
|   Message:   "a"        |
|   LineID:    1          |
|   Severity:  info       |
|   Tag:       "1"        |
+-------------------------+
            |            
            v                 +----------------------+
         +------+             | console sink         |
         | core | -----+----> |   file: stdout       |  --> written
         +------+      |      |   filter: none       |
                       |      +----------------------+
                       |      
                       |      +----------------------+
                       |      | file sink            |
                       +----> |   file: "1_0.txt"    |  --> written
                       |      |   filter: tag == "1" |
                       |      +----------------------+
                       |      
                       |      +----------------------+
                       |      | file sink            |
                       +----> |   file: "2_0.txt"    |  --> discarded
                              |   filter: tag == "2" |
                              +----------------------+