Search code examples
c++windowsboost-asioboost-log

BOOST_LOG_SEV corrupts async_read_some after creating a thread


So I was practicing boost library and got stuck with something. My app was using asio::serial_port and I decided to add some log features. And here comes a problem.

When I create thread for asio::io_service

boost::thread t(boost::bind(&boost::asio::io_service::run, &io_service_));

and then try to log something with

BOOST_LOG_SEV(MBLog::get(), logging::trivial::trace) << "something to trace;"

before calling

port_->async_read_some(
        boost::asio::buffer(read_buf_raw_, SERIAL_PORT_READ_BUF_SIZE),
        boost::bind(
            &SerialPort::on_receive_,
            this, boost::asio::placeholders::error,
            boost::asio::placeholders::bytes_transferred));

then handler on_receive_ is never called (port can still write something with write_some thow). When the logging macro is commented out or done after execution of async_read_some it magically works. I would like to know what's the magic behind this or where to start looking the answer? Maybe some of you already know the problem then please share. Other useful info:

I'm using MSVC2017.

Boost log initialization

Logger.h

#define _HAS_AUTO_PTR_ETC 1
#include <boost/log/trivial.hpp>
#include <boost/log/sources/global_logger_storage.hpp>

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

BOOST_LOG_GLOBAL_LOGGER(MBLog, src::severity_logger_mt<logging::trivial::severity_level>)

Logger.cpp

#include "Logger.h"

#include <boost/log/support/date_time.hpp>
#include <boost/log/expressions.hpp>
#include <boost/log/utility/setup/file.hpp>
#include <boost/log/utility/setup/console.hpp>
#include <boost/log/utility/setup/common_attributes.hpp>

void full_detail_formatter(logging::record_view const& rec, logging::formatting_ostream& strm);

void normal_formatter(logging::record_view const& rec, logging::formatting_ostream& strm);

BOOST_LOG_GLOBAL_LOGGER_INIT(MBLog, src::severity_logger_mt<logging::trivial::severity_level>)
{
    src::severity_logger_mt<logging::trivial::severity_level> lg;

    logging::add_common_attributes();

    auto file_sink = logging::add_file_log(
        keywords::file_name = "./logs/L%Y-%m-%d_%3N.log", // one file per date and execution
        keywords::rotation_size = 5 * 1024 * 1024,      // rotate after 5MB
        keywords::target = "./logs",
        keywords::min_free_space = 30 * 1024 * 1024,
        keywords::auto_flush = true,
        keywords::scan_method = boost::log::sinks::file::scan_matching
    );

    file_sink->set_formatter(&full_detail_formatter);
    file_sink->set_filter(
        logging::trivial::severity >= logging::trivial::trace
    );

    auto console_sink = logging::add_console_log(std::clog);
    console_sink->set_formatter(&full_detail_formatter);
    console_sink->set_filter(
        logging::trivial::severity >= logging::trivial::trace
    );

    logging::core::get()->set_filter(
        logging::trivial::severity >= logging::trivial::trace
    );

    return lg;
}

EDIT

Seems like someone already solved this problem here by creating thread for asio::io_service::run after execution of async_read_some


Solution

  • Seems like someone already solved this problem here by creating thread for asio::io_service::run after execution of async_read_some

    Yes. Otherwise the run() might complete before any work is registered.

    The documentation of that is here: http://www.boost.org/doc/libs/1_65_0/doc/html/boost_asio/reference/io_service/run/overload1.html

    The run() function blocks until all work has finished and there are no more handlers to be dispatched, or until the io_service has been stopped.

    More explanation can be found:

    Consider keeping the service with a io_service::work: boost asio post not working , io_service::run exits right after post