0

I have an executable for both Linux and Windows with three dlls/shared libraries, and I'm using boost.log for logging. I wish to have a separate, file log for each module. My approach was to create a severity_channel_logger_mt for each module, constructed in a singleton for each module with the channel name.

class LogSingleton final
{
  src::severity_channel_logger_mt<logging::trivial::severity_level, std::string> slg_;
...
protected:
  LogSingleton() : slg_(boost::log::keywords::channel = "ModuleOne") {}
public:
  src::severity_channel_logger_mt<logging::trivial::severity_level, std::string>& logger() { return slg_; }
...
};    

Each module then creates its own file sink on initialisation, and sets a channel filter so that only that module's log messages should reach this sink.

logging::add_file_log(logging::keywords::file_name = "module_one.log",
  logging::keywords::open_mode = std::ios::app,
  ->set_filter(logging::trivial::severity >= level 
    && expr::attr< std::string >("Channel") == "ModuleOne");

I have then created my own module specific macro for logging, which passes to the right logger.

#define BLOG(lvl)  BOOST_LOG_STREAM_WITH_PARAMS((LogSingleton::instance()->logger()), (::boost::log::keywords::severity = ::boost::log::trivial::lvl))

which is used like this:

BLOG(info) << "Hello world";

Whilst on Windows logging works as expected, on Linux the log files for ModuleOne (initialised first) and ModuleThree (initialised third) do not receive any log messages. ModuleTwo logs correctly. The logging code for all three modules is identical apart from the log sink filename, channel names, and the class name of the singleton.

I wonder if the problem is with my macro but any ideas welcome, together with comments on the approach.

Update

I have reduced this problem to a minimal example, all in one executable. The shared library issue was a misdirection. The issue appears to be that if I create the severity_channel_logger in a singleton, logging fails. If I use a local logger, logging works. Even if I create a logger in the singleton and don't use it, it prevents the local logger from functioning. Despite tracing through the code, I can't see why this is happening. (platform = Fedora 21, gcc 4.9.2, boost 1.58)

#include <boost/config.hpp> 
#include <boost/filesystem.hpp>
#include <boost/log/core.hpp>
#include <boost/log/trivial.hpp>
#include <boost/log/sources/severity_feature.hpp>
#include <boost/log/sources/severity_channel_logger.hpp>
#include <boost/log/expressions.hpp>
#include <boost/log/expressions/formatters/date_time.hpp>
#include <boost/log/support/date_time.hpp>
#include <boost/log/attributes/current_thread_id.hpp>
#include <boost/log/utility/setup/file.hpp>
#include <boost/log/utility/setup/console.hpp>
#include <boost/log/utility/setup/common_attributes.hpp>

namespace logging = boost::log;
namespace expr = boost::log::expressions;
namespace src = boost::log::sources;
namespace fs = boost::filesystem;

class LogSingleton
{
    src::severity_channel_logger<logging::trivial::severity_level, std::string> slg_;
    static LogSingleton* instance_;

    LogSingleton(const LogSingleton&);
    LogSingleton& operator=(const LogSingleton&);

protected:
    LogSingleton() : slg_(boost::log::keywords::channel = "Core") {}
public:
    src::severity_channel_logger<logging::trivial::severity_level, std::string>&  logger()
    {
        return slg_;
    }

    static LogSingleton* instance()
    {
        if (!instance_)
        {
            instance_ = new LogSingleton;
        }
        return instance_;
    }
};

LogSingleton* LogSingleton::instance_ = nullptr;

// 1. doesn't work
//#define BLOG(lvl)  BOOST_LOG_STREAM_WITH_PARAMS((LogSingleton::instance()->logger()), (::boost::log::keywords::severity = ::boost::log::trivial::lvl))

// access to logger via reference. Works if it is passed a ref to logger declared in main. Doesn't work if it is ref to logger in singleton
#define BLOG(lvl)  BOOST_LOG_STREAM_WITH_PARAMS((rlogger), (::boost::log::keywords::severity = ::boost::log::trivial::lvl))

int main(int argc, char **argv)
{
    logging::add_common_attributes();
    logging::trivial::severity_level level = logging::trivial::trace;
        auto formatter = expr::stream
        << "[" << expr::format_date_time<boost::posix_time::ptime>("TimeStamp", "%Y-%m-%dT%H:%M:%S.%f")
        << "] (" << logging::trivial::severity
        << "): " << expr::message;

    fs::path plog = fs::system_complete(fs::path(".."));
    if (!fs::exists(plog) || !fs::is_directory(plog))
        throw std::invalid_argument("Log directory doesn't exist, or path isn't a directory");
    plog /= "core.log";

    logging::add_file_log(logging::keywords::file_name = plog.string(),
        logging::keywords::open_mode = std::ios::app,
        logging::keywords::format = formatter)
        ->set_filter(logging::trivial::severity >= level &&    expr::attr< std::string >("Channel") == "Core");

    // this works with rlogger macro variant
    src::severity_channel_logger<logging::trivial::severity_level, std::string> logger(boost::log::keywords::channel = "Core");
    auto& rlogger = logger;

    // 2. this doesn't work, with same macro
    //auto& rlogger = LogSingleton::instance()->logger();

    // 3. just creating the singleton, before or after the creation of the local logger, stops logging from working
    //LogSingleton::instance();

    BLOG(info) << "Hello world";

    return 0;
}

As currently written, this example works with the local logger. Comment labelled 1 - this is the variant of the macro that uses singleton logger direct (fails). Also commenting out the local logger and enabling the reference to the singleton will demonstrate the issue. (comment 2). Comment labelled 3 shows that just creating a singleton logger causes logging to fail via the local logger.

nostep
  • 35
  • 6
  • A little more detail. I can't use a single, global logger in Windows as they aren't shared between different dlls when defined in one of them (the only place I have control of). Also adding the channel to the macro doesn't change behaviour, as in `#define BLOG(lvl) BOOST_LOG_STREAM_WITH_PARAMS((LogSingleton::instance()->logger()), (::boost::log::keywords::channel="ModuleOne") (::boost::log::keywords::severity = ::boost::log::trivial::lvl))` – nostep Jul 27 '15 at 17:16

2 Answers2

2

The problem is caused by the leak of LogSingleton in your code. The singleton contains a logger, which keeps the logging core and sinks from being destroyed. The log record you make is correctly processed and written to the file stream but not flushed (i.e. it ends up in the file stream buffers). Normally, stream buffers are flushed when the stream is destroyed (in case of Boost.Log this happens when sinks are destroyed, at program termination) or after every log record, if you enable auto-flush (pass the keywords::auto_flush = true argument to the add_file_log function call).

You can fix it if you change LogSingleton::instance_ to be a std::unique_ptr.

Andrey Semashev
  • 10,046
  • 1
  • 17
  • 27
0

First ensure that you're linking all your modules with shared libraries of Boost.Log, not static. This is a requirement of Boost.Log when used in multi-module applications, on all platforms. Also, make sure you build all your modules with the same set of configuration macros affecting Boost.Log.

Next, if you manage symbol visibility make sure you export type info symbols from your libraries. This is especially important for exception types and attribute value types. If you're not familiar with symbol visibility you may want to start from exporting all symbols, which can be achieved by building your modules without any -fvisibility* flags.

If all above doesn't help, you will have to debug your application. In particular, make sure the filters you set are actually passing log records. You may want to temporarily remove filters to see if that helps. If that doesn't help still, walk through the code step-by-step in the debugger to see at which point log records are dropped.

Andrey Semashev
  • 10,046
  • 1
  • 17
  • 27
  • Andrey, many thanks for these suggestions, which I double checked. I have now reduced the problem to a single executable example, included in the update to the original question above. – nostep Jul 30 '15 at 09:50